improved single frame transmission

solved timing issues
This commit is contained in:
DJ2LS 2021-02-15 16:33:43 +01:00 committed by GitHub
parent 81cbb427e7
commit 129e0c0645
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
4 changed files with 126 additions and 99 deletions

72
arq.py
View file

@ -14,8 +14,8 @@ from random import randrange
import static
import modem
import helpers
#import main
#import tnc
@ -57,7 +57,7 @@ def data_received(data_in):
arq_percent_burst = int((static.ARQ_N_FRAME / static.ARQ_N_RX_FRAMES_PER_BURSTS)*100)
arq_percent_frame = int(((static.ARQ_RX_N_CURRENT_ARQ_FRAME)/static.ARQ_N_ARQ_FRAMES_PER_DATA_FRAME)*100)
logging.info("ARQ | RX | ARQ FRAME [" + str(static.ARQ_N_FRAME) + "/" + str(static.ARQ_N_RX_FRAMES_PER_BURSTS) + "] [" + str(arq_percent_burst).zfill(3) + "%] --- TOTAL [" + str(static.ARQ_RX_N_CURRENT_ARQ_FRAME) + "/" + str(static.ARQ_N_ARQ_FRAMES_PER_DATA_FRAME) + "] [" + str(arq_percent_frame).zfill(3) + "%]" )
logging.log(24, "ARQ | RX | ARQ FRAME [" + str(static.ARQ_N_FRAME) + "/" + str(static.ARQ_N_RX_FRAMES_PER_BURSTS) + "] [" + str(arq_percent_burst).zfill(3) + "%] --- TOTAL [" + str(static.ARQ_RX_N_CURRENT_ARQ_FRAME) + "/" + str(static.ARQ_N_ARQ_FRAMES_PER_DATA_FRAME) + "] [" + str(arq_percent_frame).zfill(3) + "%]" )
@ -121,7 +121,13 @@ def data_received(data_in):
for burstnumber in range(1,len(static.ARQ_RX_BURST_BUFFER)):
if static.ARQ_RX_BURST_BUFFER[burstnumber] == None:
frame_number = burstnumber.to_bytes(2, byteorder='big')
#frame_number = static.ARQ_RX_N_CURRENT_ARQ_FRAME - static.ARQ_N_RX_FRAMES_PER_BURSTS + burstnumber
#logging.debug("frame_number" + str(frame_number))
logging.debug("static.ARQ_RX_N_CURRENT_ARQ_FRAME" + str(static.ARQ_RX_N_CURRENT_ARQ_FRAME))
logging.debug("ARQ_N_RX_FRAMES_PER_BURSTS" + str(static.ARQ_N_RX_FRAMES_PER_BURSTS))
frame_number = burstnumber
frame_number = frame_number.to_bytes(2, byteorder='big')
missing_frames += frame_number
logging.warning("ARQ | TX | RPT ARQ FRAMES [" + str(missing_frames) + "]")
@ -173,7 +179,8 @@ def data_received(data_in):
#IF THE FRAME PAYLOAD CRC IS EQUAL TO THE FRAME CRC WHICH IS KNOWN FROM THE HEADER --> SUCCESS
if frame_payload_crc == static.FRAME_CRC:
logging.info("ARQ | RX | DATA FRAME SUCESSFULLY RECEIVED! - TIME TO PARTY")
#logging.info("ARQ | RX | DATA FRAME SUCESSFULLY RECEIVED! - TIME TO PARTY")
logging.log(25,"ARQ | RX | DATA FRAME SUCESSFULLY RECEIVED! - TIME TO PARTY")
#append received frame to RX_BUFFER
static.RX_BUFFER.append(complete_data_frame)
@ -196,6 +203,7 @@ def data_received(data_in):
#print("----------------------------------------------------------------")
#print(static.RX_BUFFER[-1])
#tnc.request.sendall(bytes(static.RX_BUFFER[-1]))
#print("----------------------------------------------------------------")
else:
@ -251,11 +259,8 @@ def transmit(data_out):
#--------------------------------------------- N ATTEMPTS TO SEND BURSTS IF ACK RECEPTION FAILS
for static.TX_N_RETRIES in range(static.TX_N_MAX_RETRIES):
if static.ARQ_N_SENT_FRAMES + 1 <= static.TX_BUFFER_SIZE:
logging.info("ARQ | TX | F:[" + str(static.ARQ_N_SENT_FRAMES+1) + "-" + str(static.ARQ_N_SENT_FRAMES + static.ARQ_TX_N_FRAMES_PER_BURST) + "] | T:[" + str(static.ARQ_N_SENT_FRAMES) + "/" + str(static.TX_BUFFER_SIZE) + "] [" + str(int(static.ARQ_N_SENT_FRAMES/(static.TX_BUFFER_SIZE)*100)).zfill(3) + "%] | A:[" + str(static.TX_N_RETRIES+1) + "/" + str(static.TX_N_MAX_RETRIES) + "]")
logging.log(24, "ARQ | TX | F:[" + str(static.ARQ_N_SENT_FRAMES+1) + "-" + str(static.ARQ_N_SENT_FRAMES + static.ARQ_TX_N_FRAMES_PER_BURST) + "] | T:[" + str(static.ARQ_N_SENT_FRAMES) + "/" + str(static.TX_BUFFER_SIZE) + "] [" + str(int(static.ARQ_N_SENT_FRAMES/(static.TX_BUFFER_SIZE)*100)).zfill(3) + "%] | A:[" + str(static.TX_N_RETRIES+1) + "/" + str(static.TX_N_MAX_RETRIES) + "]")
# lets start a thread to transmit nonblocking
@ -265,15 +270,8 @@ def transmit(data_out):
# lets wait during sending. After sending is finished we will continue
while static.ARQ_STATE == 'SENDING_DATA':
time.sleep(0.01)
#print("sending.....")
# --------------------------- START TIMER FOR WAITING FOR ACK ---> IF TIMEOUT REACHED, ACK_TIMEOUT = 1
#reset timer and ack state
#static.ARQ_FRAME_ACK_RECEIVED = False
#static.ARQ_ACK_RECEIVED = False
#static.ARQ_RX_ACK_TIMEOUT = False
logging.debug("ARQ | RX | WAITING FOR BURST ACK")
static.ARQ_STATE = 'RECEIVING_SIGNALLING'
@ -300,7 +298,7 @@ def transmit(data_out):
if static.ARQ_RPT_RECEIVED == True:
logging.warning("ARQ | RX | REQUEST FOR REPEATING FRAMES: " + str(static.ARQ_RPT_FRAMES))
logging.info("ARQ | TX | SENDING REQUESTED FRAMES: " + str(static.ARQ_RPT_FRAMES))
logging.warning("ARQ | TX | SENDING REQUESTED FRAMES: " + str(static.ARQ_RPT_FRAMES))
TRANSMIT_ARQ_BURST_THREAD = threading.Thread(target=modem.transmit_arq_burst, name="TRANSMIT_ARQ_BURST")
TRANSMIT_ARQ_BURST_THREAD.start()
@ -325,7 +323,7 @@ def transmit(data_out):
if static.ARQ_ACK_RECEIVED == True:
logging.info("ARQ | RX | ACK AFTER RPT")
rpttimer.cancel()
helpers.arq_reset_ack(True)
static.ARQ_RPT_FRAMES = []
@ -339,12 +337,13 @@ def transmit(data_out):
#--------------------------------------------------------------------------------------------------------------
elif static.ARQ_ACK_RECEIVED == 0 and static.ARQ_RX_ACK_TIMEOUT == 1:
logging.warning("ARQ | RX | ACK TIMEOUT - AND NO ACK!")
logging.warning("ARQ | RX | ACK TIMEOUT!")
pass #no break here so we can continue with the next try of repeating the burst
#--------------- BREAK LOOP IF ACK HAS BEEN RECEIVED
elif static.ARQ_ACK_RECEIVED == True:
logging.info("ARQ | RX | ACK")
acktimer.cancel()
#-----------IF ACK RECEIVED, INCREMENT ITERATOR FOR MAIN LOOP TO PROCEED WITH NEXT FRAMES/BURST
static.ARQ_N_SENT_FRAMES = static.ARQ_N_SENT_FRAMES + static.ARQ_TX_N_FRAMES_PER_BURST
break
@ -352,7 +351,8 @@ def transmit(data_out):
#--------------- BREAK LOOP IF FRAME ACK HAS BEEN RECEIVED EARLIER AS EXPECTED
elif static.ARQ_FRAME_ACK_RECEIVED == True:
logging.info("----------------------------------------------------------")
logging.info("ARQ | RX | EARLY FRAME ACK RECEIVED - STOPPING TX")
logging.info("ARQ | RX | EARLY FRAME ACK RECEIVED")
#static.ARQ_N_SENT_FRAMES = #static.TX_BUFFER_SIZE
static.ARQ_N_SENT_FRAMES = static.ARQ_N_SENT_FRAMES + static.ARQ_TX_N_FRAMES_PER_BURST
break
@ -375,7 +375,7 @@ def transmit(data_out):
logging.debug("static.ARQ_ACK_RECEIVED " + str(static.ARQ_ACK_RECEIVED))
logging.debug("static.ARQ_RX_ACK_TIMEOUT " + str(static.ARQ_RX_ACK_TIMEOUT))
logging.debug("static.ARQ_RPT_RECEIVED " + str(static.ARQ_RPT_RECEIVED))
logging.debug("static.ARQ_TX_N_FRAMES_PER_BURST " + str(static.ARQ_TX_N_FRAMES_PER_BURST))
frametimer = threading.Timer(static.ARQ_RX_FRAME_TIMEOUT_SECONDS, helpers.arq_frame_timeout)
frametimer.start()
@ -388,7 +388,6 @@ def transmit(data_out):
logging.debug("WAITING FOR FRAME ACK")
# ----------- if no ACK received and out of retries.....stop frame sending
if static.ARQ_ACK_RECEIVED == False and static.ARQ_FRAME_ACK_RECEIVED == False and static.ARQ_RX_ACK_TIMEOUT == True:
logging.error("ARQ | TX | NO BURST OR FRAME ACK RECEIVED | DATA SHOULD BE RESEND!")
@ -396,12 +395,22 @@ def transmit(data_out):
#-------------------------BREAK TX BUFFER LOOP IF ALL PACKETS HAVE BEEN SENT AND WE GOT A FRAME ACK
elif static.ARQ_N_SENT_FRAMES == static.TX_BUFFER_SIZE and static.ARQ_FRAME_ACK_RECEIVED == True:
logging.info("ARQ | RX | FRAME ACK RECEIVED - DATA TRANSMITTED! :-)")
logging.log(25,"ARQ | RX | FRAME ACK RECEIVED - DATA TRANSMITTED! :-)")
break
else:
logging.debug("NO MATCHING RULE AT THE END")
# stop all timers
try:
frametimer.cancel()
except Exception:
pass
try:
acktimer.cancel()
except Exception:
pass
# IF TX BUFFER IS EMPTY / ALL FRAMES HAVE BEEN SENT --> HERE WE COULD ADD AN static.VAR for IDLE STATE
@ -416,41 +425,26 @@ def transmit(data_out):
# BURST MACHINE TO DEFINE N BURSTS PER FRAME ---> LATER WE CAN USE CHANNEL MESSUREMENT TO SET FRAMES PER BURST
def get_n_frames_per_burst():
n_frames_per_burst = randrange(1,10)
#n_frames_per_burst = 4
#n_frames_per_burst = randrange(1,10)
n_frames_per_burst = 2
return n_frames_per_burst
def burst_ack_received():
#logging.info("ARQ | RX | BURST ACK RCVD!")
#static.ARQ_RX_ACK_TIMEOUT = True #Force timer to stop waiting
static.ARQ_ACK_RECEIVED = True #Force data loops of TNC to stop and continue with next frame
#static.ARQ_RX_RPT_TIMEOUT = True #Force timer to stop waiting
#static.ARQ_RPT_RECEIVED = False
#static.ARQ_RPT_FRAMES = []
def frame_ack_received():
#logging.info("ARQ | RX | FRAME ACK RCVD!")
#static.ARQ_RX_ACK_TIMEOUT = True #Force timer to stop waiting
static.ARQ_FRAME_ACK_RECEIVED = True #Force data loops of TNC to stop and continue with next frame
#static.ARQ_RX_RPT_TIMEOUT = True #Force timer to stop waiting
#static.ARQ_RPT_RECEIVED = False
#static.ARQ_RPT_FRAMES = []
def burst_rpt_received(data_in):
#logging.info("ARQ | RX | BURST RPT RCVD!")
#static.ARQ_RX_ACK_TIMEOUT = False #Force timer to stop waiting
#static.ARQ_ACK_RECEIVED = False #Force data loops of TNC to stop and continue with next frame
#static.ARQ_RX_RPT_TIMEOUT = True
static.ARQ_RPT_RECEIVED = True
static.ARQ_RPT_FRAMES = []

View file

@ -12,12 +12,12 @@ import logging
from colorlog import ColoredFormatter
import crcengine
import static
def get_crc_8(data):
crc_algorithm = crcengine.new('crc8-ccitt') #load crc8 library
crc_data = crc_algorithm(data)
@ -30,14 +30,11 @@ def get_crc_16(data):
crc_data = crc_data.to_bytes(2, byteorder='big')
return crc_data
def arq_ack_timeout():
if static.ARQ_STATE == 'RECEIVING_SIGNALLING':
static.ARQ_RX_ACK_TIMEOUT = True
logging.debug("ARQ_RX_ACK_TIMEOUT")
def arq_rpt_timeout():
if static.ARQ_STATE == 'RECEIVING_SIGNALLING':
static.ARQ_RX_RPT_TIMEOUT = True
@ -48,15 +45,12 @@ def arq_frame_timeout():
static.ARQ_RX_FRAME_TIMEOUT = True
logging.debug("ARQ_RX_FRAME_TIMEOUT")
def arq_reset_timeout(state):
static.ARQ_RX_ACK_TIMEOUT = state
static.ARQ_RX_FRAME_TIMEOUT = state
static.ARQ_RX_RPT_TIMEOUT = state
def arq_reset_ack(state):
static.ARQ_ACK_RECEIVED = state
static.ARQ_RPT_RECEIVED = state
static.ARQ_FRAME_ACK_RECEIVED = state
@ -69,5 +63,3 @@ def arq_reset_frame_machine():
static.ARQ_TX_N_FRAMES_PER_BURST = 0

74
main.py
View file

@ -10,7 +10,8 @@ Created on Tue Dec 22 16:58:45 2020
import socketserver
import argparse
import logging
import threading
import pyaudio
#import tnc
import static
@ -21,11 +22,47 @@ import helpers
def start_cmd_socket():
try:
logging.info("SRV | STARTING TCP/IP CMD ON PORT: " + str(static.PORT))
socketserver.TCPServer.allow_reuse_address = True #https://stackoverflow.com/a/16641793
cmdserver = socketserver.TCPServer((static.HOST, static.PORT), tnc.CMDTCPRequestHandler)
cmdserver.serve_forever()
finally:
cmdserver.server_close()
def start_data_socket():
try:
logging.info("SRV | STARTING TCP/IP DATA ON PORT: " + str(static.PORT + 1))
socketserver.TCPServer.allow_reuse_address = True #https://stackoverflow.com/a/16641793
dataserver = socketserver.TCPServer((static.HOST, static.PORT + 1), tnc.DATATCPRequestHandler)
dataserver.serve_forever()
finally:
dataserver.server_close()
p = pyaudio.PyAudio()
devices = []
for x in range(0, p.get_device_count()):
devices.append(f"{x} - {p.get_device_info_by_index(x)['name']}")
for line in devices:
print(line)
if __name__ == '__main__':
static.MYCALLSIGN = b'DJ2LS'
static.MYCALLSIGN_CRC8 = helpers.get_crc_8(static.MYCALLSIGN)
@ -61,14 +98,16 @@ if __name__ == '__main__':
#-------------------------------------------- DEFINE LOGGING
logging.basicConfig(format='%(asctime)s.%(msecs)03d %(levelname)s:\t%(message)s', datefmt='%H:%M:%S', level=logging.INFO)
#logging.addLevelName(logging.INFO, "\033[1;37m%s\033[1;0m" % 'SUCCESS')
logging.addLevelName( logging.DEBUG, "\033[1;37m%s\033[1;0m" % logging.getLevelName(logging.DEBUG))
logging.addLevelName( logging.INFO, "\033[1;32m%s\033[1;0m" % logging.getLevelName(logging.INFO))
logging.addLevelName( logging.DEBUG, "\033[1;36m%s\033[1;0m" % logging.getLevelName(logging.DEBUG))
logging.addLevelName( logging.INFO, "\033[1;37m%s\033[1;0m" % logging.getLevelName(logging.INFO))
logging.addLevelName( logging.WARNING, "\033[1;33m%s\033[1;0m" % logging.getLevelName(logging.WARNING))
logging.addLevelName( logging.ERROR, "\033[1;31m%s\033[1;0m" % logging.getLevelName(logging.ERROR))
logging.addLevelName( logging.ERROR, "\033[1;31m%s\033[1;0m" % "FAILED")
#logging.addLevelName( logging.ERROR, "\033[1;31m%s\033[1;0m" % logging.getLevelName(logging.ERROR))
logging.addLevelName( logging.CRITICAL, "\033[1;41m%s\033[1;0m" % logging.getLevelName(logging.CRITICAL))
logging.addLevelName( 25, "\033[1;32m%s\033[1;0m" % "SUCCESS")
logging.addLevelName( 24, "\033[1;34m%s\033[1;0m" % "DATA")
# https://stackoverflow.com/questions/384076/how-can-i-color-python-logging-output
#'DEBUG' : 37, # white
@ -78,13 +117,14 @@ if __name__ == '__main__':
#'CRITICAL': 41, # white on red bg
#--------------------------------------------START CMD SERVER
logging.info("SRV | STARTING TCP/IP SOCKET ON PORT " + str(static.PORT))
try:
socketserver.TCPServer.allow_reuse_address = True #https://stackoverflow.com/a/16641793
server = socketserver.TCPServer((static.HOST, static.PORT), tnc.TCPRequestHandler)
server.serve_forever()
finally:
server.server_close()
#--------------------------------------------START CMD & DATA SERVER
cmd_server_thread = threading.Thread(target=start_cmd_socket, name="cmd server")
cmd_server_thread.start()
data_server_thread = threading.Thread(target=start_data_socket, name="data server")
data_server_thread.start()

View file

@ -19,6 +19,8 @@ import helpers
import static
import arq
import audioop
@ -94,15 +96,13 @@ class RF():
logging.debug("SEND SIGNALLING FRAME " + str(ack_buffer))
self.stream_tx.write(bytes(txbuffer))
self.stream_tx.write(bytes(txbuffer))
static.ARQ_STATE = 'RECEIVING_DATA'
#--------------------------------------------------------------------------------------------------------
# GET ARQ BURST FRAME VOM BUFFER AND MODULATE IT
def transmit_arq_burst(self):
static.ARQ_STATE = 'SENDING_DATA'
self.c_lib.freedv_open.restype = ctypes.POINTER(ctypes.c_ubyte)
@ -186,6 +186,8 @@ class RF():
static.MYCALLSIGN_CRC8 + \
payload_data
#print(arqframe)
buffer = bytearray(static.FREEDV_DATA_PAYLOAD_PER_FRAME) # create TX buffer
buffer[:len(arqframe)] = arqframe # set buffersize to length of data which will be send
@ -238,18 +240,18 @@ class RF():
time.sleep(0.01)
nin = self.c_lib.freedv_nin(freedv_data)
nin = int(nin*(static.AUDIO_SAMPLE_RATE_RX/static.MODEM_SAMPLE_RATE))
#nin = int(nin*(static.AUDIO_SAMPLE_RATE_RX/static.MODEM_SAMPLE_RATE))
data_in = self.stream_rx.read(nin, exception_on_overflow = False)
#print(audioop.rms(data_in, 2))
data_in = data_in.rstrip(b'\x00')
#print(data_in)
self.c_lib.freedv_rawdatarx.argtype = [ctypes.POINTER(ctypes.c_ubyte), data_bytes_out, data_in] # check if really neccessary
#self.c_lib.freedv_rawdatarx.argtype = [ctypes.POINTER(ctypes.c_ubyte), data_bytes_out, data_in] # check if really neccessary
nbytes = self.c_lib.freedv_rawdatarx(freedv_data, data_bytes_out, data_in) # demodulate audio
logging.debug(self.c_lib.freedv_get_rx_status(freedv_data))
#-------------STUCK IN SYNC DETECTOR
stuck_in_sync_counter += 1
if self.c_lib.freedv_get_rx_status(freedv_data) == 10:
@ -313,12 +315,12 @@ class RF():
time.sleep(0.01)
nin = self.c_lib.freedv_nin(freedv_signalling)
nin = int(nin*(static.AUDIO_SAMPLE_RATE_RX/static.MODEM_SAMPLE_RATE))
#nin = int(nin*(static.AUDIO_SAMPLE_RATE_RX/static.MODEM_SAMPLE_RATE))
data_in = self.stream_rx.read(nin, exception_on_overflow = False)
data_in = data_in.rstrip(b'\x00')
self.c_lib.freedv_rawdatarx.argtype = [ctypes.POINTER(ctypes.c_ubyte), signalling_bytes_out, data_in] # check if really neccessary
#self.c_lib.freedv_rawdatarx.argtype = [ctypes.POINTER(ctypes.c_ubyte), signalling_bytes_out, data_in] # check if really neccessary
nbytes = self.c_lib.freedv_rawdatarx(freedv_signalling, signalling_bytes_out, data_in) # demodulate audio
# CHECK IF FRAME CONTAINS ACK------------------------
@ -348,7 +350,6 @@ class RF():
rxstatus = self.c_lib.freedv_get_rx_status(freedv_signalling)
logging.debug("ACK-" + str(rxstatus))
#print(rxstatus)
if nbytes == static.FREEDV_SIGNALLING_BYTES_PER_FRAME or rxstatus == 10:
self.c_lib.freedv_set_sync(freedv_signalling, 0) #FORCE UNSYNC