2022-05-24T17:19:58.713Z,1653412798.713 [CommandExec](IMPORTANT): got command restart logs 2022-05-24T17:20:10.024Z,1653412810.024 [DataOverHttps](INFO): Sending 324 bytes from file Logs/20220524T102542/Express0076.lzma 2022-05-24T17:20:11.026Z,1653412811.026 [DataOverHttps](INFO): Moved sent file to Logs/20220524T102542/Express0076.lzma.bak 2022-05-24T17:20:11.026Z,1653412811.026 [DataOverHttps](INFO): SBD MOMSN=16824160 2022-05-24T17:20:13.537Z,1653412813.537 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T17:20:24.048Z,1653412824.048 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-24T17:20:24.048Z,1653412824.048 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+0.0,1489.0,000 2022-05-24T17:20:26.927Z,1653412826.927 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220524T102542/Courier0078.lzma 2022-05-24T17:20:27.930Z,1653412827.930 [DataOverHttps](INFO): Moved sent file to Logs/20220524T102542/Courier0078.lzma.bak 2022-05-24T17:20:27.930Z,1653412827.930 [DataOverHttps](INFO): SBD MOMSN=16824167 2022-05-24T17:20:46.948Z,1653412846.948 [DataOverHttps](INFO): Sending 107 bytes from file Logs/20220524T102542/Express0079.lzma 2022-05-24T17:20:47.950Z,1653412847.950 [DataOverHttps](INFO): Moved sent file to Logs/20220524T102542/Express0079.lzma.bak 2022-05-24T17:20:47.950Z,1653412847.950 [DataOverHttps](INFO): SBD MOMSN=16824172 2022-05-24T17:20:50.379Z,1653412850.379 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T17:20:50.379Z,1653412850.379 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T17:20:50.379Z,1653412850.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T17:23:09.169Z,1653412989.169 [DataOverHttps](IMPORTANT): SBD MTMSN=20220524T172305 2022-05-24T17:23:16.507Z,1653412996.507 [DataOverHttps](INFO): Received command: strobe off 2022-05-24T17:23:16.561Z,1653412996.561 [CommandExec](IMPORTANT): got command strobe off 2022-05-24T17:23:16.561Z,1653412996.561 [CommandExec](IMPORTANT): Deactivating strobe 2022-05-24T17:25:41.908Z,1653413141.908 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:25:50.939Z,1653413150.939 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T17:25:50.939Z,1653413150.939 [Default:CheckIn:C.Wait] Stopped 2022-05-24T17:25:50.939Z,1653413150.939 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T17:25:50.939Z,1653413150.939 [Default:CheckIn:D] Running Loop=1 2022-05-24T17:25:51.347Z,1653413151.347 [Default:CheckIn:D] Stopped 2022-05-24T17:25:51.348Z,1653413151.348 [Default:CheckIn:E] Running Loop=1 2022-05-24T17:25:51.764Z,1653413151.764 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.445789 min 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn:E] Stopped 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn] Stopped 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn](INFO): Running loop #2 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn] Running Loop=2 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T17:25:51.765Z,1653413151.765 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T17:25:53.759Z,1653413153.759 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172550.00,A,3424.84654,N,11949.71742,W,0.019,227.10,240522,,,D*79 2022-05-24T17:25:53.761Z,1653413153.761 [NAL9602](INFO): GPS fix at 20220524T172550: (34.414109, -119.828624) 2022-05-24T17:25:53.772Z,1653413153.772 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T17:25:53.772Z,1653413153.772 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T17:26:09.149Z,1653413169.149 [NAL9602](INFO): SBD MO Status=1, MOMSN=47135, MT Status=0, MTMSN=0 2022-05-24T17:26:09.149Z,1653413169.149 [NAL9602](INFO): No messages in MT queue 2022-05-24T17:26:13.044Z,1653413173.044 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:26:39.851Z,1653413199.851 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T17:26:44.168Z,1653413204.168 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:27:15.296Z,1653413235.296 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:27:26.726Z,1653413246.726 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2022-05-24T17:27:46.420Z,1653413266.420 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:27:50.437Z,1653413270.437 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.743637 2022-05-24T17:28:18.165Z,1653413298.165 [NAL9602](INFO): SBD MO Status=2, MOMSN=47136, MT Status=2, MTMSN=0 2022-05-24T17:28:18.165Z,1653413298.165 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:28:21.580Z,1653413301.580 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:28:30.397Z,1653413310.397 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003677 2022-05-24T17:28:39.600Z,1653413319.600 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20220524T171958/Courier0003.lzma 2022-05-24T17:28:40.602Z,1653413320.602 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0003.lzma.bak 2022-05-24T17:28:40.602Z,1653413320.602 [DataOverHttps](INFO): SBD MOMSN=16824198 2022-05-24T17:29:00.996Z,1653413340.996 [DataOverHttps](INFO): Sending 508 bytes from file Logs/20220524T171958/Express0004.lzma 2022-05-24T17:29:01.999Z,1653413341.999 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0004.lzma.bak 2022-05-24T17:29:01.999Z,1653413341.999 [DataOverHttps](INFO): SBD MOMSN=16824209 2022-05-24T17:29:03.485Z,1653413343.485 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T17:29:18.871Z,1653413358.871 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220524T171958/Express0007.lzma 2022-05-24T17:29:19.874Z,1653413359.874 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0007.lzma.bak 2022-05-24T17:29:19.874Z,1653413359.874 [DataOverHttps](INFO): SBD MOMSN=16824224 2022-05-24T17:29:22.085Z,1653413362.085 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T17:29:22.085Z,1653413362.085 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T17:29:22.086Z,1653413362.086 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T17:30:29.564Z,1653413429.564 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:31:00.688Z,1653413460.688 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:31:01.855Z,1653413461.855 [DVL_micro](ERROR): Failed to parse: 01,+00391,00000,A 2022-05-24T17:31:31.812Z,1653413491.812 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:32:02.956Z,1653413522.956 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:34:22.763Z,1653413662.763 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T17:34:22.763Z,1653413662.763 [Default:CheckIn:C.Wait] Stopped 2022-05-24T17:34:22.763Z,1653413662.763 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T17:34:22.768Z,1653413662.768 [Default:CheckIn:D] Running Loop=1 2022-05-24T17:34:23.153Z,1653413663.153 [Default:CheckIn:D] Stopped 2022-05-24T17:34:23.153Z,1653413663.153 [Default:CheckIn:E] Running Loop=1 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.975879 min 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn:E] Stopped 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn] Stopped 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn](INFO): Running loop #3 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn] Running Loop=3 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T17:34:23.555Z,1653413663.555 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T17:34:25.577Z,1653413665.577 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173421.00,A,3424.84666,N,11949.71778,W,0.078,164.81,240522,,,D*7C 2022-05-24T17:34:25.580Z,1653413665.580 [NAL9602](INFO): GPS fix at 20220524T173421: (34.414111, -119.828630) 2022-05-24T17:34:25.591Z,1653413665.591 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T17:34:25.591Z,1653413665.591 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T17:34:33.531Z,1653413673.531 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0009.lzma 2022-05-24T17:34:34.533Z,1653413674.533 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0009.lzma.bak 2022-05-24T17:34:34.534Z,1653413674.534 [DataOverHttps](INFO): SBD MOMSN=16824253 2022-05-24T17:34:37.297Z,1653413677.297 [DVL_micro](ERROR): only read 0 of 4 data items 2022-05-24T17:34:37.297Z,1653413677.297 [DVL_micro](ERROR): Failed to parse: :RD,++9999.99,+99999.99 2022-05-24T17:34:49.469Z,1653413689.469 [NAL9602](INFO): SBD MO Status=2, MOMSN=47136, MT Status=2, MTMSN=0 2022-05-24T17:34:49.469Z,1653413689.469 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:34:56.727Z,1653413696.727 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220524T171958/Express0010.lzma 2022-05-24T17:34:57.730Z,1653413697.730 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0010.lzma.bak 2022-05-24T17:34:57.730Z,1653413697.730 [DataOverHttps](INFO): SBD MOMSN=16824287 2022-05-24T17:34:59.998Z,1653413699.998 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T17:34:59.998Z,1653413699.998 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T17:34:59.999Z,1653413699.999 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T17:35:57.346Z,1653413757.346 [NAL9602](INFO): SBD MO Status=1, MOMSN=47136, MT Status=0, MTMSN=0 2022-05-24T17:35:57.346Z,1653413757.346 [NAL9602](INFO): No messages in MT queue 2022-05-24T17:36:03.447Z,1653413763.447 [CBIT](IMPORTANT): Beginning ground fault scan 2022-05-24T17:36:10.116Z,1653413770.116 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:36:14.357Z,1653413774.357 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.019969 CHAN A1 (24V): 0.015998 CHAN A2 (12V): -0.017188 CHAN A3 (5V): -0.027809 CHAN B0 (3.3V): -0.012460 CHAN B1 (3.15aV): -0.006361 CHAN B2 (3.15bV): -0.003020 CHAN B3 (GND): -0.014556 OPEN: 0.009623 Full Scale: +/- 1 mA 2022-05-24T17:36:28.049Z,1653413788.049 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T17:36:43.819Z,1653413803.819 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-24T17:36:43.833Z,1653413803.833 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2022-05-24T17:37:12.068Z,1653413832.068 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:37:43.196Z,1653413863.196 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:38:14.340Z,1653413894.340 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-05-24T17:39:35.926Z,1653413975.926 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-24T17:39:35.927Z,1653413975.927 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+16.81489.0,000 2022-05-24T17:40:00.583Z,1653414000.583 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T17:40:00.583Z,1653414000.583 [Default:CheckIn:C.Wait] Stopped 2022-05-24T17:40:00.583Z,1653414000.583 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T17:40:00.583Z,1653414000.583 [Default:CheckIn:D] Running Loop=1 2022-05-24T17:40:00.981Z,1653414000.981 [Default:CheckIn:D] Stopped 2022-05-24T17:40:00.982Z,1653414000.982 [Default:CheckIn:E] Running Loop=1 2022-05-24T17:40:01.397Z,1653414001.397 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.606356 min 2022-05-24T17:40:01.397Z,1653414001.397 [Default:CheckIn:E] Stopped 2022-05-24T17:40:01.398Z,1653414001.398 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T17:40:01.398Z,1653414001.398 [Default:CheckIn] Stopped 2022-05-24T17:40:01.398Z,1653414001.398 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T17:40:01.398Z,1653414001.398 [Default:CheckIn](INFO): Running loop #4 2022-05-24T17:40:01.398Z,1653414001.398 [Default:CheckIn] Running Loop=4 2022-05-24T17:40:01.398Z,1653414001.398 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T17:40:01.398Z,1653414001.398 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T17:40:03.401Z,1653414003.401 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173959.00,A,3424.84664,N,11949.71776,W,0.097,274.09,240522,,,D*71 2022-05-24T17:40:03.403Z,1653414003.403 [NAL9602](INFO): GPS fix at 20220524T173959: (34.414111, -119.828629) 2022-05-24T17:40:03.413Z,1653414003.413 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T17:40:03.414Z,1653414003.414 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T17:40:10.515Z,1653414010.515 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0012.lzma 2022-05-24T17:40:11.518Z,1653414011.518 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0012.lzma.bak 2022-05-24T17:40:11.518Z,1653414011.518 [DataOverHttps](INFO): SBD MOMSN=16824296 2022-05-24T17:40:27.392Z,1653414027.392 [DataOverHttps](INFO): Sending 330 bytes from file Logs/20220524T171958/Express0013.lzma 2022-05-24T17:40:28.393Z,1653414028.393 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0013.lzma.bak 2022-05-24T17:40:28.394Z,1653414028.394 [DataOverHttps](INFO): SBD MOMSN=16824302 2022-05-24T17:40:30.227Z,1653414030.227 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T17:40:30.227Z,1653414030.227 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T17:40:30.227Z,1653414030.227 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T17:41:52.613Z,1653414112.613 [DVL_micro](ERROR): Failed to parse: 0000000000,35.0,+16.9,0000.0,1489.0,000 2022-05-24T17:43:21.545Z,1653414201.545 [NAL9602](INFO): SBD MO Status=2, MOMSN=47137, MT Status=2, MTMSN=0 2022-05-24T17:43:21.545Z,1653414201.545 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:44:19.771Z,1653414259.771 [NAL9602](INFO): SBD MO Status=2, MOMSN=47137, MT Status=2, MTMSN=0 2022-05-24T17:44:19.771Z,1653414259.771 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:44:59.431Z,1653414299.431 [NAL9602](INFO): SBD MO Status=2, MOMSN=47137, MT Status=2, MTMSN=0 2022-05-24T17:44:59.431Z,1653414299.431 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:45:05.480Z,1653414305.480 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-24T17:45:30.945Z,1653414330.945 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T17:45:30.945Z,1653414330.945 [Default:CheckIn:C.Wait] Stopped 2022-05-24T17:45:30.945Z,1653414330.945 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T17:45:30.945Z,1653414330.945 [Default:CheckIn:D] Running Loop=1 2022-05-24T17:45:31.351Z,1653414331.351 [Default:CheckIn:D] Stopped 2022-05-24T17:45:31.351Z,1653414331.351 [Default:CheckIn:E] Running Loop=1 2022-05-24T17:45:31.755Z,1653414331.755 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.112510 min 2022-05-24T17:45:31.756Z,1653414331.756 [Default:CheckIn:E] Stopped 2022-05-24T17:45:31.756Z,1653414331.756 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T17:45:31.756Z,1653414331.756 [Default:CheckIn] Stopped 2022-05-24T17:45:31.756Z,1653414331.756 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T17:45:31.756Z,1653414331.756 [Default:CheckIn](INFO): Running loop #5 2022-05-24T17:45:31.756Z,1653414331.756 [Default:CheckIn] Running Loop=5 2022-05-24T17:45:31.756Z,1653414331.756 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T17:45:31.757Z,1653414331.757 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T17:45:32.959Z,1653414332.959 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-24T17:45:32.960Z,1653414332.960 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2022-05-24T17:45:33.765Z,1653414333.765 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174530.00,A,3424.84718,N,11949.71728,W,0.019,167.42,240522,,,D*7C 2022-05-24T17:45:33.767Z,1653414333.767 [NAL9602](INFO): GPS fix at 20220524T174530: (34.414120, -119.828621) 2022-05-24T17:45:33.798Z,1653414333.798 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T17:45:33.798Z,1653414333.798 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T17:45:44.279Z,1653414344.279 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0015.lzma 2022-05-24T17:45:45.282Z,1653414345.282 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0015.lzma.bak 2022-05-24T17:45:45.282Z,1653414345.282 [DataOverHttps](INFO): SBD MOMSN=16824312 2022-05-24T17:46:02.584Z,1653414362.584 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20220524T171958/Express0016.lzma 2022-05-24T17:46:03.586Z,1653414363.586 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0016.lzma.bak 2022-05-24T17:46:03.586Z,1653414363.586 [DataOverHttps](INFO): SBD MOMSN=16824318 2022-05-24T17:46:05.799Z,1653414365.799 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T17:46:05.799Z,1653414365.799 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T17:46:05.799Z,1653414365.799 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T17:46:06.555Z,1653414366.555 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T17:51:06.338Z,1653414666.338 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T17:51:06.338Z,1653414666.338 [Default:CheckIn:C.Wait] Stopped 2022-05-24T17:51:06.338Z,1653414666.338 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T17:51:06.338Z,1653414666.338 [Default:CheckIn:D] Running Loop=1 2022-05-24T17:51:06.750Z,1653414666.750 [Default:CheckIn:D] Stopped 2022-05-24T17:51:06.751Z,1653414666.751 [Default:CheckIn:E] Running Loop=1 2022-05-24T17:51:07.133Z,1653414667.133 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.702507 min 2022-05-24T17:51:07.133Z,1653414667.133 [Default:CheckIn:E] Stopped 2022-05-24T17:51:07.133Z,1653414667.133 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T17:51:07.133Z,1653414667.133 [Default:CheckIn] Stopped 2022-05-24T17:51:07.133Z,1653414667.133 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T17:51:07.133Z,1653414667.133 [Default:CheckIn](INFO): Running loop #6 2022-05-24T17:51:07.133Z,1653414667.133 [Default:CheckIn] Running Loop=6 2022-05-24T17:51:07.134Z,1653414667.134 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T17:51:07.134Z,1653414667.134 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T17:51:09.163Z,1653414669.163 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175105.00,A,3424.84643,N,11949.71668,W,0.019,167.42,240522,,,D*75 2022-05-24T17:51:09.165Z,1653414669.165 [NAL9602](INFO): GPS fix at 20220524T175105: (34.414107, -119.828611) 2022-05-24T17:51:09.175Z,1653414669.175 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T17:51:09.175Z,1653414669.175 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T17:51:16.051Z,1653414676.051 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0018.lzma 2022-05-24T17:51:17.054Z,1653414677.054 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0018.lzma.bak 2022-05-24T17:51:17.054Z,1653414677.054 [DataOverHttps](INFO): SBD MOMSN=16824326 2022-05-24T17:51:33.091Z,1653414693.091 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220524T171958/Express0019.lzma 2022-05-24T17:51:34.094Z,1653414694.094 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0019.lzma.bak 2022-05-24T17:51:34.094Z,1653414694.094 [DataOverHttps](INFO): SBD MOMSN=16824332 2022-05-24T17:51:37.574Z,1653414697.574 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T17:51:37.574Z,1653414697.574 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T17:51:37.575Z,1653414697.575 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T17:51:39.568Z,1653414699.568 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2022-05-24T17:51:39.647Z,1653414699.647 [NAL9602](ERROR): received: +CSQ:0 OK137, 2, 0, 0, 0 OK 2022-05-24T17:52:53.135Z,1653414773.135 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-24T17:52:53.140Z,1653414773.140 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35,0000.0,1489.0,000 2022-05-24T17:53:45.245Z,1653414825.245 [NAL9602](INFO): SBD MO Status=2, MOMSN=47137, MT Status=2, MTMSN=0 2022-05-24T17:53:45.245Z,1653414825.245 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:54:32.575Z,1653414872.575 [NAL9602](INFO): SBD MO Status=2, MOMSN=47137, MT Status=2, MTMSN=0 2022-05-24T17:54:32.575Z,1653414872.575 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:54:59.648Z,1653414899.648 [NAL9602](INFO): SBD MO Status=1, MOMSN=47137, MT Status=0, MTMSN=0 2022-05-24T17:54:59.648Z,1653414899.648 [NAL9602](INFO): No messages in MT queue 2022-05-24T17:55:30.341Z,1653414930.341 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T17:56:28.126Z,1653414988.126 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-24T17:56:28.127Z,1653414988.127 [DVL_micro](ERROR): Failed to parse: :BI,+00423,-1570,+00000,I 2022-05-24T17:56:38.242Z,1653414998.242 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T17:56:38.242Z,1653414998.242 [Default:CheckIn:C.Wait] Stopped 2022-05-24T17:56:38.242Z,1653414998.242 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T17:56:38.242Z,1653414998.242 [Default:CheckIn:D] Running Loop=1 2022-05-24T17:56:38.627Z,1653414998.627 [Default:CheckIn:D] Stopped 2022-05-24T17:56:38.627Z,1653414998.627 [Default:CheckIn:E] Running Loop=1 2022-05-24T17:56:39.038Z,1653414999.038 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.233781 min 2022-05-24T17:56:39.038Z,1653414999.038 [Default:CheckIn:E] Stopped 2022-05-24T17:56:39.038Z,1653414999.038 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T17:56:39.038Z,1653414999.038 [Default:CheckIn] Stopped 2022-05-24T17:56:39.038Z,1653414999.038 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T17:56:39.039Z,1653414999.039 [Default:CheckIn](INFO): Running loop #7 2022-05-24T17:56:39.039Z,1653414999.039 [Default:CheckIn] Running Loop=7 2022-05-24T17:56:39.039Z,1653414999.039 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T17:56:39.039Z,1653414999.039 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T17:56:41.042Z,1653415001.042 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175637.00,A,3424.84815,N,11949.71703,W,0.194,273.52,240522,,,D*71 2022-05-24T17:56:41.064Z,1653415001.064 [NAL9602](INFO): GPS fix at 20220524T175637: (34.414136, -119.828617) 2022-05-24T17:56:41.082Z,1653415001.082 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T17:56:41.083Z,1653415001.083 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T17:56:49.631Z,1653415009.631 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0021.lzma 2022-05-24T17:56:50.640Z,1653415010.640 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0021.lzma.bak 2022-05-24T17:56:50.641Z,1653415010.641 [DataOverHttps](INFO): SBD MOMSN=16824341 2022-05-24T17:57:00.911Z,1653415020.911 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-24T17:57:00.911Z,1653415020.911 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+17.7,089.0,000 2022-05-24T17:57:06.607Z,1653415026.607 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20220524T171958/Express0022.lzma 2022-05-24T17:57:07.610Z,1653415027.610 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0022.lzma.bak 2022-05-24T17:57:07.610Z,1653415027.610 [DataOverHttps](INFO): SBD MOMSN=16824347 2022-05-24T17:57:09.799Z,1653415029.799 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T17:57:09.804Z,1653415029.804 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T17:57:09.804Z,1653415029.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T17:57:14.227Z,1653415034.227 [NAL9602](INFO): SBD MO Status=2, MOMSN=47138, MT Status=2, MTMSN=0 2022-05-24T17:57:14.227Z,1653415034.227 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T17:58:22.139Z,1653415102.139 [NAL9602](INFO): SBD MO Status=1, MOMSN=47138, MT Status=0, MTMSN=0 2022-05-24T17:58:22.139Z,1653415102.139 [NAL9602](INFO): No messages in MT queue 2022-05-24T17:58:52.843Z,1653415132.843 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:02:10.421Z,1653415330.421 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:02:10.422Z,1653415330.422 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:02:10.422Z,1653415330.422 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:02:10.422Z,1653415330.422 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:02:10.825Z,1653415330.825 [Default:CheckIn:D] Stopped 2022-05-24T18:02:10.825Z,1653415330.825 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.770406 min 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn:E] Stopped 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn] Stopped 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn](INFO): Running loop #8 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn] Running Loop=8 2022-05-24T18:02:11.231Z,1653415331.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:02:11.232Z,1653415331.232 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:02:13.250Z,1653415333.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180209.00,A,3424.84765,N,11949.71858,W,0.078,273.52,240522,,,D*78 2022-05-24T18:02:13.252Z,1653415333.252 [NAL9602](INFO): GPS fix at 20220524T180209: (34.414127, -119.828643) 2022-05-24T18:02:13.263Z,1653415333.263 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:02:13.263Z,1653415333.263 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:02:20.859Z,1653415340.859 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0024.lzma 2022-05-24T18:02:21.865Z,1653415341.865 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0024.lzma.bak 2022-05-24T18:02:21.865Z,1653415341.865 [DataOverHttps](INFO): SBD MOMSN=16824361 2022-05-24T18:02:39.507Z,1653415359.507 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220524T171958/Express0025.lzma 2022-05-24T18:02:40.510Z,1653415360.510 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0025.lzma.bak 2022-05-24T18:02:40.510Z,1653415360.510 [DataOverHttps](INFO): SBD MOMSN=16824367 2022-05-24T18:02:43.253Z,1653415363.253 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:02:43.254Z,1653415363.254 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:02:43.254Z,1653415363.254 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:03:22.883Z,1653415402.883 [NAL9602](INFO): SBD MO Status=1, MOMSN=47139, MT Status=0, MTMSN=0 2022-05-24T18:03:22.883Z,1653415402.883 [NAL9602](INFO): No messages in MT queue 2022-05-24T18:03:53.593Z,1653415433.593 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:07:43.889Z,1653415663.889 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:07:43.889Z,1653415663.889 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:07:43.889Z,1653415663.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:07:43.890Z,1653415663.890 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:07:44.282Z,1653415664.282 [Default:CheckIn:D] Stopped 2022-05-24T18:07:44.283Z,1653415664.283 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:07:44.683Z,1653415664.683 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.328040 min 2022-05-24T18:07:44.683Z,1653415664.683 [Default:CheckIn:E] Stopped 2022-05-24T18:07:44.683Z,1653415664.683 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:07:44.683Z,1653415664.683 [Default:CheckIn] Stopped 2022-05-24T18:07:44.683Z,1653415664.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:07:44.684Z,1653415664.684 [Default:CheckIn](INFO): Running loop #9 2022-05-24T18:07:44.684Z,1653415664.684 [Default:CheckIn] Running Loop=9 2022-05-24T18:07:44.684Z,1653415664.684 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:07:44.684Z,1653415664.684 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:07:46.696Z,1653415666.696 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180743.00,A,3424.84743,N,11949.71632,W,0.058,273.52,240522,,,D*77 2022-05-24T18:07:46.698Z,1653415666.698 [NAL9602](INFO): GPS fix at 20220524T180743: (34.414124, -119.828605) 2022-05-24T18:07:46.709Z,1653415666.709 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:07:46.709Z,1653415666.709 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:07:54.355Z,1653415674.355 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0027.lzma 2022-05-24T18:07:55.358Z,1653415675.358 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0027.lzma.bak 2022-05-24T18:07:55.358Z,1653415675.358 [DataOverHttps](INFO): SBD MOMSN=16824379 2022-05-24T18:08:11.636Z,1653415691.636 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20220524T171958/Express0028.lzma 2022-05-24T18:08:12.638Z,1653415692.638 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0028.lzma.bak 2022-05-24T18:08:12.638Z,1653415692.638 [DataOverHttps](INFO): SBD MOMSN=16824385 2022-05-24T18:08:14.615Z,1653415694.615 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:08:14.615Z,1653415694.615 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:08:14.615Z,1653415694.615 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:08:15.805Z,1653415695.805 [NAL9602](INFO): SBD MO Status=1, MOMSN=47140, MT Status=0, MTMSN=0 2022-05-24T18:08:15.805Z,1653415695.805 [NAL9602](INFO): No messages in MT queue 2022-05-24T18:08:46.531Z,1653415726.531 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:09:01.470Z,1653415741.470 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-24T18:09:01.470Z,1653415741.470 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2022-05-24T18:13:09.149Z,1653415989.149 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-24T18:13:09.149Z,1653415989.149 [DVL_micro](ERROR): Failed to parse: :TS,00000000000,+18.4,0000.0,1489.0,000 2022-05-24T18:13:15.195Z,1653415995.195 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:13:15.195Z,1653415995.195 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:13:15.195Z,1653415995.195 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:13:15.196Z,1653415995.196 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:13:15.608Z,1653415995.608 [Default:CheckIn:D] Stopped 2022-05-24T18:13:15.608Z,1653415995.608 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.850134 min 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn:E] Stopped 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn] Stopped 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn](INFO): Running loop #10 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn] Running Loop=10 2022-05-24T18:13:15.995Z,1653415995.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:13:15.996Z,1653415995.996 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:13:18.010Z,1653415998.010 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181314.00,A,3424.84881,N,11949.71734,W,0.039,273.52,240522,,,D*71 2022-05-24T18:13:18.012Z,1653415998.012 [NAL9602](INFO): GPS fix at 20220524T181314: (34.414147, -119.828622) 2022-05-24T18:13:18.022Z,1653415998.022 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:13:18.022Z,1653415998.022 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:13:25.427Z,1653416005.427 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0030.lzma 2022-05-24T18:13:26.430Z,1653416006.430 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0030.lzma.bak 2022-05-24T18:13:26.430Z,1653416006.430 [DataOverHttps](INFO): SBD MOMSN=16824394 2022-05-24T18:13:45.220Z,1653416025.220 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220524T171958/Express0031.lzma 2022-05-24T18:13:46.222Z,1653416026.222 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0031.lzma.bak 2022-05-24T18:13:46.222Z,1653416026.222 [DataOverHttps](INFO): SBD MOMSN=16824400 2022-05-24T18:13:48.385Z,1653416028.385 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:13:48.385Z,1653416028.385 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:13:48.385Z,1653416028.385 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:14:53.015Z,1653416093.015 [NAL9602](INFO): SBD MO Status=2, MOMSN=47141, MT Status=2, MTMSN=0 2022-05-24T18:14:53.015Z,1653416093.015 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T18:15:03.913Z,1653416103.913 [NAL9602](INFO): SBD MO Status=1, MOMSN=47141, MT Status=0, MTMSN=0 2022-05-24T18:15:03.913Z,1653416103.913 [NAL9602](INFO): No messages in MT queue 2022-05-24T18:15:34.621Z,1653416134.621 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:17:12.037Z,1653416232.037 [DVL_micro](ERROR): Failed to parse: :WI,+01246,-00012,-01204,+00000,A 2022-05-24T18:18:49.006Z,1653416329.006 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:18:49.007Z,1653416329.007 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:18:49.007Z,1653416329.007 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:18:49.007Z,1653416329.007 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:18:49.403Z,1653416329.403 [Default:CheckIn:D] Stopped 2022-05-24T18:18:49.403Z,1653416329.403 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:18:49.815Z,1653416329.815 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.413379 min 2022-05-24T18:18:49.815Z,1653416329.815 [Default:CheckIn:E] Stopped 2022-05-24T18:18:49.815Z,1653416329.815 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:18:49.816Z,1653416329.816 [Default:CheckIn] Stopped 2022-05-24T18:18:49.816Z,1653416329.816 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:18:49.816Z,1653416329.816 [Default:CheckIn](INFO): Running loop #11 2022-05-24T18:18:49.816Z,1653416329.816 [Default:CheckIn] Running Loop=11 2022-05-24T18:18:49.816Z,1653416329.816 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:18:49.816Z,1653416329.816 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:18:51.831Z,1653416331.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181848.00,A,3424.84860,N,11949.71922,W,0.019,273.52,240522,,,D*77 2022-05-24T18:18:51.834Z,1653416331.834 [NAL9602](INFO): GPS fix at 20220524T181848: (34.414143, -119.828654) 2022-05-24T18:18:51.844Z,1653416331.844 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:18:51.844Z,1653416331.844 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:18:58.811Z,1653416338.811 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220524T171958/Courier0033.lzma 2022-05-24T18:18:59.814Z,1653416339.814 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0033.lzma.bak 2022-05-24T18:18:59.814Z,1653416339.814 [DataOverHttps](INFO): SBD MOMSN=16824409 2022-05-24T18:19:14.467Z,1653416354.467 [NAL9602](INFO): SBD MO Status=1, MOMSN=47142, MT Status=0, MTMSN=0 2022-05-24T18:19:14.467Z,1653416354.467 [NAL9602](INFO): No messages in MT queue 2022-05-24T18:19:15.951Z,1653416355.951 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20220524T171958/Express0034.lzma 2022-05-24T18:19:16.954Z,1653416356.954 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0034.lzma.bak 2022-05-24T18:19:16.954Z,1653416356.954 [DataOverHttps](INFO): SBD MOMSN=16824415 2022-05-24T18:19:18.925Z,1653416358.925 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:19:18.925Z,1653416358.925 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:19:18.925Z,1653416358.925 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:19:45.166Z,1653416385.166 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:21:09.613Z,1653416469.613 [DVL_micro](ERROR): Failed to parse:125,+00349,-01241,+00000,I 2022-05-24T18:24:19.516Z,1653416659.516 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:24:19.517Z,1653416659.517 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:24:19.517Z,1653416659.517 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:24:19.517Z,1653416659.517 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:24:19.906Z,1653416659.906 [Default:CheckIn:D] Stopped 2022-05-24T18:24:19.906Z,1653416659.906 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.921761 min 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn:E] Stopped 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn] Stopped 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn](INFO): Running loop #12 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn] Running Loop=12 2022-05-24T18:24:20.307Z,1653416660.307 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:24:20.308Z,1653416660.308 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:24:22.318Z,1653416662.318 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182418.00,A,3424.84836,N,11949.71622,W,0.019,273.52,240522,,,D*71 2022-05-24T18:24:22.332Z,1653416662.332 [NAL9602](INFO): GPS fix at 20220524T182418: (34.414139, -119.828604) 2022-05-24T18:24:22.355Z,1653416662.355 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:24:22.355Z,1653416662.355 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:24:29.939Z,1653416669.939 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0036.lzma 2022-05-24T18:24:30.942Z,1653416670.942 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0036.lzma.bak 2022-05-24T18:24:30.942Z,1653416670.942 [DataOverHttps](INFO): SBD MOMSN=16824424 2022-05-24T18:24:47.439Z,1653416687.439 [NAL9602](INFO): SBD MO Status=2, MOMSN=47143, MT Status=2, MTMSN=0 2022-05-24T18:24:47.444Z,1653416687.444 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-05-24T18:24:50.011Z,1653416690.011 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20220524T171958/Express0037.lzma 2022-05-24T18:24:51.014Z,1653416691.014 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0037.lzma.bak 2022-05-24T18:24:51.014Z,1653416691.014 [DataOverHttps](INFO): SBD MOMSN=16824430 2022-05-24T18:24:53.113Z,1653416693.113 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:24:53.113Z,1653416693.113 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:24:53.114Z,1653416693.114 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:24:59.941Z,1653416699.941 [NAL9602](INFO): SBD MO Status=1, MOMSN=47143, MT Status=0, MTMSN=0 2022-05-24T18:24:59.941Z,1653416699.941 [NAL9602](INFO): No messages in MT queue 2022-05-24T18:25:30.645Z,1653416730.645 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:29:04.960Z,1653416944.960 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-24T18:29:04.960Z,1653416944.960 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+190,1489.0I,+01162,+00026,-01162,+00000+01162,+00026,-01162,+00000,I 2022-05-24T18:29:20.659Z,1653416960.659 [CommandExec](IMPORTANT): got command report touch NAL9602.sigQuality 2022-05-24T18:29:53.518Z,1653416993.518 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:29:53.518Z,1653416993.518 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:29:53.518Z,1653416993.518 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:29:53.518Z,1653416993.518 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:29:53.921Z,1653416993.921 [Default:CheckIn:D] Stopped 2022-05-24T18:29:53.921Z,1653416993.921 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:29:54.327Z,1653416994.327 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.488680 min 2022-05-24T18:29:54.327Z,1653416994.327 [Default:CheckIn:E] Stopped 2022-05-24T18:29:54.327Z,1653416994.327 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:29:54.327Z,1653416994.327 [Default:CheckIn] Stopped 2022-05-24T18:29:54.327Z,1653416994.327 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:29:54.327Z,1653416994.327 [Default:CheckIn](INFO): Running loop #13 2022-05-24T18:29:54.328Z,1653416994.328 [Default:CheckIn] Running Loop=13 2022-05-24T18:29:54.328Z,1653416994.328 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:29:54.328Z,1653416994.328 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:29:56.344Z,1653416996.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182952.00,A,3424.84881,N,11949.71611,W,0.097,273.52,240522,,,D*78 2022-05-24T18:29:56.346Z,1653416996.346 [NAL9602](INFO): GPS fix at 20220524T182952: (34.414147, -119.828602) 2022-05-24T18:29:56.357Z,1653416996.357 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:29:56.357Z,1653416996.357 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:30:04.035Z,1653417004.035 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220524T171958/Courier0039.lzma 2022-05-24T18:30:04.866Z,1653417004.866 [Reporter](INFO): NAL9602.sigQuality 5 count 2022-05-24T18:30:05.038Z,1653417005.038 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0039.lzma.bak 2022-05-24T18:30:05.038Z,1653417005.038 [DataOverHttps](INFO): SBD MOMSN=16824439 2022-05-24T18:30:18.969Z,1653417018.969 [NAL9602](INFO): SBD MO Status=1, MOMSN=47144, MT Status=0, MTMSN=0 2022-05-24T18:30:18.969Z,1653417018.969 [NAL9602](INFO): No messages in MT queue 2022-05-24T18:30:21.003Z,1653417021.003 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20220524T171958/Express0040.lzma 2022-05-24T18:30:22.006Z,1653417022.006 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0040.lzma.bak 2022-05-24T18:30:22.006Z,1653417022.006 [DataOverHttps](INFO): SBD MOMSN=16824445 2022-05-24T18:30:24.245Z,1653417024.245 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:30:24.245Z,1653417024.245 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:30:24.245Z,1653417024.245 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:30:49.676Z,1653417049.676 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:30:49.720Z,1653417049.720 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:32:55.339Z,1653417175.339 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-05-24T18:32:55.339Z,1653417175.339 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+19.2,0000.0,1489.0,000 2022-05-24T18:35:14.025Z,1653417314.025 [DVL_micro](ERROR): only read 3 of 4 data items 2022-05-24T18:35:14.025Z,1653417314.025 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2022-05-24T18:35:24.913Z,1653417324.913 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:35:24.913Z,1653417324.913 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:35:24.913Z,1653417324.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:35:24.914Z,1653417324.914 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:35:25.327Z,1653417325.327 [Default:CheckIn:D] Stopped 2022-05-24T18:35:25.327Z,1653417325.327 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:35:25.736Z,1653417325.736 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.012109 min 2022-05-24T18:35:25.736Z,1653417325.736 [Default:CheckIn:E] Stopped 2022-05-24T18:35:25.736Z,1653417325.736 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:35:25.736Z,1653417325.736 [Default:CheckIn] Stopped 2022-05-24T18:35:25.736Z,1653417325.736 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:35:25.737Z,1653417325.737 [Default:CheckIn](INFO): Running loop #14 2022-05-24T18:35:25.737Z,1653417325.737 [Default:CheckIn] Running Loop=14 2022-05-24T18:35:25.737Z,1653417325.737 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:35:25.737Z,1653417325.737 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:35:27.733Z,1653417327.733 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183524.00,A,3424.84878,N,11949.71736,W,0.039,273.52,240522,,,D*72 2022-05-24T18:35:27.735Z,1653417327.735 [NAL9602](INFO): GPS fix at 20220524T183524: (34.414146, -119.828623) 2022-05-24T18:35:27.746Z,1653417327.746 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:35:27.746Z,1653417327.746 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:35:34.743Z,1653417334.743 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220524T171958/Courier0042.lzma 2022-05-24T18:35:35.076Z,1653417335.076 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:35:35.746Z,1653417335.746 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0042.lzma.bak 2022-05-24T18:35:35.746Z,1653417335.746 [DataOverHttps](INFO): SBD MOMSN=16824459 2022-05-24T18:35:39.095Z,1653417339.095 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:35:48.079Z,1653417348.079 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:35:52.129Z,1653417352.129 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:35:56.519Z,1653417356.519 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:35:56.608Z,1653417356.608 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20220524T171958/Express0043.lzma 2022-05-24T18:35:57.365Z,1653417357.365 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:35:57.610Z,1653417357.610 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0043.lzma.bak 2022-05-24T18:35:57.610Z,1653417357.610 [DataOverHttps](INFO): SBD MOMSN=16824466 2022-05-24T18:35:59.817Z,1653417359.817 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:35:59.817Z,1653417359.817 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:35:59.817Z,1653417359.817 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:36:01.381Z,1653417361.381 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:05.039Z,1653417365.039 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:13.534Z,1653417373.534 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:22.403Z,1653417382.403 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:30.863Z,1653417390.863 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:39.425Z,1653417399.425 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:48.346Z,1653417408.346 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:49.958Z,1653417409.958 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:36:56.827Z,1653417416.827 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:05.347Z,1653417425.347 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:09.816Z,1653417429.816 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:14.210Z,1653417434.210 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:22.685Z,1653417442.685 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:31.570Z,1653417451.570 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:40.077Z,1653417460.077 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:48.566Z,1653417468.566 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:53.003Z,1653417473.003 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:37:57.450Z,1653417477.450 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:05.966Z,1653417485.966 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:10.395Z,1653417490.395 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:14.450Z,1653417494.450 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:18.850Z,1653417498.850 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:24.942Z,1653417504.942 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:28.958Z,1653417508.958 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:33.403Z,1653417513.403 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:41.902Z,1653417521.902 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:38:50.846Z,1653417530.846 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:52.055Z,1653417532.055 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:38:58.134Z,1653417538.134 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:39:00.546Z,1653417540.546 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:39:09.422Z,1653417549.422 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:39:15.510Z,1653417555.510 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:39:17.911Z,1653417557.911 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:39:24.406Z,1653417564.406 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:39:26.417Z,1653417566.417 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:39:35.278Z,1653417575.278 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:39:43.367Z,1653417583.367 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:39:51.878Z,1653417591.878 [Reporter](INFO): NAL9602.sigQuality 2 count 2022-05-24T18:40:04.332Z,1653417604.332 [NAL9602](INFO): SBD MO Status=1, MOMSN=47145, MT Status=0, MTMSN=0 2022-05-24T18:40:04.332Z,1653417604.332 [NAL9602](INFO): No messages in MT queue 2022-05-24T18:40:35.041Z,1653417635.041 [NAL9602](INFO): Not Powering down - fast GPS 2022-05-24T18:40:35.093Z,1653417635.093 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:41:00.275Z,1653417660.275 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:41:00.275Z,1653417660.275 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:41:00.275Z,1653417660.275 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:41:00.278Z,1653417660.278 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:41:00.503Z,1653417660.503 [Default:CheckIn:D] Stopped 2022-05-24T18:41:00.503Z,1653417660.503 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:41:00.899Z,1653417660.899 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.598389 min 2022-05-24T18:41:00.899Z,1653417660.899 [Default:CheckIn:E] Stopped 2022-05-24T18:41:00.899Z,1653417660.899 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:41:00.899Z,1653417660.899 [Default:CheckIn] Stopped 2022-05-24T18:41:00.899Z,1653417660.899 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:41:00.900Z,1653417660.900 [Default:CheckIn](INFO): Running loop #15 2022-05-24T18:41:00.900Z,1653417660.900 [Default:CheckIn] Running Loop=15 2022-05-24T18:41:00.900Z,1653417660.900 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:41:00.900Z,1653417660.900 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:41:02.933Z,1653417662.933 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184059.00,A,3424.84878,N,11949.71678,W,0.039,0.00,240522,,,D*70 2022-05-24T18:41:02.935Z,1653417662.935 [NAL9602](INFO): GPS fix at 20220524T184059: (34.414146, -119.828613) 2022-05-24T18:41:02.946Z,1653417662.946 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:41:02.946Z,1653417662.946 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:41:10.095Z,1653417670.095 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220524T171958/Courier0045.lzma 2022-05-24T18:41:11.030Z,1653417671.030 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:41:11.098Z,1653417671.098 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Courier0045.lzma.bak 2022-05-24T18:41:11.098Z,1653417671.098 [DataOverHttps](INFO): SBD MOMSN=16824494 2022-05-24T18:41:19.511Z,1653417679.511 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:41:26.786Z,1653417686.786 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:41:27.188Z,1653417687.188 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220524T171958/Express0046.lzma 2022-05-24T18:41:28.190Z,1653417688.190 [DataOverHttps](INFO): Moved sent file to Logs/20220524T171958/Express0046.lzma.bak 2022-05-24T18:41:28.190Z,1653417688.190 [DataOverHttps](INFO): SBD MOMSN=16824497 2022-05-24T18:41:30.474Z,1653417690.474 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:41:30.474Z,1653417690.474 [Default:CheckIn:C.Wait] Running Loop=1 2022-05-24T18:41:30.474Z,1653417690.474 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-05-24T18:41:35.319Z,1653417695.319 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:41:44.328Z,1653417704.328 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:41:52.690Z,1653417712.690 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:41:55.889Z,1653417715.889 [DVL_micro](ERROR): Failed to parse: :B,-00070,-0070,I 2022-05-24T18:42:01.178Z,1653417721.178 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:10.077Z,1653417730.077 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:18.582Z,1653417738.582 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:22.994Z,1653417742.994 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:27.431Z,1653417747.431 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:29.850Z,1653417749.850 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:38.373Z,1653417758.373 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:42.856Z,1653417762.856 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:47.366Z,1653417767.366 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:42:51.347Z,1653417771.347 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:00.206Z,1653417780.206 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:08.687Z,1653417788.687 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:10.302Z,1653417790.302 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:17.577Z,1653417797.577 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:21.646Z,1653417801.646 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:27.273Z,1653417807.273 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:36.150Z,1653417816.150 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:44.699Z,1653417824.699 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:43:53.514Z,1653417833.514 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:44:02.047Z,1653417842.047 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:10.495Z,1653417850.495 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:19.404Z,1653417859.404 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:21.416Z,1653417861.416 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:30.730Z,1653417870.730 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:36.419Z,1653417876.419 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:43.657Z,1653417883.657 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:45.270Z,1653417885.270 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:44:53.722Z,1653417893.722 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:44:56.146Z,1653417896.146 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-05-24T18:45:05.054Z,1653417905.054 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:09.482Z,1653417909.482 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:15.583Z,1653417915.583 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:19.583Z,1653417919.583 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:26.854Z,1653417926.854 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:28.082Z,1653417928.082 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:35.343Z,1653417935.343 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:36.967Z,1653417936.967 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:43.827Z,1653417943.827 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:49.627Z,1653417949.627 [CommandExec](IMPORTANT): got command configSet MassServo.loadAtStartup 1 bool persist 2022-05-24T18:45:49.629Z,1653417949.629 [CommandExec](IMPORTANT): configSet MassServo.loadAtStartup requires a restart to take effect. 2022-05-24T18:45:52.740Z,1653417952.740 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:45:53.930Z,1653417953.930 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:46:02.845Z,1653417962.845 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-05-24T18:46:05.604Z,1653417965.604 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-05-24T18:46:21.825Z,1653417981.825 [DataOverHttps](IMPORTANT): SBD MTMSN=20220524T184617 2022-05-24T18:46:29.400Z,1653417989.400 [DataOverHttps](INFO): Received command: restart app 2022-05-24T18:46:29.441Z,1653417989.441 [CommandExec](IMPORTANT): got command restart application 2022-05-24T18:46:30.448Z,1653417990.448 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:30.448Z,1653417990.448 [CommandExec](INFO): Uninitializing the command executive. 2022-05-24T18:46:30.448Z,1653417990.448 [CommandExec](INFO): Uninitializing the command scheduler. 2022-05-24T18:46:30.449Z,1653417990.449 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:30.504Z,1653417990.504 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-05-24T18:46:30.504Z,1653417990.504 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-05-24T18:46:30.504Z,1653417990.504 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:30.505Z,1653417990.505 [NavChartDb](INFO): Join timeout helper Thread ID is 9809 2022-05-24T18:46:30.832Z,1653417990.832 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:30.832Z,1653417990.832 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:30.844Z,1653417990.844 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-05-24T18:46:30.844Z,1653417990.844 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:30.844Z,1653417990.844 [Radio_Surface](INFO): Join timeout helper Thread ID is 9810 2022-05-24T18:46:30.860Z,1653417990.860 [Radio_Surface](INFO): Powering down 2022-05-24T18:46:30.862Z,1653417990.862 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:30.863Z,1653417990.863 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:30.874Z,1653417990.874 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-05-24T18:46:30.874Z,1653417990.874 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:30.874Z,1653417990.874 [Onboard](INFO): Join timeout helper Thread ID is 9811 2022-05-24T18:46:31.063Z,1653417991.063 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-05-24T18:46:31.063Z,1653417991.063 [Default:CheckIn:C.Wait] Stopped 2022-05-24T18:46:31.063Z,1653417991.063 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-05-24T18:46:31.076Z,1653417991.076 [Default:CheckIn:D] Running Loop=1 2022-05-24T18:46:31.404Z,1653417991.404 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-05-24T18:46:31.465Z,1653417991.465 [Default:CheckIn:D] Stopped 2022-05-24T18:46:31.465Z,1653417991.465 [Default:CheckIn:E] Running Loop=1 2022-05-24T18:46:31.875Z,1653417991.875 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.114421 min 2022-05-24T18:46:31.875Z,1653417991.875 [Default:CheckIn:E] Stopped 2022-05-24T18:46:31.875Z,1653417991.875 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-05-24T18:46:31.875Z,1653417991.875 [Default:CheckIn] Stopped 2022-05-24T18:46:31.875Z,1653417991.875 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:46:31.875Z,1653417991.875 [Default:CheckIn](INFO): Running loop #16 2022-05-24T18:46:31.876Z,1653417991.876 [Default:CheckIn] Running Loop=16 2022-05-24T18:46:31.876Z,1653417991.876 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-05-24T18:46:31.876Z,1653417991.876 [Default:CheckIn:Read_GPS] Running Loop=1 2022-05-24T18:46:33.884Z,1653417993.884 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184630.00,A,3424.84939,N,11949.71699,W,0.253,230.87,240522,,,D*72 2022-05-24T18:46:33.886Z,1653417993.886 [NAL9602](INFO): GPS fix at 20220524T184630: (34.414156, -119.828616) 2022-05-24T18:46:33.897Z,1653417993.897 [Default:CheckIn:Read_GPS] Stopped 2022-05-24T18:46:33.897Z,1653417993.897 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-05-24T18:46:35.776Z,1653417995.776 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:35.776Z,1653417995.776 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:35.796Z,1653417995.796 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-05-24T18:46:35.796Z,1653417995.796 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:35.796Z,1653417995.796 [DataOverHttps](INFO): Join timeout helper Thread ID is 9812 2022-05-24T18:46:36.424Z,1653417996.424 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:36.425Z,1653417996.425 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.436Z,1653417996.436 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-05-24T18:46:36.436Z,1653417996.436 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.436Z,1653417996.436 [BackseatComponent](INFO): Join timeout helper Thread ID is 9813 2022-05-24T18:46:36.624Z,1653417996.624 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:36.624Z,1653417996.624 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.645Z,1653417996.645 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-05-24T18:46:36.645Z,1653417996.645 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.645Z,1653417996.645 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9814 2022-05-24T18:46:36.720Z,1653417996.720 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:36.720Z,1653417996.720 [WetLabsBB2FL](INFO): Powering down 2022-05-24T18:46:36.721Z,1653417996.721 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.725Z,1653417996.725 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-05-24T18:46:36.725Z,1653417996.725 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.725Z,1653417996.725 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9815 2022-05-24T18:46:36.740Z,1653417996.740 [CTD_Seabird](INFO): Powering down 2022-05-24T18:46:36.752Z,1653417996.752 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:36.752Z,1653417996.752 [CTD_Seabird](INFO): Powering down 2022-05-24T18:46:36.764Z,1653417996.764 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.781Z,1653417996.781 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-05-24T18:46:36.781Z,1653417996.781 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.781Z,1653417996.781 [logger](INFO): Join timeout helper Thread ID is 9816 2022-05-24T18:46:36.789Z,1653417996.789 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:36.789Z,1653417996.789 [logger ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.797Z,1653417996.797 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-05-24T18:46:36.797Z,1653417996.797 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.797Z,1653417996.797 [CommandLine](INFO): Join timeout helper Thread ID is 9817 2022-05-24T18:46:36.876Z,1653417996.876 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:36.876Z,1653417996.876 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.886Z,1653417996.886 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-05-24T18:46:36.886Z,1653417996.886 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.886Z,1653417996.886 [CommandExec](INFO): Join timeout helper Thread ID is 9818 2022-05-24T18:46:36.888Z,1653417996.888 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-05-24T18:46:36.888Z,1653417996.888 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:36.888Z,1653417996.888 [controlThread](INFO): Join timeout helper Thread ID is 9819 2022-05-24T18:46:37.092Z,1653417997.092 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-05-24T18:46:37.092Z,1653417997.092 [controlThread](DEBUG): Uninitializing ControlThread 2022-05-24T18:46:37.094Z,1653417997.094 [AHRS_M2](INFO): Powering down 2022-05-24T18:46:37.236Z,1653417997.236 [DVL_micro](INFO): Powering down 2022-05-24T18:46:37.237Z,1653417997.237 [NAL9602](INFO): Powering down 2022-05-24T18:46:37.238Z,1653417997.238 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-05-24T18:46:37.239Z,1653417997.239 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-05-24T18:46:37.240Z,1653417997.240 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-05-24T18:46:37.241Z,1653417997.241 [MissionManager](INFO): Uninitializing Mission Default 2022-05-24T18:46:37.241Z,1653417997.241 [Default] Stopped 2022-05-24T18:46:37.241Z,1653417997.241 [Default](DEBUG): Aggregate::uninitialize Default 2022-05-24T18:46:37.241Z,1653417997.241 [Default:B.GoToSurface] Stopped 2022-05-24T18:46:37.241Z,1653417997.241 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-05-24T18:46:37.241Z,1653417997.241 [Default:CheckIn] Stopped 2022-05-24T18:46:37.241Z,1653417997.241 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-05-24T18:46:37.241Z,1653417997.241 [Default:CheckIn:Read_Iridium] Stopped 2022-05-24T18:46:37.244Z,1653417997.244 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-05-24T18:46:37.244Z,1653417997.244 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-05-24T18:46:37.244Z,1653417997.244 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-05-24T18:46:37.245Z,1653417997.245 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-05-24T18:46:37.245Z,1653417997.245 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-05-24T18:46:37.245Z,1653417997.245 [BuoyancyServo](INFO): Powering down 2022-05-24T18:46:37.260Z,1653417997.260 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-05-24T18:46:37.260Z,1653417997.260 [ElevatorServo](INFO): Powering down 2022-05-24T18:46:37.261Z,1653417997.261 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-05-24T18:46:37.261Z,1653417997.261 [RudderServo](INFO): Powering down 2022-05-24T18:46:37.262Z,1653417997.262 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-05-24T18:46:37.262Z,1653417997.262 [ThrusterHE](INFO): Powering down 2022-05-24T18:46:37.263Z,1653417997.263 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-05-24T18:46:37.263Z,1653417997.263 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-05-24T18:46:37.263Z,1653417997.263 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-05-24T18:46:37.263Z,1653417997.263 [CBIT](DEBUG): Powering off loads. 2022-05-24T18:46:37.276Z,1653417997.276 [CBIT](DEBUG): Disabling WDT. 2022-05-24T18:46:37.288Z,1653417997.288 [CBIT](DEBUG): Opening all GF detection circuits. 2022-05-24T18:46:37.289Z,1653417997.289 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.345Z,1653417997.345 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.350Z,1653417997.350 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.380Z,1653417997.380 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.382Z,1653417997.382 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.389Z,1653417997.389 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.396Z,1653417997.396 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.445Z,1653417997.445 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-05-24T18:46:37.535Z,1653417997.535 [logger ThreadHandler](INFO): Thread cancelled.