2023-03-28T20:14:44.361Z,1680034484.361 [CommandExec](IMPORTANT): got command restart logs 2023-03-28T20:17:25.563Z,1680034645.563 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:17:25.563Z,1680034645.563 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:17:25.563Z,1680034645.563 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:17:25.563Z,1680034645.563 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:17:25.977Z,1680034645.977 [Default:CheckIn:D] Stopped 2023-03-28T20:17:25.977Z,1680034645.977 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:17:26.370Z,1680034646.370 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 183.451335 min 2023-03-28T20:17:26.370Z,1680034646.370 [Default:CheckIn:E] Stopped 2023-03-28T20:17:26.370Z,1680034646.370 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:17:26.370Z,1680034646.370 [Default:CheckIn] Stopped 2023-03-28T20:17:26.370Z,1680034646.370 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:17:26.370Z,1680034646.370 [Default:CheckIn](INFO): Running loop #34 2023-03-28T20:17:26.370Z,1680034646.370 [Default:CheckIn] Running Loop=34 2023-03-28T20:17:26.371Z,1680034646.371 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:17:26.371Z,1680034646.371 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:17:28.380Z,1680034648.380 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201727.00,A,3648.17683,N,12147.28592,W,0.078,0.00,280323,,,D*78 2023-03-28T20:17:28.382Z,1680034648.382 [NAL9602](INFO): GPS fix at 20230328T201727: (36.802947, -121.788099) 2023-03-28T20:17:28.393Z,1680034648.393 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:17:28.393Z,1680034648.393 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:17:39.255Z,1680034659.255 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230328T174318/Courier0081.lzma 2023-03-28T20:17:40.262Z,1680034660.262 [DataOverHttps](INFO): Moved sent file to Logs/20230328T174318/Courier0081.lzma.bak 2023-03-28T20:17:40.262Z,1680034660.262 [DataOverHttps](INFO): SBD MOMSN=17734295 2023-03-28T20:17:56.768Z,1680034676.768 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20230328T201444/Courier0000.lzma 2023-03-28T20:17:57.770Z,1680034677.770 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0000.lzma.bak 2023-03-28T20:17:57.770Z,1680034677.770 [DataOverHttps](INFO): SBD MOMSN=17734298 2023-03-28T20:18:00.446Z,1680034680.446 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T20:18:14.167Z,1680034694.167 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T174318/Express0082.lzma 2023-03-28T20:18:15.170Z,1680034695.170 [DataOverHttps](INFO): Moved sent file to Logs/20230328T174318/Express0082.lzma.bak 2023-03-28T20:18:15.170Z,1680034695.170 [DataOverHttps](INFO): SBD MOMSN=17734304 2023-03-28T20:18:20.581Z,1680034700.581 [NAL9602](INFO): SBD MO Status=0, MOMSN=47545, MT Status=0, MTMSN=0 2023-03-28T20:18:20.581Z,1680034700.581 [NAL9602](INFO): No messages in MT queue 2023-03-28T20:18:25.815Z,1680034705.815 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T20:18:25.815Z,1680034705.815 [DVL_micro](ERROR): Failed to parse: :TS,000000000000+10.3,0000.0,1489.0,000 2023-03-28T20:18:31.117Z,1680034711.117 [DataOverHttps](INFO): Sending 384 bytes from file Logs/20230328T201444/Express0001.lzma 2023-03-28T20:18:32.118Z,1680034712.118 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0001.lzma.bak 2023-03-28T20:18:32.118Z,1680034712.118 [DataOverHttps](INFO): SBD MOMSN=17734310 2023-03-28T20:18:33.528Z,1680034713.528 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:18:33.528Z,1680034713.528 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:18:33.528Z,1680034713.528 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:18:51.325Z,1680034731.325 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T20:18:51.347Z,1680034731.347 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:22:37.262Z,1680034957.262 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T20:22:37.262Z,1680034957.262 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2023-03-28T20:23:34.226Z,1680035014.226 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:23:34.226Z,1680035014.226 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:23:34.226Z,1680035014.226 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:23:34.226Z,1680035014.226 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:23:34.632Z,1680035014.632 [Default:CheckIn:D] Stopped 2023-03-28T20:23:34.632Z,1680035014.632 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:23:35.055Z,1680035015.055 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 189.595573 min 2023-03-28T20:23:35.055Z,1680035015.055 [Default:CheckIn:E] Stopped 2023-03-28T20:23:35.055Z,1680035015.055 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:23:35.055Z,1680035015.055 [Default:CheckIn] Stopped 2023-03-28T20:23:35.055Z,1680035015.055 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:23:35.056Z,1680035015.056 [Default:CheckIn](INFO): Running loop #35 2023-03-28T20:23:35.056Z,1680035015.056 [Default:CheckIn] Running Loop=35 2023-03-28T20:23:35.056Z,1680035015.056 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:23:35.056Z,1680035015.056 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:23:37.051Z,1680035017.051 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202336.00,A,3648.17647,N,12147.28437,W,0.019,0.00,280323,,,D*7E 2023-03-28T20:23:37.054Z,1680035017.054 [NAL9602](INFO): GPS fix at 20230328T202336: (36.802941, -121.788073) 2023-03-28T20:23:37.075Z,1680035017.075 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:23:37.075Z,1680035017.075 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:23:40.121Z,1680035020.121 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:23:46.081Z,1680035026.081 [CBIT](INFO): Clearing failed state for component DropWeight 2023-03-28T20:23:46.081Z,1680035026.081 [DropWeight] No Fault, FailCount= 1 2023-03-28T20:23:46.543Z,1680035026.543 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230328T201444/Courier0003.lzma 2023-03-28T20:23:47.546Z,1680035027.546 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0003.lzma.bak 2023-03-28T20:23:47.546Z,1680035027.546 [DataOverHttps](INFO): SBD MOMSN=17734693 2023-03-28T20:23:54.981Z,1680035034.981 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:24:03.403Z,1680035043.403 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0004.lzma 2023-03-28T20:24:04.406Z,1680035044.406 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0004.lzma.bak 2023-03-28T20:24:04.406Z,1680035044.406 [DataOverHttps](INFO): SBD MOMSN=17734696 2023-03-28T20:24:05.882Z,1680035045.882 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:24:05.882Z,1680035045.882 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:24:05.882Z,1680035045.882 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:27:04.926Z,1680035224.926 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T20:27:11.344Z,1680035231.344 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T20:27:11.345Z,1680035231.345 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+10.4,0000.0,10 2023-03-28T20:27:15.391Z,1680035235.391 [NAL9602](INFO): SBD MO Status=0, MOMSN=47546, MT Status=0, MTMSN=0 2023-03-28T20:27:15.391Z,1680035235.391 [NAL9602](INFO): No messages in MT queue 2023-03-28T20:27:46.088Z,1680035266.088 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T20:27:46.139Z,1680035266.139 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:29:06.500Z,1680035346.500 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:29:06.500Z,1680035346.500 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:29:06.500Z,1680035346.500 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:29:06.500Z,1680035346.500 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:29:06.915Z,1680035346.915 [Default:CheckIn:D] Stopped 2023-03-28T20:29:06.915Z,1680035346.915 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:29:07.307Z,1680035347.307 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 195.133626 min 2023-03-28T20:29:07.307Z,1680035347.307 [Default:CheckIn:E] Stopped 2023-03-28T20:29:07.307Z,1680035347.307 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:29:07.307Z,1680035347.307 [Default:CheckIn] Stopped 2023-03-28T20:29:07.307Z,1680035347.307 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:29:07.308Z,1680035347.308 [Default:CheckIn](INFO): Running loop #36 2023-03-28T20:29:07.308Z,1680035347.308 [Default:CheckIn] Running Loop=36 2023-03-28T20:29:07.308Z,1680035347.308 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:29:07.308Z,1680035347.308 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:29:09.320Z,1680035349.320 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202908.00,A,3648.17687,N,12147.28554,W,0.058,0.00,280323,,,D*74 2023-03-28T20:29:09.322Z,1680035349.322 [NAL9602](INFO): GPS fix at 20230328T202908: (36.802948, -121.788092) 2023-03-28T20:29:09.332Z,1680035349.332 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:29:09.332Z,1680035349.332 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:29:17.343Z,1680035357.343 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230328T201444/Courier0006.lzma 2023-03-28T20:29:17.842Z,1680035357.842 [Reporter](INFO): NAL9602.sigQuality 4 count 2023-03-28T20:29:18.347Z,1680035358.347 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0006.lzma.bak 2023-03-28T20:29:18.347Z,1680035358.347 [DataOverHttps](INFO): SBD MOMSN=17734705 2023-03-28T20:29:34.449Z,1680035374.449 [NAL9602](INFO): SBD MO Status=2, MOMSN=47547, MT Status=2, MTMSN=0 2023-03-28T20:29:34.449Z,1680035374.449 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T20:29:36.439Z,1680035376.439 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0007.lzma 2023-03-28T20:29:37.442Z,1680035377.442 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0007.lzma.bak 2023-03-28T20:29:37.442Z,1680035377.442 [DataOverHttps](INFO): SBD MOMSN=17734708 2023-03-28T20:29:38.913Z,1680035378.913 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:29:38.913Z,1680035378.913 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:29:38.913Z,1680035378.913 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:29:38.957Z,1680035378.957 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:29:50.602Z,1680035390.602 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:29:59.499Z,1680035399.499 [Reporter](INFO): NAL9602.sigQuality 5 count 2023-03-28T20:30:03.899Z,1680035403.899 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T20:30:03.899Z,1680035403.899 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+0.0,1489.0,,-05602,+0731,+00000,05602,+07420,+01431,+00000,I 2023-03-28T20:30:09.958Z,1680035409.958 [NAL9602](INFO): SBD MO Status=0, MOMSN=47547, MT Status=0, MTMSN=0 2023-03-28T20:30:09.958Z,1680035409.958 [NAL9602](INFO): No messages in MT queue 2023-03-28T20:30:40.681Z,1680035440.681 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T20:30:40.703Z,1680035440.703 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:34:39.455Z,1680035679.455 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:34:39.455Z,1680035679.455 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:34:39.455Z,1680035679.455 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:34:39.455Z,1680035679.455 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:34:39.867Z,1680035679.867 [Default:CheckIn:D] Stopped 2023-03-28T20:34:39.867Z,1680035679.867 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 200.682813 min 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn:E] Stopped 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn] Stopped 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn](INFO): Running loop #37 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn] Running Loop=37 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:34:40.321Z,1680035680.321 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:34:42.260Z,1680035682.260 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203441.00,A,3648.17506,N,12147.28238,W,0.039,0.00,280323,,,D*75 2023-03-28T20:34:42.262Z,1680035682.262 [NAL9602](INFO): GPS fix at 20230328T203441: (36.802918, -121.788040) 2023-03-28T20:34:42.273Z,1680035682.273 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:34:42.273Z,1680035682.273 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:34:49.823Z,1680035689.823 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0009.lzma 2023-03-28T20:34:50.827Z,1680035690.827 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0009.lzma.bak 2023-03-28T20:34:50.827Z,1680035690.827 [DataOverHttps](INFO): SBD MOMSN=17735090 2023-03-28T20:35:07.187Z,1680035707.187 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20230328T201444/Express0010.lzma 2023-03-28T20:35:08.190Z,1680035708.190 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0010.lzma.bak 2023-03-28T20:35:08.190Z,1680035708.190 [DataOverHttps](INFO): SBD MOMSN=17735093 2023-03-28T20:35:09.757Z,1680035709.757 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:35:09.757Z,1680035709.757 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:35:09.757Z,1680035709.757 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:35:59.020Z,1680035759.020 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T20:35:59.020Z,1680035759.020 [DVL_micro](ERROR): Failed to parse: :BI,+01150,+00202,-0000,I 2023-03-28T20:36:03.110Z,1680035763.110 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T20:36:21.648Z,1680035781.648 [NAL9602](INFO): SBD MO Status=2, MOMSN=47548, MT Status=2, MTMSN=0 2023-03-28T20:36:21.648Z,1680035781.648 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T20:36:26.143Z,1680035786.143 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:36:37.713Z,1680035797.713 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:38:11.592Z,1680035891.592 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:38:20.491Z,1680035900.491 [Reporter](INFO): NAL9602.sigQuality 3 count 2023-03-28T20:38:22.845Z,1680035902.845 [NAL9602](INFO): SBD MO Status=0, MOMSN=47548, MT Status=0, MTMSN=0 2023-03-28T20:38:22.845Z,1680035902.845 [NAL9602](INFO): No messages in MT queue 2023-03-28T20:38:53.550Z,1680035933.550 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T20:38:53.577Z,1680035933.577 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:39:14.587Z,1680035954.587 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2023-03-28T20:39:20.211Z,1680035960.211 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-03-28T20:39:20.214Z,1680035960.214 [BPC1](INFO): Received data from all battery sticks. 2023-03-28T20:40:10.330Z,1680036010.330 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:40:10.331Z,1680036010.331 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:40:10.331Z,1680036010.331 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:40:10.331Z,1680036010.331 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:40:10.714Z,1680036010.714 [Default:CheckIn:D] Stopped 2023-03-28T20:40:10.714Z,1680036010.714 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 206.196940 min 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn:E] Stopped 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn] Stopped 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn](INFO): Running loop #38 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn] Running Loop=38 2023-03-28T20:40:11.123Z,1680036011.123 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:40:11.124Z,1680036011.124 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:40:13.143Z,1680036013.143 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204012.00,A,3648.17632,N,12147.28455,W,0.078,0.00,280323,,,D*7C 2023-03-28T20:40:13.145Z,1680036013.145 [NAL9602](INFO): GPS fix at 20230328T204012: (36.802939, -121.788076) 2023-03-28T20:40:13.155Z,1680036013.155 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:40:13.155Z,1680036013.155 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:40:17.635Z,1680036017.635 [Reporter](INFO): NAL9602.sigQuality 3 count 2023-03-28T20:40:20.428Z,1680036020.428 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230328T201444/Courier0012.lzma 2023-03-28T20:40:21.429Z,1680036021.429 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0012.lzma.bak 2023-03-28T20:40:21.430Z,1680036021.430 [DataOverHttps](INFO): SBD MOMSN=17735102 2023-03-28T20:40:34.595Z,1680036034.595 [NAL9602](INFO): SBD MO Status=2, MOMSN=47549, MT Status=2, MTMSN=0 2023-03-28T20:40:34.595Z,1680036034.595 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T20:40:39.252Z,1680036039.252 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T20:40:40.384Z,1680036040.384 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20230328T201444/Express0013.lzma 2023-03-28T20:40:41.386Z,1680036041.386 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0013.lzma.bak 2023-03-28T20:40:41.386Z,1680036041.386 [DataOverHttps](INFO): SBD MOMSN=17735105 2023-03-28T20:40:43.143Z,1680036043.143 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:40:43.143Z,1680036043.143 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:40:43.143Z,1680036043.143 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:40:47.935Z,1680036047.935 [NAL9602](INFO): SBD MO Status=2, MOMSN=47549, MT Status=2, MTMSN=0 2023-03-28T20:40:47.935Z,1680036047.935 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T20:40:52.019Z,1680036052.019 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:41:10.218Z,1680036070.218 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:41:32.061Z,1680036092.061 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:44:06.762Z,1680036246.762 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:44:15.261Z,1680036255.261 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:45:15.384Z,1680036315.384 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T20:45:43.679Z,1680036343.679 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:45:43.679Z,1680036343.679 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:45:43.679Z,1680036343.679 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:45:43.679Z,1680036343.679 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:45:44.083Z,1680036344.083 [Default:CheckIn:D] Stopped 2023-03-28T20:45:44.084Z,1680036344.084 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:45:44.495Z,1680036344.495 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 211.753109 min 2023-03-28T20:45:44.496Z,1680036344.496 [Default:CheckIn:E] Stopped 2023-03-28T20:45:44.496Z,1680036344.496 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:45:44.496Z,1680036344.496 [Default:CheckIn] Stopped 2023-03-28T20:45:44.496Z,1680036344.496 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:45:44.496Z,1680036344.496 [Default:CheckIn](INFO): Running loop #39 2023-03-28T20:45:44.496Z,1680036344.496 [Default:CheckIn] Running Loop=39 2023-03-28T20:45:44.496Z,1680036344.496 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:45:44.497Z,1680036344.497 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:45:46.494Z,1680036346.494 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204545.00,A,3648.17657,N,12147.28392,W,0.039,0.00,280323,,,D*71 2023-03-28T20:45:46.496Z,1680036346.496 [NAL9602](INFO): GPS fix at 20230328T204545: (36.802943, -121.788065) 2023-03-28T20:45:46.506Z,1680036346.506 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:45:46.506Z,1680036346.506 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:45:54.435Z,1680036354.435 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0015.lzma 2023-03-28T20:45:55.438Z,1680036355.438 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0015.lzma.bak 2023-03-28T20:45:55.438Z,1680036355.438 [DataOverHttps](INFO): SBD MOMSN=17735500 2023-03-28T20:46:11.340Z,1680036371.340 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20230328T201444/Express0016.lzma 2023-03-28T20:46:12.342Z,1680036372.342 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0016.lzma.bak 2023-03-28T20:46:12.342Z,1680036372.342 [DataOverHttps](INFO): SBD MOMSN=17735503 2023-03-28T20:46:13.607Z,1680036373.607 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:46:13.607Z,1680036373.607 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:46:13.607Z,1680036373.607 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:46:19.219Z,1680036379.219 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T20:47:39.617Z,1680036459.617 [DVL_micro](ERROR): Failed to parse: :WI,+03396,-01444,+00002,+00000,A 2023-03-28T20:51:14.152Z,1680036674.152 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:51:14.152Z,1680036674.152 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:51:14.152Z,1680036674.152 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:51:14.152Z,1680036674.152 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:51:14.553Z,1680036674.553 [Default:CheckIn:D] Stopped 2023-03-28T20:51:14.553Z,1680036674.553 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:51:14.960Z,1680036674.960 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 217.260937 min 2023-03-28T20:51:14.960Z,1680036674.960 [Default:CheckIn:E] Stopped 2023-03-28T20:51:14.960Z,1680036674.960 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:51:14.960Z,1680036674.960 [Default:CheckIn] Stopped 2023-03-28T20:51:14.960Z,1680036674.960 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:51:14.961Z,1680036674.961 [Default:CheckIn](INFO): Running loop #40 2023-03-28T20:51:14.961Z,1680036674.961 [Default:CheckIn] Running Loop=40 2023-03-28T20:51:14.961Z,1680036674.961 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:51:14.961Z,1680036674.961 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:51:16.974Z,1680036676.974 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205116.00,A,3648.17633,N,12147.28339,W,0.039,0.00,280323,,,D*71 2023-03-28T20:51:16.977Z,1680036676.977 [NAL9602](INFO): GPS fix at 20230328T205116: (36.802939, -121.788056) 2023-03-28T20:51:16.987Z,1680036676.987 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:51:16.987Z,1680036676.987 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:51:24.795Z,1680036684.795 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230328T201444/Courier0018.lzma 2023-03-28T20:51:25.798Z,1680036685.798 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0018.lzma.bak 2023-03-28T20:51:25.798Z,1680036685.798 [DataOverHttps](INFO): SBD MOMSN=17735516 2023-03-28T20:51:45.351Z,1680036705.351 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0019.lzma 2023-03-28T20:51:46.354Z,1680036706.354 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0019.lzma.bak 2023-03-28T20:51:46.354Z,1680036706.354 [DataOverHttps](INFO): SBD MOMSN=17735523 2023-03-28T20:51:47.707Z,1680036707.707 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-28T20:51:47.784Z,1680036707.784 [NAL9602](ERROR): received: +CSQ:0 OK549, 2, 0, 0, 0 OK 2023-03-28T20:51:47.800Z,1680036707.800 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:51:47.801Z,1680036707.801 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:51:47.801Z,1680036707.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:53:47.283Z,1680036827.283 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-03-28T20:53:47.283Z,1680036827.283 [DropWeight] Hardware Fault, FailCount= 1 2023-03-28T20:53:47.283Z,1680036827.283 [DropWeight](ERROR): Hardware Fault 2023-03-28T20:53:47.302Z,1680036827.302 [CBIT](INFO): Critical error at 20230328T205347 2023-03-28T20:53:47.304Z,1680036827.304 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-03-28T20:53:47.305Z,1680036827.305 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-03-28T20:53:47.719Z,1680036827.719 [CBIT](INFO): Critical error at 20230328T205347 2023-03-28T20:54:24.933Z,1680036864.933 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:54:42.278Z,1680036882.278 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:56:00.247Z,1680036960.247 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:56:03.887Z,1680036963.887 [Reporter](INFO): NAL9602.sigQuality 3 count 2023-03-28T20:56:17.982Z,1680036977.982 [NAL9602](INFO): SBD MO Status=0, MOMSN=47549, MT Status=0, MTMSN=0 2023-03-28T20:56:17.982Z,1680036977.982 [NAL9602](INFO): No messages in MT queue 2023-03-28T20:56:48.285Z,1680037008.285 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T20:56:48.285Z,1680037008.285 [Default:CheckIn:C.Wait] Stopped 2023-03-28T20:56:48.285Z,1680037008.285 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T20:56:48.285Z,1680037008.285 [Default:CheckIn:D] Running Loop=1 2023-03-28T20:56:48.680Z,1680037008.680 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T20:56:48.692Z,1680037008.692 [Default:CheckIn:D] Stopped 2023-03-28T20:56:48.692Z,1680037008.692 [Default:CheckIn:E] Running Loop=1 2023-03-28T20:56:48.702Z,1680037008.702 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:56:49.104Z,1680037009.104 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 222.829899 min 2023-03-28T20:56:49.104Z,1680037009.104 [Default:CheckIn:E] Stopped 2023-03-28T20:56:49.104Z,1680037009.104 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T20:56:49.105Z,1680037009.105 [Default:CheckIn] Stopped 2023-03-28T20:56:49.105Z,1680037009.105 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T20:56:49.105Z,1680037009.105 [Default:CheckIn](INFO): Running loop #41 2023-03-28T20:56:49.105Z,1680037009.105 [Default:CheckIn] Running Loop=41 2023-03-28T20:56:49.105Z,1680037009.105 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T20:56:49.105Z,1680037009.105 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T20:56:51.118Z,1680037011.118 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205650.00,A,3648.17568,N,12147.28412,W,0.019,0.00,280323,,,D*75 2023-03-28T20:56:51.120Z,1680037011.120 [NAL9602](INFO): GPS fix at 20230328T205650: (36.802928, -121.788069) 2023-03-28T20:56:51.130Z,1680037011.130 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T20:56:51.130Z,1680037011.130 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T20:56:55.658Z,1680037015.658 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T20:56:58.992Z,1680037018.992 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20230328T201444/Courier0021.lzma 2023-03-28T20:56:59.994Z,1680037019.994 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0021.lzma.bak 2023-03-28T20:56:59.994Z,1680037019.994 [DataOverHttps](INFO): SBD MOMSN=17735556 2023-03-28T20:57:06.870Z,1680037026.870 [NAL9602](INFO): SBD MO Status=2, MOMSN=47550, MT Status=2, MTMSN=0 2023-03-28T20:57:06.870Z,1680037026.870 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T20:57:11.379Z,1680037031.379 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:57:16.131Z,1680037036.131 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230328T201444/Express0022.lzma 2023-03-28T20:57:17.134Z,1680037037.134 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0022.lzma.bak 2023-03-28T20:57:17.134Z,1680037037.134 [DataOverHttps](INFO): SBD MOMSN=17735561 2023-03-28T20:57:18.606Z,1680037038.606 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T20:57:18.606Z,1680037038.606 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T20:57:18.606Z,1680037038.606 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T20:57:22.698Z,1680037042.698 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:57:36.602Z,1680037056.602 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T20:57:55.751Z,1680037075.751 [NAL9602](INFO): SBD MO Status=2, MOMSN=47550, MT Status=2, MTMSN=0 2023-03-28T20:57:55.752Z,1680037075.752 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T20:58:00.239Z,1680037080.239 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T20:59:44.475Z,1680037184.475 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T20:59:52.972Z,1680037192.972 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:01:53.297Z,1680037313.297 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T21:02:19.166Z,1680037339.166 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:02:19.166Z,1680037339.166 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:02:19.166Z,1680037339.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:02:19.166Z,1680037339.166 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:02:19.571Z,1680037339.571 [Default:CheckIn:D] Stopped 2023-03-28T21:02:19.571Z,1680037339.571 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 228.344564 min 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn:E] Stopped 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn] Stopped 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn](INFO): Running loop #42 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn] Running Loop=42 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:02:19.998Z,1680037339.998 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:02:21.986Z,1680037341.986 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210221.00,A,3648.17833,N,12147.28505,W,0.058,0.00,280323,,,D*72 2023-03-28T21:02:21.989Z,1680037341.989 [NAL9602](INFO): GPS fix at 20230328T210221: (36.802972, -121.788084) 2023-03-28T21:02:21.999Z,1680037341.999 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:02:21.999Z,1680037341.999 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:02:29.587Z,1680037349.587 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0024.lzma 2023-03-28T21:02:30.590Z,1680037350.590 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0024.lzma.bak 2023-03-28T21:02:30.590Z,1680037350.590 [DataOverHttps](INFO): SBD MOMSN=17735934 2023-03-28T21:02:49.524Z,1680037369.524 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230328T201444/Express0025.lzma 2023-03-28T21:02:50.526Z,1680037370.526 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0025.lzma.bak 2023-03-28T21:02:50.526Z,1680037370.526 [DataOverHttps](INFO): SBD MOMSN=17735937 2023-03-28T21:02:51.960Z,1680037371.960 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:02:51.960Z,1680037371.960 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:02:51.960Z,1680037371.960 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:02:54.390Z,1680037374.390 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T21:07:52.587Z,1680037672.587 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:07:52.587Z,1680037672.587 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:07:52.587Z,1680037672.587 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:07:52.587Z,1680037672.587 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:07:52.984Z,1680037672.984 [Default:CheckIn:D] Stopped 2023-03-28T21:07:52.984Z,1680037672.984 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 233.901449 min 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn:E] Stopped 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn] Stopped 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn](INFO): Running loop #43 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn] Running Loop=43 2023-03-28T21:07:53.403Z,1680037673.403 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:07:53.404Z,1680037673.404 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:07:55.398Z,1680037675.398 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210754.00,A,3648.17588,N,12147.28373,W,0.039,0.00,280323,,,D*78 2023-03-28T21:07:55.401Z,1680037675.401 [NAL9602](INFO): GPS fix at 20230328T210754: (36.802931, -121.788062) 2023-03-28T21:07:55.427Z,1680037675.427 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:07:55.427Z,1680037675.427 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:08:02.627Z,1680037682.627 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230328T201444/Courier0027.lzma 2023-03-28T21:08:03.630Z,1680037683.630 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0027.lzma.bak 2023-03-28T21:08:03.630Z,1680037683.630 [DataOverHttps](INFO): SBD MOMSN=17735969 2023-03-28T21:08:19.563Z,1680037699.563 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0028.lzma 2023-03-28T21:08:20.566Z,1680037700.566 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0028.lzma.bak 2023-03-28T21:08:20.566Z,1680037700.566 [DataOverHttps](INFO): SBD MOMSN=17735972 2023-03-28T21:08:22.076Z,1680037702.076 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:08:22.076Z,1680037702.076 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:08:22.076Z,1680037702.076 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:08:26.106Z,1680037706.106 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-28T21:08:26.180Z,1680037706.180 [NAL9602](ERROR): received: +CSQ:0 OK550, 2, 0, 0, 0 OK 2023-03-28T21:08:45.984Z,1680037725.984 [DVL_micro](ERROR): DVL uart error: serial timeout 2023-03-28T21:08:45.984Z,1680037725.984 [DVL_micro] Communications Fault, FailCount= 1 2023-03-28T21:08:45.984Z,1680037725.984 [DVL_micro](ERROR): Communications Fault 2023-03-28T21:08:45.984Z,1680037725.984 [DVL_micro](ERROR): Failed to parse: 2023-03-28T21:08:46.014Z,1680037726.014 [CBIT](ERROR): Communications Fault in component: DVL_micro 2023-03-28T21:08:46.376Z,1680037726.376 [DVL_micro](INFO): Powering down 2023-03-28T21:08:47.137Z,1680037727.137 [CBIT](INFO): Clearing failed state for component DVL_micro 2023-03-28T21:08:47.137Z,1680037727.137 [DVL_micro] No Fault, FailCount= 1 2023-03-28T21:08:47.663Z,1680037727.663 [CBIT](INFO): Clearing failed state for component DropWeight 2023-03-28T21:08:47.663Z,1680037727.663 [DropWeight] No Fault, FailCount= 1 2023-03-28T21:09:55.798Z,1680037795.798 [DVL_micro](ERROR): only read 1 of 4 data items 2023-03-28T21:09:55.798Z,1680037795.798 [DVL_micro](ERROR): Failed to parse: :BI,-02861-03096,+00000,I 2023-03-28T21:10:07.153Z,1680037807.153 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T21:10:26.521Z,1680037826.521 [NAL9602](INFO): SBD MO Status=2, MOMSN=47550, MT Status=2, MTMSN=0 2023-03-28T21:10:26.522Z,1680037826.522 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T21:10:30.998Z,1680037830.998 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:10:54.047Z,1680037854.047 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T21:11:02.563Z,1680037862.563 [Reporter](INFO): NAL9602.sigQuality 4 count 2023-03-28T21:11:14.978Z,1680037874.978 [NAL9602](INFO): SBD MO Status=0, MOMSN=47550, MT Status=0, MTMSN=0 2023-03-28T21:11:14.979Z,1680037874.979 [NAL9602](INFO): No messages in MT queue 2023-03-28T21:11:45.684Z,1680037905.684 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T21:11:45.726Z,1680037905.726 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:11:48.133Z,1680037908.133 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-28T21:11:59.073Z,1680037919.073 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.050116 CHAN A1 (24V): 0.096599 CHAN A2 (12V): 0.029564 CHAN A3 (5V): 0.003652 CHAN B0 (3.3V): 0.000546 CHAN B1 (3.15aV): 0.000504 CHAN B2 (3.15bV): 0.000608 CHAN B3 (GND): -0.008425 OPEN: 0.007627 Full Scale: +/- 1 mA 2023-03-28T21:12:55.994Z,1680037975.994 [DVL_micro](ERROR): only read 0 of 4 data items 2023-03-28T21:12:55.994Z,1680037975.994 [DVL_micro](ERROR): Failed to parse: :RD9,+9999.99,+9999.99,+9999.99 2023-03-28T21:13:22.662Z,1680038002.662 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:13:22.662Z,1680038002.662 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:13:22.662Z,1680038002.662 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:13:22.662Z,1680038002.662 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:13:23.067Z,1680038003.067 [Default:CheckIn:D] Stopped 2023-03-28T21:13:23.067Z,1680038003.067 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:13:23.476Z,1680038003.476 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 239.402832 min 2023-03-28T21:13:23.476Z,1680038003.476 [Default:CheckIn:E] Stopped 2023-03-28T21:13:23.477Z,1680038003.477 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:13:23.477Z,1680038003.477 [Default:CheckIn] Stopped 2023-03-28T21:13:23.477Z,1680038003.477 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:13:23.477Z,1680038003.477 [Default:CheckIn](INFO): Running loop #44 2023-03-28T21:13:23.477Z,1680038003.477 [Default:CheckIn] Running Loop=44 2023-03-28T21:13:23.477Z,1680038003.477 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:13:23.477Z,1680038003.477 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:13:25.485Z,1680038005.485 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211324.00,A,3648.17711,N,12147.28483,W,0.097,0.00,280323,,,D*74 2023-03-28T21:13:25.487Z,1680038005.487 [NAL9602](INFO): GPS fix at 20230328T211324: (36.802952, -121.788081) 2023-03-28T21:13:25.514Z,1680038005.514 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:13:25.514Z,1680038005.514 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:13:33.820Z,1680038013.820 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230328T201444/Courier0030.lzma 2023-03-28T21:13:34.822Z,1680038014.822 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0030.lzma.bak 2023-03-28T21:13:34.822Z,1680038014.822 [DataOverHttps](INFO): SBD MOMSN=17736342 2023-03-28T21:13:36.894Z,1680038016.894 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T21:13:53.800Z,1680038033.800 [DataOverHttps](INFO): Sending 330 bytes from file Logs/20230328T201444/Express0031.lzma 2023-03-28T21:13:54.802Z,1680038034.802 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0031.lzma.bak 2023-03-28T21:13:54.802Z,1680038034.802 [DataOverHttps](INFO): SBD MOMSN=17736345 2023-03-28T21:13:56.239Z,1680038036.239 [NAL9602](INFO): SBD MO Status=2, MOMSN=47551, MT Status=2, MTMSN=0 2023-03-28T21:13:56.239Z,1680038036.239 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T21:13:56.267Z,1680038036.267 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:13:56.267Z,1680038036.267 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:13:56.267Z,1680038036.267 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:14:00.746Z,1680038040.746 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:14:43.947Z,1680038083.947 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T21:14:52.420Z,1680038092.420 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T21:15:02.898Z,1680038102.898 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T21:15:02.898Z,1680038102.898 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+11.81489.0,000 2023-03-28T21:15:10.984Z,1680038110.984 [NAL9602](INFO): SBD MO Status=2, MOMSN=47551, MT Status=2, MTMSN=0 2023-03-28T21:15:10.984Z,1680038110.984 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T21:15:15.059Z,1680038115.059 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:16:36.339Z,1680038196.339 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T21:16:44.795Z,1680038204.795 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:17:47.857Z,1680038267.857 [DVL_micro](ERROR): Failed to parse: :WI,+08934,-02720,-00156,+00000,A 2023-03-28T21:18:27.085Z,1680038307.085 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T21:18:28.274Z,1680038308.274 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T21:18:56.989Z,1680038336.989 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:18:56.989Z,1680038336.989 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:18:56.990Z,1680038336.990 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:18:56.990Z,1680038336.990 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:18:57.394Z,1680038337.394 [Default:CheckIn:D] Stopped 2023-03-28T21:18:57.394Z,1680038337.394 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:18:57.807Z,1680038337.807 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 244.974935 min 2023-03-28T21:18:57.807Z,1680038337.807 [Default:CheckIn:E] Stopped 2023-03-28T21:18:57.807Z,1680038337.807 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:18:57.807Z,1680038337.807 [Default:CheckIn] Stopped 2023-03-28T21:18:57.807Z,1680038337.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:18:57.809Z,1680038337.809 [Default:CheckIn](INFO): Running loop #45 2023-03-28T21:18:57.809Z,1680038337.809 [Default:CheckIn] Running Loop=45 2023-03-28T21:18:57.809Z,1680038337.809 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:18:57.809Z,1680038337.809 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:18:59.814Z,1680038339.814 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211859.00,A,3648.17707,N,12147.28539,W,0.019,0.00,280323,,,D*74 2023-03-28T21:18:59.817Z,1680038339.817 [NAL9602](INFO): GPS fix at 20230328T211859: (36.802951, -121.788090) 2023-03-28T21:18:59.843Z,1680038339.843 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:18:59.843Z,1680038339.843 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:19:07.035Z,1680038347.035 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0033.lzma 2023-03-28T21:19:08.038Z,1680038348.038 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0033.lzma.bak 2023-03-28T21:19:08.038Z,1680038348.038 [DataOverHttps](INFO): SBD MOMSN=17736350 2023-03-28T21:19:24.056Z,1680038364.056 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230328T201444/Express0034.lzma 2023-03-28T21:19:25.058Z,1680038365.058 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0034.lzma.bak 2023-03-28T21:19:25.058Z,1680038365.058 [DataOverHttps](INFO): SBD MOMSN=17736353 2023-03-28T21:19:26.488Z,1680038366.488 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:19:26.488Z,1680038366.488 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:19:26.488Z,1680038366.488 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:19:32.162Z,1680038372.162 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T21:19:32.248Z,1680038372.248 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:21:56.447Z,1680038516.447 [DVL_micro](ERROR): only read 2 of 4 data items 2023-03-28T21:21:56.447Z,1680038516.447 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+99999.99 2023-03-28T21:24:27.206Z,1680038667.206 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:24:27.206Z,1680038667.206 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:24:27.206Z,1680038667.206 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:24:27.206Z,1680038667.206 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:24:27.619Z,1680038667.619 [Default:CheckIn:D] Stopped 2023-03-28T21:24:27.619Z,1680038667.619 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:24:28.026Z,1680038668.026 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 250.478695 min 2023-03-28T21:24:28.026Z,1680038668.026 [Default:CheckIn:E] Stopped 2023-03-28T21:24:28.026Z,1680038668.026 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:24:28.026Z,1680038668.026 [Default:CheckIn] Stopped 2023-03-28T21:24:28.026Z,1680038668.026 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:24:28.026Z,1680038668.026 [Default:CheckIn](INFO): Running loop #46 2023-03-28T21:24:28.026Z,1680038668.026 [Default:CheckIn] Running Loop=46 2023-03-28T21:24:28.027Z,1680038668.027 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:24:28.027Z,1680038668.027 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:24:30.030Z,1680038670.030 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212429.00,A,3648.17815,N,12147.28647,W,0.039,0.00,280323,,,D*78 2023-03-28T21:24:30.033Z,1680038670.033 [NAL9602](INFO): GPS fix at 20230328T212429: (36.802969, -121.788108) 2023-03-28T21:24:30.043Z,1680038670.043 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:24:30.043Z,1680038670.043 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:24:40.263Z,1680038680.263 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0036.lzma 2023-03-28T21:24:41.266Z,1680038681.266 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0036.lzma.bak 2023-03-28T21:24:41.266Z,1680038681.266 [DataOverHttps](INFO): SBD MOMSN=17736801 2023-03-28T21:24:57.363Z,1680038697.363 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230328T201444/Express0037.lzma 2023-03-28T21:24:58.366Z,1680038698.366 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0037.lzma.bak 2023-03-28T21:24:58.366Z,1680038698.366 [DataOverHttps](INFO): SBD MOMSN=17736804 2023-03-28T21:24:59.610Z,1680038699.610 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:24:59.610Z,1680038699.610 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:24:59.610Z,1680038699.610 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:25:00.797Z,1680038700.797 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-28T21:25:00.877Z,1680038700.877 [NAL9602](ERROR): received: +CSQ:1 OK551, 2, 0, 0, 0 OK 2023-03-28T21:28:01.633Z,1680038881.633 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T21:28:01.950Z,1680038881.950 [DVL_micro](ERROR): only read 2 of 4 data items 2023-03-28T21:28:01.950Z,1680038881.950 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,++9999.99 2023-03-28T21:28:10.478Z,1680038890.478 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T21:28:29.422Z,1680038909.422 [NAL9602](INFO): SBD MO Status=0, MOMSN=47551, MT Status=0, MTMSN=0 2023-03-28T21:28:29.422Z,1680038909.422 [NAL9602](INFO): No messages in MT queue 2023-03-28T21:29:00.206Z,1680038940.206 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T21:29:00.233Z,1680038940.233 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:30:00.058Z,1680039000.058 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:30:00.058Z,1680039000.058 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:30:00.058Z,1680039000.058 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:30:00.059Z,1680039000.059 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:30:00.450Z,1680039000.450 [Default:CheckIn:D] Stopped 2023-03-28T21:30:00.450Z,1680039000.450 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:30:00.900Z,1680039000.900 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 256.025879 min 2023-03-28T21:30:00.900Z,1680039000.900 [Default:CheckIn:E] Stopped 2023-03-28T21:30:00.900Z,1680039000.900 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:30:00.900Z,1680039000.900 [Default:CheckIn] Stopped 2023-03-28T21:30:00.900Z,1680039000.900 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:30:00.901Z,1680039000.901 [Default:CheckIn](INFO): Running loop #47 2023-03-28T21:30:00.901Z,1680039000.901 [Default:CheckIn] Running Loop=47 2023-03-28T21:30:00.901Z,1680039000.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:30:00.901Z,1680039000.901 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:30:02.879Z,1680039002.879 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213002.00,A,3648.17786,N,12147.28642,W,0.019,0.00,280323,,,D*76 2023-03-28T21:30:02.882Z,1680039002.882 [NAL9602](INFO): GPS fix at 20230328T213002: (36.802964, -121.788107) 2023-03-28T21:30:02.892Z,1680039002.892 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:30:02.892Z,1680039002.892 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:30:10.855Z,1680039010.855 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0039.lzma 2023-03-28T21:30:11.858Z,1680039011.858 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0039.lzma.bak 2023-03-28T21:30:11.858Z,1680039011.858 [DataOverHttps](INFO): SBD MOMSN=17736807 2023-03-28T21:30:27.879Z,1680039027.879 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0040.lzma 2023-03-28T21:30:28.882Z,1680039028.882 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0040.lzma.bak 2023-03-28T21:30:28.882Z,1680039028.882 [DataOverHttps](INFO): SBD MOMSN=17736810 2023-03-28T21:30:30.351Z,1680039030.351 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:30:30.351Z,1680039030.351 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:30:30.351Z,1680039030.351 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:30:36.707Z,1680039036.707 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T21:30:47.371Z,1680039047.371 [NAL9602](INFO): SBD MO Status=0, MOMSN=47552, MT Status=0, MTMSN=0 2023-03-28T21:30:47.371Z,1680039047.371 [NAL9602](INFO): No messages in MT queue 2023-03-28T21:31:04.337Z,1680039064.337 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T21:31:04.337Z,1680039064.337 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+11.9,0000.0,10 2023-03-28T21:31:18.068Z,1680039078.068 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T21:31:18.114Z,1680039078.114 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:34:07.127Z,1680039247.127 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T21:34:07.127Z,1680039247.127 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+11.7,0000.0,10 2023-03-28T21:35:30.811Z,1680039330.811 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:35:30.811Z,1680039330.811 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:35:30.811Z,1680039330.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:35:30.811Z,1680039330.811 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:35:31.204Z,1680039331.204 [Default:CheckIn:D] Stopped 2023-03-28T21:35:31.204Z,1680039331.204 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:35:31.612Z,1680039331.612 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 261.538428 min 2023-03-28T21:35:31.612Z,1680039331.612 [Default:CheckIn:E] Stopped 2023-03-28T21:35:31.612Z,1680039331.612 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:35:31.612Z,1680039331.612 [Default:CheckIn] Stopped 2023-03-28T21:35:31.612Z,1680039331.612 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:35:31.613Z,1680039331.613 [Default:CheckIn](INFO): Running loop #48 2023-03-28T21:35:31.613Z,1680039331.613 [Default:CheckIn] Running Loop=48 2023-03-28T21:35:31.613Z,1680039331.613 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:35:31.613Z,1680039331.613 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:35:33.639Z,1680039333.639 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213533.00,A,3648.17601,N,12147.28642,W,0.019,0.00,280323,,,D*7F 2023-03-28T21:35:33.641Z,1680039333.641 [NAL9602](INFO): GPS fix at 20230328T213533: (36.802934, -121.788107) 2023-03-28T21:35:33.659Z,1680039333.659 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:35:33.659Z,1680039333.659 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:35:44.631Z,1680039344.631 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0042.lzma 2023-03-28T21:35:45.634Z,1680039345.634 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0042.lzma.bak 2023-03-28T21:35:45.635Z,1680039345.635 [DataOverHttps](INFO): SBD MOMSN=17737206 2023-03-28T21:36:01.527Z,1680039361.527 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0043.lzma 2023-03-28T21:36:02.530Z,1680039362.530 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0043.lzma.bak 2023-03-28T21:36:02.530Z,1680039362.530 [DataOverHttps](INFO): SBD MOMSN=17737209 2023-03-28T21:36:03.990Z,1680039363.990 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:36:03.991Z,1680039363.991 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:36:03.991Z,1680039363.991 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:37:20.430Z,1680039440.430 [Reporter](INFO): NAL9602.sigQuality 2 count 2023-03-28T21:37:32.935Z,1680039452.935 [NAL9602](INFO): SBD MO Status=2, MOMSN=47553, MT Status=2, MTMSN=0 2023-03-28T21:37:32.935Z,1680039452.935 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-03-28T21:37:37.461Z,1680039457.461 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T21:38:48.915Z,1680039528.915 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-03-28T21:38:48.915Z,1680039528.915 [DropWeight] Hardware Fault, FailCount= 1 2023-03-28T21:38:48.916Z,1680039528.916 [DropWeight](ERROR): Hardware Fault 2023-03-28T21:38:48.964Z,1680039528.964 [CBIT](INFO): Critical error at 20230328T213848 2023-03-28T21:38:48.966Z,1680039528.966 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-03-28T21:38:48.967Z,1680039528.967 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-03-28T21:38:49.339Z,1680039529.339 [CBIT](INFO): Critical error at 20230328T213848 2023-03-28T21:39:45.685Z,1680039585.685 [DataOverHttps](IMPORTANT): SBD MTMSN=20230328T213944 2023-03-28T21:39:53.329Z,1680039593.329 [DataOverHttps](INFO): Received command: strobe off 2023-03-28T21:39:53.425Z,1680039593.425 [CommandExec](IMPORTANT): got command strobe off 2023-03-28T21:39:53.425Z,1680039593.425 [CommandExec](IMPORTANT): Deactivating strobe 2023-03-28T21:40:00.020Z,1680039600.020 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T21:40:00.020Z,1680039600.020 [DVL_micro](ERROR): Failed to parse: :BI,+02678,-03027,-0100,I 2023-03-28T21:40:36.379Z,1680039636.379 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T21:41:04.670Z,1680039664.670 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:41:04.670Z,1680039664.670 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:41:04.671Z,1680039664.671 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:41:04.671Z,1680039664.671 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:41:05.074Z,1680039665.074 [Default:CheckIn:D] Stopped 2023-03-28T21:41:05.075Z,1680039665.075 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:41:05.476Z,1680039665.476 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 267.102946 min 2023-03-28T21:41:05.476Z,1680039665.476 [Default:CheckIn:E] Stopped 2023-03-28T21:41:05.476Z,1680039665.476 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:41:05.476Z,1680039665.476 [Default:CheckIn] Stopped 2023-03-28T21:41:05.476Z,1680039665.476 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:41:05.476Z,1680039665.476 [Default:CheckIn](INFO): Running loop #49 2023-03-28T21:41:05.477Z,1680039665.477 [Default:CheckIn] Running Loop=49 2023-03-28T21:41:05.477Z,1680039665.477 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:41:05.477Z,1680039665.477 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:41:07.550Z,1680039667.550 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214106.00,A,3648.16823,N,12147.27729,W,0.097,214.81,280323,,,D*7E 2023-03-28T21:41:07.553Z,1680039667.553 [NAL9602](INFO): GPS fix at 20230328T214106: (36.802804, -121.787955) 2023-03-28T21:41:07.563Z,1680039667.563 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:41:07.563Z,1680039667.563 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:41:15.427Z,1680039675.427 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20230328T201444/Courier0045.lzma 2023-03-28T21:41:16.430Z,1680039676.430 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0045.lzma.bak 2023-03-28T21:41:16.430Z,1680039676.430 [DataOverHttps](INFO): SBD MOMSN=17737214 2023-03-28T21:41:32.912Z,1680039692.912 [DataOverHttps](INFO): Sending 307 bytes from file Logs/20230328T201444/Express0046.lzma 2023-03-28T21:41:33.914Z,1680039693.914 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0046.lzma.bak 2023-03-28T21:41:33.914Z,1680039693.914 [DataOverHttps](INFO): SBD MOMSN=17737219 2023-03-28T21:41:40.279Z,1680039700.279 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T21:41:53.511Z,1680039713.511 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230328T201444/Express0049.lzma 2023-03-28T21:41:54.514Z,1680039714.514 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0049.lzma.bak 2023-03-28T21:41:54.514Z,1680039714.514 [DataOverHttps](INFO): SBD MOMSN=17737230 2023-03-28T21:41:56.046Z,1680039716.046 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:41:56.046Z,1680039716.046 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:41:56.046Z,1680039716.046 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:42:44.600Z,1680039764.600 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T21:42:44.600Z,1680039764.600 [DVL_micro](ERROR): Failed to parse: :BI,+02326,+00164,-0000,I 2023-03-28T21:46:56.715Z,1680040016.715 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:46:56.715Z,1680040016.715 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:46:56.715Z,1680040016.715 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:46:56.715Z,1680040016.715 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:46:57.121Z,1680040017.121 [Default:CheckIn:D] Stopped 2023-03-28T21:46:57.121Z,1680040017.121 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 272.970394 min 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn:E] Stopped 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn] Stopped 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn](INFO): Running loop #50 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn] Running Loop=50 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:46:57.526Z,1680040017.526 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:46:59.540Z,1680040019.540 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214659.00,A,3648.16975,N,12147.27773,W,0.641,30.80,280323,,,A*43 2023-03-28T21:46:59.542Z,1680040019.542 [NAL9602](INFO): GPS fix at 20230328T214659: (36.802829, -121.787962) 2023-03-28T21:46:59.552Z,1680040019.552 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:46:59.552Z,1680040019.552 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:47:02.046Z,1680040022.046 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-03-28T21:47:02.053Z,1680040022.053 [BPC1](INFO): Received data from all battery sticks. 2023-03-28T21:47:06.559Z,1680040026.559 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0051.lzma 2023-03-28T21:47:07.562Z,1680040027.562 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0051.lzma.bak 2023-03-28T21:47:07.562Z,1680040027.562 [DataOverHttps](INFO): SBD MOMSN=17737271 2023-03-28T21:47:23.548Z,1680040043.548 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230328T201444/Express0052.lzma 2023-03-28T21:47:24.550Z,1680040044.550 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0052.lzma.bak 2023-03-28T21:47:24.550Z,1680040044.550 [DataOverHttps](INFO): SBD MOMSN=17737274 2023-03-28T21:47:25.859Z,1680040045.859 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:47:25.859Z,1680040045.859 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:47:25.859Z,1680040045.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:52:02.277Z,1680040322.277 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T21:52:26.545Z,1680040346.545 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:52:26.545Z,1680040346.545 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:52:26.545Z,1680040346.545 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:52:26.545Z,1680040346.545 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:52:26.933Z,1680040346.933 [Default:CheckIn:D] Stopped 2023-03-28T21:52:26.933Z,1680040346.933 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:52:27.343Z,1680040347.343 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 278.467253 min 2023-03-28T21:52:27.343Z,1680040347.343 [Default:CheckIn:E] Stopped 2023-03-28T21:52:27.345Z,1680040347.345 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:52:27.345Z,1680040347.345 [Default:CheckIn] Stopped 2023-03-28T21:52:27.345Z,1680040347.345 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:52:27.345Z,1680040347.345 [Default:CheckIn](INFO): Running loop #51 2023-03-28T21:52:27.345Z,1680040347.345 [Default:CheckIn] Running Loop=51 2023-03-28T21:52:27.345Z,1680040347.345 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:52:27.345Z,1680040347.345 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:52:29.350Z,1680040349.350 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215228.00,A,3648.17009,N,12147.28161,W,0.194,331.58,280323,,,A*71 2023-03-28T21:52:29.352Z,1680040349.352 [NAL9602](INFO): GPS fix at 20230328T215228: (36.802835, -121.788027) 2023-03-28T21:52:29.382Z,1680040349.382 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:52:29.382Z,1680040349.382 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:52:39.783Z,1680040359.783 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230328T201444/Courier0054.lzma 2023-03-28T21:52:40.786Z,1680040360.786 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0054.lzma.bak 2023-03-28T21:52:40.786Z,1680040360.786 [DataOverHttps](INFO): SBD MOMSN=17737629 2023-03-28T21:52:58.004Z,1680040378.004 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20230328T201444/Express0055.lzma 2023-03-28T21:52:59.006Z,1680040379.006 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0055.lzma.bak 2023-03-28T21:52:59.006Z,1680040379.006 [DataOverHttps](INFO): SBD MOMSN=17737632 2023-03-28T21:53:00.523Z,1680040380.523 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:53:00.523Z,1680040380.523 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:53:00.523Z,1680040380.523 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:53:01.312Z,1680040381.312 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T21:53:49.093Z,1680040429.093 [CBIT](INFO): Clearing failed state for component DropWeight 2023-03-28T21:53:49.093Z,1680040429.093 [DropWeight] No Fault, FailCount= 1 2023-03-28T21:55:17.990Z,1680040517.990 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T21:55:17.990Z,1680040517.990 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+12.9,0000.0,1489.0,000 2023-03-28T21:55:38.266Z,1680040538.266 [DVL_micro](ERROR): only read 2 of 4 data items 2023-03-28T21:55:38.266Z,1680040538.266 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+ 2023-03-28T21:58:00.967Z,1680040680.967 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T21:58:00.967Z,1680040680.967 [Default:CheckIn:C.Wait] Stopped 2023-03-28T21:58:00.967Z,1680040680.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T21:58:00.967Z,1680040680.967 [Default:CheckIn:D] Running Loop=1 2023-03-28T21:58:01.370Z,1680040681.370 [Default:CheckIn:D] Stopped 2023-03-28T21:58:01.370Z,1680040681.370 [Default:CheckIn:E] Running Loop=1 2023-03-28T21:58:01.783Z,1680040681.783 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 284.041211 min 2023-03-28T21:58:01.783Z,1680040681.783 [Default:CheckIn:E] Stopped 2023-03-28T21:58:01.783Z,1680040681.783 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T21:58:01.783Z,1680040681.783 [Default:CheckIn] Stopped 2023-03-28T21:58:01.783Z,1680040681.783 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T21:58:01.784Z,1680040681.784 [Default:CheckIn](INFO): Running loop #52 2023-03-28T21:58:01.784Z,1680040681.784 [Default:CheckIn] Running Loop=52 2023-03-28T21:58:01.784Z,1680040681.784 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T21:58:01.784Z,1680040681.784 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T21:58:03.792Z,1680040683.792 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215803.00,A,3648.17023,N,12147.28381,W,0.233,236.28,280323,,,A*79 2023-03-28T21:58:03.794Z,1680040683.794 [NAL9602](INFO): GPS fix at 20230328T215803: (36.802837, -121.788064) 2023-03-28T21:58:03.805Z,1680040683.805 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T21:58:03.805Z,1680040683.805 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T21:58:12.115Z,1680040692.115 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0057.lzma 2023-03-28T21:58:13.138Z,1680040693.138 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0057.lzma.bak 2023-03-28T21:58:13.138Z,1680040693.138 [DataOverHttps](INFO): SBD MOMSN=17737673 2023-03-28T21:58:29.139Z,1680040709.139 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0058.lzma 2023-03-28T21:58:30.142Z,1680040710.142 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0058.lzma.bak 2023-03-28T21:58:30.142Z,1680040710.142 [DataOverHttps](INFO): SBD MOMSN=17737676 2023-03-28T21:58:31.680Z,1680040711.680 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T21:58:31.681Z,1680040711.681 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T21:58:31.681Z,1680040711.681 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T21:58:34.541Z,1680040714.541 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-28T21:58:34.612Z,1680040714.612 [NAL9602](ERROR): received: +CSQ:0 OK553, 2, 0, 0, 0 OK 2023-03-28T22:03:05.809Z,1680040985.809 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T22:03:32.136Z,1680041012.136 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T22:03:32.137Z,1680041012.137 [Default:CheckIn:C.Wait] Stopped 2023-03-28T22:03:32.137Z,1680041012.137 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T22:03:32.137Z,1680041012.137 [Default:CheckIn:D] Running Loop=1 2023-03-28T22:03:32.512Z,1680041012.512 [Default:CheckIn:D] Stopped 2023-03-28T22:03:32.512Z,1680041012.512 [Default:CheckIn:E] Running Loop=1 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 289.560254 min 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn:E] Stopped 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn] Stopped 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn](INFO): Running loop #53 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn] Running Loop=53 2023-03-28T22:03:32.890Z,1680041012.890 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T22:03:32.891Z,1680041012.891 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T22:03:34.912Z,1680041014.912 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220334.00,A,3648.16658,N,12147.27548,W,0.097,188.34,280323,,,D*75 2023-03-28T22:03:34.914Z,1680041014.914 [NAL9602](INFO): GPS fix at 20230328T220334: (36.802776, -121.787925) 2023-03-28T22:03:34.964Z,1680041014.964 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T22:03:34.964Z,1680041014.964 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T22:03:45.455Z,1680041025.455 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0060.lzma 2023-03-28T22:03:46.458Z,1680041026.458 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0060.lzma.bak 2023-03-28T22:03:46.458Z,1680041026.458 [DataOverHttps](INFO): SBD MOMSN=17738042 2023-03-28T22:04:02.387Z,1680041042.387 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20230328T201444/Express0061.lzma 2023-03-28T22:04:03.390Z,1680041043.390 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0061.lzma.bak 2023-03-28T22:04:03.390Z,1680041043.390 [DataOverHttps](INFO): SBD MOMSN=17738045 2023-03-28T22:04:04.870Z,1680041044.870 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T22:04:04.870Z,1680041044.870 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T22:04:04.870Z,1680041044.870 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T22:04:07.290Z,1680041047.290 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T22:05:03.899Z,1680041103.899 [DVL_micro](ERROR): Failed to parse:00000000000,.4,0000.0,1489:WI,-01550,-00883,-0000,A 2023-03-28T22:08:13.815Z,1680041293.815 [DVL_micro](ERROR): only read 0 of 4 data items 2023-03-28T22:08:13.815Z,1680041293.815 [DVL_micro](ERROR): Failed to parse: :RD,,+9999.99,++9999.99 2023-03-28T22:09:05.536Z,1680041345.536 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T22:09:05.536Z,1680041345.536 [Default:CheckIn:C.Wait] Stopped 2023-03-28T22:09:05.536Z,1680041345.536 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T22:09:05.536Z,1680041345.536 [Default:CheckIn:D] Running Loop=1 2023-03-28T22:09:05.935Z,1680041345.935 [Default:CheckIn:D] Stopped 2023-03-28T22:09:05.935Z,1680041345.935 [Default:CheckIn:E] Running Loop=1 2023-03-28T22:09:06.343Z,1680041346.343 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 295.117285 min 2023-03-28T22:09:06.343Z,1680041346.343 [Default:CheckIn:E] Stopped 2023-03-28T22:09:06.343Z,1680041346.343 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T22:09:06.343Z,1680041346.343 [Default:CheckIn] Stopped 2023-03-28T22:09:06.344Z,1680041346.344 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:09:06.344Z,1680041346.344 [Default:CheckIn](INFO): Running loop #54 2023-03-28T22:09:06.344Z,1680041346.344 [Default:CheckIn] Running Loop=54 2023-03-28T22:09:06.344Z,1680041346.344 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T22:09:06.344Z,1680041346.344 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T22:09:08.352Z,1680041348.352 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220907.00,A,3648.17095,N,12147.28400,W,0.544,291.26,280323,,,D*78 2023-03-28T22:09:08.354Z,1680041348.354 [NAL9602](INFO): GPS fix at 20230328T220907: (36.802849, -121.788067) 2023-03-28T22:09:08.364Z,1680041348.364 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T22:09:08.365Z,1680041348.365 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T22:09:16.479Z,1680041356.479 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0063.lzma 2023-03-28T22:09:17.482Z,1680041357.482 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0063.lzma.bak 2023-03-28T22:09:17.482Z,1680041357.482 [DataOverHttps](INFO): SBD MOMSN=17738058 2023-03-28T22:09:33.867Z,1680041373.867 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0064.lzma 2023-03-28T22:09:34.870Z,1680041374.870 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0064.lzma.bak 2023-03-28T22:09:34.870Z,1680041374.870 [DataOverHttps](INFO): SBD MOMSN=17738062 2023-03-28T22:09:36.251Z,1680041376.251 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T22:09:36.251Z,1680041376.251 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T22:09:36.251Z,1680041376.251 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T22:09:39.090Z,1680041379.090 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-28T22:09:39.184Z,1680041379.184 [NAL9602](ERROR): received: +CSQ:0 OK553, 2, 0, 0, 0 OK 2023-03-28T22:11:26.564Z,1680041486.564 [DVL_micro](ERROR): Failed to parse: :SA,-02.72,+00.90,351.0 2023-03-28T22:11:59.291Z,1680041519.291 [CBIT](IMPORTANT): Beginning ground fault scan 2023-03-28T22:12:10.217Z,1680041530.217 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.034389 CHAN A1 (24V): 0.075274 CHAN A2 (12V): 0.023794 CHAN A3 (5V): 0.002549 CHAN B0 (3.3V): 0.000890 CHAN B1 (3.15aV): 0.001381 CHAN B2 (3.15bV): 0.000781 CHAN B3 (GND): -0.006384 OPEN: 0.007378 Full Scale: +/- 1 mA 2023-03-28T22:12:55.442Z,1680041575.442 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T22:12:55.442Z,1680041575.442 [DVL_micro](ERROR): Failed to parse: :BI,-01520,-03378,-0000,I 2023-03-28T22:13:48.462Z,1680041628.462 [Reporter](INFO): NAL9602.sigQuality 1 count 2023-03-28T22:13:56.930Z,1680041636.930 [Reporter](INFO): NAL9602.sigQuality 0 count 2023-03-28T22:14:10.204Z,1680041650.204 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T22:14:36.912Z,1680041676.912 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T22:14:36.912Z,1680041676.912 [Default:CheckIn:C.Wait] Stopped 2023-03-28T22:14:36.912Z,1680041676.912 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T22:14:36.912Z,1680041676.912 [Default:CheckIn:D] Running Loop=1 2023-03-28T22:14:37.305Z,1680041677.305 [Default:CheckIn:D] Stopped 2023-03-28T22:14:37.305Z,1680041677.305 [Default:CheckIn:E] Running Loop=1 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 300.640137 min 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn:E] Stopped 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn] Stopped 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn](INFO): Running loop #55 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn] Running Loop=55 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T22:14:37.691Z,1680041677.691 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T22:14:39.301Z,1680041679.301 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T22:14:39.302Z,1680041679.302 [DVL_micro](ERROR): Failed to parse: :BI,-0154,-01687,+00000,I 2023-03-28T22:14:39.707Z,1680041679.707 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221439.00,A,3648.16531,N,12147.28545,W,0.603,291.26,280323,,,D*73 2023-03-28T22:14:39.710Z,1680041679.710 [NAL9602](INFO): GPS fix at 20230328T221439: (36.802755, -121.788091) 2023-03-28T22:14:39.729Z,1680041679.729 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T22:14:39.729Z,1680041679.729 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T22:14:46.920Z,1680041686.920 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0066.lzma 2023-03-28T22:14:47.922Z,1680041687.922 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0066.lzma.bak 2023-03-28T22:14:47.922Z,1680041687.922 [DataOverHttps](INFO): SBD MOMSN=17738447 2023-03-28T22:15:03.796Z,1680041703.796 [DataOverHttps](INFO): Sending 377 bytes from file Logs/20230328T201444/Express0067.lzma 2023-03-28T22:15:04.798Z,1680041704.798 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0067.lzma.bak 2023-03-28T22:15:04.798Z,1680041704.798 [DataOverHttps](INFO): SBD MOMSN=17738451 2023-03-28T22:15:06.179Z,1680041706.179 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T22:15:06.179Z,1680041706.179 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T22:15:06.179Z,1680041706.179 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T22:15:12.246Z,1680041712.246 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T22:17:49.391Z,1680041869.391 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T22:17:49.391Z,1680041869.391 [DVL_micro](ERROR): Failed to parse: :BI,-0389,-01595,+00000,I 2023-03-28T22:20:06.778Z,1680042006.778 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T22:20:06.778Z,1680042006.778 [Default:CheckIn:C.Wait] Stopped 2023-03-28T22:20:06.778Z,1680042006.778 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T22:20:06.778Z,1680042006.778 [Default:CheckIn:D] Running Loop=1 2023-03-28T22:20:07.170Z,1680042007.170 [Default:CheckIn:D] Stopped 2023-03-28T22:20:07.170Z,1680042007.170 [Default:CheckIn:E] Running Loop=1 2023-03-28T22:20:07.574Z,1680042007.574 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 306.137891 min 2023-03-28T22:20:07.574Z,1680042007.574 [Default:CheckIn:E] Stopped 2023-03-28T22:20:07.574Z,1680042007.574 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T22:20:07.574Z,1680042007.574 [Default:CheckIn] Stopped 2023-03-28T22:20:07.574Z,1680042007.574 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:20:07.574Z,1680042007.574 [Default:CheckIn](INFO): Running loop #56 2023-03-28T22:20:07.574Z,1680042007.574 [Default:CheckIn] Running Loop=56 2023-03-28T22:20:07.575Z,1680042007.575 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T22:20:07.575Z,1680042007.575 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T22:20:09.595Z,1680042009.595 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222009.00,A,3648.16667,N,12147.28052,W,4.004,276.26,280323,,,A*7D 2023-03-28T22:20:09.598Z,1680042009.598 [NAL9602](INFO): GPS fix at 20230328T222009: (36.802778, -121.788009) 2023-03-28T22:20:09.608Z,1680042009.608 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T22:20:09.608Z,1680042009.608 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T22:20:20.059Z,1680042020.059 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0069.lzma 2023-03-28T22:20:21.062Z,1680042021.062 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0069.lzma.bak 2023-03-28T22:20:21.062Z,1680042021.062 [DataOverHttps](INFO): SBD MOMSN=17738464 2023-03-28T22:20:40.432Z,1680042040.432 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230328T201444/Express0070.lzma 2023-03-28T22:20:41.430Z,1680042041.430 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0070.lzma.bak 2023-03-28T22:20:41.430Z,1680042041.430 [DataOverHttps](INFO): SBD MOMSN=17738468 2023-03-28T22:20:42.797Z,1680042042.797 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T22:20:42.797Z,1680042042.797 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T22:20:42.797Z,1680042042.797 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T22:20:59.788Z,1680042059.788 [DVL_micro](ERROR): only read 3 of 4 data items 2023-03-28T22:20:59.788Z,1680042059.788 [DVL_micro](ERROR): Failed to parse: :BI,-0162,-00951,+00000,I 2023-03-28T22:23:50.637Z,1680042230.637 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-03-28T22:23:50.637Z,1680042230.637 [DropWeight] Hardware Fault, FailCount= 1 2023-03-28T22:23:50.637Z,1680042230.637 [DropWeight](ERROR): Hardware Fault 2023-03-28T22:23:50.691Z,1680042230.691 [CBIT](INFO): Critical error at 20230328T222350 2023-03-28T22:23:50.702Z,1680042230.702 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-03-28T22:23:50.702Z,1680042230.702 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-03-28T22:23:51.073Z,1680042231.073 [CBIT](INFO): Critical error at 20230328T222350 2023-03-28T22:24:09.630Z,1680042249.630 [DVL_micro](ERROR): Failed to parse: :WI,+00730,+00835,-02479,+00000,A 2023-03-28T22:25:12.253Z,1680042312.253 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T22:25:42.951Z,1680042342.951 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T22:25:43.396Z,1680042343.396 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T22:25:43.396Z,1680042343.396 [Default:CheckIn:C.Wait] Stopped 2023-03-28T22:25:43.397Z,1680042343.397 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T22:25:43.397Z,1680042343.397 [Default:CheckIn:D] Running Loop=1 2023-03-28T22:25:43.774Z,1680042343.774 [Default:CheckIn:D] Stopped 2023-03-28T22:25:43.774Z,1680042343.774 [Default:CheckIn:E] Running Loop=1 2023-03-28T22:25:44.175Z,1680042344.175 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 311.747949 min 2023-03-28T22:25:44.175Z,1680042344.175 [Default:CheckIn:E] Stopped 2023-03-28T22:25:44.175Z,1680042344.175 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T22:25:44.175Z,1680042344.175 [Default:CheckIn] Stopped 2023-03-28T22:25:44.175Z,1680042344.175 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:25:44.175Z,1680042344.175 [Default:CheckIn](INFO): Running loop #57 2023-03-28T22:25:44.176Z,1680042344.176 [Default:CheckIn] Running Loop=57 2023-03-28T22:25:44.176Z,1680042344.176 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T22:25:44.176Z,1680042344.176 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T22:25:46.268Z,1680042346.268 [DVL_micro](ERROR): DVL uart error: serial timeout 2023-03-28T22:25:46.268Z,1680042346.268 [DVL_micro] Communications Fault, FailCount= 1 2023-03-28T22:25:46.268Z,1680042346.268 [DVL_micro](ERROR): Communications Fault 2023-03-28T22:25:46.268Z,1680042346.268 [DVL_micro](ERROR): Failed to parse: 2023-03-28T22:25:46.271Z,1680042346.271 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222545.00,A,3648.15195,N,12147.27896,W,0.719,218.69,280323,,,A*7A 2023-03-28T22:25:46.274Z,1680042346.274 [NAL9602](INFO): GPS fix at 20230328T222545: (36.802532, -121.787983) 2023-03-28T22:25:46.308Z,1680042346.308 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T22:25:46.309Z,1680042346.309 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T22:25:46.326Z,1680042346.326 [CBIT](ERROR): Communications Fault in component: DVL_micro 2023-03-28T22:25:46.652Z,1680042346.652 [DVL_micro](INFO): Powering down 2023-03-28T22:25:47.466Z,1680042347.466 [CBIT](INFO): Clearing failed state for component DVL_micro 2023-03-28T22:25:47.466Z,1680042347.466 [DVL_micro] No Fault, FailCount= 1 2023-03-28T22:25:53.195Z,1680042353.195 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20230328T201444/Courier0072.lzma 2023-03-28T22:25:54.198Z,1680042354.198 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0072.lzma.bak 2023-03-28T22:25:54.198Z,1680042354.198 [DataOverHttps](INFO): SBD MOMSN=17738853 2023-03-28T22:26:10.100Z,1680042370.100 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20230328T201444/Express0073.lzma 2023-03-28T22:26:11.102Z,1680042371.102 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0073.lzma.bak 2023-03-28T22:26:11.102Z,1680042371.102 [DataOverHttps](INFO): SBD MOMSN=17738863 2023-03-28T22:26:12.500Z,1680042372.500 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T22:26:12.500Z,1680042372.500 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T22:26:12.500Z,1680042372.500 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T22:26:16.922Z,1680042376.922 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-28T22:26:16.000Z,1680042377.000 [NAL9602](ERROR): received: +CSQ:0 OK553, 2, 0, 0, 0 OK 2023-03-28T22:28:07.230Z,1680042487.230 [DVL_micro](ERROR): Failed to parse: :SA,-03.63,+08.47,228.0 2023-03-28T22:30:48.011Z,1680042648.011 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-03-28T22:31:13.071Z,1680042673.071 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T22:31:13.071Z,1680042673.071 [Default:CheckIn:C.Wait] Stopped 2023-03-28T22:31:13.071Z,1680042673.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T22:31:13.071Z,1680042673.071 [Default:CheckIn:D] Running Loop=1 2023-03-28T22:31:13.488Z,1680042673.488 [Default:CheckIn:D] Stopped 2023-03-28T22:31:13.488Z,1680042673.488 [Default:CheckIn:E] Running Loop=1 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 317.243164 min 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn:E] Stopped 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn] Stopped 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn](INFO): Running loop #58 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn] Running Loop=58 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T22:31:13.874Z,1680042673.874 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T22:31:15.891Z,1680042675.891 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223115.00,A,3648.17574,N,12147.27476,W,0.525,0.00,280323,,,A*78 2023-03-28T22:31:15.894Z,1680042675.894 [NAL9602](INFO): GPS fix at 20230328T223115: (36.802929, -121.787913) 2023-03-28T22:31:15.904Z,1680042675.904 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T22:31:15.904Z,1680042675.904 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-03-28T22:31:23.268Z,1680042683.268 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230328T201444/Courier0075.lzma 2023-03-28T22:31:24.270Z,1680042684.270 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Courier0075.lzma.bak 2023-03-28T22:31:24.270Z,1680042684.270 [DataOverHttps](INFO): SBD MOMSN=17738867 2023-03-28T22:31:40.182Z,1680042700.182 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T22:31:40.182Z,1680042700.182 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+1.0,1489.0,000 2023-03-28T22:31:43.048Z,1680042703.048 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20230328T201444/Express0076.lzma 2023-03-28T22:31:44.034Z,1680042704.034 [DataOverHttps](INFO): Moved sent file to Logs/20230328T201444/Express0076.lzma.bak 2023-03-28T22:31:44.034Z,1680042704.034 [DataOverHttps](INFO): SBD MOMSN=17738870 2023-03-28T22:31:45.438Z,1680042705.438 [Default:CheckIn:Read_Iridium] Stopped 2023-03-28T22:31:45.439Z,1680042705.439 [Default:CheckIn:C.Wait] Running Loop=1 2023-03-28T22:31:45.439Z,1680042705.439 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-03-28T22:31:48.248Z,1680042708.248 [NAL9602](INFO): Not Powering down - fast GPS 2023-03-28T22:34:55.328Z,1680042895.328 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.99,000.00 2023-03-28T22:35:48.880Z,1680042948.880 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-03-28T22:36:20.004Z,1680042980.004 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-03-28T22:36:46.024Z,1680043006.024 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-03-28T22:36:46.024Z,1680043006.024 [Default:CheckIn:C.Wait] Stopped 2023-03-28T22:36:46.024Z,1680043006.024 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-03-28T22:36:46.024Z,1680043006.024 [Default:CheckIn:D] Running Loop=1 2023-03-28T22:36:46.439Z,1680043006.439 [Default:CheckIn:D] Stopped 2023-03-28T22:36:46.439Z,1680043006.439 [Default:CheckIn:E] Running Loop=1 2023-03-28T22:36:46.861Z,1680043006.861 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 322.792350 min 2023-03-28T22:36:46.861Z,1680043006.861 [Default:CheckIn:E] Stopped 2023-03-28T22:36:46.861Z,1680043006.861 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-03-28T22:36:46.861Z,1680043006.861 [Default:CheckIn] Stopped 2023-03-28T22:36:46.861Z,1680043006.861 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:36:46.861Z,1680043006.861 [Default:CheckIn](INFO): Running loop #59 2023-03-28T22:36:46.861Z,1680043006.861 [Default:CheckIn] Running Loop=59 2023-03-28T22:36:46.862Z,1680043006.862 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-03-28T22:36:46.862Z,1680043006.862 [Default:CheckIn:Read_GPS] Running Loop=1 2023-03-28T22:36:51.128Z,1680043011.128 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-03-28T22:37:19.541Z,1680043039.541 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-03-28T22:37:19.616Z,1680043039.616 [NAL9602](ERROR): received: +CSQ:0 OK553, 2, 0, 0, 0 OK 2023-03-28T22:37:22.252Z,1680043042.252 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-03-28T22:37:37.340Z,1680043057.340 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-03-28T22:37:37.340Z,1680043057.340 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+15.7,089.0,000 2023-03-28T22:37:53.388Z,1680043073.388 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-03-28T22:37:56.401Z,1680043076.401 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.747833 2023-03-28T22:38:50.874Z,1680043130.874 [CBIT](INFO): Clearing failed state for component DropWeight 2023-03-28T22:38:50.874Z,1680043130.874 [DropWeight] No Fault, FailCount= 1 2023-03-28T22:38:54.632Z,1680043134.632 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-03-28T22:39:05.164Z,1680043145.164 [CommandExec](IMPORTANT): got command quit 2023-03-28T22:39:06.168Z,1680043146.168 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:06.168Z,1680043146.168 [CommandExec](INFO): Uninitializing the command executive. 2023-03-28T22:39:06.168Z,1680043146.168 [CommandExec](INFO): Uninitializing the command scheduler. 2023-03-28T22:39:06.168Z,1680043146.168 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.220Z,1680043146.220 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-03-28T22:39:06.220Z,1680043146.220 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-03-28T22:39:06.220Z,1680043146.220 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.221Z,1680043146.221 [NavChartDb](INFO): Join timeout helper Thread ID is 9598 2023-03-28T22:39:06.332Z,1680043146.332 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:06.332Z,1680043146.332 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.344Z,1680043146.344 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2023-03-28T22:39:06.344Z,1680043146.344 [DAT ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.344Z,1680043146.344 [DAT](INFO): Join timeout helper Thread ID is 9599 2023-03-28T22:39:06.460Z,1680043146.460 [DAT](INFO): Powering down 2023-03-28T22:39:06.532Z,1680043146.532 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:06.533Z,1680043146.533 [DAT](INFO): Powering down 2023-03-28T22:39:06.533Z,1680043146.533 [DAT ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.544Z,1680043146.544 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-03-28T22:39:06.544Z,1680043146.544 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.544Z,1680043146.544 [Radio_Surface](INFO): Join timeout helper Thread ID is 9600 2023-03-28T22:39:06.724Z,1680043146.724 [Radio_Surface](INFO): Powering down 2023-03-28T22:39:06.725Z,1680043146.725 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:06.725Z,1680043146.725 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.736Z,1680043146.736 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-03-28T22:39:06.736Z,1680043146.736 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:06.736Z,1680043146.736 [Onboard](INFO): Join timeout helper Thread ID is 9601 2023-03-28T22:39:10.228Z,1680043150.228 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:10.228Z,1680043150.228 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.244Z,1680043150.244 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-03-28T22:39:10.244Z,1680043150.244 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.244Z,1680043150.244 [DataOverHttps](INFO): Join timeout helper Thread ID is 9602 2023-03-28T22:39:10.696Z,1680043150.696 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:10.696Z,1680043150.696 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.713Z,1680043150.713 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2023-03-28T22:39:10.713Z,1680043150.713 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.713Z,1680043150.713 [BackseatComponent](INFO): Join timeout helper Thread ID is 9603 2023-03-28T22:39:10.768Z,1680043150.768 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:10.769Z,1680043150.769 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.777Z,1680043150.777 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-03-28T22:39:10.777Z,1680043150.777 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.777Z,1680043150.777 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9604 2023-03-28T22:39:10.916Z,1680043150.916 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:10.916Z,1680043150.916 [WetLabsBB2FL](INFO): Powering down 2023-03-28T22:39:10.917Z,1680043150.917 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.937Z,1680043150.937 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-03-28T22:39:10.937Z,1680043150.937 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:10.937Z,1680043150.937 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9605 2023-03-28T22:39:11.488Z,1680043151.488 [CTD_Seabird](INFO): Powering down 2023-03-28T22:39:11.500Z,1680043151.500 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:11.500Z,1680043151.500 [CTD_Seabird](INFO): Powering down 2023-03-28T22:39:11.512Z,1680043151.512 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:11.525Z,1680043151.525 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-03-28T22:39:11.525Z,1680043151.525 [logger ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:11.525Z,1680043151.525 [logger](INFO): Join timeout helper Thread ID is 9606 2023-03-28T22:39:11.554Z,1680043151.554 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:11.555Z,1680043151.555 [logger ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:11.578Z,1680043151.578 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-03-28T22:39:11.578Z,1680043151.578 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:11.579Z,1680043151.579 [CommandLine](INFO): Join timeout helper Thread ID is 9607 2023-03-28T22:39:11.616Z,1680043151.616 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:11.616Z,1680043151.616 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:11.636Z,1680043151.636 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-03-28T22:39:11.637Z,1680043151.637 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:11.637Z,1680043151.637 [CommandExec](INFO): Join timeout helper Thread ID is 9608 2023-03-28T22:39:11.638Z,1680043151.638 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-03-28T22:39:11.638Z,1680043151.638 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:11.639Z,1680043151.639 [controlThread](INFO): Join timeout helper Thread ID is 9609 2023-03-28T22:39:11.832Z,1680043151.832 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-03-28T22:39:11.832Z,1680043151.832 [controlThread](DEBUG): Uninitializing ControlThread 2023-03-28T22:39:11.833Z,1680043151.833 [AHRS_M2](INFO): Powering down 2023-03-28T22:39:11.976Z,1680043151.976 [DVL_micro](INFO): Powering down 2023-03-28T22:39:11.977Z,1680043151.977 [MultiRay](INFO): Powering down. 2023-03-28T22:39:11.978Z,1680043151.978 [NAL9602](INFO): Powering down 2023-03-28T22:39:11.979Z,1680043151.979 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-03-28T22:39:11.980Z,1680043151.980 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2023-03-28T22:39:11.981Z,1680043151.981 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2023-03-28T22:39:11.982Z,1680043151.982 [MissionManager](INFO): Uninitializing Mission Default 2023-03-28T22:39:11.982Z,1680043151.982 [Default] Stopped 2023-03-28T22:39:11.982Z,1680043151.982 [Default](DEBUG): Aggregate::uninitialize Default 2023-03-28T22:39:11.982Z,1680043151.982 [Default:B.GoToSurface] Stopped 2023-03-28T22:39:11.982Z,1680043151.982 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-03-28T22:39:11.982Z,1680043151.982 [Default:CheckIn] Stopped 2023-03-28T22:39:11.982Z,1680043151.982 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-03-28T22:39:11.982Z,1680043151.982 [Default:CheckIn:Read_GPS] Stopped 2023-03-28T22:39:11.985Z,1680043151.985 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2023-03-28T22:39:11.985Z,1680043151.985 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2023-03-28T22:39:11.986Z,1680043151.986 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2023-03-28T22:39:11.986Z,1680043151.986 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2023-03-28T22:39:11.986Z,1680043151.986 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2023-03-28T22:39:11.986Z,1680043151.986 [BuoyancyServo](INFO): Powering down 2023-03-28T22:39:11.000Z,1680043152.000 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2023-03-28T22:39:12.000Z,1680043152.000 [ElevatorServo](INFO): Powering down 2023-03-28T22:39:12.001Z,1680043152.001 [MassServo](DEBUG): Uninitialize Mass Servo. 2023-03-28T22:39:12.001Z,1680043152.001 [MassServo](INFO): Powering down 2023-03-28T22:39:12.002Z,1680043152.002 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-03-28T22:39:12.002Z,1680043152.002 [RudderServo](INFO): Powering down 2023-03-28T22:39:12.003Z,1680043152.003 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2023-03-28T22:39:12.003Z,1680043152.003 [ThrusterHE](INFO): Powering down 2023-03-28T22:39:12.004Z,1680043152.004 [SBIT](DEBUG): Uninitialize SBIT Component. 2023-03-28T22:39:12.004Z,1680043152.004 [IBIT](DEBUG): Uninitialize IBIT Component. 2023-03-28T22:39:12.004Z,1680043152.004 [CBIT](DEBUG): Uninitialize CBIT Component. 2023-03-28T22:39:12.005Z,1680043152.005 [CBIT](DEBUG): Powering off loads. 2023-03-28T22:39:12.016Z,1680043152.016 [CBIT](DEBUG): Disabling WDT. 2023-03-28T22:39:12.028Z,1680043152.028 [CBIT](DEBUG): Opening all GF detection circuits. 2023-03-28T22:39:12.029Z,1680043152.029 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.067Z,1680043152.067 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.072Z,1680043152.072 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.101Z,1680043152.101 [DAT ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.105Z,1680043152.105 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.107Z,1680043152.107 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.115Z,1680043152.115 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.158Z,1680043152.158 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.208Z,1680043152.208 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-03-28T22:39:12.275Z,1680043152.275 [logger ThreadHandler](INFO): Thread cancelled.