2021-04-09T17:26:51.437Z,1617989211.437 [CommandLine](IMPORTANT): got command restart logs 2021-04-09T17:27:06.201Z,1617989226.201 [DVL_micro](ERROR): Failed to parse: :WI,-00149,+00053,-00230,+00000,A 2021-04-09T17:27:21.954Z,1617989241.954 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T17:30:47.296Z,1617989447.296 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T17:30:47.317Z,1617989447.317 [Default:CheckIn:C.Wait] Stopped 2021-04-09T17:30:47.317Z,1617989447.317 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T17:30:47.317Z,1617989447.317 [Default:CheckIn:D] Running Loop=1 2021-04-09T17:30:47.688Z,1617989447.688 [Default:CheckIn:D] Stopped 2021-04-09T17:30:47.688Z,1617989447.688 [Default:CheckIn:E] Running Loop=1 2021-04-09T17:30:48.107Z,1617989448.107 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.920565 min 2021-04-09T17:30:48.107Z,1617989448.107 [Default:CheckIn:E] Stopped 2021-04-09T17:30:48.107Z,1617989448.107 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T17:30:48.107Z,1617989448.107 [Default:CheckIn] Stopped 2021-04-09T17:30:48.107Z,1617989448.107 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T17:30:48.108Z,1617989448.108 [Default:CheckIn](INFO): Running loop #17 2021-04-09T17:30:48.108Z,1617989448.108 [Default:CheckIn] Running Loop=17 2021-04-09T17:30:48.108Z,1617989448.108 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T17:30:48.108Z,1617989448.108 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T17:30:50.104Z,1617989450.104 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173035.00,A,3648.25322,N,12147.14381,W,4.043,190.98,090421,,,D*7D 2021-04-09T17:30:50.107Z,1617989450.107 [NAL9602](INFO): GPS fix at 20210409T173035: (36.804220, -121.785730) 2021-04-09T17:30:50.142Z,1617989450.142 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T17:30:50.142Z,1617989450.142 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T17:30:57.832Z,1617989457.832 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210409T094856/Courier0115.lzma 2021-04-09T17:30:58.835Z,1617989458.835 [DataOverHttps](INFO): Moved sent file to Logs/20210409T094856/Courier0115.lzma.bak 2021-04-09T17:30:58.835Z,1617989458.835 [DataOverHttps](INFO): SBD MOMSN=15555786 2021-04-09T17:31:09.490Z,1617989469.490 [NAL9602](INFO): SBD MO Status=2, MOMSN=1796, MT Status=2, MTMSN=0 2021-04-09T17:31:09.490Z,1617989469.490 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T17:31:14.729Z,1617989474.729 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20210409T172651/Courier0000.lzma 2021-04-09T17:31:15.727Z,1617989475.727 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0000.lzma.bak 2021-04-09T17:31:15.727Z,1617989475.727 [DataOverHttps](INFO): SBD MOMSN=15555788 2021-04-09T17:31:19.188Z,1617989479.188 [NAL9602](INFO): SBD MO Status=0, MOMSN=1796, MT Status=0, MTMSN=0 2021-04-09T17:31:19.188Z,1617989479.188 [NAL9602](INFO): No messages in MT queue 2021-04-09T17:31:32.067Z,1617989492.067 [DataOverHttps](INFO): Sending 116 bytes from file Logs/20210409T094856/Express0116.lzma 2021-04-09T17:31:32.615Z,1617989492.615 [DataOverHttps](INFO): Moved sent file to Logs/20210409T094856/Express0116.lzma.bak 2021-04-09T17:31:32.615Z,1617989492.615 [DataOverHttps](INFO): SBD MOMSN=15555792 2021-04-09T17:31:48.421Z,1617989508.421 [DataOverHttps](INFO): Sending 392 bytes from file Logs/20210409T172651/Express0001.lzma 2021-04-09T17:31:49.422Z,1617989509.422 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0001.lzma.bak 2021-04-09T17:31:49.423Z,1617989509.423 [DataOverHttps](INFO): SBD MOMSN=15555795 2021-04-09T17:31:49.894Z,1617989509.894 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T17:31:51.525Z,1617989511.525 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T17:31:51.525Z,1617989511.525 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T17:31:51.525Z,1617989511.525 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T17:33:28.882Z,1617989608.882 [DVL_micro](ERROR): Failed to parse: :WI,-0062,-00182,+00000,A 2021-04-09T17:36:52.167Z,1617989812.167 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T17:36:52.167Z,1617989812.167 [Default:CheckIn:C.Wait] Stopped 2021-04-09T17:36:52.167Z,1617989812.167 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T17:36:52.168Z,1617989812.168 [Default:CheckIn:D] Running Loop=1 2021-04-09T17:36:52.564Z,1617989812.564 [Default:CheckIn:D] Stopped 2021-04-09T17:36:52.565Z,1617989812.565 [Default:CheckIn:E] Running Loop=1 2021-04-09T17:36:52.982Z,1617989812.982 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.001831 min 2021-04-09T17:36:52.982Z,1617989812.982 [Default:CheckIn:E] Stopped 2021-04-09T17:36:52.982Z,1617989812.982 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T17:36:52.982Z,1617989812.982 [Default:CheckIn] Stopped 2021-04-09T17:36:52.982Z,1617989812.982 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T17:36:52.982Z,1617989812.982 [Default:CheckIn](INFO): Running loop #18 2021-04-09T17:36:52.983Z,1617989812.983 [Default:CheckIn] Running Loop=18 2021-04-09T17:36:52.983Z,1617989812.983 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T17:36:52.983Z,1617989812.983 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T17:36:54.975Z,1617989814.975 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173640.00,A,3648.15800,N,12147.21546,W,0.058,210.94,090421,,,D*73 2021-04-09T17:36:54.977Z,1617989814.977 [NAL9602](INFO): GPS fix at 20210409T173640: (36.802633, -121.786924) 2021-04-09T17:36:54.988Z,1617989814.988 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T17:36:54.988Z,1617989814.988 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T17:37:02.728Z,1617989822.728 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210409T172651/Courier0003.lzma 2021-04-09T17:37:03.730Z,1617989823.730 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0003.lzma.bak 2021-04-09T17:37:03.731Z,1617989823.731 [DataOverHttps](INFO): SBD MOMSN=15555866 2021-04-09T17:37:19.620Z,1617989839.620 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210409T172651/Express0004.lzma 2021-04-09T17:37:20.623Z,1617989840.623 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0004.lzma.bak 2021-04-09T17:37:20.623Z,1617989840.623 [DataOverHttps](INFO): SBD MOMSN=15555870 2021-04-09T17:37:22.483Z,1617989842.483 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T17:37:22.484Z,1617989842.484 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T17:37:22.484Z,1617989842.484 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T17:38:19.814Z,1617989899.814 [NAL9602](INFO): SBD MO Status=0, MOMSN=1797, MT Status=0, MTMSN=0 2021-04-09T17:38:19.814Z,1617989899.814 [NAL9602](INFO): No messages in MT queue 2021-04-09T17:38:50.518Z,1617989930.518 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T17:42:21.865Z,1617990141.865 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T17:42:21.865Z,1617990141.865 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2021-04-09T17:42:23.089Z,1617990143.089 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T17:42:23.089Z,1617990143.089 [Default:CheckIn:C.Wait] Stopped 2021-04-09T17:42:23.089Z,1617990143.089 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T17:42:23.089Z,1617990143.089 [Default:CheckIn:D] Running Loop=1 2021-04-09T17:42:23.493Z,1617990143.493 [Default:CheckIn:D] Stopped 2021-04-09T17:42:23.493Z,1617990143.493 [Default:CheckIn:E] Running Loop=1 2021-04-09T17:42:23.897Z,1617990143.897 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.517301 min 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn:E] Stopped 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn] Stopped 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn](INFO): Running loop #19 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn] Running Loop=19 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T17:42:23.898Z,1617990143.898 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T17:42:25.902Z,1617990145.902 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174211.00,A,3648.15773,N,12147.21607,W,0.039,210.94,090421,,,D*7E 2021-04-09T17:42:25.904Z,1617990145.904 [NAL9602](INFO): GPS fix at 20210409T174211: (36.802629, -121.786935) 2021-04-09T17:42:25.920Z,1617990145.920 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T17:42:25.920Z,1617990145.920 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T17:42:37.492Z,1617990157.492 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0006.lzma 2021-04-09T17:42:38.020Z,1617990158.020 [NAL9602](INFO): SBD MO Status=0, MOMSN=1798, MT Status=0, MTMSN=0 2021-04-09T17:42:38.020Z,1617990158.020 [NAL9602](INFO): No messages in MT queue 2021-04-09T17:42:38.495Z,1617990158.495 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0006.lzma.bak 2021-04-09T17:42:38.495Z,1617990158.495 [DataOverHttps](INFO): SBD MOMSN=15555895 2021-04-09T17:42:54.468Z,1617990174.468 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210409T172651/Express0007.lzma 2021-04-09T17:42:55.471Z,1617990175.471 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0007.lzma.bak 2021-04-09T17:42:55.471Z,1617990175.471 [DataOverHttps](INFO): SBD MOMSN=15555898 2021-04-09T17:42:57.419Z,1617990177.419 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T17:42:57.420Z,1617990177.420 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T17:42:57.420Z,1617990177.420 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T17:43:08.711Z,1617990188.711 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T17:44:17.019Z,1617990257.019 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-09T17:44:17.019Z,1617990257.019 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2021-04-09T17:47:58.109Z,1617990478.109 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T17:47:58.109Z,1617990478.109 [Default:CheckIn:C.Wait] Stopped 2021-04-09T17:47:58.109Z,1617990478.109 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T17:47:58.110Z,1617990478.110 [Default:CheckIn:D] Running Loop=1 2021-04-09T17:47:58.525Z,1617990478.525 [Default:CheckIn:D] Stopped 2021-04-09T17:47:58.525Z,1617990478.525 [Default:CheckIn:E] Running Loop=1 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.100903 min 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn:E] Stopped 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn] Stopped 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn](INFO): Running loop #20 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn] Running Loop=20 2021-04-09T17:47:58.907Z,1617990478.907 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T17:47:58.908Z,1617990478.908 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T17:48:00.920Z,1617990480.920 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174746.00,A,3648.14202,N,12147.24427,W,2.527,293.65,090421,,,D*73 2021-04-09T17:48:00.922Z,1617990480.922 [NAL9602](INFO): GPS fix at 20210409T174746: (36.802367, -121.787404) 2021-04-09T17:48:00.933Z,1617990480.933 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T17:48:00.933Z,1617990480.933 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T17:48:08.264Z,1617990488.264 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0009.lzma 2021-04-09T17:48:09.266Z,1617990489.266 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0009.lzma.bak 2021-04-09T17:48:09.267Z,1617990489.267 [DataOverHttps](INFO): SBD MOMSN=15555921 2021-04-09T17:48:16.301Z,1617990496.301 [NAL9602](INFO): SBD MO Status=0, MOMSN=1799, MT Status=0, MTMSN=0 2021-04-09T17:48:16.301Z,1617990496.301 [NAL9602](INFO): No messages in MT queue 2021-04-09T17:48:29.265Z,1617990509.265 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210409T172651/Express0010.lzma 2021-04-09T17:48:30.263Z,1617990510.263 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0010.lzma.bak 2021-04-09T17:48:30.263Z,1617990510.263 [DataOverHttps](INFO): SBD MOMSN=15555924 2021-04-09T17:48:33.003Z,1617990513.003 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T17:48:33.004Z,1617990513.004 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T17:48:33.004Z,1617990513.004 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T17:48:46.708Z,1617990526.708 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T17:49:19.853Z,1617990559.853 [DVL_micro](ERROR): Failed to parse: :SA,-01.68,-12.34,266.1 2021-04-09T17:50:20.845Z,1617990620.845 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2021-04-09T17:50:20.846Z,1617990620.846 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2021-04-09T17:50:20.848Z,1617990620.848 [BPC1](INFO): Received data from all battery sticks. 2021-04-09T17:51:51.358Z,1617990711.358 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2021-04-09T17:52:29.784Z,1617990749.784 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-09T17:52:29.785Z,1617990749.785 [DVL_micro](ERROR): Failed to parse: :BI,-01816,-00061,-0031,I 2021-04-09T17:53:33.657Z,1617990813.657 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T17:53:33.657Z,1617990813.657 [Default:CheckIn:C.Wait] Stopped 2021-04-09T17:53:33.658Z,1617990813.658 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T17:53:33.658Z,1617990813.658 [Default:CheckIn:D] Running Loop=1 2021-04-09T17:53:34.032Z,1617990814.032 [Default:CheckIn:D] Stopped 2021-04-09T17:53:34.032Z,1617990814.032 [Default:CheckIn:E] Running Loop=1 2021-04-09T17:53:34.449Z,1617990814.449 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.692961 min 2021-04-09T17:53:34.449Z,1617990814.449 [Default:CheckIn:E] Stopped 2021-04-09T17:53:34.449Z,1617990814.449 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T17:53:34.449Z,1617990814.449 [Default:CheckIn] Stopped 2021-04-09T17:53:34.450Z,1617990814.450 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T17:53:34.450Z,1617990814.450 [Default:CheckIn](INFO): Running loop #21 2021-04-09T17:53:34.450Z,1617990814.450 [Default:CheckIn] Running Loop=21 2021-04-09T17:53:34.450Z,1617990814.450 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T17:53:34.450Z,1617990814.450 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T17:53:36.451Z,1617990816.451 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175322.00,A,3648.16648,N,12147.28096,W,0.233,92.25,090421,,,D*49 2021-04-09T17:53:36.453Z,1617990816.453 [NAL9602](INFO): GPS fix at 20210409T175322: (36.802775, -121.788016) 2021-04-09T17:53:36.484Z,1617990816.484 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T17:53:36.484Z,1617990816.484 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T17:53:44.660Z,1617990824.660 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210409T172651/Courier0012.lzma 2021-04-09T17:53:45.663Z,1617990825.663 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0012.lzma.bak 2021-04-09T17:53:45.663Z,1617990825.663 [DataOverHttps](INFO): SBD MOMSN=15555951 2021-04-09T17:54:01.529Z,1617990841.529 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210409T172651/Express0013.lzma 2021-04-09T17:54:02.531Z,1617990842.531 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0013.lzma.bak 2021-04-09T17:54:02.531Z,1617990842.531 [DataOverHttps](INFO): SBD MOMSN=15555954 2021-04-09T17:54:04.362Z,1617990844.362 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T17:54:04.362Z,1617990844.362 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T17:54:04.362Z,1617990844.362 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T17:56:48.808Z,1617991008.808 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T17:56:48.808Z,1617991008.808 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T17:58:23.808Z,1617991103.808 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T17:58:23.808Z,1617991103.808 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T17:58:39.195Z,1617991119.195 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T17:59:05.051Z,1617991145.051 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T17:59:05.051Z,1617991145.051 [Default:CheckIn:C.Wait] Stopped 2021-04-09T17:59:05.051Z,1617991145.051 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T17:59:05.051Z,1617991145.051 [Default:CheckIn:D] Running Loop=1 2021-04-09T17:59:05.464Z,1617991145.464 [Default:CheckIn:D] Stopped 2021-04-09T17:59:05.464Z,1617991145.464 [Default:CheckIn:E] Running Loop=1 2021-04-09T17:59:05.865Z,1617991145.865 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.216821 min 2021-04-09T17:59:05.865Z,1617991145.865 [Default:CheckIn:E] Stopped 2021-04-09T17:59:05.865Z,1617991145.865 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T17:59:05.866Z,1617991145.866 [Default:CheckIn] Stopped 2021-04-09T17:59:05.866Z,1617991145.866 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T17:59:05.866Z,1617991145.866 [Default:CheckIn](INFO): Running loop #22 2021-04-09T17:59:05.866Z,1617991145.866 [Default:CheckIn] Running Loop=22 2021-04-09T17:59:05.866Z,1617991145.866 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T17:59:05.866Z,1617991145.866 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T17:59:07.906Z,1617991147.906 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175853.00,A,3648.16692,N,12147.28071,W,0.914,92.25,090421,,,A*41 2021-04-09T17:59:07.908Z,1617991147.908 [NAL9602](INFO): GPS fix at 20210409T175853: (36.802782, -121.788012) 2021-04-09T17:59:07.919Z,1617991147.919 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T17:59:07.919Z,1617991147.919 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T17:59:15.640Z,1617991155.640 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0015.lzma 2021-04-09T17:59:16.643Z,1617991156.643 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0015.lzma.bak 2021-04-09T17:59:16.643Z,1617991156.643 [DataOverHttps](INFO): SBD MOMSN=15555971 2021-04-09T17:59:32.501Z,1617991172.501 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20210409T172651/Express0016.lzma 2021-04-09T17:59:33.503Z,1617991173.503 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0016.lzma.bak 2021-04-09T17:59:33.503Z,1617991173.503 [DataOverHttps](INFO): SBD MOMSN=15555974 2021-04-09T17:59:35.373Z,1617991175.373 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T17:59:35.373Z,1617991175.373 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T17:59:35.373Z,1617991175.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T17:59:39.790Z,1617991179.790 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:03:47.894Z,1617991427.894 [DVL_micro](ERROR): Failed to parse: :B,-00125,+0000,I 2021-04-09T18:04:36.057Z,1617991476.057 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:04:36.057Z,1617991476.057 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:04:36.058Z,1617991476.058 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:04:36.058Z,1617991476.058 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:04:36.494Z,1617991476.494 [Default:CheckIn:D] Stopped 2021-04-09T18:04:36.494Z,1617991476.494 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.734001 min 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn:E] Stopped 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn] Stopped 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn](INFO): Running loop #23 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn] Running Loop=23 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:04:36.897Z,1617991476.897 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:04:38.876Z,1617991478.876 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180424.00,A,3648.16491,N,12147.28466,W,0.272,0.00,090421,,,A*73 2021-04-09T18:04:38.878Z,1617991478.878 [NAL9602](INFO): GPS fix at 20210409T180424: (36.802748, -121.788078) 2021-04-09T18:04:38.889Z,1617991478.889 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:04:38.889Z,1617991478.889 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:04:46.504Z,1617991486.504 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210409T172651/Courier0018.lzma 2021-04-09T18:04:47.507Z,1617991487.507 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0018.lzma.bak 2021-04-09T18:04:47.507Z,1617991487.507 [DataOverHttps](INFO): SBD MOMSN=15555992 2021-04-09T18:05:03.340Z,1617991503.340 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20210409T172651/Express0019.lzma 2021-04-09T18:05:04.343Z,1617991504.343 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0019.lzma.bak 2021-04-09T18:05:04.343Z,1617991504.343 [DataOverHttps](INFO): SBD MOMSN=15555996 2021-04-09T18:05:06.368Z,1617991506.368 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:05:06.368Z,1617991506.368 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:05:06.373Z,1617991506.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:05:09.575Z,1617991509.575 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-09T18:05:09.649Z,1617991509.649 [NAL9602](FAULT): received: +CSQ:0 OK00, 2, 0, 0, 0 OK 2021-04-09T18:05:09.649Z,1617991509.649 [NAL9602] Data Fault, FailCount= 1 2021-04-09T18:05:09.649Z,1617991509.649 [NAL9602](ERROR): Data Fault 2021-04-09T18:05:09.718Z,1617991509.718 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-09T18:05:09.996Z,1617991509.996 [NAL9602](INFO): Powering down 2021-04-09T18:05:10.805Z,1617991510.805 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-09T18:05:10.805Z,1617991510.805 [NAL9602] No Fault, FailCount= 1 2021-04-09T18:05:28.158Z,1617991528.158 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T18:05:28.158Z,1617991528.158 [DVL_micro](ERROR): Failed to parse: :TS,000000000000003.9,0000.0,1489.0,000 2021-04-09T18:05:40.276Z,1617991540.276 [NAL9602](INFO): Powering up NAL9602 2021-04-09T18:05:51.204Z,1617991551.204 [NAL9602](INFO): NAL9602 initialized 2021-04-09T18:06:22.292Z,1617991582.292 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:10:06.000Z,1617991807.000 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:10:06.000Z,1617991807.000 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:10:06.000Z,1617991807.000 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:10:07.000Z,1617991807.000 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:10:07.428Z,1617991807.428 [Default:CheckIn:D] Stopped 2021-04-09T18:10:07.428Z,1617991807.428 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:10:07.831Z,1617991807.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.249561 min 2021-04-09T18:10:07.831Z,1617991807.831 [Default:CheckIn:E] Stopped 2021-04-09T18:10:07.831Z,1617991807.831 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:10:07.831Z,1617991807.831 [Default:CheckIn] Stopped 2021-04-09T18:10:07.831Z,1617991807.831 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:10:07.831Z,1617991807.831 [Default:CheckIn](INFO): Running loop #24 2021-04-09T18:10:07.831Z,1617991807.831 [Default:CheckIn] Running Loop=24 2021-04-09T18:10:07.832Z,1617991807.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:10:07.832Z,1617991807.832 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:10:09.824Z,1617991809.824 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180954.00,A,3648.16562,N,12147.28273,W,1.069,333.53,090421,,,A*7A 2021-04-09T18:10:09.826Z,1617991809.826 [NAL9602](INFO): GPS fix at 20210409T180954: (36.802760, -121.788045) 2021-04-09T18:10:09.838Z,1617991809.838 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:10:09.838Z,1617991809.838 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:10:11.435Z,1617991811.435 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T18:10:18.736Z,1617991818.736 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0021.lzma 2021-04-09T18:10:19.739Z,1617991819.739 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0021.lzma.bak 2021-04-09T18:10:19.739Z,1617991819.739 [DataOverHttps](INFO): SBD MOMSN=15556017 2021-04-09T18:10:42.218Z,1617991842.218 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:10:42.300Z,1617991842.300 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20210409T172651/Express0022.lzma 2021-04-09T18:10:43.306Z,1617991843.306 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0022.lzma.bak 2021-04-09T18:10:43.307Z,1617991843.307 [DataOverHttps](INFO): SBD MOMSN=15556021 2021-04-09T18:10:45.474Z,1617991845.474 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:10:45.474Z,1617991845.474 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:10:45.474Z,1617991845.474 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:15:46.105Z,1617992146.105 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:15:46.105Z,1617992146.105 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:15:46.105Z,1617992146.105 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:15:46.106Z,1617992146.106 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:15:46.473Z,1617992146.473 [Default:CheckIn:D] Stopped 2021-04-09T18:15:46.473Z,1617992146.473 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:15:46.878Z,1617992146.878 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.900309 min 2021-04-09T18:15:46.878Z,1617992146.878 [Default:CheckIn:E] Stopped 2021-04-09T18:15:46.879Z,1617992146.879 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:15:46.879Z,1617992146.879 [Default:CheckIn] Stopped 2021-04-09T18:15:46.879Z,1617992146.879 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:15:46.879Z,1617992146.879 [Default:CheckIn](INFO): Running loop #25 2021-04-09T18:15:46.879Z,1617992146.879 [Default:CheckIn] Running Loop=25 2021-04-09T18:15:46.879Z,1617992146.879 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:15:46.879Z,1617992146.879 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:15:48.882Z,1617992148.882 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181533.00,A,3648.16659,N,12147.28280,W,0.136,333.53,090421,,,A*7B 2021-04-09T18:15:48.884Z,1617992148.884 [NAL9602](INFO): GPS fix at 20210409T181533: (36.802777, -121.788047) 2021-04-09T18:15:48.913Z,1617992148.913 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:15:48.913Z,1617992148.913 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:15:55.992Z,1617992155.992 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0024.lzma 2021-04-09T18:15:56.995Z,1617992156.995 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0024.lzma.bak 2021-04-09T18:15:56.995Z,1617992156.995 [DataOverHttps](INFO): SBD MOMSN=15556039 2021-04-09T18:16:12.841Z,1617992172.841 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210409T172651/Express0025.lzma 2021-04-09T18:16:13.843Z,1617992173.843 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0025.lzma.bak 2021-04-09T18:16:13.843Z,1617992173.843 [DataOverHttps](INFO): SBD MOMSN=15556042 2021-04-09T18:16:16.860Z,1617992176.860 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:16:16.860Z,1617992176.860 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:16:16.860Z,1617992176.860 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:18:21.829Z,1617992301.829 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T18:18:21.829Z,1617992301.829 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T18:20:50.944Z,1617992450.944 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T18:21:17.585Z,1617992477.585 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:21:17.585Z,1617992477.585 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:21:17.585Z,1617992477.585 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:21:17.586Z,1617992477.586 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:21:18.002Z,1617992478.002 [Default:CheckIn:D] Stopped 2021-04-09T18:21:18.002Z,1617992478.002 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:21:18.404Z,1617992478.404 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 142.425798 min 2021-04-09T18:21:18.404Z,1617992478.404 [Default:CheckIn:E] Stopped 2021-04-09T18:21:18.404Z,1617992478.404 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:21:18.404Z,1617992478.404 [Default:CheckIn] Stopped 2021-04-09T18:21:18.404Z,1617992478.404 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:21:18.404Z,1617992478.404 [Default:CheckIn](INFO): Running loop #26 2021-04-09T18:21:18.405Z,1617992478.405 [Default:CheckIn] Running Loop=26 2021-04-09T18:21:18.405Z,1617992478.405 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:21:18.405Z,1617992478.405 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:21:20.404Z,1617992480.404 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182106.00,A,3648.16755,N,12147.28040,W,0.078,223.42,090421,,,A*72 2021-04-09T18:21:20.407Z,1617992480.407 [NAL9602](INFO): GPS fix at 20210409T182106: (36.802793, -121.788007) 2021-04-09T18:21:20.437Z,1617992480.437 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:21:20.437Z,1617992480.437 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:21:27.504Z,1617992487.504 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0027.lzma 2021-04-09T18:21:28.506Z,1617992488.506 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0027.lzma.bak 2021-04-09T18:21:28.507Z,1617992488.507 [DataOverHttps](INFO): SBD MOMSN=15556061 2021-04-09T18:21:44.264Z,1617992504.264 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210409T172651/Express0028.lzma 2021-04-09T18:21:45.266Z,1617992505.266 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0028.lzma.bak 2021-04-09T18:21:45.267Z,1617992505.267 [DataOverHttps](INFO): SBD MOMSN=15556064 2021-04-09T18:21:48.006Z,1617992508.006 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:21:48.006Z,1617992508.006 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:21:48.006Z,1617992508.006 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:21:52.830Z,1617992512.830 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:23:11.618Z,1617992591.618 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T18:23:11.618Z,1617992591.618 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,00.0,1489.0,000 2021-04-09T18:25:04.006Z,1617992704.006 [DVL_micro](ERROR): only read 2 of 4 data items 2021-04-09T18:25:04.007Z,1617992704.007 [DVL_micro](ERROR): Failed to parse: :RD,+9999.999,+9999.999 2021-04-09T18:26:48.640Z,1617992808.640 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:26:48.640Z,1617992808.640 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:26:48.640Z,1617992808.640 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:26:48.641Z,1617992808.641 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:26:49.075Z,1617992809.075 [Default:CheckIn:D] Stopped 2021-04-09T18:26:49.075Z,1617992809.075 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:26:49.445Z,1617992809.445 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.943669 min 2021-04-09T18:26:49.445Z,1617992809.445 [Default:CheckIn:E] Stopped 2021-04-09T18:26:49.446Z,1617992809.446 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:26:49.446Z,1617992809.446 [Default:CheckIn] Stopped 2021-04-09T18:26:49.446Z,1617992809.446 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:26:49.446Z,1617992809.446 [Default:CheckIn](INFO): Running loop #27 2021-04-09T18:26:49.446Z,1617992809.446 [Default:CheckIn] Running Loop=27 2021-04-09T18:26:49.446Z,1617992809.446 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:26:49.446Z,1617992809.446 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:26:51.466Z,1617992811.466 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182637.00,A,3648.16538,N,12147.27872,W,0.311,199.52,090421,,,A*77 2021-04-09T18:26:51.468Z,1617992811.468 [NAL9602](INFO): GPS fix at 20210409T182637: (36.802756, -121.787979) 2021-04-09T18:26:51.479Z,1617992811.479 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:26:51.479Z,1617992811.479 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:26:59.072Z,1617992819.072 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0030.lzma 2021-04-09T18:27:00.075Z,1617992820.075 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0030.lzma.bak 2021-04-09T18:27:00.075Z,1617992820.075 [DataOverHttps](INFO): SBD MOMSN=15556080 2021-04-09T18:27:16.020Z,1617992836.020 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210409T172651/Express0031.lzma 2021-04-09T18:27:17.023Z,1617992837.023 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0031.lzma.bak 2021-04-09T18:27:17.023Z,1617992837.023 [DataOverHttps](INFO): SBD MOMSN=15556083 2021-04-09T18:27:18.944Z,1617992838.944 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:27:18.944Z,1617992838.944 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:27:18.945Z,1617992838.945 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:27:22.196Z,1617992842.196 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-09T18:27:22.269Z,1617992842.269 [NAL9602](FAULT): received: +CSQ:0 OK00, 2, 0, 0, 0 OK 2021-04-09T18:27:22.269Z,1617992842.269 [NAL9602] Data Fault, FailCount= 1 2021-04-09T18:27:22.269Z,1617992842.269 [NAL9602](ERROR): Data Fault 2021-04-09T18:27:22.340Z,1617992842.340 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-09T18:27:22.558Z,1617992842.558 [NAL9602](INFO): Powering down 2021-04-09T18:27:23.455Z,1617992843.455 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-09T18:27:23.455Z,1617992843.455 [NAL9602] No Fault, FailCount= 1 2021-04-09T18:27:52.866Z,1617992872.866 [NAL9602](INFO): Powering up NAL9602 2021-04-09T18:28:03.767Z,1617992883.767 [NAL9602](INFO): NAL9602 initialized 2021-04-09T18:28:34.882Z,1617992914.882 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:32:19.585Z,1617993139.585 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:32:19.585Z,1617993139.585 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:32:19.585Z,1617993139.585 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:32:19.586Z,1617993139.586 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:32:20.001Z,1617993140.001 [Default:CheckIn:D] Stopped 2021-04-09T18:32:20.001Z,1617993140.001 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:32:20.388Z,1617993140.388 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 153.459098 min 2021-04-09T18:32:20.388Z,1617993140.388 [Default:CheckIn:E] Stopped 2021-04-09T18:32:20.389Z,1617993140.389 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:32:20.389Z,1617993140.389 [Default:CheckIn] Stopped 2021-04-09T18:32:20.389Z,1617993140.389 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:32:20.389Z,1617993140.389 [Default:CheckIn](INFO): Running loop #28 2021-04-09T18:32:20.389Z,1617993140.389 [Default:CheckIn] Running Loop=28 2021-04-09T18:32:20.389Z,1617993140.389 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:32:20.389Z,1617993140.389 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:32:22.404Z,1617993142.404 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183208.00,A,3648.16764,N,12147.27774,W,0.019,0.00,090421,,,A*71 2021-04-09T18:32:22.410Z,1617993142.410 [NAL9602](INFO): GPS fix at 20210409T183208: (36.802794, -121.787962) 2021-04-09T18:32:22.428Z,1617993142.428 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:32:22.428Z,1617993142.428 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:32:24.363Z,1617993144.363 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T18:32:33.820Z,1617993153.820 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210409T172651/Courier0033.lzma 2021-04-09T18:32:34.823Z,1617993154.823 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0033.lzma.bak 2021-04-09T18:32:34.823Z,1617993154.823 [DataOverHttps](INFO): SBD MOMSN=15556106 2021-04-09T18:32:49.468Z,1617993169.468 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-09T18:32:49.473Z,1617993169.473 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2021-04-09T18:32:51.984Z,1617993171.984 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20210409T172651/Express0034.lzma 2021-04-09T18:32:52.987Z,1617993172.987 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0034.lzma.bak 2021-04-09T18:32:52.987Z,1617993172.987 [DataOverHttps](INFO): SBD MOMSN=15556109 2021-04-09T18:32:55.122Z,1617993175.122 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:32:55.146Z,1617993175.146 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:32:55.146Z,1617993175.146 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:32:55.146Z,1617993175.146 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:34:54.768Z,1617993294.768 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T18:34:54.768Z,1617993294.768 [DVL_micro](ERROR): Failed to parse: :TS,000000,35.0,+1.0,1489.0,000 2021-04-09T18:37:55.784Z,1617993475.784 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:37:55.785Z,1617993475.785 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:37:55.785Z,1617993475.785 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:37:55.786Z,1617993475.786 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:37:56.199Z,1617993476.199 [Default:CheckIn:D] Stopped 2021-04-09T18:37:56.199Z,1617993476.199 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 159.062402 min 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn:E] Stopped 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn] Stopped 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn](INFO): Running loop #29 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn] Running Loop=29 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:37:56.585Z,1617993476.585 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:37:58.603Z,1617993478.603 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183744.00,A,3648.16592,N,12147.27852,W,0.039,0.00,090421,,,A*7E 2021-04-09T18:37:58.606Z,1617993478.606 [NAL9602](INFO): GPS fix at 20210409T183744: (36.802765, -121.787975) 2021-04-09T18:37:58.616Z,1617993478.616 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:37:58.616Z,1617993478.616 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:38:06.244Z,1617993486.244 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210409T172651/Courier0036.lzma 2021-04-09T18:38:07.247Z,1617993487.247 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0036.lzma.bak 2021-04-09T18:38:07.247Z,1617993487.247 [DataOverHttps](INFO): SBD MOMSN=15556136 2021-04-09T18:38:27.065Z,1617993507.065 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210409T172651/Express0037.lzma 2021-04-09T18:38:28.067Z,1617993508.067 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0037.lzma.bak 2021-04-09T18:38:28.067Z,1617993508.067 [DataOverHttps](INFO): SBD MOMSN=15556139 2021-04-09T18:38:30.650Z,1617993510.650 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:38:30.651Z,1617993510.651 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:38:30.651Z,1617993510.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:39:42.987Z,1617993582.987 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T18:39:42.987Z,1617993582.987 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T18:43:00.684Z,1617993780.684 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T18:43:09.980Z,1617993789.980 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T18:43:09.980Z,1617993789.980 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+15.6,009.0,000 2021-04-09T18:43:31.386Z,1617993811.386 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:43:31.412Z,1617993811.412 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:43:31.412Z,1617993811.412 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:43:31.433Z,1617993811.433 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:43:31.433Z,1617993811.433 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:43:31.809Z,1617993811.809 [Default:CheckIn:D] Stopped 2021-04-09T18:43:31.809Z,1617993811.809 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:43:32.222Z,1617993812.222 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.655908 min 2021-04-09T18:43:32.222Z,1617993812.222 [Default:CheckIn:E] Stopped 2021-04-09T18:43:32.222Z,1617993812.222 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:43:32.222Z,1617993812.222 [Default:CheckIn] Stopped 2021-04-09T18:43:32.222Z,1617993812.222 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:43:32.222Z,1617993812.222 [Default:CheckIn](INFO): Running loop #30 2021-04-09T18:43:32.222Z,1617993812.222 [Default:CheckIn] Running Loop=30 2021-04-09T18:43:32.223Z,1617993812.223 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:43:32.223Z,1617993812.223 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:43:34.220Z,1617993814.220 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184320.00,A,3648.16466,N,12147.28109,W,0.136,0.00,090421,,,A*73 2021-04-09T18:43:34.223Z,1617993814.223 [NAL9602](INFO): GPS fix at 20210409T184320: (36.802744, -121.788018) 2021-04-09T18:43:34.254Z,1617993814.254 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:43:34.254Z,1617993814.254 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:43:42.648Z,1617993822.648 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210409T172651/Courier0039.lzma 2021-04-09T18:43:43.651Z,1617993823.651 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0039.lzma.bak 2021-04-09T18:43:43.651Z,1617993823.651 [DataOverHttps](INFO): SBD MOMSN=15556159 2021-04-09T18:43:59.598Z,1617993839.598 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20210409T172651/Express0040.lzma 2021-04-09T18:44:00.599Z,1617993840.599 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0040.lzma.bak 2021-04-09T18:44:00.599Z,1617993840.599 [DataOverHttps](INFO): SBD MOMSN=15556162 2021-04-09T18:44:02.515Z,1617993842.515 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:44:02.516Z,1617993842.516 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:44:02.516Z,1617993842.516 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:44:04.936Z,1617993844.936 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-09T18:44:05.017Z,1617993845.017 [NAL9602](FAULT): received: +CSQ:0 OK00, 2, 0, 0, 0 OK 2021-04-09T18:44:05.017Z,1617993845.017 [NAL9602] Data Fault, FailCount= 1 2021-04-09T18:44:05.017Z,1617993845.017 [NAL9602](ERROR): Data Fault 2021-04-09T18:44:05.078Z,1617993845.078 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-09T18:44:05.322Z,1617993845.322 [NAL9602](INFO): Powering down 2021-04-09T18:44:06.196Z,1617993846.196 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-09T18:44:06.196Z,1617993846.196 [NAL9602] No Fault, FailCount= 1 2021-04-09T18:44:35.623Z,1617993875.623 [NAL9602](INFO): Powering up NAL9602 2021-04-09T18:44:46.530Z,1617993886.530 [NAL9602](INFO): NAL9602 initialized 2021-04-09T18:45:17.653Z,1617993917.653 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:47:22.941Z,1617994042.941 [DVL_micro](ERROR): Failed to parse: :SA,-02.30,-05.97,113.0 2021-04-09T18:49:03.154Z,1617994143.154 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:49:03.154Z,1617994143.154 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:49:03.154Z,1617994143.154 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:49:03.154Z,1617994143.154 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:49:03.564Z,1617994143.564 [Default:CheckIn:D] Stopped 2021-04-09T18:49:03.564Z,1617994143.564 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.185156 min 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn:E] Stopped 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn] Stopped 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn](INFO): Running loop #31 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn] Running Loop=31 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:49:03.952Z,1617994143.952 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:49:05.968Z,1617994145.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184850.00,A,3648.16253,N,12147.28256,W,0.097,50.52,090421,,,A*4E 2021-04-09T18:49:05.970Z,1617994145.970 [NAL9602](INFO): GPS fix at 20210409T184850: (36.802709, -121.788043) 2021-04-09T18:49:05.981Z,1617994145.981 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:49:05.981Z,1617994145.981 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:49:07.588Z,1617994147.588 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T18:49:13.204Z,1617994153.204 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0042.lzma 2021-04-09T18:49:14.207Z,1617994154.207 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0042.lzma.bak 2021-04-09T18:49:14.207Z,1617994154.207 [DataOverHttps](INFO): SBD MOMSN=15556183 2021-04-09T18:49:25.356Z,1617994165.356 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T18:49:25.356Z,1617994165.356 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+15.9,0000.0,1489.0,000 2021-04-09T18:49:30.076Z,1617994170.076 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20210409T172651/Express0043.lzma 2021-04-09T18:49:31.079Z,1617994171.079 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0043.lzma.bak 2021-04-09T18:49:31.079Z,1617994171.079 [DataOverHttps](INFO): SBD MOMSN=15556186 2021-04-09T18:49:33.066Z,1617994173.066 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:49:33.066Z,1617994173.066 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:49:33.066Z,1617994173.066 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:49:38.287Z,1617994178.287 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:51:30.611Z,1617994290.611 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-09T18:51:30.611Z,1617994290.611 [DVL_micro](ERROR): Failed to parse: :BI,-00218,-01763,-00328,+ 2021-04-09T18:53:35.439Z,1617994415.439 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T18:53:35.439Z,1617994415.439 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+0.0,1489.0I,+00001-00336,+00000,A 2021-04-09T18:54:33.516Z,1617994473.516 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T18:54:33.521Z,1617994473.521 [Default:CheckIn:C.Wait] Stopped 2021-04-09T18:54:33.521Z,1617994473.521 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T18:54:33.521Z,1617994473.521 [Default:CheckIn:D] Running Loop=1 2021-04-09T18:54:33.882Z,1617994473.882 [Default:CheckIn:D] Stopped 2021-04-09T18:54:33.882Z,1617994473.882 [Default:CheckIn:E] Running Loop=1 2021-04-09T18:54:34.555Z,1617994474.555 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.690462 min 2021-04-09T18:54:34.555Z,1617994474.555 [Default:CheckIn:E] Stopped 2021-04-09T18:54:34.555Z,1617994474.555 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T18:54:34.555Z,1617994474.555 [Default:CheckIn] Stopped 2021-04-09T18:54:34.555Z,1617994474.555 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T18:54:34.555Z,1617994474.555 [Default:CheckIn](INFO): Running loop #32 2021-04-09T18:54:34.555Z,1617994474.555 [Default:CheckIn] Running Loop=32 2021-04-09T18:54:34.556Z,1617994474.556 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T18:54:34.556Z,1617994474.556 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T18:54:36.296Z,1617994476.296 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185422.00,A,3648.16597,N,12147.28341,W,0.078,50.52,090421,,,A*4F 2021-04-09T18:54:36.298Z,1617994476.298 [NAL9602](INFO): GPS fix at 20210409T185422: (36.802766, -121.788057) 2021-04-09T18:54:36.310Z,1617994476.310 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T18:54:36.310Z,1617994476.310 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T18:54:44.020Z,1617994484.020 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0045.lzma 2021-04-09T18:54:45.023Z,1617994485.023 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0045.lzma.bak 2021-04-09T18:54:45.023Z,1617994485.023 [DataOverHttps](INFO): SBD MOMSN=15556207 2021-04-09T18:55:01.061Z,1617994501.061 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210409T172651/Express0046.lzma 2021-04-09T18:55:02.063Z,1617994502.063 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0046.lzma.bak 2021-04-09T18:55:02.063Z,1617994502.063 [DataOverHttps](INFO): SBD MOMSN=15556210 2021-04-09T18:55:04.222Z,1617994504.222 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T18:55:04.222Z,1617994504.222 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T18:55:04.222Z,1617994504.222 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T18:55:07.417Z,1617994507.417 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T18:55:07.417Z,1617994507.417 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T18:56:03.156Z,1617994563.156 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T18:56:03.156Z,1617994563.156 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T18:56:18.504Z,1617994578.504 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T18:56:18.504Z,1617994578.504 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T18:56:35.276Z,1617994595.276 [NAL9602](INFO): SBD MO Status=2, MOMSN=1800, MT Status=2, MTMSN=0 2021-04-09T18:56:35.276Z,1617994595.276 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T18:57:04.785Z,1617994624.785 [NAL9602](INFO): SBD MO Status=0, MOMSN=1800, MT Status=0, MTMSN=0 2021-04-09T18:57:04.785Z,1617994624.785 [NAL9602](INFO): No messages in MT queue 2021-04-09T18:57:35.474Z,1617994655.474 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T18:58:00.520Z,1617994680.520 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2021-04-09T18:58:00.521Z,1617994680.521 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2021-04-09T18:58:00.524Z,1617994680.524 [BPC1](INFO): Received data from all battery sticks. 2021-04-09T18:59:58.492Z,1617994798.492 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T18:59:58.493Z,1617994798.493 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+16.3,0000.0,1489.0,000 2021-04-09T19:00:04.971Z,1617994804.971 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:00:04.971Z,1617994804.971 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:00:04.971Z,1617994804.971 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:00:04.972Z,1617994804.972 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:00:05.390Z,1617994805.390 [Default:CheckIn:D] Stopped 2021-04-09T19:00:05.390Z,1617994805.390 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:00:05.774Z,1617994805.774 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.215592 min 2021-04-09T19:00:05.774Z,1617994805.774 [Default:CheckIn:E] Stopped 2021-04-09T19:00:05.775Z,1617994805.775 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:00:05.775Z,1617994805.775 [Default:CheckIn] Stopped 2021-04-09T19:00:05.775Z,1617994805.775 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:00:05.775Z,1617994805.775 [Default:CheckIn](INFO): Running loop #33 2021-04-09T19:00:05.775Z,1617994805.775 [Default:CheckIn] Running Loop=33 2021-04-09T19:00:05.775Z,1617994805.775 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:00:05.775Z,1617994805.775 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:00:07.781Z,1617994807.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185953.00,A,3648.16751,N,12147.28220,W,0.039,50.52,090421,,,A*4F 2021-04-09T19:00:07.784Z,1617994807.784 [NAL9602](INFO): GPS fix at 20210409T185953: (36.802792, -121.788037) 2021-04-09T19:00:07.810Z,1617994807.810 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:00:07.810Z,1617994807.810 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:00:15.528Z,1617994815.528 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20210409T172651/Courier0048.lzma 2021-04-09T19:00:16.531Z,1617994816.531 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0048.lzma.bak 2021-04-09T19:00:16.531Z,1617994816.531 [DataOverHttps](INFO): SBD MOMSN=15556229 2021-04-09T19:00:41.148Z,1617994841.148 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20210409T172651/Express0049.lzma 2021-04-09T19:00:42.151Z,1617994842.151 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0049.lzma.bak 2021-04-09T19:00:42.151Z,1617994842.151 [DataOverHttps](INFO): SBD MOMSN=15556232 2021-04-09T19:00:44.356Z,1617994844.356 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:00:44.356Z,1617994844.356 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:00:44.356Z,1617994844.356 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:01:53.357Z,1617994913.357 [DVL_micro](ERROR): Failed to parse: :SA,-02.34,-06.06,113.1 2021-04-09T19:02:58.009Z,1617994978.009 [NAL9602](INFO): SBD MO Status=2, MOMSN=1801, MT Status=2, MTMSN=0 2021-04-09T19:02:58.009Z,1617994978.009 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:03:46.892Z,1617995026.892 [NAL9602](INFO): SBD MO Status=0, MOMSN=1801, MT Status=0, MTMSN=0 2021-04-09T19:03:46.892Z,1617995026.892 [NAL9602](INFO): No messages in MT queue 2021-04-09T19:04:17.586Z,1617995057.586 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:05:44.921Z,1617995144.921 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:05:44.921Z,1617995144.921 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:05:44.921Z,1617995144.921 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:05:44.922Z,1617995144.922 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:05:45.334Z,1617995145.334 [Default:CheckIn:D] Stopped 2021-04-09T19:05:45.334Z,1617995145.334 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:05:45.782Z,1617995145.782 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.881315 min 2021-04-09T19:05:45.782Z,1617995145.782 [Default:CheckIn:E] Stopped 2021-04-09T19:05:45.783Z,1617995145.783 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:05:45.783Z,1617995145.783 [Default:CheckIn] Stopped 2021-04-09T19:05:45.783Z,1617995145.783 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:05:45.783Z,1617995145.783 [Default:CheckIn](INFO): Running loop #34 2021-04-09T19:05:45.783Z,1617995145.783 [Default:CheckIn] Running Loop=34 2021-04-09T19:05:45.783Z,1617995145.783 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:05:45.783Z,1617995145.783 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:05:47.738Z,1617995147.738 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190533.00,A,3648.16885,N,12147.28307,W,0.428,0.00,090421,,,A*75 2021-04-09T19:05:47.740Z,1617995147.740 [NAL9602](INFO): GPS fix at 20210409T190533: (36.802814, -121.788051) 2021-04-09T19:05:47.751Z,1617995147.751 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:05:47.751Z,1617995147.751 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:05:54.724Z,1617995154.724 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0051.lzma 2021-04-09T19:05:55.727Z,1617995155.727 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0051.lzma.bak 2021-04-09T19:05:55.727Z,1617995155.727 [DataOverHttps](INFO): SBD MOMSN=15556264 2021-04-09T19:06:05.580Z,1617995165.580 [NAL9602](INFO): SBD MO Status=2, MOMSN=1802, MT Status=2, MTMSN=0 2021-04-09T19:06:05.580Z,1617995165.580 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:06:11.592Z,1617995171.592 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20210409T172651/Express0052.lzma 2021-04-09T19:06:12.595Z,1617995172.595 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0052.lzma.bak 2021-04-09T19:06:12.595Z,1617995172.595 [DataOverHttps](INFO): SBD MOMSN=15556267 2021-04-09T19:06:14.484Z,1617995174.484 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:06:14.484Z,1617995174.484 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:06:14.484Z,1617995174.484 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:06:16.269Z,1617995176.269 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T19:06:16.269Z,1617995176.269 [DVL_micro](ERROR): Failed to parse: :TS,000000005.0,+16.4,0000.0,1489.0,000 2021-04-09T19:06:48.980Z,1617995208.980 [NAL9602](INFO): SBD MO Status=0, MOMSN=1802, MT Status=0, MTMSN=0 2021-04-09T19:06:48.980Z,1617995208.980 [NAL9602](INFO): No messages in MT queue 2021-04-09T19:07:19.678Z,1617995239.678 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:08:16.282Z,1617995296.282 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-09T19:08:16.282Z,1617995296.282 [DVL_micro](ERROR): Failed to parse: :BI,-00189,-0216,+00000,I 2021-04-09T19:10:26.453Z,1617995426.453 [DVL_micro](ERROR): DVL uart error: serial timeout 2021-04-09T19:10:26.453Z,1617995426.453 [DVL_micro] Communications Fault, FailCount= 1 2021-04-09T19:10:26.453Z,1617995426.453 [DVL_micro](ERROR): Communications Fault 2021-04-09T19:10:26.453Z,1617995426.453 [DVL_micro](ERROR): Failed to parse: 2021-04-09T19:10:26.574Z,1617995426.574 [CBIT](ERROR): Communications Fault in component: DVL_micro 2021-04-09T19:10:26.849Z,1617995426.849 [DVL_micro](INFO): Powering down 2021-04-09T19:10:27.692Z,1617995427.692 [CBIT](INFO): Clearing failed state for component DVL_micro 2021-04-09T19:10:27.692Z,1617995427.692 [DVL_micro] No Fault, FailCount= 1 2021-04-09T19:11:14.915Z,1617995474.915 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:11:14.915Z,1617995474.915 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:11:14.915Z,1617995474.915 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:11:14.915Z,1617995474.915 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:11:15.306Z,1617995475.306 [Default:CheckIn:D] Stopped 2021-04-09T19:11:15.306Z,1617995475.306 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:11:15.717Z,1617995475.717 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.380859 min 2021-04-09T19:11:15.717Z,1617995475.717 [Default:CheckIn:E] Stopped 2021-04-09T19:11:15.717Z,1617995475.717 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:11:15.717Z,1617995475.717 [Default:CheckIn] Stopped 2021-04-09T19:11:15.718Z,1617995475.718 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:11:15.718Z,1617995475.718 [Default:CheckIn](INFO): Running loop #35 2021-04-09T19:11:15.718Z,1617995475.718 [Default:CheckIn] Running Loop=35 2021-04-09T19:11:15.718Z,1617995475.718 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:11:15.718Z,1617995475.718 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:11:17.725Z,1617995477.725 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191103.00,A,3648.16865,N,12147.28176,W,0.525,0.00,090421,,,A*75 2021-04-09T19:11:17.727Z,1617995477.727 [NAL9602](INFO): GPS fix at 20210409T191103: (36.802811, -121.788029) 2021-04-09T19:11:17.738Z,1617995477.738 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:11:17.738Z,1617995477.738 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:11:21.388Z,1617995481.388 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-09T19:11:21.388Z,1617995481.388 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-04-09T19:11:25.076Z,1617995485.076 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0054.lzma 2021-04-09T19:11:26.079Z,1617995486.079 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0054.lzma.bak 2021-04-09T19:11:26.079Z,1617995486.079 [DataOverHttps](INFO): SBD MOMSN=15556291 2021-04-09T19:11:42.832Z,1617995502.832 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210409T172651/Express0055.lzma 2021-04-09T19:11:43.835Z,1617995503.835 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0055.lzma.bak 2021-04-09T19:11:43.835Z,1617995503.835 [DataOverHttps](INFO): SBD MOMSN=15556294 2021-04-09T19:11:44.820Z,1617995504.820 [NAL9602](INFO): SBD MO Status=2, MOMSN=1803, MT Status=2, MTMSN=0 2021-04-09T19:11:44.820Z,1617995504.820 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:11:46.058Z,1617995506.058 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:11:46.058Z,1617995506.058 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:11:46.058Z,1617995506.058 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:12:12.718Z,1617995532.718 [NAL9602](INFO): SBD MO Status=2, MOMSN=1803, MT Status=2, MTMSN=0 2021-04-09T19:12:12.718Z,1617995532.718 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:12:23.204Z,1617995543.204 [NAL9602](INFO): SBD MO Status=0, MOMSN=1803, MT Status=0, MTMSN=0 2021-04-09T19:12:23.204Z,1617995543.204 [NAL9602](INFO): No messages in MT queue 2021-04-09T19:12:53.907Z,1617995573.907 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:15:46.521Z,1617995746.521 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T19:15:46.521Z,1617995746.521 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+16.7,0000.0,1489:WI,-0015,-00064,+00000,A 2021-04-09T19:16:46.696Z,1617995806.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:16:46.696Z,1617995806.696 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:16:46.696Z,1617995806.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:16:46.696Z,1617995806.696 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:16:47.093Z,1617995807.093 [Default:CheckIn:D] Stopped 2021-04-09T19:16:47.094Z,1617995807.094 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:16:47.490Z,1617995807.490 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.910661 min 2021-04-09T19:16:47.490Z,1617995807.490 [Default:CheckIn:E] Stopped 2021-04-09T19:16:47.490Z,1617995807.490 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:16:47.491Z,1617995807.491 [Default:CheckIn] Stopped 2021-04-09T19:16:47.491Z,1617995807.491 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:16:47.491Z,1617995807.491 [Default:CheckIn](INFO): Running loop #36 2021-04-09T19:16:47.491Z,1617995807.491 [Default:CheckIn] Running Loop=36 2021-04-09T19:16:47.491Z,1617995807.491 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:16:47.491Z,1617995807.491 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:16:49.512Z,1617995809.512 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191635.00,A,3648.16762,N,12147.28133,W,0.039,0.00,090421,,,A*76 2021-04-09T19:16:49.514Z,1617995809.514 [NAL9602](INFO): GPS fix at 20210409T191635: (36.802794, -121.788022) 2021-04-09T19:16:49.525Z,1617995809.525 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:16:49.525Z,1617995809.525 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:16:56.824Z,1617995816.824 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0057.lzma 2021-04-09T19:16:57.827Z,1617995817.827 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0057.lzma.bak 2021-04-09T19:16:57.827Z,1617995817.827 [DataOverHttps](INFO): SBD MOMSN=15556326 2021-04-09T19:17:13.660Z,1617995833.660 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210409T172651/Express0058.lzma 2021-04-09T19:17:14.663Z,1617995834.663 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0058.lzma.bak 2021-04-09T19:17:14.663Z,1617995834.663 [DataOverHttps](INFO): SBD MOMSN=15556329 2021-04-09T19:17:16.588Z,1617995836.588 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:17:16.588Z,1617995836.588 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:17:16.589Z,1617995836.589 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:19:27.924Z,1617995967.924 [NAL9602](INFO): SBD MO Status=2, MOMSN=1804, MT Status=2, MTMSN=0 2021-04-09T19:19:27.924Z,1617995967.924 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:19:35.602Z,1617995975.602 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-04-09T19:19:35.602Z,1617995975.602 [DropWeight] Hardware Fault, FailCount= 1 2021-04-09T19:19:35.602Z,1617995975.602 [DropWeight](ERROR): Hardware Fault 2021-04-09T19:19:35.625Z,1617995975.625 [CommandLine](FAULT): Scheduling is paused 2021-04-09T19:19:35.625Z,1617995975.625 [CBIT](INFO): Critical error at 20210409T191935 2021-04-09T19:19:35.628Z,1617995975.628 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-04-09T19:19:35.628Z,1617995975.628 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-04-09T19:19:36.052Z,1617995976.052 [CBIT](INFO): Critical error at 20210409T191935 2021-04-09T19:19:57.012Z,1617995997.012 [NAL9602](INFO): SBD MO Status=2, MOMSN=1804, MT Status=2, MTMSN=0 2021-04-09T19:19:57.012Z,1617995997.012 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:20:14.391Z,1617996014.391 [DVL_micro](ERROR): Failed to parse: :WI,-0155,+00541,+00000,A 2021-04-09T19:20:39.496Z,1617996039.496 [NAL9602](INFO): SBD MO Status=0, MOMSN=1804, MT Status=0, MTMSN=0 2021-04-09T19:20:39.496Z,1617996039.496 [NAL9602](INFO): No messages in MT queue 2021-04-09T19:21:10.198Z,1617996070.198 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:22:17.266Z,1617996137.266 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:22:17.266Z,1617996137.266 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:22:17.267Z,1617996137.267 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:22:17.267Z,1617996137.267 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:22:17.692Z,1617996137.692 [Default:CheckIn:D] Stopped 2021-04-09T19:22:17.697Z,1617996137.697 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:22:18.081Z,1617996138.081 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.420638 min 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn:E] Stopped 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn] Stopped 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn](INFO): Running loop #37 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn] Running Loop=37 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:22:18.082Z,1617996138.082 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:22:20.092Z,1617996140.092 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192205.00,A,3648.17020,N,12147.28365,W,0.175,135.18,090421,,,A*74 2021-04-09T19:22:20.099Z,1617996140.099 [NAL9602](INFO): GPS fix at 20210409T192205: (36.802837, -121.788061) 2021-04-09T19:22:20.114Z,1617996140.114 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:22:20.114Z,1617996140.114 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:22:31.557Z,1617996151.557 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20210409T172651/Courier0060.lzma 2021-04-09T19:22:32.559Z,1617996152.559 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0060.lzma.bak 2021-04-09T19:22:32.559Z,1617996152.559 [DataOverHttps](INFO): SBD MOMSN=15556346 2021-04-09T19:22:34.308Z,1617996154.308 [NAL9602](INFO): SBD MO Status=0, MOMSN=1805, MT Status=0, MTMSN=0 2021-04-09T19:22:34.308Z,1617996154.308 [NAL9602](INFO): No messages in MT queue 2021-04-09T19:22:49.948Z,1617996169.948 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20210409T172651/Express0061.lzma 2021-04-09T19:22:50.951Z,1617996170.951 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0061.lzma.bak 2021-04-09T19:22:50.951Z,1617996170.951 [DataOverHttps](INFO): SBD MOMSN=15556352 2021-04-09T19:22:52.917Z,1617996172.917 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:22:52.918Z,1617996172.918 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:22:52.918Z,1617996172.918 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:23:05.010Z,1617996185.010 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:27:53.505Z,1617996473.505 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:27:53.505Z,1617996473.505 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:27:53.505Z,1617996473.505 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:27:53.505Z,1617996473.505 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:27:53.922Z,1617996473.922 [Default:CheckIn:D] Stopped 2021-04-09T19:27:53.922Z,1617996473.922 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 209.024463 min 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn:E] Stopped 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn] Stopped 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn](INFO): Running loop #38 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn] Running Loop=38 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:27:54.320Z,1617996474.320 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:27:56.333Z,1617996476.333 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192742.00,A,3648.17045,N,12147.27968,W,0.311,140.09,090421,,,A*7B 2021-04-09T19:27:56.335Z,1617996476.335 [NAL9602](INFO): GPS fix at 20210409T192742: (36.802841, -121.787995) 2021-04-09T19:27:56.366Z,1617996476.366 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:27:56.366Z,1617996476.366 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:28:03.900Z,1617996483.900 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0063.lzma 2021-04-09T19:28:04.903Z,1617996484.903 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0063.lzma.bak 2021-04-09T19:28:04.903Z,1617996484.903 [DataOverHttps](INFO): SBD MOMSN=15556367 2021-04-09T19:28:23.793Z,1617996503.793 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210409T172651/Express0064.lzma 2021-04-09T19:28:24.795Z,1617996504.795 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0064.lzma.bak 2021-04-09T19:28:24.795Z,1617996504.795 [DataOverHttps](INFO): SBD MOMSN=15556370 2021-04-09T19:28:27.580Z,1617996507.580 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:28:27.580Z,1617996507.580 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:28:27.580Z,1617996507.580 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:29:16.896Z,1617996556.896 [NAL9602](INFO): SBD MO Status=2, MOMSN=1806, MT Status=2, MTMSN=0 2021-04-09T19:29:16.896Z,1617996556.896 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:30:10.217Z,1617996610.217 [NAL9602](INFO): SBD MO Status=2, MOMSN=1806, MT Status=2, MTMSN=0 2021-04-09T19:30:10.217Z,1617996610.217 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:30:38.121Z,1617996638.121 [NAL9602](INFO): SBD MO Status=2, MOMSN=1806, MT Status=2, MTMSN=0 2021-04-09T19:30:38.121Z,1617996638.121 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:30:54.684Z,1617996654.684 [NAL9602](INFO): SBD MO Status=2, MOMSN=1806, MT Status=2, MTMSN=0 2021-04-09T19:30:54.684Z,1617996654.684 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:30:55.091Z,1617996655.091 [DVL_micro](ERROR): Failed to parse: :B,+00034,+00631,+00000,I0000000.00,+.00,+000,9999.99,000.00999.99,+99999.99,+9999.99 2021-04-09T19:31:10.449Z,1617996670.449 [NAL9602](INFO): SBD MO Status=2, MOMSN=1806, MT Status=2, MTMSN=0 2021-04-09T19:31:10.449Z,1617996670.449 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:31:37.908Z,1617996697.908 [NAL9602](INFO): SBD MO Status=0, MOMSN=1806, MT Status=0, MTMSN=0 2021-04-09T19:31:37.908Z,1617996697.908 [NAL9602](INFO): No messages in MT queue 2021-04-09T19:32:08.614Z,1617996728.614 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:33:02.436Z,1617996782.436 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T19:33:02.436Z,1617996782.436 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+1.0,1489.0,000 2021-04-09T19:33:28.309Z,1617996808.309 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:33:28.310Z,1617996808.310 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:33:28.310Z,1617996808.310 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:33:28.310Z,1617996808.310 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:33:28.668Z,1617996808.668 [Default:CheckIn:D] Stopped 2021-04-09T19:33:28.668Z,1617996808.668 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:33:29.085Z,1617996809.085 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 214.603548 min 2021-04-09T19:33:29.085Z,1617996809.085 [Default:CheckIn:E] Stopped 2021-04-09T19:33:29.085Z,1617996809.085 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:33:29.085Z,1617996809.085 [Default:CheckIn] Stopped 2021-04-09T19:33:29.085Z,1617996809.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:33:29.085Z,1617996809.085 [Default:CheckIn](INFO): Running loop #39 2021-04-09T19:33:29.085Z,1617996809.085 [Default:CheckIn] Running Loop=39 2021-04-09T19:33:29.086Z,1617996809.086 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:33:29.086Z,1617996809.086 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:33:31.080Z,1617996811.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193316.00,A,3648.17041,N,12147.28534,W,0.292,127.51,090421,,,A*77 2021-04-09T19:33:31.082Z,1617996811.082 [NAL9602](INFO): GPS fix at 20210409T193316: (36.802840, -121.788089) 2021-04-09T19:33:31.093Z,1617996811.093 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:33:31.093Z,1617996811.093 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:33:39.640Z,1617996819.640 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210409T172651/Courier0066.lzma 2021-04-09T19:33:40.648Z,1617996820.648 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0066.lzma.bak 2021-04-09T19:33:40.649Z,1617996820.649 [DataOverHttps](INFO): SBD MOMSN=15556393 2021-04-09T19:33:54.916Z,1617996834.916 [NAL9602](INFO): SBD MO Status=2, MOMSN=1807, MT Status=2, MTMSN=0 2021-04-09T19:33:54.916Z,1617996834.916 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:33:56.484Z,1617996836.484 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20210409T172651/Express0067.lzma 2021-04-09T19:33:57.487Z,1617996837.487 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0067.lzma.bak 2021-04-09T19:33:57.487Z,1617996837.487 [DataOverHttps](INFO): SBD MOMSN=15556397 2021-04-09T19:33:59.805Z,1617996839.805 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:33:59.805Z,1617996839.805 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:33:59.805Z,1617996839.805 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:34:20.780Z,1617996860.780 [NAL9602](INFO): SBD MO Status=2, MOMSN=1807, MT Status=2, MTMSN=0 2021-04-09T19:34:20.780Z,1617996860.780 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:34:35.763Z,1617996875.763 [CBIT](INFO): Clearing failed state for component DropWeight 2021-04-09T19:34:35.763Z,1617996875.763 [DropWeight] No Fault, FailCount= 1 2021-04-09T19:37:51.288Z,1617997071.288 [NAL9602](INFO): SBD MO Status=2, MOMSN=1807, MT Status=2, MTMSN=0 2021-04-09T19:37:51.288Z,1617997071.288 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-04-09T19:38:33.757Z,1617997113.757 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T19:39:00.444Z,1617997140.444 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:39:00.444Z,1617997140.444 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:39:00.444Z,1617997140.444 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:39:00.444Z,1617997140.444 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:39:00.841Z,1617997140.841 [Default:CheckIn:D] Stopped 2021-04-09T19:39:00.842Z,1617997140.842 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:39:01.238Z,1617997141.238 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 220.139779 min 2021-04-09T19:39:01.238Z,1617997141.238 [Default:CheckIn:E] Stopped 2021-04-09T19:39:01.238Z,1617997141.238 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:39:01.239Z,1617997141.239 [Default:CheckIn] Stopped 2021-04-09T19:39:01.239Z,1617997141.239 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:39:01.239Z,1617997141.239 [Default:CheckIn](INFO): Running loop #40 2021-04-09T19:39:01.239Z,1617997141.239 [Default:CheckIn] Running Loop=40 2021-04-09T19:39:01.239Z,1617997141.239 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:39:01.239Z,1617997141.239 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:39:03.252Z,1617997143.252 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193849.00,A,3648.16645,N,12147.28155,W,0.117,130.34,090421,,,A*7D 2021-04-09T19:39:03.254Z,1617997143.254 [NAL9602](INFO): GPS fix at 20210409T193849: (36.802774, -121.788026) 2021-04-09T19:39:03.289Z,1617997143.289 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:39:03.289Z,1617997143.289 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:39:10.976Z,1617997150.976 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210409T172651/Courier0069.lzma 2021-04-09T19:39:11.979Z,1617997151.979 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0069.lzma.bak 2021-04-09T19:39:11.979Z,1617997151.979 [DataOverHttps](INFO): SBD MOMSN=15556407 2021-04-09T19:39:27.788Z,1617997167.788 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210409T172651/Express0070.lzma 2021-04-09T19:39:28.791Z,1617997168.791 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0070.lzma.bak 2021-04-09T19:39:28.791Z,1617997168.791 [DataOverHttps](INFO): SBD MOMSN=15556410 2021-04-09T19:39:30.744Z,1617997170.744 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:39:30.744Z,1617997170.744 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:39:30.744Z,1617997170.744 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:39:35.974Z,1617997175.974 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:39:38.018Z,1617997178.018 [DVL_micro](ERROR): only read 3 of 4 data items 2021-04-09T19:39:38.018Z,1617997178.018 [DVL_micro](ERROR): Failed to parse: :BI,-00356,-01489,+00121,+0:BD,+00000000.00,+00000000.00,+.00,9999.99,000.00 2021-04-09T19:41:43.241Z,1617997303.241 [DVL_micro](ERROR): Failed to parse: :WI,+01510,-01638,+00416,+00000,A 2021-04-09T19:44:05.865Z,1617997445.865 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,0RD,+9999.99,+9999.99,+9999.99,+9999.99 2021-04-09T19:44:31.402Z,1617997471.402 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:44:31.402Z,1617997471.402 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:44:31.402Z,1617997471.402 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:44:31.402Z,1617997471.402 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:44:31.782Z,1617997471.782 [Default:CheckIn:D] Stopped 2021-04-09T19:44:31.782Z,1617997471.782 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:44:32.185Z,1617997472.185 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 225.655452 min 2021-04-09T19:44:32.185Z,1617997472.185 [Default:CheckIn:E] Stopped 2021-04-09T19:44:32.185Z,1617997472.185 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:44:32.185Z,1617997472.185 [Default:CheckIn] Stopped 2021-04-09T19:44:32.186Z,1617997472.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:44:32.186Z,1617997472.186 [Default:CheckIn](INFO): Running loop #41 2021-04-09T19:44:32.186Z,1617997472.186 [Default:CheckIn] Running Loop=41 2021-04-09T19:44:32.186Z,1617997472.186 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:44:32.186Z,1617997472.186 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:44:34.192Z,1617997474.192 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194420.00,A,3648.17126,N,12147.28903,W,0.797,130.34,090421,,,A*7F 2021-04-09T19:44:34.194Z,1617997474.194 [NAL9602](INFO): GPS fix at 20210409T194420: (36.802854, -121.788151) 2021-04-09T19:44:34.210Z,1617997474.210 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:44:34.210Z,1617997474.210 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-04-09T19:44:42.812Z,1617997482.812 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210409T172651/Courier0072.lzma 2021-04-09T19:44:43.815Z,1617997483.815 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Courier0072.lzma.bak 2021-04-09T19:44:43.815Z,1617997483.815 [DataOverHttps](INFO): SBD MOMSN=15556427 2021-04-09T19:44:59.700Z,1617997499.700 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210409T172651/Express0073.lzma 2021-04-09T19:45:00.703Z,1617997500.703 [DataOverHttps](INFO): Moved sent file to Logs/20210409T172651/Express0073.lzma.bak 2021-04-09T19:45:00.703Z,1617997500.703 [DataOverHttps](INFO): SBD MOMSN=15556430 2021-04-09T19:45:02.973Z,1617997502.973 [Default:CheckIn:Read_Iridium] Stopped 2021-04-09T19:45:02.973Z,1617997502.973 [Default:CheckIn:C.Wait] Running Loop=1 2021-04-09T19:45:02.973Z,1617997502.973 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-04-09T19:45:04.977Z,1617997504.977 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-04-09T19:45:05.061Z,1617997505.061 [NAL9602](FAULT): received: +CSQ:0 OK07, 2, 0, 0, 0 OK 2021-04-09T19:45:05.061Z,1617997505.061 [NAL9602] Data Fault, FailCount= 1 2021-04-09T19:45:05.061Z,1617997505.061 [NAL9602](ERROR): Data Fault 2021-04-09T19:45:05.117Z,1617997505.117 [CBIT](ERROR): Data Fault in component: NAL9602 2021-04-09T19:45:05.370Z,1617997505.370 [NAL9602](INFO): Powering down 2021-04-09T19:45:05.774Z,1617997505.774 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2021-04-09T19:45:05.774Z,1617997505.774 [NAL9602] Hardware Fault, FailCount= 1 2021-04-09T19:45:05.775Z,1617997505.775 [NAL9602](ERROR): Hardware Fault 2021-04-09T19:45:06.257Z,1617997506.257 [CBIT](INFO): Clearing failed state for component NAL9602 2021-04-09T19:45:06.257Z,1617997506.257 [NAL9602] No Fault, FailCount= 1 2021-04-09T19:45:35.675Z,1617997535.675 [NAL9602](INFO): Powering up NAL9602 2021-04-09T19:45:46.579Z,1617997546.579 [NAL9602](INFO): NAL9602 initialized 2021-04-09T19:46:17.680Z,1617997577.680 [NAL9602](INFO): Not Powering down - fast GPS 2021-04-09T19:47:27.817Z,1617997647.817 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-04-09T19:47:32.838Z,1617997652.838 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.263443 2021-04-09T19:48:15.599Z,1617997695.599 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005255 2021-04-09T19:50:03.592Z,1617997803.592 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-04-09T19:50:03.592Z,1617997803.592 [Default:CheckIn:C.Wait] Stopped 2021-04-09T19:50:03.592Z,1617997803.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-04-09T19:50:03.593Z,1617997803.593 [Default:CheckIn:D] Running Loop=1 2021-04-09T19:50:03.997Z,1617997803.997 [Default:CheckIn:D] Stopped 2021-04-09T19:50:03.997Z,1617997803.997 [Default:CheckIn:E] Running Loop=1 2021-04-09T19:50:04.407Z,1617997804.407 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 231.192367 min 2021-04-09T19:50:04.407Z,1617997804.407 [Default:CheckIn:E] Stopped 2021-04-09T19:50:04.407Z,1617997804.407 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-04-09T19:50:04.407Z,1617997804.407 [Default:CheckIn] Stopped 2021-04-09T19:50:04.407Z,1617997804.407 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:50:04.407Z,1617997804.407 [Default:CheckIn](INFO): Running loop #42 2021-04-09T19:50:04.407Z,1617997804.407 [Default:CheckIn] Running Loop=42 2021-04-09T19:50:04.408Z,1617997804.408 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-04-09T19:50:04.408Z,1617997804.408 [Default:CheckIn:Read_GPS] Running Loop=1 2021-04-09T19:50:08.424Z,1617997808.424 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-04-09T19:50:58.532Z,1617997858.532 [DVL_micro](ERROR): only read 2 of 4 data items 2021-04-09T19:50:58.532Z,1617997858.532 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999..99,+9999.99 2021-04-09T19:53:13.868Z,1617997993.868 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-04-09T19:53:13.868Z,1617997993.868 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+17.2,0000.0,1489.0,000 2021-04-09T19:53:30.102Z,1617998010.102 [CommandLine](IMPORTANT): got command quit 2021-04-09T19:53:31.110Z,1617998011.110 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:31.110Z,1617998011.110 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:31.293Z,1617998011.293 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-04-09T19:53:31.293Z,1617998011.293 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:31.294Z,1617998011.294 [CommandLine](INFO): Join timeout helper Thread ID is 5946 2021-04-09T19:53:31.295Z,1617998011.295 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-04-09T19:53:31.295Z,1617998011.295 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:31.296Z,1617998011.296 [NavChartDb](INFO): Join timeout helper Thread ID is 5947 2021-04-09T19:53:31.513Z,1617998011.513 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:31.513Z,1617998011.513 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:31.514Z,1617998011.514 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-04-09T19:53:31.514Z,1617998011.514 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:31.514Z,1617998011.514 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5948 2021-04-09T19:53:31.649Z,1617998011.649 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:31.649Z,1617998011.649 [WetLabsBB2FL](INFO): Powering down 2021-04-09T19:53:31.650Z,1617998011.650 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:31.661Z,1617998011.661 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-04-09T19:53:31.661Z,1617998011.661 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:31.661Z,1617998011.661 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5949 2021-04-09T19:53:32.637Z,1617998012.637 [CTD_Seabird](INFO): Powering down 2021-04-09T19:53:32.649Z,1617998012.649 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:32.649Z,1617998012.649 [CTD_Seabird](INFO): Powering down 2021-04-09T19:53:32.661Z,1617998012.661 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:32.673Z,1617998012.673 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-04-09T19:53:32.673Z,1617998012.673 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:32.673Z,1617998012.673 [Radio_Surface](INFO): Join timeout helper Thread ID is 5950 2021-04-09T19:53:32.993Z,1617998012.993 [Radio_Surface](INFO): Powering down 2021-04-09T19:53:32.994Z,1617998012.994 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:32.994Z,1617998012.994 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:33.010Z,1617998013.010 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-04-09T19:53:33.010Z,1617998013.010 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:33.011Z,1617998013.011 [Onboard](INFO): Join timeout helper Thread ID is 5951 2021-04-09T19:53:33.485Z,1617998013.485 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:33.486Z,1617998013.486 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:33.501Z,1617998013.501 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-04-09T19:53:33.502Z,1617998013.502 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:33.502Z,1617998013.502 [DataOverHttps](INFO): Join timeout helper Thread ID is 5952 2021-04-09T19:53:36.066Z,1617998016.066 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:36.088Z,1617998016.088 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.106Z,1617998016.106 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2021-04-09T19:53:36.106Z,1617998016.106 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.106Z,1617998016.106 [BackseatComponent](INFO): Join timeout helper Thread ID is 5953 2021-04-09T19:53:36.193Z,1617998016.193 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:36.193Z,1617998016.193 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.210Z,1617998016.210 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-04-09T19:53:36.210Z,1617998016.210 [logger ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.210Z,1617998016.210 [logger](INFO): Join timeout helper Thread ID is 5954 2021-04-09T19:53:36.225Z,1617998016.225 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:36.225Z,1617998016.225 [logger ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.230Z,1617998016.230 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-04-09T19:53:36.230Z,1617998016.230 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.230Z,1617998016.230 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-04-09T19:53:36.230Z,1617998016.230 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.230Z,1617998016.230 [controlThread](INFO): Join timeout helper Thread ID is 5955 2021-04-09T19:53:36.473Z,1617998016.473 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-04-09T19:53:36.473Z,1617998016.473 [controlThread](DEBUG): Uninitializing ControlThread 2021-04-09T19:53:36.474Z,1617998016.474 [AHRS_M2](INFO): Powering down 2021-04-09T19:53:36.617Z,1617998016.617 [DVL_micro](INFO): Powering down 2021-04-09T19:53:36.618Z,1617998016.618 [NAL9602](INFO): Powering down 2021-04-09T19:53:36.619Z,1617998016.619 [DAT](INFO): Powering down 2021-04-09T19:53:36.738Z,1617998016.738 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-04-09T19:53:36.739Z,1617998016.739 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-04-09T19:53:36.739Z,1617998016.739 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-04-09T19:53:36.740Z,1617998016.740 [MissionManager](INFO): Uninitializing Mission Default 2021-04-09T19:53:36.740Z,1617998016.740 [Default] Stopped 2021-04-09T19:53:36.740Z,1617998016.740 [Default](DEBUG): Aggregate::uninitialize Default 2021-04-09T19:53:36.740Z,1617998016.740 [Default:B.GoToSurface] Stopped 2021-04-09T19:53:36.740Z,1617998016.740 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-04-09T19:53:36.740Z,1617998016.740 [Default:CheckIn] Stopped 2021-04-09T19:53:36.740Z,1617998016.740 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-04-09T19:53:36.740Z,1617998016.740 [Default:CheckIn:Read_GPS] Stopped 2021-04-09T19:53:36.743Z,1617998016.743 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-04-09T19:53:36.744Z,1617998016.744 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-04-09T19:53:36.744Z,1617998016.744 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-04-09T19:53:36.744Z,1617998016.744 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-04-09T19:53:36.744Z,1617998016.744 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-04-09T19:53:36.745Z,1617998016.745 [BuoyancyServo](INFO): Powering down 2021-04-09T19:53:36.757Z,1617998016.757 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-04-09T19:53:36.757Z,1617998016.757 [ElevatorServo](INFO): Powering down 2021-04-09T19:53:36.758Z,1617998016.758 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-04-09T19:53:36.758Z,1617998016.758 [MassServo](INFO): Powering down 2021-04-09T19:53:36.759Z,1617998016.759 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-04-09T19:53:36.759Z,1617998016.759 [RudderServo](INFO): Powering down 2021-04-09T19:53:36.759Z,1617998016.759 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-04-09T19:53:36.760Z,1617998016.760 [ThrusterServo](INFO): Powering down 2021-04-09T19:53:36.760Z,1617998016.760 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-04-09T19:53:36.761Z,1617998016.761 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-04-09T19:53:36.761Z,1617998016.761 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-04-09T19:53:36.761Z,1617998016.761 [CBIT](DEBUG): Powering off loads. 2021-04-09T19:53:36.773Z,1617998016.773 [CBIT](DEBUG): Disabling WDT. 2021-04-09T19:53:36.785Z,1617998016.785 [CBIT](DEBUG): Opening all GF detection circuits. 2021-04-09T19:53:36.786Z,1617998016.786 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.831Z,1617998016.831 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.833Z,1617998016.833 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.841Z,1617998016.841 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.885Z,1617998016.885 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.946Z,1617998016.946 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.951Z,1617998016.951 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:36.973Z,1617998016.973 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-04-09T19:53:37.050Z,1617998017.050 [logger ThreadHandler](INFO): Thread cancelled.