TheThingsProducts / gateway

The Things Kickstarter Gateway
https://www.thethingsindustries.com/docs/gateways/models/thethingskickstartergateway
54 stars 20 forks source link

Reboot after MQTT error #21

Open willem4ever opened 6 years ago

willem4ever commented 6 years ago

This is a bug report

What went wrong? What is missing?

Gateway Reboots 58 minutes after the successful upgrade. Different reason though ...

What firmware is running on your gateway?

v1.0.2-475aef56

What do the logs show?

2018-03-15 13:43:04.263647 MQTT: Sending UPLINK failed: -1
2018-03-15 13:43:04.263684 
2018-03-15 13:43:04.263688 MAIN: MQTT error
2018-03-15 13:43:04.263691 
2018-03-15 13:43:04.263694 MAIN: Leaving state 5
2018-03-15 13:43:04.999120 MON: SYS Stack size: 2837
2018-03-15 13:43:04.999156 MON: heap usage: 262KB (274KB), free: 77KB
2018-03-15 13:43:05.717329 LORA: Accepted packet
2018-03-15 13:43:09.983239 CB: Disconnect
2018-03-15 13:43:13.390588 SNTP: State change from 0 to 0
2018-03-15 13:43:13.390625 SNTP: State change from 0 to 0
2018-03-15 13:43:13.390629 
2018-03-15 13:43:13.390632 
2018-03-15 13:43:13.390634 
2018-03-15 13:43:13.390637 **************************
2018-03-15 13:43:13.390640 *   The Things Network   *
2018-03-15 13:43:13.390900 *      G A T E W A Y     *
2018-03-15 13:43:13.390911 **************************
2018-03-15 13:43:13.391669 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973
2018-03-15 13:43:13.391995 Bootloader revision: 1, commit: 7167873a, timestamp: 1496411298
2018-03-15 13:43:13.392007 Build time: Mar 15 2018 10:16:33
2018-03-15 13:43:13.392733 Reboot reason: 0x10
htdvisser commented 6 years ago

I updated your issue to use the template that Github provided when you create a new issue. Please use the template for any future issues you may submit.

htdvisser commented 6 years ago

Possibly related to #8

willem4ever commented 6 years ago

Additional log information on the subsequent reboots, all happen after an MQTT error and result in a consistent Reboot reason: 0x10

2018-03-15 15:18:08.965376 SNTP: State change from 1 to 2
2018-03-15 15:18:10.084116 SNTP: State change from 2 to 3
2018-03-15 15:18:10.107992 MQTT: Sending UPLINK failed: -1
2018-03-15 15:18:10.108014 
2018-03-15 15:18:10.108018 MAIN: MQTT error
2018-03-15 15:18:10.108021 
2018-03-15 15:18:10.108210 MAIN: Leaving state 5
2018-03-15 15:18:10.796108 LORA: Accepted packet
2018-03-15 15:18:10.875296 LORA: Packet dropped! Bad CRC
2018-03-15 15:18:11.179067 SNTP: State change from 3 to 4
2018-03-15 15:18:12.281409 SNTP: State change from 4 to 5
2018-03-15 15:18:12.312859 SNTP: State change from 5 to 6
2018-03-15 15:18:12.329377 SNTP: State change from 6 to 7
2018-03-15 15:18:19.235022 SNTP: State change from 0 to 0
2018-03-15 15:18:19.235068 SNTP: State change from 0 to 0
2018-03-15 15:18:19.235406 
2018-03-15 15:18:19.235418 
2018-03-15 15:18:19.235421 
2018-03-15 15:18:19.235424 **************************
2018-03-15 15:18:19.235427 *   The Things Network   *
2018-03-15 15:18:19.236429 *      G A T E W A Y     *
2018-03-15 15:18:19.236446 **************************
2018-03-15 15:18:19.236451 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973
2018-03-15 15:18:19.236641 Bootloader revision: 1, commit: 7167873a, timestamp: 1496411298
2018-03-15 15:18:19.236664 Build time: Mar 15 2018 10:16:33
2018-03-15 15:18:19.237324 Reboot reason: 0x10
--
2018-03-16 04:52:44.006956 MON: SYS Stack size: 2845
2018-03-16 04:52:44.006992 MON: heap usage: 262KB (267KB), free: 77KB
2018-03-16 04:52:48.257578 MQTT: Sending status packet
2018-03-16 04:52:48.290245 MQTT: Sending status succeeded: 1614
2018-03-16 04:52:52.043405 LORA: Accepted packet
2018-03-16 04:52:52.107628 LORA: Packet dropped! Bad CRC
2018-03-16 04:52:54.070660 MON: SYS Stack size: 2845
2018-03-16 04:52:54.070696 MON: heap usage: 262KB (267KB), free: 76KB
2018-03-16 04:52:54.549250 MQTT: Sending UPLINK failed: -1
2018-03-16 04:52:54.549313 
2018-03-16 04:52:54.565615 MAIN: MQTT error
2018-03-16 04:52:54.565630 
2018-03-16 04:52:54.565634 MAIN: Leaving state 5
2018-03-16 04:53:03.656741 SNTP: State change from 0 to 0
2018-03-16 04:53:03.700373 SNTP: State change from 0 to 0
2018-03-16 04:53:03.700389 
2018-03-16 04:53:03.700394 
2018-03-16 04:53:03.700397 
2018-03-16 04:53:03.700400 **************************
2018-03-16 04:53:03.700403 *   The Things Network   *
2018-03-16 04:53:03.700405 *      G A T E W A Y     *
2018-03-16 04:53:03.700408 **************************
2018-03-16 04:53:03.700640 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973
2018-03-16 04:53:03.701489 Bootloader revision: 1, commit: 7167873a, timestamp: 1496411298
2018-03-16 04:53:03.701513 Build time: Mar 15 2018 10:16:33
2018-03-16 04:53:03.701721 Reboot reason: 0x10
--
2018-03-16 07:11:33.778142 MON: heap usage: 264KB (267KB), free: 75KB
2018-03-16 07:11:39.386969 LORA: Accepted packet
2018-03-16 07:11:41.911606 MQTT: Sending UPLINK failed: -1
2018-03-16 07:11:41.911668 
2018-03-16 07:11:41.911682 MAIN: MQTT error
2018-03-16 07:11:41.911685 
2018-03-16 07:11:41.911688 MAIN: Leaving state 5
2018-03-16 07:11:43.838110 MON: SYS Stack size: 2837
2018-03-16 07:11:43.838149 MON: heap usage: 267KB (267KB), free: 71KB
2018-03-16 07:11:44.435536 MAIN: Entering state 6
2018-03-16 07:11:44.435571 INET: State change to 0
2018-03-16 07:11:44.435575 WIFI: Disabling modules
2018-03-16 07:11:44.435579 SNTP: State change from 7 to 8
2018-03-16 07:11:51.036263 SNTP: State change from 0 to 0
2018-03-16 07:11:51.036364 SNTP: State change from 0 to 0
2018-03-16 07:11:51.036387 
2018-03-16 07:11:51.036391 
2018-03-16 07:11:51.036394 
2018-03-16 07:11:51.036397 **************************
2018-03-16 07:11:51.036400 *   The Things Network   *
2018-03-16 07:11:51.036657 *      G A T E W A Y     *
2018-03-16 07:11:51.036678 **************************
2018-03-16 07:11:51.037550 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973
2018-03-16 07:11:51.037740 Bootloader revision: 1, commit: 7167873a, timestamp: 1496411298
2018-03-16 07:11:51.037752 Build time: Mar 15 2018 10:16:33
2018-03-16 07:11:51.038540 Reboot reason: 0x10
willem4ever commented 6 years ago

I extended the logging information for all 'Sending UPLINK failed: -1' including the ones which do not trigger the WDT and reboot .... when things go wrong 'SNTP: State change from 0 to 0' appears to be present ....

note-1: I now realize it appears after the WDT already expired .....

--
2018-03-15 13:43:04.263647 MQTT: Sending UPLINK failed: -1
2018-03-15 13:43:04.263684 
2018-03-15 13:43:04.263688 MAIN: MQTT error
2018-03-15 13:43:04.263691 
2018-03-15 13:43:04.263694 MAIN: Leaving state 5
2018-03-15 13:43:04.999120 MON: SYS Stack size: 2837
2018-03-15 13:43:04.999156 MON: heap usage: 262KB (274KB), free: 77KB
2018-03-15 13:43:05.717329 LORA: Accepted packet
2018-03-15 13:43:09.983239 CB: Disconnect
2018-03-15 13:43:13.390588 SNTP: State change from 0 to 0
2018-03-15 13:43:13.390625 SNTP: State change from 0 to 0
2018-03-15 13:43:13.390629 
2018-03-15 13:43:13.390632 
2018-03-15 13:43:13.390634 
2018-03-15 13:43:13.390637 **************************
2018-03-15 13:43:13.390640 *   The Things Network   *
2018-03-15 13:43:13.390900 *      G A T E W A Y     *
2018-03-15 13:43:13.390911 **************************
2018-03-15 13:43:13.391669 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973
2018-03-15 13:43:13.391995 Bootloader revision: 1, commit: 7167873a, timestamp: 1496411298
2018-03-15 13:43:13.392007 Build time: Mar 15 2018 10:16:33
--
2018-03-15 15:18:10.107992 MQTT: Sending UPLINK failed: -1
2018-03-15 15:18:10.108014 
2018-03-15 15:18:10.108018 MAIN: MQTT error
2018-03-15 15:18:10.108021 
2018-03-15 15:18:10.108210 MAIN: Leaving state 5
2018-03-15 15:18:10.796108 LORA: Accepted packet
2018-03-15 15:18:10.875296 LORA: Packet dropped! Bad CRC
2018-03-15 15:18:11.179067 SNTP: State change from 3 to 4
2018-03-15 15:18:12.281409 SNTP: State change from 4 to 5
2018-03-15 15:18:12.312859 SNTP: State change from 5 to 6
2018-03-15 15:18:12.329377 SNTP: State change from 6 to 7
2018-03-15 15:18:19.235022 SNTP: State change from 0 to 0
2018-03-15 15:18:19.235068 SNTP: State change from 0 to 0
2018-03-15 15:18:19.235406 
2018-03-15 15:18:19.235418 
2018-03-15 15:18:19.235421 
2018-03-15 15:18:19.235424 **************************
2018-03-15 15:18:19.235427 *   The Things Network   *
2018-03-15 15:18:19.236429 *      G A T E W A Y     *
2018-03-15 15:18:19.236446 **************************
2018-03-15 15:18:19.236451 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973
--
2018-03-15 15:40:54.014224 MQTT: Sending UPLINK failed: -1
2018-03-15 15:40:54.014329 
2018-03-15 15:40:54.014350 MAIN: MQTT error
2018-03-15 15:40:54.014353 
2018-03-15 15:40:54.014359 MAIN: Leaving state 5
2018-03-15 15:40:55.994773 LORA: Accepted packet
2018-03-15 15:40:56.550579 MAIN: Entering state 6
2018-03-15 15:40:56.550727 INET: State change to 0
2018-03-15 15:40:56.550746 WIFI: Disabling modules
2018-03-15 15:40:56.550753 SNTP: State change from 7 to 8
2018-03-15 15:40:56.550759 CB: Disconnect
2018-03-15 15:40:56.551096 Head magic match void: trying to free an already freed block, ignore
2018-03-15 15:40:56.551753 SNTP: State change from 8 to 1
2018-03-15 15:40:56.551772 WIFI: Entering state 3
2018-03-15 15:40:56.790070 LORA: Packet dropped! Bad CRC
2018-03-15 15:40:57.148102 MON: SYS Stack size: 2845
2018-03-15 15:40:57.148141 MON: heap usage: 169KB (267KB), free: 170KB
2018-03-15 15:40:57.426373 WIFI: Enabling modules for client
2018-03-15 15:40:57.426475 WIFI: Entering state 6
2018-03-15 15:40:57.426484 WIFI: IP Address: 0.0.0.0 
2018-03-15 15:40:58.608157 CB: INET: Gateway has WiFi
--
2018-03-15 16:46:10.214513 MQTT: Sending UPLINK failed: -1
2018-03-15 16:46:10.214559 
2018-03-15 16:46:10.214564 MAIN: MQTT error
2018-03-15 16:46:10.214575 
2018-03-15 16:46:10.214579 MAIN: Leaving state 5
2018-03-15 16:46:10.262745 MAIN: Entering state 6
2018-03-15 16:46:10.262840 INET: State change to 0
2018-03-15 16:46:10.262848 WIFI: Disabling modules
2018-03-15 16:46:10.262851 SNTP: State change from 7 to 8
2018-03-15 16:46:10.262854 CB: Disconnect
2018-03-15 16:46:10.262860 Head magic match void: trying to free an already freed block, ignore
2018-03-15 16:46:10.263385 SNTP: State change from 8 to 1
2018-03-15 16:46:10.263400 WIFI: Entering state 3
2018-03-15 16:46:10.294079 MON: SYS Stack size: 2845
2018-03-15 16:46:10.294382 MON: heap usage: 169KB (267KB), free: 170KB
2018-03-15 16:46:11.139599 WIFI: Enabling modules for client
2018-03-15 16:46:11.139635 WIFI: Entering state 6
2018-03-15 16:46:11.139639 WIFI: IP Address: 0.0.0.0 
2018-03-15 16:46:12.518098 CB: INET: Gateway has WiFi
2018-03-15 16:46:12.518207 INET: State change to 2
2018-03-15 16:46:12.518468 INET: Connected to a network, waiting for DHCP lease, checking validity with ping
--
2018-03-16 04:52:54.549250 MQTT: Sending UPLINK failed: -1
2018-03-16 04:52:54.549313 
2018-03-16 04:52:54.565615 MAIN: MQTT error
2018-03-16 04:52:54.565630 
2018-03-16 04:52:54.565634 MAIN: Leaving state 5
2018-03-16 04:53:03.656741 SNTP: State change from 0 to 0
2018-03-16 04:53:03.700373 SNTP: State change from 0 to 0
2018-03-16 04:53:03.700389 
2018-03-16 04:53:03.700394 
2018-03-16 04:53:03.700397 
2018-03-16 04:53:03.700400 **************************
2018-03-16 04:53:03.700403 *   The Things Network   *
2018-03-16 04:53:03.700405 *      G A T E W A Y     *
2018-03-16 04:53:03.700408 **************************
2018-03-16 04:53:03.700640 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973
2018-03-16 04:53:03.701489 Bootloader revision: 1, commit: 7167873a, timestamp: 1496411298
2018-03-16 04:53:03.701513 Build time: Mar 15 2018 10:16:33
2018-03-16 04:53:03.701721 Reboot reason: 0x10
2018-03-16 04:53:03.701902 BOOT: (persisted info) 6F 72 72 65 01 10 D1 3E 57 1F 1A 7E A3 BA A1 FB 
2018-03-16 04:53:03.701912 
2018-03-16 04:53:03.701916 
--
2018-03-16 07:11:41.911606 MQTT: Sending UPLINK failed: -1
2018-03-16 07:11:41.911668 
2018-03-16 07:11:41.911682 MAIN: MQTT error
2018-03-16 07:11:41.911685 
2018-03-16 07:11:41.911688 MAIN: Leaving state 5
2018-03-16 07:11:43.838110 MON: SYS Stack size: 2837
2018-03-16 07:11:43.838149 MON: heap usage: 267KB (267KB), free: 71KB
2018-03-16 07:11:44.435536 MAIN: Entering state 6
2018-03-16 07:11:44.435571 INET: State change to 0
2018-03-16 07:11:44.435575 WIFI: Disabling modules
2018-03-16 07:11:44.435579 SNTP: State change from 7 to 8
2018-03-16 07:11:51.036263 SNTP: State change from 0 to 0
2018-03-16 07:11:51.036364 SNTP: State change from 0 to 0
2018-03-16 07:11:51.036387 
2018-03-16 07:11:51.036391 
2018-03-16 07:11:51.036394 
2018-03-16 07:11:51.036397 **************************
2018-03-16 07:11:51.036400 *   The Things Network   *
2018-03-16 07:11:51.036657 *      G A T E W A Y     *
2018-03-16 07:11:51.036678 **************************
2018-03-16 07:11:51.037550 Firmware name: AmazingAckermann, type: 0, version: 1.0.2, commit: 475aef56, timestamp: 1521108973