2022-08-09T17:25:53.860Z,1660065953.860 [DataOverHttps](INFO): Received command: restart logs 2022-08-09T17:25:53.861Z,1660065953.861 [CommandExec](IMPORTANT): got command restart logs 2022-08-09T17:26:05.291Z,1660065965.291 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220808T174346/Express0121.lzma 2022-08-09T17:26:06.294Z,1660065966.294 [DataOverHttps](INFO): Moved sent file to Logs/20220808T174346/Express0121.lzma.bak 2022-08-09T17:26:06.294Z,1660065966.294 [DataOverHttps](INFO): SBD MOMSN=17097343 2022-08-09T17:26:06.465Z,1660065966.465 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T17:26:06.466Z,1660065966.466 [DVL_micro](ERROR): Failed to parse: :BI,+0496,+01576,+00000,I 2022-08-09T17:26:08.896Z,1660065968.896 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T17:26:24.231Z,1660065984.231 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220808T174346/Courier0123.lzma 2022-08-09T17:26:25.234Z,1660065985.234 [DataOverHttps](INFO): Moved sent file to Logs/20220808T174346/Courier0123.lzma.bak 2022-08-09T17:26:25.234Z,1660065985.234 [DataOverHttps](INFO): SBD MOMSN=17097346 2022-08-09T17:26:43.311Z,1660066003.311 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20220808T174346/Express0124.lzma 2022-08-09T17:26:44.314Z,1660066004.314 [DataOverHttps](INFO): Moved sent file to Logs/20220808T174346/Express0124.lzma.bak 2022-08-09T17:26:44.314Z,1660066004.314 [DataOverHttps](INFO): SBD MOMSN=17097348 2022-08-09T17:26:49.329Z,1660066009.329 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T17:26:49.330Z,1660066009.330 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T17:26:49.330Z,1660066009.330 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T17:29:01.396Z,1660066141.396 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T17:29:01.396Z,1660066141.396 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+23.01489.0,000 2022-08-09T17:30:32.036Z,1660066232.036 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.559261 2022-08-09T17:30:42.530Z,1660066242.530 [DataOverHttps](IMPORTANT): SBD MTMSN=20220809T173046 2022-08-09T17:30:42.533Z,1660066242.533 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003265 2022-08-09T17:30:49.987Z,1660066249.987 [DataOverHttps](INFO): Received command: strobe off 2022-08-09T17:30:50.037Z,1660066250.037 [CommandExec](IMPORTANT): got command strobe off 2022-08-09T17:30:50.037Z,1660066250.037 [CommandExec](IMPORTANT): Deactivating strobe 2022-08-09T17:31:49.871Z,1660066309.871 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T17:31:49.871Z,1660066309.871 [Default:CheckIn:C.Wait] Stopped 2022-08-09T17:31:49.871Z,1660066309.871 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T17:31:49.871Z,1660066309.871 [Default:CheckIn:D] Running Loop=1 2022-08-09T17:31:50.276Z,1660066310.276 [Default:CheckIn:D] Stopped 2022-08-09T17:31:50.277Z,1660066310.277 [Default:CheckIn:E] Running Loop=1 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.087398 min 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn:E] Stopped 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn] Stopped 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn](INFO): Running loop #6 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn] Running Loop=6 2022-08-09T17:31:50.689Z,1660066310.689 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T17:31:50.690Z,1660066310.690 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T17:31:52.690Z,1660066312.690 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173156.00,A,4356.72429,N,08629.27473,W,10.808,64.95,090822,,,A*7B 2022-08-09T17:31:52.692Z,1660066312.692 [NAL9602](INFO): GPS fix at 20220809T173156: (43.945405, -86.487912) 2022-08-09T17:31:52.703Z,1660066312.703 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T17:31:52.703Z,1660066312.703 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T17:31:56.369Z,1660066316.369 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T17:31:56.369Z,1660066316.369 [DVL_micro](ERROR): Failed to parse: :BI,-0125,+00607,+00000,I 2022-08-09T17:32:01.528Z,1660066321.528 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20220809T172553/Courier0003.lzma 2022-08-09T17:32:02.530Z,1660066322.530 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0003.lzma.bak 2022-08-09T17:32:02.530Z,1660066322.530 [DataOverHttps](INFO): SBD MOMSN=17097354 2022-08-09T17:32:14.917Z,1660066334.917 [NAL9602](INFO): SBD MO Status=2, MOMSN=10134, MT Status=2, MTMSN=0 2022-08-09T17:32:14.917Z,1660066334.917 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T17:32:20.640Z,1660066340.640 [DataOverHttps](INFO): Sending 475 bytes from file Logs/20220809T172553/Express0004.lzma 2022-08-09T17:32:21.641Z,1660066341.641 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0004.lzma.bak 2022-08-09T17:32:21.642Z,1660066341.642 [DataOverHttps](INFO): SBD MOMSN=17097358 2022-08-09T17:32:40.767Z,1660066360.767 [NAL9602](INFO): SBD MO Status=2, MOMSN=10134, MT Status=2, MTMSN=0 2022-08-09T17:32:40.767Z,1660066360.767 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T17:32:44.431Z,1660066364.431 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20220809T172553/Express0007.lzma 2022-08-09T17:32:45.434Z,1660066365.434 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0007.lzma.bak 2022-08-09T17:32:45.434Z,1660066365.434 [DataOverHttps](INFO): SBD MOMSN=17097365 2022-08-09T17:32:48.889Z,1660066368.889 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T17:32:48.889Z,1660066368.889 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T17:32:48.889Z,1660066368.889 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T17:33:25.221Z,1660066405.221 [NAL9602](INFO): SBD MO Status=2, MOMSN=10134, MT Status=2, MTMSN=0 2022-08-09T17:33:25.221Z,1660066405.221 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T17:33:34.902Z,1660066414.902 [NAL9602](INFO): SBD MO Status=0, MOMSN=10134, MT Status=0, MTMSN=0 2022-08-09T17:33:34.902Z,1660066414.902 [NAL9602](INFO): No messages in MT queue 2022-08-09T17:34:05.609Z,1660066445.609 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T17:37:49.445Z,1660066669.445 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T17:37:49.445Z,1660066669.445 [Default:CheckIn:C.Wait] Stopped 2022-08-09T17:37:49.445Z,1660066669.445 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T17:37:49.445Z,1660066669.445 [Default:CheckIn:D] Running Loop=1 2022-08-09T17:37:49.850Z,1660066669.850 [Default:CheckIn:D] Stopped 2022-08-09T17:37:49.850Z,1660066669.850 [Default:CheckIn:E] Running Loop=1 2022-08-09T17:37:50.244Z,1660066670.244 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.080286 min 2022-08-09T17:37:50.244Z,1660066670.244 [Default:CheckIn:E] Stopped 2022-08-09T17:37:50.244Z,1660066670.244 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T17:37:50.244Z,1660066670.244 [Default:CheckIn] Stopped 2022-08-09T17:37:50.244Z,1660066670.244 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T17:37:50.245Z,1660066670.245 [Default:CheckIn](INFO): Running loop #7 2022-08-09T17:37:50.245Z,1660066670.245 [Default:CheckIn] Running Loop=7 2022-08-09T17:37:50.245Z,1660066670.245 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T17:37:50.245Z,1660066670.245 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T17:37:52.250Z,1660066672.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173756.00,A,4357.18598,N,08627.90795,W,7.542,92.13,090822,,,A*40 2022-08-09T17:37:52.253Z,1660066672.253 [NAL9602](INFO): GPS fix at 20220809T173756: (43.953100, -86.465132) 2022-08-09T17:37:52.263Z,1660066672.263 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T17:37:52.263Z,1660066672.263 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T17:38:01.035Z,1660066681.035 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0009.lzma 2022-08-09T17:38:02.037Z,1660066682.037 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0009.lzma.bak 2022-08-09T17:38:02.038Z,1660066682.038 [DataOverHttps](INFO): SBD MOMSN=17097368 2022-08-09T17:38:08.015Z,1660066688.015 [NAL9602](INFO): SBD MO Status=0, MOMSN=10135, MT Status=0, MTMSN=0 2022-08-09T17:38:08.015Z,1660066688.015 [NAL9602](INFO): No messages in MT queue 2022-08-09T17:38:21.903Z,1660066701.903 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220809T172553/Express0010.lzma 2022-08-09T17:38:22.906Z,1660066702.906 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0010.lzma.bak 2022-08-09T17:38:22.906Z,1660066702.906 [DataOverHttps](INFO): SBD MOMSN=17097371 2022-08-09T17:38:26.639Z,1660066706.639 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T17:38:26.676Z,1660066706.676 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T17:38:26.676Z,1660066706.676 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T17:38:38.710Z,1660066718.710 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T17:39:05.801Z,1660066745.801 [DVL_micro](ERROR): only read 2 of 4 data items 2022-08-09T17:39:05.801Z,1660066745.801 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,,+9999.99 2022-08-09T17:39:13.515Z,1660066753.515 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T17:39:13.515Z,1660066753.515 [DVL_micro](ERROR): Failed to parse: :BI,-01445,-0305,+00000,I 2022-08-09T17:40:31.834Z,1660066831.834 [DVL_micro](ERROR): only read 1 of 4 data items 2022-08-09T17:40:31.834Z,1660066831.834 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,++9999.99,+ 2022-08-09T17:43:21.946Z,1660067001.946 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T17:43:21.947Z,1660067001.947 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,14 2022-08-09T17:43:27.206Z,1660067007.206 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T17:43:27.206Z,1660067007.206 [Default:CheckIn:C.Wait] Stopped 2022-08-09T17:43:27.206Z,1660067007.206 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T17:43:27.207Z,1660067007.207 [Default:CheckIn:D] Running Loop=1 2022-08-09T17:43:27.583Z,1660067007.583 [Default:CheckIn:D] Stopped 2022-08-09T17:43:27.584Z,1660067007.584 [Default:CheckIn:E] Running Loop=1 2022-08-09T17:43:27.992Z,1660067007.992 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.709180 min 2022-08-09T17:43:27.992Z,1660067007.992 [Default:CheckIn:E] Stopped 2022-08-09T17:43:27.992Z,1660067007.992 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T17:43:27.992Z,1660067007.992 [Default:CheckIn] Stopped 2022-08-09T17:43:27.992Z,1660067007.992 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T17:43:27.992Z,1660067007.992 [Default:CheckIn](INFO): Running loop #8 2022-08-09T17:43:27.992Z,1660067007.992 [Default:CheckIn] Running Loop=8 2022-08-09T17:43:27.993Z,1660067007.993 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T17:43:27.993Z,1660067007.993 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T17:43:29.994Z,1660067009.994 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174333.00,A,4357.27278,N,08627.71447,W,0.136,97.54,090822,,,D*45 2022-08-09T17:43:29.996Z,1660067009.996 [NAL9602](INFO): GPS fix at 20220809T174333: (43.954546, -86.461908) 2022-08-09T17:43:30.007Z,1660067010.007 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T17:43:30.007Z,1660067010.007 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T17:43:38.363Z,1660067018.363 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0012.lzma 2022-08-09T17:43:39.366Z,1660067019.366 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0012.lzma.bak 2022-08-09T17:43:39.366Z,1660067019.366 [DataOverHttps](INFO): SBD MOMSN=17097375 2022-08-09T17:43:46.559Z,1660067026.559 [NAL9602](INFO): SBD MO Status=0, MOMSN=10136, MT Status=0, MTMSN=0 2022-08-09T17:43:46.559Z,1660067026.559 [NAL9602](INFO): No messages in MT queue 2022-08-09T17:43:58.371Z,1660067038.371 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220809T172553/Express0013.lzma 2022-08-09T17:43:59.374Z,1660067039.374 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0013.lzma.bak 2022-08-09T17:43:59.374Z,1660067039.374 [DataOverHttps](INFO): SBD MOMSN=17097378 2022-08-09T17:44:02.773Z,1660067042.773 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T17:44:02.774Z,1660067042.774 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T17:44:02.774Z,1660067042.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T17:44:17.261Z,1660067057.261 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T17:49:03.335Z,1660067343.335 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T17:49:03.335Z,1660067343.335 [Default:CheckIn:C.Wait] Stopped 2022-08-09T17:49:03.335Z,1660067343.335 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T17:49:03.335Z,1660067343.335 [Default:CheckIn:D] Running Loop=1 2022-08-09T17:49:03.745Z,1660067343.745 [Default:CheckIn:D] Stopped 2022-08-09T17:49:03.745Z,1660067343.745 [Default:CheckIn:E] Running Loop=1 2022-08-09T17:49:04.138Z,1660067344.138 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.311877 min 2022-08-09T17:49:04.138Z,1660067344.138 [Default:CheckIn:E] Stopped 2022-08-09T17:49:04.138Z,1660067344.138 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T17:49:04.138Z,1660067344.138 [Default:CheckIn] Stopped 2022-08-09T17:49:04.138Z,1660067344.138 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T17:49:04.139Z,1660067344.139 [Default:CheckIn](INFO): Running loop #9 2022-08-09T17:49:04.139Z,1660067344.139 [Default:CheckIn] Running Loop=9 2022-08-09T17:49:04.139Z,1660067344.139 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T17:49:04.139Z,1660067344.139 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T17:49:06.155Z,1660067346.155 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174909.00,A,4357.27368,N,08627.71500,W,0.078,15.05,090822,,,D*41 2022-08-09T17:49:06.158Z,1660067346.158 [NAL9602](INFO): GPS fix at 20220809T174909: (43.954561, -86.461917) 2022-08-09T17:49:06.168Z,1660067346.168 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T17:49:06.168Z,1660067346.168 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T17:49:14.851Z,1660067354.851 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0015.lzma 2022-08-09T17:49:15.856Z,1660067355.856 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0015.lzma.bak 2022-08-09T17:49:15.856Z,1660067355.856 [DataOverHttps](INFO): SBD MOMSN=17097382 2022-08-09T17:49:21.915Z,1660067361.915 [NAL9602](INFO): SBD MO Status=0, MOMSN=10137, MT Status=0, MTMSN=0 2022-08-09T17:49:21.915Z,1660067361.915 [NAL9602](INFO): No messages in MT queue 2022-08-09T17:49:35.571Z,1660067375.571 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220809T172553/Express0016.lzma 2022-08-09T17:49:36.574Z,1660067376.574 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0016.lzma.bak 2022-08-09T17:49:36.574Z,1660067376.574 [DataOverHttps](INFO): SBD MOMSN=17097385 2022-08-09T17:49:40.113Z,1660067380.113 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T17:49:40.113Z,1660067380.113 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T17:49:40.113Z,1660067380.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T17:49:52.610Z,1660067392.610 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T17:53:08.968Z,1660067588.968 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+ 2022-08-09T17:53:13.807Z,1660067593.807 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T17:53:13.807Z,1660067593.807 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2022-08-09T17:54:40.675Z,1660067680.675 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T17:54:40.675Z,1660067680.675 [Default:CheckIn:C.Wait] Stopped 2022-08-09T17:54:40.675Z,1660067680.675 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T17:54:40.675Z,1660067680.675 [Default:CheckIn:D] Running Loop=1 2022-08-09T17:54:41.085Z,1660067681.085 [Default:CheckIn:D] Stopped 2022-08-09T17:54:41.085Z,1660067681.085 [Default:CheckIn:E] Running Loop=1 2022-08-09T17:54:41.496Z,1660067681.496 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.934212 min 2022-08-09T17:54:41.496Z,1660067681.496 [Default:CheckIn:E] Stopped 2022-08-09T17:54:41.496Z,1660067681.496 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T17:54:41.496Z,1660067681.496 [Default:CheckIn] Stopped 2022-08-09T17:54:41.496Z,1660067681.496 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T17:54:41.496Z,1660067681.496 [Default:CheckIn](INFO): Running loop #10 2022-08-09T17:54:41.496Z,1660067681.496 [Default:CheckIn] Running Loop=10 2022-08-09T17:54:41.497Z,1660067681.497 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T17:54:41.497Z,1660067681.497 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T17:54:43.494Z,1660067683.494 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175447.00,A,4357.27344,N,08627.71289,W,0.058,15.05,090822,,,D*4D 2022-08-09T17:54:43.497Z,1660067683.497 [NAL9602](INFO): GPS fix at 20220809T175447: (43.954557, -86.461882) 2022-08-09T17:54:43.528Z,1660067683.528 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T17:54:43.532Z,1660067683.532 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T17:54:51.800Z,1660067691.800 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0018.lzma 2022-08-09T17:54:52.802Z,1660067692.802 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0018.lzma.bak 2022-08-09T17:54:52.802Z,1660067692.802 [DataOverHttps](INFO): SBD MOMSN=17097389 2022-08-09T17:54:53.999Z,1660067693.999 [NAL9602](INFO): SBD MO Status=0, MOMSN=10138, MT Status=0, MTMSN=0 2022-08-09T17:54:53.999Z,1660067693.999 [NAL9602](INFO): No messages in MT queue 2022-08-09T17:55:10.931Z,1660067710.931 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220809T172553/Express0019.lzma 2022-08-09T17:55:11.934Z,1660067711.934 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0019.lzma.bak 2022-08-09T17:55:11.934Z,1660067711.934 [DataOverHttps](INFO): SBD MOMSN=17097392 2022-08-09T17:55:15.437Z,1660067715.437 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T17:55:15.437Z,1660067715.437 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T17:55:15.437Z,1660067715.437 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T17:55:24.725Z,1660067724.725 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:00:15.999Z,1660068015.999 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:00:15.999Z,1660068015.999 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:00:15.999Z,1660068015.999 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:00:16.024Z,1660068016.024 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:00:16.432Z,1660068016.432 [Default:CheckIn:D] Stopped 2022-08-09T18:00:16.432Z,1660068016.432 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:00:16.813Z,1660068016.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.522982 min 2022-08-09T18:00:16.813Z,1660068016.813 [Default:CheckIn:E] Stopped 2022-08-09T18:00:16.813Z,1660068016.813 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:00:16.814Z,1660068016.814 [Default:CheckIn] Stopped 2022-08-09T18:00:16.814Z,1660068016.814 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:00:16.814Z,1660068016.814 [Default:CheckIn](INFO): Running loop #11 2022-08-09T18:00:16.814Z,1660068016.814 [Default:CheckIn] Running Loop=11 2022-08-09T18:00:16.814Z,1660068016.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:00:16.814Z,1660068016.814 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:00:18.816Z,1660068018.816 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180022.00,A,4357.27317,N,08627.71257,W,0.039,15.05,090822,,,D*42 2022-08-09T18:00:18.818Z,1660068018.818 [NAL9602](INFO): GPS fix at 20220809T180022: (43.954553, -86.461876) 2022-08-09T18:00:18.829Z,1660068018.829 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:00:18.829Z,1660068018.829 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:00:27.195Z,1660068027.195 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0021.lzma 2022-08-09T18:00:28.197Z,1660068028.197 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0021.lzma.bak 2022-08-09T18:00:28.198Z,1660068028.198 [DataOverHttps](INFO): SBD MOMSN=17097396 2022-08-09T18:00:42.247Z,1660068042.247 [NAL9602](INFO): SBD MO Status=2, MOMSN=10139, MT Status=2, MTMSN=0 2022-08-09T18:00:42.247Z,1660068042.247 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T18:00:46.303Z,1660068046.303 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20220809T172553/Express0022.lzma 2022-08-09T18:00:47.305Z,1660068047.305 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0022.lzma.bak 2022-08-09T18:00:47.306Z,1660068047.306 [DataOverHttps](INFO): SBD MOMSN=17097399 2022-08-09T18:00:50.760Z,1660068050.760 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:00:50.760Z,1660068050.760 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:00:50.760Z,1660068050.760 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:00:53.964Z,1660068053.964 [DVL_micro](ERROR): Failed to parse: :WI,+01891,-00172,-00188,+00000,A 2022-08-09T18:01:16.990Z,1660068076.990 [NAL9602](INFO): SBD MO Status=0, MOMSN=10139, MT Status=0, MTMSN=0 2022-08-09T18:01:16.991Z,1660068076.991 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:01:47.717Z,1660068107.717 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:02:20.891Z,1660068140.891 [CBIT](IMPORTANT): Beginning ground fault scan 2022-08-09T18:02:31.778Z,1660068151.778 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002073 CHAN A1 (24V): 0.001563 CHAN A2 (12V): 0.001353 CHAN A3 (5V): 0.000448 CHAN B0 (3.3V): 0.000416 CHAN B1 (3.15aV): 0.000272 CHAN B2 (3.15bV): -0.000034 CHAN B3 (GND): 0.000152 OPEN: 0.004968 Full Scale: +/- 1 mA 2022-08-09T18:02:45.488Z,1660068165.488 [DVL_micro](ERROR): Failed to parse: :WI,+02332-00322,+00000,A 2022-08-09T18:05:30.729Z,1660068330.729 [DVL_micro](ERROR): Failed to parse: :B,-04633,+00472,+00000,I 2022-08-09T18:05:51.358Z,1660068351.358 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:05:51.358Z,1660068351.358 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:05:51.358Z,1660068351.358 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:05:51.358Z,1660068351.358 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:05:51.767Z,1660068351.767 [Default:CheckIn:D] Stopped 2022-08-09T18:05:51.767Z,1660068351.767 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:05:52.158Z,1660068352.158 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.112231 min 2022-08-09T18:05:52.158Z,1660068352.158 [Default:CheckIn:E] Stopped 2022-08-09T18:05:52.158Z,1660068352.158 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:05:52.158Z,1660068352.158 [Default:CheckIn] Stopped 2022-08-09T18:05:52.158Z,1660068352.158 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:05:52.158Z,1660068352.158 [Default:CheckIn](INFO): Running loop #12 2022-08-09T18:05:52.158Z,1660068352.158 [Default:CheckIn] Running Loop=12 2022-08-09T18:05:52.159Z,1660068352.159 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:05:52.159Z,1660068352.159 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:05:54.155Z,1660068354.155 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180557.00,A,4357.27398,N,08627.71245,W,0.039,18.00,090822,,,D*49 2022-08-09T18:05:54.157Z,1660068354.157 [NAL9602](INFO): GPS fix at 20220809T180557: (43.954566, -86.461874) 2022-08-09T18:05:54.172Z,1660068354.172 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:05:54.172Z,1660068354.172 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:06:02.767Z,1660068362.767 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0024.lzma 2022-08-09T18:06:03.770Z,1660068363.770 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0024.lzma.bak 2022-08-09T18:06:03.770Z,1660068363.770 [DataOverHttps](INFO): SBD MOMSN=17097406 2022-08-09T18:06:23.647Z,1660068383.647 [NAL9602](INFO): SBD MO Status=0, MOMSN=10140, MT Status=0, MTMSN=0 2022-08-09T18:06:23.647Z,1660068383.647 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:06:23.756Z,1660068383.756 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20220809T172553/Express0025.lzma 2022-08-09T18:06:24.758Z,1660068384.758 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0025.lzma.bak 2022-08-09T18:06:24.758Z,1660068384.758 [DataOverHttps](INFO): SBD MOMSN=17097409 2022-08-09T18:06:28.139Z,1660068388.139 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:06:28.144Z,1660068388.144 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:06:28.144Z,1660068388.144 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:06:54.353Z,1660068414.353 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:11:03.637Z,1660068663.637 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+22.8,0000.0,1489.0,000 2022-08-09T18:11:28.694Z,1660068688.694 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:11:28.694Z,1660068688.694 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:11:28.694Z,1660068688.694 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:11:28.694Z,1660068688.694 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:11:29.109Z,1660068689.109 [Default:CheckIn:D] Stopped 2022-08-09T18:11:29.109Z,1660068689.109 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:11:29.515Z,1660068689.515 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.734603 min 2022-08-09T18:11:29.515Z,1660068689.515 [Default:CheckIn:E] Stopped 2022-08-09T18:11:29.515Z,1660068689.515 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:11:29.515Z,1660068689.515 [Default:CheckIn] Stopped 2022-08-09T18:11:29.515Z,1660068689.515 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:11:29.520Z,1660068689.520 [Default:CheckIn](INFO): Running loop #13 2022-08-09T18:11:29.520Z,1660068689.520 [Default:CheckIn] Running Loop=13 2022-08-09T18:11:29.520Z,1660068689.520 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:11:29.520Z,1660068689.520 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:11:31.523Z,1660068691.523 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181135.00,A,4357.27286,N,08627.67159,W,0.039,144.82,090822,,,D*7D 2022-08-09T18:11:31.526Z,1660068691.526 [NAL9602](INFO): GPS fix at 20220809T181135: (43.954548, -86.461193) 2022-08-09T18:11:31.572Z,1660068691.572 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:11:31.572Z,1660068691.572 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:11:40.151Z,1660068700.151 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0027.lzma 2022-08-09T18:11:41.154Z,1660068701.154 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0027.lzma.bak 2022-08-09T18:11:41.154Z,1660068701.154 [DataOverHttps](INFO): SBD MOMSN=17097417 2022-08-09T18:11:48.887Z,1660068708.887 [NAL9602](INFO): SBD MO Status=0, MOMSN=10141, MT Status=0, MTMSN=0 2022-08-09T18:11:48.887Z,1660068708.887 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:11:59.323Z,1660068719.323 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220809T172553/Express0028.lzma 2022-08-09T18:12:00.326Z,1660068720.326 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0028.lzma.bak 2022-08-09T18:12:00.326Z,1660068720.326 [DataOverHttps](INFO): SBD MOMSN=17097420 2022-08-09T18:12:03.851Z,1660068723.851 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:12:03.875Z,1660068723.875 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:12:03.875Z,1660068723.875 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:12:19.607Z,1660068739.607 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:13:48.510Z,1660068828.510 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T18:13:48.510Z,1660068828.510 [DVL_micro](ERROR): Failed to parse: :TS,000000000.0,+22.9,0000.0,1489.0,000 2022-08-09T18:13:50.501Z,1660068830.501 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-09T18:13:58.970Z,1660068838.970 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:07.051Z,1660068847.051 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:12.708Z,1660068852.708 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:21.594Z,1660068861.594 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:21.599Z,1660068861.599 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2022-08-09T18:14:26.442Z,1660068866.442 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:36.946Z,1660068876.946 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:40.178Z,1660068880.178 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:51.898Z,1660068891.898 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:14:54.318Z,1660068894.318 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:06.842Z,1660068906.842 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:08.069Z,1660068908.069 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:22.194Z,1660068922.194 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:22.200Z,1660068922.200 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:35.931Z,1660068935.931 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:37.148Z,1660068937.148 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:50.071Z,1660068950.071 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:15:51.686Z,1660068951.686 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:16:03.806Z,1660068963.806 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:16:07.040Z,1660068967.040 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:16:17.946Z,1660068977.946 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:17:04.464Z,1660069024.464 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:17:04.464Z,1660069024.464 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:17:04.464Z,1660069024.464 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:17:04.464Z,1660069024.464 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:17:04.840Z,1660069024.840 [Default:CheckIn:D] Stopped 2022-08-09T18:17:04.840Z,1660069024.840 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:17:05.241Z,1660069025.241 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.330054 min 2022-08-09T18:17:05.241Z,1660069025.241 [Default:CheckIn:E] Stopped 2022-08-09T18:17:05.241Z,1660069025.241 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:17:05.241Z,1660069025.241 [Default:CheckIn] Stopped 2022-08-09T18:17:05.242Z,1660069025.242 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:17:05.242Z,1660069025.242 [Default:CheckIn](INFO): Running loop #14 2022-08-09T18:17:05.242Z,1660069025.242 [Default:CheckIn] Running Loop=14 2022-08-09T18:17:05.242Z,1660069025.242 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:17:05.242Z,1660069025.242 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:17:07.238Z,1660069027.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181711.00,A,4357.27165,N,08627.67033,W,0.039,144.82,090822,,,D*7E 2022-08-09T18:17:07.240Z,1660069027.240 [NAL9602](INFO): GPS fix at 20220809T181711: (43.954527, -86.461172) 2022-08-09T18:17:07.250Z,1660069027.250 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:17:07.251Z,1660069027.251 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:17:17.263Z,1660069037.263 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0030.lzma 2022-08-09T18:17:18.266Z,1660069038.266 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0030.lzma.bak 2022-08-09T18:17:18.266Z,1660069038.266 [DataOverHttps](INFO): SBD MOMSN=17097424 2022-08-09T18:17:36.783Z,1660069056.783 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220809T172553/Express0031.lzma 2022-08-09T18:17:37.786Z,1660069057.786 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0031.lzma.bak 2022-08-09T18:17:37.786Z,1660069057.786 [DataOverHttps](INFO): SBD MOMSN=17097427 2022-08-09T18:17:41.193Z,1660069061.193 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:17:41.193Z,1660069061.193 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:17:41.193Z,1660069061.193 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:17:45.231Z,1660069065.231 [NAL9602](INFO): SBD MO Status=0, MOMSN=10142, MT Status=0, MTMSN=0 2022-08-09T18:17:45.231Z,1660069065.231 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:18:15.917Z,1660069095.917 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:18:45.813Z,1660069125.813 [BPC1](ERROR): BPC1A: No match for serial number 3F63 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file). 2022-08-09T18:22:09.028Z,1660069329.028 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 321 2022-08-09T18:22:09.030Z,1660069329.030 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2022-08-09T18:22:41.763Z,1660069361.763 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:22:41.763Z,1660069361.763 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:22:41.763Z,1660069361.763 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:22:41.764Z,1660069361.764 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:22:42.173Z,1660069362.173 [Default:CheckIn:D] Stopped 2022-08-09T18:22:42.173Z,1660069362.173 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:22:42.577Z,1660069362.577 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.952336 min 2022-08-09T18:22:42.577Z,1660069362.577 [Default:CheckIn:E] Stopped 2022-08-09T18:22:42.577Z,1660069362.577 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:22:42.577Z,1660069362.577 [Default:CheckIn] Stopped 2022-08-09T18:22:42.578Z,1660069362.578 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:22:42.578Z,1660069362.578 [Default:CheckIn](INFO): Running loop #15 2022-08-09T18:22:42.578Z,1660069362.578 [Default:CheckIn] Running Loop=15 2022-08-09T18:22:42.578Z,1660069362.578 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:22:42.578Z,1660069362.578 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:22:44.588Z,1660069364.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182248.00,A,4357.27388,N,08627.66856,W,0.019,144.82,090822,,,D*7D 2022-08-09T18:22:44.590Z,1660069364.590 [NAL9602](INFO): GPS fix at 20220809T182248: (43.954565, -86.461143) 2022-08-09T18:22:44.634Z,1660069364.634 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:22:44.634Z,1660069364.634 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:22:52.975Z,1660069372.975 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0033.lzma 2022-08-09T18:22:53.980Z,1660069373.980 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0033.lzma.bak 2022-08-09T18:22:53.981Z,1660069373.981 [DataOverHttps](INFO): SBD MOMSN=17097431 2022-08-09T18:23:01.951Z,1660069381.951 [NAL9602](INFO): SBD MO Status=0, MOMSN=10143, MT Status=0, MTMSN=0 2022-08-09T18:23:01.951Z,1660069381.951 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:23:13.723Z,1660069393.723 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220809T172553/Express0034.lzma 2022-08-09T18:23:15.307Z,1660069395.307 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T18:23:15.307Z,1660069395.307 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+22.9,0000.0,1489.0,000 2022-08-09T18:23:15.332Z,1660069395.332 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0034.lzma.bak 2022-08-09T18:23:15.333Z,1660069395.333 [DataOverHttps](INFO): SBD MOMSN=17097434 2022-08-09T18:23:18.146Z,1660069398.146 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:23:18.147Z,1660069398.147 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:23:18.147Z,1660069398.147 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:23:32.653Z,1660069412.653 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:23:46.387Z,1660069426.387 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:23:56.890Z,1660069436.890 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:01.334Z,1660069441.334 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:11.036Z,1660069451.036 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:16.687Z,1660069456.687 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:24.767Z,1660069464.767 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:31.634Z,1660069471.634 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:38.909Z,1660069478.909 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:46.987Z,1660069486.987 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:52.642Z,1660069492.642 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:24:56.698Z,1660069496.698 [DVL_micro](ERROR): Failed to parse: :BD,+000,000000.99,000.+9999.99,+9999.99,+9999.99,+9999.99 2022-08-09T18:25:01.934Z,1660069501.934 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:25:06.783Z,1660069506.783 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:25:16.882Z,1660069516.882 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:25:20.518Z,1660069520.518 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:25:32.234Z,1660069532.234 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:25:34.659Z,1660069534.659 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:25:47.186Z,1660069547.186 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:25:48.398Z,1660069548.398 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:26:01.730Z,1660069561.730 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T18:26:02.552Z,1660069562.552 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:26:13.046Z,1660069573.046 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T18:26:13.046Z,1660069573.046 [DVL_micro](ERROR): Failed to parse: :TS,000000035.0,+22.9,0000.0,1489.0,000 2022-08-09T18:26:16.281Z,1660069576.281 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T18:28:18.703Z,1660069698.703 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:28:18.703Z,1660069698.703 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:28:18.703Z,1660069698.703 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:28:18.703Z,1660069698.703 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:28:19.113Z,1660069699.113 [Default:CheckIn:D] Stopped 2022-08-09T18:28:19.113Z,1660069699.113 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:28:19.525Z,1660069699.525 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.568009 min 2022-08-09T18:28:19.525Z,1660069699.525 [Default:CheckIn:E] Stopped 2022-08-09T18:28:19.525Z,1660069699.525 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:28:19.525Z,1660069699.525 [Default:CheckIn] Stopped 2022-08-09T18:28:19.525Z,1660069699.525 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:28:19.525Z,1660069699.525 [Default:CheckIn](INFO): Running loop #16 2022-08-09T18:28:19.525Z,1660069699.525 [Default:CheckIn] Running Loop=16 2022-08-09T18:28:19.526Z,1660069699.526 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:28:19.526Z,1660069699.526 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:28:21.519Z,1660069701.519 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182825.00,A,4357.36741,N,08625.48010,W,0.039,87.47,090822,,,D*4C 2022-08-09T18:28:21.521Z,1660069701.521 [NAL9602](INFO): GPS fix at 20220809T182825: (43.956123, -86.424668) 2022-08-09T18:28:21.532Z,1660069701.532 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:28:21.532Z,1660069701.532 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:28:29.907Z,1660069709.907 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0036.lzma 2022-08-09T18:28:30.910Z,1660069710.910 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0036.lzma.bak 2022-08-09T18:28:30.910Z,1660069710.910 [DataOverHttps](INFO): SBD MOMSN=17097438 2022-08-09T18:28:48.183Z,1660069728.183 [NAL9602](INFO): SBD MO Status=0, MOMSN=10144, MT Status=0, MTMSN=0 2022-08-09T18:28:48.183Z,1660069728.183 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:28:49.404Z,1660069729.404 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20220809T172553/Express0037.lzma 2022-08-09T18:28:50.406Z,1660069730.406 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0037.lzma.bak 2022-08-09T18:28:50.406Z,1660069730.406 [DataOverHttps](INFO): SBD MOMSN=17097441 2022-08-09T18:28:54.759Z,1660069734.759 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:28:54.789Z,1660069734.789 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:28:54.789Z,1660069734.789 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:29:18.901Z,1660069758.901 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:30:29.720Z,1660069829.720 [DVL_micro](ERROR): Failed to parse: :WI,+00699,+0272,+00000,A 2022-08-09T18:33:29.098Z,1660070009.098 [BPC1](ERROR): Battery stick #61 (s/n: 0278) reported OVER_TEMP_ALARM. Status code: 0x1717. 2022-08-09T18:33:29.098Z,1660070009.098 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 4. 2022-08-09T18:33:29.101Z,1660070009.101 [BPC1](INFO): Received data from all battery sticks. 2022-08-09T18:33:55.376Z,1660070035.376 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:33:55.376Z,1660070035.376 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:33:55.376Z,1660070035.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:33:55.377Z,1660070035.377 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:33:55.778Z,1660070035.778 [Default:CheckIn:D] Stopped 2022-08-09T18:33:55.778Z,1660070035.778 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:33:56.175Z,1660070036.175 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.179085 min 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn:E] Stopped 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn] Stopped 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn](INFO): Running loop #17 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn] Running Loop=17 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:33:56.176Z,1660070036.176 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:33:58.183Z,1660070038.183 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183402.00,A,4354.73713,N,08624.70724,W,48.343,232.63,090822,,,D*43 2022-08-09T18:33:58.186Z,1660070038.186 [NAL9602](INFO): GPS fix at 20220809T183402: (43.912286, -86.411787) 2022-08-09T18:33:58.196Z,1660070038.196 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:33:58.196Z,1660070038.196 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:34:06.431Z,1660070046.431 [DataOverHttps](INFO): Sending 201 bytes from file Logs/20220809T172553/Courier0039.lzma 2022-08-09T18:34:07.434Z,1660070047.434 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0039.lzma.bak 2022-08-09T18:34:07.434Z,1660070047.434 [DataOverHttps](INFO): SBD MOMSN=17097445 2022-08-09T18:34:21.619Z,1660070061.619 [NAL9602](INFO): SBD MO Status=0, MOMSN=10145, MT Status=0, MTMSN=0 2022-08-09T18:34:21.619Z,1660070061.619 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:34:25.627Z,1660070065.627 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220809T172553/Express0040.lzma 2022-08-09T18:34:26.630Z,1660070066.630 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0040.lzma.bak 2022-08-09T18:34:26.630Z,1660070066.630 [DataOverHttps](INFO): SBD MOMSN=17097448 2022-08-09T18:34:30.131Z,1660070070.131 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:34:30.131Z,1660070070.131 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:34:30.131Z,1660070070.131 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:34:52.325Z,1660070092.325 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:38:39.808Z,1660070319.808 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 1775 2022-08-09T18:38:39.810Z,1660070319.810 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.09,000.00 2022-08-09T18:39:30.733Z,1660070370.733 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:39:30.733Z,1660070370.733 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:39:30.733Z,1660070370.733 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:39:30.733Z,1660070370.733 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:39:31.138Z,1660070371.138 [Default:CheckIn:D] Stopped 2022-08-09T18:39:31.139Z,1660070371.139 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:39:31.529Z,1660070371.529 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.768433 min 2022-08-09T18:39:31.529Z,1660070371.529 [Default:CheckIn:E] Stopped 2022-08-09T18:39:31.529Z,1660070371.529 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:39:31.529Z,1660070371.529 [Default:CheckIn] Stopped 2022-08-09T18:39:31.530Z,1660070371.530 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:39:31.530Z,1660070371.530 [Default:CheckIn](INFO): Running loop #18 2022-08-09T18:39:31.530Z,1660070371.530 [Default:CheckIn] Running Loop=18 2022-08-09T18:39:31.530Z,1660070371.530 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:39:31.530Z,1660070371.530 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:39:33.539Z,1660070373.539 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183937.00,A,4350.23067,N,08623.56807,W,51.570,175.41,090822,,,D*4E 2022-08-09T18:39:33.541Z,1660070373.541 [NAL9602](INFO): GPS fix at 20220809T183937: (43.837178, -86.392801) 2022-08-09T18:39:33.552Z,1660070373.552 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:39:33.552Z,1660070373.552 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:39:42.027Z,1660070382.027 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0042.lzma 2022-08-09T18:39:43.030Z,1660070383.030 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0042.lzma.bak 2022-08-09T18:39:43.030Z,1660070383.030 [DataOverHttps](INFO): SBD MOMSN=17097454 2022-08-09T18:40:03.827Z,1660070403.827 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220809T172553/Express0043.lzma 2022-08-09T18:40:04.843Z,1660070404.843 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0043.lzma.bak 2022-08-09T18:40:04.850Z,1660070404.850 [DataOverHttps](INFO): SBD MOMSN=17097457 2022-08-09T18:40:08.331Z,1660070408.331 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:40:08.336Z,1660070408.336 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:40:08.336Z,1660070408.336 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:40:15.973Z,1660070415.973 [NAL9602](INFO): SBD MO Status=2, MOMSN=10146, MT Status=2, MTMSN=0 2022-08-09T18:40:15.974Z,1660070415.974 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T18:40:30.597Z,1660070430.597 [NAL9602](INFO): SBD MO Status=0, MOMSN=10146, MT Status=0, MTMSN=0 2022-08-09T18:40:30.597Z,1660070430.597 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:41:01.221Z,1660070461.221 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:42:13.560Z,1660070533.560 [DVL_micro](ERROR): only read 2 of 4 data items 2022-08-09T18:42:13.561Z,1660070533.561 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,++9999.99 2022-08-09T18:42:18.577Z,1660070538.577 [DAT](INFO): unknown deviceResponse_: Acoustic Wakeup 2022-08-09T18:42:18.578Z,1660070538.578 [DAT](INFO): commRate: 800 2022-08-09T18:42:19.333Z,1660070539.333 [DAT](INFO): unknown deviceResponse_: Lowpower 2022-08-09T18:42:21.228Z,1660070541.228 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2022-08-09T18:44:05.076Z,1660070645.076 [DVL_micro](ERROR): Failed to parse: 00000000022.8,0000.0,1489.0,000 2022-08-09T18:45:08.901Z,1660070708.901 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:45:08.901Z,1660070708.901 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:45:08.901Z,1660070708.901 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:45:08.901Z,1660070708.901 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:45:09.291Z,1660070709.291 [Default:CheckIn:D] Stopped 2022-08-09T18:45:09.291Z,1660070709.291 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:45:09.691Z,1660070709.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.404305 min 2022-08-09T18:45:09.691Z,1660070709.691 [Default:CheckIn:E] Stopped 2022-08-09T18:45:09.692Z,1660070709.692 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:45:09.692Z,1660070709.692 [Default:CheckIn] Stopped 2022-08-09T18:45:09.692Z,1660070709.692 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:45:09.692Z,1660070709.692 [Default:CheckIn](INFO): Running loop #19 2022-08-09T18:45:09.692Z,1660070709.692 [Default:CheckIn] Running Loop=19 2022-08-09T18:45:09.692Z,1660070709.692 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:45:09.692Z,1660070709.692 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:45:11.711Z,1660070711.711 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184515.00,A,4345.10483,N,08623.05867,W,61.406,189.31,090822,,,A*4D 2022-08-09T18:45:11.713Z,1660070711.713 [NAL9602](INFO): GPS fix at 20220809T184515: (43.751747, -86.384311) 2022-08-09T18:45:11.724Z,1660070711.724 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:45:11.724Z,1660070711.724 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:45:20.591Z,1660070720.591 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0045.lzma 2022-08-09T18:45:21.594Z,1660070721.594 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0045.lzma.bak 2022-08-09T18:45:21.594Z,1660070721.594 [DataOverHttps](INFO): SBD MOMSN=17097462 2022-08-09T18:45:39.903Z,1660070739.903 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20220809T172553/Express0046.lzma 2022-08-09T18:45:41.284Z,1660070741.284 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0046.lzma.bak 2022-08-09T18:45:41.284Z,1660070741.284 [DataOverHttps](INFO): SBD MOMSN=17097465 2022-08-09T18:45:44.460Z,1660070744.460 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:45:44.461Z,1660070744.461 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:45:44.461Z,1660070744.461 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:45:45.635Z,1660070745.635 [NAL9602](INFO): SBD MO Status=2, MOMSN=10147, MT Status=2, MTMSN=0 2022-08-09T18:45:45.635Z,1660070745.635 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T18:46:04.223Z,1660070764.223 [NAL9602](INFO): SBD MO Status=2, MOMSN=10147, MT Status=2, MTMSN=0 2022-08-09T18:46:04.223Z,1660070764.223 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T18:47:18.555Z,1660070838.555 [NAL9602](INFO): SBD MO Status=0, MOMSN=10147, MT Status=0, MTMSN=0 2022-08-09T18:47:18.555Z,1660070838.555 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:47:49.257Z,1660070869.257 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:50:45.032Z,1660071045.032 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:50:45.033Z,1660071045.033 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:50:45.033Z,1660071045.033 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:50:45.033Z,1660071045.033 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:50:45.417Z,1660071045.417 [Default:CheckIn:D] Stopped 2022-08-09T18:50:45.417Z,1660071045.417 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:50:45.814Z,1660071045.814 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.006405 min 2022-08-09T18:50:45.814Z,1660071045.814 [Default:CheckIn:E] Stopped 2022-08-09T18:50:45.815Z,1660071045.815 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:50:45.815Z,1660071045.815 [Default:CheckIn] Stopped 2022-08-09T18:50:45.815Z,1660071045.815 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:50:45.815Z,1660071045.815 [Default:CheckIn](INFO): Running loop #20 2022-08-09T18:50:45.815Z,1660071045.815 [Default:CheckIn] Running Loop=20 2022-08-09T18:50:45.815Z,1660071045.815 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:50:45.815Z,1660071045.815 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:50:47.836Z,1660071047.836 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185051.00,A,4339.60046,N,08623.91551,W,61.076,172.55,090822,,,A*48 2022-08-09T18:50:47.839Z,1660071047.839 [NAL9602](INFO): GPS fix at 20220809T185051: (43.660008, -86.398592) 2022-08-09T18:50:47.850Z,1660071047.850 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:50:47.850Z,1660071047.850 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:50:57.483Z,1660071057.483 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0048.lzma 2022-08-09T18:50:58.486Z,1660071058.486 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0048.lzma.bak 2022-08-09T18:50:58.486Z,1660071058.486 [DataOverHttps](INFO): SBD MOMSN=17097471 2022-08-09T18:51:02.371Z,1660071062.371 [NAL9602](INFO): SBD MO Status=0, MOMSN=10148, MT Status=0, MTMSN=0 2022-08-09T18:51:02.371Z,1660071062.371 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:51:17.703Z,1660071077.703 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220809T172553/Express0049.lzma 2022-08-09T18:51:18.706Z,1660071078.706 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0049.lzma.bak 2022-08-09T18:51:18.706Z,1660071078.706 [DataOverHttps](INFO): SBD MOMSN=17097474 2022-08-09T18:51:22.201Z,1660071082.201 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:51:22.201Z,1660071082.201 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:51:22.201Z,1660071082.201 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:51:29.852Z,1660071089.852 [DVL_micro](ERROR): Failed to parse:99.99,+9999.99,+9999.99,+9999.99 2022-08-09T18:51:33.072Z,1660071093.072 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T18:55:31.439Z,1660071331.439 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T18:55:31.439Z,1660071331.439 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+2.0,1489.0,000 2022-08-09T18:56:22.775Z,1660071382.775 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T18:56:22.775Z,1660071382.775 [Default:CheckIn:C.Wait] Stopped 2022-08-09T18:56:22.775Z,1660071382.775 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T18:56:22.775Z,1660071382.775 [Default:CheckIn:D] Running Loop=1 2022-08-09T18:56:23.154Z,1660071383.154 [Default:CheckIn:D] Stopped 2022-08-09T18:56:23.155Z,1660071383.155 [Default:CheckIn:E] Running Loop=1 2022-08-09T18:56:23.578Z,1660071383.578 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.635368 min 2022-08-09T18:56:23.578Z,1660071383.578 [Default:CheckIn:E] Stopped 2022-08-09T18:56:23.578Z,1660071383.578 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T18:56:23.578Z,1660071383.578 [Default:CheckIn] Stopped 2022-08-09T18:56:23.578Z,1660071383.578 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T18:56:23.578Z,1660071383.578 [Default:CheckIn](INFO): Running loop #21 2022-08-09T18:56:23.579Z,1660071383.579 [Default:CheckIn] Running Loop=21 2022-08-09T18:56:23.579Z,1660071383.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T18:56:23.579Z,1660071383.579 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T18:56:25.575Z,1660071385.575 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185629.00,A,4334.12926,N,08623.59240,W,58.587,162.52,090822,,,A*42 2022-08-09T18:56:25.578Z,1660071385.578 [NAL9602](INFO): GPS fix at 20220809T185629: (43.568821, -86.393207) 2022-08-09T18:56:25.589Z,1660071385.589 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T18:56:25.589Z,1660071385.589 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T18:56:33.831Z,1660071393.831 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0051.lzma 2022-08-09T18:56:34.834Z,1660071394.834 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0051.lzma.bak 2022-08-09T18:56:34.834Z,1660071394.834 [DataOverHttps](INFO): SBD MOMSN=17097478 2022-08-09T18:56:52.959Z,1660071412.959 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20220809T172553/Express0052.lzma 2022-08-09T18:56:53.058Z,1660071413.058 [NAL9602](INFO): SBD MO Status=0, MOMSN=10149, MT Status=0, MTMSN=0 2022-08-09T18:56:53.058Z,1660071413.058 [NAL9602](INFO): No messages in MT queue 2022-08-09T18:56:53.962Z,1660071413.962 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0052.lzma.bak 2022-08-09T18:56:53.962Z,1660071413.962 [DataOverHttps](INFO): SBD MOMSN=17097481 2022-08-09T18:56:57.554Z,1660071417.554 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T18:56:57.554Z,1660071417.554 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T18:56:57.554Z,1660071417.554 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T18:57:23.765Z,1660071443.765 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:01:58.105Z,1660071718.105 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:01:58.106Z,1660071718.106 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:01:58.106Z,1660071718.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:01:58.106Z,1660071718.106 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:01:58.515Z,1660071718.515 [Default:CheckIn:D] Stopped 2022-08-09T19:01:58.515Z,1660071718.515 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.224707 min 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn:E] Stopped 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn] Stopped 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn](INFO): Running loop #22 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn] Running Loop=22 2022-08-09T19:01:58.925Z,1660071718.925 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:01:58.926Z,1660071718.926 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:02:00.931Z,1660071720.931 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190204.00,A,4328.91980,N,08621.61832,W,60.726,119.98,090822,,,A*49 2022-08-09T19:02:00.965Z,1660071720.965 [NAL9602](INFO): GPS fix at 20220809T190204: (43.481997, -86.360305) 2022-08-09T19:02:00.984Z,1660071720.984 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:02:00.984Z,1660071720.984 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:02:09.887Z,1660071729.887 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220809T172553/Courier0054.lzma 2022-08-09T19:02:10.890Z,1660071730.890 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0054.lzma.bak 2022-08-09T19:02:10.890Z,1660071730.890 [DataOverHttps](INFO): SBD MOMSN=17097485 2022-08-09T19:02:13.051Z,1660071733.051 [NAL9602](INFO): SBD MO Status=0, MOMSN=10150, MT Status=0, MTMSN=0 2022-08-09T19:02:13.051Z,1660071733.051 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:02:29.475Z,1660071749.475 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220809T172553/Express0055.lzma 2022-08-09T19:02:30.478Z,1660071750.478 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0055.lzma.bak 2022-08-09T19:02:30.478Z,1660071750.478 [DataOverHttps](INFO): SBD MOMSN=17097488 2022-08-09T19:02:34.087Z,1660071754.087 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:02:34.087Z,1660071754.087 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:02:34.087Z,1660071754.087 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:02:43.750Z,1660071763.750 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:05:58.901Z,1660071958.901 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T19:05:58.901Z,1660071958.901 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+22.5,489.0,000 2022-08-09T19:07:34.643Z,1660072054.643 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:07:34.643Z,1660072054.643 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:07:34.643Z,1660072054.643 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:07:34.644Z,1660072054.644 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:07:35.047Z,1660072055.047 [Default:CheckIn:D] Stopped 2022-08-09T19:07:35.047Z,1660072055.047 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:07:35.457Z,1660072055.457 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.833569 min 2022-08-09T19:07:35.457Z,1660072055.457 [Default:CheckIn:E] Stopped 2022-08-09T19:07:35.457Z,1660072055.457 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:07:35.457Z,1660072055.457 [Default:CheckIn] Stopped 2022-08-09T19:07:35.457Z,1660072055.457 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:07:35.457Z,1660072055.457 [Default:CheckIn](INFO): Running loop #23 2022-08-09T19:07:35.457Z,1660072055.457 [Default:CheckIn] Running Loop=23 2022-08-09T19:07:35.458Z,1660072055.458 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:07:35.458Z,1660072055.458 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:07:37.458Z,1660072057.458 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190741.00,A,4324.21725,N,08618.49488,W,59.501,127.29,090822,,,D*49 2022-08-09T19:07:37.461Z,1660072057.461 [NAL9602](INFO): GPS fix at 20220809T190741: (43.403621, -86.308248) 2022-08-09T19:07:37.486Z,1660072057.486 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:07:37.486Z,1660072057.486 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:07:45.871Z,1660072065.871 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0057.lzma 2022-08-09T19:07:46.874Z,1660072066.874 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0057.lzma.bak 2022-08-09T19:07:46.874Z,1660072066.874 [DataOverHttps](INFO): SBD MOMSN=17097493 2022-08-09T19:07:54.451Z,1660072074.451 [NAL9602](INFO): SBD MO Status=0, MOMSN=10151, MT Status=0, MTMSN=0 2022-08-09T19:07:54.451Z,1660072074.451 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:08:06.616Z,1660072086.616 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220809T172553/Express0058.lzma 2022-08-09T19:08:07.618Z,1660072087.618 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0058.lzma.bak 2022-08-09T19:08:07.618Z,1660072087.618 [DataOverHttps](INFO): SBD MOMSN=17097496 2022-08-09T19:08:11.065Z,1660072091.065 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:08:11.065Z,1660072091.065 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:08:11.065Z,1660072091.065 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:08:25.153Z,1660072105.153 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:08:44.162Z,1660072124.162 [DVL_micro](ERROR): Failed to parse: :SA,-06.52,-08.76,163.0 2022-08-09T19:13:11.610Z,1660072391.610 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:13:11.610Z,1660072391.610 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:13:11.610Z,1660072391.610 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:13:11.611Z,1660072391.611 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:13:12.004Z,1660072392.004 [Default:CheckIn:D] Stopped 2022-08-09T19:13:12.004Z,1660072392.004 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:13:12.411Z,1660072392.411 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.449520 min 2022-08-09T19:13:12.412Z,1660072392.412 [Default:CheckIn:E] Stopped 2022-08-09T19:13:12.412Z,1660072392.412 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:13:12.412Z,1660072392.412 [Default:CheckIn] Stopped 2022-08-09T19:13:12.412Z,1660072392.412 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:13:12.412Z,1660072392.412 [Default:CheckIn](INFO): Running loop #24 2022-08-09T19:13:12.412Z,1660072392.412 [Default:CheckIn] Running Loop=24 2022-08-09T19:13:12.412Z,1660072392.412 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:13:12.413Z,1660072392.413 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:13:14.424Z,1660072394.424 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191318.00,A,4319.65669,N,08614.57389,W,58.646,168.05,090822,,,D*46 2022-08-09T19:13:14.426Z,1660072394.426 [NAL9602](INFO): GPS fix at 20220809T191318: (43.327612, -86.242898) 2022-08-09T19:13:14.436Z,1660072394.436 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:13:14.436Z,1660072394.436 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:13:22.839Z,1660072402.839 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0060.lzma 2022-08-09T19:13:23.842Z,1660072403.842 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0060.lzma.bak 2022-08-09T19:13:23.842Z,1660072403.842 [DataOverHttps](INFO): SBD MOMSN=17097501 2022-08-09T19:13:35.028Z,1660072415.028 [NAL9602](INFO): SBD MO Status=0, MOMSN=10152, MT Status=0, MTMSN=0 2022-08-09T19:13:35.028Z,1660072415.028 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:13:43.823Z,1660072423.823 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220809T172553/Express0061.lzma 2022-08-09T19:13:44.826Z,1660072424.826 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0061.lzma.bak 2022-08-09T19:13:44.826Z,1660072424.826 [DataOverHttps](INFO): SBD MOMSN=17097504 2022-08-09T19:13:48.388Z,1660072428.388 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:13:48.388Z,1660072428.388 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:13:48.388Z,1660072428.388 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:14:05.726Z,1660072445.726 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:18:48.957Z,1660072728.957 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:18:48.958Z,1660072728.958 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:18:48.958Z,1660072728.958 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:18:48.958Z,1660072728.958 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:18:49.349Z,1660072729.349 [Default:CheckIn:D] Stopped 2022-08-09T19:18:49.349Z,1660072729.349 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:18:49.751Z,1660072729.751 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.071932 min 2022-08-09T19:18:49.751Z,1660072729.751 [Default:CheckIn:E] Stopped 2022-08-09T19:18:49.752Z,1660072729.752 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:18:49.752Z,1660072729.752 [Default:CheckIn] Stopped 2022-08-09T19:18:49.752Z,1660072729.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:18:49.752Z,1660072729.752 [Default:CheckIn](INFO): Running loop #25 2022-08-09T19:18:49.752Z,1660072729.752 [Default:CheckIn] Running Loop=25 2022-08-09T19:18:49.752Z,1660072729.752 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:18:49.752Z,1660072729.752 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:18:51.763Z,1660072731.763 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191855.00,A,4315.31485,N,08613.14932,W,48.829,247.92,090822,,,A*40 2022-08-09T19:18:51.765Z,1660072731.765 [NAL9602](INFO): GPS fix at 20220809T191855: (43.255248, -86.219155) 2022-08-09T19:18:51.777Z,1660072731.777 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:18:51.777Z,1660072731.777 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:19:00.167Z,1660072740.167 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0063.lzma 2022-08-09T19:19:01.170Z,1660072741.170 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0063.lzma.bak 2022-08-09T19:19:01.170Z,1660072741.170 [DataOverHttps](INFO): SBD MOMSN=17097508 2022-08-09T19:19:02.263Z,1660072742.263 [NAL9602](INFO): SBD MO Status=0, MOMSN=10153, MT Status=0, MTMSN=0 2022-08-09T19:19:02.263Z,1660072742.263 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:19:20.048Z,1660072760.048 [DataOverHttps](INFO): Sending 147 bytes from file Logs/20220809T172553/Express0064.lzma 2022-08-09T19:19:21.051Z,1660072761.051 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0064.lzma.bak 2022-08-09T19:19:21.051Z,1660072761.051 [DataOverHttps](INFO): SBD MOMSN=17097511 2022-08-09T19:19:24.519Z,1660072764.519 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:19:24.519Z,1660072764.519 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:19:24.519Z,1660072764.519 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:19:32.970Z,1660072772.970 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:24:25.067Z,1660073065.067 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:24:25.067Z,1660073065.067 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:24:25.067Z,1660073065.067 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:24:25.067Z,1660073065.067 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:24:25.475Z,1660073065.475 [Default:CheckIn:D] Stopped 2022-08-09T19:24:25.475Z,1660073065.475 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:24:25.874Z,1660073065.874 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.674040 min 2022-08-09T19:24:25.874Z,1660073065.874 [Default:CheckIn:E] Stopped 2022-08-09T19:24:25.874Z,1660073065.874 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:24:25.874Z,1660073065.874 [Default:CheckIn] Stopped 2022-08-09T19:24:25.874Z,1660073065.874 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:24:25.875Z,1660073065.875 [Default:CheckIn](INFO): Running loop #26 2022-08-09T19:24:25.875Z,1660073065.875 [Default:CheckIn] Running Loop=26 2022-08-09T19:24:25.875Z,1660073065.875 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:24:25.875Z,1660073065.875 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:24:27.886Z,1660073067.886 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192431.00,A,4313.81336,N,08615.67291,W,6.667,199.83,090822,,,A*71 2022-08-09T19:24:27.888Z,1660073067.888 [NAL9602](INFO): GPS fix at 20220809T192431: (43.230223, -86.261215) 2022-08-09T19:24:27.898Z,1660073067.898 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:24:27.898Z,1660073067.898 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:24:36.287Z,1660073076.287 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0066.lzma 2022-08-09T19:24:37.290Z,1660073077.290 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0066.lzma.bak 2022-08-09T19:24:37.290Z,1660073077.290 [DataOverHttps](INFO): SBD MOMSN=17097515 2022-08-09T19:24:42.052Z,1660073082.052 [NAL9602](INFO): SBD MO Status=0, MOMSN=10154, MT Status=0, MTMSN=0 2022-08-09T19:24:42.052Z,1660073082.052 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:24:55.335Z,1660073095.335 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20220809T172553/Express0067.lzma 2022-08-09T19:24:56.338Z,1660073096.338 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0067.lzma.bak 2022-08-09T19:24:56.338Z,1660073096.338 [DataOverHttps](INFO): SBD MOMSN=17097518 2022-08-09T19:24:59.861Z,1660073099.861 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:24:59.861Z,1660073099.861 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:24:59.861Z,1660073099.861 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:25:12.729Z,1660073112.729 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:27:52.330Z,1660073272.330 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T19:27:52.330Z,1660073272.330 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2022-08-09T19:29:34.136Z,1660073374.136 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+9999.99 2022-08-09T19:30:00.385Z,1660073400.385 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:30:00.386Z,1660073400.386 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:30:00.386Z,1660073400.386 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:30:00.386Z,1660073400.386 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:30:00.794Z,1660073400.794 [Default:CheckIn:D] Stopped 2022-08-09T19:30:00.794Z,1660073400.794 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:30:01.200Z,1660073401.200 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.262679 min 2022-08-09T19:30:01.200Z,1660073401.200 [Default:CheckIn:E] Stopped 2022-08-09T19:30:01.200Z,1660073401.200 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:30:01.200Z,1660073401.200 [Default:CheckIn] Stopped 2022-08-09T19:30:01.200Z,1660073401.200 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:30:01.201Z,1660073401.201 [Default:CheckIn](INFO): Running loop #27 2022-08-09T19:30:01.201Z,1660073401.201 [Default:CheckIn] Running Loop=27 2022-08-09T19:30:01.201Z,1660073401.201 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:30:01.201Z,1660073401.201 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:30:03.212Z,1660073403.212 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193007.00,A,4312.86727,N,08617.80882,W,26.806,247.19,090822,,,A*48 2022-08-09T19:30:03.214Z,1660073403.214 [NAL9602](INFO): GPS fix at 20220809T193007: (43.214455, -86.296814) 2022-08-09T19:30:03.225Z,1660073403.225 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:30:03.225Z,1660073403.225 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:30:11.531Z,1660073411.531 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0069.lzma 2022-08-09T19:30:12.534Z,1660073412.534 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0069.lzma.bak 2022-08-09T19:30:12.534Z,1660073412.534 [DataOverHttps](INFO): SBD MOMSN=17097522 2022-08-09T19:30:31.891Z,1660073431.891 [NAL9602](INFO): SBD MO Status=2, MOMSN=10155, MT Status=2, MTMSN=0 2022-08-09T19:30:31.891Z,1660073431.891 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-08-09T19:30:32.626Z,1660073432.626 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220809T172553/Express0070.lzma 2022-08-09T19:30:34.630Z,1660073434.630 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0070.lzma.bak 2022-08-09T19:30:34.630Z,1660073434.630 [DataOverHttps](INFO): SBD MOMSN=17097525 2022-08-09T19:30:38.377Z,1660073438.377 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:30:38.377Z,1660073438.377 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:30:38.377Z,1660073438.377 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:30:42.799Z,1660073442.799 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T19:30:42.800Z,1660073442.800 [DVL_micro](ERROR): Failed to parse: :TS0000000,35,0000.0,1489:WI,+02812,-00878,-00150,+00000,A 2022-08-09T19:30:49.671Z,1660073449.671 [NAL9602](INFO): SBD MO Status=0, MOMSN=10155, MT Status=0, MTMSN=0 2022-08-09T19:30:49.671Z,1660073449.671 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:31:20.373Z,1660073480.373 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:35:38.944Z,1660073738.944 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:35:38.944Z,1660073738.944 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:35:38.944Z,1660073738.944 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:35:38.944Z,1660073738.944 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:35:39.347Z,1660073739.347 [Default:CheckIn:D] Stopped 2022-08-09T19:35:39.347Z,1660073739.347 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:35:39.763Z,1660073739.763 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.905241 min 2022-08-09T19:35:39.763Z,1660073739.763 [Default:CheckIn:E] Stopped 2022-08-09T19:35:39.764Z,1660073739.764 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:35:39.764Z,1660073739.764 [Default:CheckIn] Stopped 2022-08-09T19:35:39.764Z,1660073739.764 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:35:39.765Z,1660073739.765 [Default:CheckIn](INFO): Running loop #28 2022-08-09T19:35:39.765Z,1660073739.765 [Default:CheckIn] Running Loop=28 2022-08-09T19:35:39.765Z,1660073739.765 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:35:39.765Z,1660073739.765 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:35:41.766Z,1660073741.766 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193545.00,A,4313.64143,N,08620.27837,W,5.462,266.59,090822,,,A*7D 2022-08-09T19:35:41.768Z,1660073741.768 [NAL9602](INFO): GPS fix at 20220809T193545: (43.227357, -86.337973) 2022-08-09T19:35:41.778Z,1660073741.778 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:35:41.779Z,1660073741.779 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:35:56.303Z,1660073756.303 [NAL9602](INFO): SBD MO Status=0, MOMSN=10156, MT Status=0, MTMSN=0 2022-08-09T19:35:56.303Z,1660073756.303 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:35:57.127Z,1660073757.127 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0072.lzma 2022-08-09T19:35:58.130Z,1660073758.130 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0072.lzma.bak 2022-08-09T19:35:58.130Z,1660073758.130 [DataOverHttps](INFO): SBD MOMSN=17097529 2022-08-09T19:36:03.570Z,1660073763.570 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:36:07.610Z,1660073767.610 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:36:17.831Z,1660073777.831 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220809T172553/Express0073.lzma 2022-08-09T19:36:18.834Z,1660073778.834 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0073.lzma.bak 2022-08-09T19:36:18.834Z,1660073778.834 [DataOverHttps](INFO): SBD MOMSN=17097532 2022-08-09T19:36:18.922Z,1660073778.922 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:36:21.347Z,1660073781.347 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:36:22.196Z,1660073782.196 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:36:22.196Z,1660073782.196 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:36:22.197Z,1660073782.197 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:36:27.005Z,1660073787.005 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:36:33.869Z,1660073793.869 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:36:35.100Z,1660073795.100 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:36:48.866Z,1660073808.866 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:36:49.222Z,1660073809.222 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:02.959Z,1660073822.959 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:04.171Z,1660073824.171 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:16.694Z,1660073836.694 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:19.118Z,1660073839.118 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:30.833Z,1660073850.833 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:34.469Z,1660073854.469 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:44.571Z,1660073864.571 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:49.418Z,1660073869.418 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:37:58.711Z,1660073878.711 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:38:04.366Z,1660073884.366 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:38:12.446Z,1660073892.446 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:38:19.718Z,1660073899.718 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:38:26.585Z,1660073906.585 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:41:22.825Z,1660074082.825 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:41:22.825Z,1660074082.825 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:41:22.826Z,1660074082.826 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:41:22.826Z,1660074082.826 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:41:23.155Z,1660074083.155 [Default:CheckIn:D] Stopped 2022-08-09T19:41:23.155Z,1660074083.155 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:41:23.571Z,1660074083.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.635368 min 2022-08-09T19:41:23.571Z,1660074083.571 [Default:CheckIn:E] Stopped 2022-08-09T19:41:23.571Z,1660074083.571 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:41:23.571Z,1660074083.571 [Default:CheckIn] Stopped 2022-08-09T19:41:23.571Z,1660074083.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:41:23.571Z,1660074083.571 [Default:CheckIn](INFO): Running loop #29 2022-08-09T19:41:23.571Z,1660074083.571 [Default:CheckIn] Running Loop=29 2022-08-09T19:41:23.572Z,1660074083.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:41:23.572Z,1660074083.572 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:41:25.562Z,1660074085.562 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194129.00,A,4313.62944,N,08620.27551,W,0.019,113.61,090822,,,D*72 2022-08-09T19:41:25.564Z,1660074085.564 [NAL9602](INFO): GPS fix at 20220809T194129: (43.227157, -86.337925) 2022-08-09T19:41:25.575Z,1660074085.575 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:41:25.575Z,1660074085.575 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:41:34.515Z,1660074094.515 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0075.lzma 2022-08-09T19:41:35.518Z,1660074095.518 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0075.lzma.bak 2022-08-09T19:41:35.518Z,1660074095.518 [DataOverHttps](INFO): SBD MOMSN=17097536 2022-08-09T19:41:55.555Z,1660074115.555 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20220809T172553/Express0076.lzma 2022-08-09T19:41:56.558Z,1660074116.558 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0076.lzma.bak 2022-08-09T19:41:56.558Z,1660074116.558 [DataOverHttps](INFO): SBD MOMSN=17097539 2022-08-09T19:41:59.932Z,1660074119.932 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:41:59.932Z,1660074119.932 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:41:59.932Z,1660074119.932 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:42:42.735Z,1660074162.735 [NAL9602](INFO): SBD MO Status=0, MOMSN=10157, MT Status=0, MTMSN=0 2022-08-09T19:42:42.735Z,1660074162.735 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:43:04.149Z,1660074184.149 [DVL_micro](ERROR): Failed to parse: :2,-00581,-00203,+00000,I 2022-08-09T19:43:13.429Z,1660074193.429 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:43:19.492Z,1660074199.492 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file). 2022-08-09T19:45:00.907Z,1660074300.907 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T19:45:00.908Z,1660074300.908 [DVL_micro](ERROR): Failed to parse: :BI,-01113,-0719,+00000,I 2022-08-09T19:45:52.253Z,1660074352.253 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2022-08-09T19:45:57.449Z,1660074357.449 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:07.550Z,1660074367.550 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:11.994Z,1660074371.994 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:21.287Z,1660074381.287 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:27.346Z,1660074387.346 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:35.021Z,1660074395.021 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:42.299Z,1660074402.299 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:49.163Z,1660074409.163 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:46:57.243Z,1660074417.243 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:00.496Z,1660074420.496 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:47:00.496Z,1660074420.496 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:47:00.496Z,1660074420.496 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:47:00.496Z,1660074420.496 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:47:00.899Z,1660074420.899 [Default:CheckIn:D] Stopped 2022-08-09T19:47:00.900Z,1660074420.900 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:47:01.318Z,1660074421.318 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.264453 min 2022-08-09T19:47:01.318Z,1660074421.318 [Default:CheckIn:E] Stopped 2022-08-09T19:47:01.318Z,1660074421.318 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:47:01.319Z,1660074421.319 [Default:CheckIn] Stopped 2022-08-09T19:47:01.319Z,1660074421.319 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:47:01.319Z,1660074421.319 [Default:CheckIn](INFO): Running loop #30 2022-08-09T19:47:01.319Z,1660074421.319 [Default:CheckIn] Running Loop=30 2022-08-09T19:47:01.319Z,1660074421.319 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:47:01.319Z,1660074421.319 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:47:02.898Z,1660074422.898 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:03.325Z,1660074423.325 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194707.00,A,4313.62701,N,08620.33523,W,0.000,327.61,090822,,,A*7F 2022-08-09T19:47:03.342Z,1660074423.342 [NAL9602](INFO): GPS fix at 20220809T194707: (43.227117, -86.338921) 2022-08-09T19:47:03.369Z,1660074423.369 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:47:03.369Z,1660074423.369 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:47:06.058Z,1660074426.058 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20220809T172553/Courier0078.lzma 2022-08-09T19:47:09.070Z,1660074429.070 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0078.lzma.bak 2022-08-09T19:47:09.070Z,1660074429.070 [DataOverHttps](INFO): SBD MOMSN=17097543 2022-08-09T19:47:12.659Z,1660074432.659 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:16.698Z,1660074436.698 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:27.607Z,1660074447.607 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:28.032Z,1660074448.032 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T19:47:28.032Z,1660074448.032 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+23.5,0000.0000 2022-08-09T19:47:30.486Z,1660074450.486 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220809T172553/Express0079.lzma 2022-08-09T19:47:30.838Z,1660074450.838 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:31.486Z,1660074451.486 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0079.lzma.bak 2022-08-09T19:47:31.486Z,1660074451.486 [DataOverHttps](INFO): SBD MOMSN=17097546 2022-08-09T19:47:34.905Z,1660074454.905 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:47:34.905Z,1660074454.905 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:47:34.905Z,1660074454.905 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:47:35.703Z,1660074455.703 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T19:47:35.703Z,1660074455.703 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+23.,1489.0,000 2022-08-09T19:47:37.307Z,1660074457.307 [NAL9602](INFO): SBD MO Status=0, MOMSN=10158, MT Status=0, MTMSN=0 2022-08-09T19:47:37.307Z,1660074457.307 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:47:40.945Z,1660074460.945 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T19:47:40.945Z,1660074460.945 [DVL_micro](ERROR): Failed to parse: :BI,+0218,+00583,+00000,I 2022-08-09T19:47:42.555Z,1660074462.555 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:44.575Z,1660074464.575 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:57.906Z,1660074477.906 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:47:58.736Z,1660074478.736 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:48:08.014Z,1660074488.014 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:48:12.497Z,1660074492.497 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:48:12.854Z,1660074492.854 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:48:26.595Z,1660074506.595 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:50:02.240Z,1660074602.240 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-09T19:50:08.264Z,1660074608.264 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239281 2022-08-09T19:51:12.520Z,1660074672.520 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2022-08-09T19:51:25.052Z,1660074685.052 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002880 2022-08-09T19:52:35.478Z,1660074755.478 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:52:35.478Z,1660074755.478 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:52:35.478Z,1660074755.478 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:52:35.478Z,1660074755.478 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:52:35.882Z,1660074755.882 [Default:CheckIn:D] Stopped 2022-08-09T19:52:35.882Z,1660074755.882 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:52:36.274Z,1660074756.274 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.847493 min 2022-08-09T19:52:36.274Z,1660074756.274 [Default:CheckIn:E] Stopped 2022-08-09T19:52:36.274Z,1660074756.274 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:52:36.274Z,1660074756.274 [Default:CheckIn] Stopped 2022-08-09T19:52:36.275Z,1660074756.275 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:52:36.275Z,1660074756.275 [Default:CheckIn](INFO): Running loop #31 2022-08-09T19:52:36.275Z,1660074756.275 [Default:CheckIn] Running Loop=31 2022-08-09T19:52:36.275Z,1660074756.275 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:52:36.275Z,1660074756.275 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:52:38.342Z,1660074758.342 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195242.00,A,4313.62903,N,08620.33735,W,0.058,327.61,090822,,,D*7B 2022-08-09T19:52:38.345Z,1660074758.345 [NAL9602](INFO): GPS fix at 20220809T195242: (43.227151, -86.338956) 2022-08-09T19:52:38.355Z,1660074758.355 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:52:38.355Z,1660074758.355 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:52:46.723Z,1660074766.723 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0081.lzma 2022-08-09T19:52:47.726Z,1660074767.726 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0081.lzma.bak 2022-08-09T19:52:47.726Z,1660074767.726 [DataOverHttps](INFO): SBD MOMSN=17097550 2022-08-09T19:53:06.119Z,1660074786.119 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20220809T172553/Express0082.lzma 2022-08-09T19:53:07.122Z,1660074787.122 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0082.lzma.bak 2022-08-09T19:53:07.122Z,1660074787.122 [DataOverHttps](INFO): SBD MOMSN=17097553 2022-08-09T19:53:10.644Z,1660074790.644 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:53:10.644Z,1660074790.644 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:53:10.644Z,1660074790.644 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:53:26.799Z,1660074806.799 [NAL9602](INFO): SBD MO Status=0, MOMSN=10159, MT Status=0, MTMSN=0 2022-08-09T19:53:26.799Z,1660074806.799 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:53:57.496Z,1660074837.496 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T19:55:50.210Z,1660074950.210 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:05.158Z,1660074965.158 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:08.796Z,1660074968.796 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:19.703Z,1660074979.703 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:22.530Z,1660074982.530 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:35.054Z,1660074995.054 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:36.289Z,1660074996.289 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:50.004Z,1660075010.004 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:56:50.010Z,1660075010.010 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:04.142Z,1660075024.142 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:04.950Z,1660075024.950 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:17.878Z,1660075037.878 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:20.302Z,1660075040.302 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:32.031Z,1660075052.031 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:35.262Z,1660075055.262 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:45.766Z,1660075065.766 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:50.211Z,1660075070.211 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:57:59.907Z,1660075079.907 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:58:05.562Z,1660075085.562 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T19:58:11.251Z,1660075091.251 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T19:58:11.251Z,1660075091.251 [Default:CheckIn:C.Wait] Stopped 2022-08-09T19:58:11.256Z,1660075091.256 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T19:58:11.256Z,1660075091.256 [Default:CheckIn:D] Running Loop=1 2022-08-09T19:58:11.669Z,1660075091.669 [Default:CheckIn:D] Stopped 2022-08-09T19:58:11.669Z,1660075091.669 [Default:CheckIn:E] Running Loop=1 2022-08-09T19:58:12.047Z,1660075092.047 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.443929 min 2022-08-09T19:58:12.047Z,1660075092.047 [Default:CheckIn:E] Stopped 2022-08-09T19:58:12.047Z,1660075092.047 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T19:58:12.047Z,1660075092.047 [Default:CheckIn] Stopped 2022-08-09T19:58:12.064Z,1660075092.064 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T19:58:12.064Z,1660075092.064 [Default:CheckIn](INFO): Running loop #32 2022-08-09T19:58:12.064Z,1660075092.064 [Default:CheckIn] Running Loop=32 2022-08-09T19:58:12.064Z,1660075092.064 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T19:58:12.064Z,1660075092.064 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T19:58:13.643Z,1660075093.643 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:58:14.072Z,1660075094.072 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195818.00,A,4313.62880,N,08620.33628,W,0.039,327.61,090822,,,D*7E 2022-08-09T19:58:14.074Z,1660075094.074 [NAL9602](INFO): GPS fix at 20220809T195818: (43.227147, -86.338938) 2022-08-09T19:58:14.104Z,1660075094.104 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T19:58:14.104Z,1660075094.104 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T19:58:22.615Z,1660075102.615 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0084.lzma 2022-08-09T19:58:23.618Z,1660075103.618 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0084.lzma.bak 2022-08-09T19:58:23.618Z,1660075103.618 [DataOverHttps](INFO): SBD MOMSN=17097557 2022-08-09T19:58:27.782Z,1660075107.782 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T19:58:31.831Z,1660075111.831 [NAL9602](INFO): SBD MO Status=0, MOMSN=10160, MT Status=0, MTMSN=0 2022-08-09T19:58:31.831Z,1660075111.831 [NAL9602](INFO): No messages in MT queue 2022-08-09T19:58:41.899Z,1660075121.899 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220809T172553/Express0085.lzma 2022-08-09T19:58:42.902Z,1660075122.902 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0085.lzma.bak 2022-08-09T19:58:42.902Z,1660075122.902 [DataOverHttps](INFO): SBD MOMSN=17097560 2022-08-09T19:58:46.804Z,1660075126.804 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T19:58:46.804Z,1660075126.804 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T19:58:46.804Z,1660075126.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T19:59:02.534Z,1660075142.534 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:02:34.235Z,1660075354.235 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T20:02:34.240Z,1660075354.240 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2022-08-09T20:03:47.363Z,1660075427.363 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T20:03:47.363Z,1660075427.363 [Default:CheckIn:C.Wait] Stopped 2022-08-09T20:03:47.363Z,1660075427.363 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T20:03:47.380Z,1660075427.380 [Default:CheckIn:D] Running Loop=1 2022-08-09T20:03:47.778Z,1660075427.778 [Default:CheckIn:D] Stopped 2022-08-09T20:03:47.778Z,1660075427.778 [Default:CheckIn:E] Running Loop=1 2022-08-09T20:03:48.168Z,1660075428.168 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.045752 min 2022-08-09T20:03:48.168Z,1660075428.168 [Default:CheckIn:E] Stopped 2022-08-09T20:03:48.168Z,1660075428.168 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T20:03:48.168Z,1660075428.168 [Default:CheckIn] Stopped 2022-08-09T20:03:48.168Z,1660075428.168 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T20:03:48.168Z,1660075428.168 [Default:CheckIn](INFO): Running loop #33 2022-08-09T20:03:48.168Z,1660075428.168 [Default:CheckIn] Running Loop=33 2022-08-09T20:03:48.169Z,1660075428.169 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T20:03:48.169Z,1660075428.169 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T20:03:50.188Z,1660075430.188 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200354.00,A,4313.62551,N,08620.33736,W,0.039,327.61,090822,,,D*7D 2022-08-09T20:03:50.191Z,1660075430.191 [NAL9602](INFO): GPS fix at 20220809T200354: (43.227092, -86.338956) 2022-08-09T20:03:50.201Z,1660075430.201 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T20:03:50.201Z,1660075430.201 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T20:03:58.551Z,1660075438.551 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0087.lzma 2022-08-09T20:03:59.554Z,1660075439.554 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0087.lzma.bak 2022-08-09T20:03:59.554Z,1660075439.554 [DataOverHttps](INFO): SBD MOMSN=17097564 2022-08-09T20:04:07.265Z,1660075447.265 [NAL9602](INFO): SBD MO Status=0, MOMSN=10161, MT Status=0, MTMSN=0 2022-08-09T20:04:07.266Z,1660075447.266 [NAL9602](INFO): No messages in MT queue 2022-08-09T20:04:18.535Z,1660075458.535 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20220809T172553/Express0088.lzma 2022-08-09T20:04:19.538Z,1660075459.538 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0088.lzma.bak 2022-08-09T20:04:19.538Z,1660075459.538 [DataOverHttps](INFO): SBD MOMSN=17097568 2022-08-09T20:04:23.352Z,1660075463.352 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T20:04:23.353Z,1660075463.353 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T20:04:23.353Z,1660075463.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T20:04:30.171Z,1660075470.171 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 4. 2022-08-09T20:04:30.174Z,1660075470.174 [BPC1](FAULT): Failed to receive data from 8 sticks prior to timeout. Missing stick IDs are: 3, 4, 5, 6, 8, 16, 42, 43. 2022-08-09T20:04:30.174Z,1660075470.174 [BPC1] Data Fault, FailCount= 1 2022-08-09T20:04:30.174Z,1660075470.174 [BPC1](ERROR): Data Fault 2022-08-09T20:04:30.222Z,1660075470.222 [CBIT](ERROR): Data Fault in component: BPC1 2022-08-09T20:04:37.849Z,1660075477.849 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:08:37.019Z,1660075717.019 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T20:08:37.019Z,1660075717.019 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+24.3,0000.0,00 2022-08-09T20:09:23.890Z,1660075763.890 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T20:09:23.890Z,1660075763.890 [Default:CheckIn:C.Wait] Stopped 2022-08-09T20:09:23.890Z,1660075763.890 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T20:09:23.891Z,1660075763.891 [Default:CheckIn:D] Running Loop=1 2022-08-09T20:09:24.296Z,1660075764.296 [Default:CheckIn:D] Stopped 2022-08-09T20:09:24.296Z,1660075764.296 [Default:CheckIn:E] Running Loop=1 2022-08-09T20:09:24.713Z,1660075764.713 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.654378 min 2022-08-09T20:09:24.713Z,1660075764.713 [Default:CheckIn:E] Stopped 2022-08-09T20:09:24.713Z,1660075764.713 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T20:09:24.713Z,1660075764.713 [Default:CheckIn] Stopped 2022-08-09T20:09:24.713Z,1660075764.713 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T20:09:24.714Z,1660075764.714 [Default:CheckIn](INFO): Running loop #34 2022-08-09T20:09:24.714Z,1660075764.714 [Default:CheckIn] Running Loop=34 2022-08-09T20:09:24.714Z,1660075764.714 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T20:09:24.714Z,1660075764.714 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T20:09:26.715Z,1660075766.715 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200930.00,A,4313.62915,N,08620.33725,W,0.039,327.61,090822,,,D*7B 2022-08-09T20:09:26.717Z,1660075766.717 [NAL9602](INFO): GPS fix at 20220809T200930: (43.227153, -86.338954) 2022-08-09T20:09:26.748Z,1660075766.748 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T20:09:26.748Z,1660075766.748 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T20:09:35.087Z,1660075775.087 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20220809T172553/Courier0090.lzma 2022-08-09T20:09:36.090Z,1660075776.090 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0090.lzma.bak 2022-08-09T20:09:36.090Z,1660075776.090 [DataOverHttps](INFO): SBD MOMSN=17097572 2022-08-09T20:09:38.027Z,1660075778.027 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T20:09:38.027Z,1660075778.027 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.999 2022-08-09T20:09:44.891Z,1660075784.891 [NAL9602](INFO): SBD MO Status=0, MOMSN=10162, MT Status=0, MTMSN=0 2022-08-09T20:09:44.891Z,1660075784.891 [NAL9602](INFO): No messages in MT queue 2022-08-09T20:09:55.520Z,1660075795.520 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20220809T172553/Express0091.lzma 2022-08-09T20:09:56.522Z,1660075796.522 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0091.lzma.bak 2022-08-09T20:09:56.522Z,1660075796.522 [DataOverHttps](INFO): SBD MOMSN=17097575 2022-08-09T20:10:00.272Z,1660075800.272 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T20:10:00.272Z,1660075800.272 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T20:10:00.272Z,1660075800.272 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T20:10:15.593Z,1660075815.593 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:10:59.245Z,1660075859.245 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T20:10:59.245Z,1660075859.245 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,00.0,1489.0,000 2022-08-09T20:11:29.540Z,1660075889.540 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T20:11:29.540Z,1660075889.540 [DVL_micro](ERROR): Failed to parse: :TS,000000000000004.3,0000.0,1489.0,000 2022-08-09T20:14:31.351Z,1660076071.351 [CBIT](INFO): Clearing failed state for component BPC1 2022-08-09T20:14:31.351Z,1660076071.351 [BPC1] No Fault, FailCount= 1 2022-08-09T20:15:00.838Z,1660076100.838 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T20:15:00.838Z,1660076100.838 [Default:CheckIn:C.Wait] Stopped 2022-08-09T20:15:00.838Z,1660076100.838 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T20:15:00.838Z,1660076100.838 [Default:CheckIn:D] Running Loop=1 2022-08-09T20:15:01.236Z,1660076101.236 [Default:CheckIn:D] Stopped 2022-08-09T20:15:01.236Z,1660076101.236 [Default:CheckIn:E] Running Loop=1 2022-08-09T20:15:01.634Z,1660076101.634 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 192.270052 min 2022-08-09T20:15:01.634Z,1660076101.634 [Default:CheckIn:E] Stopped 2022-08-09T20:15:01.634Z,1660076101.634 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T20:15:01.635Z,1660076101.635 [Default:CheckIn] Stopped 2022-08-09T20:15:01.635Z,1660076101.635 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T20:15:01.635Z,1660076101.635 [Default:CheckIn](INFO): Running loop #35 2022-08-09T20:15:01.635Z,1660076101.635 [Default:CheckIn] Running Loop=35 2022-08-09T20:15:01.635Z,1660076101.635 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T20:15:01.635Z,1660076101.635 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T20:15:03.647Z,1660076103.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201507.00,A,4313.62611,N,08620.33357,W,0.058,154.58,090822,,,D*73 2022-08-09T20:15:03.649Z,1660076103.649 [NAL9602](INFO): GPS fix at 20220809T201507: (43.227102, -86.338893) 2022-08-09T20:15:03.660Z,1660076103.660 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T20:15:03.660Z,1660076103.660 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T20:15:10.519Z,1660076110.519 [DVL_micro](ERROR): only read 3 of 4 data items 2022-08-09T20:15:10.519Z,1660076110.519 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2022-08-09T20:15:12.115Z,1660076112.115 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0093.lzma 2022-08-09T20:15:13.118Z,1660076113.118 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0093.lzma.bak 2022-08-09T20:15:13.118Z,1660076113.118 [DataOverHttps](INFO): SBD MOMSN=17097580 2022-08-09T20:15:16.579Z,1660076116.579 [NAL9602](INFO): SBD MO Status=0, MOMSN=10163, MT Status=0, MTMSN=0 2022-08-09T20:15:16.579Z,1660076116.579 [NAL9602](INFO): No messages in MT queue 2022-08-09T20:15:31.319Z,1660076131.319 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220809T172553/Express0094.lzma 2022-08-09T20:15:32.322Z,1660076132.322 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0094.lzma.bak 2022-08-09T20:15:32.322Z,1660076132.322 [DataOverHttps](INFO): SBD MOMSN=17097583 2022-08-09T20:15:35.000Z,1660076136.000 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T20:15:36.000Z,1660076136.000 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T20:15:36.000Z,1660076136.000 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T20:15:47.280Z,1660076147.280 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:17:05.658Z,1660076225.658 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:17:10.506Z,1660076230.506 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:17:21.013Z,1660076241.013 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:17:24.242Z,1660076244.242 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:17:35.959Z,1660076255.959 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:17:38.382Z,1660076258.382 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:17:45.258Z,1660076265.258 [DVL_micro](ERROR): only read 2 of 4 data items 2022-08-09T20:17:45.258Z,1660076265.258 [DVL_micro](ERROR): Failed to parse: :BI,-00237,-00132+00000,I 2022-08-09T20:17:51.310Z,1660076271.310 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:17:52.132Z,1660076272.132 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:06.259Z,1660076286.259 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:06.265Z,1660076286.265 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:19.994Z,1660076299.994 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:21.207Z,1660076301.207 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:34.134Z,1660076314.134 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:35.750Z,1660076315.750 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:47.870Z,1660076327.870 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:18:51.102Z,1660076331.102 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:19:02.010Z,1660076342.010 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:19:06.050Z,1660076346.050 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:19:15.746Z,1660076355.746 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:19:20.594Z,1660076360.594 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2022-08-09T20:19:29.886Z,1660076369.886 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2022-08-09T20:20:36.571Z,1660076436.571 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T20:20:36.576Z,1660076436.576 [Default:CheckIn:C.Wait] Stopped 2022-08-09T20:20:36.576Z,1660076436.576 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T20:20:36.576Z,1660076436.576 [Default:CheckIn:D] Running Loop=1 2022-08-09T20:20:36.985Z,1660076436.985 [Default:CheckIn:D] Stopped 2022-08-09T20:20:36.985Z,1660076436.985 [Default:CheckIn:E] Running Loop=1 2022-08-09T20:20:37.393Z,1660076437.393 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.865869 min 2022-08-09T20:20:37.393Z,1660076437.393 [Default:CheckIn:E] Stopped 2022-08-09T20:20:37.393Z,1660076437.393 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T20:20:37.393Z,1660076437.393 [Default:CheckIn] Stopped 2022-08-09T20:20:37.393Z,1660076437.393 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T20:20:37.393Z,1660076437.393 [Default:CheckIn](INFO): Running loop #36 2022-08-09T20:20:37.393Z,1660076437.393 [Default:CheckIn] Running Loop=36 2022-08-09T20:20:37.394Z,1660076437.394 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T20:20:37.394Z,1660076437.394 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T20:20:39.383Z,1660076439.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202043.00,A,4313.62820,N,08620.33316,W,0.019,154.58,090822,,,D*79 2022-08-09T20:20:39.386Z,1660076439.386 [NAL9602](INFO): GPS fix at 20220809T202043: (43.227137, -86.338886) 2022-08-09T20:20:39.416Z,1660076439.416 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T20:20:39.417Z,1660076439.417 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T20:20:48.139Z,1660076448.139 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20220809T172553/Courier0096.lzma 2022-08-09T20:20:49.142Z,1660076449.142 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0096.lzma.bak 2022-08-09T20:20:49.142Z,1660076449.142 [DataOverHttps](INFO): SBD MOMSN=17097587 2022-08-09T20:21:09.247Z,1660076469.247 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220809T172553/Express0097.lzma 2022-08-09T20:21:10.250Z,1660076470.250 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0097.lzma.bak 2022-08-09T20:21:10.250Z,1660076470.250 [DataOverHttps](INFO): SBD MOMSN=17097591 2022-08-09T20:21:13.767Z,1660076473.767 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T20:21:13.767Z,1660076473.767 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T20:21:13.767Z,1660076473.767 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T20:21:17.779Z,1660076477.779 [NAL9602](INFO): SBD MO Status=0, MOMSN=10164, MT Status=0, MTMSN=0 2022-08-09T20:21:17.779Z,1660076477.779 [NAL9602](INFO): No messages in MT queue 2022-08-09T20:21:30.862Z,1660076490.862 [DVL_micro](ERROR): Failed to parse: 9.99,+9999.99,+9999.99,+9999.99 2022-08-09T20:21:48.490Z,1660076508.490 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:26:14.332Z,1660076774.332 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T20:26:14.332Z,1660076774.332 [Default:CheckIn:C.Wait] Stopped 2022-08-09T20:26:14.332Z,1660076774.332 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T20:26:14.333Z,1660076774.333 [Default:CheckIn:D] Running Loop=1 2022-08-09T20:26:14.740Z,1660076774.740 [Default:CheckIn:D] Stopped 2022-08-09T20:26:14.740Z,1660076774.740 [Default:CheckIn:E] Running Loop=1 2022-08-09T20:26:15.135Z,1660076775.135 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 203.495117 min 2022-08-09T20:26:15.135Z,1660076775.135 [Default:CheckIn:E] Stopped 2022-08-09T20:26:15.136Z,1660076775.136 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T20:26:15.136Z,1660076775.136 [Default:CheckIn] Stopped 2022-08-09T20:26:15.136Z,1660076775.136 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T20:26:15.136Z,1660076775.136 [Default:CheckIn](INFO): Running loop #37 2022-08-09T20:26:15.136Z,1660076775.136 [Default:CheckIn] Running Loop=37 2022-08-09T20:26:15.136Z,1660076775.136 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T20:26:15.136Z,1660076775.136 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T20:26:17.152Z,1660076777.152 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202621.00,A,4313.62930,N,08620.33701,W,0.039,154.58,090822,,,D*7B 2022-08-09T20:26:17.154Z,1660076777.154 [NAL9602](INFO): GPS fix at 20220809T202621: (43.227155, -86.338950) 2022-08-09T20:26:17.165Z,1660076777.165 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T20:26:17.165Z,1660076777.165 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T20:26:25.443Z,1660076785.443 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20220809T172553/Courier0099.lzma 2022-08-09T20:26:26.446Z,1660076786.446 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0099.lzma.bak 2022-08-09T20:26:26.446Z,1660076786.446 [DataOverHttps](INFO): SBD MOMSN=17097595 2022-08-09T20:26:46.567Z,1660076806.567 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220809T172553/Express0100.lzma 2022-08-09T20:26:47.572Z,1660076807.572 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0100.lzma.bak 2022-08-09T20:26:47.573Z,1660076807.573 [DataOverHttps](INFO): SBD MOMSN=17097598 2022-08-09T20:26:51.100Z,1660076811.100 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T20:26:51.100Z,1660076811.100 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T20:26:51.100Z,1660076811.100 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T20:26:53.935Z,1660076813.935 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 4. 2022-08-09T20:26:53.942Z,1660076813.942 [BPC1](INFO): Received data from all battery sticks. 2022-08-09T20:27:22.993Z,1660076842.993 [NAL9602](INFO): SBD MO Status=0, MOMSN=10165, MT Status=0, MTMSN=0 2022-08-09T20:27:22.993Z,1660076842.993 [NAL9602](INFO): No messages in MT queue 2022-08-09T20:27:53.700Z,1660076873.700 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:28:38.951Z,1660076918.951 [DVL_micro](ERROR): Failed to parse: :WI,-00254,-00359,-00063,+00000,A 2022-08-09T20:31:15.719Z,1660077075.719 [DVL_micro](ERROR): only read 0 of 4 data items 2022-08-09T20:31:15.719Z,1660077075.719 [DVL_micro](ERROR): Failed to parse: :RD,++9999.99,+99999.99 2022-08-09T20:31:51.667Z,1660077111.667 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T20:31:51.667Z,1660077111.667 [Default:CheckIn:C.Wait] Stopped 2022-08-09T20:31:51.667Z,1660077111.667 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T20:31:51.668Z,1660077111.668 [Default:CheckIn:D] Running Loop=1 2022-08-09T20:31:52.067Z,1660077112.067 [Default:CheckIn:D] Stopped 2022-08-09T20:31:52.067Z,1660077112.067 [Default:CheckIn:E] Running Loop=1 2022-08-09T20:31:52.481Z,1660077112.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 209.117236 min 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn:E] Stopped 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn] Stopped 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn](INFO): Running loop #38 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn] Running Loop=38 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T20:31:52.482Z,1660077112.482 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T20:31:54.482Z,1660077114.482 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203158.00,A,4313.62820,N,08620.33549,W,0.019,196.24,090822,,,D*7A 2022-08-09T20:31:54.484Z,1660077114.484 [NAL9602](INFO): GPS fix at 20220809T203158: (43.227137, -86.338925) 2022-08-09T20:31:54.494Z,1660077114.494 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T20:31:54.494Z,1660077114.494 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T20:32:03.055Z,1660077123.055 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20220809T172553/Courier0102.lzma 2022-08-09T20:32:04.058Z,1660077124.058 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0102.lzma.bak 2022-08-09T20:32:04.058Z,1660077124.058 [DataOverHttps](INFO): SBD MOMSN=17097602 2022-08-09T20:32:22.343Z,1660077142.343 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20220809T172553/Express0103.lzma 2022-08-09T20:32:23.346Z,1660077143.346 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0103.lzma.bak 2022-08-09T20:32:23.346Z,1660077143.346 [DataOverHttps](INFO): SBD MOMSN=17097606 2022-08-09T20:32:27.209Z,1660077147.209 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-08-09T20:32:27.209Z,1660077147.209 [DropWeight] Hardware Fault, FailCount= 1 2022-08-09T20:32:27.209Z,1660077147.209 [DropWeight](ERROR): Hardware Fault 2022-08-09T20:32:27.283Z,1660077147.283 [CommandExec](FAULT): Scheduling is paused 2022-08-09T20:32:27.283Z,1660077147.283 [CBIT](INFO): Critical error at 20220809T203227 2022-08-09T20:32:27.293Z,1660077147.293 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-08-09T20:32:27.294Z,1660077147.294 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-08-09T20:32:27.679Z,1660077147.679 [CBIT](INFO): Critical error at 20220809T203227 2022-08-09T20:32:28.454Z,1660077148.454 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T20:32:28.454Z,1660077148.454 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T20:32:28.454Z,1660077148.454 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T20:32:34.126Z,1660077154.126 [NAL9602](INFO): SBD MO Status=0, MOMSN=10166, MT Status=0, MTMSN=0 2022-08-09T20:32:34.126Z,1660077154.126 [NAL9602](INFO): No messages in MT queue 2022-08-09T20:33:04.793Z,1660077184.793 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:37:29.009Z,1660077449.009 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-08-09T20:37:29.009Z,1660077449.009 [Default:CheckIn:C.Wait] Stopped 2022-08-09T20:37:29.009Z,1660077449.009 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-08-09T20:37:29.009Z,1660077449.009 [Default:CheckIn:D] Running Loop=1 2022-08-09T20:37:29.410Z,1660077449.410 [Default:CheckIn:D] Stopped 2022-08-09T20:37:29.410Z,1660077449.410 [Default:CheckIn:E] Running Loop=1 2022-08-09T20:37:29.821Z,1660077449.821 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 214.739632 min 2022-08-09T20:37:29.821Z,1660077449.821 [Default:CheckIn:E] Stopped 2022-08-09T20:37:29.821Z,1660077449.821 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-08-09T20:37:29.821Z,1660077449.821 [Default:CheckIn] Stopped 2022-08-09T20:37:29.821Z,1660077449.821 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-08-09T20:37:29.822Z,1660077449.822 [Default:CheckIn](INFO): Running loop #39 2022-08-09T20:37:29.822Z,1660077449.822 [Default:CheckIn] Running Loop=39 2022-08-09T20:37:29.822Z,1660077449.822 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-08-09T20:37:29.822Z,1660077449.822 [Default:CheckIn:Read_GPS] Running Loop=1 2022-08-09T20:37:31.831Z,1660077451.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203735.00,A,4313.62794,N,08620.33474,W,0.019,196.24,090822,,,D*78 2022-08-09T20:37:31.841Z,1660077451.841 [NAL9602](INFO): GPS fix at 20220809T203735: (43.227132, -86.338912) 2022-08-09T20:37:31.851Z,1660077451.851 [Default:CheckIn:Read_GPS] Stopped 2022-08-09T20:37:31.851Z,1660077451.851 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-08-09T20:37:40.623Z,1660077460.623 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20220809T172553/Courier0105.lzma 2022-08-09T20:37:41.626Z,1660077461.626 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Courier0105.lzma.bak 2022-08-09T20:37:41.626Z,1660077461.626 [DataOverHttps](INFO): SBD MOMSN=17097610 2022-08-09T20:37:43.161Z,1660077463.161 [NAL9602](INFO): SBD MO Status=0, MOMSN=10167, MT Status=0, MTMSN=0 2022-08-09T20:37:43.161Z,1660077463.161 [NAL9602](INFO): No messages in MT queue 2022-08-09T20:37:59.713Z,1660077479.713 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20220809T172553/Express0106.lzma 2022-08-09T20:38:00.714Z,1660077480.714 [DataOverHttps](INFO): Moved sent file to Logs/20220809T172553/Express0106.lzma.bak 2022-08-09T20:38:00.714Z,1660077480.714 [DataOverHttps](INFO): SBD MOMSN=17097615 2022-08-09T20:38:04.579Z,1660077484.579 [Default:CheckIn:Read_Iridium] Stopped 2022-08-09T20:38:04.584Z,1660077484.584 [Default:CheckIn:C.Wait] Running Loop=1 2022-08-09T20:38:04.584Z,1660077484.584 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-08-09T20:38:13.841Z,1660077493.841 [NAL9602](INFO): Not Powering down - fast GPS 2022-08-09T20:38:25.973Z,1660077505.973 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2022-08-09T20:38:25.973Z,1660077505.973 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2022-08-09T20:41:54.673Z,1660077714.673 [DataOverHttps](IMPORTANT): SBD MTMSN=20220809T204158 2022-08-09T20:42:02.051Z,1660077722.051 [DataOverHttps](INFO): Received command: restart sys 2022-08-09T20:42:02.094Z,1660077722.094 [CommandExec](IMPORTANT): got command restart system 2022-08-09T20:42:04.192Z,1660077724.192 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-09T20:42:04.192Z,1660077724.192 [CommandExec](INFO): Uninitializing the command executive. 2022-08-09T20:42:04.192Z,1660077724.192 [CommandExec](INFO): Uninitializing the command scheduler. 2022-08-09T20:42:04.193Z,1660077724.193 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:04.328Z,1660077724.328 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-08-09T20:42:04.328Z,1660077724.328 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-08-09T20:42:04.328Z,1660077724.328 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:04.329Z,1660077724.329 [NavChartDb](INFO): Join timeout helper Thread ID is 2180 2022-08-09T20:42:04.656Z,1660077724.656 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-09T20:42:04.656Z,1660077724.656 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:04.672Z,1660077724.672 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-08-09T20:42:04.672Z,1660077724.672 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:04.672Z,1660077724.672 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2181 2022-08-09T20:42:05.048Z,1660077725.048 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-09T20:42:05.048Z,1660077725.048 [WetLabsBB2FL](INFO): Powering down 2022-08-09T20:42:05.049Z,1660077725.049 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:05.060Z,1660077725.060 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2022-08-09T20:42:05.060Z,1660077725.060 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:05.060Z,1660077725.060 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2182 2022-08-09T20:42:05.993Z,1660077725.993 [CTD_Seabird](INFO): Powering down 2022-08-09T20:42:06.008Z,1660077726.008 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-09T20:42:06.009Z,1660077726.009 [CTD_Seabird](INFO): Powering down 2022-08-09T20:42:06.024Z,1660077726.024 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:06.034Z,1660077726.034 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-08-09T20:42:06.034Z,1660077726.034 [DAT ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:06.035Z,1660077726.035 [DAT](INFO): Join timeout helper Thread ID is 2183 2022-08-09T20:42:06.132Z,1660077726.132 [DAT](INFO): Powering down 2022-08-09T20:42:06.205Z,1660077726.205 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-08-09T20:42:06.205Z,1660077726.205 [DAT](INFO): Powering down 2022-08-09T20:42:06.206Z,1660077726.206 [DAT ThreadHandler](INFO): Thread cancelled. 2022-08-09T20:42:06.208Z,166007