2023-03-24T16:43:39.447Z,1679676219.447 [CommandExec](IMPORTANT): got command restart logs
2023-03-24T16:44:37.241Z,1679676277.241 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-24T16:45:07.929Z,1679676307.929 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T16:45:16.824Z,1679676316.824 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T16:45:16.824Z,1679676316.824 [Default:CheckIn:C.Wait] Stopped
2023-03-24T16:45:16.824Z,1679676316.824 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T16:45:16.824Z,1679676316.824 [Default:CheckIn:D] Running Loop=1
2023-03-24T16:45:17.220Z,1679676317.220 [Default:CheckIn:D] Stopped
2023-03-24T16:45:17.220Z,1679676317.220 [Default:CheckIn:E] Running Loop=1
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.539596 min 
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn:E] Stopped
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn] Stopped
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn](INFO): Running loop #8
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn] Running Loop=8
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T16:45:17.630Z,1679676317.630 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T16:45:19.641Z,1679676319.641 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164518.00,A,3647.78649,N,12149.81816,W,24.415,81.65,240323,,,D*75
2023-03-24T16:45:19.643Z,1679676319.643 [NAL9602](INFO): GPS fix at 20230324T164518: (36.796442, -121.830303)
2023-03-24T16:45:19.656Z,1679676319.656 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T16:45:19.656Z,1679676319.656 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T16:45:28.217Z,1679676328.217 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230323T204203/Courier0196.lzma
2023-03-24T16:45:29.219Z,1679676329.219 [DataOverHttps](INFO): Moved sent file to Logs/20230323T204203/Courier0196.lzma.bak
2023-03-24T16:45:29.220Z,1679676329.220 [DataOverHttps](INFO): SBD MOMSN=17548005
2023-03-24T16:45:46.665Z,1679676346.665 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20230324T164339/Courier0000.lzma
2023-03-24T16:45:47.667Z,1679676347.667 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0000.lzma.bak
2023-03-24T16:45:47.667Z,1679676347.667 [DataOverHttps](INFO): SBD MOMSN=17548007
2023-03-24T16:45:50.371Z,1679676350.371 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-24T16:45:50.454Z,1679676350.454 [NAL9602](ERROR): received: 
+CSQ:0

OK711, 2, 0, 0, 0

OK
2023-03-24T16:46:13.757Z,1679676373.757 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20230323T204203/Express0197.lzma
2023-03-24T16:46:14.759Z,1679676374.759 [DataOverHttps](INFO): Moved sent file to Logs/20230323T204203/Express0197.lzma.bak
2023-03-24T16:46:14.760Z,1679676374.760 [DataOverHttps](INFO): SBD MOMSN=17548011
2023-03-24T16:46:18.285Z,1679676378.285 [NAL9602](INFO): SBD MO Status=2, MOMSN=14711, MT Status=2, MTMSN=0
2023-03-24T16:46:18.285Z,1679676378.285 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T16:46:35.542Z,1679676395.542 [DataOverHttps](INFO): Sending 479 bytes from file Logs/20230324T164339/Express0001.lzma
2023-03-24T16:46:36.543Z,1679676396.543 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0001.lzma.bak
2023-03-24T16:46:36.543Z,1679676396.543 [DataOverHttps](INFO): SBD MOMSN=17548014
2023-03-24T16:46:55.741Z,1679676415.741 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230324T164339/Express0004.lzma
2023-03-24T16:46:56.743Z,1679676416.743 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0004.lzma.bak
2023-03-24T16:46:56.743Z,1679676416.743 [DataOverHttps](INFO): SBD MOMSN=17548019
2023-03-24T16:47:01.127Z,1679676421.127 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T16:47:01.128Z,1679676421.128 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T16:47:01.128Z,1679676421.128 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T16:47:40.327Z,1679676460.327 [NAL9602](INFO): SBD MO Status=2, MOMSN=14711, MT Status=2, MTMSN=0
2023-03-24T16:47:40.327Z,1679676460.327 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T16:48:09.375Z,1679676489.375 [NAL9602](INFO): SBD MO Status=1, MOMSN=14711, MT Status=0, MTMSN=0
2023-03-24T16:48:09.376Z,1679676489.376 [NAL9602](INFO): No messages in MT queue
2023-03-24T16:48:40.083Z,1679676520.083 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T16:50:52.600Z,1679676652.600 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-03-24T16:52:01.703Z,1679676721.703 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T16:52:01.703Z,1679676721.703 [Default:CheckIn:C.Wait] Stopped
2023-03-24T16:52:01.703Z,1679676721.703 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T16:52:01.704Z,1679676721.704 [Default:CheckIn:D] Running Loop=1
2023-03-24T16:52:02.103Z,1679676722.103 [Default:CheckIn:D] Stopped
2023-03-24T16:52:02.103Z,1679676722.103 [Default:CheckIn:E] Running Loop=1
2023-03-24T16:52:02.536Z,1679676722.536 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.287642 min 
2023-03-24T16:52:02.536Z,1679676722.536 [Default:CheckIn:E] Stopped
2023-03-24T16:52:02.536Z,1679676722.536 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T16:52:02.536Z,1679676722.536 [Default:CheckIn] Stopped
2023-03-24T16:52:02.536Z,1679676722.536 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T16:52:02.537Z,1679676722.537 [Default:CheckIn](INFO): Running loop #9
2023-03-24T16:52:02.537Z,1679676722.537 [Default:CheckIn] Running Loop=9
2023-03-24T16:52:02.537Z,1679676722.537 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T16:52:02.537Z,1679676722.537 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T16:52:04.518Z,1679676724.518 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165203.00,A,3648.48794,N,12147.12051,W,4.704,163.86,240323,,,D*7A
2023-03-24T16:52:04.521Z,1679676724.521 [NAL9602](INFO): GPS fix at 20230324T165203: (36.808132, -121.785342)
2023-03-24T16:52:04.573Z,1679676724.573 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T16:52:04.573Z,1679676724.573 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T16:52:07.219Z,1679676727.219 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T164339/Courier0006.lzma
2023-03-24T16:52:08.223Z,1679676728.223 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0006.lzma.bak
2023-03-24T16:52:08.223Z,1679676728.223 [DataOverHttps](INFO): SBD MOMSN=17548030
2023-03-24T16:52:27.605Z,1679676747.605 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20230324T164339/Express0007.lzma
2023-03-24T16:52:28.603Z,1679676748.603 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0007.lzma.bak
2023-03-24T16:52:28.603Z,1679676748.603 [DataOverHttps](INFO): SBD MOMSN=17548033
2023-03-24T16:52:33.286Z,1679676753.286 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T16:52:33.286Z,1679676753.286 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T16:52:33.286Z,1679676753.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T16:54:16.687Z,1679676856.687 [NAL9602](INFO): SBD MO Status=2, MOMSN=14712, MT Status=2, MTMSN=0
2023-03-24T16:54:16.687Z,1679676856.687 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T16:54:57.896Z,1679676897.896 [NAL9602](INFO): SBD MO Status=2, MOMSN=14712, MT Status=2, MTMSN=0
2023-03-24T16:54:57.896Z,1679676897.896 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T16:55:18.922Z,1679676918.922 [NAL9602](INFO): SBD MO Status=2, MOMSN=14712, MT Status=2, MTMSN=0
2023-03-24T16:55:18.922Z,1679676918.922 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T16:56:22.812Z,1679676982.812 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-24T16:56:22.813Z,1679676982.813 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2023-03-24T16:56:40.994Z,1679677000.994 [DVL_micro](ERROR): only read 0 of 4 data items
2023-03-24T16:56:40.995Z,1679677000.995 [DVL_micro](ERROR): Failed to parse:
:RD,,+9999.99,+9999.99,+9999.99
2023-03-24T16:57:06.449Z,1679677026.449 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-24T16:57:33.923Z,1679677053.923 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T16:57:33.923Z,1679677053.923 [Default:CheckIn:C.Wait] Stopped
2023-03-24T16:57:33.923Z,1679677053.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T16:57:33.924Z,1679677053.924 [Default:CheckIn:D] Running Loop=1
2023-03-24T16:57:34.333Z,1679677054.333 [Default:CheckIn:D] Stopped
2023-03-24T16:57:34.333Z,1679677054.333 [Default:CheckIn:E] Running Loop=1
2023-03-24T16:57:34.758Z,1679677054.758 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.824805 min 
2023-03-24T16:57:34.758Z,1679677054.758 [Default:CheckIn:E] Stopped
2023-03-24T16:57:34.758Z,1679677054.758 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T16:57:34.758Z,1679677054.758 [Default:CheckIn] Stopped
2023-03-24T16:57:34.758Z,1679677054.758 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T16:57:34.758Z,1679677054.758 [Default:CheckIn](INFO): Running loop #10
2023-03-24T16:57:34.759Z,1679677054.759 [Default:CheckIn] Running Loop=10
2023-03-24T16:57:34.759Z,1679677054.759 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T16:57:34.759Z,1679677054.759 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T16:57:36.736Z,1679677056.736 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165736.00,A,3648.13843,N,12147.20382,W,0.019,219.10,240323,,,D*70
2023-03-24T16:57:36.738Z,1679677056.738 [NAL9602](INFO): GPS fix at 20230324T165736: (36.802307, -121.786730)
2023-03-24T16:57:36.750Z,1679677056.750 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T16:57:36.750Z,1679677056.750 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T16:57:49.273Z,1679677069.273 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230324T164339/Courier0009.lzma
2023-03-24T16:57:50.275Z,1679677070.275 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0009.lzma.bak
2023-03-24T16:57:50.275Z,1679677070.275 [DataOverHttps](INFO): SBD MOMSN=17548043
2023-03-24T16:58:09.207Z,1679677089.207 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T16:58:19.303Z,1679677099.303 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20230324T164339/Express0010.lzma
2023-03-24T16:58:20.303Z,1679677100.303 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0010.lzma.bak
2023-03-24T16:58:20.303Z,1679677100.303 [DataOverHttps](INFO): SBD MOMSN=17548046
2023-03-24T16:58:25.014Z,1679677105.014 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T16:58:25.015Z,1679677105.015 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T16:58:25.015Z,1679677105.015 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T16:58:54.114Z,1679677134.114 [DVL_micro](ERROR): Failed to parse:
:SA,+00.59,-06.31,193.9
2023-03-24T17:01:42.569Z,1679677302.569 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-24T17:01:42.569Z,1679677302.569 [DVL_micro](ERROR): Failed to parse:
:BI,-00009,-00030,-0000,I
2023-03-24T17:02:03.213Z,1679677323.213 [DVL_micro](ERROR): DVL uart error: serial timeout
2023-03-24T17:02:03.213Z,1679677323.213 [DVL_micro] Communications Fault, FailCount= 1
2023-03-24T17:02:03.213Z,1679677323.213 [DVL_micro](ERROR): Communications Fault
2023-03-24T17:02:03.214Z,1679677323.214 [DVL_micro](ERROR): Failed to parse:
2023-03-24T17:02:03.241Z,1679677323.241 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-24T17:02:03.626Z,1679677323.626 [DVL_micro](INFO): Powering down
2023-03-24T17:02:04.378Z,1679677324.378 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-24T17:02:04.378Z,1679677324.378 [DVL_micro] No Fault, FailCount= 1
2023-03-24T17:03:25.586Z,1679677405.586 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:03:25.586Z,1679677405.586 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:03:25.586Z,1679677405.586 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:03:25.586Z,1679677405.586 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:03:25.991Z,1679677405.991 [Default:CheckIn:D] Stopped
2023-03-24T17:03:25.991Z,1679677405.991 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:03:26.403Z,1679677406.403 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.685775 min 
2023-03-24T17:03:26.403Z,1679677406.403 [Default:CheckIn:E] Stopped
2023-03-24T17:03:26.403Z,1679677406.403 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:03:26.404Z,1679677406.404 [Default:CheckIn] Stopped
2023-03-24T17:03:26.404Z,1679677406.404 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:03:26.404Z,1679677406.404 [Default:CheckIn](INFO): Running loop #11
2023-03-24T17:03:26.404Z,1679677406.404 [Default:CheckIn] Running Loop=11
2023-03-24T17:03:26.404Z,1679677406.404 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:03:26.404Z,1679677406.404 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:03:28.393Z,1679677408.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170327.00,A,3648.14118,N,12147.20914,W,0.000,10.54,240323,,,D*46
2023-03-24T17:03:28.395Z,1679677408.395 [NAL9602](INFO): GPS fix at 20230324T170327: (36.802353, -121.786819)
2023-03-24T17:03:28.427Z,1679677408.427 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:03:28.427Z,1679677408.427 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:03:37.969Z,1679677417.969 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T164339/Courier0012.lzma
2023-03-24T17:03:38.971Z,1679677418.971 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0012.lzma.bak
2023-03-24T17:03:38.971Z,1679677418.971 [DataOverHttps](INFO): SBD MOMSN=17548056
2023-03-24T17:03:59.123Z,1679677439.123 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-24T17:03:59.205Z,1679677439.205 [NAL9602](ERROR): received: 
+CSQ:0

OK712, 2, 0, 0, 0

OK
2023-03-24T17:04:03.565Z,1679677443.565 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230324T164339/Express0013.lzma
2023-03-24T17:04:04.567Z,1679677444.567 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0013.lzma.bak
2023-03-24T17:04:04.567Z,1679677444.567 [DataOverHttps](INFO): SBD MOMSN=17548062
2023-03-24T17:04:09.280Z,1679677449.280 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:04:09.281Z,1679677449.281 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:04:09.281Z,1679677449.281 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:04:40.440Z,1679677480.440 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-24T17:04:40.440Z,1679677480.440 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000001.0,1489.0,000
2023-03-24T17:05:03.384Z,1679677503.384 [NAL9602](INFO): SBD MO Status=2, MOMSN=14712, MT Status=2, MTMSN=0
2023-03-24T17:05:03.384Z,1679677503.384 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T17:06:25.380Z,1679677585.380 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 6.
2023-03-24T17:06:25.383Z,1679677585.383 [BPC1](INFO): Received data from all battery sticks.
2023-03-24T17:07:30.815Z,1679677650.815 [NAL9602](INFO): SBD MO Status=1, MOMSN=14712, MT Status=0, MTMSN=0
2023-03-24T17:07:30.815Z,1679677650.815 [NAL9602](INFO): No messages in MT queue
2023-03-24T17:08:01.527Z,1679677681.527 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T17:09:09.811Z,1679677749.811 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:09:09.811Z,1679677749.811 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:09:09.811Z,1679677749.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:09:09.811Z,1679677749.811 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:09:10.218Z,1679677750.218 [Default:CheckIn:D] Stopped
2023-03-24T17:09:10.218Z,1679677750.218 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.422884 min 
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn:E] Stopped
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn] Stopped
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn](INFO): Running loop #12
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn] Running Loop=12
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:09:10.619Z,1679677750.619 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:09:12.629Z,1679677752.629 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170911.00,A,3648.14056,N,12147.20995,W,0.117,10.54,240323,,,D*4C
2023-03-24T17:09:12.631Z,1679677752.631 [NAL9602](INFO): GPS fix at 20230324T170911: (36.802343, -121.786833)
2023-03-24T17:09:12.643Z,1679677752.643 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:09:12.643Z,1679677752.643 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:09:21.649Z,1679677761.649 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230324T164339/Courier0015.lzma
2023-03-24T17:09:22.651Z,1679677762.651 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0015.lzma.bak
2023-03-24T17:09:22.651Z,1679677762.651 [DataOverHttps](INFO): SBD MOMSN=17548096
2023-03-24T17:09:42.037Z,1679677782.037 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230324T164339/Express0016.lzma
2023-03-24T17:09:43.040Z,1679677783.040 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0016.lzma.bak
2023-03-24T17:09:43.040Z,1679677783.040 [DataOverHttps](INFO): SBD MOMSN=17548099
2023-03-24T17:09:50.397Z,1679677790.397 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:09:50.397Z,1679677790.397 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:09:50.409Z,1679677790.409 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:12:06.505Z,1679677926.505 [DVL_micro](ERROR): Failed to parse:
:WI,-00046,-00012,-00227,+00000,A
2023-03-24T17:14:15.379Z,1679678055.379 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-24T17:14:46.083Z,1679678086.083 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T17:14:50.965Z,1679678090.965 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:14:50.965Z,1679678090.965 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:14:50.969Z,1679678090.969 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:14:50.970Z,1679678090.970 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:14:51.380Z,1679678091.380 [Default:CheckIn:D] Stopped
2023-03-24T17:14:51.380Z,1679678091.380 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:14:51.801Z,1679678091.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.108919 min 
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn:E] Stopped
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn] Stopped
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn](INFO): Running loop #13
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn] Running Loop=13
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:14:51.802Z,1679678091.802 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:14:53.769Z,1679678093.769 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171453.00,A,3648.14074,N,12147.20840,W,0.447,221.05,240323,,,D*7B
2023-03-24T17:14:53.771Z,1679678093.771 [NAL9602](INFO): GPS fix at 20230324T171453: (36.802346, -121.786807)
2023-03-24T17:14:53.795Z,1679678093.795 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:14:53.795Z,1679678093.795 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:14:56.775Z,1679678096.775 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230324T164339/Courier0018.lzma
2023-03-24T17:14:57.796Z,1679678097.796 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0018.lzma.bak
2023-03-24T17:14:57.797Z,1679678097.797 [DataOverHttps](INFO): SBD MOMSN=17548116
2023-03-24T17:15:17.297Z,1679678117.297 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230324T164339/Express0019.lzma
2023-03-24T17:15:18.299Z,1679678118.299 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0019.lzma.bak
2023-03-24T17:15:18.299Z,1679678118.299 [DataOverHttps](INFO): SBD MOMSN=17548121
2023-03-24T17:15:22.929Z,1679678122.929 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:15:22.933Z,1679678122.933 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:15:22.933Z,1679678122.933 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:15:38.627Z,1679678138.627 [NAL9602](INFO): SBD MO Status=2, MOMSN=14713, MT Status=2, MTMSN=0
2023-03-24T17:15:38.627Z,1679678138.627 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T17:16:12.572Z,1679678172.572 [DVL_micro](ERROR): Failed to parse:
:R99,+9999.99,+9999.99,+9999.99
2023-03-24T17:16:42.459Z,1679678202.459 [NAL9602](INFO): SBD MO Status=2, MOMSN=14713, MT Status=2, MTMSN=0
2023-03-24T17:16:42.460Z,1679678202.460 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-03-24T17:17:09.129Z,1679678229.129 [DVL_micro](ERROR): only read 2 of 4 data items
2023-03-24T17:17:09.129Z,1679678229.129 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,++9999.99
2023-03-24T17:19:56.499Z,1679678396.499 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-24T17:20:18.788Z,1679678418.788 [DVL_micro](ERROR): Failed to parse:
0000000000,35.0,+12.4,0000.0,1489.0,000
2023-03-24T17:20:23.657Z,1679678423.657 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:20:23.657Z,1679678423.657 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:20:23.657Z,1679678423.657 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:20:23.658Z,1679678423.658 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:20:24.044Z,1679678424.044 [Default:CheckIn:D] Stopped
2023-03-24T17:20:24.044Z,1679678424.044 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:20:24.426Z,1679678424.426 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.653320 min 
2023-03-24T17:20:24.426Z,1679678424.426 [Default:CheckIn:E] Stopped
2023-03-24T17:20:24.427Z,1679678424.427 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:20:24.427Z,1679678424.427 [Default:CheckIn] Stopped
2023-03-24T17:20:24.427Z,1679678424.427 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:20:24.427Z,1679678424.427 [Default:CheckIn](INFO): Running loop #14
2023-03-24T17:20:24.427Z,1679678424.427 [Default:CheckIn] Running Loop=14
2023-03-24T17:20:24.427Z,1679678424.427 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:20:24.427Z,1679678424.427 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:20:26.459Z,1679678426.459 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172025.00,A,3648.16955,N,12147.27735,W,0.156,155.69,240323,,,D*70
2023-03-24T17:20:26.466Z,1679678426.466 [NAL9602](INFO): GPS fix at 20230324T172025: (36.802826, -121.787956)
2023-03-24T17:20:26.511Z,1679678426.511 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:20:26.511Z,1679678426.511 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:20:31.254Z,1679678431.254 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230324T164339/Courier0021.lzma
2023-03-24T17:20:32.259Z,1679678432.259 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0021.lzma.bak
2023-03-24T17:20:32.259Z,1679678432.259 [DataOverHttps](INFO): SBD MOMSN=17548136
2023-03-24T17:20:39.031Z,1679678439.031 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-24T17:20:39.031Z,1679678439.031 [DVL_micro](ERROR): Failed to parse:
:RD,+99999.99,+9999.99,+9999.99
2023-03-24T17:20:51.537Z,1679678451.537 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230324T164339/Express0022.lzma
2023-03-24T17:20:52.539Z,1679678452.539 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0022.lzma.bak
2023-03-24T17:20:52.539Z,1679678452.539 [DataOverHttps](INFO): SBD MOMSN=17548139
2023-03-24T17:20:57.243Z,1679678457.243 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:20:57.243Z,1679678457.243 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:20:57.243Z,1679678457.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:20:58.411Z,1679678458.411 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T17:25:57.927Z,1679678757.927 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:25:57.928Z,1679678757.928 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:25:57.928Z,1679678757.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:25:57.928Z,1679678757.928 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:25:58.348Z,1679678758.348 [Default:CheckIn:D] Stopped
2023-03-24T17:25:58.348Z,1679678758.348 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:25:58.745Z,1679678758.745 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.225057 min 
2023-03-24T17:25:58.745Z,1679678758.745 [Default:CheckIn:E] Stopped
2023-03-24T17:25:58.745Z,1679678758.745 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:25:58.782Z,1679678758.782 [Default:CheckIn] Stopped
2023-03-24T17:25:58.782Z,1679678758.782 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:25:58.782Z,1679678758.782 [Default:CheckIn](INFO): Running loop #15
2023-03-24T17:25:58.782Z,1679678758.782 [Default:CheckIn] Running Loop=15
2023-03-24T17:25:58.783Z,1679678758.783 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:25:58.783Z,1679678758.783 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:26:00.762Z,1679678760.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172600.00,A,3648.16569,N,12147.27968,W,0.097,22.51,240323,,,D*42
2023-03-24T17:26:00.764Z,1679678760.764 [NAL9602](INFO): GPS fix at 20230324T172600: (36.802762, -121.787995)
2023-03-24T17:26:00.797Z,1679678760.797 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:26:00.797Z,1679678760.797 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:26:05.266Z,1679678765.266 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230324T164339/Courier0024.lzma
2023-03-24T17:26:06.271Z,1679678766.271 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0024.lzma.bak
2023-03-24T17:26:06.272Z,1679678766.272 [DataOverHttps](INFO): SBD MOMSN=17548149
2023-03-24T17:26:26.265Z,1679678786.265 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230324T164339/Express0025.lzma
2023-03-24T17:26:27.268Z,1679678787.268 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0025.lzma.bak
2023-03-24T17:26:27.268Z,1679678787.268 [DataOverHttps](INFO): SBD MOMSN=17548153
2023-03-24T17:26:31.480Z,1679678791.480 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-03-24T17:26:31.553Z,1679678791.553 [NAL9602](ERROR): received: 
+CSQ:0

OK713, 2, 0, 0, 0

OK
2023-03-24T17:26:31.936Z,1679678791.936 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:26:31.936Z,1679678791.936 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:26:31.936Z,1679678791.936 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:27:04.219Z,1679678824.219 [DVL_micro](ERROR): Failed to parse:148,+0081,+00000,I
2023-03-24T17:27:17.138Z,1679678837.138 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-24T17:27:17.138Z,1679678837.138 [DVL_micro](ERROR): Failed to parse:
:TS,000000000000+12.6,0000.0,1489.0,000
2023-03-24T17:30:24.689Z,1679679024.689 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-03-24T17:30:24.689Z,1679679024.689 [DVL_micro](ERROR): Failed to parse:
:TS,000000,35.0,00.0,1489.0,000
2023-03-24T17:31:03.482Z,1679679063.482 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-24T17:31:32.583Z,1679679092.583 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:31:32.583Z,1679679092.583 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:31:32.583Z,1679679092.583 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:31:32.583Z,1679679092.583 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:31:32.975Z,1679679092.975 [Default:CheckIn:D] Stopped
2023-03-24T17:31:32.975Z,1679679092.975 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:31:33.391Z,1679679093.391 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.802181 min 
2023-03-24T17:31:33.391Z,1679679093.391 [Default:CheckIn:E] Stopped
2023-03-24T17:31:33.391Z,1679679093.391 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:31:33.392Z,1679679093.392 [Default:CheckIn] Stopped
2023-03-24T17:31:33.392Z,1679679093.392 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:31:33.392Z,1679679093.392 [Default:CheckIn](INFO): Running loop #16
2023-03-24T17:31:33.392Z,1679679093.392 [Default:CheckIn] Running Loop=16
2023-03-24T17:31:33.392Z,1679679093.392 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:31:33.392Z,1679679093.392 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:31:35.384Z,1679679095.384 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173134.00,A,3648.16964,N,12147.28499,W,0.058,22.51,240323,,,D*4D
2023-03-24T17:31:35.386Z,1679679095.386 [NAL9602](INFO): GPS fix at 20230324T173134: (36.802827, -121.788083)
2023-03-24T17:31:35.418Z,1679679095.418 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:31:35.418Z,1679679095.418 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:31:44.673Z,1679679104.673 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T164339/Courier0027.lzma
2023-03-24T17:31:45.676Z,1679679105.676 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0027.lzma.bak
2023-03-24T17:31:45.676Z,1679679105.676 [DataOverHttps](INFO): SBD MOMSN=17548163
2023-03-24T17:32:07.397Z,1679679127.397 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T17:32:10.282Z,1679679130.282 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230324T164339/Express0028.lzma
2023-03-24T17:32:11.283Z,1679679131.283 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0028.lzma.bak
2023-03-24T17:32:11.283Z,1679679131.283 [DataOverHttps](INFO): SBD MOMSN=17548166
2023-03-24T17:32:15.886Z,1679679135.886 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:32:15.887Z,1679679135.887 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:32:15.887Z,1679679135.887 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:35:25.802Z,1679679325.802 [DVL_micro](ERROR): DVL uart error: serial timeout
2023-03-24T17:35:25.802Z,1679679325.802 [DVL_micro] Communications Fault, FailCount= 1
2023-03-24T17:35:25.802Z,1679679325.802 [DVL_micro](ERROR): Communications Fault
2023-03-24T17:35:25.802Z,1679679325.802 [DVL_micro](ERROR): Failed to parse:
2023-03-24T17:35:25.834Z,1679679325.834 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-03-24T17:35:26.206Z,1679679326.206 [DVL_micro](INFO): Powering down
2023-03-24T17:35:26.998Z,1679679326.998 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-03-24T17:35:26.998Z,1679679326.998 [DVL_micro] No Fault, FailCount= 1
2023-03-24T17:37:09.968Z,1679679429.968 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-24T17:37:09.969Z,1679679429.969 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.999,+9999.99,+9999.99
2023-03-24T17:37:16.443Z,1679679436.443 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:37:16.443Z,1679679436.443 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:37:16.443Z,1679679436.443 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:37:16.444Z,1679679436.444 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:37:16.841Z,1679679436.841 [Default:CheckIn:D] Stopped
2023-03-24T17:37:16.842Z,1679679436.842 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:37:17.257Z,1679679437.257 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.533285 min 
2023-03-24T17:37:17.257Z,1679679437.257 [Default:CheckIn:E] Stopped
2023-03-24T17:37:17.258Z,1679679437.258 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:37:17.258Z,1679679437.258 [Default:CheckIn] Stopped
2023-03-24T17:37:17.258Z,1679679437.258 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:37:17.258Z,1679679437.258 [Default:CheckIn](INFO): Running loop #17
2023-03-24T17:37:17.258Z,1679679437.258 [Default:CheckIn] Running Loop=17
2023-03-24T17:37:17.258Z,1679679437.258 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:37:17.258Z,1679679437.258 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:37:19.256Z,1679679439.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173718.00,A,3648.16634,N,12147.28165,W,0.097,78.41,240323,,,D*44
2023-03-24T17:37:19.259Z,1679679439.259 [NAL9602](INFO): GPS fix at 20230324T173718: (36.802772, -121.788027)
2023-03-24T17:37:19.270Z,1679679439.270 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:37:19.270Z,1679679439.270 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:37:28.493Z,1679679448.493 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T164339/Courier0030.lzma
2023-03-24T17:37:29.495Z,1679679449.495 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0030.lzma.bak
2023-03-24T17:37:29.495Z,1679679449.495 [DataOverHttps](INFO): SBD MOMSN=17548179
2023-03-24T17:37:53.717Z,1679679473.717 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230324T164339/Express0031.lzma
2023-03-24T17:37:54.719Z,1679679474.719 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0031.lzma.bak
2023-03-24T17:37:54.719Z,1679679474.719 [DataOverHttps](INFO): SBD MOMSN=17548182
2023-03-24T17:37:58.929Z,1679679478.929 [DVL_micro](ERROR): Failed to parse:
:WI,+00037,-00213,-00034,+

2023-03-24T17:38:00.969Z,1679679480.969 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:38:00.969Z,1679679480.969 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:38:00.969Z,1679679480.969 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:38:40.128Z,1679679520.128 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-24T17:38:40.128Z,1679679520.128 [DVL_micro](ERROR): Failed to parse:
:BI,-00073,-00012,-00051,+00000+00000000.00,+00000000.00,0.00,9999.99,000.00
2023-03-24T17:39:57.350Z,1679679597.350 [DAT](INFO): DAT read: Acoustic Wakeup

2023-03-24T17:39:57.351Z,1679679597.351 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup

2023-03-24T17:39:57.352Z,1679679597.352 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-03-24T17:39:57.352Z,1679679597.352 [DAT](INFO): commRate: 800
2023-03-24T17:39:58.110Z,1679679598.110 [DAT](INFO): DAT read: Lowpower

2023-03-24T17:39:58.111Z,1679679598.111 [DAT](INFO): unknown deviceResponse_: Lowpower

2023-03-24T17:42:15.188Z,1679679735.188 [DVL_micro](ERROR): only read 3 of 4 data items
2023-03-24T17:42:15.188Z,1679679735.188 [DVL_micro](ERROR): Failed to parse:
:BI,+00144,+0206,+00000,I
2023-03-24T17:42:21.606Z,1679679741.606 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-03-24T17:42:52.311Z,1679679772.311 [NAL9602](INFO): Not Powering down - fast GPS
2023-03-24T17:43:01.660Z,1679679781.660 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-03-24T17:43:01.660Z,1679679781.660 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:43:01.660Z,1679679781.660 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:43:01.660Z,1679679781.660 [Default:CheckIn:D] Running Loop=1
2023-03-24T17:43:02.035Z,1679679782.035 [Default:CheckIn:D] Stopped
2023-03-24T17:43:02.035Z,1679679782.035 [Default:CheckIn:E] Running Loop=1
2023-03-24T17:43:02.438Z,1679679782.438 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.286507 min 
2023-03-24T17:43:02.438Z,1679679782.438 [Default:CheckIn:E] Stopped
2023-03-24T17:43:02.439Z,1679679782.439 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-03-24T17:43:02.439Z,1679679782.439 [Default:CheckIn] Stopped
2023-03-24T17:43:02.439Z,1679679782.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:43:02.439Z,1679679782.439 [Default:CheckIn](INFO): Running loop #18
2023-03-24T17:43:02.439Z,1679679782.439 [Default:CheckIn] Running Loop=18
2023-03-24T17:43:02.439Z,1679679782.439 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-03-24T17:43:02.439Z,1679679782.439 [Default:CheckIn:Read_GPS] Running Loop=1
2023-03-24T17:43:04.441Z,1679679784.441 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174303.00,A,3648.16616,N,12147.27869,W,0.369,100.88,240323,,,D*7E
2023-03-24T17:43:04.443Z,1679679784.443 [NAL9602](INFO): GPS fix at 20230324T174303: (36.802769, -121.787978)
2023-03-24T17:43:04.475Z,1679679784.475 [Default:CheckIn:Read_GPS] Stopped
2023-03-24T17:43:04.475Z,1679679784.475 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-03-24T17:43:13.757Z,1679679793.757 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230324T164339/Courier0033.lzma
2023-03-24T17:43:14.759Z,1679679794.759 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Courier0033.lzma.bak
2023-03-24T17:43:14.759Z,1679679794.759 [DataOverHttps](INFO): SBD MOMSN=17548192
2023-03-24T17:43:20.209Z,1679679800.209 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2023-03-24T17:43:20.209Z,1679679800.209 [DropWeight] Hardware Fault, FailCount= 1
2023-03-24T17:43:20.209Z,1679679800.209 [DropWeight](ERROR): Hardware Fault
2023-03-24T17:43:20.244Z,1679679800.244 [CommandExec](FAULT): Scheduling is paused
2023-03-24T17:43:20.245Z,1679679800.245 [CBIT](INFO): Critical error at 20230324T174320
2023-03-24T17:43:20.251Z,1679679800.251 [CBIT](ERROR): Hardware Fault in component: DropWeight
2023-03-24T17:43:20.252Z,1679679800.252 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2023-03-24T17:43:20.618Z,1679679800.618 [CBIT](INFO): Critical error at 20230324T174320
2023-03-24T17:43:34.385Z,1679679814.385 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230324T164339/Express0034.lzma
2023-03-24T17:43:35.387Z,1679679815.387 [DataOverHttps](INFO): Moved sent file to Logs/20230324T164339/Express0034.lzma.bak
2023-03-24T17:43:35.387Z,1679679815.387 [DataOverHttps](INFO): SBD MOMSN=17548195
2023-03-24T17:43:40.064Z,1679679820.064 [Default:CheckIn:Read_Iridium] Stopped
2023-03-24T17:43:40.064Z,1679679820.064 [Default:CheckIn:C.Wait] Running Loop=1
2023-03-24T17:43:40.064Z,1679679820.064 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-03-24T17:47:05.734Z,1679680025.734 [CommandExec](IMPORTANT): got command quit
2023-03-24T17:47:06.737Z,1679680026.737 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:06.738Z,1679680026.738 [CommandExec](INFO): Uninitializing the command executive.
2023-03-24T17:47:06.738Z,1679680026.738 [CommandExec](INFO): Uninitializing the command scheduler.
2023-03-24T17:47:06.738Z,1679680026.738 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:06.937Z,1679680026.937 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-03-24T17:47:06.937Z,1679680026.937 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-03-24T17:47:06.938Z,1679680026.938 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:06.938Z,1679680026.938 [NavChartDb](INFO): Join timeout helper Thread ID is 6458
2023-03-24T17:47:06.970Z,1679680026.970 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:06.970Z,1679680026.970 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:06.978Z,1679680026.978 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-03-24T17:47:06.978Z,1679680026.978 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:06.978Z,1679680026.978 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6459
2023-03-24T17:47:07.398Z,1679680027.398 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:07.398Z,1679680027.398 [WetLabsBB2FL](INFO): Powering down
2023-03-24T17:47:07.399Z,1679680027.399 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:07.417Z,1679680027.417 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-03-24T17:47:07.417Z,1679680027.417 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:07.418Z,1679680027.418 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6460
2023-03-24T17:47:07.621Z,1679680027.621 [CTD_Seabird](INFO): Powering down
2023-03-24T17:47:07.634Z,1679680027.634 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:07.634Z,1679680027.634 [CTD_Seabird](INFO): Powering down
2023-03-24T17:47:07.657Z,1679680027.657 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:07.658Z,1679680027.658 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-03-24T17:47:07.658Z,1679680027.658 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:07.658Z,1679680027.658 [DAT](INFO): Join timeout helper Thread ID is 6461
2023-03-24T17:47:07.813Z,1679680027.813 [DAT](INFO): Powering down
2023-03-24T17:47:07.886Z,1679680027.886 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:07.886Z,1679680027.886 [DAT](INFO): Powering down
2023-03-24T17:47:07.887Z,1679680027.887 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:07.905Z,1679680027.905 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-03-24T17:47:07.905Z,1679680027.905 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:07.906Z,1679680027.906 [Radio_Surface](INFO): Join timeout helper Thread ID is 6462
2023-03-24T17:47:08.225Z,1679680028.225 [Radio_Surface](INFO): Powering down
2023-03-24T17:47:08.226Z,1679680028.226 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:08.227Z,1679680028.227 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:08.228Z,1679680028.228 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-03-24T17:47:08.228Z,1679680028.228 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:08.229Z,1679680028.229 [Onboard](INFO): Join timeout helper Thread ID is 6463
2023-03-24T17:47:08.282Z,1679680028.282 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-03-24T17:47:10.354Z,1679680030.354 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:10.354Z,1679680030.354 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:10.362Z,1679680030.362 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-03-24T17:47:10.362Z,1679680030.362 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:10.362Z,1679680030.362 [DataOverHttps](INFO): Join timeout helper Thread ID is 6464
2023-03-24T17:47:11.293Z,1679680031.293 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:11.294Z,1679680031.294 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.302Z,1679680031.302 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-03-24T17:47:11.302Z,1679680031.302 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.302Z,1679680031.302 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:11.303Z,1679680031.303 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.305Z,1679680031.305 [BackseatComponent](INFO): Join timeout helper Thread ID is 6465
2023-03-24T17:47:11.307Z,1679680031.307 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-03-24T17:47:11.307Z,1679680031.307 [logger ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.307Z,1679680031.307 [logger](INFO): Join timeout helper Thread ID is 6466
2023-03-24T17:47:11.351Z,1679680031.351 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:11.352Z,1679680031.352 [logger ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.366Z,1679680031.366 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-03-24T17:47:11.366Z,1679680031.366 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.367Z,1679680031.367 [CommandLine](INFO): Join timeout helper Thread ID is 6467
2023-03-24T17:47:11.442Z,1679680031.442 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:11.442Z,1679680031.442 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.450Z,1679680031.450 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-03-24T17:47:11.450Z,1679680031.450 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.450Z,1679680031.450 [CommandExec](INFO): Join timeout helper Thread ID is 6468
2023-03-24T17:47:11.452Z,1679680031.452 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-03-24T17:47:11.452Z,1679680031.452 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.452Z,1679680031.452 [controlThread](INFO): Join timeout helper Thread ID is 6469
2023-03-24T17:47:11.685Z,1679680031.685 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-03-24T17:47:11.686Z,1679680031.686 [controlThread](DEBUG): Uninitializing ControlThread
2023-03-24T17:47:11.686Z,1679680031.686 [AHRS_M2](INFO): Powering down
2023-03-24T17:47:11.829Z,1679680031.829 [DVL_micro](INFO): Powering down
2023-03-24T17:47:11.830Z,1679680031.830 [MultiRay](INFO): Powering down.
2023-03-24T17:47:11.831Z,1679680031.831 [NAL9602](INFO): Powering down
2023-03-24T17:47:11.834Z,1679680031.834 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-03-24T17:47:11.835Z,1679680031.835 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-03-24T17:47:11.836Z,1679680031.836 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-03-24T17:47:11.836Z,1679680031.836 [MissionManager](INFO): Uninitializing Mission Default
2023-03-24T17:47:11.836Z,1679680031.836 [Default] Stopped
2023-03-24T17:47:11.837Z,1679680031.837 [Default](DEBUG): Aggregate::uninitialize Default
2023-03-24T17:47:11.837Z,1679680031.837 [Default:B.GoToSurface] Stopped
2023-03-24T17:47:11.837Z,1679680031.837 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-03-24T17:47:11.837Z,1679680031.837 [Default:CheckIn] Stopped
2023-03-24T17:47:11.837Z,1679680031.837 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-03-24T17:47:11.837Z,1679680031.837 [Default:CheckIn:C.Wait] Stopped
2023-03-24T17:47:11.837Z,1679680031.837 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-03-24T17:47:11.840Z,1679680031.840 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-03-24T17:47:11.840Z,1679680031.840 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-03-24T17:47:11.840Z,1679680031.840 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-03-24T17:47:11.841Z,1679680031.841 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-03-24T17:47:11.841Z,1679680031.841 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-03-24T17:47:11.841Z,1679680031.841 [BuoyancyServo](INFO): Powering down
2023-03-24T17:47:11.853Z,1679680031.853 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-03-24T17:47:11.854Z,1679680031.854 [ElevatorServo](INFO): Powering down
2023-03-24T17:47:11.854Z,1679680031.854 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-03-24T17:47:11.855Z,1679680031.855 [MassServo](INFO): Powering down
2023-03-24T17:47:11.855Z,1679680031.855 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-03-24T17:47:11.855Z,1679680031.855 [RudderServo](INFO): Powering down
2023-03-24T17:47:11.856Z,1679680031.856 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-03-24T17:47:11.856Z,1679680031.856 [ThrusterHE](INFO): Powering down
2023-03-24T17:47:11.857Z,1679680031.857 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-03-24T17:47:11.858Z,1679680031.858 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-03-24T17:47:11.858Z,1679680031.858 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-03-24T17:47:11.858Z,1679680031.858 [CBIT](DEBUG): Powering off loads.
2023-03-24T17:47:11.869Z,1679680031.869 [CBIT](DEBUG): Disabling WDT.
2023-03-24T17:47:11.881Z,1679680031.881 [CBIT](DEBUG): Opening all GF detection circuits.
2023-03-24T17:47:11.882Z,1679680031.882 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.934Z,1679680031.934 [DAT ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.939Z,1679680031.939 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.941Z,1679680031.941 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.950Z,1679680031.950 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:11.992Z,1679680031.992 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:12.051Z,1679680032.051 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:12.139Z,1679680032.139 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:12.165Z,1679680032.165 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-03-24T17:47:12.229Z,1679680032.229 [logger ThreadHandler](INFO): Thread cancelled.