Capture actual time on B-RST output

[pejacoby]

When the code receives a B-side reset it logs the reset reason, the UT (millis), and the bluetooth count. This is useful for debugging but doesn't give a sense of the actual time of the event. Could the 'epoch' value also be logged to give an indication of when the related run started? Or since that value isn't updated regularly, does it provide limited additional information? Or with some math, could the actual time of the event be derived and recorded from epoch + millis ?

Use case -- had a situation where the B-side reset many times during a long run.

_BOOT1.2.0b5, ut=2194985, rr=1, id=13180780, bc=73, ep=1713008853, bsh=xxxxx << 4/13/24 @ 5:47am >>_ _B-RST_4,ut=5348047,blc=150 _B-RST_4,ut=5356125,blc=150 _B-RST_4,ut=5364341,blc=150

... a hundred or more reset lines ...

_B-RST_4,ut=12816205,blc=140 _B-RST_4,ut=12824283,blc=140 _BOOT_1.2.0b5, ut=2196211, rr=1, id=13180780 _BOOT1.2.0b5, ut=2193803, rr=1, id=13180780, bc=75, ep=1713043240, bsh=xxxxx << 4/13/24 @ 3:20pm >>_

Another of my interesting edge cases :)

[JosephHewitt]

Thanks for the suggestion. I will change it to also include the current epoch value whenever this line gets logged.

Indeed it should be possible to determine the time it happened at since you have the epoch value from when the device booted. However, the ut value comes from millis() which uses a very inaccurate clock; it could be gaining/losing a few minutes each hour. So if you derive the 'true' time of the crash from this, you should expect it to be offset slightly from the real time.

Did the crash only occur during a single session? If so, do you notice any strange data in the WiGLE .csv file for that session?

[pejacoby]

One clarifiying note -- observations are from a BW16 5G mod wardriver, different from my Wispy standard build.

Unfortunately more recent cases where I've seen many fewer RSTs logged the BOOT message doesn't show an epoch - indicating an off-network startup that hasn't gotten a GPS signal to have a time established yet.

_BOOT_1.2.0b5, ut=2232964, rr=1, id=13180780, bc=82, ep=0, bsh=xxxxx (I know this was finalized 2024-04-29 based on the filename - data is from 04-22 through 04-29)

I have had three other runs since with two RST messages seen, again with ep=0 on the BOOT line. Most of the 'blc' values are between 130 and 160, though run 88 show '57' for both. So there's potentially a relation to #23

_BOOT_1.2.0b5, ut=2191971, rr=1, id=13180780, bc=87, ep=0, bsh=xxxxx _B-RST_4,ut=24248494,blc=132 _B-RST_4,ut=24256574,blc=132

_BOOT_1.2.0b5, ut=2194579, rr=1, id=13180780, bc=88, ep=0, bsh=xxxxx _B-RST_4,ut=2073835,blc=57 _B-RST_4,ut=2081916,blc=57

Looking closer at run 82, there are 16 RST lines in test.txt after bc=82 and before bc=83. This was multi-day run with a 1/2 million line CSV file with ~22 bad lines. With a timestamp I could potentially correlate these to the RSTs.

Some examples: one with two BLE lines running together:

36:41:0F:73:8B:15,,[BLE],2024-04-22 06:15:59,0,-96,42.9714546,-85.6671524,194.10,3.00,BLE 0C:3C:08:24:CD:5C,,[BLE],2024-04-22 06:15:59,0,-97,42.9714546,-85.6671524,194.10,3.00,BLEAC:4A:67:73:16:A6,sh-tenant,[WPA2],2024-04-22 06:15:59,6,-88,42.9714546,-85.6671524,194.10,3.00,WIFI

0D:35:FE:C1:EF:AF,,[BLE],2024-04-22 06:15:59,0,-95,42.9714546,-85.6671524,194.10,3.00,BLE

This one where two WIFI lines run together:

E4:55:A8:16:24:5E,Hilton Honors,[OPEN],2024-04-22 06:16:40,11,-80,42.9717445,-85.6566086,207.80,3.00,WIFI3E:82:C0:E3:69:66,,[WPA2_PSK],2024-04-22 06:16:40,11,-85,42.9717445,-85.6566086,207.80,3.00,WIFI

And a BLE line with a line break in an odd spot:

94:A3:CA:0C:0E:42,Z-Link_0E42 ,[BLE],2024-04-22 12:31:59,0,-90,42.3310242,-83.0412064,51.70,9.25,BLE 44:54:02:41:E4:7C,,[BLE],2024-04-22 12:31:59,0,-84,42.3310242,-83.0412064,51.70,9.25,BLE

I'd have to look back to drives to see where I saw at the time.