matthijskooijman / arduino-lmic

:warning: This library is deprecated, see the README for alternatives.
710 stars 652 forks source link

How does the frame counter increase at new message? #196

Open borjamilcar opened 6 years ago

borjamilcar commented 6 years ago

Hello! I'm a new LMIC_user and I'm trying to run a sample example (ttn-abp.ino) from your example folder. But I can't send message continouosly. The first message is send without any issues and I can see it on the TTN Gateway Page. When the node send the second message it print on Arduino Monitor: "EV_TXCOMPLETE (includes waiting for RX windows)" but the message can't be seen on the TTN. I am think that the issue is with the frame counter that isn't increases at the new message.

Please can someone help?

utkarshshah007 commented 6 years ago

EV_TXCOMPLETE indicates that the node has sent a message and waited for a response, but not necessarily that the gateway has received it.

I'm not sure what your specific problem might be, but for TTN, I'd try:

  1. Reset or Disable frame counter checks for your registered node on the TTN console. This will get rid of the frame problem if that's the issue.
  2. Check the actual gateway logs to see if the messages are being heard, but not forwarded to your application.
ntmcminn commented 6 years ago

I'm running into a similar issue on an ESP32 based board with the ttn-abp example. From the look of things the second message is never actually sent. It is queued up when EV_TXCOMPLETE is received. The way the sample code works is that the first message gets sent, and on EV_TXCOMPLETE, a call to os_setTimedCallback is made. This call passes the job, the send function, and a time based on os_getTime + a delay which is converted from seconds to ticks. In the example I'm running, the second message should fire at 3883080, but that time is never reached, as os_getTime resets when it gets to around 1118380. So, the time never reaches the scheduled time, and the second job never fires.

Here's what I see when I turn up the log level:

1862: engineUpdate, opmode=0x808
1879: Uplink data pending
1882: Airtime available at 1878 (channel duty limit)
1886: Ready for uplink
1978: TXMODE, freq=903900000, len=15, SF=7, BW=125, CR=4/5, IH=0
Packet queued
4891: irq: dio: 0x0 flags: 0x8
5069: Scheduled job 0x3ffc45cc, cb 0x400d1618 ASAP
5434: Running job 0x3ffc45cc, cb 0x400d1618, deadline 0
5745: Scheduled job 0x3ffc45cc, cb 0x400d1340 at 67288
67315: Running job 0x3ffc45cc, cb 0x400d1340, deadline 67288
67670: RXMODE_SINGLE, freq=923300000, SF=7, BW=500, CR=4/5, IH=0
68010: irq: dio: 0x1 flags: 0x80
68197: Scheduled job 0x3ffc45cc, cb 0x400d2abc ASAP
68573: Running job 0x3ffc45cc, cb 0x400d2abc, deadline 0
68889: Scheduled job 0x3ffc45cc, cb 0x400d1390 at 130148
130183: Running job 0x3ffc45cc, cb 0x400d1390, deadline 130148
130549: RXMODE_SINGLE, freq=923300000, SF=9, BW=125, CR=4/5, IH=0
131870: irq: dio: 0x1 flags: 0x80
132063: Scheduled job 0x3ffc45cc, cb 0x400d2ae8 ASAP
132451: Running job 0x3ffc45cc, cb 0x400d2ae8, deadline 0
132773: EV_TXCOMPLETE (includes waiting for RX windows)
133080: Scheduled job 0x3ffc2558, cb 0x400d08e4 at 3883080
133406: engineUpdate, opmode=0x900

Could the problem here be that the job is scheduled for when os_getTime reaches 3883080 but that value is never reached? That would be consistent with the deadlines and executions that show up in earlier logs.

ntmcminn commented 6 years ago

Found the issue, at least for me. On an ESP32 board, there is an issue that breaks LMIC's hal_ticks. In short, some versions of the ESP32 Arduino core have an issue that causes micros() to randomly and unexpectedly reset to zero. This issue describes some of the behavior:

https://github.com/espressif/arduino-esp32/issues/297

Updating to the latest ESP32 core appears to have fixed it.

matthijskooijman commented 6 years ago

@ntmcminn Thanks for reporting back with details :-)

@borjamilcar Are you also using an ESP board? If so, could you see if using the latest core solves your problem?