amateurfunk/hamnet70
1
0
Fork 0
Code Issues Pull requests Actions Packages Projects Releases Wiki Activity

rx: tag most debug messages with the sample index

Browse source
This commit is contained in:
Thomas Kolb 2024-05-25 18:24:40 +02:00
parent 5f8346d290
commit 33df7132ef
1 changed files with 22 additions and 17 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

39
impl/src/layer1/rx.c
View file

@ -84,15 +84,16 @@ static bool acquire_preamble(layer1_rx_t *rx, const float complex sample, bool d
if(abs_corr_out > 0.5f * preamble_get_symbol_count()) { if(abs_corr_out > 0.5f * preamble_get_symbol_count()) {
// Preamble found! // Preamble found!
DEBUG_LOG("Preamble found: %.3f > %.3f\n", abs_corr_out, 0.5f * preamble_get_symbol_count()); DEBUG_LOG("@%zu: Preamble found: %.3f > %.3f\n", rx->sample_index,
abs_corr_out, 0.5f * preamble_get_symbol_count());
rx->packet_debug_info.preamble_correlation_peak = abs_corr_out; rx->packet_debug_info.preamble_correlation_peak = abs_corr_out;
float phase_offset; float phase_offset;
float mean_frequency_error = correlator_get_mean_frequency_deviation(&rx->preamble_correlator, FREQ_EST_L, &phase_offset); float mean_frequency_error = correlator_get_mean_frequency_deviation(&rx->preamble_correlator, FREQ_EST_L, &phase_offset);
DEBUG_LOG("Phase offset: %.6f rad\n", phase_offset); DEBUG_LOG("@%zu: Phase offset: %.6f rad\n", rx->sample_index, phase_offset);
DEBUG_LOG("Preamble frequency deviation: %.6f rad/symbol\n", mean_frequency_error); DEBUG_LOG("@%zu: Preamble frequency deviation: %.6f rad/symbol\n", rx->sample_index, mean_frequency_error);
// Set the fine carrier correction NCO to the values estimated from the preamble // Set the fine carrier correction NCO to the values estimated from the preamble
nco_crcf_set_frequency(rx->carrier_fine_nco, mean_frequency_error); nco_crcf_set_frequency(rx->carrier_fine_nco, mean_frequency_error);
@ -100,7 +101,8 @@ static bool acquire_preamble(layer1_rx_t *rx, const float complex sample, bool d
float fcoarse = nco_crcf_get_frequency(rx->carrier_coarse_nco); float fcoarse = nco_crcf_get_frequency(rx->carrier_coarse_nco);
float ffine = nco_crcf_get_frequency(rx->carrier_fine_nco); float ffine = nco_crcf_get_frequency(rx->carrier_fine_nco);
DEBUG_LOG("New estimated carrier frequency: %.6f + %.6f/4 = %.6f rad/sample\n", fcoarse, ffine, fcoarse+ffine/4); DEBUG_LOG("@%zu: New estimated carrier frequency: %.6f + %.6f/4 = %.6f rad/sample\n",
rx->sample_index, fcoarse, ffine, fcoarse+ffine/4);
// store debug info // store debug info
rx->packet_debug_info.carrier_tracked_freq = fcoarse * 4 * SYMBOL_RATE / (2.0f * (float)M_PI); rx->packet_debug_info.carrier_tracked_freq = fcoarse * 4 * SYMBOL_RATE / (2.0f * (float)M_PI);
@ -119,7 +121,8 @@ static bool acquire_preamble(layer1_rx_t *rx, const float complex sample, bool d
return true; // preamble found! return true; // preamble found!
} else if(do_coarse_freq_est) { } else if(do_coarse_freq_est) {
// preamble not found. // preamble not found.
//DEBUG_LOG("Preamble not found: %.3f < %.3f\n", cabsf(corr_out), 0.5f * preamble_get_symbol_count()); //DEBUG_LOG("@%zu: Preamble not found: %.3f < %.3f\n",
// rx->sample_index, cabsf(corr_out), 0.5f * preamble_get_symbol_count());
// Run the frequency estimator for every incoming sample overy the last // Run the frequency estimator for every incoming sample overy the last
// FREQ_EST_L samples. This is an implementation that works with unknown // FREQ_EST_L samples. This is an implementation that works with unknown
@ -153,8 +156,9 @@ static bool acquire_preamble(layer1_rx_t *rx, const float complex sample, bool d
//freq_est_history_write_idx = 0; //freq_est_history_write_idx = 0;
DEBUG_LOG("Freq. est (x%d): %0.6f - Adj (x1): %.6f - carrier frequency (x1): %.6f\n", DEBUG_LOG("@%zu: Freq. est (x%d): %0.6f - Adj (x1): %.6f - carrier frequency (x1): %.6f\n",
RRC_SPS, freq_est, freq_adjustment, nco_crcf_get_frequency(rx->carrier_coarse_nco)); rx->sample_index, RRC_SPS, freq_est, freq_adjustment,
nco_crcf_get_frequency(rx->carrier_coarse_nco));
freq_est_holdoff_samples = preamble_get_symbol_count() * 2; freq_est_holdoff_samples = preamble_get_symbol_count() * 2;
} }
@ -257,7 +261,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
float complex filtered_samples[sample_count]; float complex filtered_samples[sample_count];
firfilt_crcf_execute_block(rx->channel_filter, (float complex *)samples, sample_count, filtered_samples); firfilt_crcf_execute_block(rx->channel_filter, (float complex *)samples, sample_count, filtered_samples);
DEBUG_LOG("\nagc: %f\n", agc_crcf_get_gain(rx->agc)); //DEBUG_LOG("@%zu: agc: %f\n", rx->sample_index, agc_crcf_get_gain(rx->agc));
for(unsigned int i = 0; i < sample_count; i++) { for(unsigned int i = 0; i < sample_count; i++) {
rx->sample_index++; rx->sample_index++;
@ -340,7 +344,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
modem_demodulate(rx->hdr_demod, mixed_sample, &sym_demod); modem_demodulate(rx->hdr_demod, mixed_sample, &sym_demod);
float phase_error = modem_get_demodulator_phase_error(rx->hdr_demod); float phase_error = modem_get_demodulator_phase_error(rx->hdr_demod);
DEBUG_LOG("Sym: %d; Phase error: %f %s\n", sym_demod, phase_error, DEBUG_LOG("@%zu: Sym: %d; Phase error: %f %s\n", rx->sample_index, sym_demod, phase_error,
(fabs(phase_error) > 0.3) ? "!!!" : ""); (fabs(phase_error) > 0.3) ? "!!!" : "");
@ -365,7 +369,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
header_enc, 8, sizeof(header_enc), &nsyms)); header_enc, 8, sizeof(header_enc), &nsyms));
if(fec_decode(rx->hdr_fec, sizeof(header), header_enc, header) != LIQUID_OK) { if(fec_decode(rx->hdr_fec, sizeof(header), header_enc, header) != LIQUID_OK) {
DEBUG_LOG("Header decoding failed!\n"); DEBUG_LOG("@%zu: Header decoding failed!\n", rx->sample_index);
rx->state = RX_STATE_ACQUISITION; rx->state = RX_STATE_ACQUISITION;
rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0); rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0);
break; break;
@ -374,8 +378,8 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
// CRC check // CRC check
if(crc_check_key(LIQUID_CRC_8, header, HEADER_SIZE_BYTES) != LIQUID_OK) { if(crc_check_key(LIQUID_CRC_8, header, HEADER_SIZE_BYTES) != LIQUID_OK) {
uint8_t expected_crc = crc_generate_key(LIQUID_CRC_8, header, 4); uint8_t expected_crc = crc_generate_key(LIQUID_CRC_8, header, 4);
DEBUG_LOG("Header CRC check failed! Expected: 0x%02x, received: 0x%02x\n", DEBUG_LOG("@%zu: Header CRC check failed! Expected: 0x%02x, received: 0x%02x\n",
expected_crc, header[4]); rx->sample_index, expected_crc, header[4]);
rx->state = RX_STATE_ACQUISITION; rx->state = RX_STATE_ACQUISITION;
rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0); rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0);
break; break;
@ -387,7 +391,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
// check the received information // check the received information
if(!MODCOD_IS_VALID(rx->modcod)) { if(!MODCOD_IS_VALID(rx->modcod)) {
DEBUG_LOG("Decoded MODCOD %d is invalid!\n", rx->modcod); DEBUG_LOG("@%zu: Decoded MODCOD %d is invalid!\n", rx->sample_index, rx->modcod);
rx->state = RX_STATE_ACQUISITION; rx->state = RX_STATE_ACQUISITION;
rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0); rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0);
break; break;
@ -395,7 +399,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
// check the payload length // check the payload length
if(rx->payload_len_bytes == 0) { if(rx->payload_len_bytes == 0) {
DEBUG_LOG("Packet length %u is not supported.\n", rx->payload_len_bytes); DEBUG_LOG("@%zu: Packet length %u is not supported.\n", rx->sample_index, rx->payload_len_bytes);
rx->state = RX_STATE_ACQUISITION; rx->state = RX_STATE_ACQUISITION;
rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0); rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0);
break; break;
@ -408,7 +412,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
rx->payload_len_symbols = (rx->payload_len_enc_bytes * 8 + payload_bps - 1) / payload_bps; rx->payload_len_symbols = (rx->payload_len_enc_bytes * 8 + payload_bps - 1) / payload_bps;
if(rx->payload_len_symbols > SYMBOL_BUFFER_SIZE) { if(rx->payload_len_symbols > SYMBOL_BUFFER_SIZE) {
DEBUG_LOG("Symbol count %u is too lange for buffer. Ignoring packet.\n", rx->payload_len_symbols); DEBUG_LOG("@%zu: Symbol count %u is too lange for buffer. Ignoring packet.\n", rx->sample_index, rx->payload_len_symbols);
rx->state = RX_STATE_ACQUISITION; rx->state = RX_STATE_ACQUISITION;
rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0); rx->callback(RX_EVT_HEADER_ERROR, rx, NULL, 0);
break; break;
@ -416,7 +420,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
assert(rx->payload_len_symbols < sizeof(symbols_int)/sizeof(symbols_int[0])); assert(rx->payload_len_symbols < sizeof(symbols_int)/sizeof(symbols_int[0]));
DEBUG_LOG("=== DECODED HEADER ===\n"); DEBUG_LOG("=== DECODED HEADER @%zu ===\n", rx->sample_index);
DEBUG_LOG("Payload length: %u symbols, %u bytes encoded, %u bytes decoded\n", rx->payload_len_symbols, rx->payload_len_enc_bytes, rx->payload_len_bytes); DEBUG_LOG("Payload length: %u symbols, %u bytes encoded, %u bytes decoded\n", rx->payload_len_symbols, rx->payload_len_enc_bytes, rx->payload_len_bytes);
DEBUG_LOG("CRC16: 0x%04x\n", rx->payload_crc); DEBUG_LOG("CRC16: 0x%04x\n", rx->payload_crc);
DEBUG_LOG("======================\n"); DEBUG_LOG("======================\n");
@ -440,7 +444,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
modem_demodulate(rx->payload_demod, mixed_sample, &sym_demod); modem_demodulate(rx->payload_demod, mixed_sample, &sym_demod);
float phase_error = modem_get_demodulator_phase_error(rx->payload_demod); float phase_error = modem_get_demodulator_phase_error(rx->payload_demod);
//DEBUG_LOG("Sym: %d; Phase error: %f\n", sym_demod, phase_error); //DEBUG_LOG("@%zu: Sym: %d; Phase error: %f\n", rx->sample_index, sym_demod, phase_error);
update_nco_pll(rx->carrier_fine_nco, phase_error, PLL_BW_DATA); update_nco_pll(rx->carrier_fine_nco, phase_error, PLL_BW_DATA);
@ -487,6 +491,7 @@ result_t layer1_rx_process(layer1_rx_t *rx, const float complex *samples, size_t
} }
if(rx->state != last_state) { if(rx->state != last_state) {
DEBUG_LOG("@%zu: RX state changed: %d -> %d\n", rx->sample_index, last_state, rx->state);
if(rx->state == RX_STATE_ACQUISITION) { if(rx->state == RX_STATE_ACQUISITION) {
// ensure the AGC is in acquisition mode again when // ensure the AGC is in acquisition mode again when
// RX_STATE_ACQUISITION is entered. // RX_STATE_ACQUISITION is entered.