search

OPEnSLab-OSU / Loom-V4

Open Source Internet Of Things Rapid Prototyping Framework For Environmental Sensing Applications
5 stars 1 forks source link

Whisp LTE Crashing With Batch Logging #151

Closed drcrockerjr closed 1 week ago

drcrockerjr commented 1 month ago

Describe the bug The Whisp device hangs in the connection stage of a batch log following a batch log that had unsent packets within it.

Hardware in Use Whisp/Weatherchimes unit

To Reproduce Steps to reproduce the behavior:

  1. Upload Loom/Lab Example/Wisp Batch logging. ino
  2. Then wait for a packet to be dropped during a batch publish

Expected behavior The Batch loggin should occur normally

Code Loom/Lab Example/Wisp Batch logging. ino code

Output Instance #1: "time_local": "2024-04-27T17:15:53Z" } } [2024.04.28 00:15:54] [DEBUG] [:log:159] Successfully logged data to Whisp_brd_v0p4_9.csv [2024.04.28 00:15:54] [DEBUG] [:publish:148] Batch not ready to publish: 71/72 [2024.04.28 00:15:55] [DEBUG] [:setInterruptDuration:381] Current Time (Local): 2024.04.27 17:15:55 [2024.04.28 00:15:55] [DEBUG] [:setInterruptDuration:384] Next Interrupt Alarm Set For: 2024.04.27 17:20:55 [2024.04.28 00:15:55] [DEBUG] [:reattachRTCInterrupt:163] Interrupt successfully reattached! [2024.04.28 00:15:55] [DEBUG] [:sleep:409] Entering Standby Sleep... [2024.04.28 00:20:55] [DEBUG] [:power_up:98] Powering up GPRS Modem. This should take about 10 seconds... [2024.04.28 00:21:17] [DEBUG] [:power_up:105] Powering up complete! [2024.04.28 00:21:17] [DEBUG] [:connect:154] Waiting for network... [2024.04.28 00:21:19] [DEBUG] [:connect:167] Connected to network! [2024.04.28 00:21:19] [DEBUG] [:connect:171] Attempting to connect to LTE Network: hologram [2024.04.28 00:21:19] [DEBUG] [:connect:173] Successfully Connected! [2024.04.28 00:21:19] [DEBUG] [:post_sleep:460] Device has awoken from sleep! [2024.04.28 00:21:19] [DEBUG] [:networkTimeUpdate:262] Attempting to set RTC time to the current network time... [2024.04.28 00:21:20] [DEBUG] [:networkTimeUpdate:268] Network time successfully set to: 2024.04.28 00:21:20 [2024.04.28 00:21:20] [DEBUG] [:measure:68] Measuring [2024.04.28 00:21:20] [DEBUG] [:measure:74] Waiting 10 seconds seconds so that we can warm the sensor up [2024.04.28 00:21:35] [DEBUG] [:measure:85] Measuring Complete [2024.04.28 00:21:35] [DEBUG] [:package:95] Packaging [2024.04.28 00:21:35] [DEBUG] [:package:125] Packaging Complete [2024.04.28 00:21:35] [DEBUG] [:display_data:198] Data Json:

{ "type": "data", "id": { "name": "Whisp_brdv0p4", "instance": 4 }, "contents": [ { "module": "Packet", "data": { "Number": 288 } }, { "module": "Analog", "data": { "Vbat": 4.070214748, "Vbat_MV": 4076.660156 } }, { "module": "SEN55", "data": { "PM1_0": 0.600000024, "PM2_5": 0.600000024, "PM4_0": 0.600000024, "PM10_0": 0.600000024, "N_PM0_5": 4.099999905, "N_PM1_0": 4.699999809, "N_PM2_5": 4.699999809, "N_PM4_0": 4.699999809, "N_PM10_0": 4.699999809, "Typical_Particle_Size": 0.280000001, "AmbientHumidity": 92.95999908, "AmbientTemperature": 9.395000458, "VocIndex": 82, "NoxIndex": 3 } }, { "module": "SHT31", "data": { "Temperature": 12.93000031, "Humidity": 75.59999847 } }, { "module": "LTE", "data": { "RSSI": 27 } } ], "timestamp": { "time_utc": "2024-04-28T0:21:35Z", "time_local": "2024-04-27T17:21:35Z" } } [2024.04.28 00:21:35] [DEBUG] [:log:159] Successfully logged data to Whisp_brd_v0p4_9.csv [2024.04.28 00:21:35] [DEBUG] [:connectToBroker:46] Attempting to connect to broker: cas-mosquitto.biossys.oregonstate.edu:1883 [2024.04.28 00:21:38] [DEBUG] [:connectToBroker:58] Successfully connected to broker!

Instance #2

time_utc": "2024-05-22T13:41:16Z", "time_local": "2024-05-22T6:41:16Z" } } [2024.05.22 13:41:17] [DEBUG] [:log:159] Successfully logged data to Whisp_brd_v0p4_3.csv [2024.05.22 13:41:17] [DEBUG] [:publish:148] Batch not ready to publish: 71/72 [2024.05.22 13:41:17] [DEBUG] [:setInterruptDuration:417] Current Time (Local): 2024.05.22 06:41:17 [2024.05.22 13:41:17] [DEBUG] [:setInterruptDuration:420] Next Interrupt Alarm Set For: 2024.05.22 06:46:17 [2024.05.22 13:41:17] [DEBUG] [:reattachRTCInterrupt:199] Interrupt successfully reattached! [2024.05.22 13:41:17] [WARNING] [:power_down:178] SHT31 Not initialized! [2024.05.22 13:41:17] [DEBUG] [:sleep:439] Entering Standby Sleep... [2024.05.22 13:46:17] [WARNING] [:power_up:159] SHT31 Not initialized! [2024.05.22 13:46:17] [DEBUG] [:power_up:98] Powering up GPRS Modem. This should take about 10 seconds... [2024.05.22 13:46:39] [DEBUG] [:power_up:105] Powering up complete! [2024.05.22 13:46:39] [DEBUG] [:connect:154] Waiting for network... [2024.05.22 13:46:41] [DEBUG] [:connect:167] Connected to network! [2024.05.22 13:46:41] [DEBUG] [:connect:171] Attempting to connect to LTE Network: hologram [2024.05.22 13:46:41] [DEBUG] [:connect:173] Successfully Connected! [2024.05.22 13:46:47] [DEBUG] [:post_sleep:525] Device has awoken from sleep! [2024.05.22 13:46:47] [DEBUG] [:sleep:482] v3 Status: LOW/Enabled [2024.05.22 13:46:47] [DEBUG] [:sleep:483] v5 Status: HIGH/Enabled [2024.05.22 13:46:47] [DEBUG] [:networkTimeUpdate:298] Attempting to set RTC time to the current network time... [2024.05.22 13:46:48] [DEBUG] [:networkTimeUpdate:304] Network time successfully set to: 2024.05.22 13:46:48 [2024.05.22 13:46:48] [DEBUG] [:measure:68] Measuring [2024.05.22 13:46:48] [DEBUG] [:measure:78] Beginning PM measurement, waiting 2 seconds at each increment for stablizing mesurement... [2024.05.22 13:47:08] [WARNING] [:measure:77] SHT31 Not initialized! [2024.05.22 13:47:08] [DEBUG] [:measure:85] Measuring Complete [2024.05.22 13:47:08] [DEBUG] [:package:95] Packaging [2024.05.22 13:47:08] [WARNING] [:package:119] SHT31 Not initialized! [2024.05.22 13:47:09] [DEBUG] [:package:125] Packaging Complete [2024.05.22 13:47:09] [DEBUG] [:display_data:198] Data Json:

{ "type": "data", "id": { "name": "Whisp_brdv0p4", "instance": 10 }, "contents": [ { "module": "Packet", "data": { "Number": 360 } }, { "module": "Analog", "data": { "Vbat": 4.113720894, "Vbat_MV": 4105.664063 } }, { "module": "SEN55", "data": { "PM1_0": 0.920000076, "PM2_5": 0.930000007, "PM4_0": 0.939999938, "PM10_0": 0.939999938, "N_PM0_5": 6.039999485, "N_PM1_0": 7, "N_PM2_5": 7.03000021, "N_PM4_0": 7.050000668, "N_PM10_0": 7.050000668, "Typical_Particle_Size": 0.385299981, "AmbientHumidity": 54.34000015, "AmbientTemperature": 17.12999916, "VocIndex": 110, "NoxIndex": 1 } }, { "module": "LTE", "data": { "RSSI": 23 } } ], "timestamp": { "time_utc": "2024-05-22T13:47:8Z", "time_local": "2024-05-22T6:47:8Z" } } [2024.05.22 13:47:09] [DEBUG] [:log:159] Successfully logged data to Whisp_brd_v0p4_3.csv [2024.05.22 13:47:09] [DEBUG] [:connectToBroker:46] Attempting to connect to broker: cas-mosquitto.biossys.oregonstate.edu:1883 [2024.05.22 13:47:11] [DEBUG] [:connectToBroker:58] Successfully connected to broker! [2024.05.22 13:47:12] [DEBUG] [:publish:138] Data has been successfully sent!

Additional context This error has been observed twice, once at woodhall vineyard and once at the PAB. Both of which have spotty LTE reception. It seems like if there is a batch publish and a packet is unsent due to bad connection, the next batch publish that happens will hang in the connection stage around the output line: "[2024.04.28 00:21:38] [DEBUG] [:connectToBroker:58] Successfully connected to broker!"

Here are the two output files during both instances: Whisp10output.log output_9.log

WL-Richards commented 1 month ago

Is this before the test with the MQTT change?

ZakaryW commented 1 week ago

Resolved after the polling fix