FreeDATA/tnc/data_handler.py

873 lines
34 KiB
Python
Raw Normal View History

2021-02-24 13:22:28 +00:00
#!/usr/bin/env python3
# -*- coding: utf-8 -*-
"""
Created on Sun Dec 27 20:43:40 2020
@author: DJ2LS
"""
import sys
2021-11-18 18:40:22 +00:00
import logging, structlog, log_handler
2021-02-24 13:22:28 +00:00
import threading
import time
from random import randrange
2021-02-28 16:28:07 +00:00
import asyncio
import zlib
import ujson as json
2021-02-24 13:22:28 +00:00
import static
import modem
import helpers
import codec2
2021-03-12 13:14:36 +00:00
modem = modem.RF()
2021-02-24 13:22:28 +00:00
2022-01-04 12:09:15 +00:00
2021-09-26 15:51:11 +00:00
'''
Author: DJ2LS
Description:
data_handler is a module like file, which handles all the ARQ related parts.
2021-12-29 19:54:54 +00:00
Because of the fact, that we need to use it from both directions - circular import,
2021-09-26 15:51:11 +00:00
socket.py and modem.py ( TX and RX ), I was not able, to move it to a class system, yet.
Global variables are needed, because we need to save our ack state for example, which needs to
be accessable by several functions.
If we want to use global varialbes within a multithreaded environment,
2021-09-26 15:51:11 +00:00
we need to declare every needed variable in every function, so the threading module can
detect and use them.
From time to time I try to reduce the amount of application wide variables within static. module
and moving them to module wide globals
2021-09-26 15:51:11 +00:00
'''
2022-01-04 15:34:20 +00:00
TESTMODE = False
# MODULE GLOBALS
2021-09-26 15:51:11 +00:00
DATA_CHANNEL_LAST_RECEIVED = 0.0 # time of last "live sign" of a frame
2022-01-04 12:09:15 +00:00
BURST_ACK_SNR = 0 # SNR from received ack frames
2021-09-26 15:51:11 +00:00
BURST_ACK_RECEIVED = False # if we received an acknowledge frame for a burst
DATA_FRAME_ACK_RECEIVED = False # if we received an acknowledge frame for a data frame
RPT_REQUEST_RECEIVED = False # if we received an request for repeater frames
RPT_REQUEST_BUFFER = [] # requested frames, saved in a list
RX_START_OF_TRANSMISSION = 0 # time of transmission start
2022-01-02 09:39:49 +00:00
DATA_FRAME_BOF = b'BOF'#b'\xAA\xAA' # 2 bytes for the BOF End of File indicator in a data frame
DATA_FRAME_EOF = b'EOF'#b'\xFF\xFF' # 2 bytes for the EOF End of File indicator in a data frame
def arq_data_received(data_in:bytes, bytes_per_frame:int, snr:int, freedv):
2021-12-29 19:54:54 +00:00
data_in = bytes(data_in)
2021-09-26 15:51:11 +00:00
# we neeed to declare our global variables, so the thread has access to them
global RX_START_OF_TRANSMISSION
global DATA_CHANNEL_LAST_RECEIVED
2021-12-29 19:54:54 +00:00
global DATA_FRAME_BOF
global DATA_FRAME_EOF
2022-01-04 15:34:20 +00:00
global TESTMODE
# only process data if we are in ARQ and BUSY state else return to quit
if not static.ARQ_STATE and static.TNC_STATE != 'BUSY':
return
# these vars will be overwritten during processing data
RX_FRAME_BOF_RECEIVED = False # here we save, if we received a "beginn of (data)frame"
RX_FRAME_EOF_RECEIVED = False # here we save, if we received a "end of (data)frame"
RX_PAYLOAD_PER_MODEM_FRAME = bytes_per_frame - 2 # payload per moden frame
2021-02-24 13:22:28 +00:00
2021-03-12 13:14:36 +00:00
static.TNC_STATE = 'BUSY'
static.ARQ_STATE = True
2021-12-29 19:54:54 +00:00
static.INFO.append("ARQ;RECEIVING")
2021-09-26 15:51:11 +00:00
DATA_CHANNEL_LAST_RECEIVED = int(time.time())
2021-11-07 19:31:26 +00:00
# get some important data from the frame
2021-09-26 15:51:11 +00:00
RX_N_FRAME_OF_BURST = int.from_bytes(bytes(data_in[:1]), "big") - 10 # get number of burst frame
RX_N_FRAMES_PER_BURST = int.from_bytes(bytes(data_in[1:2]), "big") # get number of bursts from received frame
2021-12-29 19:54:54 +00:00
print(f"RX_N_FRAME_OF_BURST-{RX_N_FRAME_OF_BURST}")
print(f"RX_N_FRAMES_PER_BURST-{RX_N_FRAMES_PER_BURST}")
2021-03-12 13:14:36 +00:00
2021-12-29 19:54:54 +00:00
'''
The RX burst buffer needs to have a fixed length filled with "None". We need this later for counting the "Nones"
check if burst buffer has expected length else create it
'''
if len(static.RX_BURST_BUFFER) != RX_N_FRAMES_PER_BURST:
static.RX_BURST_BUFFER = [None] * RX_N_FRAMES_PER_BURST
# append data to rx burst buffer
static.RX_BURST_BUFFER[RX_N_FRAME_OF_BURST] = data_in[4:]
2021-12-29 19:54:54 +00:00
'''
check if we received all frames per burst by checking if burst buffer has no more "Nones"
this is the ideal case because we received all data
'''
if not None in static.RX_BURST_BUFFER:
# then iterate through burst buffer and append data to frame buffer
for i in range(0,len(static.RX_BURST_BUFFER)):
static.RX_FRAME_BUFFER += static.RX_BURST_BUFFER[i]
# then delete burst buffer
static.RX_BURST_BUFFER = []
2021-12-29 19:54:54 +00:00
# lets check if we didnt receive a BOF and EOF yet to avoid sending ack frames if we already received all data
if not RX_FRAME_BOF_RECEIVED and not RX_FRAME_EOF_RECEIVED and data_in.find(DATA_FRAME_EOF) < 0:
print(RX_FRAME_BOF_RECEIVED)
print(RX_FRAME_EOF_RECEIVED)
2021-12-29 19:54:54 +00:00
# create an ack frame
ack_frame = bytearray(14)
ack_frame[:1] = bytes([60])
ack_frame[1:2] = static.DXCALLSIGN_CRC8
ack_frame[2:3] = static.MYCALLSIGN_CRC8
ack_frame[3:4] = bytes([int(snr)])
2021-12-29 19:54:54 +00:00
# and transmit it
txbuffer = [ack_frame]
structlog.get_logger("structlog").info("[TNC] ARQ | RX | ACK")
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
2022-01-02 11:35:00 +00:00
2022-01-02 22:42:56 +00:00
calculate_transfer_rate_rx(RX_START_OF_TRANSMISSION, len(static.RX_FRAME_BUFFER))
2022-01-02 11:35:00 +00:00
2021-12-29 19:54:54 +00:00
# check if we received last frame of burst and we have "Nones" in our rx buffer
# this is an indicator for missed frames.
# with this way of doing this, we always MUST receive the last frame of a burst otherwise the entire
# burst is lost
elif RX_N_FRAME_OF_BURST == RX_N_FRAMES_PER_BURST -1:
# check where a None is in our burst buffer and do frame+1, beacuse lists start at 0
missing_frames = [(frame+1) for frame, element in enumerate(static.RX_BURST_BUFFER) if element == None]
structlog.get_logger("structlog").debug("all frames per burst received", frame=RX_N_FRAME_OF_BURST, frames=RX_N_FRAMES_PER_BURST)
# set n frames per burst to modem
# this is an idea so its not getting lost....
# we need to work on this
codec2.api.freedv_set_frames_per_burst(freedv,len(missing_frames))
2021-12-29 19:54:54 +00:00
# then create a repeat frame
2021-09-26 15:51:11 +00:00
rpt_frame = bytearray(14)
rpt_frame[:1] = bytes([62])
rpt_frame[1:2] = static.DXCALLSIGN_CRC8
rpt_frame[2:3] = static.MYCALLSIGN_CRC8
rpt_frame[3:9] = missing_frames
2021-03-12 13:14:36 +00:00
2021-12-29 19:54:54 +00:00
# and transmit it
txbuffer = [rpt_frame]
2021-12-29 19:54:54 +00:00
structlog.get_logger("structlog").info("[TNC] ARQ | RX | Requesting", frames=missing_frames)
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
2022-01-02 22:42:56 +00:00
calculate_transfer_rate_rx(RX_START_OF_TRANSMISSION, len(static.RX_FRAME_BUFFER))
2021-12-29 19:54:54 +00:00
# we should never reach this point
else:
structlog.get_logger("structlog").error("we shouldnt reach this point...", frame=RX_N_FRAME_OF_BURST, frames=RX_N_FRAMES_PER_BURST)
2021-12-29 19:54:54 +00:00
# We have a BOF and EOF flag in our data. If we received both we received our frame.
# In case of loosing data but we received already a BOF and EOF we need to make sure, we
# received the complete last burst by checking it for Nones
bof_position = static.RX_FRAME_BUFFER.find(DATA_FRAME_BOF)
eof_position = static.RX_FRAME_BUFFER.find(DATA_FRAME_EOF)
if bof_position >= 0 and eof_position > 0 and not None in static.RX_BURST_BUFFER:
print(f"bof_position {bof_position} / eof_position {eof_position}")
2021-12-29 19:54:54 +00:00
RX_FRAME_BOF_RECEIVED = True
RX_FRAME_EOF_RECEIVED = True
#now extract raw data from buffer
payload = static.RX_FRAME_BUFFER[bof_position+len(DATA_FRAME_BOF):eof_position]
# get the data frame crc
2021-12-29 19:54:54 +00:00
data_frame_crc = payload[:2]
data_frame = payload[2:]
data_frame_crc_received = helpers.get_crc_16(data_frame)
2021-12-29 19:54:54 +00:00
# check if data_frame_crc is equal with received crc
if data_frame_crc == data_frame_crc_received:
structlog.get_logger("structlog").info("[TNC] ARQ | RX | DATA FRAME SUCESSFULLY RECEIVED")
2021-12-29 19:54:54 +00:00
static.INFO.append("ARQ;RECEIVING;SUCCESS")
# decompression
data_frame_decompressed = zlib.decompress(data_frame)
static.ARQ_COMPRESSION_FACTOR = len(data_frame_decompressed) / len(data_frame)
data_frame = data_frame_decompressed
# decode to utf-8 string
2021-12-29 19:54:54 +00:00
data_frame = data_frame.decode("utf-8")
# decode json objects from data frame to inspect if we received a file or message
2021-12-29 19:54:54 +00:00
rawdata = json.loads(data_frame)
'''
if datatype is a file, we append to RX_BUFFER, which contains files only
dt = datatype
--> f = file
--> m = message
fn = filename
ft = filetype
d = data
crc = checksum
'''
if rawdata["dt"] == "f":
2022-01-04 13:45:30 +00:00
#structlog.get_logger("structlog").debug("RECEIVED FILE --> MOVING DATA TO RX BUFFER")
2021-12-29 19:54:54 +00:00
static.RX_BUFFER.append([static.DXCALLSIGN,static.DXGRID,int(time.time()), data_frame])
# if datatype is a file, we append to RX_MSG_BUFFER, which contains messages only
if rawdata["dt"] == "m":
static.RX_MSG_BUFFER.append([static.DXCALLSIGN,static.DXGRID,int(time.time()), complete_data_frame])
2022-01-04 13:45:30 +00:00
#structlog.get_logger("structlog").debug("RECEIVED MESSAGE --> MOVING DATA TO MESSAGE BUFFER")
2021-12-29 19:54:54 +00:00
# BUILDING ACK FRAME FOR DATA FRAME
2021-09-26 15:51:11 +00:00
ack_frame = bytearray(14)
ack_frame[:1] = bytes([61])
ack_frame[1:2] = static.DXCALLSIGN_CRC8
ack_frame[2:3] = static.MYCALLSIGN_CRC8
2021-03-12 13:14:36 +00:00
2021-12-29 19:54:54 +00:00
# TRANSMIT ACK FRAME FOR BURST
structlog.get_logger("structlog").info("[TNC] ARQ | RX | SENDING DATA FRAME ACK", snr=static.SNR, crc=data_frame_crc.hex())
txbuffer = [ack_frame]
2021-12-29 19:54:54 +00:00
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
2022-01-02 22:42:56 +00:00
# update our statistics AFTER the frame ACK
calculate_transfer_rate_rx(RX_START_OF_TRANSMISSION, len(static.RX_FRAME_BUFFER))
2022-01-04 15:34:20 +00:00
2021-12-29 19:54:54 +00:00
structlog.get_logger("structlog").info("[TNC] | RX | DATACHANNEL [" + str(static.MYCALLSIGN, 'utf-8') + "]<< >>[" + str(static.DXCALLSIGN, 'utf-8') + "]", snr=static.SNR)
2021-02-24 13:22:28 +00:00
2021-12-29 19:54:54 +00:00
else:
static.INFO.append("ARQ;RECEIVING;FAILED")
structlog.get_logger("structlog").warning("[TNC] ARQ | RX | DATA FRAME NOT SUCESSFULLY RECEIVED!", e="wrong crc", expected=data_frame_crc, received=data_frame_crc_received)
# BUILDING NACK FRAME FOR DATA FRAME
nack_frame = bytearray(14)
nack_frame[:1] = bytes([63])
nack_frame[1:2] = static.DXCALLSIGN_CRC8
nack_frame[2:3] = static.MYCALLSIGN_CRC8
# TRANSMIT NACK FRAME FOR BURST
txbuffer = [nack_frame]
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
2021-12-29 19:54:54 +00:00
# And finally we do a cleanup of our buffers and states
2022-01-04 15:34:20 +00:00
# do cleanup only when not in testmode
if not TESTMODE:
arq_cleanup()
2021-12-29 19:54:54 +00:00
2022-01-02 08:51:37 +00:00
def arq_transmit(data_out:bytes, mode:int, n_frames_per_burst:int):
2022-01-04 15:34:20 +00:00
2021-09-26 15:51:11 +00:00
global RPT_REQUEST_BUFFER
global DATA_FRAME_ACK_RECEIVED
global RPT_REQUEST_RECEIVED
global BURST_ACK_RECEIVED
2022-01-04 12:09:15 +00:00
global BURST_ACK_SNR
#global TX_START_OF_TRANSMISSION
2021-12-29 19:54:54 +00:00
global DATA_FRAME_BOF
global DATA_FRAME_EOF
2022-01-04 15:34:20 +00:00
global TESTMODE
2021-12-29 19:54:54 +00:00
TX_N_SENT_BYTES = 0 # already sent bytes per data frame
TX_N_RETRIES_PER_BURST = 0 # retries we already sent data
TX_N_MAX_RETRIES_PER_BURST = 5 # max amount of retries we sent before frame is lost
TX_N_FRAMES_PER_BURST = n_frames_per_burst # amount of n frames per burst
TX_BUFFER = [] # our buffer for appending new data
2021-09-26 15:51:11 +00:00
2021-11-07 19:31:26 +00:00
# TIMEOUTS
2022-01-02 09:35:30 +00:00
BURST_ACK_TIMEOUT_SECONDS = 3.0 # timeout for burst acknowledges
DATA_FRAME_ACK_TIMEOUT_SECONDS = 3.0 # timeout for data frame acknowledges
RPT_ACK_TIMEOUT_SECONDS = 3.0 # timeout for rpt frame acknowledges
# save len of data_out to TOTAL_BYTES for our statistics --> kBytes
static.TOTAL_BYTES = round(len(data_out) / 1024, 2)
2021-12-29 19:54:54 +00:00
static.INFO.append("ARQ;TRANSMITTING")
structlog.get_logger("structlog").info("[TNC] | TX | DATACHANNEL", mode=mode, kBytes=static.TOTAL_BYTES)
2021-09-26 15:51:11 +00:00
# compression
data_frame_compressed = zlib.compress(data_out)
static.ARQ_COMPRESSION_FACTOR = len(data_out) / len(data_frame_compressed)
data_out = data_frame_compressed
# reset statistics
tx_start_of_transmission = time.time()
calculate_transfer_rate_tx(tx_start_of_transmission, 0, len(data_out))
2021-12-29 19:54:54 +00:00
# append a crc and beginn and end of file indicators
2021-03-12 13:14:36 +00:00
frame_payload_crc = helpers.get_crc_16(data_out)
2021-12-29 19:54:54 +00:00
data_out = DATA_FRAME_BOF + frame_payload_crc + data_out + DATA_FRAME_EOF
#initial bufferposition is 0
bufferposition = 0
# iterate through data out buffer
while bufferposition < len(data_out) and not DATA_FRAME_ACK_RECEIVED and static.ARQ_STATE:
2022-01-02 09:35:30 +00:00
2022-01-04 13:45:30 +00:00
structlog.get_logger("structlog").debug("DATA_FRAME_ACK_RECEIVED", state=DATA_FRAME_ACK_RECEIVED)
2022-01-04 12:09:15 +00:00
2021-12-29 19:54:54 +00:00
# we have TX_N_MAX_RETRIES_PER_BURST attempts for sending a burst
for TX_N_RETRIES_PER_BURST in range(0,TX_N_MAX_RETRIES_PER_BURST):
# AUTO MODE SELECTION
# mode 255 == AUTO MODE
# force usage of selected mode
2022-01-04 12:09:15 +00:00
if mode != 255:
data_mode = mode
2022-01-04 13:45:30 +00:00
structlog.get_logger("structlog").debug("FIXED MODE", mode=data_mode)
2022-01-04 12:09:15 +00:00
else:
# at beginnign of transmission try fastest mode
if bufferposition == 0:
data_mode = 10
# if we have a reduced SNR OR its the second attempt of sending data, select slower mode
if BURST_ACK_SNR < 10 or TX_N_RETRIES_PER_BURST >= 2:
2022-01-04 12:09:15 +00:00
data_mode = 12
2022-01-04 13:45:30 +00:00
structlog.get_logger("structlog").debug("AUTO MODE", mode=data_mode)
# if we have (again) a high SNR and our attmepts are 0, then switch back to a faster mode
if BURST_ACK_SNR < 20 and TX_N_RETRIES_PER_BURST == 0:
data_mode = 10
2022-01-04 13:45:30 +00:00
structlog.get_logger("structlog").debug("FIXED MODE", mode=data_mode)
2022-01-04 12:09:15 +00:00
2021-12-29 19:54:54 +00:00
# payload information
2022-01-04 12:09:15 +00:00
payload_per_frame = modem.get_bytes_per_frame(data_mode) -2
2021-12-29 19:54:54 +00:00
# tempbuffer list for storing our data frames
tempbuffer = []
# append data frames with TX_N_FRAMES_PER_BURST to tempbuffer
for i in range(0, TX_N_FRAMES_PER_BURST):
arqheader = bytearray()
arqheader[:1] = bytes([10 + i])
arqheader[1:2] = bytes([TX_N_FRAMES_PER_BURST])
arqheader[3:4] = bytes(static.DXCALLSIGN_CRC8)
arqheader[4:5] = bytes(static.MYCALLSIGN_CRC8)
bufferposition_end = (bufferposition + payload_per_frame - len(arqheader))
# normal behavior
if bufferposition_end <= len(data_out):
frame = data_out[bufferposition:bufferposition_end]
frame = arqheader + frame
# this point shouldnt reached that often
elif bufferposition > len(data_out):
break
# the last bytes of a frame
else:
extended_data_out = data_out[bufferposition:]
extended_data_out += bytes([0]) * (payload_per_frame-len(extended_data_out)-len(arqheader))
frame = arqheader + extended_data_out
# update the bufferposition
# bufferposition = bufferposition_end
tempbuffer.append(frame)
2022-01-04 12:09:15 +00:00
structlog.get_logger("structlog").info("[TNC] ARQ | TX | FRAMES", mode=data_mode, fpb=TX_N_FRAMES_PER_BURST, retry=TX_N_RETRIES_PER_BURST)
modem.transmit(mode=data_mode, repeats=1, repeat_delay=0, frames=tempbuffer)
2021-12-29 19:54:54 +00:00
# lets wait for an ACK or RPT frame
burstacktimeout = time.time() + BURST_ACK_TIMEOUT_SECONDS
while not BURST_ACK_RECEIVED and not RPT_REQUEST_RECEIVED and not DATA_FRAME_ACK_RECEIVED and time.time() < burstacktimeout and static.ARQ_STATE:
2021-12-29 19:54:54 +00:00
time.sleep(0.001)
2022-01-02 09:35:30 +00:00
2021-12-29 19:54:54 +00:00
# once we received a burst ack, reset its state and break the RETRIES loop
if BURST_ACK_RECEIVED:
BURST_ACK_RECEIVED = False # reset ack state
TX_N_RETRIES_PER_BURST = 0 # reset retries
break #break retry loop
2021-03-12 13:14:36 +00:00
2021-12-29 19:54:54 +00:00
if RPT_REQUEST_RECEIVED:
pass
2021-03-12 13:14:36 +00:00
2021-12-29 19:54:54 +00:00
if DATA_FRAME_ACK_RECEIVED:
break #break retry loop
2022-01-02 09:35:30 +00:00
# we need this part for leaving the repeat loop
# static.ARQ_STATE == 'DATA' --> when stopping transmission manually
if not static.ARQ_STATE:
2022-01-02 09:35:30 +00:00
#print("not ready for data...leaving loop....")
break
2021-12-29 19:54:54 +00:00
# NEXT ATTEMPT
2022-01-04 13:45:30 +00:00
structlog.get_logger("structlog").debug("ATTEMPT", retry=TX_N_RETRIES_PER_BURST, maxretries=TX_N_MAX_RETRIES_PER_BURST)
2021-12-29 19:54:54 +00:00
# update buffer position
bufferposition = bufferposition_end
# update stats
calculate_transfer_rate_tx(tx_start_of_transmission, bufferposition_end, len(data_out))
#GOING TO NEXT ITERATION
2021-03-12 13:14:36 +00:00
2021-12-29 19:54:54 +00:00
if DATA_FRAME_ACK_RECEIVED:
static.INFO.append("ARQ;TRANSMITTING;SUCCESS")
2022-01-04 15:34:20 +00:00
2021-12-29 19:54:54 +00:00
structlog.get_logger("structlog").info("ARQ | TX | DATA TRANSMITTED!", BytesPerMinute=static.ARQ_BYTES_PER_MINUTE, BitsPerSecond=static.ARQ_BITS_PER_SECOND)
2022-01-04 15:34:20 +00:00
2021-12-29 19:54:54 +00:00
else:
static.INFO.append("ARQ;TRANSMITTING;FAILED")
2022-01-02 09:35:30 +00:00
structlog.get_logger("structlog").info("ARQ | TX | TRANSMISSION FAILED OR TIME OUT!")
2021-03-12 13:14:36 +00:00
2022-01-04 15:34:20 +00:00
# and last but not least doing a state cleanup
# do cleanup only when not in testmode
if not TESTMODE:
arq_cleanup()
2021-03-12 13:14:36 +00:00
2022-01-04 15:34:20 +00:00
# quit after transmission
if TESTMODE:
import os
os._exit(0)
2021-03-17 10:22:06 +00:00
def burst_ack_received(data_in:bytes):
2021-09-26 15:51:11 +00:00
global BURST_ACK_RECEIVED
2022-01-04 12:09:15 +00:00
global BURST_ACK_SNR
2021-09-26 15:51:11 +00:00
global DATA_CHANNEL_LAST_RECEIVED
# only process data if we are in ARQ and BUSY state
if static.ARQ_STATE:
BURST_ACK_RECEIVED = True # Force data loops of TNC to stop and continue with next frame
DATA_CHANNEL_LAST_RECEIVED = int(time.time()) # we need to update our timeout timestamp
BURST_ACK_SNR = int.from_bytes(bytes(data_in[3:4]), "big")
2022-01-04 13:45:30 +00:00
2021-02-24 13:22:28 +00:00
def frame_ack_received():
2021-09-26 15:51:11 +00:00
global DATA_FRAME_ACK_RECEIVED
global DATA_CHANNEL_LAST_RECEIVED
# only process data if we are in ARQ and BUSY state
if static.ARQ_STATE:
DATA_FRAME_ACK_RECEIVED = True # Force data loops of TNC to stop and continue with next frame
DATA_CHANNEL_LAST_RECEIVED = int(time.time()) # we need to update our timeout timestamp
2021-03-12 13:14:36 +00:00
2021-02-24 13:22:28 +00:00
2022-01-04 12:09:15 +00:00
def frame_nack_received(data_in:bytes):
static.INFO.append("ARQ;TRANSMITTING;FAILED")
arq_cleanup()
2022-01-02 08:51:37 +00:00
def burst_rpt_received(data_in:bytes):
2021-09-26 15:51:11 +00:00
global RPT_REQUEST_RECEIVED
global RPT_REQUEST_BUFFER
global DATA_CHANNEL_LAST_RECEIVED
# only process data if we are in ARQ and BUSY state
if static.ARQ_STATE and static.TNC_STATE == 'BUSY':
RPT_REQUEST_RECEIVED = True
DATA_CHANNEL_LAST_RECEIVED = int(time.time()) # we need to update our timeout timestamp
RPT_REQUEST_BUFFER = []
2021-03-12 13:14:36 +00:00
missing_area = bytes(data_in[3:12]) # 1:9
2021-03-12 13:14:36 +00:00
for i in range(0, 6, 2):
if not missing_area[i:i + 2].endswith(b'\x00\x00'):
missing = missing_area[i:i + 2]
RPT_REQUEST_BUFFER.insert(0, missing)
2021-03-12 13:14:36 +00:00
# ############################################################################################################
2021-02-28 14:24:14 +00:00
# ARQ DATA CHANNEL HANDLER
2021-03-12 13:14:36 +00:00
# ############################################################################################################
2021-02-28 14:24:14 +00:00
2022-01-02 08:51:37 +00:00
def open_dc_and_transmit(data_out:bytes, mode:int, n_frames_per_burst:int):
static.TNC_STATE = 'BUSY'
2022-01-02 11:35:00 +00:00
2022-01-02 23:27:05 +00:00
# we need to compress data for gettin a compression factor.
# so we are compressing twice. This is not that nice and maybe theres another way
# for calculating transmission statistics
static.ARQ_COMPRESSION_FACTOR = len(data_out) / len(zlib.compress(data_out))
arq_open_data_channel(mode, len(data_out), n_frames_per_burst)
# wait until data channel is open
while not static.ARQ_STATE:
time.sleep(0.01)
arq_transmit(data_out, mode, n_frames_per_burst)
2021-03-19 10:16:24 +00:00
def arq_open_data_channel(mode:int, data_len:int, n_frames_per_burst:int):
2021-09-26 15:51:11 +00:00
global DATA_CHANNEL_LAST_RECEIVED
2021-03-19 10:16:24 +00:00
DATA_CHANNEL_MAX_RETRIES = 5 # N attempts for connecting to another station
2021-09-26 15:51:11 +00:00
DATA_CHANNEL_LAST_RECEIVED = int(time.time())
2021-03-12 13:14:36 +00:00
# devide by 1024 for getting Bytes -> kBytes
data_len = int(data_len / 1024)
2022-01-02 23:27:05 +00:00
# multiply compression factor for reducing it from float to int
compression_factor = int(static.ARQ_COMPRESSION_FACTOR * 10)
2021-09-26 15:51:11 +00:00
connection_frame = bytearray(14)
connection_frame[:1] = bytes([225])
connection_frame[1:2] = static.DXCALLSIGN_CRC8
connection_frame[2:3] = static.MYCALLSIGN_CRC8
connection_frame[3:9] = static.MYCALLSIGN
connection_frame[9:10] = bytes([0]) # ONE BYTE LEFT FOR OTHER THINGS
connection_frame[10:12] = data_len.to_bytes(2, byteorder='big')
2022-01-02 23:27:05 +00:00
connection_frame[12:13] = bytes([compression_factor])
connection_frame[13:14] = bytes([n_frames_per_burst])
print(connection_frame)
2021-11-19 16:47:25 +00:00
while not static.ARQ_STATE:
time.sleep(0.01)
for attempt in range(1,DATA_CHANNEL_MAX_RETRIES+1):
static.INFO.append("DATACHANNEL;OPENING")
2021-12-29 19:54:54 +00:00
structlog.get_logger("structlog").info("[TNC] ARQ | DATA | TX | [" + str(static.MYCALLSIGN, 'utf-8') + "]>> <<[" + str(static.DXCALLSIGN, 'utf-8') + "]", attempt=str(attempt) + "/" + str(DATA_CHANNEL_MAX_RETRIES))
2022-01-02 11:35:00 +00:00
txbuffer = [connection_frame]
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
timeout = time.time() + 3
while time.time() < timeout:
time.sleep(0.01)
# break if data channel is openend
if static.ARQ_STATE:
break
if static.ARQ_STATE:
2021-03-18 14:29:51 +00:00
break
2021-11-19 16:47:25 +00:00
if not static.ARQ_STATE and attempt == DATA_CHANNEL_MAX_RETRIES:
static.INFO.append("DATACHANNEL;FAILED")
2021-12-29 19:54:54 +00:00
structlog.get_logger("structlog").warning("[TNC] ARQ | TX | DATA [" + str(static.MYCALLSIGN, 'utf-8') + "]>>X<<[" + str(static.DXCALLSIGN, 'utf-8') + "]")
arq_cleanup()
sys.exit() # close thread and so connection attempts
2021-03-12 13:14:36 +00:00
2022-01-02 08:51:37 +00:00
def arq_received_data_channel_opener(data_in:bytes):
2021-09-26 15:51:11 +00:00
global DATA_CHANNEL_LAST_RECEIVED
2022-01-02 22:42:56 +00:00
global RX_START_OF_TRANSMISSION
2021-09-26 15:51:11 +00:00
static.INFO.append("DATACHANNEL;RECEIVEDOPENER")
static.DXCALLSIGN_CRC8 = bytes(data_in[2:3]).rstrip(b'\x00')
static.DXCALLSIGN = bytes(data_in[3:9]).rstrip(b'\x00')
static.TOTAL_BYTES = int.from_bytes(bytes(data_in[10:12]), "big") # kBytes
static.ARQ_COMPRESSION_FACTOR = float(int.from_bytes(bytes(data_in[12:13]), "big") / 10)
n_frames_per_burst = int.from_bytes(bytes(data_in[13:14]), "big")
modem.set_frames_per_burst(n_frames_per_burst)
2022-01-02 22:42:56 +00:00
helpers.add_to_heard_stations(static.DXCALLSIGN,static.DXGRID, 'DATA-CHANNEL', static.SNR, static.FREQ_OFFSET, static.HAMLIB_FREQUENCY)
2021-03-16 14:21:58 +00:00
2021-12-29 19:54:54 +00:00
structlog.get_logger("structlog").info("[TNC] ARQ | DATA | RX | [" + str(static.MYCALLSIGN, 'utf-8') + "]>> <<[" + str(static.DXCALLSIGN, 'utf-8') + "]")
static.ARQ_STATE = True
static.TNC_STATE = 'BUSY'
2021-05-09 15:55:15 +00:00
2022-01-02 22:42:56 +00:00
#mode = int.from_bytes(bytes(data_in[12:13]), "big")
2022-01-02 23:27:05 +00:00
print(static.ARQ_COMPRESSION_FACTOR)
print(int.from_bytes(bytes(data_in[12:13]), "big"))
print(bytes(data_in[12:13]))
2021-09-26 15:51:11 +00:00
DATA_CHANNEL_LAST_RECEIVED = int(time.time())
2021-02-28 14:24:14 +00:00
connection_frame = bytearray(14)
connection_frame[:1] = bytes([226])
connection_frame[1:2] = static.DXCALLSIGN_CRC8
connection_frame[2:3] = static.MYCALLSIGN_CRC8
2021-03-16 14:21:58 +00:00
connection_frame[3:9] = static.MYCALLSIGN
2022-01-02 23:27:05 +00:00
2022-01-02 22:42:56 +00:00
#connection_frame[12:13] = bytes([mode])
2022-01-02 22:42:56 +00:00
txbuffer = [connection_frame]
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
2021-12-25 16:05:38 +00:00
2022-01-02 22:42:56 +00:00
structlog.get_logger("structlog").info("[TNC] ARQ | DATA | RX | [" + str(static.MYCALLSIGN, 'utf-8') + "]>>|<<[" + str(static.DXCALLSIGN, 'utf-8') + "]", snr=static.SNR)
# set start of transmission for our statistics
RX_START_OF_TRANSMISSION = time.time()
2022-01-02 08:51:37 +00:00
def arq_received_channel_is_open(data_in:bytes):
2021-03-16 14:21:58 +00:00
2021-09-26 15:51:11 +00:00
global DATA_CHANNEL_LAST_RECEIVED
static.INFO.append("DATACHANNEL;OPEN")
2021-03-16 14:21:58 +00:00
static.DXCALLSIGN_CRC8 = bytes(data_in[2:3]).rstrip(b'\x00')
static.DXCALLSIGN = bytes(data_in[3:9]).rstrip(b'\x00')
helpers.add_to_heard_stations(static.DXCALLSIGN,static.DXGRID, 'DATA-CHANNEL', static.SNR, static.FREQ_OFFSET, static.HAMLIB_FREQUENCY)
2021-03-16 14:21:58 +00:00
2021-09-26 15:51:11 +00:00
DATA_CHANNEL_LAST_RECEIVED = int(time.time())
2021-03-12 13:14:36 +00:00
2022-01-04 12:09:15 +00:00
structlog.get_logger("structlog").info("[TNC] ARQ | DATA | TX | [" + str(static.MYCALLSIGN, 'utf-8') + "]>>|<<[" + str(static.DXCALLSIGN, 'utf-8') + "]", snr=static.SNR)
2021-02-28 14:24:14 +00:00
2022-01-04 12:09:15 +00:00
# as soon as we set ARQ_STATE to DATA, transmission starts
static.ARQ_STATE = True
DATA_CHANNEL_LAST_RECEIVED = int(time.time())
2021-03-12 13:14:36 +00:00
# ############################################################################################################
2021-02-24 15:47:52 +00:00
# PING HANDLER
2021-03-12 13:14:36 +00:00
# ############################################################################################################
2022-01-02 08:51:37 +00:00
def transmit_ping(callsign:str):
2021-03-11 19:04:31 +00:00
static.DXCALLSIGN = bytes(callsign, 'utf-8').rstrip(b'\x00')
2021-03-09 10:05:59 +00:00
static.DXCALLSIGN_CRC8 = helpers.get_crc_8(static.DXCALLSIGN)
static.INFO.append("PING;SENDING")
structlog.get_logger("structlog").info("[TNC] PING REQ [" + str(static.MYCALLSIGN, 'utf-8') + "] >>> [" + str(static.DXCALLSIGN, 'utf-8') + "]" )
2021-03-12 13:14:36 +00:00
2021-09-26 15:51:11 +00:00
ping_frame = bytearray(14)
ping_frame[:1] = bytes([210])
2021-03-07 15:41:02 +00:00
ping_frame[1:2] = static.DXCALLSIGN_CRC8
ping_frame[2:3] = static.MYCALLSIGN_CRC8
ping_frame[3:9] = static.MYCALLSIGN
2021-02-24 13:22:28 +00:00
txbuffer = [ping_frame]
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
2021-03-12 13:14:36 +00:00
2022-01-02 08:51:37 +00:00
def received_ping(data_in:bytes, frequency_offset:str):
2021-02-28 14:24:14 +00:00
2021-03-11 19:04:31 +00:00
static.DXCALLSIGN_CRC8 = bytes(data_in[2:3]).rstrip(b'\x00')
static.DXCALLSIGN = bytes(data_in[3:9]).rstrip(b'\x00')
helpers.add_to_heard_stations(static.DXCALLSIGN,static.DXGRID, 'PING', static.SNR, static.FREQ_OFFSET, static.HAMLIB_FREQUENCY)
static.INFO.append("PING;RECEIVING")
structlog.get_logger("structlog").info("[TNC] PING REQ [" + str(static.MYCALLSIGN, 'utf-8') + "] <<< [" + str(static.DXCALLSIGN, 'utf-8') + "]", snr=static.SNR )
2021-03-07 15:41:02 +00:00
2021-09-26 15:51:11 +00:00
ping_frame = bytearray(14)
ping_frame[:1] = bytes([211])
2021-03-07 15:41:02 +00:00
ping_frame[1:2] = static.DXCALLSIGN_CRC8
ping_frame[2:3] = static.MYCALLSIGN_CRC8
2021-05-13 19:02:14 +00:00
ping_frame[3:9] = static.MYGRID
ping_frame[9:11] = frequency_offset.to_bytes(2, byteorder='big', signed=True)
txbuffer = [ping_frame]
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
2021-03-12 13:14:36 +00:00
2022-01-02 08:51:37 +00:00
def received_ping_ack(data_in:bytes):
2021-03-07 15:41:02 +00:00
2021-03-11 19:04:31 +00:00
static.DXCALLSIGN_CRC8 = bytes(data_in[2:3]).rstrip(b'\x00')
2021-05-13 19:02:14 +00:00
static.DXGRID = bytes(data_in[3:9]).rstrip(b'\x00')
2021-09-26 15:51:11 +00:00
helpers.add_to_heard_stations(static.DXCALLSIGN,static.DXGRID, 'PING-ACK', static.SNR, static.FREQ_OFFSET, static.HAMLIB_FREQUENCY)
2021-05-13 19:02:14 +00:00
static.INFO.append("PING;RECEIVEDACK")
structlog.get_logger("structlog").info("[TNC] PING ACK [" + str(static.MYCALLSIGN, 'utf-8') + "] >|< [" + str(static.DXCALLSIGN, 'utf-8') + "]", snr=static.SNR )
2021-02-24 15:47:52 +00:00
static.TNC_STATE = 'IDLE'
2021-03-12 13:14:36 +00:00
# ############################################################################################################
2021-02-24 15:47:52 +00:00
# BROADCAST HANDLER
2021-03-12 13:14:36 +00:00
# ############################################################################################################
2022-01-02 08:51:37 +00:00
def run_beacon(interval:int):
try:
structlog.get_logger("structlog").warning("[TNC] Starting beacon!", interval=interval)
while static.BEACON_STATE and static.ARQ_STATE == 'IDLE':
beacon_frame = bytearray(14)
beacon_frame[:1] = bytes([230])
beacon_frame[1:2] = b'\x01'
beacon_frame[2:8] = static.MYCALLSIGN
beacon_frame[8:14] = static.MYGRID
static.INFO.append("BEACON;SENDING")
structlog.get_logger("structlog").info("[TNC] Sending beacon!", interval=interval)
txbuffer = [beacon_frame]
modem.transmit(mode=14, repeats=1, repeat_delay=0, frames=txbuffer)
time.sleep(interval)
except Exception as e:
print(e)
2022-01-02 08:51:37 +00:00
def received_beacon(data_in:bytes):
# here we add the received station to the heard stations buffer
dxcallsign = bytes(data_in[2:8]).rstrip(b'\x00')
dxgrid = bytes(data_in[8:14]).rstrip(b'\x00')
static.INFO.append("BEACON;RECEIVING")
structlog.get_logger("structlog").info("[TNC] BEACON RCVD [" + str(dxcallsign, 'utf-8') + "]["+ str(dxgrid, 'utf-8') +"] ", snr=static.SNR)
helpers.add_to_heard_stations(dxcallsign,dxgrid, 'BEACON', static.SNR, static.FREQ_OFFSET, static.HAMLIB_FREQUENCY)
def transmit_cq():
2021-02-24 13:22:28 +00:00
logging.info("CQ CQ CQ")
static.INFO.append("CQ;SENDING")
2021-09-26 15:51:11 +00:00
cq_frame = bytearray(14)
cq_frame[:1] = bytes([200])
cq_frame[1:2] = b'\x01'
2021-05-13 16:50:56 +00:00
#cq_frame[2:3] = static.MYCALLSIGN_CRC8
#cq_frame[3:9] = static.MYCALLSIGN
2021-09-26 15:51:11 +00:00
cq_frame[2:8] = static.MYCALLSIGN
2021-05-13 16:50:56 +00:00
cq_frame[8:14] = static.MYGRID
2021-05-09 15:55:15 +00:00
txbuffer = [cq_frame]
modem.transmit(mode=14, repeats=1, repeat_delay=1000, frames=txbuffer)
#while not modem.transmit(14, 1, txbuffer):
# pass
2021-09-26 15:51:11 +00:00
2021-03-12 13:14:36 +00:00
2022-01-02 08:51:37 +00:00
def received_cq(data_in:bytes):
2021-03-12 13:14:36 +00:00
# here we add the received station to the heard stations buffer
2021-05-13 16:50:56 +00:00
dxcallsign = bytes(data_in[2:8]).rstrip(b'\x00')
dxgrid = bytes(data_in[8:14]).rstrip(b'\x00')
static.INFO.append("CQ;RECEIVING")
structlog.get_logger("structlog").info("[TNC] CQ RCVD [" + str(dxcallsign, 'utf-8') + "]["+ str(dxgrid, 'utf-8') +"] ", snr=static.SNR)
helpers.add_to_heard_stations(dxcallsign,dxgrid, 'CQ CQ CQ', static.SNR, static.FREQ_OFFSET, static.HAMLIB_FREQUENCY)
2021-03-16 14:21:58 +00:00
2021-03-12 13:14:36 +00:00
2022-01-02 22:42:56 +00:00
def calculate_transfer_rate_rx(rx_start_of_transmission:float, receivedbytes:int) -> list:
2022-01-02 23:27:05 +00:00
2022-01-02 22:42:56 +00:00
try:
static.ARQ_TRANSMISSION_PERCENT = int((receivedbytes*static.ARQ_COMPRESSION_FACTOR / (static.TOTAL_BYTES * 1024)) * 100)
2022-01-02 22:42:56 +00:00
transmissiontime = time.time() - rx_start_of_transmission
2022-01-02 22:42:56 +00:00
2021-12-29 19:54:54 +00:00
if receivedbytes > 0:
static.ARQ_BITS_PER_SECOND = int((receivedbytes*8) / transmissiontime)
static.ARQ_BYTES_PER_MINUTE = int((receivedbytes) / (transmissiontime/60))
else:
static.ARQ_BITS_PER_SECOND = 0
static.ARQ_BYTES_PER_MINUTE = 0
except:
static.ARQ_TRANSMISSION_PERCENT = 0.0
static.ARQ_BITS_PER_SECOND = 0
static.ARQ_BYTES_PER_MINUTE = 0
2021-09-26 15:51:11 +00:00
return [static.ARQ_BITS_PER_SECOND, \
static.ARQ_BYTES_PER_MINUTE, \
static.ARQ_TRANSMISSION_PERCENT]
2021-09-26 15:51:11 +00:00
2022-01-02 08:51:37 +00:00
def calculate_transfer_rate_tx(tx_start_of_transmission:float, sentbytes:int, tx_buffer_length:int) -> list:
2021-12-29 19:54:54 +00:00
try:
2021-12-29 19:54:54 +00:00
static.ARQ_TRANSMISSION_PERCENT = int((sentbytes / tx_buffer_length) * 100)
2021-09-26 15:51:11 +00:00
transmissiontime = time.time() - tx_start_of_transmission
2021-12-29 19:54:54 +00:00
if sentbytes > 0:
2021-09-26 15:51:11 +00:00
static.ARQ_BITS_PER_SECOND = int((sentbytes*8) / transmissiontime) # Bits per Second
static.ARQ_BYTES_PER_MINUTE = int((sentbytes) / (transmissiontime/60)) #Bytes per Minute
2021-09-26 15:51:11 +00:00
else:
static.ARQ_BITS_PER_SECOND = 0
static.ARQ_BYTES_PER_MINUTE = 0
except:
2021-09-26 15:51:11 +00:00
static.ARQ_TRANSMISSION_PERCENT = 0.0
static.ARQ_BITS_PER_SECOND = 0
static.ARQ_BYTES_PER_MINUTE = 0
return [static.ARQ_BITS_PER_SECOND, \
static.ARQ_BYTES_PER_MINUTE, \
static.ARQ_TRANSMISSION_PERCENT]
2021-09-26 15:51:11 +00:00
# WATCHDOG FUNCTIONS
def watchdog():
"""
Author: DJ2LS
watchdog master function. Frome here we call the watchdogs
"""
while True:
time.sleep(0.5)
2021-09-26 15:51:11 +00:00
data_channel_keep_alive_watchdog()
def data_channel_keep_alive_watchdog():
"""
Author: DJ2LS
"""
global DATA_CHANNEL_LAST_RECEIVED
2021-09-26 15:51:11 +00:00
# and not static.ARQ_SEND_KEEP_ALIVE:
if static.ARQ_STATE and static.TNC_STATE == 'BUSY':
2021-09-26 15:51:11 +00:00
time.sleep(0.01)
if DATA_CHANNEL_LAST_RECEIVED + 30 > time.time():
time.sleep(0.01)
#pass
else:
DATA_CHANNEL_LAST_RECEIVED = 0
2021-12-29 19:54:54 +00:00
logging.info("DATA [" + str(static.MYCALLSIGN, 'utf-8') + "]<<T>>[" + str(static.DXCALLSIGN, 'utf-8') + "]")
arq_cleanup()
2022-01-02 09:35:30 +00:00
def arq_cleanup():
global DATA_CHANNEL_LAST_RECEIVED
global BURST_ACK_RECEIVED
global RPT_REQUEST_RECEIVED
global DATA_FRAME_ACK_RECEIVED
global RX_FRAME_BOF_RECEIVED
global RX_FRAME_EOF_RECEIVED
2022-01-04 12:09:15 +00:00
global BURST_ACK_SNR
2022-01-04 15:34:20 +00:00
structlog.get_logger("structlog").debug("cleanup")
RX_FRAME_BOF_RECEIVED = False
RX_FRAME_EOF_RECEIVED = False
static.TNC_STATE = 'IDLE'
static.ARQ_STATE = False
BURST_ACK_RECEIVED = False
RPT_REQUEST_RECEIVED = False
DATA_FRAME_ACK_RECEIVED = False
static.RX_BURST_BUFFER = []
static.RX_FRAME_BUFFER = b''
2022-01-04 12:09:15 +00:00
BURST_ACK_SNR = 255
2021-09-26 15:51:11 +00:00
def arq_reset_ack(state:bool):
"""
Author: DJ2LS
"""
global BURST_ACK_RECEIVED
global RPT_REQUEST_RECEIVED
global DATA_FRAME_ACK_RECEIVED
BURST_ACK_RECEIVED = state
RPT_REQUEST_RECEIVED = state
DATA_FRAME_ACK_RECEIVED = state
2021-09-26 15:51:11 +00:00
# START THE THREAD FOR THE TIMEOUT WATCHDOG
WATCHDOG_SERVER_THREAD = threading.Thread(target=watchdog, name="watchdog")
WATCHDOG_SERVER_THREAD.start()