2021-06-03T18:12:30.695Z,1622743950.695 [NAL9602](INFO): Received command:restart logs 2021-06-03T18:12:30.712Z,1622743950.712 [CommandLine](IMPORTANT): got command restart logs 2021-06-03T18:12:56.638Z,1622743976.638 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210603T171225/Express0028.lzma 2021-06-03T18:12:57.641Z,1622743977.641 [DataOverHttps](INFO): Moved sent file to Logs/20210603T171225/Express0028.lzma.bak 2021-06-03T18:12:57.641Z,1622743977.641 [DataOverHttps](INFO): SBD MOMSN=15687680 2021-06-03T18:13:01.110Z,1622743981.110 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:13:16.846Z,1622743996.846 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T171225/Courier0030.lzma 2021-06-03T18:13:17.848Z,1622743997.848 [DataOverHttps](INFO): Moved sent file to Logs/20210603T171225/Courier0030.lzma.bak 2021-06-03T18:13:17.849Z,1622743997.849 [DataOverHttps](INFO): SBD MOMSN=15687686 2021-06-03T18:13:35.430Z,1622744015.430 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20210603T171225/Express0031.lzma 2021-06-03T18:13:36.433Z,1622744016.433 [DataOverHttps](INFO): Moved sent file to Logs/20210603T171225/Express0031.lzma.bak 2021-06-03T18:13:36.433Z,1622744016.433 [DataOverHttps](INFO): SBD MOMSN=15687690 2021-06-03T18:13:39.135Z,1622744019.135 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:13:39.135Z,1622744019.135 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:13:39.135Z,1622744019.135 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:18:39.734Z,1622744319.734 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:18:39.735Z,1622744319.735 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:18:39.735Z,1622744319.735 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:18:39.735Z,1622744319.735 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:18:40.145Z,1622744320.145 [Default:CheckIn:D] Stopped 2021-06-03T18:18:40.145Z,1622744320.145 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.930619 min 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn:E] Stopped 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn] Stopped 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn](INFO): Running loop #7 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn] Running Loop=7 2021-06-03T18:18:40.605Z,1622744320.605 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:18:40.606Z,1622744320.606 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:18:42.550Z,1622744322.550 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181824.00,A,3648.14264,N,12147.20772,W,0.039,205.29,030621,,,A*77 2021-06-03T18:18:42.555Z,1622744322.555 [NAL9602](INFO): GPS fix at 20210603T181824: (36.802377, -121.786795) 2021-06-03T18:18:42.619Z,1622744322.619 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:18:42.619Z,1622744322.619 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:18:56.163Z,1622744336.163 [DataOverHttps](INFO): Sending 266 bytes from file Logs/20210603T181230/Courier0000.lzma 2021-06-03T18:18:57.164Z,1622744337.164 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0000.lzma.bak 2021-06-03T18:18:57.165Z,1622744337.165 [DataOverHttps](INFO): SBD MOMSN=15687725 2021-06-03T18:19:14.647Z,1622744354.647 [DataOverHttps](INFO): Sending 395 bytes from file Logs/20210603T181230/Express0001.lzma 2021-06-03T18:19:15.649Z,1622744355.649 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0001.lzma.bak 2021-06-03T18:19:15.649Z,1622744355.649 [DataOverHttps](INFO): SBD MOMSN=15687731 2021-06-03T18:19:18.783Z,1622744358.783 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:19:18.784Z,1622744358.784 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:19:18.784Z,1622744358.784 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:20:06.837Z,1622744406.837 [NAL9602](INFO): SBD MO Status=2, MOMSN=27971, MT Status=2, MTMSN=0 2021-06-03T18:20:06.838Z,1622744406.838 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:21:42.193Z,1622744502.193 [NAL9602](INFO): SBD MO Status=2, MOMSN=27971, MT Status=2, MTMSN=0 2021-06-03T18:21:42.194Z,1622744502.194 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:22:17.334Z,1622744537.334 [NAL9602](INFO): SBD MO Status=2, MOMSN=27971, MT Status=2, MTMSN=0 2021-06-03T18:22:17.334Z,1622744537.334 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:22:31.070Z,1622744551.070 [NAL9602](INFO): SBD MO Status=1, MOMSN=27971, MT Status=0, MTMSN=0 2021-06-03T18:22:31.070Z,1622744551.070 [NAL9602](INFO): No messages in MT queue 2021-06-03T18:23:01.812Z,1622744581.812 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:24:19.398Z,1622744659.398 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:24:19.398Z,1622744659.398 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:24:19.398Z,1622744659.398 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:24:19.398Z,1622744659.398 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:24:19.808Z,1622744659.808 [Default:CheckIn:D] Stopped 2021-06-03T18:24:19.808Z,1622744659.808 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:24:20.202Z,1622744660.202 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.591683 min 2021-06-03T18:24:20.202Z,1622744660.202 [Default:CheckIn:E] Stopped 2021-06-03T18:24:20.219Z,1622744660.219 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:24:20.219Z,1622744660.219 [Default:CheckIn] Stopped 2021-06-03T18:24:20.219Z,1622744660.219 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:24:20.219Z,1622744660.219 [Default:CheckIn](INFO): Running loop #8 2021-06-03T18:24:20.219Z,1622744660.219 [Default:CheckIn] Running Loop=8 2021-06-03T18:24:20.219Z,1622744660.219 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:24:20.219Z,1622744660.219 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:24:22.214Z,1622744662.214 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182403.00,A,3648.14614,N,12147.20813,W,0.039,205.29,030621,,,D*73 2021-06-03T18:24:22.216Z,1622744662.216 [NAL9602](INFO): GPS fix at 20210603T182403: (36.802436, -121.786802) 2021-06-03T18:24:22.227Z,1622744662.227 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:24:22.227Z,1622744662.227 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:24:30.762Z,1622744670.762 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210603T181230/Courier0003.lzma 2021-06-03T18:24:31.764Z,1622744671.764 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0003.lzma.bak 2021-06-03T18:24:31.765Z,1622744671.765 [DataOverHttps](INFO): SBD MOMSN=15687761 2021-06-03T18:24:40.006Z,1622744680.006 [NAL9602](INFO): SBD MO Status=1, MOMSN=27972, MT Status=0, MTMSN=0 2021-06-03T18:24:40.006Z,1622744680.006 [NAL9602](INFO): No messages in MT queue 2021-06-03T18:24:57.206Z,1622744697.206 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210603T181230/Express0004.lzma 2021-06-03T18:24:58.212Z,1622744698.212 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0004.lzma.bak 2021-06-03T18:24:58.212Z,1622744698.212 [DataOverHttps](INFO): SBD MOMSN=15687767 2021-06-03T18:25:01.138Z,1622744701.138 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:25:01.138Z,1622744701.138 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:25:01.138Z,1622744701.138 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:25:10.811Z,1622744710.811 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:30:01.853Z,1622745001.853 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:30:01.854Z,1622745001.854 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:30:01.854Z,1622745001.854 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:30:01.854Z,1622745001.854 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:30:02.264Z,1622745002.264 [Default:CheckIn:D] Stopped 2021-06-03T18:30:02.264Z,1622745002.264 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:30:02.658Z,1622745002.658 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.299272 min 2021-06-03T18:30:02.658Z,1622745002.658 [Default:CheckIn:E] Stopped 2021-06-03T18:30:02.658Z,1622745002.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:30:02.675Z,1622745002.675 [Default:CheckIn] Stopped 2021-06-03T18:30:02.675Z,1622745002.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:30:02.675Z,1622745002.675 [Default:CheckIn](INFO): Running loop #9 2021-06-03T18:30:02.675Z,1622745002.675 [Default:CheckIn] Running Loop=9 2021-06-03T18:30:02.675Z,1622745002.675 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:30:02.675Z,1622745002.675 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:30:04.666Z,1622745004.666 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182946.00,A,3648.14230,N,12147.20765,W,0.039,205.29,030621,,,D*73 2021-06-03T18:30:04.668Z,1622745004.668 [NAL9602](INFO): GPS fix at 20210603T182946: (36.802372, -121.786794) 2021-06-03T18:30:04.680Z,1622745004.680 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:30:04.680Z,1622745004.680 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:30:13.326Z,1622745013.326 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210603T181230/Courier0006.lzma 2021-06-03T18:30:14.328Z,1622745014.328 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0006.lzma.bak 2021-06-03T18:30:14.329Z,1622745014.329 [DataOverHttps](INFO): SBD MOMSN=15687786 2021-06-03T18:30:22.442Z,1622745022.442 [NAL9602](INFO): SBD MO Status=1, MOMSN=27973, MT Status=0, MTMSN=0 2021-06-03T18:30:22.442Z,1622745022.442 [NAL9602](INFO): No messages in MT queue 2021-06-03T18:30:31.686Z,1622745031.686 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210603T181230/Express0007.lzma 2021-06-03T18:30:32.688Z,1622745032.688 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0007.lzma.bak 2021-06-03T18:30:32.689Z,1622745032.689 [DataOverHttps](INFO): SBD MOMSN=15687789 2021-06-03T18:30:36.280Z,1622745036.280 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:30:36.280Z,1622745036.280 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:30:36.280Z,1622745036.280 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:30:53.260Z,1622745053.260 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:35:36.922Z,1622745336.922 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:35:36.923Z,1622745336.923 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:35:36.923Z,1622745336.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:35:36.923Z,1622745336.923 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:35:37.331Z,1622745337.331 [Default:CheckIn:D] Stopped 2021-06-03T18:35:37.331Z,1622745337.331 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:35:37.742Z,1622745337.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.883720 min 2021-06-03T18:35:37.743Z,1622745337.743 [Default:CheckIn:E] Stopped 2021-06-03T18:35:37.743Z,1622745337.743 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:35:37.743Z,1622745337.743 [Default:CheckIn] Stopped 2021-06-03T18:35:37.743Z,1622745337.743 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:35:37.743Z,1622745337.743 [Default:CheckIn](INFO): Running loop #10 2021-06-03T18:35:37.743Z,1622745337.743 [Default:CheckIn] Running Loop=10 2021-06-03T18:35:37.743Z,1622745337.743 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:35:37.744Z,1622745337.744 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:35:39.740Z,1622745339.740 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183521.00,A,3648.17258,N,12147.27318,W,1.361,300.78,030621,,,D*74 2021-06-03T18:35:39.742Z,1622745339.742 [NAL9602](INFO): GPS fix at 20210603T183521: (36.802876, -121.787886) 2021-06-03T18:35:39.753Z,1622745339.753 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:35:39.753Z,1622745339.753 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:35:48.066Z,1622745348.066 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210603T181230/Courier0009.lzma 2021-06-03T18:35:49.069Z,1622745349.069 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0009.lzma.bak 2021-06-03T18:35:49.069Z,1622745349.069 [DataOverHttps](INFO): SBD MOMSN=15687813 2021-06-03T18:36:04.081Z,1622745364.081 [NAL9602](INFO): SBD MO Status=2, MOMSN=27974, MT Status=2, MTMSN=0 2021-06-03T18:36:04.082Z,1622745364.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:36:07.674Z,1622745367.674 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20210603T181230/Express0010.lzma 2021-06-03T18:36:09.063Z,1622745369.063 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0010.lzma.bak 2021-06-03T18:36:09.063Z,1622745369.063 [DataOverHttps](INFO): SBD MOMSN=15687816 2021-06-03T18:36:11.364Z,1622745371.364 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:36:11.364Z,1622745371.364 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:36:11.364Z,1622745371.364 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:40:42.026Z,1622745642.026 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T18:41:11.935Z,1622745671.935 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:41:11.935Z,1622745671.935 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:41:11.935Z,1622745671.935 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:41:11.935Z,1622745671.935 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:41:12.348Z,1622745672.348 [Default:CheckIn:D] Stopped 2021-06-03T18:41:12.348Z,1622745672.348 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:41:12.728Z,1622745672.728 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:41:12.741Z,1622745672.741 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.467334 min 2021-06-03T18:41:12.741Z,1622745672.741 [Default:CheckIn:E] Stopped 2021-06-03T18:41:12.741Z,1622745672.741 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:41:12.741Z,1622745672.741 [Default:CheckIn] Stopped 2021-06-03T18:41:12.741Z,1622745672.741 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:41:12.742Z,1622745672.742 [Default:CheckIn](INFO): Running loop #11 2021-06-03T18:41:12.742Z,1622745672.742 [Default:CheckIn] Running Loop=11 2021-06-03T18:41:12.742Z,1622745672.742 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:41:12.742Z,1622745672.742 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:41:14.746Z,1622745674.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184056.00,A,3648.16519,N,12147.28314,W,1.127,359.82,030621,,,D*7F 2021-06-03T18:41:14.750Z,1622745674.750 [NAL9602](INFO): GPS fix at 20210603T184056: (36.802753, -121.788052) 2021-06-03T18:41:14.768Z,1622745674.768 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:41:14.768Z,1622745674.768 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:41:23.646Z,1622745683.646 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210603T181230/Courier0012.lzma 2021-06-03T18:41:24.649Z,1622745684.649 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0012.lzma.bak 2021-06-03T18:41:24.649Z,1622745684.649 [DataOverHttps](INFO): SBD MOMSN=15687834 2021-06-03T18:41:42.367Z,1622745702.367 [DataOverHttps](INFO): Sending 229 bytes from file Logs/20210603T181230/Express0013.lzma 2021-06-03T18:41:43.369Z,1622745703.369 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0013.lzma.bak 2021-06-03T18:41:43.369Z,1622745703.369 [DataOverHttps](INFO): SBD MOMSN=15687837 2021-06-03T18:41:45.448Z,1622745705.448 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T18:41:45.523Z,1622745705.523 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T18:41:46.279Z,1622745706.279 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:41:46.280Z,1622745706.280 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:41:46.280Z,1622745706.280 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:42:09.292Z,1622745729.292 [NAL9602](INFO): SBD MO Status=2, MOMSN=27974, MT Status=2, MTMSN=0 2021-06-03T18:42:09.292Z,1622745729.292 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:42:26.661Z,1622745746.661 [NAL9602](INFO): SBD MO Status=2, MOMSN=27974, MT Status=2, MTMSN=0 2021-06-03T18:42:26.662Z,1622745746.662 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:42:44.030Z,1622745764.030 [NAL9602](INFO): SBD MO Status=2, MOMSN=27974, MT Status=2, MTMSN=0 2021-06-03T18:42:44.030Z,1622745764.030 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:44:38.768Z,1622745878.768 [NAL9602](INFO): SBD MO Status=2, MOMSN=27974, MT Status=2, MTMSN=0 2021-06-03T18:44:38.768Z,1622745878.768 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-06-03T18:46:16.948Z,1622745976.948 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T18:46:46.854Z,1622746006.854 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:46:46.854Z,1622746006.854 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:46:46.854Z,1622746006.854 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:46:46.854Z,1622746006.854 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:46:47.266Z,1622746007.266 [Default:CheckIn:D] Stopped 2021-06-03T18:46:47.266Z,1622746007.266 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:46:47.652Z,1622746007.652 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:46:47.693Z,1622746007.693 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.049308 min 2021-06-03T18:46:47.693Z,1622746007.693 [Default:CheckIn:E] Stopped 2021-06-03T18:46:47.693Z,1622746007.693 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:46:47.693Z,1622746007.693 [Default:CheckIn] Stopped 2021-06-03T18:46:47.694Z,1622746007.694 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:46:47.694Z,1622746007.694 [Default:CheckIn](INFO): Running loop #12 2021-06-03T18:46:47.694Z,1622746007.694 [Default:CheckIn] Running Loop=12 2021-06-03T18:46:47.694Z,1622746007.694 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:46:47.694Z,1622746007.694 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:46:49.674Z,1622746009.674 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184631.00,A,3648.15854,N,12147.27699,W,0.816,61.98,030621,,,A*4C 2021-06-03T18:46:49.676Z,1622746009.676 [NAL9602](INFO): GPS fix at 20210603T184631: (36.802642, -121.787950) 2021-06-03T18:46:49.708Z,1622746009.708 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:46:49.708Z,1622746009.708 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:46:58.866Z,1622746018.866 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210603T181230/Courier0015.lzma 2021-06-03T18:46:59.868Z,1622746019.868 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0015.lzma.bak 2021-06-03T18:46:59.869Z,1622746019.869 [DataOverHttps](INFO): SBD MOMSN=15687856 2021-06-03T18:47:17.323Z,1622746037.323 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20210603T181230/Express0016.lzma 2021-06-03T18:47:18.345Z,1622746038.345 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0016.lzma.bak 2021-06-03T18:47:18.345Z,1622746038.345 [DataOverHttps](INFO): SBD MOMSN=15687859 2021-06-03T18:47:20.116Z,1622746040.116 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T18:47:20.199Z,1622746040.199 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T18:47:20.975Z,1622746040.975 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:47:20.975Z,1622746040.975 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:47:20.975Z,1622746040.975 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:51:51.716Z,1622746311.716 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T18:52:21.622Z,1622746341.622 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:52:21.622Z,1622746341.622 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:52:21.622Z,1622746341.622 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:52:21.622Z,1622746341.622 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:52:22.039Z,1622746342.039 [Default:CheckIn:D] Stopped 2021-06-03T18:52:22.039Z,1622746342.039 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:52:22.424Z,1622746342.424 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:52:22.437Z,1622746342.437 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.628857 min 2021-06-03T18:52:22.437Z,1622746342.437 [Default:CheckIn:E] Stopped 2021-06-03T18:52:22.437Z,1622746342.437 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:52:22.437Z,1622746342.437 [Default:CheckIn] Stopped 2021-06-03T18:52:22.437Z,1622746342.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:52:22.437Z,1622746342.437 [Default:CheckIn](INFO): Running loop #13 2021-06-03T18:52:22.438Z,1622746342.438 [Default:CheckIn] Running Loop=13 2021-06-03T18:52:22.438Z,1622746342.438 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:52:22.438Z,1622746342.438 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:52:24.438Z,1622746344.438 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185206.00,A,3648.15204,N,12147.30312,W,2.002,61.98,030621,,,A*4D 2021-06-03T18:52:24.440Z,1622746344.440 [NAL9602](INFO): GPS fix at 20210603T185206: (36.802534, -121.788385) 2021-06-03T18:52:24.478Z,1622746344.478 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:52:24.478Z,1622746344.478 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:52:33.066Z,1622746353.066 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210603T181230/Courier0018.lzma 2021-06-03T18:52:34.068Z,1622746354.068 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0018.lzma.bak 2021-06-03T18:52:34.069Z,1622746354.069 [DataOverHttps](INFO): SBD MOMSN=15687878 2021-06-03T18:52:59.292Z,1622746379.292 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20210603T181230/Express0019.lzma 2021-06-03T18:53:00.293Z,1622746380.293 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0019.lzma.bak 2021-06-03T18:53:00.293Z,1622746380.293 [DataOverHttps](INFO): SBD MOMSN=15687881 2021-06-03T18:53:03.438Z,1622746383.438 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:53:03.439Z,1622746383.439 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:53:03.439Z,1622746383.439 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T18:57:26.504Z,1622746646.504 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T18:57:57.199Z,1622746677.199 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T18:58:04.082Z,1622746684.082 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T18:58:04.082Z,1622746684.082 [Default:CheckIn:C.Wait] Stopped 2021-06-03T18:58:04.082Z,1622746684.082 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T18:58:04.082Z,1622746684.082 [Default:CheckIn:D] Running Loop=1 2021-06-03T18:58:04.484Z,1622746684.484 [Default:CheckIn:D] Stopped 2021-06-03T18:58:04.484Z,1622746684.484 [Default:CheckIn:E] Running Loop=1 2021-06-03T18:58:04.900Z,1622746684.900 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.336279 min 2021-06-03T18:58:04.900Z,1622746684.900 [Default:CheckIn:E] Stopped 2021-06-03T18:58:04.900Z,1622746684.900 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T18:58:04.900Z,1622746684.900 [Default:CheckIn] Stopped 2021-06-03T18:58:04.900Z,1622746684.900 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T18:58:04.900Z,1622746684.900 [Default:CheckIn](INFO): Running loop #14 2021-06-03T18:58:04.900Z,1622746684.900 [Default:CheckIn] Running Loop=14 2021-06-03T18:58:04.901Z,1622746684.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T18:58:04.901Z,1622746684.901 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T18:58:06.898Z,1622746686.898 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185748.00,A,3648.16159,N,12147.26560,W,1.555,213.52,030621,,,A*7B 2021-06-03T18:58:06.900Z,1622746686.900 [NAL9602](INFO): GPS fix at 20210603T185748: (36.802693, -121.787760) 2021-06-03T18:58:06.911Z,1622746686.911 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T18:58:06.912Z,1622746686.912 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T18:58:15.250Z,1622746695.250 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210603T181230/Courier0021.lzma 2021-06-03T18:58:16.265Z,1622746696.265 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0021.lzma.bak 2021-06-03T18:58:16.265Z,1622746696.265 [DataOverHttps](INFO): SBD MOMSN=15687903 2021-06-03T18:58:34.224Z,1622746714.224 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20210603T181230/Express0022.lzma 2021-06-03T18:58:35.225Z,1622746715.225 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0022.lzma.bak 2021-06-03T18:58:35.225Z,1622746715.225 [DataOverHttps](INFO): SBD MOMSN=15687906 2021-06-03T18:58:39.339Z,1622746719.339 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T18:58:39.339Z,1622746719.339 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T18:58:39.339Z,1622746719.339 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T19:03:08.528Z,1622746988.528 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T19:03:39.225Z,1622747019.225 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T19:03:40.046Z,1622747020.046 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T19:03:40.046Z,1622747020.046 [Default:CheckIn:C.Wait] Stopped 2021-06-03T19:03:40.046Z,1622747020.046 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T19:03:40.046Z,1622747020.046 [Default:CheckIn:D] Running Loop=1 2021-06-03T19:03:40.446Z,1622747020.446 [Default:CheckIn:D] Stopped 2021-06-03T19:03:40.446Z,1622747020.446 [Default:CheckIn:E] Running Loop=1 2021-06-03T19:03:40.860Z,1622747020.860 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.935645 min 2021-06-03T19:03:40.860Z,1622747020.860 [Default:CheckIn:E] Stopped 2021-06-03T19:03:40.861Z,1622747020.861 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T19:03:40.861Z,1622747020.861 [Default:CheckIn] Stopped 2021-06-03T19:03:40.861Z,1622747020.861 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T19:03:40.861Z,1622747020.861 [Default:CheckIn](INFO): Running loop #15 2021-06-03T19:03:40.861Z,1622747020.861 [Default:CheckIn] Running Loop=15 2021-06-03T19:03:40.861Z,1622747020.861 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T19:03:40.861Z,1622747020.861 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T19:03:42.862Z,1622747022.862 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190324.00,A,3648.15120,N,12147.29275,W,1.069,142.69,030621,,,A*75 2021-06-03T19:03:42.865Z,1622747022.865 [NAL9602](INFO): GPS fix at 20210603T190324: (36.802520, -121.788213) 2021-06-03T19:03:42.876Z,1622747022.876 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T19:03:42.876Z,1622747022.876 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T19:03:51.290Z,1622747031.290 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210603T181230/Courier0024.lzma 2021-06-03T19:03:52.293Z,1622747032.293 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0024.lzma.bak 2021-06-03T19:03:52.293Z,1622747032.293 [DataOverHttps](INFO): SBD MOMSN=15687925 2021-06-03T19:04:10.339Z,1622747050.339 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20210603T181230/Express0025.lzma 2021-06-03T19:04:11.341Z,1622747051.341 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0025.lzma.bak 2021-06-03T19:04:11.341Z,1622747051.341 [DataOverHttps](INFO): SBD MOMSN=15687928 2021-06-03T19:04:13.564Z,1622747053.564 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T19:04:13.643Z,1622747053.643 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T19:04:14.431Z,1622747054.431 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T19:04:14.432Z,1622747054.432 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T19:04:14.432Z,1622747054.432 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T19:08:44.660Z,1622747324.660 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T19:09:14.966Z,1622747354.966 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T19:09:14.966Z,1622747354.966 [Default:CheckIn:C.Wait] Stopped 2021-06-03T19:09:14.967Z,1622747354.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T19:09:14.967Z,1622747354.967 [Default:CheckIn:D] Running Loop=1 2021-06-03T19:09:15.368Z,1622747355.368 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T19:09:15.380Z,1622747355.380 [Default:CheckIn:D] Stopped 2021-06-03T19:09:15.380Z,1622747355.380 [Default:CheckIn:E] Running Loop=1 2021-06-03T19:09:15.791Z,1622747355.791 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.517879 min 2021-06-03T19:09:15.791Z,1622747355.791 [Default:CheckIn:E] Stopped 2021-06-03T19:09:15.791Z,1622747355.791 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T19:09:15.792Z,1622747355.792 [Default:CheckIn] Stopped 2021-06-03T19:09:15.792Z,1622747355.792 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T19:09:15.792Z,1622747355.792 [Default:CheckIn](INFO): Running loop #16 2021-06-03T19:09:15.792Z,1622747355.792 [Default:CheckIn] Running Loop=16 2021-06-03T19:09:15.792Z,1622747355.792 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T19:09:15.792Z,1622747355.792 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T19:09:17.791Z,1622747357.791 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190859.00,A,3648.15865,N,12147.24966,W,4.432,131.05,030621,,,A*79 2021-06-03T19:09:17.793Z,1622747357.793 [NAL9602](INFO): GPS fix at 20210603T190859: (36.802644, -121.787494) 2021-06-03T19:09:17.837Z,1622747357.837 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T19:09:17.837Z,1622747357.837 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T19:09:27.170Z,1622747367.170 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210603T181230/Courier0027.lzma 2021-06-03T19:09:28.172Z,1622747368.172 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0027.lzma.bak 2021-06-03T19:09:28.173Z,1622747368.173 [DataOverHttps](INFO): SBD MOMSN=15687948 2021-06-03T19:09:45.723Z,1622747385.723 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20210603T181230/Express0028.lzma 2021-06-03T19:09:46.724Z,1622747386.724 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0028.lzma.bak 2021-06-03T19:09:46.725Z,1622747386.725 [DataOverHttps](INFO): SBD MOMSN=15687951 2021-06-03T19:09:48.492Z,1622747388.492 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T19:09:48.567Z,1622747388.567 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T19:09:49.748Z,1622747389.748 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T19:09:49.748Z,1622747389.748 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T19:09:49.748Z,1622747389.748 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T19:14:20.156Z,1622747660.156 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T19:14:50.299Z,1622747690.299 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T19:14:50.300Z,1622747690.300 [Default:CheckIn:C.Wait] Stopped 2021-06-03T19:14:50.300Z,1622747690.300 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T19:14:50.300Z,1622747690.300 [Default:CheckIn:D] Running Loop=1 2021-06-03T19:14:50.668Z,1622747690.668 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T19:14:50.725Z,1622747690.725 [Default:CheckIn:D] Stopped 2021-06-03T19:14:50.725Z,1622747690.725 [Default:CheckIn:E] Running Loop=1 2021-06-03T19:14:51.193Z,1622747691.193 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.106958 min 2021-06-03T19:14:51.193Z,1622747691.193 [Default:CheckIn:E] Stopped 2021-06-03T19:14:51.193Z,1622747691.193 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T19:14:51.193Z,1622747691.193 [Default:CheckIn] Stopped 2021-06-03T19:14:51.193Z,1622747691.193 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T19:14:51.193Z,1622747691.193 [Default:CheckIn](INFO): Running loop #17 2021-06-03T19:14:51.193Z,1622747691.193 [Default:CheckIn] Running Loop=17 2021-06-03T19:14:51.194Z,1622747691.194 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T19:14:51.194Z,1622747691.194 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T19:15:02.791Z,1622747702.791 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-06-03T19:15:02.804Z,1622747702.804 [BPC1](INFO): Received data from all battery sticks. 2021-06-03T19:15:23.792Z,1622747723.792 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T19:15:23.867Z,1622747723.867 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T19:19:51.367Z,1622747991.367 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T19:14:51.2Z 2021-06-03T19:19:51.367Z,1622747991.367 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T19:19:51.367Z,1622747991.367 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T19:19:55.800Z,1622747995.800 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T19:20:00.066Z,1622748000.066 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20210603T181230/Courier0030.lzma 2021-06-03T19:20:01.068Z,1622748001.068 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0030.lzma.bak 2021-06-03T19:20:01.069Z,1622748001.069 [DataOverHttps](INFO): SBD MOMSN=15687979 2021-06-03T19:20:18.387Z,1622748018.387 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20210603T181230/Express0031.lzma 2021-06-03T19:20:19.388Z,1622748019.388 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0031.lzma.bak 2021-06-03T19:20:19.389Z,1622748019.389 [DataOverHttps](INFO): SBD MOMSN=15687985 2021-06-03T19:20:22.083Z,1622748022.083 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T19:20:22.083Z,1622748022.083 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T19:20:22.083Z,1622748022.083 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T19:20:26.504Z,1622748026.504 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T19:25:22.809Z,1622748322.809 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T19:25:22.809Z,1622748322.809 [Default:CheckIn:C.Wait] Stopped 2021-06-03T19:25:22.810Z,1622748322.810 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T19:25:22.810Z,1622748322.810 [Default:CheckIn:D] Running Loop=1 2021-06-03T19:25:23.198Z,1622748323.198 [Default:CheckIn:D] Stopped 2021-06-03T19:25:23.198Z,1622748323.198 [Default:CheckIn:E] Running Loop=1 2021-06-03T19:25:23.653Z,1622748323.653 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.648185 min 2021-06-03T19:25:23.653Z,1622748323.653 [Default:CheckIn:E] Stopped 2021-06-03T19:25:23.653Z,1622748323.653 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T19:25:23.653Z,1622748323.653 [Default:CheckIn] Stopped 2021-06-03T19:25:23.653Z,1622748323.653 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T19:25:23.653Z,1622748323.653 [Default:CheckIn](INFO): Running loop #18 2021-06-03T19:25:23.653Z,1622748323.653 [Default:CheckIn] Running Loop=18 2021-06-03T19:25:23.654Z,1622748323.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T19:25:23.654Z,1622748323.654 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T19:25:25.215Z,1622748325.215 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-06-03T19:25:25.215Z,1622748325.215 [NAL9602] Data Fault, FailCount= 1 2021-06-03T19:25:25.215Z,1622748325.215 [NAL9602](ERROR): Data Fault 2021-06-03T19:25:25.235Z,1622748325.235 [CBIT](ERROR): Data Fault in component: NAL9602 2021-06-03T19:25:25.620Z,1622748325.620 [NAL9602](INFO): Powering down 2021-06-03T19:25:26.020Z,1622748326.020 [NAL9602](FAULT): LCB fault: Software Overcurrent. 2021-06-03T19:25:26.020Z,1622748326.020 [NAL9602] Hardware Fault, FailCount= 1 2021-06-03T19:25:26.020Z,1622748326.020 [NAL9602](ERROR): Hardware Fault 2021-06-03T19:25:26.497Z,1622748326.497 [CBIT](INFO): Clearing failed state for component NAL9602 2021-06-03T19:25:26.497Z,1622748326.497 [NAL9602] No Fault, FailCount= 1 2021-06-03T19:25:55.912Z,1622748355.912 [NAL9602](INFO): Powering up NAL9602 2021-06-03T19:26:06.821Z,1622748366.821 [NAL9602](INFO): NAL9602 initialized 2021-06-03T19:30:23.891Z,1622748623.891 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T19:25:23.7Z 2021-06-03T19:30:23.891Z,1622748623.891 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T19:30:23.892Z,1622748623.892 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T19:30:31.194Z,1622748631.194 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0033.lzma 2021-06-03T19:30:32.198Z,1622748632.198 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0033.lzma.bak 2021-06-03T19:30:32.198Z,1622748632.198 [DataOverHttps](INFO): SBD MOMSN=15688012 2021-06-03T19:30:56.343Z,1622748656.343 [DataOverHttps](INFO): Sending 258 bytes from file Logs/20210603T181230/Express0034.lzma 2021-06-03T19:30:57.345Z,1622748657.345 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0034.lzma.bak 2021-06-03T19:30:57.345Z,1622748657.345 [DataOverHttps](INFO): SBD MOMSN=15688014 2021-06-03T19:31:00.828Z,1622748660.828 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T19:31:00.829Z,1622748660.829 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T19:31:00.829Z,1622748660.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T19:31:10.076Z,1622748670.076 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T19:31:40.783Z,1622748700.783 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T19:35:24.501Z,1622748924.501 [CommandLine](IMPORTANT): got command show stack 2021-06-03T19:35:24.501Z,1622748924.501 [CommandLine](IMPORTANT): Behavior Stack: 2021-06-03T19:35:24.501Z,1622748924.501 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface 2021-06-03T19:35:24.502Z,1622748924.502 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:C.Wait 2021-06-03T19:36:01.513Z,1622748961.513 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T19:36:01.513Z,1622748961.513 [Default:CheckIn:C.Wait] Stopped 2021-06-03T19:36:01.513Z,1622748961.513 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T19:36:01.514Z,1622748961.514 [Default:CheckIn:D] Running Loop=1 2021-06-03T19:36:01.926Z,1622748961.926 [Default:CheckIn:D] Stopped 2021-06-03T19:36:01.926Z,1622748961.926 [Default:CheckIn:E] Running Loop=1 2021-06-03T19:36:02.323Z,1622748962.323 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.293644 min 2021-06-03T19:36:02.323Z,1622748962.323 [Default:CheckIn:E] Stopped 2021-06-03T19:36:02.323Z,1622748962.323 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T19:36:02.323Z,1622748962.323 [Default:CheckIn] Stopped 2021-06-03T19:36:02.323Z,1622748962.323 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T19:36:02.323Z,1622748962.323 [Default:CheckIn](INFO): Running loop #19 2021-06-03T19:36:02.323Z,1622748962.323 [Default:CheckIn] Running Loop=19 2021-06-03T19:36:02.324Z,1622748962.324 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T19:36:02.324Z,1622748962.324 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T19:36:35.036Z,1622748995.036 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T19:36:35.115Z,1622748995.115 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T19:41:02.701Z,1622749262.701 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T19:36:02.3Z 2021-06-03T19:41:02.701Z,1622749262.701 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T19:41:02.702Z,1622749262.702 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T19:41:06.324Z,1622749266.324 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T19:41:10.079Z,1622749270.079 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0036.lzma 2021-06-03T19:41:11.080Z,1622749271.080 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0036.lzma.bak 2021-06-03T19:41:11.081Z,1622749271.081 [DataOverHttps](INFO): SBD MOMSN=15688050 2021-06-03T19:41:29.315Z,1622749289.315 [DataOverHttps](INFO): Sending 333 bytes from file Logs/20210603T181230/Express0037.lzma 2021-06-03T19:41:30.317Z,1622749290.317 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0037.lzma.bak 2021-06-03T19:41:30.317Z,1622749290.317 [DataOverHttps](INFO): SBD MOMSN=15688052 2021-06-03T19:41:33.027Z,1622749293.027 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T19:41:33.028Z,1622749293.028 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T19:41:33.028Z,1622749293.028 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T19:41:37.028Z,1622749297.028 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T19:46:33.700Z,1622749593.700 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T19:46:33.700Z,1622749593.700 [Default:CheckIn:C.Wait] Stopped 2021-06-03T19:46:33.700Z,1622749593.700 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T19:46:33.701Z,1622749593.701 [Default:CheckIn:D] Running Loop=1 2021-06-03T19:46:34.106Z,1622749594.106 [Default:CheckIn:D] Stopped 2021-06-03T19:46:34.106Z,1622749594.106 [Default:CheckIn:E] Running Loop=1 2021-06-03T19:46:34.518Z,1622749594.518 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.829980 min 2021-06-03T19:46:34.518Z,1622749594.518 [Default:CheckIn:E] Stopped 2021-06-03T19:46:34.519Z,1622749594.519 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T19:46:34.519Z,1622749594.519 [Default:CheckIn] Stopped 2021-06-03T19:46:34.519Z,1622749594.519 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T19:46:34.519Z,1622749594.519 [Default:CheckIn](INFO): Running loop #20 2021-06-03T19:46:34.519Z,1622749594.519 [Default:CheckIn] Running Loop=20 2021-06-03T19:46:34.519Z,1622749594.519 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T19:46:34.519Z,1622749594.519 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T19:46:36.117Z,1622749596.117 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-06-03T19:46:36.117Z,1622749596.117 [NAL9602] Data Fault, FailCount= 2 2021-06-03T19:46:36.117Z,1622749596.117 [NAL9602](ERROR): Data Fault 2021-06-03T19:46:36.151Z,1622749596.151 [CBIT](ERROR): Data Fault in component: NAL9602 2021-06-03T19:46:36.520Z,1622749596.520 [NAL9602](INFO): Powering down 2021-06-03T19:46:37.376Z,1622749597.376 [CBIT](INFO): Clearing failed state for component NAL9602 2021-06-03T19:46:37.376Z,1622749597.376 [NAL9602] No Fault, FailCount= 2 2021-06-03T19:47:06.840Z,1622749626.840 [NAL9602](INFO): Powering up NAL9602 2021-06-03T19:47:17.755Z,1622749637.755 [NAL9602](INFO): NAL9602 initialized 2021-06-03T19:51:34.720Z,1622749894.720 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T19:46:34.5Z 2021-06-03T19:51:34.720Z,1622749894.720 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T19:51:34.721Z,1622749894.721 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T19:51:42.390Z,1622749902.390 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0039.lzma 2021-06-03T19:51:43.393Z,1622749903.393 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0039.lzma.bak 2021-06-03T19:51:43.393Z,1622749903.393 [DataOverHttps](INFO): SBD MOMSN=15688087 2021-06-03T19:52:01.123Z,1622749921.123 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20210603T181230/Express0040.lzma 2021-06-03T19:52:02.125Z,1622749922.125 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0040.lzma.bak 2021-06-03T19:52:02.125Z,1622749922.125 [DataOverHttps](INFO): SBD MOMSN=15688089 2021-06-03T19:52:05.067Z,1622749925.067 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T19:52:05.067Z,1622749925.067 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T19:52:05.067Z,1622749925.067 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T19:52:21.168Z,1622749941.168 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T19:52:51.916Z,1622749971.916 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T19:57:05.666Z,1622750225.666 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T19:57:05.666Z,1622750225.666 [Default:CheckIn:C.Wait] Stopped 2021-06-03T19:57:05.666Z,1622750225.666 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T19:57:05.666Z,1622750225.666 [Default:CheckIn:D] Running Loop=1 2021-06-03T19:57:06.077Z,1622750226.077 [Default:CheckIn:D] Stopped 2021-06-03T19:57:06.077Z,1622750226.077 [Default:CheckIn:E] Running Loop=1 2021-06-03T19:57:06.466Z,1622750226.466 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.362826 min 2021-06-03T19:57:06.467Z,1622750226.467 [Default:CheckIn:E] Stopped 2021-06-03T19:57:06.467Z,1622750226.467 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T19:57:06.467Z,1622750226.467 [Default:CheckIn] Stopped 2021-06-03T19:57:06.467Z,1622750226.467 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T19:57:06.467Z,1622750226.467 [Default:CheckIn](INFO): Running loop #21 2021-06-03T19:57:06.467Z,1622750226.467 [Default:CheckIn] Running Loop=21 2021-06-03T19:57:06.468Z,1622750226.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T19:57:06.468Z,1622750226.468 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T20:02:06.719Z,1622750526.719 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T19:57:06.5Z 2021-06-03T20:02:06.719Z,1622750526.719 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T20:02:06.719Z,1622750526.719 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T20:02:10.772Z,1622750530.772 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T20:02:14.754Z,1622750534.754 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0042.lzma 2021-06-03T20:02:15.759Z,1622750535.759 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0042.lzma.bak 2021-06-03T20:02:15.760Z,1622750535.760 [DataOverHttps](INFO): SBD MOMSN=15688149 2021-06-03T20:02:33.558Z,1622750553.558 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210603T181230/Express0043.lzma 2021-06-03T20:02:34.549Z,1622750554.549 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0043.lzma.bak 2021-06-03T20:02:34.549Z,1622750554.549 [DataOverHttps](INFO): SBD MOMSN=15688155 2021-06-03T20:02:38.746Z,1622750558.746 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T20:02:38.746Z,1622750558.746 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T20:02:38.746Z,1622750558.746 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T20:02:41.528Z,1622750561.528 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T20:07:39.433Z,1622750859.433 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T20:07:39.433Z,1622750859.433 [Default:CheckIn:C.Wait] Stopped 2021-06-03T20:07:39.433Z,1622750859.433 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T20:07:39.434Z,1622750859.434 [Default:CheckIn:D] Running Loop=1 2021-06-03T20:07:39.850Z,1622750859.850 [Default:CheckIn:D] Stopped 2021-06-03T20:07:39.850Z,1622750859.850 [Default:CheckIn:E] Running Loop=1 2021-06-03T20:07:40.233Z,1622750860.233 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 149.925700 min 2021-06-03T20:07:40.233Z,1622750860.233 [Default:CheckIn:E] Stopped 2021-06-03T20:07:40.233Z,1622750860.233 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T20:07:40.233Z,1622750860.233 [Default:CheckIn] Stopped 2021-06-03T20:07:40.233Z,1622750860.233 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T20:07:40.234Z,1622750860.234 [Default:CheckIn](INFO): Running loop #22 2021-06-03T20:07:40.234Z,1622750860.234 [Default:CheckIn] Running Loop=22 2021-06-03T20:07:40.234Z,1622750860.234 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T20:07:40.234Z,1622750860.234 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T20:07:41.837Z,1622750861.837 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-06-03T20:07:41.838Z,1622750861.838 [NAL9602] Data Fault, FailCount= 3 2021-06-03T20:07:41.838Z,1622750861.838 [NAL9602](ERROR): Data Fault 2021-06-03T20:07:41.859Z,1622750861.859 [CBIT](ERROR): Data Fault in component: NAL9602 2021-06-03T20:07:42.240Z,1622750862.240 [NAL9602](INFO): Powering down 2021-06-03T20:07:43.070Z,1622750863.070 [CBIT](INFO): Clearing failed state for component NAL9602 2021-06-03T20:07:43.070Z,1622750863.070 [NAL9602] No Fault, FailCount= 3 2021-06-03T20:08:12.540Z,1622750892.540 [NAL9602](INFO): Powering up NAL9602 2021-06-03T20:08:23.456Z,1622750903.456 [NAL9602](INFO): NAL9602 initialized 2021-06-03T20:12:40.555Z,1622751160.555 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T20:07:40.2Z 2021-06-03T20:12:40.555Z,1622751160.555 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T20:12:40.556Z,1622751160.556 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T20:12:43.333Z,1622751163.333 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0045.lzma 2021-06-03T20:12:44.337Z,1622751164.337 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0045.lzma.bak 2021-06-03T20:12:44.337Z,1622751164.337 [DataOverHttps](INFO): SBD MOMSN=15688207 2021-06-03T20:13:07.595Z,1622751187.595 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20210603T181230/Express0046.lzma 2021-06-03T20:13:08.597Z,1622751188.597 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0046.lzma.bak 2021-06-03T20:13:08.597Z,1622751188.597 [DataOverHttps](INFO): SBD MOMSN=15688212 2021-06-03T20:13:11.676Z,1622751191.676 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T20:13:11.676Z,1622751191.676 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T20:13:11.676Z,1622751191.676 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T20:13:26.944Z,1622751206.944 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T20:13:57.647Z,1622751237.647 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T20:14:51.843Z,1622751291.843 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:15:22.967Z,1622751322.967 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:15:54.091Z,1622751354.091 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:18:12.325Z,1622751492.325 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T20:18:12.325Z,1622751492.325 [Default:CheckIn:C.Wait] Stopped 2021-06-03T20:18:12.325Z,1622751492.325 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T20:18:12.326Z,1622751492.326 [Default:CheckIn:D] Running Loop=1 2021-06-03T20:18:12.651Z,1622751492.651 [Default:CheckIn:D] Stopped 2021-06-03T20:18:12.651Z,1622751492.651 [Default:CheckIn:E] Running Loop=1 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 160.472396 min 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn:E] Stopped 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn] Stopped 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn](INFO): Running loop #23 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn] Running Loop=23 2021-06-03T20:18:13.149Z,1622751493.149 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T20:18:13.150Z,1622751493.150 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T20:18:45.749Z,1622751525.749 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T20:18:45.827Z,1622751525.827 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T20:22:27.194Z,1622751747.194 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2021-06-03T20:22:27.205Z,1622751747.205 [BPC1](INFO): Received data from all battery sticks. 2021-06-03T20:23:13.308Z,1622751793.308 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T20:18:13.1Z 2021-06-03T20:23:13.309Z,1622751793.309 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T20:23:13.309Z,1622751793.309 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T20:23:17.756Z,1622751797.756 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T20:23:20.218Z,1622751800.218 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20210603T181230/Courier0048.lzma 2021-06-03T20:23:21.220Z,1622751801.220 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0048.lzma.bak 2021-06-03T20:23:21.221Z,1622751801.221 [DataOverHttps](INFO): SBD MOMSN=15688247 2021-06-03T20:23:38.695Z,1622751818.695 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20210603T181230/Express0049.lzma 2021-06-03T20:23:39.697Z,1622751819.697 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0049.lzma.bak 2021-06-03T20:23:39.697Z,1622751819.697 [DataOverHttps](INFO): SBD MOMSN=15688249 2021-06-03T20:23:42.431Z,1622751822.431 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T20:23:42.431Z,1622751822.431 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T20:23:42.431Z,1622751822.431 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T20:23:48.468Z,1622751828.468 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T20:28:42.998Z,1622752122.998 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T20:28:42.998Z,1622752122.998 [Default:CheckIn:C.Wait] Stopped 2021-06-03T20:28:42.998Z,1622752122.998 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T20:28:43.015Z,1622752123.015 [Default:CheckIn:D] Running Loop=1 2021-06-03T20:28:43.405Z,1622752123.405 [Default:CheckIn:D] Stopped 2021-06-03T20:28:43.405Z,1622752123.405 [Default:CheckIn:E] Running Loop=1 2021-06-03T20:28:43.813Z,1622752123.813 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 170.984961 min 2021-06-03T20:28:43.813Z,1622752123.813 [Default:CheckIn:E] Stopped 2021-06-03T20:28:43.813Z,1622752123.813 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T20:28:43.813Z,1622752123.813 [Default:CheckIn] Stopped 2021-06-03T20:28:43.813Z,1622752123.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T20:28:43.814Z,1622752123.814 [Default:CheckIn](INFO): Running loop #24 2021-06-03T20:28:43.814Z,1622752123.814 [Default:CheckIn] Running Loop=24 2021-06-03T20:28:43.814Z,1622752123.814 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T20:28:43.814Z,1622752123.814 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T20:28:45.418Z,1622752125.418 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-06-03T20:28:45.418Z,1622752125.418 [NAL9602] Data Fault, FailCount= 4 2021-06-03T20:28:45.419Z,1622752125.419 [NAL9602](ERROR): Data Fault 2021-06-03T20:28:45.452Z,1622752125.452 [CBIT](ERROR): Data Fault in component: NAL9602 2021-06-03T20:28:45.816Z,1622752125.816 [NAL9602](INFO): Powering down 2021-06-03T20:28:46.655Z,1622752126.655 [CBIT](INFO): Clearing failed state for component NAL9602 2021-06-03T20:28:46.655Z,1622752126.655 [NAL9602] No Fault, FailCount= 4 2021-06-03T20:29:16.120Z,1622752156.120 [NAL9602](INFO): Powering up NAL9602 2021-06-03T20:29:27.033Z,1622752167.033 [NAL9602](INFO): NAL9602 initialized 2021-06-03T20:33:44.022Z,1622752424.022 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T20:28:43.8Z 2021-06-03T20:33:44.022Z,1622752424.022 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T20:33:44.022Z,1622752424.022 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T20:34:01.815Z,1622752441.815 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:34:30.464Z,1622752470.464 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T20:34:32.939Z,1622752472.939 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:34:52.386Z,1622752492.386 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0051.lzma 2021-06-03T20:34:53.389Z,1622752493.389 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0051.lzma.bak 2021-06-03T20:34:53.389Z,1622752493.389 [DataOverHttps](INFO): SBD MOMSN=15688312 2021-06-03T20:35:00.860Z,1622752500.860 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T20:35:15.115Z,1622752515.115 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20210603T181230/Express0052.lzma 2021-06-03T20:35:16.117Z,1622752516.117 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0052.lzma.bak 2021-06-03T20:35:16.117Z,1622752516.117 [DataOverHttps](INFO): SBD MOMSN=15688317 2021-06-03T20:35:19.098Z,1622752519.098 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T20:35:19.098Z,1622752519.098 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T20:35:19.098Z,1622752519.098 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T20:38:07.215Z,1622752687.215 [CBIT](IMPORTANT): Beginning ground fault scan 2021-06-03T20:38:18.119Z,1622752698.119 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.001954 CHAN A1 (24V): -0.180989 CHAN A2 (12V): -0.002301 CHAN A3 (5V): -0.001498 CHAN B0 (3.3V): 0.000104 CHAN B1 (3.15aV): 0.000083 CHAN B2 (3.15bV): -0.000189 CHAN B3 (GND): 0.000167 OPEN: -0.000594 Full Scale Calc: 4.765 mA, -1.589 mA 2021-06-03T20:40:19.734Z,1622752819.734 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T20:40:19.734Z,1622752819.734 [Default:CheckIn:C.Wait] Stopped 2021-06-03T20:40:19.734Z,1622752819.734 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T20:40:19.735Z,1622752819.735 [Default:CheckIn:D] Running Loop=1 2021-06-03T20:40:20.130Z,1622752820.130 [Default:CheckIn:D] Stopped 2021-06-03T20:40:20.130Z,1622752820.130 [Default:CheckIn:E] Running Loop=1 2021-06-03T20:40:20.539Z,1622752820.539 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 182.597038 min 2021-06-03T20:40:20.539Z,1622752820.539 [Default:CheckIn:E] Stopped 2021-06-03T20:40:20.539Z,1622752820.539 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T20:40:20.539Z,1622752820.539 [Default:CheckIn] Stopped 2021-06-03T20:40:20.539Z,1622752820.539 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T20:40:20.539Z,1622752820.539 [Default:CheckIn](INFO): Running loop #25 2021-06-03T20:40:20.540Z,1622752820.540 [Default:CheckIn] Running Loop=25 2021-06-03T20:40:20.540Z,1622752820.540 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T20:40:20.540Z,1622752820.540 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T20:40:22.140Z,1622752822.140 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-06-03T20:40:22.140Z,1622752822.140 [NAL9602] Data Fault, FailCount= 5 2021-06-03T20:40:22.140Z,1622752822.140 [NAL9602](ERROR): Data Fault 2021-06-03T20:40:22.165Z,1622752822.165 [CBIT](ERROR): Data Fault in component: NAL9602 2021-06-03T20:40:22.166Z,1622752822.166 [CBIT](CRITICAL): Data Fault in component: NAL9602 2021-06-03T20:40:22.552Z,1622752822.552 [NAL9602](INFO): Powering down 2021-06-03T20:40:22.574Z,1622752822.574 [CommandLine](FAULT): Scheduling is paused 2021-06-03T20:40:22.575Z,1622752822.575 [CBIT](INFO): Critical error at 20210603T204022 2021-06-03T20:40:33.443Z,1622752833.443 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:41:04.567Z,1622752864.567 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:41:35.691Z,1622752895.691 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:42:06.815Z,1622752926.815 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:42:22.159Z,1622752942.159 [CBIT](INFO): Clearing failed state for component NAL9602 2021-06-03T20:42:22.159Z,1622752942.159 [NAL9602] No Fault, FailCount= 5 2021-06-03T20:42:22.536Z,1622752942.536 [NAL9602](INFO): Powering up NAL9602 2021-06-03T20:42:33.440Z,1622752953.440 [NAL9602](INFO): NAL9602 initialized 2021-06-03T20:42:37.939Z,1622752957.939 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:42:40.952Z,1622752960.952 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.735641 2021-06-03T20:43:21.607Z,1622753001.607 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003075 2021-06-03T20:45:20.779Z,1622753120.779 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T20:40:20.5Z 2021-06-03T20:45:20.779Z,1622753120.779 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T20:45:20.779Z,1622753120.779 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T20:45:28.154Z,1622753128.154 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20210603T181230/Courier0054.lzma 2021-06-03T20:45:29.156Z,1622753129.156 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0054.lzma.bak 2021-06-03T20:45:29.157Z,1622753129.157 [DataOverHttps](INFO): SBD MOMSN=15688361 2021-06-03T20:45:46.623Z,1622753146.623 [DataOverHttps](INFO): Sending 455 bytes from file Logs/20210603T181230/Express0055.lzma 2021-06-03T20:45:47.625Z,1622753147.625 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0055.lzma.bak 2021-06-03T20:45:47.625Z,1622753147.625 [DataOverHttps](INFO): SBD MOMSN=15688364 2021-06-03T20:45:50.670Z,1622753150.670 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T20:45:50.670Z,1622753150.670 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T20:45:50.671Z,1622753150.671 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T20:47:36.940Z,1622753256.940 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T20:48:07.644Z,1622753287.644 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T20:50:51.370Z,1622753451.370 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T20:50:51.370Z,1622753451.370 [Default:CheckIn:C.Wait] Stopped 2021-06-03T20:50:51.370Z,1622753451.370 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T20:50:51.371Z,1622753451.371 [Default:CheckIn:D] Running Loop=1 2021-06-03T20:50:51.855Z,1622753451.855 [Default:CheckIn:D] Stopped 2021-06-03T20:50:51.855Z,1622753451.855 [Default:CheckIn:E] Running Loop=1 2021-06-03T20:50:52.200Z,1622753452.200 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 193.125798 min 2021-06-03T20:50:52.200Z,1622753452.200 [Default:CheckIn:E] Stopped 2021-06-03T20:50:52.200Z,1622753452.200 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T20:50:52.200Z,1622753452.200 [Default:CheckIn] Stopped 2021-06-03T20:50:52.201Z,1622753452.201 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T20:50:52.201Z,1622753452.201 [Default:CheckIn](INFO): Running loop #26 2021-06-03T20:50:52.201Z,1622753452.201 [Default:CheckIn] Running Loop=26 2021-06-03T20:50:52.201Z,1622753452.201 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T20:50:52.201Z,1622753452.201 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T20:51:24.901Z,1622753484.901 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-06-03T20:51:24.975Z,1622753484.975 [NAL9602](ERROR): received: +CSQ:0 OK974, 2, 0, 0, 0 OK 2021-06-03T20:54:06.395Z,1622753646.395 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:54:37.531Z,1622753677.531 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:55:08.663Z,1622753708.663 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:55:39.787Z,1622753739.787 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:55:52.431Z,1622753752.431 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T20:50:52.2Z 2021-06-03T20:55:52.431Z,1622753752.431 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T20:55:52.431Z,1622753752.431 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T20:55:55.656Z,1622753755.656 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T20:56:10.911Z,1622753770.911 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:56:14.927Z,1622753774.927 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.747437 2021-06-03T20:56:46.065Z,1622753806.065 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:57:17.195Z,1622753837.195 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:57:48.335Z,1622753868.335 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:58:19.463Z,1622753899.463 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:58:50.587Z,1622753930.587 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:59:21.719Z,1622753961.719 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T20:59:52.843Z,1622753992.843 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:00:17.263Z,1622754017.263 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003104 2021-06-03T21:00:24.774Z,1622754024.774 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0057.lzma 2021-06-03T21:00:25.777Z,1622754025.777 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0057.lzma.bak 2021-06-03T21:00:25.777Z,1622754025.777 [DataOverHttps](INFO): SBD MOMSN=15688423 2021-06-03T21:00:46.171Z,1622754046.171 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20210603T181230/Express0058.lzma 2021-06-03T21:00:47.173Z,1622754047.173 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0058.lzma.bak 2021-06-03T21:00:47.173Z,1622754047.173 [DataOverHttps](INFO): SBD MOMSN=15688425 2021-06-03T21:00:48.156Z,1622754048.156 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T21:00:51.495Z,1622754051.495 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T21:00:51.495Z,1622754051.495 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T21:00:51.495Z,1622754051.495 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T21:05:52.158Z,1622754352.158 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T21:05:52.158Z,1622754352.158 [Default:CheckIn:C.Wait] Stopped 2021-06-03T21:05:52.158Z,1622754352.158 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T21:05:52.158Z,1622754352.158 [Default:CheckIn:D] Running Loop=1 2021-06-03T21:05:52.563Z,1622754352.563 [Default:CheckIn:D] Stopped 2021-06-03T21:05:52.563Z,1622754352.563 [Default:CheckIn:E] Running Loop=1 2021-06-03T21:05:52.963Z,1622754352.963 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 208.137598 min 2021-06-03T21:05:52.963Z,1622754352.963 [Default:CheckIn:E] Stopped 2021-06-03T21:05:52.963Z,1622754352.963 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T21:05:52.964Z,1622754352.964 [Default:CheckIn] Stopped 2021-06-03T21:05:52.964Z,1622754352.964 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T21:05:52.964Z,1622754352.964 [Default:CheckIn](INFO): Running loop #27 2021-06-03T21:05:52.964Z,1622754352.964 [Default:CheckIn] Running Loop=27 2021-06-03T21:05:52.964Z,1622754352.964 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T21:05:52.964Z,1622754352.964 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T21:05:54.568Z,1622754354.568 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-06-03T21:05:54.568Z,1622754354.568 [NAL9602] Data Fault, FailCount= 1 2021-06-03T21:05:54.568Z,1622754354.568 [NAL9602](ERROR): Data Fault 2021-06-03T21:05:54.619Z,1622754354.619 [CBIT](ERROR): Data Fault in component: NAL9602 2021-06-03T21:05:54.972Z,1622754354.972 [NAL9602](INFO): Powering down 2021-06-03T21:05:55.809Z,1622754355.809 [CBIT](INFO): Clearing failed state for component NAL9602 2021-06-03T21:05:55.810Z,1622754355.810 [NAL9602] No Fault, FailCount= 1 2021-06-03T21:06:25.265Z,1622754385.265 [NAL9602](INFO): Powering up NAL9602 2021-06-03T21:06:36.188Z,1622754396.188 [NAL9602](INFO): NAL9602 initialized 2021-06-03T21:10:53.215Z,1622754653.215 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-06-03T21:05:52.0Z 2021-06-03T21:10:53.215Z,1622754653.215 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T21:10:53.215Z,1622754653.215 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-06-03T21:11:06.282Z,1622754666.282 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210603T181230/Courier0060.lzma 2021-06-03T21:11:07.294Z,1622754667.294 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Courier0060.lzma.bak 2021-06-03T21:11:07.294Z,1622754667.294 [DataOverHttps](INFO): SBD MOMSN=15688454 2021-06-03T21:11:37.591Z,1622754697.591 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20210603T181230/Express0061.lzma 2021-06-03T21:11:38.593Z,1622754698.593 [DataOverHttps](INFO): Moved sent file to Logs/20210603T181230/Express0061.lzma.bak 2021-06-03T21:11:38.593Z,1622754698.593 [DataOverHttps](INFO): SBD MOMSN=15688456 2021-06-03T21:11:39.664Z,1622754699.664 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-06-03T21:11:43.748Z,1622754703.748 [Default:CheckIn:Read_Iridium] Stopped 2021-06-03T21:11:43.749Z,1622754703.749 [Default:CheckIn:C.Wait] Running Loop=1 2021-06-03T21:11:43.749Z,1622754703.749 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-06-03T21:12:10.362Z,1622754730.362 [NAL9602](INFO): Not Powering down - fast GPS 2021-06-03T21:15:33.319Z,1622754933.319 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:16:04.443Z,1622754964.443 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:16:35.567Z,1622754995.567 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:16:44.288Z,1622755004.288 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-06-03T21:16:44.288Z,1622755004.288 [Default:CheckIn:C.Wait] Stopped 2021-06-03T21:16:44.288Z,1622755004.288 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-06-03T21:16:44.289Z,1622755004.289 [Default:CheckIn:D] Running Loop=1 2021-06-03T21:16:44.685Z,1622755004.685 [Default:CheckIn:D] Stopped 2021-06-03T21:16:44.685Z,1622755004.685 [Default:CheckIn:E] Running Loop=1 2021-06-03T21:16:45.091Z,1622755005.091 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 219.006299 min 2021-06-03T21:16:45.091Z,1622755005.091 [Default:CheckIn:E] Stopped 2021-06-03T21:16:45.091Z,1622755005.091 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-06-03T21:16:45.091Z,1622755005.091 [Default:CheckIn] Stopped 2021-06-03T21:16:45.091Z,1622755005.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T21:16:45.092Z,1622755005.092 [Default:CheckIn](INFO): Running loop #28 2021-06-03T21:16:45.092Z,1622755005.092 [Default:CheckIn] Running Loop=28 2021-06-03T21:16:45.092Z,1622755005.092 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-06-03T21:16:45.092Z,1622755005.092 [Default:CheckIn:Read_GPS] Running Loop=1 2021-06-03T21:16:46.700Z,1622755006.700 [NAL9602](FAULT): GPS failed to acquire within timeout. 2021-06-03T21:16:46.700Z,1622755006.700 [NAL9602] Data Fault, FailCount= 2 2021-06-03T21:16:46.700Z,1622755006.700 [NAL9602](ERROR): Data Fault 2021-06-03T21:16:46.721Z,1622755006.721 [CBIT](ERROR): Data Fault in component: NAL9602 2021-06-03T21:16:47.112Z,1622755007.112 [NAL9602](INFO): Powering down 2021-06-03T21:16:47.934Z,1622755007.934 [CBIT](INFO): Clearing failed state for component NAL9602 2021-06-03T21:16:47.934Z,1622755007.934 [NAL9602] No Fault, FailCount= 2 2021-06-03T21:17:06.691Z,1622755026.691 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:17:17.400Z,1622755037.400 [NAL9602](INFO): Powering up NAL9602 2021-06-03T21:17:28.312Z,1622755048.312 [NAL9602](INFO): NAL9602 initialized 2021-06-03T21:17:37.815Z,1622755057.815 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:17:44.855Z,1622755064.855 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.731110 2021-06-03T21:18:39.071Z,1622755119.071 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:19:10.195Z,1622755150.195 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:19:41.343Z,1622755181.343 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:20:12.468Z,1622755212.468 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:20:43.599Z,1622755243.599 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2021-06-03T21:20:46.315Z,1622755246.315 [CommandLine](IMPORTANT): got command quit 2021-06-03T21:20:47.323Z,1622755247.323 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:47.323Z,1622755247.323 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:47.491Z,1622755247.491 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2021-06-03T21:20:47.491Z,1622755247.491 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:47.492Z,1622755247.492 [CommandLine](INFO): Join timeout helper Thread ID is 2773 2021-06-03T21:20:47.527Z,1622755247.527 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2021-06-03T21:20:47.527Z,1622755247.527 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:47.527Z,1622755247.527 [NavChartDb](INFO): Join timeout helper Thread ID is 2774 2021-06-03T21:20:47.603Z,1622755247.603 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:47.603Z,1622755247.603 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:47.615Z,1622755247.615 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2021-06-03T21:20:47.615Z,1622755247.615 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:47.615Z,1622755247.615 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2775 2021-06-03T21:20:48.003Z,1622755248.003 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:48.003Z,1622755248.003 [WetLabsBB2FL](INFO): Powering down 2021-06-03T21:20:48.004Z,1622755248.004 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:48.015Z,1622755248.015 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2021-06-03T21:20:48.015Z,1622755248.015 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:48.015Z,1622755248.015 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2776 2021-06-03T21:20:48.855Z,1622755248.855 [CTD_Seabird](INFO): Powering down 2021-06-03T21:20:48.867Z,1622755248.867 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:48.867Z,1622755248.867 [CTD_Seabird](INFO): Powering down 2021-06-03T21:20:48.879Z,1622755248.879 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:48.887Z,1622755248.887 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2021-06-03T21:20:48.887Z,1622755248.887 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:48.887Z,1622755248.887 [Radio_Surface](INFO): Join timeout helper Thread ID is 2777 2021-06-03T21:20:49.235Z,1622755249.235 [Radio_Surface](INFO): Powering down 2021-06-03T21:20:49.236Z,1622755249.236 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:49.236Z,1622755249.236 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:49.251Z,1622755249.251 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2021-06-03T21:20:49.252Z,1622755249.252 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:49.252Z,1622755249.252 [Onboard](INFO): Join timeout helper Thread ID is 2778 2021-06-03T21:20:50.011Z,1622755250.011 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:50.011Z,1622755250.011 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.027Z,1622755250.027 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2021-06-03T21:20:50.027Z,1622755250.027 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.028Z,1622755250.028 [DataOverHttps](INFO): Join timeout helper Thread ID is 2779 2021-06-03T21:20:50.627Z,1622755250.627 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:50.627Z,1622755250.627 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.631Z,1622755250.631 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2021-06-03T21:20:50.632Z,1622755250.632 [logger ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.632Z,1622755250.632 [logger](INFO): Join timeout helper Thread ID is 2780 2021-06-03T21:20:50.643Z,1622755250.643 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:50.643Z,1622755250.643 [logger ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.651Z,1622755250.651 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2021-06-03T21:20:50.651Z,1622755250.651 [CommandLine ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.652Z,1622755250.652 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2021-06-03T21:20:50.652Z,1622755250.652 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.652Z,1622755250.652 [controlThread](INFO): Join timeout helper Thread ID is 2781 2021-06-03T21:20:50.695Z,1622755250.695 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2021-06-03T21:20:50.695Z,1622755250.695 [controlThread](DEBUG): Uninitializing ControlThread 2021-06-03T21:20:50.695Z,1622755250.695 [AHRS_M2](INFO): Powering down 2021-06-03T21:20:50.768Z,1622755250.768 [NAL9602](INFO): Powering down 2021-06-03T21:20:50.770Z,1622755250.770 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2021-06-03T21:20:50.771Z,1622755250.771 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2021-06-03T21:20:50.772Z,1622755250.772 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2021-06-03T21:20:50.772Z,1622755250.772 [MissionManager](INFO): Uninitializing Mission Default 2021-06-03T21:20:50.773Z,1622755250.773 [Default] Stopped 2021-06-03T21:20:50.773Z,1622755250.773 [Default](DEBUG): Aggregate::uninitialize Default 2021-06-03T21:20:50.773Z,1622755250.773 [Default:B.GoToSurface] Stopped 2021-06-03T21:20:50.773Z,1622755250.773 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-06-03T21:20:50.773Z,1622755250.773 [Default:CheckIn] Stopped 2021-06-03T21:20:50.773Z,1622755250.773 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-06-03T21:20:50.773Z,1622755250.773 [Default:CheckIn:Read_GPS] Stopped 2021-06-03T21:20:50.777Z,1622755250.777 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2021-06-03T21:20:50.777Z,1622755250.777 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2021-06-03T21:20:50.777Z,1622755250.777 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2021-06-03T21:20:50.777Z,1622755250.777 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2021-06-03T21:20:50.778Z,1622755250.778 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-06-03T21:20:50.778Z,1622755250.778 [BuoyancyServo](INFO): Powering down 2021-06-03T21:20:50.791Z,1622755250.791 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2021-06-03T21:20:50.791Z,1622755250.791 [ElevatorServo](INFO): Powering down 2021-06-03T21:20:50.792Z,1622755250.792 [MassServo](DEBUG): Uninitialize Mass Servo. 2021-06-03T21:20:50.792Z,1622755250.792 [MassServo](INFO): Powering down 2021-06-03T21:20:50.793Z,1622755250.793 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-06-03T21:20:50.793Z,1622755250.793 [RudderServo](INFO): Powering down 2021-06-03T21:20:50.794Z,1622755250.794 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2021-06-03T21:20:50.794Z,1622755250.794 [ThrusterServo](INFO): Powering down 2021-06-03T21:20:50.795Z,1622755250.795 [SBIT](DEBUG): Uninitialize SBIT Component. 2021-06-03T21:20:50.796Z,1622755250.796 [IBIT](DEBUG): Uninitialize IBIT Component. 2021-06-03T21:20:50.796Z,1622755250.796 [CBIT](DEBUG): Uninitialize CBIT Component. 2021-06-03T21:20:50.796Z,1622755250.796 [CBIT](DEBUG): Powering off loads. 2021-06-03T21:20:50.807Z,1622755250.806 [CBIT](DEBUG): Disabling WDT. 2021-06-03T21:20:50.819Z,1622755250.819 [CBIT](DEBUG): Opening all GF detection circuits. 2021-06-03T21:20:50.819Z,1622755250.819 [controlThread ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.866Z,1622755250.866 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.869Z,1622755250.869 [Onboard ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.875Z,1622755250.875 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.945Z,1622755250.945 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.948Z,1622755250.948 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:50.988Z,1622755250.988 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2021-06-03T21:20:51.063Z,1622755251.063 [logger ThreadHandler](INFO): Thread cancelled.