Crash_Override/FreeDATA
1
0
Fork 0
mirror of https://github.com/DJ2LS/FreeDATA synced 2024-05-14 10:04:33 +02:00
Code Issues Packages Projects Releases Wiki Activity

new logging

Browse source 
still not finished....
This commit is contained in:
DJ2LS 2021-11-18 19:40:22 +01:00
parent 039de380b1
commit f8cc8c58c8
6 changed files with 121 additions and 68 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

59
tnc/daemon.py
View file

@ -19,7 +19,12 @@ import psutil
import serial.tools.list_ports
import static
import crcengine
import re
import logging, structlog, log_handler
log_handler.setup_logging("daemon")
structlog.get_logger("structlog").info("[DMN] Starting...")
####################################################
@ -54,12 +59,24 @@ def noalsaerr():
# sys.path.append("hamlib/linux")
try:
from hamlib.linux import Hamlib
print("running Hamlib Version - {0} - from precompiled bundle".format(Hamlib.cvar.hamlib_version))
# https://stackoverflow.com/a/4703409
hamlib_version = re.findall(r"[-+]?\d*\.?\d+|\d+", Hamlib.cvar.hamlib_version)
hamlib_version = float(hamlib_version[0])
hamlib_path = "lib/hamlib/" + sys.platform
structlog.get_logger("structlog").info("[DMN] Hamlib found", version=hamlib_version, path=hamlib_path)
except ImportError:
import Hamlib
print("running Hamlib Version - {0} - from Sys Path".format(Hamlib.cvar.hamlib_version))
# https://stackoverflow.com/a/4703409
hamlib_version = re.findall(r"[-+]?\d*\.?\d+|\d+", Hamlib.cvar.hamlib_version)
hamlib_version = float(hamlib_version[0])
min_hamlib_version = 4.1
if hamlib_version > min_hamlib_version:
structlog.get_logger("structlog").info("[DMN] Hamlib found", version=hamlib_version, path="system")
else:
structlog.get_logger("structlog").critical("[DMN] Hamlib outdated", found=hamlib_version, needed=min_hamlib_version, path="system")
else:
# place for rigctld
pass
@ -71,21 +88,21 @@ crc_algorithm = crcengine.new('crc16-ccitt-false') # load crc8 library
def start_daemon():
try:
print("SRV | STARTING TCP/IP SOCKET FOR CMD ON PORT: " + str(PORT))
structlog.get_logger("structlog").info("[DMN] Starting TCP/IP socket", port=PORT)
# https://stackoverflow.com/a/16641793
socketserver.TCPServer.allow_reuse_address = True
daemon = socketserver.TCPServer(
('0.0.0.0', PORT), CMDTCPRequestHandler)
daemon = socketserver.TCPServer(('0.0.0.0', PORT), CMDTCPRequestHandler)
daemon.serve_forever()
finally:
structlog.get_logger("structlog").warning("[DMN] Closing socket", port=PORT)
daemon.server_close()
class CMDTCPRequestHandler(socketserver.BaseRequestHandler):
def handle(self):
print("Client connected...")
structlog.get_logger("structlog").debug("[DMN] Client connected", ip=self.client_address[0])
# loop through socket buffer until timeout is reached. then close buffer
socketTimeout = time.time() + 3
@ -145,8 +162,9 @@ class CMDTCPRequestHandler(socketserver.BaseRequestHandler):
serialspeed = str(received_json["parameter"][0]["serialspeed"])
pttprotocol = str(received_json["parameter"][0]["pttprotocol"])
pttport = str(received_json["parameter"][0]["pttport"])
print("---- STARTING TNC !")
print(received_json["parameter"][0])
structlog.get_logger("structlog").warning("[DMN] Starting TNC", rig=deviceid, port=deviceport)
#print(received_json["parameter"][0])
# command = "--rx "+ rx_audio +" \
# --tx "+ tx_audio +" \
@ -180,21 +198,21 @@ class CMDTCPRequestHandler(socketserver.BaseRequestHandler):
command.append('./tnc')
command += options
p = subprocess.Popen(command)
print("running TNC from binary...")
except Exception as e:
structlog.get_logger("structlog").info("[DMN] TNC started", path="binary")
except:
command = []
command.append('python3')
command.append('main.py')
command += options
p = subprocess.Popen(command)
print("running TNC from source...")
structlog.get_logger("structlog").info("[DMN] TNC started", path="source")
static.TNCPROCESS = p # .pid
static.TNCSTARTED = True
if received_json["type"] == 'SET' and received_json["command"] == 'STOPTNC':
static.TNCPROCESS.kill()
print("KILLING PROCESS ------------")
structlog.get_logger("structlog").warning("[DMN] Stopping TNC")
#os.kill(static.TNCPROCESS, signal.SIGKILL)
static.TNCSTARTED = False
@ -331,9 +349,8 @@ class CMDTCPRequestHandler(socketserver.BaseRequestHandler):
self.request.sendall(bytes(jsondata, encoding))
except:
print("Unexpected error:", sys.exc_info()[0])
print("can't open rig")
#sys.exit("hamlib error")
structlog.get_logger("structlog").error("[DMN] Hamlib: Can't open rig")
structlog.get_logger("structlog").error("[DMN] Unexpected error", e = sys.exc_info()[0])
# exception, if JSON cant be decoded
# except Exception as e:
@ -351,17 +368,15 @@ class CMDTCPRequestHandler(socketserver.BaseRequestHandler):
# exception for any other errors
# in case of index error for example which is caused by a hard network interruption
except:
print("other network error...")
print("Client disconnected...")
structlog.get_logger("structlog").error("[DMN] Network error", e = sys.exc_info()[0])
structlog.get_logger("structlog").warning("[DMN] Closing client socket")
if __name__ == '__main__':
# --------------------------------------------GET PARAMETER INPUTS
PARSER = argparse.ArgumentParser(description='Simons TEST TNC')
PARSER.add_argument('--port', dest="socket_port",
default=3001, help="Socket port", type=int)
PARSER.add_argument('--port', dest="socket_port",default=3001, help="Socket port", type=int)
ARGS = PARSER.parse_args()
PORT = ARGS.socket_port

28
tnc/data_handler.py
View file

@ -7,7 +7,7 @@ Created on Sun Dec 27 20:43:40 2020
"""
import logging
import logging, structlog, log_handler
import threading
import time
from random import randrange
@ -286,13 +286,12 @@ def arq_data_received(data_in, bytes_per_frame):
logging.info("DATA [" + str(static.MYCALLSIGN, 'utf-8') + "]<< >>[" + str(static.DXCALLSIGN, 'utf-8') + "] [SNR:" + str(static.SNR) + "]")
else:
print("ARQ_FRAME_BOF_RECEIVED " + str(RX_FRAME_BOF_RECEIVED))
print("ARQ_FRAME_EOF_RECEIVED " + str(RX_FRAME_EOF_RECEIVED))
print(static.RX_FRAME_BUFFER)
structlog.get_logger("structlog").debug("[TNC] ARQ: ", ARQ_FRAME_BOF_RECEIVED=RX_FRAME_BOF_RECEIVED, ARQ_FRAME_EOF_RECEIVED=RX_FRAME_EOF_RECEIVED )
calculate_transfer_rate_rx(RX_N_FRAMES_PER_DATA_FRAME, RX_N_FRAME_OF_DATA_FRAME, RX_START_OF_TRANSMISSION, RX_PAYLOAD_PER_ARQ_FRAME)
static.INFO.append("ARQ;RECEIVING;FAILED")
logging.error("ARQ | RX | DATA FRAME NOT SUCESSFULLY RECEIVED!")
structlog.get_logger("structlog").warning("[TNC] ARQ: DATA FRAME NOT SUCESSFULLY RECEIVED!")
# STATE CLEANUP
#arq_reset_frame_machine()
@ -302,7 +301,7 @@ def arq_data_received(data_in, bytes_per_frame):
static.RX_BURST_BUFFER = []
static.RX_FRAME_BUFFER = []
logging.info("DATA [" + str(static.MYCALLSIGN, 'utf-8') + "]<<X>>[" + str(static.DXCALLSIGN, 'utf-8') + "] [SNR:" + str(static.SNR) + "]")
structlog.get_logger("structlog").info("[TNC] DATA [" + str(static.MYCALLSIGN, 'utf-8') + "]<<X>>[" + str(static.DXCALLSIGN, 'utf-8') + "]", snr=static.SNR)
def arq_transmit(data_out, mode, n_frames_per_burst):
@ -364,6 +363,8 @@ def arq_transmit(data_out, mode, n_frames_per_burst):
static.INFO.append("ARQ;TRANSMITTING")
logging.info("ARQ | TX | M:" + str(DATA_CHANNEL_MODE) + " | DATA FRAME --- BYTES: " + str(len(data_out)) + " ARQ FRAMES: " + str(TX_BUFFER_SIZE))
# ----------------------- THIS IS THE MAIN LOOP-----------------------------------------------------------------
TX_N_SENT_FRAMES = 0 # SET N SENT FRAMES TO 0 FOR A NEW SENDING CYCLE
while TX_N_SENT_FRAMES <= TX_BUFFER_SIZE and static.ARQ_STATE == 'DATA':
@ -429,7 +430,7 @@ def arq_transmit(data_out, mode, n_frames_per_burst):
# --------------------------- START TIMER FOR WAITING FOR ACK ---> IF TIMEOUT REACHED, ACK_TIMEOUT = 1
logging.debug("ARQ | RX | WAITING FOR BURST ACK")
structlog.get_logger("structlog").debug("[TNC] ARQ | RX | WAITING FOR BURST ACK")
static.CHANNEL_STATE = 'RECEIVING_SIGNALLING'
burstacktimeout = time.time() + BURST_ACK_TIMEOUT_SECONDS
@ -441,9 +442,9 @@ def arq_transmit(data_out, mode, n_frames_per_burst):
# HERE WE PROCESS DATA IF WE RECEIVED ACK/RPT FRAMES OR NOT WHILE WE ARE IN ARQ STATE
# IF WE ARE NOT IN ARQ STATE, WE STOPPED THE TRANSMISSION
if RPT_REQUEST_RECEIVED and static.ARQ_STATE == 'DATA':
logging.warning("ARQ | RX | REQUEST FOR REPEATING FRAMES: " + str(RPT_REQUEST_BUFFER))
logging.warning("ARQ | TX | SENDING REQUESTED FRAMES: " + str(RPT_REQUEST_BUFFER))
structlog.get_logger("structlog").debug("[TNC] ARQ | RX | REQUEST FOR REPEATING FRAMES: ",buffer=RPT_REQUEST_BUFFER)
structlog.get_logger("structlog").debug("[TNC] ARQ | TX | SENDING REQUESTED FRAMES: ",buffer=RPT_REQUEST_BUFFER)
# --------- BUILD RPT FRAME --------------
tempbuffer = []
for n in range(0, len(RPT_REQUEST_BUFFER)):
@ -457,8 +458,7 @@ def arq_transmit(data_out, mode, n_frames_per_burst):
try:
payload_data = bytes(TX_BUFFER[TX_N_SENT_FRAMES + missing_frame - 1])
except:
print("modem buffer selection problem with ARQ RPT frames")
structlog.get_logger("structlog").warning("[TNC] ARQ :modem buffer selection problem with ARQ RPT frames")
n_current_arq_frame = TX_N_SENT_FRAMES + missing_frame
n_current_arq_frame = n_current_arq_frame.to_bytes(2, byteorder='big')
@ -492,13 +492,13 @@ def arq_transmit(data_out, mode, n_frames_per_burst):
if BURST_ACK_RECEIVED:
logging.info("ARQ | RX | ACK AFTER RPT")
structlog.get_logger("structlog").info("[TNC] ARQ : ACK after repeat")
arq_reset_ack(True)
RPT_REQUEST_BUFFER = []
TX_N_SENT_FRAMES = TX_N_SENT_FRAMES + TX_N_FRAMES_PER_BURST
if time.time() > rpttimeout and not BURST_ACK_RECEIVED:
logging.error("ARQ | Burst lost....")
structlog.get_logger("structlog").warning("[TNC] ARQ : Burst lost...")
arq_reset_ack(False)
RPT_REQUEST_BUFFER = []

2
tnc/helpers.py
View file

@ -75,6 +75,7 @@ def add_to_heard_stations(dxcallsign, dxgrid, datatype, snr, offset, frequency):
# item = [dxcallsign, int(time.time())]
# static.HEARD_STATIONS[idx] = item
'''
def setup_logging():
"""
Author: DJ2LS
@ -101,3 +102,4 @@ def setup_logging():
logging.addLevelName(25, "\033[1;32m%s\033[1;0m" % "SUCCESS")
logging.addLevelName(24, "\033[1;34m%s\033[1;0m" % "DATA")
'''

10
tnc/main.py
View file

@ -14,6 +14,13 @@ import static
import subprocess
import sys
import logging, structlog, log_handler
if __name__ == '__main__':
# --------------------------------------------GET PARAMETER INPUTS
@ -45,7 +52,8 @@ if __name__ == '__main__':
# config logging
helpers.setup_logging()
#helpers.setup_logging()
log_handler.setup_logging("tnc")
# --------------------------------------------START CMD SERVER

58
tnc/modem.py
View file

@ -11,7 +11,7 @@ from ctypes import *
import pathlib
import audioop
#import asyncio
import logging
import logging, structlog, log_handler
import time
import threading
import atexit
@ -19,6 +19,7 @@ import numpy as np
import helpers
import static
import data_handler
import re
####################################################
# https://stackoverflow.com/questions/7088672/pyaudio-working-but-spits-out-error-messages-each-time
@ -51,12 +52,24 @@ def noalsaerr():
# sys.path.append("hamlib/linux")
try:
from hamlib.linux import Hamlib
print("running Hamlib Version - {0} - from precompiled bundle".format(Hamlib.cvar.hamlib_version))
# https://stackoverflow.com/a/4703409
hamlib_version = re.findall(r"[-+]?\d*\.?\d+|\d+", Hamlib.cvar.hamlib_version)
hamlib_version = float(hamlib_version[0])
hamlib_path = "/lib/hamlib/" + sys.platform
structlog.get_logger("structlog").info("[TNC] Hamlib found", version=hamlib_version, path=hamlib_path)
except ImportError:
import Hamlib
print("running Hamlib Version - {0} - from Sys Path".format(Hamlib.cvar.hamlib_version))
# https://stackoverflow.com/a/4703409
hamlib_version = re.findall(r"[-+]?\d*\.?\d+|\d+", Hamlib.cvar.hamlib_version)
hamlib_version = float(hamlib_version[0])
min_hamlib_version = 4.1
if hamlib_version > min_hamlib_version:
structlog.get_logger("structlog").info("[TNC] Hamlib found", version=hamlib_version, path="system")
else:
structlog.get_logger("structlog").critical("[TNC] Hamlib outdated", found=hamlib_version, needed=min_hamlib_version, path="system")
else:
# place for rigctld
pass
@ -100,17 +113,26 @@ class RF():
# -------------------------------------------- LOAD FREEDV
try:
# we check at first for libcodec2 in root - necessary if we want to run it inside a pyinstaller binary
libname = pathlib.Path("libcodec2.so.1.0")
self.c_lib = ctypes.CDLL(libname)
print("running libcodec from INTERNAL library")
except:
# if we cant load libcodec from root, we check for subdirectory
# we check at first for libcodec2 compiled from source
# this happens, if we want to run it beeing build in a dev environment
libname = pathlib.Path().absolute() / "codec2/build_linux/src/libcodec2.so.1.0"
self.c_lib = ctypes.CDLL(libname)
print("running libcodec from EXTERNAL library")
# --------------------------------------------CREATE PYAUDIO INSTANCE
if libname.is_file():
self.c_lib = ctypes.CDLL(libname)
structlog.get_logger("structlog").info("[TNC] Codec2 found", path=libname, origin="source")
else:
raise UnboundLocalError
except:
# this is the normal behavior. Run codec2 from lib folder
libname = pathlib.Path().absolute() / "lib/codec2/linux/libcodec2.so.1.0"
if libname.is_file():
self.c_lib = ctypes.CDLL(libname)
structlog.get_logger("structlog").info("[TNC] Codec2 found", path=libname, origin="precompiled")
else:
structlog.get_logger("structlog").critical("[TNC] Codec2 not found")
# --------------------------------------------CREATE PYAUDIO INSTANCE
try:
# we need to "try" this, because sometimes libasound.so isn't in the default place
# try to supress error messages
@ -212,8 +234,8 @@ class RF():
HAMLIB_THREAD.start()
except:
print("Unexpected error:", sys.exc_info()[0])
print("can't open rig")
structlog.get_logger("structlog").error("[TNC] Network error", e=sys.exc_info()[0])
structlog.get_logger("structlog").error("[TNC] Hamlib - can't open rig", e=sys.exc_info()[0])
sys.exit("hamlib error")
@ -660,8 +682,7 @@ class RF():
data_handler.received_beacon(bytes_out[:-2])
else:
logging.info("OTHER FRAME: " + str(bytes_out[:-2]))
print(frametype)
structlog.get_logger("structlog").warning("[TNC] ARQ - other frame type", frametype=frametype)
# DO UNSYNC AFTER LAST BURST by checking the frame nums against the total frames per burst
if frame == n_frames_per_burst:
@ -774,7 +795,8 @@ class RF():
#static.FFT = dfftlist
except:
print("setting fft = 0")
structlog.get_logger("structlog").debug("[TNC] Setting fft=0")
# else 0
static.FFT = [0] * 400
else:

32
tnc/sock.py
View file

@ -36,6 +36,9 @@ import helpers
import sys
import os
import logging, structlog, log_handler
class ThreadedTCPServer(socketserver.ThreadingMixIn, socketserver.TCPServer):
pass
@ -44,7 +47,7 @@ class ThreadedTCPServer(socketserver.ThreadingMixIn, socketserver.TCPServer):
class ThreadedTCPRequestHandler(socketserver.BaseRequestHandler):
def handle(self):
print("Client connected...")
structlog.get_logger("structlog").debug("[TNC] Client connected", ip=self.client_address[0])
# loop through socket buffer until timeout is reached. then close buffer
socketTimeout = time.time() + 3
@ -137,6 +140,7 @@ class ThreadedTCPRequestHandler(socketserver.BaseRequestHandler):
if received_json["type"] == 'ARQ' and received_json["command"] == "stopTransmission":
print(" >>> STOPPING TRANSMISSION <<<")
structlog.get_logger("structlog").warning("[TNC] Stopping transmission!")
static.TNC_STATE = 'IDLE'
static.ARQ_STATE = 'IDLE'
@ -149,11 +153,10 @@ class ThreadedTCPRequestHandler(socketserver.BaseRequestHandler):
self.request.sendall(b'INVALID CALLSIGN')
else:
static.MYCALLSIGN = bytes(callsign, encoding)
static.MYCALLSIGN_CRC8 = helpers.get_crc_8(
static.MYCALLSIGN)
logging.info("CMD | MYCALLSIGN: " +
str(static.MYCALLSIGN))
static.MYCALLSIGN_CRC8 = helpers.get_crc_8(static.MYCALLSIGN)
structlog.get_logger("structlog").info("[TNC] SET MYCALL", grid=static.MYCALLSIGN, crc=static.MYCALLSIGN_CRC8)
if received_json["type"] == 'SET' and received_json["command"] == 'MYGRID':
mygrid = received_json["parameter"]
@ -161,7 +164,7 @@ class ThreadedTCPRequestHandler(socketserver.BaseRequestHandler):
self.request.sendall(b'INVALID GRID')
else:
static.MYGRID = bytes(mygrid, encoding)
logging.info("CMD | MYGRID: " + str(static.MYGRID))
structlog.get_logger("structlog").info("[TNC] SET MYGRID", grid=static.MYGRID)
if received_json["type"] == 'GET' and received_json["command"] == 'STATION_INFO':
output = {
@ -217,12 +220,12 @@ class ThreadedTCPRequestHandler(socketserver.BaseRequestHandler):
try:
jsondata = json.dumps(output)
except ValueError as e:
print(e)
structlog.get_logger("structlog").error(e, data=jsondata)
try:
self.request.sendall(bytes(jsondata, encoding))
except Exception as e:
print(e)
structlog.get_logger("structlog").error(e, data=jsondata)
if received_json["type"] == 'GET' and received_json["command"] == 'RX_BUFFER':
output = {
@ -271,15 +274,18 @@ class ThreadedTCPRequestHandler(socketserver.BaseRequestHandler):
print("############ END OF ERROR #######################")
print("reset of connection...")
structlog.get_logger("structlog").warning("[TNC] Stopping transmission!")
#socketTimeout = 0
print("Client disconnected...")
structlog.get_logger("structlog").error("[TNC] Network error", e = sys.exc_info()[0])
structlog.get_logger("structlog").warning("[TNC] Closing client socket")
def start_cmd_socket():
try:
logging.info(
"SRV | STARTING TCP/IP SOCKET FOR CMD ON PORT: " + str(static.PORT))
structlog.get_logger("structlog").info("[TNC] Starting TCP/IP socket", port=static.PORT)
# https://stackoverflow.com/a/16641793
socketserver.TCPServer.allow_reuse_address = True
cmdserver = ThreadedTCPServer(
@ -289,7 +295,7 @@ def start_cmd_socket():
server_thread.start()
except:
print("Socket error...")
structlog.get_logger("structlog").error("[TNC] Starting TCP/IP socket failed", port=static.PORT)
e = sys.exc_info()[0]
print(e)
exc_type, exc_obj, exc_tb = sys.exc_info()