2023-05-15T16:30:22.793Z,1684168222.793 [CommandExec](IMPORTANT): got command restart logs 2023-05-15T16:30:25.611Z,1684168225.611 [NAL9602](INFO): SBD MO Status=2, MOMSN=4016, MT Status=2, MTMSN=0 2023-05-15T16:30:25.611Z,1684168225.611 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:31:00.493Z,1684168260.493 [NAL9602](INFO): SBD MO Status=2, MOMSN=4016, MT Status=2, MTMSN=0 2023-05-15T16:31:00.493Z,1684168260.493 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:31:42.906Z,1684168302.906 [NAL9602](INFO): SBD MO Status=1, MOMSN=4016, MT Status=0, MTMSN=0 2023-05-15T16:31:42.906Z,1684168302.906 [NAL9602](INFO): No messages in MT queue 2023-05-15T16:31:47.284Z,1684168307.284 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:32:03.533Z,1684168323.533 [DVL_micro](ERROR): Failed to parse:233,+0139,+00000,A 2023-05-15T16:32:11.598Z,1684168331.598 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2023-05-15T16:32:13.621Z,1684168333.621 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T16:32:18.416Z,1684168338.416 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:32:49.540Z,1684168369.540 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:33:20.664Z,1684168400.664 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:33:51.788Z,1684168431.788 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:34:02.832Z,1684168442.832 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.727386 2023-05-15T16:34:37.289Z,1684168477.289 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003607 2023-05-15T16:35:09.392Z,1684168509.392 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T16:35:09.392Z,1684168509.392 [Default:CheckIn:C.Wait] Stopped 2023-05-15T16:35:09.392Z,1684168509.392 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T16:35:09.392Z,1684168509.392 [Default:CheckIn:D] Running Loop=1 2023-05-15T16:35:09.833Z,1684168509.833 [Default:CheckIn:D] Stopped 2023-05-15T16:35:09.833Z,1684168509.833 [Default:CheckIn:E] Running Loop=1 2023-05-15T16:35:10.193Z,1684168510.193 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.550551 min 2023-05-15T16:35:10.193Z,1684168510.193 [Default:CheckIn:E] Stopped 2023-05-15T16:35:10.193Z,1684168510.193 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T16:35:10.193Z,1684168510.193 [Default:CheckIn] Stopped 2023-05-15T16:35:10.193Z,1684168510.193 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T16:35:10.193Z,1684168510.193 [Default:CheckIn](INFO): Running loop #6 2023-05-15T16:35:10.193Z,1684168510.193 [Default:CheckIn] Running Loop=6 2023-05-15T16:35:10.194Z,1684168510.194 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T16:35:10.194Z,1684168510.194 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T16:35:12.179Z,1684168512.179 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163510.00,A,3647.72361,N,12150.91162,W,2.255,269.85,150523,,,D*74 2023-05-15T16:35:12.181Z,1684168512.181 [NAL9602](INFO): GPS fix at 20230515T163510: (36.795394, -121.848527) 2023-05-15T16:35:12.190Z,1684168512.190 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T16:35:12.190Z,1684168512.190 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T16:35:23.583Z,1684168523.583 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20230515T025836/Courier0112.lzma 2023-05-15T16:35:24.586Z,1684168524.586 [DataOverHttps](INFO): Moved sent file to Logs/20230515T025836/Courier0112.lzma.bak 2023-05-15T16:35:24.586Z,1684168524.586 [DataOverHttps](INFO): SBD MOMSN=18310526 2023-05-15T16:35:26.315Z,1684168526.315 [DVL_micro](ERROR): Failed to parse: :BI,-03823,+00313,-01317,+00000,I 2023-05-15T16:35:33.942Z,1684168533.942 [DVL_micro](ERROR): Failed to parse: :SA,-02.04,-00.78,014.5 2023-05-15T16:35:43.357Z,1684168543.357 [NAL9602](INFO): SBD MO Status=1, MOMSN=4017, MT Status=0, MTMSN=0 2023-05-15T16:35:43.357Z,1684168543.357 [NAL9602](INFO): No messages in MT queue 2023-05-15T16:35:56.036Z,1684168556.036 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20230515T163022/Courier0000.lzma 2023-05-15T16:35:57.037Z,1684168557.037 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0000.lzma.bak 2023-05-15T16:35:57.037Z,1684168557.037 [DataOverHttps](INFO): SBD MOMSN=18310528 2023-05-15T16:36:12.061Z,1684168572.061 [DVL_micro](ERROR): Failed to parse: :WI,-00276,-00182,-01934,+00000,A 2023-05-15T16:36:13.323Z,1684168573.323 [DataOverHttps](INFO): Sending 97 bytes from file Logs/20230515T025836/Express0113.lzma 2023-05-15T16:36:14.063Z,1684168574.063 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T16:36:14.326Z,1684168574.326 [DataOverHttps](INFO): Moved sent file to Logs/20230515T025836/Express0113.lzma.bak 2023-05-15T16:36:14.326Z,1684168574.326 [DataOverHttps](INFO): SBD MOMSN=18310532 2023-05-15T16:36:31.892Z,1684168591.892 [DataOverHttps](INFO): Sending 380 bytes from file Logs/20230515T163022/Express0001.lzma 2023-05-15T16:36:32.894Z,1684168592.894 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0001.lzma.bak 2023-05-15T16:36:32.894Z,1684168592.894 [DataOverHttps](INFO): SBD MOMSN=18310535 2023-05-15T16:36:52.043Z,1684168612.043 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230515T163022/Express0004.lzma 2023-05-15T16:36:53.045Z,1684168613.045 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0004.lzma.bak 2023-05-15T16:36:53.046Z,1684168613.046 [DataOverHttps](INFO): SBD MOMSN=18310539 2023-05-15T16:36:54.954Z,1684168614.954 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T16:36:54.954Z,1684168614.954 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T16:36:54.955Z,1684168614.955 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T16:37:07.441Z,1684168627.441 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-05-15T16:37:07.443Z,1684168627.443 [BPC1](INFO): Received data from all battery sticks. 2023-05-15T16:38:21.034Z,1684168701.034 [DVL_micro](ERROR): Failed to parse: :SA,-01.96,-01.53,059.7 2023-05-15T16:38:46.542Z,1684168726.542 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T16:38:46.542Z,1684168726.542 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+14.4,0000.0,1489:WI,+01549,+00084,-02341,+00000,A 2023-05-15T16:41:55.685Z,1684168915.685 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T16:41:55.685Z,1684168915.685 [Default:CheckIn:C.Wait] Stopped 2023-05-15T16:41:55.685Z,1684168915.685 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T16:41:55.685Z,1684168915.685 [Default:CheckIn:D] Running Loop=1 2023-05-15T16:41:56.086Z,1684168916.086 [Default:CheckIn:D] Stopped 2023-05-15T16:41:56.086Z,1684168916.086 [Default:CheckIn:E] Running Loop=1 2023-05-15T16:41:56.521Z,1684168916.521 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.321423 min 2023-05-15T16:41:56.521Z,1684168916.521 [Default:CheckIn:E] Stopped 2023-05-15T16:41:56.521Z,1684168916.521 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T16:41:56.521Z,1684168916.521 [Default:CheckIn] Stopped 2023-05-15T16:41:56.522Z,1684168916.522 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T16:41:56.522Z,1684168916.522 [Default:CheckIn](INFO): Running loop #7 2023-05-15T16:41:56.522Z,1684168916.522 [Default:CheckIn] Running Loop=7 2023-05-15T16:41:56.522Z,1684168916.522 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T16:41:56.522Z,1684168916.522 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T16:41:58.507Z,1684168918.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164156.00,A,3647.69929,N,12150.95483,W,0.641,256.52,150523,,,D*72 2023-05-15T16:41:58.518Z,1684168918.518 [NAL9602](INFO): GPS fix at 20230515T164156: (36.794988, -121.849247) 2023-05-15T16:41:58.527Z,1684168918.527 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T16:41:58.527Z,1684168918.527 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T16:42:06.568Z,1684168926.568 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230515T163022/Courier0006.lzma 2023-05-15T16:42:06.602Z,1684168926.602 [DVL_micro](ERROR): only read 2 of 4 data items 2023-05-15T16:42:06.602Z,1684168926.602 [DVL_micro](ERROR): Failed to parse: :BI,-03172,-00001+00000,I 2023-05-15T16:42:07.570Z,1684168927.570 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0006.lzma.bak 2023-05-15T16:42:07.570Z,1684168927.570 [DataOverHttps](INFO): SBD MOMSN=18310545 2023-05-15T16:42:19.913Z,1684168939.913 [NAL9602](INFO): SBD MO Status=2, MOMSN=4018, MT Status=2, MTMSN=0 2023-05-15T16:42:19.913Z,1684168939.913 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:42:46.179Z,1684168966.179 [NAL9602](INFO): SBD MO Status=2, MOMSN=4018, MT Status=2, MTMSN=0 2023-05-15T16:42:46.179Z,1684168966.179 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:43:10.820Z,1684168990.820 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:43:20.515Z,1684169000.515 [NAL9602](INFO): SBD MO Status=2, MOMSN=4018, MT Status=2, MTMSN=0 2023-05-15T16:43:20.515Z,1684169000.515 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:43:41.944Z,1684169021.944 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:43:46.370Z,1684169026.370 [NAL9602](INFO): SBD MO Status=2, MOMSN=4018, MT Status=2, MTMSN=0 2023-05-15T16:43:46.371Z,1684169026.371 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:44:06.975Z,1684169046.975 [NAL9602](INFO): SBD MO Status=1, MOMSN=4018, MT Status=0, MTMSN=0 2023-05-15T16:44:06.975Z,1684169046.975 [NAL9602](INFO): No messages in MT queue 2023-05-15T16:44:13.068Z,1684169053.068 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:44:37.685Z,1684169077.685 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T16:44:44.548Z,1684169084.548 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2023-05-15T16:45:09.016Z,1684169109.016 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=181.446075 2023-05-15T16:45:16.642Z,1684169116.642 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006907 2023-05-15T16:45:23.831Z,1684169123.831 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230515T163022/Express0007.lzma 2023-05-15T16:45:24.833Z,1684169124.833 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0007.lzma.bak 2023-05-15T16:45:24.834Z,1684169124.834 [DataOverHttps](INFO): SBD MOMSN=18310622 2023-05-15T16:45:26.734Z,1684169126.734 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T16:45:26.734Z,1684169126.734 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T16:45:26.734Z,1684169126.734 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T16:45:36.057Z,1684169136.057 [NAL9602](INFO): SBD MO Status=1, MOMSN=4019, MT Status=0, MTMSN=0 2023-05-15T16:45:36.104Z,1684169136.104 [NAL9602](INFO): Sent 130 bytes from file Logs/20230515T163022/Express0007.lzma 2023-05-15T16:45:36.104Z,1684169136.104 [NAL9602](INFO): Packets left to send: 0 2023-05-15T16:46:06.747Z,1684169166.747 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T16:47:59.173Z,1684169279.173 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:50:27.520Z,1684169427.520 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T16:50:27.520Z,1684169427.520 [Default:CheckIn:C.Wait] Stopped 2023-05-15T16:50:27.520Z,1684169427.520 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T16:50:27.521Z,1684169427.521 [Default:CheckIn:D] Running Loop=1 2023-05-15T16:50:27.926Z,1684169427.926 [Default:CheckIn:D] Stopped 2023-05-15T16:50:27.926Z,1684169427.926 [Default:CheckIn:E] Running Loop=1 2023-05-15T16:50:28.336Z,1684169428.336 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.852091 min 2023-05-15T16:50:28.336Z,1684169428.336 [Default:CheckIn:E] Stopped 2023-05-15T16:50:28.337Z,1684169428.337 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T16:50:28.337Z,1684169428.337 [Default:CheckIn] Stopped 2023-05-15T16:50:28.337Z,1684169428.337 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T16:50:28.337Z,1684169428.337 [Default:CheckIn](INFO): Running loop #8 2023-05-15T16:50:28.337Z,1684169428.337 [Default:CheckIn] Running Loop=8 2023-05-15T16:50:28.337Z,1684169428.337 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T16:50:28.337Z,1684169428.337 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T16:50:30.356Z,1684169430.356 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165028.00,A,3647.86646,N,12149.69422,W,22.568,80.83,150523,,,D*71 2023-05-15T16:50:30.358Z,1684169430.358 [NAL9602](INFO): GPS fix at 20230515T165028: (36.797774, -121.828237) 2023-05-15T16:50:30.367Z,1684169430.367 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T16:50:30.367Z,1684169430.367 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T16:50:55.797Z,1684169455.797 [NAL9602](INFO): SBD MO Status=2, MOMSN=4020, MT Status=2, MTMSN=0 2023-05-15T16:50:55.797Z,1684169455.797 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:51:02.256Z,1684169462.256 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T16:51:16.147Z,1684169476.147 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0009.lzma 2023-05-15T16:51:17.149Z,1684169477.149 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0009.lzma.bak 2023-05-15T16:51:17.150Z,1684169477.150 [DataOverHttps](INFO): SBD MOMSN=18310639 2023-05-15T16:51:34.639Z,1684169494.639 [NAL9602](INFO): SBD MO Status=0, MOMSN=4020, MT Status=0, MTMSN=0 2023-05-15T16:51:34.639Z,1684169494.639 [NAL9602](INFO): No messages in MT queue 2023-05-15T16:51:39.043Z,1684169499.043 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20230515T163022/Express0010.lzma 2023-05-15T16:51:40.045Z,1684169500.045 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0010.lzma.bak 2023-05-15T16:51:40.046Z,1684169500.046 [DataOverHttps](INFO): SBD MOMSN=18310642 2023-05-15T16:51:41.933Z,1684169501.933 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T16:51:41.933Z,1684169501.933 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T16:51:41.934Z,1684169501.934 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T16:52:02.121Z,1684169522.121 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T16:52:02.121Z,1684169522.121 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+0.0,1489.WI,-08066,01492,+000I,-08066,-01646,-01492,+00000,I 2023-05-15T16:52:05.346Z,1684169525.346 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T16:56:42.517Z,1684169802.517 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T16:56:42.517Z,1684169802.517 [Default:CheckIn:C.Wait] Stopped 2023-05-15T16:56:42.517Z,1684169802.517 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T16:56:42.517Z,1684169802.517 [Default:CheckIn:D] Running Loop=1 2023-05-15T16:56:42.906Z,1684169802.906 [Default:CheckIn:D] Stopped 2023-05-15T16:56:42.906Z,1684169802.906 [Default:CheckIn:E] Running Loop=1 2023-05-15T16:56:43.307Z,1684169803.307 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.101754 min 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn:E] Stopped 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn] Stopped 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn](INFO): Running loop #9 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn] Running Loop=9 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T16:56:43.308Z,1684169803.308 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T16:56:45.323Z,1684169805.323 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165643.00,A,3648.48890,N,12147.25833,W,7.853,50.81,150523,,,D*45 2023-05-15T16:56:45.325Z,1684169805.325 [NAL9602](INFO): GPS fix at 20230515T165643: (36.808148, -121.787639) 2023-05-15T16:56:45.335Z,1684169805.335 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T16:56:45.335Z,1684169805.335 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T16:56:52.659Z,1684169812.659 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230515T163022/Courier0012.lzma 2023-05-15T16:56:53.661Z,1684169813.661 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0012.lzma.bak 2023-05-15T16:56:53.662Z,1684169813.662 [DataOverHttps](INFO): SBD MOMSN=18310649 2023-05-15T16:57:09.605Z,1684169829.605 [NAL9602](INFO): SBD MO Status=2, MOMSN=4021, MT Status=2, MTMSN=0 2023-05-15T16:57:09.605Z,1684169829.605 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T16:57:12.955Z,1684169832.955 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20230515T163022/Express0013.lzma 2023-05-15T16:57:13.958Z,1684169833.958 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0013.lzma.bak 2023-05-15T16:57:13.958Z,1684169833.958 [DataOverHttps](INFO): SBD MOMSN=18310652 2023-05-15T16:57:15.674Z,1684169835.674 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T16:57:15.674Z,1684169835.674 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T16:57:15.674Z,1684169835.674 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T16:57:20.917Z,1684169840.917 [NAL9602](INFO): SBD MO Status=0, MOMSN=4021, MT Status=0, MTMSN=0 2023-05-15T16:57:20.917Z,1684169840.917 [NAL9602](INFO): No messages in MT queue 2023-05-15T16:57:51.621Z,1684169871.621 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:02:16.267Z,1684170136.267 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:02:16.268Z,1684170136.268 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:02:16.268Z,1684170136.268 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:02:16.268Z,1684170136.268 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:02:16.663Z,1684170136.663 [Default:CheckIn:D] Stopped 2023-05-15T17:02:16.663Z,1684170136.663 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:02:17.064Z,1684170137.064 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.664372 min 2023-05-15T17:02:17.064Z,1684170137.064 [Default:CheckIn:E] Stopped 2023-05-15T17:02:17.064Z,1684170137.064 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:02:17.064Z,1684170137.064 [Default:CheckIn] Stopped 2023-05-15T17:02:17.064Z,1684170137.064 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:02:17.065Z,1684170137.065 [Default:CheckIn](INFO): Running loop #10 2023-05-15T17:02:17.065Z,1684170137.065 [Default:CheckIn] Running Loop=10 2023-05-15T17:02:17.065Z,1684170137.065 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:02:17.065Z,1684170137.065 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:02:19.079Z,1684170139.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170217.00,A,3648.16445,N,12147.17435,W,2.255,217.18,150523,,,D*78 2023-05-15T17:02:19.082Z,1684170139.082 [NAL9602](INFO): GPS fix at 20230515T170217: (36.802741, -121.786239) 2023-05-15T17:02:19.091Z,1684170139.091 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:02:19.091Z,1684170139.091 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:02:20.808Z,1684170140.808 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T17:02:29.239Z,1684170149.239 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230515T163022/Courier0015.lzma 2023-05-15T17:02:30.242Z,1684170150.242 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0015.lzma.bak 2023-05-15T17:02:30.242Z,1684170150.242 [DataOverHttps](INFO): SBD MOMSN=18310659 2023-05-15T17:02:45.800Z,1684170165.800 [CBIT](IMPORTANT): Beginning ground fault scan 2023-05-15T17:02:46.978Z,1684170166.978 [NAL9602](INFO): SBD MO Status=2, MOMSN=4022, MT Status=2, MTMSN=0 2023-05-15T17:02:46.979Z,1684170166.979 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:02:56.819Z,1684170176.819 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.012859 CHAN A1 (24V): 0.014652 CHAN A2 (12V): -0.010532 CHAN A3 (5V): -0.019696 CHAN B0 (3.3V): -0.008947 CHAN B1 (3.15aV): -0.009175 CHAN B2 (3.15bV): -0.002892 CHAN B3 (GND): -0.010809 OPEN: 0.009502 Full Scale: +/- 1 mA 2023-05-15T17:03:01.799Z,1684170181.799 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230515T163022/Express0016.lzma 2023-05-15T17:03:02.805Z,1684170182.805 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0016.lzma.bak 2023-05-15T17:03:02.806Z,1684170182.806 [DataOverHttps](INFO): SBD MOMSN=18310662 2023-05-15T17:03:05.268Z,1684170185.268 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:03:05.269Z,1684170185.269 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:03:05.269Z,1684170185.269 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:03:33.913Z,1684170213.913 [NAL9602](INFO): SBD MO Status=2, MOMSN=4022, MT Status=2, MTMSN=0 2023-05-15T17:03:33.913Z,1684170213.913 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:04:34.912Z,1684170274.912 [NAL9602](INFO): SBD MO Status=0, MOMSN=4022, MT Status=0, MTMSN=0 2023-05-15T17:04:34.912Z,1684170274.912 [NAL9602](INFO): No messages in MT queue 2023-05-15T17:05:05.609Z,1684170305.609 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:05:42.795Z,1684170342.795 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+15.1,0000.0,1489.0,000 2023-05-15T17:06:31.270Z,1684170391.270 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T17:06:31.270Z,1684170391.270 [DVL_micro](ERROR): Failed to parse: :RD,+9999.999,+9999.99,+9999.99 2023-05-15T17:08:05.806Z,1684170485.806 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:08:05.806Z,1684170485.806 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:08:05.806Z,1684170485.806 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:08:05.806Z,1684170485.806 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:08:06.204Z,1684170486.204 [Default:CheckIn:D] Stopped 2023-05-15T17:08:06.204Z,1684170486.204 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:08:06.614Z,1684170486.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.490063 min 2023-05-15T17:08:06.614Z,1684170486.614 [Default:CheckIn:E] Stopped 2023-05-15T17:08:06.614Z,1684170486.614 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:08:06.615Z,1684170486.615 [Default:CheckIn] Stopped 2023-05-15T17:08:06.615Z,1684170486.615 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:08:06.615Z,1684170486.615 [Default:CheckIn](INFO): Running loop #11 2023-05-15T17:08:06.615Z,1684170486.615 [Default:CheckIn] Running Loop=11 2023-05-15T17:08:06.615Z,1684170486.615 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:08:06.615Z,1684170486.615 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:08:08.627Z,1684170488.627 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170806.00,A,3648.13862,N,12147.20526,W,0.136,207.63,150523,,,A*75 2023-05-15T17:08:08.638Z,1684170488.638 [NAL9602](INFO): GPS fix at 20230515T170806: (36.802310, -121.786754) 2023-05-15T17:08:08.648Z,1684170488.648 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:08:08.648Z,1684170488.648 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:08:16.204Z,1684170496.204 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230515T163022/Courier0018.lzma 2023-05-15T17:08:17.205Z,1684170497.205 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0018.lzma.bak 2023-05-15T17:08:17.206Z,1684170497.206 [DataOverHttps](INFO): SBD MOMSN=18310683 2023-05-15T17:08:25.204Z,1684170505.204 [NAL9602](INFO): SBD MO Status=0, MOMSN=4023, MT Status=0, MTMSN=0 2023-05-15T17:08:25.204Z,1684170505.204 [NAL9602](INFO): No messages in MT queue 2023-05-15T17:08:33.100Z,1684170513.100 [DataOverHttps](INFO): Sending 331 bytes from file Logs/20230515T163022/Express0019.lzma 2023-05-15T17:08:34.101Z,1684170514.101 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0019.lzma.bak 2023-05-15T17:08:34.102Z,1684170514.102 [DataOverHttps](INFO): SBD MOMSN=18310686 2023-05-15T17:08:35.696Z,1684170515.696 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:08:35.696Z,1684170515.696 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:08:35.697Z,1684170515.697 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:08:55.893Z,1684170535.893 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:12:33.249Z,1684170753.249 [DVL_micro](ERROR): Failed to parse: :WI,-00572,-0139,+00000,A 2023-05-15T17:13:36.281Z,1684170816.281 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:13:36.281Z,1684170816.281 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:13:36.281Z,1684170816.281 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:13:36.281Z,1684170816.281 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:13:36.692Z,1684170816.692 [Default:CheckIn:D] Stopped 2023-05-15T17:13:36.692Z,1684170816.692 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:13:37.095Z,1684170817.095 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.998185 min 2023-05-15T17:13:37.095Z,1684170817.095 [Default:CheckIn:E] Stopped 2023-05-15T17:13:37.095Z,1684170817.095 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:13:37.095Z,1684170817.095 [Default:CheckIn] Stopped 2023-05-15T17:13:37.095Z,1684170817.095 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:13:37.096Z,1684170817.096 [Default:CheckIn](INFO): Running loop #12 2023-05-15T17:13:37.096Z,1684170817.096 [Default:CheckIn] Running Loop=12 2023-05-15T17:13:37.096Z,1684170817.096 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:13:37.096Z,1684170817.096 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:13:39.124Z,1684170819.124 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171337.00,A,3648.15943,N,12147.24976,W,1.827,14.49,150523,,,A*44 2023-05-15T17:13:39.126Z,1684170819.126 [NAL9602](INFO): GPS fix at 20230515T171337: (36.802657, -121.787496) 2023-05-15T17:13:39.139Z,1684170819.139 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:13:39.139Z,1684170819.139 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:13:46.587Z,1684170826.587 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230515T163022/Courier0021.lzma 2023-05-15T17:13:47.590Z,1684170827.590 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0021.lzma.bak 2023-05-15T17:13:47.590Z,1684170827.590 [DataOverHttps](INFO): SBD MOMSN=18310692 2023-05-15T17:13:55.665Z,1684170835.665 [NAL9602](INFO): SBD MO Status=0, MOMSN=4024, MT Status=0, MTMSN=0 2023-05-15T17:13:55.665Z,1684170835.665 [NAL9602](INFO): No messages in MT queue 2023-05-15T17:14:03.447Z,1684170843.447 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230515T163022/Express0022.lzma 2023-05-15T17:14:04.450Z,1684170844.450 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0022.lzma.bak 2023-05-15T17:14:04.450Z,1684170844.450 [DataOverHttps](INFO): SBD MOMSN=18310695 2023-05-15T17:14:06.173Z,1684170846.173 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:14:06.173Z,1684170846.173 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:14:06.174Z,1684170846.174 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:14:12.239Z,1684170852.239 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T17:14:12.239Z,1684170852.239 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2023-05-15T17:14:26.374Z,1684170866.374 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:18:53.420Z,1684171133.420 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,+15.6,0000.0,1489.0,000 2023-05-15T17:19:06.762Z,1684171146.762 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:19:06.762Z,1684171146.762 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:19:06.762Z,1684171146.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:19:06.762Z,1684171146.762 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:19:07.157Z,1684171147.157 [Default:CheckIn:D] Stopped 2023-05-15T17:19:07.157Z,1684171147.157 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:19:07.562Z,1684171147.562 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.505941 min 2023-05-15T17:19:07.562Z,1684171147.562 [Default:CheckIn:E] Stopped 2023-05-15T17:19:07.562Z,1684171147.562 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:19:07.562Z,1684171147.562 [Default:CheckIn] Stopped 2023-05-15T17:19:07.563Z,1684171147.563 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:19:07.563Z,1684171147.563 [Default:CheckIn](INFO): Running loop #13 2023-05-15T17:19:07.563Z,1684171147.563 [Default:CheckIn] Running Loop=13 2023-05-15T17:19:07.563Z,1684171147.563 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:19:07.563Z,1684171147.563 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:19:09.580Z,1684171149.580 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171907.00,A,3648.16523,N,12147.28260,W,0.117,299.69,150523,,,A*7A 2023-05-15T17:19:09.583Z,1684171149.583 [NAL9602](INFO): GPS fix at 20230515T171907: (36.802754, -121.788043) 2023-05-15T17:19:09.592Z,1684171149.592 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:19:09.592Z,1684171149.592 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:19:17.691Z,1684171157.691 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230515T163022/Courier0024.lzma 2023-05-15T17:19:18.525Z,1684171158.525 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T17:19:18.525Z,1684171158.525 [DVL_micro](ERROR): Failed to parse: :BI,-0036,-01664,+00000,I 2023-05-15T17:19:18.695Z,1684171158.695 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0024.lzma.bak 2023-05-15T17:19:18.695Z,1684171158.695 [DataOverHttps](INFO): SBD MOMSN=18310699 2023-05-15T17:19:34.787Z,1684171174.787 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230515T163022/Express0025.lzma 2023-05-15T17:19:35.790Z,1684171175.790 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0025.lzma.bak 2023-05-15T17:19:35.790Z,1684171175.790 [DataOverHttps](INFO): SBD MOMSN=18310702 2023-05-15T17:19:37.503Z,1684171177.503 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:19:37.503Z,1684171177.503 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:19:37.503Z,1684171177.503 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:22:14.283Z,1684171334.283 [NAL9602](INFO): SBD MO Status=2, MOMSN=4025, MT Status=2, MTMSN=0 2023-05-15T17:22:14.283Z,1684171334.283 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:22:57.917Z,1684171377.917 [NAL9602](INFO): SBD MO Status=0, MOMSN=4025, MT Status=0, MTMSN=0 2023-05-15T17:22:57.917Z,1684171377.917 [NAL9602](INFO): No messages in MT queue 2023-05-15T17:23:28.604Z,1684171408.604 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:24:38.101Z,1684171478.101 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:24:38.101Z,1684171478.101 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:24:38.101Z,1684171478.101 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:24:38.101Z,1684171478.101 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:24:38.510Z,1684171478.510 [Default:CheckIn:D] Stopped 2023-05-15T17:24:38.510Z,1684171478.510 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:24:38.916Z,1684171478.916 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.028491 min 2023-05-15T17:24:38.916Z,1684171478.916 [Default:CheckIn:E] Stopped 2023-05-15T17:24:38.916Z,1684171478.916 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:24:38.916Z,1684171478.916 [Default:CheckIn] Stopped 2023-05-15T17:24:38.916Z,1684171478.916 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:24:38.916Z,1684171478.916 [Default:CheckIn](INFO): Running loop #14 2023-05-15T17:24:38.916Z,1684171478.916 [Default:CheckIn] Running Loop=14 2023-05-15T17:24:38.917Z,1684171478.917 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:24:38.917Z,1684171478.917 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:24:40.933Z,1684171480.933 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172439.00,A,3648.16662,N,12147.28389,W,3.402,31.23,150523,,,D*40 2023-05-15T17:24:40.935Z,1684171480.935 [NAL9602](INFO): GPS fix at 20230515T172439: (36.802777, -121.788065) 2023-05-15T17:24:40.944Z,1684171480.944 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:24:40.944Z,1684171480.944 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:24:48.211Z,1684171488.211 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0027.lzma 2023-05-15T17:24:49.214Z,1684171489.214 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0027.lzma.bak 2023-05-15T17:24:49.214Z,1684171489.214 [DataOverHttps](INFO): SBD MOMSN=18310705 2023-05-15T17:25:09.347Z,1684171509.347 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230515T163022/Express0028.lzma 2023-05-15T17:25:10.349Z,1684171510.349 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0028.lzma.bak 2023-05-15T17:25:10.350Z,1684171510.350 [DataOverHttps](INFO): SBD MOMSN=18310708 2023-05-15T17:25:12.086Z,1684171512.086 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:25:12.086Z,1684171512.086 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:25:12.087Z,1684171512.087 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:29:43.590Z,1684171783.590 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T17:30:12.685Z,1684171812.685 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:30:12.685Z,1684171812.685 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:30:12.685Z,1684171812.685 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:30:12.685Z,1684171812.685 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:30:13.089Z,1684171813.089 [Default:CheckIn:D] Stopped 2023-05-15T17:30:13.089Z,1684171813.089 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:30:13.500Z,1684171813.500 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.604818 min 2023-05-15T17:30:13.500Z,1684171813.500 [Default:CheckIn:E] Stopped 2023-05-15T17:30:13.500Z,1684171813.500 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:30:13.501Z,1684171813.501 [Default:CheckIn] Stopped 2023-05-15T17:30:13.501Z,1684171813.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:30:13.501Z,1684171813.501 [Default:CheckIn](INFO): Running loop #15 2023-05-15T17:30:13.501Z,1684171813.501 [Default:CheckIn] Running Loop=15 2023-05-15T17:30:13.501Z,1684171813.501 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:30:13.501Z,1684171813.501 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:30:15.502Z,1684171815.502 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173013.00,A,3648.16573,N,12147.28155,W,0.156,353.35,150523,,,D*7A 2023-05-15T17:30:15.504Z,1684171815.504 [NAL9602](INFO): GPS fix at 20230515T173013: (36.802762, -121.788026) 2023-05-15T17:30:15.526Z,1684171815.526 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:30:15.526Z,1684171815.526 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:30:19.139Z,1684171819.139 [DVL_micro](ERROR): only read 2 of 4 data items 2023-05-15T17:30:19.139Z,1684171819.139 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.999 2023-05-15T17:30:21.601Z,1684171821.601 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T17:30:21.602Z,1684171821.602 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+16.3,0000.0,1489.WI,+00038,+01416,-01772,+00000,A 2023-05-15T17:30:22.615Z,1684171822.615 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0030.lzma 2023-05-15T17:30:23.618Z,1684171823.618 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0030.lzma.bak 2023-05-15T17:30:23.618Z,1684171823.618 [DataOverHttps](INFO): SBD MOMSN=18310716 2023-05-15T17:30:46.928Z,1684171846.928 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20230515T163022/Express0031.lzma 2023-05-15T17:30:47.590Z,1684171847.590 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:30:47.922Z,1684171847.922 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0031.lzma.bak 2023-05-15T17:30:47.922Z,1684171847.922 [DataOverHttps](INFO): SBD MOMSN=18310719 2023-05-15T17:30:50.477Z,1684171850.477 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:30:50.477Z,1684171850.477 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:30:50.477Z,1684171850.477 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:35:51.030Z,1684172151.030 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:35:51.030Z,1684172151.030 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:35:51.030Z,1684172151.030 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:35:51.030Z,1684172151.030 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:35:51.426Z,1684172151.426 [Default:CheckIn:D] Stopped 2023-05-15T17:35:51.426Z,1684172151.426 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:35:51.842Z,1684172151.842 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.243758 min 2023-05-15T17:35:51.842Z,1684172151.842 [Default:CheckIn:E] Stopped 2023-05-15T17:35:51.842Z,1684172151.842 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:35:51.842Z,1684172151.842 [Default:CheckIn] Stopped 2023-05-15T17:35:51.842Z,1684172151.842 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:35:51.843Z,1684172151.843 [Default:CheckIn](INFO): Running loop #16 2023-05-15T17:35:51.843Z,1684172151.843 [Default:CheckIn] Running Loop=16 2023-05-15T17:35:51.843Z,1684172151.843 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:35:51.843Z,1684172151.843 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:35:53.841Z,1684172153.841 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173552.00,A,3648.17236,N,12147.28320,W,0.136,85.92,150523,,,D*4E 2023-05-15T17:35:53.844Z,1684172153.844 [NAL9602](INFO): GPS fix at 20230515T173552: (36.802873, -121.788053) 2023-05-15T17:35:53.869Z,1684172153.869 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:35:53.869Z,1684172153.869 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:36:00.923Z,1684172160.923 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230515T163022/Courier0033.lzma 2023-05-15T17:36:01.925Z,1684172161.925 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0033.lzma.bak 2023-05-15T17:36:01.926Z,1684172161.926 [DataOverHttps](INFO): SBD MOMSN=18310768 2023-05-15T17:36:13.764Z,1684172173.764 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T17:36:13.765Z,1684172173.765 [DVL_micro](ERROR): Failed to parse: :BI,+00257,-00094,-01475,+000D,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2023-05-15T17:36:18.003Z,1684172178.003 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230515T163022/Express0034.lzma 2023-05-15T17:36:19.006Z,1684172179.006 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0034.lzma.bak 2023-05-15T17:36:19.006Z,1684172179.006 [DataOverHttps](INFO): SBD MOMSN=18310771 2023-05-15T17:36:21.129Z,1684172181.129 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:36:21.129Z,1684172181.129 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:36:21.130Z,1684172181.130 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:36:24.666Z,1684172184.666 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-05-15T17:36:24.744Z,1684172184.744 [NAL9602](ERROR): received: +CSQ:0 OK25, 0, 0, 0, 0 OK 2023-05-15T17:36:46.555Z,1684172206.555 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+16.6,0000.0,1489.0,000 2023-05-15T17:37:37.045Z,1684172257.045 [DVL_micro](ERROR): Failed to parse: :BD,+0000000000000.00,+.00,9999.99,00D,+9999.99,+9999.99,+9999.99,+9999.99 2023-05-15T17:39:49.659Z,1684172389.659 [NAL9602](INFO): SBD MO Status=0, MOMSN=4026, MT Status=0, MTMSN=0 2023-05-15T17:39:49.659Z,1684172389.659 [NAL9602](INFO): No messages in MT queue 2023-05-15T17:40:20.347Z,1684172420.347 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:41:14.908Z,1684172474.908 [DVL_micro](ERROR): only read 2 of 4 data items 2023-05-15T17:41:14.908Z,1684172474.908 [DVL_micro](ERROR): Failed to parse: :BI,-00165,+01520+00000,I 2023-05-15T17:41:21.894Z,1684172481.894 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:41:21.894Z,1684172481.894 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:41:21.894Z,1684172481.894 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:41:21.895Z,1684172481.895 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:41:22.237Z,1684172482.237 [Default:CheckIn:D] Stopped 2023-05-15T17:41:22.237Z,1684172482.237 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:41:22.624Z,1684172482.624 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.757275 min 2023-05-15T17:41:22.624Z,1684172482.624 [Default:CheckIn:E] Stopped 2023-05-15T17:41:22.624Z,1684172482.624 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:41:22.624Z,1684172482.624 [Default:CheckIn] Stopped 2023-05-15T17:41:22.624Z,1684172482.624 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:41:22.625Z,1684172482.625 [Default:CheckIn](INFO): Running loop #17 2023-05-15T17:41:22.625Z,1684172482.625 [Default:CheckIn] Running Loop=17 2023-05-15T17:41:22.625Z,1684172482.625 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:41:22.625Z,1684172482.625 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:41:24.626Z,1684172484.626 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174122.00,A,3648.16515,N,12147.28415,W,0.369,314.85,150523,,,D*79 2023-05-15T17:41:24.629Z,1684172484.629 [NAL9602](INFO): GPS fix at 20230515T174122: (36.802752, -121.788069) 2023-05-15T17:41:24.654Z,1684172484.654 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:41:24.654Z,1684172484.654 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:41:32.031Z,1684172492.031 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230515T163022/Courier0036.lzma 2023-05-15T17:41:33.034Z,1684172493.034 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0036.lzma.bak 2023-05-15T17:41:33.034Z,1684172493.034 [DataOverHttps](INFO): SBD MOMSN=18310801 2023-05-15T17:41:41.570Z,1684172501.570 [NAL9602](INFO): SBD MO Status=2, MOMSN=4027, MT Status=2, MTMSN=0 2023-05-15T17:41:41.570Z,1684172501.570 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:41:49.129Z,1684172509.129 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230515T163022/Express0037.lzma 2023-05-15T17:41:50.130Z,1684172510.130 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0037.lzma.bak 2023-05-15T17:41:50.130Z,1684172510.130 [DataOverHttps](INFO): SBD MOMSN=18310804 2023-05-15T17:41:52.079Z,1684172512.079 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:41:52.079Z,1684172512.079 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:41:52.079Z,1684172512.079 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:41:58.939Z,1684172518.939 [NAL9602](INFO): SBD MO Status=2, MOMSN=4027, MT Status=2, MTMSN=0 2023-05-15T17:41:58.939Z,1684172518.939 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:42:02.567Z,1684172522.567 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2023-05-15T17:42:10.274Z,1684172530.274 [NAL9602](INFO): SBD MO Status=0, MOMSN=4027, MT Status=0, MTMSN=0 2023-05-15T17:42:10.274Z,1684172530.274 [NAL9602](INFO): No messages in MT queue 2023-05-15T17:42:40.665Z,1684172560.665 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:44:48.856Z,1684172688.856 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-05-15T17:44:48.858Z,1684172688.858 [BPC1](INFO): Received data from all battery sticks. 2023-05-15T17:44:59.827Z,1684172699.827 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T17:44:59.827Z,1684172699.827 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,30,0000.0,1489.0,000 2023-05-15T17:46:52.555Z,1684172812.555 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:46:52.555Z,1684172812.555 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:46:52.555Z,1684172812.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:46:52.555Z,1684172812.555 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:46:52.967Z,1684172812.967 [Default:CheckIn:D] Stopped 2023-05-15T17:46:52.967Z,1684172812.967 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:46:53.357Z,1684172813.357 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.269450 min 2023-05-15T17:46:53.357Z,1684172813.357 [Default:CheckIn:E] Stopped 2023-05-15T17:46:53.357Z,1684172813.357 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:46:53.357Z,1684172813.357 [Default:CheckIn] Stopped 2023-05-15T17:46:53.357Z,1684172813.357 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:46:53.357Z,1684172813.357 [Default:CheckIn](INFO): Running loop #18 2023-05-15T17:46:53.357Z,1684172813.357 [Default:CheckIn] Running Loop=18 2023-05-15T17:46:53.358Z,1684172813.358 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:46:53.358Z,1684172813.358 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:46:55.371Z,1684172815.371 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174653.00,A,3648.16657,N,12147.28248,W,0.272,99.03,150523,,,D*40 2023-05-15T17:46:55.373Z,1684172815.373 [NAL9602](INFO): GPS fix at 20230515T174653: (36.802776, -121.788041) 2023-05-15T17:46:55.382Z,1684172815.382 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:46:55.382Z,1684172815.382 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:47:02.849Z,1684172822.849 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20230515T163022/Courier0039.lzma 2023-05-15T17:47:03.754Z,1684172823.754 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0039.lzma.bak 2023-05-15T17:47:03.754Z,1684172823.754 [DataOverHttps](INFO): SBD MOMSN=18310809 2023-05-15T17:47:19.659Z,1684172839.659 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230515T163022/Express0040.lzma 2023-05-15T17:47:20.662Z,1684172840.662 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0040.lzma.bak 2023-05-15T17:47:20.662Z,1684172840.662 [DataOverHttps](INFO): SBD MOMSN=18310812 2023-05-15T17:47:22.475Z,1684172842.475 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:47:22.475Z,1684172842.475 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:47:22.476Z,1684172842.476 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:48:45.307Z,1684172925.307 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T17:48:45.307Z,1684172925.307 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0000.0,1489.0,000 2023-05-15T17:49:20.862Z,1684172960.862 [NAL9602](INFO): SBD MO Status=2, MOMSN=4028, MT Status=2, MTMSN=0 2023-05-15T17:49:20.863Z,1684172960.863 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:50:12.565Z,1684173012.565 [NAL9602](INFO): SBD MO Status=2, MOMSN=4028, MT Status=2, MTMSN=0 2023-05-15T17:50:12.565Z,1684173012.565 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:51:22.123Z,1684173082.123 [NAL9602](INFO): SBD MO Status=0, MOMSN=4028, MT Status=0, MTMSN=0 2023-05-15T17:51:22.123Z,1684173082.123 [NAL9602](INFO): No messages in MT queue 2023-05-15T17:51:52.819Z,1684173112.819 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:52:12.214Z,1684173132.214 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T17:52:12.214Z,1684173132.214 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.2,0000.0,148 2023-05-15T17:52:23.145Z,1684173143.145 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:52:23.145Z,1684173143.145 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:52:23.146Z,1684173143.146 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:52:23.146Z,1684173143.146 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:52:23.529Z,1684173143.529 [Default:CheckIn:D] Stopped 2023-05-15T17:52:23.529Z,1684173143.529 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:52:23.934Z,1684173143.934 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.778809 min 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn:E] Stopped 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn] Stopped 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn](INFO): Running loop #19 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn] Running Loop=19 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:52:23.935Z,1684173143.935 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:52:25.946Z,1684173145.946 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175224.00,A,3648.16710,N,12147.28331,W,0.136,206.15,150523,,,D*78 2023-05-15T17:52:25.956Z,1684173145.956 [NAL9602](INFO): GPS fix at 20230515T175224: (36.802785, -121.788055) 2023-05-15T17:52:25.974Z,1684173145.974 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:52:25.974Z,1684173145.974 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:52:37.183Z,1684173157.183 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230515T163022/Courier0042.lzma 2023-05-15T17:52:38.186Z,1684173158.186 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0042.lzma.bak 2023-05-15T17:52:38.186Z,1684173158.186 [DataOverHttps](INFO): SBD MOMSN=18310838 2023-05-15T17:53:01.207Z,1684173181.207 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230515T163022/Express0043.lzma 2023-05-15T17:53:02.210Z,1684173182.210 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0043.lzma.bak 2023-05-15T17:53:02.210Z,1684173182.210 [DataOverHttps](INFO): SBD MOMSN=18310841 2023-05-15T17:53:04.095Z,1684173184.095 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:53:04.095Z,1684173184.095 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:53:04.096Z,1684173184.096 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:53:08.519Z,1684173188.519 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T17:53:08.519Z,1684173188.519 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:53:20.239Z,1684173200.239 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T17:53:20.239Z,1684173200.239 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.1,0000.0,1489.WI,-00150,+00061,-01100,+ 2023-05-15T17:53:40.453Z,1684173220.453 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T17:53:40.454Z,1684173220.454 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:54:01.842Z,1684173241.842 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T17:54:01.842Z,1684173241.842 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T17:56:35.398Z,1684173395.398 [DVL_micro](ERROR): only read 2 of 4 data items 2023-05-15T17:56:35.398Z,1684173395.398 [DVL_micro](ERROR): Failed to parse: :BI,1075,+00000,I 2023-05-15T17:56:55.577Z,1684173415.577 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T17:56:55.578Z,1684173415.578 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,30,0000.0,1489.0,000 2023-05-15T17:57:28.709Z,1684173448.709 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T17:57:59.408Z,1684173479.408 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T17:58:04.672Z,1684173484.672 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T17:58:04.672Z,1684173484.672 [Default:CheckIn:C.Wait] Stopped 2023-05-15T17:58:04.672Z,1684173484.672 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T17:58:04.672Z,1684173484.672 [Default:CheckIn:D] Running Loop=1 2023-05-15T17:58:05.074Z,1684173485.074 [Default:CheckIn:D] Stopped 2023-05-15T17:58:05.074Z,1684173485.074 [Default:CheckIn:E] Running Loop=1 2023-05-15T17:58:05.487Z,1684173485.487 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.471224 min 2023-05-15T17:58:05.487Z,1684173485.487 [Default:CheckIn:E] Stopped 2023-05-15T17:58:05.487Z,1684173485.487 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T17:58:05.487Z,1684173485.487 [Default:CheckIn] Stopped 2023-05-15T17:58:05.487Z,1684173485.487 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T17:58:05.487Z,1684173485.487 [Default:CheckIn](INFO): Running loop #20 2023-05-15T17:58:05.487Z,1684173485.487 [Default:CheckIn] Running Loop=20 2023-05-15T17:58:05.488Z,1684173485.488 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T17:58:05.488Z,1684173485.488 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T17:58:07.495Z,1684173487.495 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175805.00,A,3648.16690,N,12147.28404,W,0.039,206.15,150523,,,D*77 2023-05-15T17:58:07.498Z,1684173487.498 [NAL9602](INFO): GPS fix at 20230515T175805: (36.802782, -121.788067) 2023-05-15T17:58:07.524Z,1684173487.524 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T17:58:07.524Z,1684173487.524 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T17:58:14.827Z,1684173494.827 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230515T163022/Courier0045.lzma 2023-05-15T17:58:15.830Z,1684173495.830 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0045.lzma.bak 2023-05-15T17:58:15.830Z,1684173495.830 [DataOverHttps](INFO): SBD MOMSN=18310845 2023-05-15T17:58:35.528Z,1684173515.528 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20230515T163022/Express0046.lzma 2023-05-15T17:58:36.530Z,1684173516.530 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0046.lzma.bak 2023-05-15T17:58:36.530Z,1684173516.530 [DataOverHttps](INFO): SBD MOMSN=18310848 2023-05-15T17:58:37.904Z,1684173517.904 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-05-15T17:58:37.984Z,1684173517.984 [NAL9602](ERROR): received: +CSQ:0 OK29, 2, 0, 0, 0 OK 2023-05-15T17:58:38.729Z,1684173518.729 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T17:58:38.729Z,1684173518.729 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T17:58:38.729Z,1684173518.729 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T17:59:32.006Z,1684173572.006 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2023-05-15T17:59:32.006Z,1684173572.006 [DropWeight] Hardware Fault, FailCount= 1 2023-05-15T17:59:32.006Z,1684173572.006 [DropWeight](ERROR): Hardware Fault 2023-05-15T17:59:32.040Z,1684173572.040 [CommandExec](FAULT): Scheduling is paused 2023-05-15T17:59:32.041Z,1684173572.041 [CBIT](INFO): Critical error at 20230515T175932 2023-05-15T17:59:32.043Z,1684173572.043 [CBIT](ERROR): Hardware Fault in component: DropWeight 2023-05-15T17:59:32.048Z,1684173572.048 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2023-05-15T17:59:32.475Z,1684173572.475 [CBIT](INFO): Critical error at 20230515T175932 2023-05-15T18:00:10.790Z,1684173610.790 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T18:00:10.791Z,1684173610.791 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T18:02:44.766Z,1684173764.766 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T18:02:44.766Z,1684173764.766 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T18:03:09.776Z,1684173789.776 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T18:03:09.776Z,1684173789.776 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T18:03:10.174Z,1684173790.174 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T18:03:39.278Z,1684173819.278 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:03:39.278Z,1684173819.278 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:03:39.278Z,1684173819.278 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:03:39.278Z,1684173819.278 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:03:39.668Z,1684173819.668 [Default:CheckIn:D] Stopped 2023-05-15T18:03:39.669Z,1684173819.669 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:03:40.072Z,1684173820.072 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.047803 min 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn:E] Stopped 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn] Stopped 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn](INFO): Running loop #21 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn] Running Loop=21 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:03:40.073Z,1684173820.073 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:03:42.091Z,1684173822.091 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180340.00,A,3648.16649,N,12147.28274,W,0.175,59.85,150523,,,A*4F 2023-05-15T18:03:42.094Z,1684173822.094 [NAL9602](INFO): GPS fix at 20230515T180340: (36.802775, -121.788046) 2023-05-15T18:03:42.103Z,1684173822.103 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:03:42.103Z,1684173822.103 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:03:49.800Z,1684173829.800 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20230515T163022/Courier0048.lzma 2023-05-15T18:03:50.802Z,1684173830.802 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0048.lzma.bak 2023-05-15T18:03:50.802Z,1684173830.802 [DataOverHttps](INFO): SBD MOMSN=18310877 2023-05-15T18:04:06.856Z,1684173846.856 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20230515T163022/Express0049.lzma 2023-05-15T18:04:07.858Z,1684173847.858 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0049.lzma.bak 2023-05-15T18:04:07.858Z,1684173847.858 [DataOverHttps](INFO): SBD MOMSN=18310882 2023-05-15T18:04:09.575Z,1684173849.575 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:04:09.575Z,1684173849.575 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:04:09.575Z,1684173849.575 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:04:14.405Z,1684173854.405 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T18:06:24.512Z,1684173984.512 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:06:24.512Z,1684173984.512 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,9 2023-05-15T18:08:21.260Z,1684174101.260 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:08:21.260Z,1684174101.260 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999..99 2023-05-15T18:08:58.860Z,1684174138.860 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T18:08:58.860Z,1684174138.860 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+0.0,10 2023-05-15T18:09:10.148Z,1684174150.148 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:09:10.149Z,1684174150.149 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:09:10.149Z,1684174150.149 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:09:10.149Z,1684174150.149 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:09:10.560Z,1684174150.560 [Default:CheckIn:D] Stopped 2023-05-15T18:09:10.560Z,1684174150.560 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:09:10.952Z,1684174150.952 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.562663 min 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn:E] Stopped 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn] Stopped 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn](INFO): Running loop #22 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn] Running Loop=22 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:09:10.953Z,1684174150.953 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:09:12.966Z,1684174152.966 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180911.00,A,3648.16798,N,12147.28000,W,0.039,11.77,150523,,,D*40 2023-05-15T18:09:12.968Z,1684174152.968 [NAL9602](INFO): GPS fix at 20230515T180911: (36.802800, -121.788000) 2023-05-15T18:09:12.978Z,1684174152.978 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:09:12.978Z,1684174152.978 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:09:20.711Z,1684174160.711 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0051.lzma 2023-05-15T18:09:21.714Z,1684174161.714 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0051.lzma.bak 2023-05-15T18:09:21.714Z,1684174161.714 [DataOverHttps](INFO): SBD MOMSN=18310894 2023-05-15T18:09:37.587Z,1684174177.587 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230515T163022/Express0052.lzma 2023-05-15T18:09:38.590Z,1684174178.590 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0052.lzma.bak 2023-05-15T18:09:38.590Z,1684174178.590 [DataOverHttps](INFO): SBD MOMSN=18310897 2023-05-15T18:09:40.460Z,1684174180.460 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:09:40.460Z,1684174180.460 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:09:40.460Z,1684174180.460 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:10:01.853Z,1684174201.853 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T18:10:01.853Z,1684174201.853 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T18:11:54.166Z,1684174314.166 [NAL9602](INFO): SBD MO Status=2, MOMSN=4029, MT Status=2, MTMSN=0 2023-05-15T18:11:54.166Z,1684174314.166 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2023-05-15T18:12:11.176Z,1684174331.176 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T18:12:11.177Z,1684174331.177 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.1,0000.0000 2023-05-15T18:12:42.612Z,1684174362.612 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T18:13:13.752Z,1684174393.752 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T18:13:44.876Z,1684174424.876 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2023-05-15T18:14:15.567Z,1684174455.567 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T18:14:32.174Z,1684174472.174 [CBIT](INFO): Clearing failed state for component DropWeight 2023-05-15T18:14:32.174Z,1684174472.174 [DropWeight] No Fault, FailCount= 1 2023-05-15T18:14:41.071Z,1684174481.071 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:14:41.071Z,1684174481.071 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:14:41.071Z,1684174481.071 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:14:41.072Z,1684174481.072 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:14:41.448Z,1684174481.448 [Default:CheckIn:D] Stopped 2023-05-15T18:14:41.448Z,1684174481.448 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:14:41.870Z,1684174481.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.077466 min 2023-05-15T18:14:41.870Z,1684174481.870 [Default:CheckIn:E] Stopped 2023-05-15T18:14:41.871Z,1684174481.871 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:14:41.871Z,1684174481.871 [Default:CheckIn] Stopped 2023-05-15T18:14:41.871Z,1684174481.871 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:14:41.871Z,1684174481.871 [Default:CheckIn](INFO): Running loop #23 2023-05-15T18:14:41.871Z,1684174481.871 [Default:CheckIn] Running Loop=23 2023-05-15T18:14:41.871Z,1684174481.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:14:41.871Z,1684174481.871 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:14:43.864Z,1684174483.864 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181442.00,A,3648.16478,N,12147.28202,W,0.117,207.38,150523,,,A*71 2023-05-15T18:14:43.866Z,1684174483.866 [NAL9602](INFO): GPS fix at 20230515T181442: (36.802746, -121.788034) 2023-05-15T18:14:43.912Z,1684174483.912 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:14:43.912Z,1684174483.912 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:14:51.563Z,1684174491.563 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0054.lzma 2023-05-15T18:14:53.056Z,1684174493.056 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0054.lzma.bak 2023-05-15T18:14:53.056Z,1684174493.056 [DataOverHttps](INFO): SBD MOMSN=18310927 2023-05-15T18:15:14.724Z,1684174514.724 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230515T163022/Express0055.lzma 2023-05-15T18:15:15.725Z,1684174515.725 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0055.lzma.bak 2023-05-15T18:15:15.726Z,1684174515.726 [DataOverHttps](INFO): SBD MOMSN=18310930 2023-05-15T18:15:16.576Z,1684174516.576 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T18:15:17.396Z,1684174517.396 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:15:17.396Z,1684174517.396 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:15:17.396Z,1684174517.396 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:15:31.935Z,1684174531.935 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:15:31.935Z,1684174531.935 [DVL_micro](ERROR): Failed to parse: :RD,+0010.99,+0010.555,+0010.89 2023-05-15T18:16:16.417Z,1684174576.417 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:16:16.418Z,1684174576.418 [DVL_micro](ERROR): Failed to parse: :BI,+00012,+00012,-00014,+00BD,+00000000.00,+000,+00000000.00,0009.40,000.00 2023-05-15T18:16:21.651Z,1684174581.651 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:16:21.651Z,1684174581.651 [DVL_micro](ERROR): Failed to parse: :RD,+99910.20,+0012.43,+0011.08 2023-05-15T18:20:18.059Z,1684174818.059 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:20:18.059Z,1684174818.059 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:20:18.059Z,1684174818.059 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:20:18.059Z,1684174818.059 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:20:18.457Z,1684174818.457 [Default:CheckIn:D] Stopped 2023-05-15T18:20:18.457Z,1684174818.457 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.694279 min 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn:E] Stopped 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn] Stopped 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn](INFO): Running loop #24 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn] Running Loop=24 2023-05-15T18:20:18.850Z,1684174818.850 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:20:18.851Z,1684174818.851 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:20:20.863Z,1684174820.863 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182019.00,A,3648.16303,N,12147.28074,W,0.039,163.36,150523,,,D*77 2023-05-15T18:20:20.865Z,1684174820.865 [NAL9602](INFO): GPS fix at 20230515T182019: (36.802717, -121.788012) 2023-05-15T18:20:20.875Z,1684174820.875 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:20:20.875Z,1684174820.875 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:20:30.827Z,1684174830.827 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0057.lzma 2023-05-15T18:20:31.830Z,1684174831.830 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0057.lzma.bak 2023-05-15T18:20:31.830Z,1684174831.830 [DataOverHttps](INFO): SBD MOMSN=18310976 2023-05-15T18:20:51.642Z,1684174851.642 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-05-15T18:20:51.720Z,1684174851.720 [NAL9602](ERROR): received: +CSQ:0 OK29, 2, 0, 0, 0 OK 2023-05-15T18:20:58.567Z,1684174858.567 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230515T163022/Express0058.lzma 2023-05-15T18:20:59.570Z,1684174859.570 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0058.lzma.bak 2023-05-15T18:20:59.570Z,1684174859.570 [DataOverHttps](INFO): SBD MOMSN=18310979 2023-05-15T18:21:01.331Z,1684174861.331 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:21:01.331Z,1684174861.331 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:21:01.331Z,1684174861.331 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:21:01.725Z,1684174861.725 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T18:21:01.726Z,1684174861.726 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.9,089.0,000 2023-05-15T18:25:23.511Z,1684175123.511 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T18:25:54.221Z,1684175154.221 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T18:26:01.904Z,1684175161.904 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:26:01.904Z,1684175161.904 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:26:01.904Z,1684175161.904 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:26:01.904Z,1684175161.904 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:26:02.311Z,1684175162.311 [Default:CheckIn:D] Stopped 2023-05-15T18:26:02.312Z,1684175162.312 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:26:02.737Z,1684175162.737 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.425179 min 2023-05-15T18:26:02.737Z,1684175162.737 [Default:CheckIn:E] Stopped 2023-05-15T18:26:02.737Z,1684175162.737 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:26:02.737Z,1684175162.737 [Default:CheckIn] Stopped 2023-05-15T18:26:02.737Z,1684175162.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:26:02.738Z,1684175162.738 [Default:CheckIn](INFO): Running loop #25 2023-05-15T18:26:02.738Z,1684175162.738 [Default:CheckIn] Running Loop=25 2023-05-15T18:26:02.738Z,1684175162.738 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:26:02.738Z,1684175162.738 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:26:04.729Z,1684175164.729 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182602.00,A,3648.16651,N,12147.28721,W,0.914,336.42,150523,,,D*79 2023-05-15T18:26:04.732Z,1684175164.732 [NAL9602](INFO): GPS fix at 20230515T182602: (36.802775, -121.788120) 2023-05-15T18:26:04.741Z,1684175164.741 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:26:04.741Z,1684175164.741 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:26:12.972Z,1684175172.972 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0060.lzma 2023-05-15T18:26:13.977Z,1684175173.977 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0060.lzma.bak 2023-05-15T18:26:13.978Z,1684175173.978 [DataOverHttps](INFO): SBD MOMSN=18311015 2023-05-15T18:26:32.732Z,1684175192.732 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20230515T163022/Express0061.lzma 2023-05-15T18:26:33.734Z,1684175193.734 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0061.lzma.bak 2023-05-15T18:26:33.734Z,1684175193.734 [DataOverHttps](INFO): SBD MOMSN=18311019 2023-05-15T18:26:35.559Z,1684175195.559 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-05-15T18:26:35.636Z,1684175195.636 [NAL9602](ERROR): received: +CSQ:0 OK29, 2, 0, 0, 0 OK 2023-05-15T18:26:35.972Z,1684175195.972 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:26:35.973Z,1684175195.973 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:26:35.973Z,1684175195.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:28:23.865Z,1684175303.865 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:28:23.865Z,1684175303.865 [DVL_micro](ERROR): Failed to parse: :RD,+9999.999,+9999.99,+9999.99 2023-05-15T18:29:32.149Z,1684175372.149 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:29:32.150Z,1684175372.150 [DVL_micro](ERROR): Failed to parse: :BI,+00174,+0131,+00000,I 2023-05-15T18:31:07.168Z,1684175467.168 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T18:31:36.627Z,1684175496.627 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:31:36.627Z,1684175496.627 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:31:36.627Z,1684175496.627 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:31:36.627Z,1684175496.627 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:31:37.039Z,1684175497.039 [Default:CheckIn:D] Stopped 2023-05-15T18:31:37.039Z,1684175497.039 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:31:37.437Z,1684175497.437 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 145.003988 min 2023-05-15T18:31:37.437Z,1684175497.437 [Default:CheckIn:E] Stopped 2023-05-15T18:31:37.437Z,1684175497.437 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:31:37.437Z,1684175497.437 [Default:CheckIn] Stopped 2023-05-15T18:31:37.437Z,1684175497.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:31:37.437Z,1684175497.437 [Default:CheckIn](INFO): Running loop #26 2023-05-15T18:31:37.438Z,1684175497.438 [Default:CheckIn] Running Loop=26 2023-05-15T18:31:37.438Z,1684175497.438 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:31:37.438Z,1684175497.438 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:31:37.828Z,1684175497.828 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T18:31:39.445Z,1684175499.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183137.00,A,3648.17010,N,12147.28865,W,0.078,323.90,150523,,,D*7C 2023-05-15T18:31:39.448Z,1684175499.448 [NAL9602](INFO): GPS fix at 20230515T183137: (36.802835, -121.788144) 2023-05-15T18:31:39.457Z,1684175499.457 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:31:39.457Z,1684175499.457 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:31:47.611Z,1684175507.611 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0063.lzma 2023-05-15T18:31:48.130Z,1684175508.130 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0063.lzma.bak 2023-05-15T18:31:48.130Z,1684175508.130 [DataOverHttps](INFO): SBD MOMSN=18311038 2023-05-15T18:32:03.709Z,1684175523.709 [DVL_micro](ERROR): only read 0 of 4 data items 2023-05-15T18:32:03.709Z,1684175523.709 [DVL_micro](ERROR): Failed to parse: :RD,,+9999.99,+9999.99,+9999.99 2023-05-15T18:32:07.019Z,1684175527.019 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230515T163022/Express0064.lzma 2023-05-15T18:32:08.022Z,1684175528.022 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0064.lzma.bak 2023-05-15T18:32:08.022Z,1684175528.022 [DataOverHttps](INFO): SBD MOMSN=18311041 2023-05-15T18:32:09.762Z,1684175529.762 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:32:09.762Z,1684175529.762 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:32:09.763Z,1684175529.763 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:32:10.152Z,1684175530.152 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-05-15T18:32:10.236Z,1684175530.236 [NAL9602](ERROR): received: +CSQ:0 OK29, 2, 0, 0, 0 OK 2023-05-15T18:36:41.727Z,1684175801.727 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T18:37:10.398Z,1684175830.398 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:37:10.398Z,1684175830.398 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:37:10.398Z,1684175830.398 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:37:10.398Z,1684175830.398 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:37:10.812Z,1684175830.812 [Default:CheckIn:D] Stopped 2023-05-15T18:37:10.813Z,1684175830.813 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:37:11.205Z,1684175831.205 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.566862 min 2023-05-15T18:37:11.205Z,1684175831.205 [Default:CheckIn:E] Stopped 2023-05-15T18:37:11.205Z,1684175831.205 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:37:11.205Z,1684175831.205 [Default:CheckIn] Stopped 2023-05-15T18:37:11.206Z,1684175831.206 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:37:11.206Z,1684175831.206 [Default:CheckIn](INFO): Running loop #27 2023-05-15T18:37:11.206Z,1684175831.206 [Default:CheckIn] Running Loop=27 2023-05-15T18:37:11.206Z,1684175831.206 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:37:11.206Z,1684175831.206 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:37:13.218Z,1684175833.218 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183711.00,A,3648.16748,N,12147.29198,W,0.039,323.90,150523,,,D*7A 2023-05-15T18:37:13.220Z,1684175833.220 [NAL9602](INFO): GPS fix at 20230515T183711: (36.802791, -121.788200) 2023-05-15T18:37:13.230Z,1684175833.230 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:37:13.230Z,1684175833.230 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:37:23.139Z,1684175843.139 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0066.lzma 2023-05-15T18:37:24.142Z,1684175844.142 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0066.lzma.bak 2023-05-15T18:37:24.142Z,1684175844.142 [DataOverHttps](INFO): SBD MOMSN=18311081 2023-05-15T18:37:40.071Z,1684175860.071 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230515T163022/Express0067.lzma 2023-05-15T18:37:41.074Z,1684175861.074 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0067.lzma.bak 2023-05-15T18:37:41.074Z,1684175861.074 [DataOverHttps](INFO): SBD MOMSN=18311084 2023-05-15T18:37:42.777Z,1684175862.777 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:37:42.777Z,1684175862.777 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:37:42.777Z,1684175862.777 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:37:45.607Z,1684175865.607 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T18:38:10.250Z,1684175890.250 [DVL_micro](ERROR): Failed to parse: :SA,-03.78,+01.41,099.6 2023-05-15T18:41:17.316Z,1684176077.316 [DVL_micro](ERROR): only read 0 of 4 data items 2023-05-15T18:41:17.316Z,1684176077.316 [DVL_micro](ERROR): Failed to parse: :RD,,+9999.99,+9999.99,+9999.99 2023-05-15T18:42:32.857Z,1684176152.857 [DVL_micro](ERROR): only read 3 of 4 data items 2023-05-15T18:42:32.857Z,1684176152.857 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2023-05-15T18:42:43.352Z,1684176163.352 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:42:43.353Z,1684176163.353 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:42:43.353Z,1684176163.353 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:42:43.353Z,1684176163.353 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:42:43.762Z,1684176163.762 [Default:CheckIn:D] Stopped 2023-05-15T18:42:43.762Z,1684176163.762 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:42:44.179Z,1684176164.179 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 156.116016 min 2023-05-15T18:42:44.179Z,1684176164.179 [Default:CheckIn:E] Stopped 2023-05-15T18:42:44.179Z,1684176164.179 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:42:44.180Z,1684176164.180 [Default:CheckIn] Stopped 2023-05-15T18:42:44.180Z,1684176164.180 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:42:44.180Z,1684176164.180 [Default:CheckIn](INFO): Running loop #28 2023-05-15T18:42:44.180Z,1684176164.180 [Default:CheckIn] Running Loop=28 2023-05-15T18:42:44.180Z,1684176164.180 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:42:44.180Z,1684176164.180 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:42:46.174Z,1684176166.174 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184244.00,A,3648.16502,N,12147.28515,W,0.136,323.90,150523,,,D*7A 2023-05-15T18:42:46.176Z,1684176166.176 [NAL9602](INFO): GPS fix at 20230515T184244: (36.802750, -121.788086) 2023-05-15T18:42:46.206Z,1684176166.206 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:42:46.206Z,1684176166.206 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:42:53.115Z,1684176173.115 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230515T163022/Courier0069.lzma 2023-05-15T18:42:54.117Z,1684176174.117 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0069.lzma.bak 2023-05-15T18:42:54.118Z,1684176174.118 [DataOverHttps](INFO): SBD MOMSN=18311088 2023-05-15T18:43:10.091Z,1684176190.091 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230515T163022/Express0070.lzma 2023-05-15T18:43:11.094Z,1684176191.094 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0070.lzma.bak 2023-05-15T18:43:11.094Z,1684176191.094 [DataOverHttps](INFO): SBD MOMSN=18311091 2023-05-15T18:43:12.902Z,1684176192.902 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:43:12.903Z,1684176192.903 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:43:12.903Z,1684176192.903 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:43:16.933Z,1684176196.933 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-05-15T18:43:17.008Z,1684176197.008 [NAL9602](ERROR): received: +CSQ:0 OK29, 2, 0, 0, 0 OK 2023-05-15T18:46:53.186Z,1684176413.186 [DVL_micro](ERROR): Failed to parse: :T00000000,35.0,+18.9,0000.0,1489:WI,-0105,-01205,+00BI,-01055-01205,+00000,I 2023-05-15T18:47:45.700Z,1684176465.700 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2023-05-15T18:47:48.520Z,1684176468.520 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-15T18:48:13.578Z,1684176493.578 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:48:13.578Z,1684176493.578 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:48:13.578Z,1684176493.578 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:48:13.578Z,1684176493.578 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:48:13.997Z,1684176493.997 [Default:CheckIn:D] Stopped 2023-05-15T18:48:13.997Z,1684176493.997 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:48:14.406Z,1684176494.406 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 161.619938 min 2023-05-15T18:48:14.406Z,1684176494.406 [Default:CheckIn:E] Stopped 2023-05-15T18:48:14.406Z,1684176494.406 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:48:14.406Z,1684176494.406 [Default:CheckIn] Stopped 2023-05-15T18:48:14.406Z,1684176494.406 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:48:14.406Z,1684176494.406 [Default:CheckIn](INFO): Running loop #29 2023-05-15T18:48:14.406Z,1684176494.406 [Default:CheckIn] Running Loop=29 2023-05-15T18:48:14.407Z,1684176494.407 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:48:14.407Z,1684176494.407 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:48:16.412Z,1684176496.412 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184814.00,A,3648.16391,N,12147.28548,W,0.914,323.90,150523,,,D*79 2023-05-15T18:48:16.414Z,1684176496.414 [NAL9602](INFO): GPS fix at 20230515T184814: (36.802732, -121.788091) 2023-05-15T18:48:16.448Z,1684176496.448 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:48:16.448Z,1684176496.448 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:48:23.627Z,1684176503.627 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230515T163022/Courier0072.lzma 2023-05-15T18:48:24.630Z,1684176504.630 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0072.lzma.bak 2023-05-15T18:48:24.630Z,1684176504.630 [DataOverHttps](INFO): SBD MOMSN=18311121 2023-05-15T18:48:29.371Z,1684176509.371 [DVL_micro](ERROR): only read 2 of 4 data items 2023-05-15T18:48:29.376Z,1684176509.376 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+999999.99 2023-05-15T18:48:47.352Z,1684176527.352 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230515T163022/Express0073.lzma 2023-05-15T18:48:48.354Z,1684176528.354 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0073.lzma.bak 2023-05-15T18:48:48.354Z,1684176528.354 [DataOverHttps](INFO): SBD MOMSN=18311127 2023-05-15T18:48:48.474Z,1684176528.474 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-15T18:48:51.174Z,1684176531.174 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:48:51.174Z,1684176531.174 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:48:51.175Z,1684176531.175 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:51:03.458Z,1684176663.458 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2023-05-15T18:51:03.458Z,1684176663.458 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.9,0000.0,10 2023-05-15T18:52:30.725Z,1684176750.725 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-05-15T18:52:30.727Z,1684176750.727 [BPC1](INFO): Received data from all battery sticks. 2023-05-15T18:53:51.528Z,1684176831.528 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-15T18:53:51.528Z,1684176831.528 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:53:51.528Z,1684176831.528 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:53:51.529Z,1684176831.529 [Default:CheckIn:D] Running Loop=1 2023-05-15T18:53:51.938Z,1684176831.938 [Default:CheckIn:D] Stopped 2023-05-15T18:53:51.939Z,1684176831.939 [Default:CheckIn:E] Running Loop=1 2023-05-15T18:53:52.349Z,1684176832.349 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 167.252295 min 2023-05-15T18:53:52.349Z,1684176832.349 [Default:CheckIn:E] Stopped 2023-05-15T18:53:52.349Z,1684176832.349 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-15T18:53:52.349Z,1684176832.349 [Default:CheckIn] Stopped 2023-05-15T18:53:52.349Z,1684176832.349 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:53:52.350Z,1684176832.350 [Default:CheckIn](INFO): Running loop #30 2023-05-15T18:53:52.350Z,1684176832.350 [Default:CheckIn] Running Loop=30 2023-05-15T18:53:52.350Z,1684176832.350 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-15T18:53:52.350Z,1684176832.350 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-15T18:53:54.349Z,1684176834.349 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185352.00,A,3648.16620,N,12147.28703,W,0.058,214.92,150523,,,D*75 2023-05-15T18:53:54.351Z,1684176834.351 [NAL9602](INFO): GPS fix at 20230515T185352: (36.802770, -121.788117) 2023-05-15T18:53:54.361Z,1684176834.361 [Default:CheckIn:Read_GPS] Stopped 2023-05-15T18:53:54.361Z,1684176834.361 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-15T18:54:04.855Z,1684176844.855 [DataOverHttps](INFO): Sending 89 bytes from file Logs/20230515T163022/Courier0075.lzma 2023-05-15T18:54:05.857Z,1684176845.857 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Courier0075.lzma.bak 2023-05-15T18:54:05.858Z,1684176845.858 [DataOverHttps](INFO): SBD MOMSN=18311170 2023-05-15T18:54:23.379Z,1684176863.379 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20230515T163022/Express0076.lzma 2023-05-15T18:54:24.382Z,1684176864.382 [DataOverHttps](INFO): Moved sent file to Logs/20230515T163022/Express0076.lzma.bak 2023-05-15T18:54:24.382Z,1684176864.382 [DataOverHttps](INFO): SBD MOMSN=18311173 2023-05-15T18:54:25.061Z,1684176865.061 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2023-05-15T18:54:25.144Z,1684176865.144 [NAL9602](ERROR): received: +CSQ:0 OK29, 2, 0, 0, 0 OK 2023-05-15T18:54:26.754Z,1684176866.754 [Default:CheckIn:Read_Iridium] Stopped 2023-05-15T18:54:26.754Z,1684176866.754 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-15T18:54:26.754Z,1684176866.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-15T18:55:08.389Z,1684176908.389 [DVL_micro](ERROR): only read 0 of 4 data items 2023-05-15T18:55:08.389Z,1684176908.389 [DVL_micro](ERROR): Failed to parse: :RD,++9999.99,+99999.99 2023-05-15T18:56:28.065Z,1684176988.065 [CommandExec](IMPORTANT): got command maintain clear 2023-05-15T18:57:26.640Z,1684177046.640 [CommandExec](IMPORTANT): got command configSet VerticalControl.massDefault 18.2411 millimeter persist 2023-05-15T18:57:49.661Z,1684177069.661 [CommandExec](IMPORTANT): got command restart application 2023-05-15T18:57:50.664Z,1684177070.664 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:50.664Z,1684177070.664 [CommandExec](INFO): Uninitializing the command executive. 2023-05-15T18:57:50.664Z,1684177070.664 [CommandExec](INFO): Uninitializing the command scheduler. 2023-05-15T18:57:50.664Z,1684177070.664 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:50.848Z,1684177070.848 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-05-15T18:57:50.848Z,1684177070.848 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-05-15T18:57:50.848Z,1684177070.848 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:50.849Z,1684177070.849 [NavChartDb](INFO): Join timeout helper Thread ID is 7124 2023-05-15T18:57:50.900Z,1684177070.900 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:50.900Z,1684177070.900 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:50.909Z,1684177070.909 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-05-15T18:57:50.909Z,1684177070.909 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:50.910Z,1684177070.910 [Radio_Surface](INFO): Join timeout helper Thread ID is 7125 2023-05-15T18:57:50.932Z,1684177070.932 [Radio_Surface](INFO): Powering down 2023-05-15T18:57:50.933Z,1684177070.933 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:50.933Z,1684177070.933 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:50.948Z,1684177070.948 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-05-15T18:57:50.948Z,1684177070.948 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:50.948Z,1684177070.948 [Onboard](INFO): Join timeout helper Thread ID is 7126 2023-05-15T18:57:53.480Z,1684177073.480 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:53.480Z,1684177073.480 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:53.492Z,1684177073.492 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-05-15T18:57:53.492Z,1684177073.492 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:53.492Z,1684177073.492 [DataOverHttps](INFO): Join timeout helper Thread ID is 7127 2023-05-15T18:57:54.072Z,1684177074.072 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:54.076Z,1684177074.076 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.088Z,1684177074.088 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler 2023-05-15T18:57:54.088Z,1684177074.088 [DATMMP ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.088Z,1684177074.088 [DATMMP](INFO): Join timeout helper Thread ID is 7128 2023-05-15T18:57:54.248Z,1684177074.248 [DATMMP](INFO): Stop 2023-05-15T18:57:54.248Z,1684177074.248 [DATMMP](INFO): uninitialize 2023-05-15T18:57:54.248Z,1684177074.248 [DATMMP](INFO): Powering down 2023-05-15T18:57:54.317Z,1684177074.317 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:54.317Z,1684177074.317 [DATMMP](INFO): uninitialize 2023-05-15T18:57:54.317Z,1684177074.317 [DATMMP](INFO): Powering down 2023-05-15T18:57:54.318Z,1684177074.318 [DATMMP ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.338Z,1684177074.338 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2023-05-15T18:57:54.338Z,1684177074.338 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.339Z,1684177074.339 [BackseatComponent](INFO): Join timeout helper Thread ID is 7129 2023-05-15T18:57:54.360Z,1684177074.360 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:54.360Z,1684177074.360 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.377Z,1684177074.377 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-05-15T18:57:54.377Z,1684177074.377 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.377Z,1684177074.377 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7130 2023-05-15T18:57:54.636Z,1684177074.636 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:54.636Z,1684177074.636 [WetLabsBB2FL](INFO): Powering down 2023-05-15T18:57:54.637Z,1684177074.637 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.652Z,1684177074.652 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-05-15T18:57:54.652Z,1684177074.652 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:54.653Z,1684177074.653 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7131 2023-05-15T18:57:55.632Z,1684177075.632 [CTD_Seabird](INFO): Powering down 2023-05-15T18:57:55.644Z,1684177075.644 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:55.644Z,1684177075.644 [CTD_Seabird](INFO): Powering down 2023-05-15T18:57:55.656Z,1684177075.656 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:55.664Z,1684177075.664 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-05-15T18:57:55.664Z,1684177075.664 [logger ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:55.665Z,1684177075.665 [logger](INFO): Join timeout helper Thread ID is 7132 2023-05-15T18:57:55.676Z,1684177075.676 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:55.676Z,1684177075.676 [logger ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:55.684Z,1684177075.684 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-05-15T18:57:55.684Z,1684177075.684 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:55.685Z,1684177075.685 [CommandLine](INFO): Join timeout helper Thread ID is 7133 2023-05-15T18:57:55.712Z,1684177075.712 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:55.712Z,1684177075.712 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:55.724Z,1684177075.724 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-05-15T18:57:55.724Z,1684177075.724 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:55.725Z,1684177075.725 [CommandExec](INFO): Join timeout helper Thread ID is 7134 2023-05-15T18:57:55.726Z,1684177075.726 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-05-15T18:57:55.726Z,1684177075.726 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:55.726Z,1684177075.726 [controlThread](INFO): Join timeout helper Thread ID is 7135 2023-05-15T18:57:55.996Z,1684177075.996 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-15T18:57:55.996Z,1684177075.996 [controlThread](DEBUG): Uninitializing ControlThread 2023-05-15T18:57:55.997Z,1684177075.997 [AHRS_M2](INFO): Powering down 2023-05-15T18:57:56.140Z,1684177076.140 [DVL_micro](INFO): Powering down 2023-05-15T18:57:56.141Z,1684177076.141 [NAL9602](INFO): Powering down 2023-05-15T18:57:56.142Z,1684177076.142 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-05-15T18:57:56.143Z,1684177076.143 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2023-05-15T18:57:56.144Z,1684177076.144 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2023-05-15T18:57:56.144Z,1684177076.144 [MissionManager](INFO): Uninitializing Mission Default 2023-05-15T18:57:56.144Z,1684177076.144 [Default] Stopped 2023-05-15T18:57:56.144Z,1684177076.144 [Default](DEBUG): Aggregate::uninitialize Default 2023-05-15T18:57:56.145Z,1684177076.145 [Default:B.GoToSurface] Stopped 2023-05-15T18:57:56.145Z,1684177076.145 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-05-15T18:57:56.145Z,1684177076.145 [Default:CheckIn] Stopped 2023-05-15T18:57:56.145Z,1684177076.145 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-15T18:57:56.145Z,1684177076.145 [Default:CheckIn:C.Wait] Stopped 2023-05-15T18:57:56.145Z,1684177076.145 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-15T18:57:56.148Z,1684177076.148 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2023-05-15T18:57:56.148Z,1684177076.148 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2023-05-15T18:57:56.148Z,1684177076.148 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2023-05-15T18:57:56.149Z,1684177076.149 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2023-05-15T18:57:56.149Z,1684177076.149 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2023-05-15T18:57:56.149Z,1684177076.149 [BuoyancyServo](INFO): Powering down 2023-05-15T18:57:56.164Z,1684177076.164 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2023-05-15T18:57:56.164Z,1684177076.164 [ElevatorServo](INFO): Powering down 2023-05-15T18:57:56.165Z,1684177076.165 [MassServo](DEBUG): Uninitialize Mass Servo. 2023-05-15T18:57:56.165Z,1684177076.165 [MassServo](INFO): Powering down 2023-05-15T18:57:56.166Z,1684177076.166 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-05-15T18:57:56.166Z,1684177076.166 [RudderServo](INFO): Powering down 2023-05-15T18:57:56.167Z,1684177076.167 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2023-05-15T18:57:56.167Z,1684177076.167 [ThrusterHE](INFO): Powering down 2023-05-15T18:57:56.168Z,1684177076.168 [SBIT](DEBUG): Uninitialize SBIT Component. 2023-05-15T18:57:56.168Z,1684177076.168 [IBIT](DEBUG): Uninitialize IBIT Component. 2023-05-15T18:57:56.168Z,1684177076.168 [CBIT](DEBUG): Uninitialize CBIT Component. 2023-05-15T18:57:56.168Z,1684177076.168 [CBIT](DEBUG): Powering off loads. 2023-05-15T18:57:56.180Z,1684177076.180 [CBIT](DEBUG): Disabling WDT. 2023-05-15T18:57:56.192Z,1684177076.192 [CBIT](DEBUG): Opening all GF detection circuits. 2023-05-15T18:57:56.193Z,1684177076.193 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.237Z,1684177076.237 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.243Z,1684177076.243 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.276Z,1684177076.276 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.278Z,1684177076.278 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.286Z,1684177076.286 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.293Z,1684177076.293 [DATMMP ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.335Z,1684177076.335 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.394Z,1684177076.394 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-15T18:57:56.473Z,1684177076.473 [logger ThreadHandler](INFO): Thread cancelled.