2021-10-11T18:17:46.731Z,1633976266.731 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T034638/Courier0084.lzma 2021-10-11T18:17:46.733Z,1633976266.733 [DataOverHttps](INFO): Received command: restart logs 2021-10-11T18:17:46.750Z,1633976266.750 [CommandExec](IMPORTANT): got command restart logs 2021-10-11T18:17:48.102Z,1633976268.102 [DataOverHttps](INFO): Moved sent file to Logs/20211011T034638/Courier0084.lzma.bak 2021-10-11T18:17:48.103Z,1633976268.103 [DataOverHttps](INFO): SBD MOMSN=16010752 2021-10-11T18:18:00.935Z,1633976280.935 [NAL9602](INFO): SBD MO Status=2, MOMSN=16863, MT Status=2, MTMSN=0 2021-10-11T18:18:00.935Z,1633976280.935 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-10-11T18:18:18.419Z,1633976298.419 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211011T034638/Courier0087.lzma 2021-10-11T18:18:19.179Z,1633976299.179 [NAL9602](INFO): SBD MO Status=0, MOMSN=16863, MT Status=0, MTMSN=0 2021-10-11T18:18:19.179Z,1633976299.179 [NAL9602](INFO): No messages in MT queue 2021-10-11T18:18:19.422Z,1633976299.422 [DataOverHttps](INFO): Moved sent file to Logs/20211011T034638/Courier0087.lzma.bak 2021-10-11T18:18:19.422Z,1633976299.422 [DataOverHttps](INFO): SBD MOMSN=16010756 2021-10-11T18:18:37.451Z,1633976317.451 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20211011T034638/Express0085.lzma 2021-10-11T18:18:38.454Z,1633976318.454 [DataOverHttps](INFO): Moved sent file to Logs/20211011T034638/Express0085.lzma.bak 2021-10-11T18:18:38.454Z,1633976318.454 [DataOverHttps](INFO): SBD MOMSN=16010759 2021-10-11T18:18:49.873Z,1633976329.873 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:19:22.269Z,1633976362.269 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-10-11T18:19:51.384Z,1633976391.384 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239464 2021-10-11T18:20:21.783Z,1633976421.783 [NAL9602](INFO): SBD MO Status=1, MOMSN=16864, MT Status=0, MTMSN=0 2021-10-11T18:20:21.840Z,1633976421.840 [NAL9602](INFO): Sent 62 bytes from file Logs/20211011T034638/Express0088.lzma 2021-10-11T18:20:21.840Z,1633976421.840 [NAL9602](INFO): Packets left to send: 0 2021-10-11T18:20:22.508Z,1633976422.508 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-10-11T18:20:31.887Z,1633976431.887 [NAL9602](INFO): SBD MO Status=0, MOMSN=16865, MT Status=0, MTMSN=0 2021-10-11T18:20:31.969Z,1633976431.969 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:20:31.969Z,1633976431.969 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:20:31.970Z,1633976431.970 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T18:20:56.048Z,1633976456.048 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002984 2021-10-11T18:21:02.594Z,1633976462.594 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:25:32.585Z,1633976732.585 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T18:25:32.585Z,1633976732.585 [Default:CheckIn:C.Wait] Stopped 2021-10-11T18:25:32.585Z,1633976732.585 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T18:25:32.586Z,1633976732.586 [Default:CheckIn:D] Running Loop=1 2021-10-11T18:25:32.956Z,1633976732.956 [Default:CheckIn:D] Stopped 2021-10-11T18:25:32.956Z,1633976732.956 [Default:CheckIn:E] Running Loop=1 2021-10-11T18:25:33.354Z,1633976733.354 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.176188 min 2021-10-11T18:25:33.354Z,1633976733.354 [Default:CheckIn:E] Stopped 2021-10-11T18:25:33.354Z,1633976733.354 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T18:25:33.355Z,1633976733.355 [Default:CheckIn] Stopped 2021-10-11T18:25:33.355Z,1633976733.355 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T18:25:33.355Z,1633976733.355 [Default:CheckIn](INFO): Running loop #8 2021-10-11T18:25:33.355Z,1633976733.355 [Default:CheckIn] Running Loop=8 2021-10-11T18:25:33.355Z,1633976733.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T18:25:33.355Z,1633976733.355 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T18:25:35.363Z,1633976735.363 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182538.00,A,3648.43564,N,12147.11979,W,4.296,179.44,111021,,,D*77 2021-10-11T18:25:35.365Z,1633976735.365 [NAL9602](INFO): GPS fix at 20211011T182538: (36.807261, -121.785330) 2021-10-11T18:25:35.404Z,1633976735.404 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T18:25:35.404Z,1633976735.404 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T18:25:44.388Z,1633976744.388 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20211011T181746/Courier0003.lzma 2021-10-11T18:25:45.389Z,1633976745.389 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0003.lzma.bak 2021-10-11T18:25:45.389Z,1633976745.389 [DataOverHttps](INFO): SBD MOMSN=16010812 2021-10-11T18:26:08.968Z,1633976768.968 [DataOverHttps](INFO): Sending 396 bytes from file Logs/20211011T181746/Express0004.lzma 2021-10-11T18:26:09.969Z,1633976769.969 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0004.lzma.bak 2021-10-11T18:26:09.970Z,1633976769.970 [DataOverHttps](INFO): SBD MOMSN=16010816 2021-10-11T18:26:13.845Z,1633976773.845 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:26:13.846Z,1633976773.846 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:26:13.846Z,1633976773.846 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T18:27:13.612Z,1633976833.612 [NAL9602](INFO): SBD MO Status=2, MOMSN=16866, MT Status=2, MTMSN=0 2021-10-11T18:27:13.612Z,1633976833.612 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-10-11T18:27:41.891Z,1633976861.891 [NAL9602](INFO): SBD MO Status=2, MOMSN=16866, MT Status=2, MTMSN=0 2021-10-11T18:27:41.891Z,1633976861.891 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-10-11T18:28:10.591Z,1633976890.591 [NAL9602](INFO): SBD MO Status=0, MOMSN=16866, MT Status=0, MTMSN=0 2021-10-11T18:28:10.591Z,1633976890.591 [NAL9602](INFO): No messages in MT queue 2021-10-11T18:28:41.279Z,1633976921.279 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:31:14.516Z,1633977074.516 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T18:31:14.516Z,1633977074.516 [Default:CheckIn:C.Wait] Stopped 2021-10-11T18:31:14.517Z,1633977074.517 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T18:31:14.517Z,1633977074.517 [Default:CheckIn:D] Running Loop=1 2021-10-11T18:31:14.908Z,1633977074.908 [Default:CheckIn:D] Stopped 2021-10-11T18:31:14.908Z,1633977074.908 [Default:CheckIn:E] Running Loop=1 2021-10-11T18:31:15.293Z,1633977075.293 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.875387 min 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn:E] Stopped 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn] Stopped 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn](INFO): Running loop #9 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn] Running Loop=9 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T18:31:15.294Z,1633977075.294 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T18:31:17.299Z,1633977077.299 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183120.00,A,3648.11722,N,12147.21028,W,1.672,231.52,111021,,,D*71 2021-10-11T18:31:17.302Z,1633977077.302 [NAL9602](INFO): GPS fix at 20211011T183120: (36.801954, -121.786838) 2021-10-11T18:31:17.337Z,1633977077.337 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T18:31:17.337Z,1633977077.337 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T18:31:26.191Z,1633977086.191 [NAL9602](INFO): SBD MO Status=0, MOMSN=16867, MT Status=0, MTMSN=0 2021-10-11T18:31:26.191Z,1633977086.191 [NAL9602](INFO): No messages in MT queue 2021-10-11T18:31:26.427Z,1633977086.427 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211011T181746/Courier0006.lzma 2021-10-11T18:31:27.441Z,1633977087.441 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0006.lzma.bak 2021-10-11T18:31:27.442Z,1633977087.442 [DataOverHttps](INFO): SBD MOMSN=16010821 2021-10-11T18:31:46.891Z,1633977106.891 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20211011T181746/Express0007.lzma 2021-10-11T18:31:47.893Z,1633977107.893 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0007.lzma.bak 2021-10-11T18:31:47.893Z,1633977107.893 [DataOverHttps](INFO): SBD MOMSN=16010824 2021-10-11T18:31:50.864Z,1633977110.864 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:31:50.865Z,1633977110.865 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:31:50.865Z,1633977110.865 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T18:31:56.893Z,1633977116.893 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:36:51.481Z,1633977411.481 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T18:36:51.482Z,1633977411.482 [Default:CheckIn:C.Wait] Stopped 2021-10-11T18:36:51.482Z,1633977411.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T18:36:51.482Z,1633977411.482 [Default:CheckIn:D] Running Loop=1 2021-10-11T18:36:51.885Z,1633977411.885 [Default:CheckIn:D] Stopped 2021-10-11T18:36:51.885Z,1633977411.885 [Default:CheckIn:E] Running Loop=1 2021-10-11T18:36:52.317Z,1633977412.317 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.491667 min 2021-10-11T18:36:52.317Z,1633977412.317 [Default:CheckIn:E] Stopped 2021-10-11T18:36:52.318Z,1633977412.318 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T18:36:52.318Z,1633977412.318 [Default:CheckIn] Stopped 2021-10-11T18:36:52.318Z,1633977412.318 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T18:36:52.319Z,1633977412.319 [Default:CheckIn](INFO): Running loop #10 2021-10-11T18:36:52.319Z,1633977412.319 [Default:CheckIn] Running Loop=10 2021-10-11T18:36:52.320Z,1633977412.320 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T18:36:52.320Z,1633977412.320 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T18:36:54.330Z,1633977414.330 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183657.00,A,3648.11935,N,12147.22382,W,0.739,155.87,111021,,,A*7D 2021-10-11T18:36:54.336Z,1633977414.336 [NAL9602](INFO): GPS fix at 20211011T183657: (36.801989, -121.787064) 2021-10-11T18:36:54.396Z,1633977414.396 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T18:36:54.397Z,1633977414.397 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T18:37:04.387Z,1633977424.387 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T181746/Courier0009.lzma 2021-10-11T18:37:05.910Z,1633977425.910 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0009.lzma.bak 2021-10-11T18:37:05.910Z,1633977425.910 [DataOverHttps](INFO): SBD MOMSN=16010866 2021-10-11T18:37:23.786Z,1633977443.786 [NAL9602](INFO): SBD MO Status=0, MOMSN=16868, MT Status=0, MTMSN=0 2021-10-11T18:37:23.787Z,1633977443.787 [NAL9602](INFO): No messages in MT queue 2021-10-11T18:37:23.819Z,1633977443.819 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211011T181746/Express0010.lzma 2021-10-11T18:37:24.821Z,1633977444.821 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0010.lzma.bak 2021-10-11T18:37:24.822Z,1633977444.822 [DataOverHttps](INFO): SBD MOMSN=16010869 2021-10-11T18:37:27.839Z,1633977447.839 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:37:27.840Z,1633977447.840 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:37:27.840Z,1633977447.840 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T18:37:54.494Z,1633977474.494 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:42:28.558Z,1633977748.558 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T18:42:28.558Z,1633977748.558 [Default:CheckIn:C.Wait] Stopped 2021-10-11T18:42:28.558Z,1633977748.558 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T18:42:28.558Z,1633977748.558 [Default:CheckIn:D] Running Loop=1 2021-10-11T18:42:28.916Z,1633977748.916 [Default:CheckIn:D] Stopped 2021-10-11T18:42:28.916Z,1633977748.916 [Default:CheckIn:E] Running Loop=1 2021-10-11T18:42:29.293Z,1633977749.293 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.108850 min 2021-10-11T18:42:29.293Z,1633977749.293 [Default:CheckIn:E] Stopped 2021-10-11T18:42:29.293Z,1633977749.293 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T18:42:29.293Z,1633977749.293 [Default:CheckIn] Stopped 2021-10-11T18:42:29.293Z,1633977749.293 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T18:42:29.294Z,1633977749.294 [Default:CheckIn](INFO): Running loop #11 2021-10-11T18:42:29.294Z,1633977749.294 [Default:CheckIn] Running Loop=11 2021-10-11T18:42:29.294Z,1633977749.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T18:42:29.294Z,1633977749.294 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T18:42:31.336Z,1633977751.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184234.00,A,3648.11875,N,12147.23147,W,0.175,155.87,111021,,,A*7A 2021-10-11T18:42:31.338Z,1633977751.338 [NAL9602](INFO): GPS fix at 20211011T184234: (36.801979, -121.787191) 2021-10-11T18:42:31.470Z,1633977751.470 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T18:42:31.471Z,1633977751.471 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T18:42:40.259Z,1633977760.259 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T181746/Courier0012.lzma 2021-10-11T18:42:41.257Z,1633977761.257 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0012.lzma.bak 2021-10-11T18:42:41.257Z,1633977761.257 [DataOverHttps](INFO): SBD MOMSN=16010876 2021-10-11T18:42:55.138Z,1633977775.138 [NAL9602](INFO): SBD MO Status=2, MOMSN=16869, MT Status=2, MTMSN=0 2021-10-11T18:42:55.139Z,1633977775.139 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-10-11T18:42:59.691Z,1633977779.691 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20211011T181746/Express0013.lzma 2021-10-11T18:43:00.693Z,1633977780.693 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0013.lzma.bak 2021-10-11T18:43:00.694Z,1633977780.694 [DataOverHttps](INFO): SBD MOMSN=16010880 2021-10-11T18:43:03.640Z,1633977783.640 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:43:03.640Z,1633977783.640 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:43:03.641Z,1633977783.641 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T18:43:04.440Z,1633977784.440 [NAL9602](INFO): SBD MO Status=0, MOMSN=16869, MT Status=0, MTMSN=0 2021-10-11T18:43:04.440Z,1633977784.440 [NAL9602](INFO): No messages in MT queue 2021-10-11T18:43:35.133Z,1633977815.133 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:48:04.355Z,1633978084.355 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T18:48:04.377Z,1633978084.377 [Default:CheckIn:C.Wait] Stopped 2021-10-11T18:48:04.377Z,1633978084.377 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T18:48:04.378Z,1633978084.378 [Default:CheckIn:D] Running Loop=1 2021-10-11T18:48:04.791Z,1633978084.791 [Default:CheckIn:D] Stopped 2021-10-11T18:48:04.791Z,1633978084.791 [Default:CheckIn:E] Running Loop=1 2021-10-11T18:48:05.149Z,1633978085.149 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.706763 min 2021-10-11T18:48:05.149Z,1633978085.149 [Default:CheckIn:E] Stopped 2021-10-11T18:48:05.150Z,1633978085.150 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T18:48:05.150Z,1633978085.150 [Default:CheckIn] Stopped 2021-10-11T18:48:05.150Z,1633978085.150 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T18:48:05.150Z,1633978085.150 [Default:CheckIn](INFO): Running loop #12 2021-10-11T18:48:05.150Z,1633978085.150 [Default:CheckIn] Running Loop=12 2021-10-11T18:48:05.150Z,1633978085.150 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T18:48:05.150Z,1633978085.150 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T18:48:07.103Z,1633978087.103 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184810.00,A,3648.17348,N,12147.27486,W,2.760,291.01,111021,,,D*79 2021-10-11T18:48:07.106Z,1633978087.106 [NAL9602](INFO): GPS fix at 20211011T184810: (36.802891, -121.787914) 2021-10-11T18:48:07.174Z,1633978087.174 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T18:48:07.174Z,1633978087.174 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T18:48:11.635Z,1633978091.635 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T181746/Courier0015.lzma 2021-10-11T18:48:12.650Z,1633978092.650 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0015.lzma.bak 2021-10-11T18:48:12.650Z,1633978092.650 [DataOverHttps](INFO): SBD MOMSN=16010929 2021-10-11T18:48:30.899Z,1633978110.899 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211011T181746/Express0016.lzma 2021-10-11T18:48:31.901Z,1633978111.901 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0016.lzma.bak 2021-10-11T18:48:31.902Z,1633978111.902 [DataOverHttps](INFO): SBD MOMSN=16010932 2021-10-11T18:48:34.958Z,1633978114.958 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:48:34.958Z,1633978114.958 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:48:34.959Z,1633978114.959 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T18:49:33.483Z,1633978173.483 [NAL9602](INFO): SBD MO Status=0, MOMSN=16870, MT Status=0, MTMSN=0 2021-10-11T18:49:33.483Z,1633978173.483 [NAL9602](INFO): No messages in MT queue 2021-10-11T18:50:04.246Z,1633978204.246 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:53:35.556Z,1633978415.556 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T18:53:35.556Z,1633978415.556 [Default:CheckIn:C.Wait] Stopped 2021-10-11T18:53:35.556Z,1633978415.556 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T18:53:35.557Z,1633978415.557 [Default:CheckIn:D] Running Loop=1 2021-10-11T18:53:35.958Z,1633978415.958 [Default:CheckIn:D] Stopped 2021-10-11T18:53:35.958Z,1633978415.958 [Default:CheckIn:E] Running Loop=1 2021-10-11T18:53:36.393Z,1633978416.393 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.226221 min 2021-10-11T18:53:36.393Z,1633978416.393 [Default:CheckIn:E] Stopped 2021-10-11T18:53:36.393Z,1633978416.393 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T18:53:36.393Z,1633978416.393 [Default:CheckIn] Stopped 2021-10-11T18:53:36.393Z,1633978416.393 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T18:53:36.393Z,1633978416.393 [Default:CheckIn](INFO): Running loop #13 2021-10-11T18:53:36.393Z,1633978416.393 [Default:CheckIn] Running Loop=13 2021-10-11T18:53:36.394Z,1633978416.394 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T18:53:36.394Z,1633978416.394 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T18:53:38.375Z,1633978418.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185341.00,A,3648.16760,N,12147.28029,W,0.175,157.79,111021,,,A*75 2021-10-11T18:53:38.378Z,1633978418.378 [NAL9602](INFO): GPS fix at 20211011T185341: (36.802793, -121.788005) 2021-10-11T18:53:38.430Z,1633978418.430 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T18:53:38.430Z,1633978418.430 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T18:53:46.947Z,1633978426.947 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T181746/Courier0018.lzma 2021-10-11T18:53:47.949Z,1633978427.949 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0018.lzma.bak 2021-10-11T18:53:47.950Z,1633978427.950 [DataOverHttps](INFO): SBD MOMSN=16010938 2021-10-11T18:54:09.207Z,1633978449.207 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20211011T181746/Express0019.lzma 2021-10-11T18:54:10.209Z,1633978450.209 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0019.lzma.bak 2021-10-11T18:54:10.210Z,1633978450.210 [DataOverHttps](INFO): SBD MOMSN=16010941 2021-10-11T18:54:16.045Z,1633978456.045 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:54:16.045Z,1633978456.045 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:54:16.045Z,1633978456.045 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T18:58:40.338Z,1633978720.338 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-10-11T18:59:10.985Z,1633978750.985 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T18:59:16.722Z,1633978756.722 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T18:59:16.722Z,1633978756.722 [Default:CheckIn:C.Wait] Stopped 2021-10-11T18:59:16.722Z,1633978756.722 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T18:59:16.723Z,1633978756.723 [Default:CheckIn:D] Running Loop=1 2021-10-11T18:59:17.060Z,1633978757.060 [Default:CheckIn:D] Stopped 2021-10-11T18:59:17.061Z,1633978757.061 [Default:CheckIn:E] Running Loop=1 2021-10-11T18:59:17.473Z,1633978757.473 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.911263 min 2021-10-11T18:59:17.473Z,1633978757.473 [Default:CheckIn:E] Stopped 2021-10-11T18:59:17.473Z,1633978757.473 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T18:59:17.473Z,1633978757.473 [Default:CheckIn] Stopped 2021-10-11T18:59:17.473Z,1633978757.473 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T18:59:17.473Z,1633978757.473 [Default:CheckIn](INFO): Running loop #14 2021-10-11T18:59:17.474Z,1633978757.474 [Default:CheckIn] Running Loop=14 2021-10-11T18:59:17.474Z,1633978757.474 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T18:59:17.474Z,1633978757.474 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T18:59:19.476Z,1633978759.476 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185922.00,A,3648.17413,N,12147.28278,W,0.330,47.38,111021,,,A*4C 2021-10-11T18:59:19.478Z,1633978759.478 [NAL9602](INFO): GPS fix at 20211011T185922: (36.802902, -121.788046) 2021-10-11T18:59:19.514Z,1633978759.514 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T18:59:19.514Z,1633978759.514 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T18:59:28.285Z,1633978768.285 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T181746/Courier0021.lzma 2021-10-11T18:59:29.281Z,1633978769.281 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0021.lzma.bak 2021-10-11T18:59:29.282Z,1633978769.282 [DataOverHttps](INFO): SBD MOMSN=16010994 2021-10-11T18:59:48.707Z,1633978788.707 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20211011T181746/Express0022.lzma 2021-10-11T18:59:49.709Z,1633978789.709 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0022.lzma.bak 2021-10-11T18:59:49.710Z,1633978789.710 [DataOverHttps](INFO): SBD MOMSN=16010997 2021-10-11T18:59:50.179Z,1633978790.179 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-10-11T18:59:50.252Z,1633978790.252 [NAL9602](ERROR): received: +CSQ:0 OK870, 0, 0, 0, 0 OK 2021-10-11T18:59:52.695Z,1633978792.695 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T18:59:52.695Z,1633978792.695 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T18:59:52.703Z,1633978792.703 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T19:04:21.329Z,1633979061.329 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-10-11T19:04:52.005Z,1633979092.005 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T19:04:53.248Z,1633979093.248 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T19:04:53.249Z,1633979093.249 [Default:CheckIn:C.Wait] Stopped 2021-10-11T19:04:53.249Z,1633979093.249 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T19:04:53.250Z,1633979093.250 [Default:CheckIn:D] Running Loop=1 2021-10-11T19:04:53.657Z,1633979093.657 [Default:CheckIn:D] Stopped 2021-10-11T19:04:53.657Z,1633979093.657 [Default:CheckIn:E] Running Loop=1 2021-10-11T19:04:54.076Z,1633979094.076 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.521208 min 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn:E] Stopped 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn] Stopped 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn](INFO): Running loop #15 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn] Running Loop=15 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T19:04:54.077Z,1633979094.077 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T19:04:56.045Z,1633979096.045 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190459.00,A,3648.16639,N,12147.27984,W,0.447,299.07,111021,,,A*7F 2021-10-11T19:04:56.047Z,1633979096.047 [NAL9602](INFO): GPS fix at 20211011T190459: (36.802773, -121.787997) 2021-10-11T19:04:56.060Z,1633979096.060 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T19:04:56.060Z,1633979096.060 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T19:05:05.044Z,1633979105.044 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T181746/Courier0024.lzma 2021-10-11T19:05:06.046Z,1633979106.046 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0024.lzma.bak 2021-10-11T19:05:06.046Z,1633979106.046 [DataOverHttps](INFO): SBD MOMSN=16011001 2021-10-11T19:05:24.207Z,1633979124.207 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20211011T181746/Express0025.lzma 2021-10-11T19:05:25.210Z,1633979125.210 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0025.lzma.bak 2021-10-11T19:05:25.210Z,1633979125.210 [DataOverHttps](INFO): SBD MOMSN=16011004 2021-10-11T19:05:28.110Z,1633979128.110 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T19:05:28.110Z,1633979128.110 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T19:05:28.111Z,1633979128.111 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T19:05:29.696Z,1633979129.696 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-10-11T19:05:29.696Z,1633979129.696 [DropWeight] Hardware Fault, FailCount= 1 2021-10-11T19:05:29.697Z,1633979129.697 [DropWeight](ERROR): Hardware Fault 2021-10-11T19:05:29.727Z,1633979129.727 [CommandExec](FAULT): Scheduling is paused 2021-10-11T19:05:29.728Z,1633979129.728 [CBIT](INFO): Critical error at 20211011T190529 2021-10-11T19:05:29.733Z,1633979129.733 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-10-11T19:05:29.733Z,1633979129.733 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-10-11T19:05:30.132Z,1633979130.132 [CBIT](INFO): Critical error at 20211011T190529 2021-10-11T19:09:03.495Z,1633979343.495 [NAL9602](INFO): SBD MO Status=2, MOMSN=16871, MT Status=2, MTMSN=0 2021-10-11T19:09:03.495Z,1633979343.495 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-10-11T19:09:41.874Z,1633979381.874 [NAL9602](INFO): SBD MO Status=2, MOMSN=16871, MT Status=2, MTMSN=0 2021-10-11T19:09:41.875Z,1633979381.875 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-10-11T19:09:58.437Z,1633979398.437 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-10-11T19:10:28.748Z,1633979428.748 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T19:10:28.748Z,1633979428.748 [Default:CheckIn:C.Wait] Stopped 2021-10-11T19:10:28.748Z,1633979428.748 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T19:10:28.749Z,1633979428.749 [Default:CheckIn:D] Running Loop=1 2021-10-11T19:10:29.142Z,1633979429.142 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T19:10:29.156Z,1633979429.156 [Default:CheckIn:D] Stopped 2021-10-11T19:10:29.156Z,1633979429.156 [Default:CheckIn:E] Running Loop=1 2021-10-11T19:10:29.568Z,1633979429.568 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.112850 min 2021-10-11T19:10:29.569Z,1633979429.569 [Default:CheckIn:E] Stopped 2021-10-11T19:10:29.569Z,1633979429.569 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T19:10:29.569Z,1633979429.569 [Default:CheckIn] Stopped 2021-10-11T19:10:29.569Z,1633979429.569 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T19:10:29.569Z,1633979429.569 [Default:CheckIn](INFO): Running loop #16 2021-10-11T19:10:29.569Z,1633979429.569 [Default:CheckIn] Running Loop=16 2021-10-11T19:10:29.569Z,1633979429.569 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T19:10:29.570Z,1633979429.570 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T19:10:31.567Z,1633979431.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191034.00,A,3648.16665,N,12147.28205,W,0.486,171.59,111021,,,A*76 2021-10-11T19:10:31.569Z,1633979431.569 [NAL9602](INFO): GPS fix at 20211011T191034: (36.802777, -121.788034) 2021-10-11T19:10:31.589Z,1633979431.589 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T19:10:31.589Z,1633979431.589 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T19:10:40.351Z,1633979440.351 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20211011T181746/Courier0027.lzma 2021-10-11T19:10:41.353Z,1633979441.353 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0027.lzma.bak 2021-10-11T19:10:41.354Z,1633979441.354 [DataOverHttps](INFO): SBD MOMSN=16011053 2021-10-11T19:10:59.540Z,1633979459.540 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20211011T181746/Express0028.lzma 2021-10-11T19:11:00.541Z,1633979460.541 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0028.lzma.bak 2021-10-11T19:11:00.542Z,1633979460.542 [DataOverHttps](INFO): SBD MOMSN=16011058 2021-10-11T19:11:02.085Z,1633979462.085 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-10-11T19:11:02.168Z,1633979462.168 [NAL9602](ERROR): received: +CSQ:0 OK871, 2, 0, 0, 0 OK 2021-10-11T19:11:03.728Z,1633979463.728 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T19:11:03.728Z,1633979463.728 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T19:11:03.728Z,1633979463.728 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T19:15:34.449Z,1633979734.449 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-10-11T19:16:04.250Z,1633979764.250 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T19:16:04.250Z,1633979764.250 [Default:CheckIn:C.Wait] Stopped 2021-10-11T19:16:04.251Z,1633979764.251 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T19:16:04.256Z,1633979764.256 [Default:CheckIn:D] Running Loop=1 2021-10-11T19:16:04.704Z,1633979764.704 [Default:CheckIn:D] Stopped 2021-10-11T19:16:04.704Z,1633979764.704 [Default:CheckIn:E] Running Loop=1 2021-10-11T19:16:04.868Z,1633979764.868 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T19:16:04.948Z,1633979764.948 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.705314 min 2021-10-11T19:16:04.948Z,1633979764.948 [Default:CheckIn:E] Stopped 2021-10-11T19:16:04.949Z,1633979764.949 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T19:16:04.949Z,1633979764.949 [Default:CheckIn] Stopped 2021-10-11T19:16:04.949Z,1633979764.949 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T19:16:04.949Z,1633979764.949 [Default:CheckIn](INFO): Running loop #17 2021-10-11T19:16:04.949Z,1633979764.949 [Default:CheckIn] Running Loop=17 2021-10-11T19:16:04.949Z,1633979764.949 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T19:16:04.949Z,1633979764.949 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T19:16:06.839Z,1633979766.839 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191610.00,A,3648.16773,N,12147.27451,W,0.816,83.11,111021,,,A*4D 2021-10-11T19:16:06.842Z,1633979766.842 [NAL9602](INFO): GPS fix at 20211011T191610: (36.802796, -121.787909) 2021-10-11T19:16:06.954Z,1633979766.954 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T19:16:06.954Z,1633979766.954 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T19:16:10.628Z,1633979770.628 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20211011T181746/Courier0030.lzma 2021-10-11T19:16:11.634Z,1633979771.634 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0030.lzma.bak 2021-10-11T19:16:11.634Z,1633979771.634 [DataOverHttps](INFO): SBD MOMSN=16011063 2021-10-11T19:16:30.331Z,1633979790.331 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20211011T181746/Express0031.lzma 2021-10-11T19:16:31.333Z,1633979791.333 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0031.lzma.bak 2021-10-11T19:16:31.334Z,1633979791.334 [DataOverHttps](INFO): SBD MOMSN=16011066 2021-10-11T19:16:34.434Z,1633979794.434 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T19:16:34.435Z,1633979794.435 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T19:16:34.435Z,1633979794.435 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T19:18:31.781Z,1633979911.781 [BPC1](INFO): Calculating totals. Valid battery stick count: 50. Valid reserve battery stick count: 6. 2021-10-11T19:18:31.792Z,1633979911.792 [BPC1](INFO): Received data from all battery sticks. 2021-10-11T19:20:29.791Z,1633980029.791 [CBIT](INFO): Clearing failed state for component DropWeight 2021-10-11T19:20:29.791Z,1633980029.791 [DropWeight] No Fault, FailCount= 1 2021-10-11T19:21:09.321Z,1633980069.321 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-10-11T19:21:35.197Z,1633980095.197 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T19:21:35.197Z,1633980095.197 [Default:CheckIn:C.Wait] Stopped 2021-10-11T19:21:35.197Z,1633980095.197 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T19:21:35.197Z,1633980095.197 [Default:CheckIn:D] Running Loop=1 2021-10-11T19:21:35.597Z,1633980095.597 [Default:CheckIn:D] Stopped 2021-10-11T19:21:35.597Z,1633980095.597 [Default:CheckIn:E] Running Loop=1 2021-10-11T19:21:36.004Z,1633980096.004 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.220207 min 2021-10-11T19:21:36.004Z,1633980096.004 [Default:CheckIn:E] Stopped 2021-10-11T19:21:36.004Z,1633980096.004 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T19:21:36.004Z,1633980096.004 [Default:CheckIn] Stopped 2021-10-11T19:21:36.004Z,1633980096.004 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T19:21:36.005Z,1633980096.005 [Default:CheckIn](INFO): Running loop #18 2021-10-11T19:21:36.005Z,1633980096.005 [Default:CheckIn] Running Loop=18 2021-10-11T19:21:36.005Z,1633980096.005 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T19:21:36.005Z,1633980096.005 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T19:21:38.007Z,1633980098.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192141.00,A,3648.16267,N,12147.28806,W,0.019,192.33,111021,,,A*7A 2021-10-11T19:21:38.009Z,1633980098.009 [NAL9602](INFO): GPS fix at 20211011T192141: (36.802711, -121.788134) 2021-10-11T19:21:38.022Z,1633980098.022 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T19:21:38.022Z,1633980098.022 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T19:21:46.639Z,1633980106.639 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20211011T181746/Courier0033.lzma 2021-10-11T19:21:47.641Z,1633980107.641 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0033.lzma.bak 2021-10-11T19:21:47.642Z,1633980107.642 [DataOverHttps](INFO): SBD MOMSN=16011097 2021-10-11T19:22:08.857Z,1633980128.857 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20211011T181746/Express0034.lzma 2021-10-11T19:22:09.858Z,1633980129.858 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0034.lzma.bak 2021-10-11T19:22:09.858Z,1633980129.858 [DataOverHttps](INFO): SBD MOMSN=16011100 2021-10-11T19:22:10.481Z,1633980130.481 [NAL9602](INFO): Not Powering down - fast GPS 2021-10-11T19:22:14.589Z,1633980134.589 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T19:22:14.589Z,1633980134.589 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T19:22:14.589Z,1633980134.589 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T19:27:15.152Z,1633980435.152 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-10-11T19:27:15.152Z,1633980435.152 [Default:CheckIn:C.Wait] Stopped 2021-10-11T19:27:15.152Z,1633980435.152 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T19:27:15.153Z,1633980435.153 [Default:CheckIn:D] Running Loop=1 2021-10-11T19:27:15.561Z,1633980435.561 [Default:CheckIn:D] Stopped 2021-10-11T19:27:15.561Z,1633980435.561 [Default:CheckIn:E] Running Loop=1 2021-10-11T19:27:15.944Z,1633980435.944 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.886271 min 2021-10-11T19:27:15.944Z,1633980435.944 [Default:CheckIn:E] Stopped 2021-10-11T19:27:15.944Z,1633980435.944 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-10-11T19:27:15.944Z,1633980435.944 [Default:CheckIn] Stopped 2021-10-11T19:27:15.944Z,1633980435.944 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T19:27:15.945Z,1633980435.945 [Default:CheckIn](INFO): Running loop #19 2021-10-11T19:27:15.945Z,1633980435.945 [Default:CheckIn] Running Loop=19 2021-10-11T19:27:15.945Z,1633980435.945 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-10-11T19:27:15.945Z,1633980435.945 [Default:CheckIn:Read_GPS] Running Loop=1 2021-10-11T19:27:17.956Z,1633980437.956 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192721.00,A,3648.16526,N,12147.28101,W,1.147,192.33,111021,,,A*7D 2021-10-11T19:27:17.958Z,1633980437.958 [NAL9602](INFO): GPS fix at 20211011T192721: (36.802754, -121.788017) 2021-10-11T19:27:18.008Z,1633980438.008 [Default:CheckIn:Read_GPS] Stopped 2021-10-11T19:27:18.008Z,1633980438.008 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-10-11T19:27:20.385Z,1633980440.385 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20211011T181746/Courier0036.lzma 2021-10-11T19:27:21.389Z,1633980441.389 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Courier0036.lzma.bak 2021-10-11T19:27:21.390Z,1633980441.390 [DataOverHttps](INFO): SBD MOMSN=16011104 2021-10-11T19:27:39.915Z,1633980459.915 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20211011T181746/Express0037.lzma 2021-10-11T19:27:40.917Z,1633980460.917 [DataOverHttps](INFO): Moved sent file to Logs/20211011T181746/Express0037.lzma.bak 2021-10-11T19:27:40.918Z,1633980460.918 [DataOverHttps](INFO): SBD MOMSN=16011111 2021-10-11T19:27:43.913Z,1633980463.913 [Default:CheckIn:Read_Iridium] Stopped 2021-10-11T19:27:43.913Z,1633980463.913 [Default:CheckIn:C.Wait] Running Loop=1 2021-10-11T19:27:43.913Z,1633980463.913 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-10-11T19:27:48.721Z,1633980468.721 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-10-11T19:27:48.796Z,1633980468.796 [NAL9602](ERROR): received: +CSQ:0 OK871, 2, 0, 0, 0 OK 2021-10-11T19:28:21.816Z,1633980501.816 [CommandExec](IMPORTANT): got command quit 2021-10-11T19:28:22.820Z,1633980502.820 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:22.820Z,1633980502.820 [CommandExec](INFO): Uninitializing the command executive. 2021-10-11T19:28:22.820Z,1633980502.820 [CommandExec](INFO): Uninitializing the command scheduler. 2021-10-11T19:28:22.820Z,1633980502.820 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:22.827Z,1633980502.827 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-10-11T19:28:22.828Z,1633980502.828 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-10-11T19:28:22.828Z,1633980502.828 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:22.828Z,1633980502.828 [NavChartDb](INFO): Join timeout helper Thread ID is 5644 2021-10-11T19:28:23.156Z,1633980503.156 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:23.156Z,1633980503.156 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.167Z,1633980503.167 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2021-10-11T19:28:23.167Z,1633980503.167 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.176Z,1633980503.176 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 5645 2021-10-11T19:28:23.568Z,1633980503.568 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:23.568Z,1633980503.568 [WetLabsUBAT](INFO): Powering down 2021-10-11T19:28:23.569Z,1633980503.569 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.569Z,1633980503.569 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-10-11T19:28:23.569Z,1633980503.569 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.570Z,1633980503.570 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5646 2021-10-11T19:28:23.624Z,1633980503.624 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:23.624Z,1633980503.624 [WetLabsBB2FL](INFO): Powering down 2021-10-11T19:28:23.625Z,1633980503.625 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.628Z,1633980503.628 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-10-11T19:28:23.628Z,1633980503.628 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.628Z,1633980503.628 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5647 2021-10-11T19:28:23.740Z,1633980503.740 [CTD_Seabird](INFO): Powering down 2021-10-11T19:28:23.752Z,1633980503.752 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:23.752Z,1633980503.752 [CTD_Seabird](INFO): Powering down 2021-10-11T19:28:23.763Z,1633980503.763 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.780Z,1633980503.780 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-10-11T19:28:23.780Z,1633980503.780 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.780Z,1633980503.780 [Radio_Surface](INFO): Join timeout helper Thread ID is 5648 2021-10-11T19:28:23.972Z,1633980503.972 [Radio_Surface](INFO): Powering down 2021-10-11T19:28:23.973Z,1633980503.973 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:23.973Z,1633980503.973 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.984Z,1633980503.984 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-10-11T19:28:23.985Z,1633980503.985 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:23.985Z,1633980503.985 [Onboard](INFO): Join timeout helper Thread ID is 5649 2021-10-11T19:28:24.064Z,1633980504.064 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2021-10-11T19:28:27.536Z,1633980507.536 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:27.536Z,1633980507.536 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:27.537Z,1633980507.537 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-10-11T19:28:27.537Z,1633980507.537 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:27.538Z,1633980507.538 [DataOverHttps](INFO): Join timeout helper Thread ID is 5650 2021-10-11T19:28:28.080Z,1633980508.080 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:28.080Z,1633980508.080 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.088Z,1633980508.088 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2021-10-11T19:28:28.088Z,1633980508.088 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.089Z,1633980508.089 [BackseatComponent](INFO): Join timeout helper Thread ID is 5651 2021-10-11T19:28:28.132Z,1633980508.132 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:28.132Z,1633980508.132 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.140Z,1633980508.140 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-10-11T19:28:28.140Z,1633980508.140 [logger ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.141Z,1633980508.141 [logger](INFO): Join timeout helper Thread ID is 5652 2021-10-11T19:28:28.157Z,1633980508.157 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:28.157Z,1633980508.157 [logger ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.172Z,1633980508.172 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-10-11T19:28:28.172Z,1633980508.172 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.173Z,1633980508.173 [CommandLine](INFO): Join timeout helper Thread ID is 5653 2021-10-11T19:28:28.208Z,1633980508.208 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:28.208Z,1633980508.208 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.212Z,1633980508.212 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2021-10-11T19:28:28.212Z,1633980508.212 [CommandExec ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.213Z,1633980508.213 [CommandExec](INFO): Join timeout helper Thread ID is 5654 2021-10-11T19:28:28.214Z,1633980508.214 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-10-11T19:28:28.214Z,1633980508.214 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.214Z,1633980508.214 [controlThread](INFO): Join timeout helper Thread ID is 5655 2021-10-11T19:28:28.293Z,1633980508.293 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-10-11T19:28:28.294Z,1633980508.294 [controlThread](DEBUG): Uninitializing ControlThread 2021-10-11T19:28:28.296Z,1633980508.296 [AHRS_M2](INFO): Powering down 2021-10-11T19:28:28.368Z,1633980508.368 [NAL9602](INFO): Powering down 2021-10-11T19:28:28.440Z,1633980508.440 [RDI_Pathfinder](INFO): Powering down 2021-10-11T19:28:28.441Z,1633980508.441 [DAT](INFO): Powering down 2021-10-11T19:28:28.513Z,1633980508.513 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-10-11T19:28:28.514Z,1633980508.514 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-10-11T19:28:28.514Z,1633980508.514 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-10-11T19:28:28.515Z,1633980508.515 [MissionManager](INFO): Uninitializing Mission Default 2021-10-11T19:28:28.515Z,1633980508.515 [Default] Stopped 2021-10-11T19:28:28.515Z,1633980508.515 [Default](DEBUG): Aggregate::uninitialize Default 2021-10-11T19:28:28.515Z,1633980508.515 [Default:B.GoToSurface] Stopped 2021-10-11T19:28:28.515Z,1633980508.515 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-10-11T19:28:28.515Z,1633980508.515 [Default:CheckIn] Stopped 2021-10-11T19:28:28.515Z,1633980508.515 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-10-11T19:28:28.515Z,1633980508.515 [Default:CheckIn:C.Wait] Stopped 2021-10-11T19:28:28.516Z,1633980508.516 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-10-11T19:28:28.519Z,1633980508.519 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-10-11T19:28:28.519Z,1633980508.519 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-10-11T19:28:28.520Z,1633980508.520 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-10-11T19:28:28.520Z,1633980508.520 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-10-11T19:28:28.520Z,1633980508.520 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-10-11T19:28:28.520Z,1633980508.520 [BuoyancyServo](INFO): Powering down 2021-10-11T19:28:28.532Z,1633980508.532 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-10-11T19:28:28.532Z,1633980508.532 [ElevatorServo](INFO): Powering down 2021-10-11T19:28:28.533Z,1633980508.533 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-10-11T19:28:28.533Z,1633980508.533 [MassServo](INFO): Powering down 2021-10-11T19:28:28.534Z,1633980508.534 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-10-11T19:28:28.534Z,1633980508.534 [RudderServo](INFO): Powering down 2021-10-11T19:28:28.535Z,1633980508.535 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-10-11T19:28:28.535Z,1633980508.535 [ThrusterServo](INFO): Powering down 2021-10-11T19:28:28.537Z,1633980508.537 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-10-11T19:28:28.537Z,1633980508.537 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-10-11T19:28:28.538Z,1633980508.538 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-10-11T19:28:28.538Z,1633980508.538 [CBIT](DEBUG): Powering off loads. 2021-10-11T19:28:28.551Z,1633980508.551 [CBIT](DEBUG): Disabling WDT. 2021-10-11T19:28:28.563Z,1633980508.563 [CBIT](DEBUG): Opening all GF detection circuits. 2021-10-11T19:28:28.565Z,1633980508.565 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.634Z,1633980508.634 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.637Z,1633980508.637 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.644Z,1633980508.644 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.687Z,1633980508.687 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.742Z,1633980508.742 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.744Z,1633980508.744 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.748Z,1633980508.748 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.755Z,1633980508.755 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-10-11T19:28:28.842Z,1633980508.842 [logger ThreadHandler](INFO): Thread cancelled.