search

lnlp / LMIC-node

LMIC-node | One example to rule them all. LMIC-node is an example LoRaWAN application for a node that can be used with The Things Network. It demonstrates how to send uplink messages, how to receive downlink messages, how to implement a downlink command and it provides useful status information. With LMIC-node it is easy to get a working node quickly up and running. LMIC-node supports many popular (LoRa) development boards out of the box. It uses the Arduino framework, the LMIC LoRaWAN library and PlatformIO.
MIT License
215 stars 102 forks source link

LMIC_PRINTF_TO is not correctly set #9

Closed megabug closed 3 years ago

megabug commented 3 years ago

README.md states:

  • When using LMIC debugging, output is automatically routed to the correct serial port. No need to set the LMIC_PRINTF_TO parameter to Serial or SerialUSB manually.

It looks like this happens is in LMIC-node.h:

#if defined(LMIC_DEBUG_LEVEL) && LMIC_DEBUG_LEVEL > 0
    // Do not overrule if already defined
    #ifndef LMIC_PRINTF_TO
        #define LMIC_PRINTF_TO serial
    #endif
#endif

However, this does not take effect when the LMIC library is actually being built. The individual LMIC source files will not include LMIC-node.h and therefore do not see the defined LMIC_PRINTF_TO value. I have verified that this results in debug output not going to serial, even when LMIC_DEBUG_LEVEL is set to > 0.

I have been fixing this in my project by simply defining LMIC_PRINTF_TO in the LMIC compilation flags in platformio.ini, i.e.:

; --------------------------------------------------
; |  MCCI LoRaWAN LMIC library specific settings   |
; --------------------------------------------------
; (...)
build_flags =
; (...)
    -D LMIC_PRINTF_TO=Serial

...but I am not sure if there is a better way that keeps the intended behaviour of it only being set when LMIC_DEBUG_LEVEL > 0.

Does it matter if LMIC_PRINTF_TO is set but LMIC_DEBUG_LEVEL is 0? I would imagine LMIC wouldn't suddenly start spamming debug output, but I haven't tried this.

lnlp commented 3 years ago

However, this does not take effect when the LMIC library is actually being built. The individual LMIC source files will not include LMIC-node.h and therefore do not see the defined LMIC_PRINTF_TO value.

What you mention seems plausible, but does not explain why I do see LMIC debug output arriving in the serial monitor (only for boards using Serial, not for boards using SerialUSB though). Therefore I was assuming that the precompiler was able to get this working.

I will have to look into this.

What OS and what board have you used for your verification results?


I have verified that this results in debug output not going to serial, even when LMIC_DEBUG_LEVEL is set to > 0.

This is different from my experience. When I enable -D LMIC_DEBUG_LEVEL and set its value to a value > 0 (1, 2 or 3) I actually see LMIC debug output on the serial monitor.


I have been fixing this in my project by simply defining LMIC_PRINTF_TO in the LMIC compilation flags in platformio.ini

If it is not possible to do this automatically in a reliable way then that will possibly be the only solution. But because LMIC-node automatically knows which serial port to use (Serial or SerialUSB) and does not bother the user to explicitly specify the correct serial port, it would be nice if this can be done automatically for LMIC_PRINTF_TO also. That is the reason why I prefer that the user does not need to specify Serial or SerialUSB explicitly because that choice is already made automatically by LMIC-node for regular output to serial monitor.

megabug commented 3 years ago

What OS and what board have you used for your verification results?

macOS 10.15.7, Adafruit Feather M0 LoRa.

This is different from my experience. When I enable -D LMIC_DEBUG_LEVEL and set its value to a value > 0 (1, 2 or 3) I actually see LMIC debug output on the serial monitor.

Here's the serial output after checking out the current main, setting the board in platformio.ini, cleaning, compiling and uploading:

LMIC-node

Device-id:     feather-m0
LMIC library:  MCCI
Activation:    OTAA
Interval:      60 seconds

000000128075:  doWork job started
000000131214:  Input data collected
               COUNTER value: 1
000000131255:  Packet queued
000000131274:  Event: EV_JOINING
000000410018:  Event: EV_TXSTART
000000803201:  Event: EV_JOIN_TXCOMPLETE

With LMIC_DEBUG_LEVEL set to 2:

LMIC-node

Device-id:     feather-m0
LMIC library:  MCCI
Activation:    OTAA
LMIC debug:    2
Interval:      60 seconds

000000191257:  doWork job started
000000194396:  Input data collected
               COUNTER value: 1
000000194431:  Packet queued
000000194460:  Event: EV_JOINING
000000483658:  Event: EV_TXSTART
000000876861:  Event: EV_JOIN_TXCOMPLETE

With LMIC_DEBUG_LEVEL set to 2 and -D LMIC_PRINTF_TO=Serial:

LMIC-node

Device-id:     feather-m0
LMIC library:  MCCI
Activation:    OTAA
LMIC debug:    2
Interval:      60 seconds
RXMODE_RSSI

000000191199:  doWork job started
000000194342:  Input data collected
               COUNTER value: 1
000000194375:  Packet queued
194396: engineUpdate, opmode=0x8
000000194451:  Event: EV_JOINING
194469: engineUpdate, opmode=0xc
579893: engineUpdate, opmode=0xc
000000579957:  Event: EV_TXSTART
580015: TXMODE, freq=868300000, len=23, SF=7, BW=125, CR=4/5, IH=0
895633: setupRx1 txrxFlags 00 --> 01
start single rx: now-rxtime: 6
896314: RXMODE_SINGLE, freq=868300000, SF=7, BW=125, CR=4/5, IH=0
rxtimeout: entry: 896796 rxtime: 896258 entry-rxtime: 538 now-entry: 3 rxtime-txend: 312375
958134: setupRx2 txrxFlags 0x1 --> 02
start single rx: now-rxtime: 7
958808: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0
rxtimeout: entry: 973131 rxtime: 958758 entry-rxtime: 14373 now-entry: 4 rxtime-txend: 374875
973285: processRx2Jacc txrxFlags 0x2 --> 00
000000973355:  Event: EV_JOIN_TXCOMPLETE
973372: engineUpdate, opmode=0xc
lnlp commented 3 years ago

I have only set -D LMIC_DEBUG_LEVEL=2 without (manually) setting LMIC_PRINTF_TO and I get below output. Very interesting. It actually shouldn't work so something must be happening automagically.

I wonder why we both see different effects. It could be related to differences in OS and/or differences in board used.

Do you have another, different type board (supported by LMIC-node) that you could try to see what happens with debug output if LMIC_PRINTF_TO is not specified?

LMIC-node

Device-id:     ttgo-tbeam        
LMIC library:  MCCI
Activation:    OTAA
LMIC debug:    2
Interval:      20 seconds        
RXMODE_RSSI

000000081591:  doWork job started
000000084740:  Input data collected
               COUNTER value: 1    
000000085594:  Packet queued   
87659: engineUpdate, opmode=0x8
000000087704:  Event: EV_JOINING
89646: engineUpdate, opmode=0xc 
522892: engineUpdate, opmode=0xc
000000522933:  Event: EV_TXSTART
525010: TXMODE, freq=868300000, len=23, SF=7, BW=125, CR=4/5, IH=0
840624: setupRx1 txrxFlags 00 --> 01
start single rx: now-rxtime: 2
841254: RXMODE_SINGLE, freq=868300000, SF=7, BW=125, CR=4/5, IH=0
845965: Setup channel, idx=3, freq=867100000
845980: Setup channel, idx=4, freq=867300000
845984: Setup channel, idx=5, freq=867500000
846030: Setup channel, idx=6, freq=867700000
846279: Setup channel, idx=7, freq=867900000
000000846549:  Event: EV_JOINED
               Network Id: 19
               Device Address: 260B84FC
               Application Session Key: 11-22-33-36-D8-79-C9-2B-4B-A1-B4-C8-99-72-57-E5
               Network Session Key:     44-55-66-61-9D-4F-B4-8C-1C-30-1F-53-EC-B6-84-40
849377: engineUpdate, opmode=0x808
000000849614:  Event: EV_TXSTART
851676: TXMODE, freq=868100000, len=15, SF=7, BW=125, CR=4/5, IH=0
1166330: setupRx1 txrxFlags 0x1 --> 01
start single rx: now-rxtime: 1
1166959: RXMODE_SINGLE, freq=868100000, SF=7, BW=125, CR=4/5, IH=0
rxtimeout: entry: 1167488 rxtime: 1166955 entry-rxtime: 533 now-entry: 2 rxtime-txend: 312375
1228830: setupRx2 txrxFlags 0x1 --> 02
start single rx: now-rxtime: 1
1229459: RXMODE_SINGLE, freq=869525000, SF=9, BW=125, CR=4/5, IH=0
rxtimeout: entry: 1231268 rxtime: 1229455 entry-rxtime: 1813 now-entry: 1 rxtime-txend: 374875
1231279: processRx2DnData txrxFlags 0x2 --> 00
1231361: processDnData_norx txrxFlags 00 --> 20
000001231625:  Event: EV_TXCOMPLETE
               Up: 1,  Down: 0     
1234589: engineUpdate, opmode=0x900
megabug commented 3 years ago

Do you have another, different type board (supported by LMIC-node) that you could try to see what happens with debug output if LMIC_PRINTF_TO is not specified?

No I don't, sorry :(

Are you doing a clean in between builds adjusting LMIC_PRINTF_TO?

lnlp commented 3 years ago

Are you doing a clean in between builds adjusting LMIC_PRINTF_TO?

It doesn't make any difference.

It looks like on Windows, Serial is used as default when LMIC_PRINTF_TO is not specified by the user. Apparently the behavior is different on macOS.

If I select the Adafruit Feather M0 LoRa, define -D LMIC_PRINTF_TO=Serial in platformio.ini and compile I get compilation errors. It works OK for AVR, ESP32 and ESP8266 boards, but for all ARM based MCU's (e.g. STM32, SAMD21, RP2040 and the MCU on the Teensy) I get the same compilation errors.

If I don't define LMIC_PRINTF_TO then (e.g.) for STM32 boards I do see debug output arriving in the serial monitor, but if I define -D LMIC_PRINTF_TO=Serial then it fails to compile successfully.

Still under investigation. The exact cause is yet unknown but may be related to the LMIC library.

lnlp commented 3 years ago

The compilation errors issue (occurred on Windows only?) for boards with an ARM based MCU has been fixed.

LMIC debugging output can now be used without manually defining -D LMIC_PRINTF_TO=Serial (or SerialUSB) because it is defined for each board separately.

Can you test if it now also works on macOS (without manually defining -D LMIC_PRINTF_TO=... in the [mcci_lmic] section)?

megabug commented 3 years ago

Yep, works for me. Thanks!