2018-08-02T18:17:58.407Z,1533233878.407 [CommandLine](IMPORTANT): got command restart logs 2018-08-02T18:18:01.968Z,1533233881.968 [NAL9602](INFO): Powering down 2018-08-02T18:21:49.556Z,1533234109.556 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T18:21:49.556Z,1533234109.556 [Default:CheckIn:C.Wait] Stopped 2018-08-02T18:21:49.556Z,1533234109.556 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T18:21:49.557Z,1533234109.557 [Default:CheckIn:D] Running Loop=1 2018-08-02T18:21:49.948Z,1533234109.948 [Default:CheckIn:D] Stopped 2018-08-02T18:21:49.948Z,1533234109.948 [Default:CheckIn:E] Running Loop=1 2018-08-02T18:21:50.352Z,1533234110.352 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.600317 min 2018-08-02T18:21:50.353Z,1533234110.353 [Default:CheckIn:E] Stopped 2018-08-02T18:21:50.353Z,1533234110.353 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T18:21:50.353Z,1533234110.353 [Default:CheckIn] Stopped 2018-08-02T18:21:50.353Z,1533234110.353 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T18:21:50.353Z,1533234110.353 [Default:CheckIn](INFO): Running loop #3 2018-08-02T18:21:50.353Z,1533234110.353 [Default:CheckIn] Running Loop=3 2018-08-02T18:21:50.353Z,1533234110.353 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T18:21:50.354Z,1533234110.354 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T18:21:51.102Z,1533234111.102 [NAL9602](INFO): Powering up 2018-08-02T18:22:02.138Z,1533234122.138 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:22:34.134Z,1533234154.134 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T18:22:34.209Z,1533234154.209 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T18:22:34.209Z,1533234154.209 [NAL9602] Data Fault, FailCount= 2 2018-08-02T18:22:34.209Z,1533234154.209 [NAL9602](ERROR): Data Fault 2018-08-02T18:22:34.312Z,1533234154.312 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T18:22:34.534Z,1533234154.534 [NAL9602](INFO): Powering down 2018-08-02T18:22:35.393Z,1533234155.393 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T18:22:35.393Z,1533234155.393 [NAL9602] No Fault, FailCount= 2 2018-08-02T18:23:04.562Z,1533234184.562 [NAL9602](INFO): Powering up NAL9602 2018-08-02T18:23:15.762Z,1533234195.762 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:23:16.562Z,1533234196.562 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T18:23:16.562Z,1533234196.562 [NAL9602] Data Fault, FailCount= 3 2018-08-02T18:23:16.562Z,1533234196.562 [NAL9602](ERROR): Data Fault 2018-08-02T18:23:16.714Z,1533234196.714 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T18:23:16.962Z,1533234196.962 [NAL9602](INFO): Powering down 2018-08-02T18:23:17.822Z,1533234197.822 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T18:23:17.822Z,1533234197.822 [NAL9602] No Fault, FailCount= 3 2018-08-02T18:23:46.966Z,1533234226.966 [NAL9602](INFO): Powering up NAL9602 2018-08-02T18:23:59.505Z,1533234239.505 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:26:50.575Z,1533234410.575 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T18:21:50.4Z 2018-08-02T18:26:50.575Z,1533234410.575 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T18:26:50.575Z,1533234410.575 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T18:26:56.045Z,1533234416.045 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T171126/Courier0009.lzma 2018-08-02T18:26:56.843Z,1533234416.843 [DataOverHttps](INFO): Moved sent file to Logs/20180802T171126/Courier0009.lzma.bak 2018-08-02T18:26:56.843Z,1533234416.843 [DataOverHttps](INFO): SBD MOMSN=8395429 2018-08-02T18:27:06.070Z,1533234426.070 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T18:27:06.565Z,1533234426.565 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0000.lzma 2018-08-02T18:27:07.363Z,1533234427.363 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0000.lzma.bak 2018-08-02T18:27:07.363Z,1533234427.363 [DataOverHttps](INFO): SBD MOMSN=8395431 2018-08-02T18:27:16.406Z,1533234436.406 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0003.lzma 2018-08-02T18:27:17.207Z,1533234437.207 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0003.lzma.bak 2018-08-02T18:27:17.207Z,1533234437.207 [DataOverHttps](INFO): SBD MOMSN=8395434 2018-08-02T18:27:27.355Z,1533234447.355 [DataOverHttps](INFO): Sending 190 bytes from file Logs/20180802T171126/Express0010.lzma 2018-08-02T18:27:28.744Z,1533234448.744 [DataOverHttps](INFO): Moved sent file to Logs/20180802T171126/Express0010.lzma.bak 2018-08-02T18:27:28.744Z,1533234448.744 [DataOverHttps](INFO): SBD MOMSN=8395436 2018-08-02T18:27:38.093Z,1533234458.093 [NAL9602](INFO): Powering down 2018-08-02T18:27:38.211Z,1533234458.211 [DataOverHttps](INFO): Sending 462 bytes from file Logs/20180802T181758/Express0001.lzma 2018-08-02T18:27:38.995Z,1533234458.995 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0001.lzma.bak 2018-08-02T18:27:38.995Z,1533234458.995 [DataOverHttps](INFO): SBD MOMSN=8395440 2018-08-02T18:27:48.829Z,1533234468.829 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20180802T181758/Express0004.lzma 2018-08-02T18:27:49.627Z,1533234469.627 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0004.lzma.bak 2018-08-02T18:27:49.627Z,1533234469.627 [DataOverHttps](INFO): SBD MOMSN=8395446 2018-08-02T18:27:50.769Z,1533234470.769 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T18:27:50.769Z,1533234470.769 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T18:27:50.769Z,1533234470.769 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T18:32:51.181Z,1533234771.181 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T18:32:51.181Z,1533234771.181 [Default:CheckIn:C.Wait] Stopped 2018-08-02T18:32:51.181Z,1533234771.181 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T18:32:51.182Z,1533234771.182 [Default:CheckIn:D] Running Loop=1 2018-08-02T18:32:51.588Z,1533234771.588 [Default:CheckIn:D] Stopped 2018-08-02T18:32:51.589Z,1533234771.589 [Default:CheckIn:E] Running Loop=1 2018-08-02T18:32:54.794Z,1533234774.794 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.627661 min 2018-08-02T18:32:54.794Z,1533234774.794 [Default:CheckIn:E] Stopped 2018-08-02T18:32:54.795Z,1533234774.795 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T18:32:54.795Z,1533234774.795 [Default:CheckIn] Stopped 2018-08-02T18:32:54.795Z,1533234774.795 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T18:32:54.795Z,1533234774.795 [Default:CheckIn](INFO): Running loop #4 2018-08-02T18:32:54.795Z,1533234774.795 [Default:CheckIn] Running Loop=4 2018-08-02T18:32:54.795Z,1533234774.795 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T18:32:54.795Z,1533234774.795 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T18:32:55.286Z,1533234775.286 [NAL9602](INFO): Powering up 2018-08-02T18:33:06.479Z,1533234786.479 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:33:38.478Z,1533234818.478 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T18:33:38.557Z,1533234818.557 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T18:33:38.557Z,1533234818.557 [NAL9602] Data Fault, FailCount= 4 2018-08-02T18:33:38.557Z,1533234818.557 [NAL9602](ERROR): Data Fault 2018-08-02T18:33:38.651Z,1533234818.651 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T18:33:38.878Z,1533234818.878 [NAL9602](INFO): Powering down 2018-08-02T18:33:39.742Z,1533234819.742 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T18:33:39.742Z,1533234819.742 [NAL9602] No Fault, FailCount= 4 2018-08-02T18:34:09.042Z,1533234849.042 [NAL9602](INFO): Powering up NAL9602 2018-08-02T18:34:20.242Z,1533234860.242 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:34:21.042Z,1533234861.042 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T18:34:21.042Z,1533234861.042 [NAL9602] Data Fault, FailCount= 5 2018-08-02T18:34:21.042Z,1533234861.042 [NAL9602](ERROR): Data Fault 2018-08-02T18:34:21.129Z,1533234861.129 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T18:34:21.130Z,1533234861.130 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-08-02T18:34:21.446Z,1533234861.446 [NAL9602](INFO): Powering down 2018-08-02T18:34:21.524Z,1533234861.524 [CBIT](INFO): Critical error at 20180802T183421 2018-08-02T18:34:21.524Z,1533234861.524 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2018-08-02T18:36:21.233Z,1533234981.233 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T18:36:21.233Z,1533234981.233 [NAL9602] No Fault, FailCount= 5 2018-08-02T18:36:21.566Z,1533234981.566 [NAL9602](INFO): Powering up NAL9602 2018-08-02T18:36:32.773Z,1533234992.773 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:37:55.303Z,1533235075.303 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T18:32:54.8Z 2018-08-02T18:37:55.303Z,1533235075.303 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T18:37:55.304Z,1533235075.304 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T18:37:56.118Z,1533235076.118 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20180802T181758/Courier0006.lzma 2018-08-02T18:37:57.027Z,1533235077.027 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0006.lzma.bak 2018-08-02T18:37:57.027Z,1533235077.027 [DataOverHttps](INFO): SBD MOMSN=8395457 2018-08-02T18:38:06.773Z,1533235086.773 [DataOverHttps](INFO): Sending 357 bytes from file Logs/20180802T181758/Express0007.lzma 2018-08-02T18:38:07.569Z,1533235087.569 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0007.lzma.bak 2018-08-02T18:38:07.569Z,1533235087.569 [DataOverHttps](INFO): SBD MOMSN=8395460 2018-08-02T18:38:08.756Z,1533235088.756 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T18:38:08.756Z,1533235088.756 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T18:38:08.756Z,1533235088.756 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T18:38:12.333Z,1533235092.333 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T18:38:42.838Z,1533235122.838 [NAL9602](INFO): Powering down 2018-08-02T18:42:48.658Z,1533235368.658 [BPC1](ERROR): Bank A: No match for stick 2 serial number:FF9F in the onboard configuration file. 2018-08-02T18:42:48.658Z,1533235368.658 [BPC1](ERROR): Failed to parse Bank A battery data 2018-08-02T18:43:09.070Z,1533235389.070 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T18:43:09.070Z,1533235389.070 [Default:CheckIn:C.Wait] Stopped 2018-08-02T18:43:09.070Z,1533235389.070 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T18:43:09.071Z,1533235389.071 [Default:CheckIn:D] Running Loop=1 2018-08-02T18:43:09.470Z,1533235389.470 [Default:CheckIn:D] Stopped 2018-08-02T18:43:09.470Z,1533235389.470 [Default:CheckIn:E] Running Loop=1 2018-08-02T18:43:12.609Z,1533235392.609 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.925692 min 2018-08-02T18:43:12.609Z,1533235392.609 [Default:CheckIn:E] Stopped 2018-08-02T18:43:12.609Z,1533235392.609 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T18:43:12.610Z,1533235392.610 [Default:CheckIn] Stopped 2018-08-02T18:43:12.610Z,1533235392.610 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T18:43:12.610Z,1533235392.610 [Default:CheckIn](INFO): Running loop #5 2018-08-02T18:43:12.610Z,1533235392.610 [Default:CheckIn] Running Loop=5 2018-08-02T18:43:12.610Z,1533235392.610 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T18:43:12.610Z,1533235392.610 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T18:43:13.041Z,1533235393.041 [NAL9602](INFO): Powering up 2018-08-02T18:43:24.234Z,1533235404.234 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:43:56.238Z,1533235436.238 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T18:43:56.313Z,1533235436.313 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T18:43:56.313Z,1533235436.313 [NAL9602] Data Fault, FailCount= 1 2018-08-02T18:43:56.313Z,1533235436.313 [NAL9602](ERROR): Data Fault 2018-08-02T18:43:56.404Z,1533235436.404 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T18:43:56.634Z,1533235436.634 [NAL9602](INFO): Powering down 2018-08-02T18:43:57.500Z,1533235437.500 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T18:43:57.500Z,1533235437.500 [NAL9602] No Fault, FailCount= 1 2018-08-02T18:44:26.725Z,1533235466.725 [NAL9602](INFO): Powering up NAL9602 2018-08-02T18:44:37.918Z,1533235477.918 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:48:16.767Z,1533235696.767 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T18:43:12.6Z 2018-08-02T18:48:16.767Z,1533235696.767 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T18:48:16.768Z,1533235696.768 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T18:48:23.448Z,1533235703.448 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0009.lzma 2018-08-02T18:48:24.223Z,1533235704.223 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0009.lzma.bak 2018-08-02T18:48:24.224Z,1533235704.224 [DataOverHttps](INFO): SBD MOMSN=8395472 2018-08-02T18:48:28.631Z,1533235708.631 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T18:48:34.365Z,1533235714.365 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20180802T181758/Express0010.lzma 2018-08-02T18:48:35.139Z,1533235715.139 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0010.lzma.bak 2018-08-02T18:48:35.140Z,1533235715.140 [DataOverHttps](INFO): SBD MOMSN=8395474 2018-08-02T18:48:36.274Z,1533235716.274 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T18:48:36.275Z,1533235716.275 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T18:48:36.275Z,1533235716.275 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T18:48:59.150Z,1533235739.150 [NAL9602](INFO): Powering down 2018-08-02T18:49:32.791Z,1533235772.791 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-02T18:49:32.792Z,1533235772.792 [BPC1] Communications Fault, FailCount= 1 2018-08-02T18:49:32.792Z,1533235772.792 [BPC1](ERROR): Communications Fault 2018-08-02T18:49:32.864Z,1533235772.864 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-02T18:49:34.017Z,1533235774.017 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-02T18:49:34.017Z,1533235774.017 [BPC1] No Fault, FailCount= 1 2018-08-02T18:51:41.729Z,1533235901.729 [PNI_TCM](FAULT): Failed to acquire valid data within timeout. 2018-08-02T18:51:41.729Z,1533235901.729 [PNI_TCM] Data Fault, FailCount= 1 2018-08-02T18:51:41.729Z,1533235901.729 [PNI_TCM](ERROR): Data Fault 2018-08-02T18:51:41.760Z,1533235901.760 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.849648 seconds old. 2018-08-02T18:51:41.815Z,1533235901.815 [CBIT](ERROR): Data Fault in component: PNI_TCM 2018-08-02T18:51:41.902Z,1533235901.902 [PNI_TCM](INFO): Powering down 2018-08-02T18:51:41.996Z,1533235901.996 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.085273 seconds old. 2018-08-02T18:51:42.249Z,1533235902.249 [PNI_TCM](FAULT): LCB fault: Software Overcurrent. 2018-08-02T18:51:42.249Z,1533235902.249 [PNI_TCM] Hardware Fault, FailCount= 1 2018-08-02T18:51:42.249Z,1533235902.249 [PNI_TCM](ERROR): Hardware Fault 2018-08-02T18:51:42.258Z,1533235902.258 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.347691 seconds old. 2018-08-02T18:51:42.652Z,1533235902.652 [PNI_TCM](FAULT): LCB fault: Software Overcurrent. 2018-08-02T18:51:42.689Z,1533235902.689 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.778543 seconds old. 2018-08-02T18:51:43.057Z,1533235903.057 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.146106 seconds old. 2018-08-02T18:51:43.104Z,1533235903.104 [CBIT](INFO): Clearing failed state for component PNI_TCM 2018-08-02T18:51:43.104Z,1533235903.104 [PNI_TCM] No Fault, FailCount= 1 2018-08-02T18:51:43.492Z,1533235903.492 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.581039 seconds old. 2018-08-02T18:51:43.893Z,1533235903.893 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 6.982105 seconds old. 2018-08-02T18:51:44.282Z,1533235904.282 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.371022 seconds old. 2018-08-02T18:51:44.660Z,1533235904.660 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 7.749669 seconds old. 2018-08-02T18:51:45.061Z,1533235905.061 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.149924 seconds old. 2018-08-02T18:51:45.492Z,1533235905.492 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.580925 seconds old. 2018-08-02T18:51:45.860Z,1533235905.860 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 8.949098 seconds old. 2018-08-02T18:51:46.268Z,1533235906.268 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 9.356929 seconds old. 2018-08-02T18:53:36.689Z,1533236016.689 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T18:53:36.689Z,1533236016.689 [Default:CheckIn:C.Wait] Stopped 2018-08-02T18:53:36.689Z,1533236016.689 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T18:53:36.690Z,1533236016.690 [Default:CheckIn:D] Running Loop=1 2018-08-02T18:53:37.093Z,1533236017.093 [Default:CheckIn:D] Stopped 2018-08-02T18:53:37.093Z,1533236017.093 [Default:CheckIn:E] Running Loop=1 2018-08-02T18:53:40.300Z,1533236020.300 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.386080 min 2018-08-02T18:53:40.301Z,1533236020.301 [Default:CheckIn:E] Stopped 2018-08-02T18:53:40.301Z,1533236020.301 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T18:53:40.301Z,1533236020.301 [Default:CheckIn] Stopped 2018-08-02T18:53:40.301Z,1533236020.301 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T18:53:40.301Z,1533236020.301 [Default:CheckIn](INFO): Running loop #6 2018-08-02T18:53:40.301Z,1533236020.301 [Default:CheckIn] Running Loop=6 2018-08-02T18:53:40.301Z,1533236020.301 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T18:53:40.302Z,1533236020.302 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T18:53:40.786Z,1533236020.786 [NAL9602](INFO): Powering up 2018-08-02T18:53:51.986Z,1533236031.986 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:53:52.786Z,1533236032.786 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T18:53:52.786Z,1533236032.786 [NAL9602] Data Fault, FailCount= 2 2018-08-02T18:53:52.786Z,1533236032.786 [NAL9602](ERROR): Data Fault 2018-08-02T18:53:52.890Z,1533236032.890 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T18:53:53.186Z,1533236033.186 [NAL9602](INFO): Powering down 2018-08-02T18:53:54.052Z,1533236034.052 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T18:53:54.053Z,1533236034.053 [NAL9602] No Fault, FailCount= 2 2018-08-02T18:54:23.586Z,1533236063.586 [NAL9602](INFO): Powering up NAL9602 2018-08-02T18:54:34.786Z,1533236074.786 [NAL9602](INFO): NAL9602 initialized 2018-08-02T18:55:34.934Z,1533236134.934 [BPC1](ERROR): Failed to receive data from both battery packs 2018-08-02T18:55:34.934Z,1533236134.934 [BPC1] Communications Fault, FailCount= 2 2018-08-02T18:55:34.934Z,1533236134.934 [BPC1](ERROR): Communications Fault 2018-08-02T18:55:34.976Z,1533236134.976 [CBIT](ERROR): Communications Fault in component: BPC1 2018-08-02T18:55:36.184Z,1533236136.184 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-02T18:55:36.184Z,1533236136.184 [BPC1] No Fault, FailCount= 2 2018-08-02T18:58:40.756Z,1533236320.756 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T18:53:40.3Z 2018-08-02T18:58:40.756Z,1533236320.756 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T18:58:40.756Z,1533236320.756 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T18:58:46.177Z,1533236326.177 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0012.lzma 2018-08-02T18:58:46.975Z,1533236326.975 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0012.lzma.bak 2018-08-02T18:58:46.975Z,1533236326.975 [DataOverHttps](INFO): SBD MOMSN=8395486 2018-08-02T18:58:56.423Z,1533236336.423 [DataOverHttps](INFO): Sending 298 bytes from file Logs/20180802T181758/Express0013.lzma 2018-08-02T18:58:57.187Z,1533236337.187 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0013.lzma.bak 2018-08-02T18:58:57.187Z,1533236337.187 [DataOverHttps](INFO): SBD MOMSN=8395488 2018-08-02T18:58:58.385Z,1533236338.385 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T18:58:58.385Z,1533236338.385 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T18:58:58.385Z,1533236338.385 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T18:59:40.550Z,1533236380.550 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T19:00:11.022Z,1533236411.022 [NAL9602](INFO): Powering down 2018-08-02T19:03:58.618Z,1533236638.618 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T19:03:58.618Z,1533236638.618 [Default:CheckIn:C.Wait] Stopped 2018-08-02T19:03:58.618Z,1533236638.618 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T19:03:58.618Z,1533236638.618 [Default:CheckIn:D] Running Loop=1 2018-08-02T19:03:59.002Z,1533236639.002 [Default:CheckIn:D] Stopped 2018-08-02T19:03:59.002Z,1533236639.002 [Default:CheckIn:E] Running Loop=1 2018-08-02T19:03:59.432Z,1533236639.432 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.751221 min 2018-08-02T19:03:59.432Z,1533236639.432 [Default:CheckIn:E] Stopped 2018-08-02T19:03:59.432Z,1533236639.432 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T19:03:59.432Z,1533236639.432 [Default:CheckIn] Stopped 2018-08-02T19:03:59.441Z,1533236639.441 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T19:03:59.441Z,1533236639.441 [Default:CheckIn](INFO): Running loop #7 2018-08-02T19:03:59.441Z,1533236639.441 [Default:CheckIn] Running Loop=7 2018-08-02T19:03:59.441Z,1533236639.441 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T19:03:59.441Z,1533236639.441 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T19:04:03.742Z,1533236643.742 [NAL9602](INFO): Powering up 2018-08-02T19:04:14.898Z,1533236654.898 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:04:46.898Z,1533236686.898 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T19:04:46.973Z,1533236686.973 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T19:04:46.973Z,1533236686.973 [NAL9602] Data Fault, FailCount= 3 2018-08-02T19:04:46.973Z,1533236686.973 [NAL9602](ERROR): Data Fault 2018-08-02T19:04:47.057Z,1533236687.057 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:04:47.298Z,1533236687.298 [NAL9602](INFO): Powering down 2018-08-02T19:04:48.154Z,1533236688.154 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:04:48.154Z,1533236688.154 [NAL9602] No Fault, FailCount= 3 2018-08-02T19:05:17.306Z,1533236717.306 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:05:28.506Z,1533236728.506 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:05:29.306Z,1533236729.306 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T19:05:29.306Z,1533236729.306 [NAL9602] Data Fault, FailCount= 4 2018-08-02T19:05:29.306Z,1533236729.306 [NAL9602](ERROR): Data Fault 2018-08-02T19:05:29.404Z,1533236729.404 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:05:29.706Z,1533236729.706 [NAL9602](INFO): Powering down 2018-08-02T19:05:30.562Z,1533236730.562 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:05:30.562Z,1533236730.562 [NAL9602] No Fault, FailCount= 4 2018-08-02T19:05:59.145Z,1533236759.145 [CommandLine](IMPORTANT): got command burn 10.000000 2018-08-02T19:05:59.714Z,1533236759.714 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:06:09.221Z,1533236769.221 [CommandLine](IMPORTANT): Deactivating dropweight wire 2018-08-02T19:06:10.658Z,1533236770.658 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:06:11.669Z,1533236771.669 [CommandLine](IMPORTANT): got command burn on 2018-08-02T19:06:11.669Z,1533236771.669 [CommandLine](IMPORTANT): Activating dropweight wire 2018-08-02T19:08:59.721Z,1533236939.721 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T19:03:59.4Z 2018-08-02T19:08:59.721Z,1533236939.721 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T19:08:59.722Z,1533236939.722 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T19:09:03.810Z,1533236943.810 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0015.lzma 2018-08-02T19:09:04.599Z,1533236944.599 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0015.lzma.bak 2018-08-02T19:09:04.599Z,1533236944.599 [DataOverHttps](INFO): SBD MOMSN=8395502 2018-08-02T19:09:14.931Z,1533236954.931 [DataOverHttps](INFO): Sending 318 bytes from file Logs/20180802T181758/Express0016.lzma 2018-08-02T19:09:15.727Z,1533236955.727 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0016.lzma.bak 2018-08-02T19:09:15.727Z,1533236955.727 [DataOverHttps](INFO): SBD MOMSN=8395504 2018-08-02T19:09:16.878Z,1533236956.878 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T19:09:16.879Z,1533236956.879 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T19:09:16.879Z,1533236956.879 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T19:09:20.161Z,1533236960.161 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T19:09:33.188Z,1533236973.188 [CommandLine](IMPORTANT): got command burn off 2018-08-02T19:09:33.189Z,1533236973.189 [CommandLine](IMPORTANT): Deactivating dropweight wire 2018-08-02T19:09:50.682Z,1533236990.682 [NAL9602](INFO): Powering down 2018-08-02T19:14:17.266Z,1533237257.266 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T19:14:17.266Z,1533237257.266 [Default:CheckIn:C.Wait] Stopped 2018-08-02T19:14:17.266Z,1533237257.266 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T19:14:17.267Z,1533237257.267 [Default:CheckIn:D] Running Loop=1 2018-08-02T19:14:17.668Z,1533237257.668 [Default:CheckIn:D] Stopped 2018-08-02T19:14:17.668Z,1533237257.668 [Default:CheckIn:E] Running Loop=1 2018-08-02T19:14:18.066Z,1533237258.066 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.062321 min 2018-08-02T19:14:18.066Z,1533237258.066 [Default:CheckIn:E] Stopped 2018-08-02T19:14:18.066Z,1533237258.066 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T19:14:18.066Z,1533237258.066 [Default:CheckIn] Stopped 2018-08-02T19:14:18.067Z,1533237258.067 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T19:14:18.067Z,1533237258.067 [Default:CheckIn](INFO): Running loop #8 2018-08-02T19:14:18.067Z,1533237258.067 [Default:CheckIn] Running Loop=8 2018-08-02T19:14:18.067Z,1533237258.067 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T19:14:18.067Z,1533237258.067 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T19:14:21.343Z,1533237261.343 [NAL9602](INFO): Powering up 2018-08-02T19:14:32.494Z,1533237272.494 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:15:04.494Z,1533237304.494 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T19:15:04.569Z,1533237304.569 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T19:15:04.569Z,1533237304.569 [NAL9602] Data Fault, FailCount= 5 2018-08-02T19:15:04.569Z,1533237304.569 [NAL9602](ERROR): Data Fault 2018-08-02T19:15:04.651Z,1533237304.651 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:15:04.652Z,1533237304.652 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-08-02T19:15:04.894Z,1533237304.894 [NAL9602](INFO): Powering down 2018-08-02T19:15:04.971Z,1533237304.971 [CBIT](INFO): Critical error at 20180802T191504 2018-08-02T19:16:36.985Z,1533237396.985 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 23 sticks. 2018-08-02T19:16:36.985Z,1533237396.985 [BPC1] Data Fault, FailCount= 3 2018-08-02T19:16:36.985Z,1533237396.985 [BPC1](ERROR): Data Fault 2018-08-02T19:16:37.037Z,1533237397.037 [CBIT](ERROR): Data Fault in component: BPC1 2018-08-02T19:16:38.241Z,1533237398.241 [CBIT](INFO): Clearing failed state for component BPC1 2018-08-02T19:16:38.241Z,1533237398.241 [BPC1] No Fault, FailCount= 3 2018-08-02T19:17:04.612Z,1533237424.612 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:17:04.612Z,1533237424.612 [NAL9602] No Fault, FailCount= 5 2018-08-02T19:17:04.958Z,1533237424.958 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:17:16.158Z,1533237436.158 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:17:16.958Z,1533237436.958 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T19:17:16.958Z,1533237436.958 [NAL9602] Data Fault, FailCount= 1 2018-08-02T19:17:16.958Z,1533237436.958 [NAL9602](ERROR): Data Fault 2018-08-02T19:17:17.073Z,1533237437.073 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:17:17.358Z,1533237437.358 [NAL9602](INFO): Powering down 2018-08-02T19:17:18.229Z,1533237438.229 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:17:18.229Z,1533237438.229 [NAL9602] No Fault, FailCount= 1 2018-08-02T19:17:47.446Z,1533237467.446 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:17:58.246Z,1533237478.246 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:19:18.405Z,1533237558.405 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T19:14:18.1Z 2018-08-02T19:19:18.405Z,1533237558.405 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T19:19:18.406Z,1533237558.406 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T19:19:23.663Z,1533237563.663 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20180802T181758/Courier0018.lzma 2018-08-02T19:19:24.291Z,1533237564.291 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0018.lzma.bak 2018-08-02T19:19:24.291Z,1533237564.291 [DataOverHttps](INFO): SBD MOMSN=8395521 2018-08-02T19:19:33.764Z,1533237573.764 [DataOverHttps](INFO): Sending 371 bytes from file Logs/20180802T181758/Express0019.lzma 2018-08-02T19:19:34.563Z,1533237574.563 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0019.lzma.bak 2018-08-02T19:19:34.564Z,1533237574.564 [DataOverHttps](INFO): SBD MOMSN=8395524 2018-08-02T19:19:35.701Z,1533237575.701 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T19:19:35.702Z,1533237575.702 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T19:19:35.702Z,1533237575.702 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T19:19:35.778Z,1533237575.778 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T19:20:08.926Z,1533237608.926 [NAL9602](INFO): Powering down 2018-08-02T19:24:36.105Z,1533237876.105 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T19:24:36.105Z,1533237876.105 [Default:CheckIn:C.Wait] Stopped 2018-08-02T19:24:36.105Z,1533237876.105 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T19:24:36.105Z,1533237876.105 [Default:CheckIn:D] Running Loop=1 2018-08-02T19:24:36.504Z,1533237876.504 [Default:CheckIn:D] Stopped 2018-08-02T19:24:36.504Z,1533237876.504 [Default:CheckIn:E] Running Loop=1 2018-08-02T19:24:39.711Z,1533237879.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.376261 min 2018-08-02T19:24:39.712Z,1533237879.712 [Default:CheckIn:E] Stopped 2018-08-02T19:24:39.712Z,1533237879.712 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T19:24:39.712Z,1533237879.712 [Default:CheckIn] Stopped 2018-08-02T19:24:39.712Z,1533237879.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T19:24:39.712Z,1533237879.712 [Default:CheckIn](INFO): Running loop #9 2018-08-02T19:24:39.713Z,1533237879.713 [Default:CheckIn] Running Loop=9 2018-08-02T19:24:39.713Z,1533237879.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T19:24:39.713Z,1533237879.713 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T19:24:40.170Z,1533237880.170 [NAL9602](INFO): Powering up 2018-08-02T19:24:51.366Z,1533237891.366 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:25:23.366Z,1533237923.366 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T19:25:23.449Z,1533237923.449 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T19:25:23.449Z,1533237923.449 [NAL9602] Data Fault, FailCount= 2 2018-08-02T19:25:23.449Z,1533237923.449 [NAL9602](ERROR): Data Fault 2018-08-02T19:25:23.540Z,1533237923.540 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:25:23.770Z,1533237923.770 [NAL9602](INFO): Powering down 2018-08-02T19:25:24.635Z,1533237924.635 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:25:24.635Z,1533237924.635 [NAL9602] No Fault, FailCount= 2 2018-08-02T19:25:53.934Z,1533237953.934 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:26:05.134Z,1533237965.134 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:29:40.225Z,1533238180.225 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T19:24:39.7Z 2018-08-02T19:29:40.225Z,1533238180.225 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T19:29:40.225Z,1533238180.225 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T19:29:45.256Z,1533238185.256 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0021.lzma 2018-08-02T19:29:46.047Z,1533238186.047 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0021.lzma.bak 2018-08-02T19:29:46.047Z,1533238186.047 [DataOverHttps](INFO): SBD MOMSN=8395539 2018-08-02T19:29:55.301Z,1533238195.301 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T19:29:55.401Z,1533238195.401 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20180802T181758/Express0022.lzma 2018-08-02T19:29:56.175Z,1533238196.175 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0022.lzma.bak 2018-08-02T19:29:56.175Z,1533238196.175 [DataOverHttps](INFO): SBD MOMSN=8395541 2018-08-02T19:29:57.334Z,1533238197.334 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T19:29:57.334Z,1533238197.334 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T19:29:57.334Z,1533238197.334 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T19:30:25.546Z,1533238225.546 [NAL9602](INFO): Powering down 2018-08-02T19:34:57.748Z,1533238497.748 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T19:34:57.749Z,1533238497.749 [Default:CheckIn:C.Wait] Stopped 2018-08-02T19:34:57.749Z,1533238497.749 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T19:34:57.749Z,1533238497.749 [Default:CheckIn:D] Running Loop=1 2018-08-02T19:34:58.148Z,1533238498.148 [Default:CheckIn:D] Stopped 2018-08-02T19:34:58.148Z,1533238498.148 [Default:CheckIn:E] Running Loop=1 2018-08-02T19:35:01.264Z,1533238501.264 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.736987 min 2018-08-02T19:35:01.264Z,1533238501.264 [Default:CheckIn:E] Stopped 2018-08-02T19:35:01.264Z,1533238501.264 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T19:35:01.297Z,1533238501.297 [Default:CheckIn] Stopped 2018-08-02T19:35:01.297Z,1533238501.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T19:35:01.297Z,1533238501.297 [Default:CheckIn](INFO): Running loop #10 2018-08-02T19:35:01.297Z,1533238501.297 [Default:CheckIn] Running Loop=10 2018-08-02T19:35:01.297Z,1533238501.297 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T19:35:01.297Z,1533238501.297 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T19:35:01.742Z,1533238501.742 [NAL9602](INFO): Powering up 2018-08-02T19:35:12.938Z,1533238512.938 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:35:13.738Z,1533238513.738 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T19:35:13.738Z,1533238513.738 [NAL9602] Data Fault, FailCount= 3 2018-08-02T19:35:13.738Z,1533238513.738 [NAL9602](ERROR): Data Fault 2018-08-02T19:35:13.825Z,1533238513.825 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:35:14.138Z,1533238514.138 [NAL9602](INFO): Powering down 2018-08-02T19:35:14.999Z,1533238514.999 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:35:14.999Z,1533238514.999 [NAL9602] No Fault, FailCount= 3 2018-08-02T19:35:44.538Z,1533238544.538 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:35:55.338Z,1533238555.338 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:40:01.857Z,1533238801.857 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T19:35:01.3Z 2018-08-02T19:40:01.857Z,1533238801.857 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T19:40:01.857Z,1533238801.857 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T19:40:06.823Z,1533238806.823 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0024.lzma 2018-08-02T19:40:07.615Z,1533238807.615 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0024.lzma.bak 2018-08-02T19:40:07.615Z,1533238807.615 [DataOverHttps](INFO): SBD MOMSN=8395552 2018-08-02T19:40:17.754Z,1533238817.754 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20180802T181758/Express0025.lzma 2018-08-02T19:40:18.527Z,1533238818.527 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0025.lzma.bak 2018-08-02T19:40:18.527Z,1533238818.527 [DataOverHttps](INFO): SBD MOMSN=8395554 2018-08-02T19:40:19.758Z,1533238819.758 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T19:40:19.758Z,1533238819.758 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T19:40:19.758Z,1533238819.758 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T19:40:57.854Z,1533238857.854 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T19:41:28.386Z,1533238888.386 [NAL9602](INFO): Powering down 2018-08-02T19:45:20.142Z,1533239120.142 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T19:45:20.142Z,1533239120.142 [Default:CheckIn:C.Wait] Stopped 2018-08-02T19:45:20.142Z,1533239120.142 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T19:45:20.142Z,1533239120.142 [Default:CheckIn:D] Running Loop=1 2018-08-02T19:45:20.545Z,1533239120.545 [Default:CheckIn:D] Stopped 2018-08-02T19:45:20.546Z,1533239120.546 [Default:CheckIn:E] Running Loop=1 2018-08-02T19:45:23.758Z,1533239123.758 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.110278 min 2018-08-02T19:45:23.758Z,1533239123.758 [Default:CheckIn:E] Stopped 2018-08-02T19:45:23.758Z,1533239123.758 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T19:45:23.758Z,1533239123.758 [Default:CheckIn] Stopped 2018-08-02T19:45:23.758Z,1533239123.758 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T19:45:23.759Z,1533239123.759 [Default:CheckIn](INFO): Running loop #11 2018-08-02T19:45:23.759Z,1533239123.759 [Default:CheckIn] Running Loop=11 2018-08-02T19:45:23.759Z,1533239123.759 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T19:45:23.759Z,1533239123.759 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T19:45:24.206Z,1533239124.206 [NAL9602](INFO): Powering up 2018-08-02T19:45:35.406Z,1533239135.406 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:46:07.406Z,1533239167.406 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T19:46:07.481Z,1533239167.481 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T19:46:07.481Z,1533239167.481 [NAL9602] Data Fault, FailCount= 4 2018-08-02T19:46:07.481Z,1533239167.481 [NAL9602](ERROR): Data Fault 2018-08-02T19:46:07.572Z,1533239167.572 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:46:07.806Z,1533239167.806 [NAL9602](INFO): Powering down 2018-08-02T19:46:08.667Z,1533239168.667 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:46:08.667Z,1533239168.667 [NAL9602] No Fault, FailCount= 4 2018-08-02T19:46:37.878Z,1533239197.878 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:46:49.078Z,1533239209.078 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:46:49.878Z,1533239209.878 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T19:46:49.878Z,1533239209.878 [NAL9602] Data Fault, FailCount= 5 2018-08-02T19:46:49.878Z,1533239209.878 [NAL9602](ERROR): Data Fault 2018-08-02T19:46:49.974Z,1533239209.974 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:46:49.975Z,1533239209.975 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-08-02T19:46:50.278Z,1533239210.278 [NAL9602](INFO): Powering down 2018-08-02T19:46:50.339Z,1533239210.339 [CBIT](INFO): Critical error at 20180802T194649 2018-08-02T19:48:50.095Z,1533239330.095 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:48:50.095Z,1533239330.095 [NAL9602] No Fault, FailCount= 5 2018-08-02T19:48:50.439Z,1533239330.439 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:49:01.634Z,1533239341.634 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:50:24.096Z,1533239424.096 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T19:45:23.8Z 2018-08-02T19:50:24.096Z,1533239424.096 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T19:50:24.098Z,1533239424.098 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T19:50:29.092Z,1533239429.092 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180802T181758/Courier0027.lzma 2018-08-02T19:50:29.887Z,1533239429.887 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0027.lzma.bak 2018-08-02T19:50:29.887Z,1533239429.887 [DataOverHttps](INFO): SBD MOMSN=8395566 2018-08-02T19:50:39.209Z,1533239439.209 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T19:50:39.311Z,1533239439.311 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20180802T181758/Express0028.lzma 2018-08-02T19:50:40.087Z,1533239440.087 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0028.lzma.bak 2018-08-02T19:50:40.087Z,1533239440.087 [DataOverHttps](INFO): SBD MOMSN=8395569 2018-08-02T19:50:41.241Z,1533239441.241 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T19:50:41.242Z,1533239441.242 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T19:50:41.242Z,1533239441.242 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T19:51:09.710Z,1533239469.710 [NAL9602](INFO): Powering down 2018-08-02T19:55:41.678Z,1533239741.678 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T19:55:41.679Z,1533239741.679 [Default:CheckIn:C.Wait] Stopped 2018-08-02T19:55:41.679Z,1533239741.679 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T19:55:41.679Z,1533239741.679 [Default:CheckIn:D] Running Loop=1 2018-08-02T19:55:42.084Z,1533239742.084 [Default:CheckIn:D] Stopped 2018-08-02T19:55:42.084Z,1533239742.084 [Default:CheckIn:E] Running Loop=1 2018-08-02T19:55:45.190Z,1533239745.190 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.469263 min 2018-08-02T19:55:45.191Z,1533239745.191 [Default:CheckIn:E] Stopped 2018-08-02T19:55:45.191Z,1533239745.191 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T19:55:45.191Z,1533239745.191 [Default:CheckIn] Stopped 2018-08-02T19:55:45.191Z,1533239745.191 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T19:55:45.191Z,1533239745.191 [Default:CheckIn](INFO): Running loop #12 2018-08-02T19:55:45.191Z,1533239745.191 [Default:CheckIn] Running Loop=12 2018-08-02T19:55:45.192Z,1533239745.192 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T19:55:45.192Z,1533239745.192 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T19:55:45.646Z,1533239745.646 [NAL9602](INFO): Powering up 2018-08-02T19:55:56.842Z,1533239756.842 [NAL9602](INFO): NAL9602 initialized 2018-08-02T19:56:28.847Z,1533239788.847 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-08-02T19:56:28.925Z,1533239788.925 [NAL9602](FAULT): received: +CSQ:0 OK738, 0, 0, 0, 0 OK 2018-08-02T19:56:28.925Z,1533239788.925 [NAL9602] Data Fault, FailCount= 1 2018-08-02T19:56:28.925Z,1533239788.925 [NAL9602](ERROR): Data Fault 2018-08-02T19:56:29.016Z,1533239789.016 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T19:56:29.242Z,1533239789.242 [NAL9602](INFO): Powering down 2018-08-02T19:56:30.101Z,1533239790.101 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T19:56:30.101Z,1533239790.101 [NAL9602] No Fault, FailCount= 1 2018-08-02T19:56:59.347Z,1533239819.347 [NAL9602](INFO): Powering up NAL9602 2018-08-02T19:57:10.546Z,1533239830.546 [NAL9602](INFO): NAL9602 initialized 2018-08-02T20:00:46.499Z,1533240046.499 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T19:55:45.2Z 2018-08-02T20:00:46.499Z,1533240046.499 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T20:00:46.500Z,1533240046.500 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T20:00:51.523Z,1533240051.523 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0030.lzma 2018-08-02T20:00:52.319Z,1533240052.319 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0030.lzma.bak 2018-08-02T20:00:52.319Z,1533240052.319 [DataOverHttps](INFO): SBD MOMSN=8395581 2018-08-02T20:01:02.425Z,1533240062.425 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T20:01:02.535Z,1533240062.535 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20180802T181758/Express0031.lzma 2018-08-02T20:01:03.335Z,1533240063.335 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0031.lzma.bak 2018-08-02T20:01:03.335Z,1533240063.335 [DataOverHttps](INFO): SBD MOMSN=8395583 2018-08-02T20:01:04.491Z,1533240064.491 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T20:01:04.491Z,1533240064.491 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T20:01:04.491Z,1533240064.491 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T20:01:32.618Z,1533240092.618 [NAL9602](INFO): Powering down 2018-08-02T20:06:04.955Z,1533240364.955 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T20:06:04.955Z,1533240364.955 [Default:CheckIn:C.Wait] Stopped 2018-08-02T20:06:04.955Z,1533240364.955 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T20:06:04.956Z,1533240364.956 [Default:CheckIn:D] Running Loop=1 2018-08-02T20:06:05.364Z,1533240365.364 [Default:CheckIn:D] Stopped 2018-08-02T20:06:05.364Z,1533240365.364 [Default:CheckIn:E] Running Loop=1 2018-08-02T20:06:08.515Z,1533240368.515 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.857259 min 2018-08-02T20:06:08.515Z,1533240368.515 [Default:CheckIn:E] Stopped 2018-08-02T20:06:08.515Z,1533240368.515 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T20:06:08.515Z,1533240368.515 [Default:CheckIn] Stopped 2018-08-02T20:06:08.515Z,1533240368.515 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T20:06:08.516Z,1533240368.516 [Default:CheckIn](INFO): Running loop #13 2018-08-02T20:06:08.516Z,1533240368.516 [Default:CheckIn] Running Loop=13 2018-08-02T20:06:08.516Z,1533240368.516 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T20:06:08.516Z,1533240368.516 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T20:06:08.942Z,1533240368.942 [NAL9602](INFO): Powering up 2018-08-02T20:06:20.142Z,1533240380.142 [NAL9602](INFO): NAL9602 initialized 2018-08-02T20:06:20.946Z,1533240380.946 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T20:06:20.946Z,1533240380.946 [NAL9602] Data Fault, FailCount= 2 2018-08-02T20:06:20.947Z,1533240380.947 [NAL9602](ERROR): Data Fault 2018-08-02T20:06:21.029Z,1533240381.029 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T20:06:21.342Z,1533240381.342 [NAL9602](INFO): Powering down 2018-08-02T20:06:22.204Z,1533240382.204 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T20:06:22.204Z,1533240382.204 [NAL9602] No Fault, FailCount= 2 2018-08-02T20:06:51.742Z,1533240411.742 [NAL9602](INFO): Powering up NAL9602 2018-08-02T20:07:02.942Z,1533240422.942 [NAL9602](INFO): NAL9602 initialized 2018-08-02T20:11:08.899Z,1533240668.899 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T20:06:08.5Z 2018-08-02T20:11:08.899Z,1533240668.899 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T20:11:08.899Z,1533240668.899 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T20:11:13.845Z,1533240673.845 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0033.lzma 2018-08-02T20:11:14.636Z,1533240674.636 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0033.lzma.bak 2018-08-02T20:11:14.637Z,1533240674.637 [DataOverHttps](INFO): SBD MOMSN=8395594 2018-08-02T20:11:25.662Z,1533240685.662 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20180802T181758/Express0034.lzma 2018-08-02T20:11:26.407Z,1533240686.408 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0034.lzma.bak 2018-08-02T20:11:26.408Z,1533240686.408 [DataOverHttps](INFO): SBD MOMSN=8395596 2018-08-02T20:11:27.558Z,1533240687.558 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T20:11:27.558Z,1533240687.558 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T20:11:27.558Z,1533240687.558 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T20:12:08.798Z,1533240728.798 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T20:12:39.402Z,1533240759.402 [NAL9602](INFO): Powering down 2018-08-02T20:15:18.090Z,1533240918.090 [CommandLine](IMPORTANT): got command burn on 2018-08-02T20:15:18.090Z,1533240918.090 [CommandLine](IMPORTANT): Activating dropweight wire 2018-08-02T20:16:28.064Z,1533240988.064 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T20:16:28.064Z,1533240988.064 [Default:CheckIn:C.Wait] Stopped 2018-08-02T20:16:28.064Z,1533240988.064 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T20:16:28.064Z,1533240988.064 [Default:CheckIn:D] Running Loop=1 2018-08-02T20:16:28.421Z,1533240988.421 [Default:CheckIn:D] Stopped 2018-08-02T20:16:28.421Z,1533240988.421 [Default:CheckIn:E] Running Loop=1 2018-08-02T20:16:28.826Z,1533240988.826 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.241536 min 2018-08-02T20:16:28.826Z,1533240988.826 [Default:CheckIn:E] Stopped 2018-08-02T20:16:28.826Z,1533240988.826 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T20:16:28.827Z,1533240988.827 [Default:CheckIn] Stopped 2018-08-02T20:16:28.827Z,1533240988.827 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T20:16:28.827Z,1533240988.827 [Default:CheckIn](INFO): Running loop #14 2018-08-02T20:16:28.827Z,1533240988.827 [Default:CheckIn] Running Loop=14 2018-08-02T20:16:28.827Z,1533240988.827 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T20:16:28.827Z,1533240988.827 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T20:16:32.389Z,1533240992.389 [NAL9602](INFO): Powering up 2018-08-02T20:16:43.306Z,1533241003.306 [NAL9602](INFO): NAL9602 initialized 2018-08-02T20:18:28.734Z,1533241108.734 [CommandLine](IMPORTANT): got command burn off 2018-08-02T20:18:28.734Z,1533241108.734 [CommandLine](IMPORTANT): Deactivating dropweight wire 2018-08-02T20:19:49.979Z,1533241189.979 [CommandLine](IMPORTANT): got command gfscan 2018-08-02T20:19:50.060Z,1533241190.060 [CBIT](IMPORTANT): Beginning ground fault scan 2018-08-02T20:20:00.847Z,1533241200.847 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.022142 CHAN A1 (24V): -0.002465 CHAN A2 (12V): -0.000802 CHAN A3 (5V): -0.002372 CHAN B0 (3.3V): -0.001395 CHAN B1 (3.15aV): -0.000935 CHAN B2 (3.15bV): -0.001029 CHAN B3 (GND): -0.001604 OPEN: 0.004144 Full Scale Calc: 4.765 mA, -1.589 mA 2018-08-02T20:21:28.987Z,1533241288.987 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-08-02T20:16:28.8Z 2018-08-02T20:21:28.987Z,1533241288.987 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T20:21:28.988Z,1533241288.988 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-08-02T20:21:32.730Z,1533241292.730 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180802T181758/Courier0036.lzma 2018-08-02T20:21:33.247Z,1533241293.247 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Courier0036.lzma.bak 2018-08-02T20:21:33.248Z,1533241293.248 [DataOverHttps](INFO): SBD MOMSN=8395607 2018-08-02T20:21:43.998Z,1533241303.998 [DataOverHttps](INFO): Sending 477 bytes from file Logs/20180802T181758/Express0037.lzma 2018-08-02T20:21:44.795Z,1533241304.795 [DataOverHttps](INFO): Moved sent file to Logs/20180802T181758/Express0037.lzma.bak 2018-08-02T20:21:44.795Z,1533241304.795 [DataOverHttps](INFO): SBD MOMSN=8395609 2018-08-02T20:21:45.941Z,1533241305.941 [Default:CheckIn:Read_Iridium] Stopped 2018-08-02T20:21:45.941Z,1533241305.941 [Default:CheckIn:C.Wait] Running Loop=1 2018-08-02T20:21:45.941Z,1533241305.941 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-08-02T20:21:49.116Z,1533241309.116 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-08-02T20:22:19.630Z,1533241339.630 [NAL9602](INFO): Powering down 2018-08-02T20:26:46.216Z,1533241606.216 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-08-02T20:26:46.216Z,1533241606.216 [Default:CheckIn:C.Wait] Stopped 2018-08-02T20:26:46.216Z,1533241606.216 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-08-02T20:26:46.217Z,1533241606.217 [Default:CheckIn:D] Running Loop=1 2018-08-02T20:26:46.611Z,1533241606.611 [Default:CheckIn:D] Stopped 2018-08-02T20:26:46.611Z,1533241606.611 [Default:CheckIn:E] Running Loop=1 2018-08-02T20:26:47.020Z,1533241607.020 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.544710 min 2018-08-02T20:26:47.037Z,1533241607.037 [Default:CheckIn:E] Stopped 2018-08-02T20:26:47.037Z,1533241607.037 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-08-02T20:26:47.037Z,1533241607.037 [Default:CheckIn] Stopped 2018-08-02T20:26:47.037Z,1533241607.037 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T20:26:47.037Z,1533241607.037 [Default:CheckIn](INFO): Running loop #15 2018-08-02T20:26:47.037Z,1533241607.037 [Default:CheckIn] Running Loop=15 2018-08-02T20:26:47.037Z,1533241607.037 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-02T20:26:47.038Z,1533241607.038 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-02T20:26:50.644Z,1533241610.644 [NAL9602](INFO): Powering up 2018-08-02T20:27:01.791Z,1533241621.791 [NAL9602](INFO): NAL9602 initialized 2018-08-02T20:27:02.590Z,1533241622.590 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-08-02T20:27:02.590Z,1533241622.590 [NAL9602] Data Fault, FailCount= 3 2018-08-02T20:27:02.590Z,1533241622.590 [NAL9602](ERROR): Data Fault 2018-08-02T20:27:02.679Z,1533241622.679 [CBIT](ERROR): Data Fault in component: NAL9602 2018-08-02T20:27:02.990Z,1533241622.990 [NAL9602](INFO): Powering down 2018-08-02T20:27:03.846Z,1533241623.846 [CBIT](INFO): Clearing failed state for component NAL9602 2018-08-02T20:27:03.846Z,1533241623.846 [NAL9602] No Fault, FailCount= 3 2018-08-02T20:27:33.390Z,1533241653.390 [NAL9602](INFO): Powering up NAL9602 2018-08-02T20:27:35.803Z,1533241655.803 [CommandLine](IMPORTANT): got command restart system 2018-08-02T20:27:40.261Z,1533241660.261 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-02T20:27:40.262Z,1533241660.262 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.265Z,1533241660.265 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2018-08-02T20:27:40.265Z,1533241660.265 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.266Z,1533241660.266 [CommandLine](INFO): Join timeout helper Thread ID is 2238 2018-08-02T20:27:40.277Z,1533241660.277 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2018-08-02T20:27:40.277Z,1533241660.277 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.277Z,1533241660.277 [NavChartDb](INFO): Join timeout helper Thread ID is 2239 2018-08-02T20:27:40.425Z,1533241660.425 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-02T20:27:40.425Z,1533241660.425 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.445Z,1533241660.445 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2018-08-02T20:27:40.445Z,1533241660.445 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.445Z,1533241660.445 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2240 2018-08-02T20:27:40.573Z,1533241660.573 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-02T20:27:40.573Z,1533241660.573 [WetLabsBB2FL](INFO): Powering down 2018-08-02T20:27:40.574Z,1533241660.574 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.586Z,1533241660.586 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2018-08-02T20:27:40.586Z,1533241660.586 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.586Z,1533241660.586 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2241 2018-08-02T20:27:40.745Z,1533241660.745 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-02T20:27:40.837Z,1533241660.837 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-08-02T20:27:40.837Z,1533241660.837 [CTD_Seabird](INFO): Powering down 2018-08-02T20:27:40.838Z,1533241660.838 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.841Z,1533241660.841 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2018-08-02T20:27:40.841Z,1533241660.841 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:40.842Z,1533241660.842 [Radio_Surface](INFO): Join timeout helper Thread ID is 2243 2018-08-02T20:27:41.025Z,1533241661.025 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-02T20:27:41.025Z,1533241661.025 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.042Z,1533241661.042 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2018-08-02T20:27:41.042Z,1533241661.042 [logger ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.043Z,1533241661.043 [logger](INFO): Join timeout helper Thread ID is 2244 2018-08-02T20:27:41.049Z,1533241661.049 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-02T20:27:41.049Z,1533241661.049 [logger ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.054Z,1533241661.054 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2018-08-02T20:27:41.054Z,1533241661.054 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.054Z,1533241661.054 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2018-08-02T20:27:41.054Z,1533241661.054 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.054Z,1533241661.054 [controlThread](INFO): Join timeout helper Thread ID is 2245 2018-08-02T20:27:41.061Z,1533241661.061 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-02T20:27:41.061Z,1533241661.061 [controlThread](DEBUG): Uninitializing ControlThread 2018-08-02T20:27:41.062Z,1533241661.062 [NAL9602](INFO): Powering down 2018-08-02T20:27:41.063Z,1533241661.063 [PNI_TCM](INFO): Powering down 2018-08-02T20:27:41.150Z,1533241661.150 [Aanderaa_O2](INFO): Powering down 2018-08-02T20:27:41.153Z,1533241661.153 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-08-02T20:27:41.154Z,1533241661.154 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2018-08-02T20:27:41.155Z,1533241661.155 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2018-08-02T20:27:41.155Z,1533241661.155 [MissionManager](INFO): Uninitializing Mission Default 2018-08-02T20:27:41.155Z,1533241661.155 [Default] Stopped 2018-08-02T20:27:41.156Z,1533241661.156 [Default](DEBUG): Aggregate::uninitialize Default 2018-08-02T20:27:41.156Z,1533241661.156 [Default:B.GoToSurface] Stopped 2018-08-02T20:27:41.156Z,1533241661.156 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-08-02T20:27:41.156Z,1533241661.156 [Default:CheckIn] Stopped 2018-08-02T20:27:41.156Z,1533241661.156 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-02T20:27:41.156Z,1533241661.156 [Default:CheckIn:Read_GPS] Stopped 2018-08-02T20:27:41.161Z,1533241661.161 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2018-08-02T20:27:41.161Z,1533241661.161 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2018-08-02T20:27:41.161Z,1533241661.161 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2018-08-02T20:27:41.162Z,1533241661.162 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2018-08-02T20:27:41.162Z,1533241661.162 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-08-02T20:27:41.162Z,1533241661.162 [BuoyancyServo](INFO): Powering down 2018-08-02T20:27:41.177Z,1533241661.177 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2018-08-02T20:27:41.177Z,1533241661.177 [ElevatorServo](INFO): Powering down 2018-08-02T20:27:41.178Z,1533241661.178 [MassServo](DEBUG): Uninitialize Mass Servo. 2018-08-02T20:27:41.178Z,1533241661.178 [MassServo](INFO): Powering down 2018-08-02T20:27:41.179Z,1533241661.179 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2018-08-02T20:27:41.179Z,1533241661.179 [RudderServo](INFO): Powering down 2018-08-02T20:27:41.181Z,1533241661.181 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2018-08-02T20:27:41.181Z,1533241661.181 [ThrusterServo](INFO): Powering down 2018-08-02T20:27:41.182Z,1533241661.182 [SBIT](DEBUG): Uninitialize SBIT Component. 2018-08-02T20:27:41.182Z,1533241661.182 [IBIT](DEBUG): Uninitialize IBIT Component. 2018-08-02T20:27:41.183Z,1533241661.183 [CBIT](DEBUG): Uninitialize CBIT Component. 2018-08-02T20:27:41.184Z,1533241661.184 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.303Z,1533241661.303 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.347Z,1533241661.347 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.426Z,1533241661.426 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.488Z,1533241661.488 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-02T20:27:41.565Z,1533241661.565 [logger ThreadHandler](INFO): Thread cancelled.