Gateway reports "assert ../src/app_lora.c:842:w == size:LORA Uart write should be blocking" and reboots

avbentem commented 6 years ago

This is a bug report

What do you want to do? What do you expect?

Expecting a proper gateway to not show software or hardware errors in the log.

What steps did you take? (Give as many details as possible so that we can reproduce it)

Gateway is just running and accepting LoRa packets, configured for both a Ziggo ethernet and XS4ALL WiFi connection.

What went wrong? What is missing?

While the gateway is running just fine, it suddenly reports something like the following and reboots:

LORA: Kick LoRa module with ACK afte
*** assert ../src/app_lora.c:842:w == size:LORA Uart write should be blocking

I've seen this message and its reboot 225 times since I upgraded to 1.0.5 on July 17th. In 3 occasions the gateway did not recover from the reboot, but that's covered in #8.

What firmware is running on your gateway?

1.0.5 with the factory bootloader.

What do the logs show?

Timestamps added by my own monitoring:

[2018-08-02T00:37:50.377Z] MQTT: Sending status packet
[2018-08-02T00:37:50.408Z] MQTT: Sending status succeeded: 457
[2018-08-02T00:37:59.677Z] MON: SYS Stack size: 2831
[2018-08-02T00:37:59.680Z] MON: TCPIP Stack size: 3765
[2018-08-02T00:37:59.682Z] MON: APP Stack size: 3259
[2018-08-02T00:37:59.684Z] MON: LoRa Stack size: 3877
[2018-08-02T00:37:59.687Z] MON: heap usage: 279KB (283KB), free: 60KB
[2018-08-02T00:38:09.676Z] MON: SYS Stack size: 2831
[2018-08-02T00:38:09.678Z] MON: TCPIP Stack size: 3765
[2018-08-02T00:38:09.680Z] MON: APP Stack size: 3259
[2018-08-02T00:38:09.682Z] MON: LoRa Stack size: 3877
[2018-08-02T00:38:09.686Z] MON: heap usage: 279KB (283KB), free: 60KB
[2018-08-02T00:38:19.673Z] MON: SYS Stack size: 2831
[2018-08-02T00:38:19.675Z] MON: TCPIP Stack size: 3765
[2018-08-02T00:38:19.678Z] MON: APP Stack size: 3259
[2018-08-02T00:38:19.680Z] MON: LoRa Stack size: 3877
[2018-08-02T00:38:19.684Z] MON: heap usage: 279KB (283KB), free: 60KB
[2018-08-02T00:38:20.319Z] LORA: Kick LoRa module with ACK afte
[2018-08-02T00:38:20.326Z] *** assert ../src/app_lora.c:842:w == size:LORA Uart write should be blocking
[2018-08-02T00:38:20.329Z] 
[2018-08-02T00:38:22.356Z] SNTP: State change from 0 to 0
[2018-08-02T00:38:22.360Z] SNTP: State change from 0 to 0
[2018-08-02T00:38:22.363Z] 
[2018-08-02T00:38:22.364Z] 
[2018-08-02T00:38:22.365Z] 
[2018-08-02T00:38:22.366Z] **************************
[2018-08-02T00:38:22.369Z] *   The Things Network   *
[2018-08-02T00:38:22.371Z] *      G A T E W A Y     *
[2018-08-02T00:38:22.374Z] **************************
[2018-08-02T00:38:22.379Z] Firmware name: AmazingAckermann, type: 0, version: 1.0.5, commit: fa89b993, timestamp: 1531815112
[2018-08-02T00:38:22.421Z] Bootloader revision: 1, commit: 7167873a, timestamp: 1496411298
[2018-08-02T00:38:22.424Z] Build time: Jul 17 2018 08:12:51
[2018-08-02T00:38:22.425Z] Reboot reason: 0x40

Any Screenshots or Photos?

N/A

Do you think you can try to fix this yourself and submit a pull request?

No.

avbentem commented 6 years ago

So far it has reported this error, and rebooted after that, 522 times since installing 1.0.5 on July 17th (which is 70 days ago). Often, if not always, the assert is preceded by (a partial) LORA: Kick LoRa module with ACK after not acked it for 60s, but not every such message yields the failing assert.

avbentem commented 5 years ago

The statistics have improved a little bit: so far it rebooted for this reason 1,070 times since installing 1.0.5 on July 17th, which is 197 days ago. It has been receiving far fewer packets in the last months as I switched off some test node, but the assert is not (always) related to recent LoRa activity, so maybe the number of packets doesn't affect this at all. It's not happening every day, but a few days even have 20 reboots or more:

  23 2018-07-23
  20 2018-08-10
  26 2018-09-22
  20 2018-11-14
  35 2018-12-13
  22 2018-12-17
  29 2019-01-20

All counts of "assert" message per day (if any)

```text 12 2018-07-20 3 2018-07-21 11 2018-07-22 23 2018-07-23 8 2018-07-24 5 2018-07-25 1 2018-07-26 4 2018-07-27 9 2018-07-28 11 2018-07-29 1 2018-07-30 12 2018-07-31 13 2018-08-01 1 2018-08-02 1 2018-08-04 2 2018-08-05 1 2018-08-07 3 2018-08-08 11 2018-08-09 20 2018-08-10 11 2018-08-11 2 2018-08-12 7 2018-08-13 14 2018-08-14 11 2018-08-15 13 2018-08-16 11 2018-08-17 10 2018-08-18 14 2018-08-19 18 2018-08-20 18 2018-08-21 11 2018-08-22 9 2018-08-23 17 2018-08-24 19 2018-08-25 6 2018-08-26 1 2018-08-25 6 2018-08-26 8 2018-08-27 7 2018-08-28 1 2018-08-29 3 2018-08-30 7 2018-08-31 8 2018-09-01 9 2018-09-02 6 2018-09-03 10 2018-09-04 9 2018-09-06 6 2018-09-07 4 2018-09-08 8 2018-09-09 9 2018-09-10 1 2018-09-11 1 2018-09-13 1 2018-09-15 6 2018-09-16 7 2018-09-18 14 2018-09-19 19 2018-09-20 26 2018-09-22 2 2018-09-26 1 2018-09-27 1 2018-10-08 1 2018-10-09 1 2018-10-11 1 2018-10-12 1 2018-10-15 2 2018-10-16 1 2018-10-17 1 2018-10-24 3 2018-10-26 1 2018-10-27 1 2018-10-28 2 2018-10-29 4 2018-10-30 3 2018-10-31 1 2018-11-01 4 2018-11-02 1 2018-11-03 3 2018-11-04 8 2018-11-05 3 2018-11-06 1 2018-11-08 2 2018-11-09 1 2018-11-10 4 2018-11-13 20 2018-11-14 2 2018-11-16 4 2018-11-17 3 2018-11-18 5 2018-11-19 2 2018-11-20 1 2018-11-22 1 2018-11-23 2 2018-11-24 3 2018-11-25 2 2018-11-26 5 2018-11-27 6 2018-11-28 5 2018-11-29 11 2018-11-30 8 2018-12-01 6 2018-12-02 3 2018-12-03 4 2018-12-05 1 2018-12-06 9 2018-12-08 3 2018-12-09 16 2018-12-11 13 2018-12-12 35 2018-12-13 2 2018-12-14 2 2018-12-15 7 2018-12-16 22 2018-12-17 6 2018-12-18 4 2018-12-19 12 2018-12-20 6 2018-12-21 15 2018-12-22 5 2018-12-23 6 2018-12-25 4 2018-12-26 8 2018-12-27 7 2018-12-28 7 2018-12-30 3 2018-12-31 5 2019-01-02 6 2019-01-03 6 2019-01-04 11 2019-01-05 5 2019-01-06 1 2019-01-07 4 2019-01-08 11 2019-01-09 16 2019-01-10 7 2019-01-11 7 2019-01-12 13 2019-01-13 1 2019-01-14 4 2019-01-15 8 2019-01-16 4 2019-01-17 2 2019-01-18 1 2019-01-19 29 2019-01-20 9 2019-01-21 10 2019-01-22 6 2019-01-23 2 2019-01-25 14 2019-01-26 9 2019-01-27 6 2019-01-28 1 2019-01-29 ```

TheThingsProducts / gateway