mirror of
https://github.com/manuelbl/ttn-esp32.git
synced 2025-10-31 10:40:35 +01:00
314 lines
9.2 KiB
C
314 lines
9.2 KiB
C
/*******************************************************************************
|
|
*
|
|
* ttn-esp32 - The Things Network device library for ESP-IDF / SX127x
|
|
*
|
|
* Copyright (c) 2018-2021 Manuel Bleichenbacher
|
|
*
|
|
* Licensed under MIT License
|
|
* https://opensource.org/licenses/MIT
|
|
*
|
|
* Circular buffer for detailed logging without affecting LMIC timing.
|
|
*******************************************************************************/
|
|
|
|
#if LMIC_ENABLE_event_logging
|
|
|
|
#include "ttn_logging.h"
|
|
#include "esp_log.h"
|
|
#include "freertos/FreeRTOS.h"
|
|
#include "freertos/task.h"
|
|
#include "lmic/lmic.h"
|
|
#include <string.h>
|
|
|
|
#define NUM_RINGBUF_MSG 50
|
|
#define TAG "lmic"
|
|
|
|
/**
|
|
* @brief Message structure used in ring buffer
|
|
*
|
|
* The structure is sent from the LMIC task to the logging task.
|
|
*/
|
|
typedef struct
|
|
{
|
|
const char *message;
|
|
uint32_t datum;
|
|
ev_t event;
|
|
ostime_t time;
|
|
ostime_t txend;
|
|
ostime_t globalDutyAvail;
|
|
u4_t freq;
|
|
u2_t opmode;
|
|
u2_t fcntDn;
|
|
u2_t fcntUp;
|
|
u2_t rxsyms;
|
|
rps_t rps;
|
|
u1_t txChnl;
|
|
u1_t datarate;
|
|
u1_t txrxFlags;
|
|
u1_t saveIrqFlags;
|
|
} TTNLogMessage;
|
|
|
|
static void loggingTask(void *param);
|
|
static void logFatal(const char *const file, const uint16_t line);
|
|
|
|
static void printMessage(TTNLogMessage *log);
|
|
static void printFatalError(TTNLogMessage *log);
|
|
static void printEvent(TTNLogMessage *log);
|
|
static void printEvtJoined(TTNLogMessage *log);
|
|
static void printEvtJoinFailed(TTNLogMessage *log);
|
|
static void printEvtTxComplete(TTNLogMessage *log);
|
|
static void printEvtTxStart(TTNLogMessage *log);
|
|
static void printEvtRxStart(TTNLogMessage *log);
|
|
static void printEvtJoinTxComplete(TTNLogMessage *log);
|
|
static void bin2hex(const uint8_t *bin, unsigned len, char *buf, char sep);
|
|
|
|
// Constants for formatting LORA values
|
|
static const char *const SF_NAMES[] = {"FSK", "SF7", "SF8", "SF9", "SF10", "SF11", "SF12", "SFrfu"};
|
|
static const char *const BW_NAMES[] = {"BW125", "BW250", "BW500", "BWrfu"};
|
|
static const char *const CR_NAMES[] = {"CR 4/5", "CR 4/6", "CR 4/7", "CR 4/8"};
|
|
static const char *const CRC_NAMES[] = {"NoCrc", "Crc"};
|
|
|
|
static RingbufHandle_t ringBuffer;
|
|
|
|
// Initialize logging
|
|
void ttn_log_init(void)
|
|
{
|
|
ringBuffer = xRingbufferCreate(NUM_RINGBUF_MSG * sizeof(TTNLogMessage), RINGBUF_TYPE_NOSPLIT);
|
|
if (ringBuffer == NULL)
|
|
{
|
|
ESP_LOGE(TAG, "Failed to create ring buffer");
|
|
ASSERT(0);
|
|
}
|
|
|
|
xTaskCreate(loggingTask, "ttn_log", 1024 * 4, ringBuffer, 4, NULL);
|
|
hal_set_failure_handler(logFatal);
|
|
}
|
|
|
|
// Record a logging event for later output
|
|
void ttn_log_event(int event, const char *message, uint32_t datum)
|
|
{
|
|
if (ringBuffer == NULL)
|
|
return;
|
|
|
|
// capture state
|
|
TTNLogMessage log = {
|
|
.message = message,
|
|
.datum = datum,
|
|
.time = os_getTime(),
|
|
.txend = LMIC.txend,
|
|
.globalDutyAvail = LMIC.globalDutyAvail,
|
|
.event = (ev_t)event,
|
|
.freq = LMIC.freq,
|
|
.opmode = LMIC.opmode,
|
|
.fcntDn = (u2_t)LMIC.seqnoDn,
|
|
.fcntUp = (u2_t)LMIC.seqnoUp,
|
|
.rxsyms = LMIC.rxsyms,
|
|
.rps = LMIC.rps,
|
|
.txChnl = LMIC.txChnl,
|
|
.datarate = LMIC.datarate,
|
|
.txrxFlags = LMIC.txrxFlags,
|
|
.saveIrqFlags = LMIC.saveIrqFlags,
|
|
};
|
|
|
|
xRingbufferSend(ringBuffer, &log, sizeof(log), 0);
|
|
}
|
|
|
|
// record a fatal event (failed assert) for later output
|
|
void logFatal(const char *const file, const uint16_t line)
|
|
{
|
|
ttn_log_event(-3, file, line);
|
|
}
|
|
|
|
// Record an informational message for later output
|
|
// The message must not be freed.
|
|
void LMICOS_logEvent(const char *pMessage)
|
|
{
|
|
ttn_log_event(-1, pMessage, 0);
|
|
}
|
|
|
|
// Record an information message with an integer value for later output
|
|
// The message must not be freed.
|
|
void LMICOS_logEventUint32(const char *pMessage, uint32_t datum)
|
|
{
|
|
ttn_log_event(-2, pMessage, datum);
|
|
}
|
|
|
|
// ---------------------------------------------------------------------------
|
|
// Log output
|
|
|
|
// Tasks that receiveds the recorded messages, formats and outputs them.
|
|
void loggingTask(void *param)
|
|
{
|
|
RingbufHandle_t ringBuffer = (RingbufHandle_t)param;
|
|
|
|
while (true)
|
|
{
|
|
size_t size;
|
|
TTNLogMessage *log = (TTNLogMessage *)xRingbufferReceive(ringBuffer, &size, portMAX_DELAY);
|
|
if (log == NULL)
|
|
continue;
|
|
|
|
printMessage(log);
|
|
|
|
vRingbufferReturnItem(ringBuffer, log);
|
|
}
|
|
}
|
|
|
|
// Format and output a log message
|
|
void printMessage(TTNLogMessage *log)
|
|
{
|
|
switch ((int)log->event)
|
|
{
|
|
case -1:
|
|
ESP_LOGI(TAG, "%u (%d ms) - %s: opmode=%x", log->time, osticks2ms(log->time), log->message, log->opmode);
|
|
break;
|
|
|
|
case -2:
|
|
ESP_LOGI(TAG, "%u (%d ms) - %s: datum=0x%x, opmode=%x)", log->time, osticks2ms(log->time), log->message,
|
|
log->datum, log->opmode);
|
|
break;
|
|
|
|
case -3:
|
|
printFatalError(log);
|
|
break;
|
|
|
|
default:
|
|
printEvent(log);
|
|
break;
|
|
}
|
|
}
|
|
|
|
void printFatalError(TTNLogMessage *log)
|
|
{
|
|
ESP_LOGE(TAG, "%u (%d ms) - %s, %d", log->time, osticks2ms(log->time), log->message, log->datum);
|
|
ESP_LOGE(TAG, "- freq=%d.%d, txend=%u, avail=%u, ch=%u", log->freq / 1000000, (log->freq % 1000000) / 100000,
|
|
log->txend, log->globalDutyAvail, (unsigned)log->txChnl);
|
|
rps_t rps = log->rps;
|
|
ESP_LOGE(TAG, "- rps=0x%02x (%s, %s, %s, %s, IH=%d)", rps, SF_NAMES[getSf(rps)], BW_NAMES[getBw(rps)],
|
|
CR_NAMES[getCr(rps)], CRC_NAMES[getNocrc(rps)], getIh(rps));
|
|
ESP_LOGE(TAG, "- opmode=%x, txrxFlags=0x%02x%s, saveIrqFlags=0x%02x", log->opmode, log->txrxFlags,
|
|
(log->txrxFlags & TXRX_ACK) != 0 ? "; received ack" : "", log->saveIrqFlags);
|
|
}
|
|
|
|
void printEvent(TTNLogMessage *log)
|
|
{
|
|
ESP_LOGI(TAG, "%u (%d ms) - %s", log->time, osticks2ms(log->time), log->message);
|
|
|
|
switch ((int)log->event)
|
|
{
|
|
case EV_JOINED:
|
|
printEvtJoined(log);
|
|
break;
|
|
|
|
case EV_JOIN_FAILED:
|
|
printEvtJoinFailed(log);
|
|
break;
|
|
|
|
case EV_TXCOMPLETE:
|
|
printEvtTxComplete(log);
|
|
break;
|
|
|
|
case EV_TXSTART:
|
|
printEvtTxStart(log);
|
|
break;
|
|
|
|
case EV_RXSTART:
|
|
printEvtRxStart(log);
|
|
break;
|
|
|
|
case EV_JOIN_TXCOMPLETE:
|
|
printEvtJoinTxComplete(log);
|
|
break;
|
|
|
|
default:
|
|
break;
|
|
};
|
|
}
|
|
|
|
// Format and output the detail of a successful network join
|
|
void printEvtJoined(TTNLogMessage *log)
|
|
{
|
|
ESP_LOGI(TAG, "- ch=%d", (unsigned)log->txChnl);
|
|
|
|
u4_t netid = 0;
|
|
devaddr_t devaddr = 0;
|
|
u1_t nwkKey[16];
|
|
u1_t artKey[16];
|
|
LMIC_getSessionKeys(&netid, &devaddr, nwkKey, artKey);
|
|
|
|
ESP_LOGI(TAG, "- netid: %d", netid);
|
|
|
|
ESP_LOGI(TAG, "- devaddr: %08x", devaddr);
|
|
|
|
char hexBuf[48];
|
|
bin2hex((uint8_t *)&artKey, sizeof(artKey), hexBuf, '-');
|
|
ESP_LOGI(TAG, "- artKey: %s", hexBuf);
|
|
|
|
bin2hex((uint8_t *)&nwkKey, sizeof(nwkKey), hexBuf, '-');
|
|
ESP_LOGI(TAG, "- nwkKey: %s", hexBuf);
|
|
}
|
|
|
|
// Format and output the detail of a failed network join
|
|
void printEvtJoinFailed(TTNLogMessage *log)
|
|
{
|
|
rps_t rps = log->rps;
|
|
ESP_LOGE(TAG, "- freq=%d.%d, opmode=%x, rps=0x%02x (%s, %s, %s, %s, IH=%d)", log->freq / 1000000,
|
|
(log->freq % 1000000) / 100000, log->opmode, rps, SF_NAMES[getSf(rps)], BW_NAMES[getBw(rps)],
|
|
CR_NAMES[getCr(rps)], CRC_NAMES[getNocrc(rps)], getIh(rps));
|
|
}
|
|
|
|
void printEvtTxComplete(TTNLogMessage *log)
|
|
{
|
|
rps_t rps = log->rps;
|
|
ESP_LOGI(TAG, "- ch=%d, rps=0x%02x (%s, %s, %s, %s, IH=%d)", (unsigned)log->txChnl, rps, SF_NAMES[getSf(rps)],
|
|
BW_NAMES[getBw(rps)], CR_NAMES[getCr(rps)], CRC_NAMES[getNocrc(rps)], getIh(rps));
|
|
ESP_LOGI(TAG, "- txrxFlags=0x%02x%s, FcntUp=%04x, FcntDn=%04x, txend=%u", log->txrxFlags,
|
|
(log->txrxFlags & TXRX_ACK) != 0 ? "; received ack" : "", log->fcntUp, log->fcntDn, log->txend);
|
|
}
|
|
|
|
void printEvtTxStart(TTNLogMessage *log)
|
|
{
|
|
rps_t rps = log->rps;
|
|
ESP_LOGI(TAG, "- ch=%d, rps=0x%02x (%s, %s, %s, %s, IH=%d)", (unsigned)log->txChnl, rps, SF_NAMES[getSf(rps)],
|
|
BW_NAMES[getBw(rps)], CR_NAMES[getCr(rps)], CRC_NAMES[getNocrc(rps)], getIh(rps));
|
|
ESP_LOGI(TAG, "- datarate=%u, opmode=%x, txend=%u", log->datarate, log->opmode, log->txend);
|
|
}
|
|
|
|
void printEvtRxStart(TTNLogMessage *log)
|
|
{
|
|
rps_t rps = log->rps;
|
|
ESP_LOGI(TAG, "- freq=%d.%d, rps=0x%02x (%s, %s, %s, %s, IH=%d)", log->freq / 1000000,
|
|
(log->freq % 1000000) / 100000, rps, SF_NAMES[getSf(rps)], BW_NAMES[getBw(rps)], CR_NAMES[getCr(rps)],
|
|
CRC_NAMES[getNocrc(rps)], getIh(rps));
|
|
ESP_LOGI(TAG, "- delta=%dms, rxsysm=%u", osticks2ms(log->time - log->txend), log->rxsyms);
|
|
}
|
|
|
|
void printEvtJoinTxComplete(TTNLogMessage *log)
|
|
{
|
|
ESP_LOGI(TAG, "- saveIrqFlags=0x%02x", log->saveIrqFlags);
|
|
}
|
|
|
|
static const char *HEX_DIGITS = "0123456789ABCDEF";
|
|
|
|
/**
|
|
* @brief Convert binary data to hexadecimal representation.
|
|
*
|
|
* @param bin start of binary data
|
|
* @param len length of binary data (in bytes)
|
|
* @param buf buffer for hexadecimal result
|
|
* @param sep separator used between bytes (or 0 for none)
|
|
*/
|
|
void bin2hex(const uint8_t *bin, unsigned len, char *buf, char sep)
|
|
{
|
|
int tgt = 0;
|
|
for (int i = 0; i < len; i++)
|
|
{
|
|
if (sep != 0 && i != 0)
|
|
buf[tgt++] = sep;
|
|
buf[tgt++] = HEX_DIGITS[bin[i] >> 4];
|
|
buf[tgt++] = HEX_DIGITS[bin[i] & 0xf];
|
|
}
|
|
buf[tgt] = 0;
|
|
}
|
|
|
|
#endif
|