2019-08-19T00:30:49.648Z,1566174649.648 [DataOverHttps](INFO): Received command:restart logs 2019-08-19T00:30:49.732Z,1566174649.732 [CommandLine](IMPORTANT): got command restart logs 2019-08-19T00:32:32.898Z,1566174752.898 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T00:32:32.898Z,1566174752.898 [Default:CheckIn:C.Wait] Stopped 2019-08-19T00:32:32.898Z,1566174752.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T00:32:32.898Z,1566174752.898 [Default:CheckIn:D] Running Loop=1 2019-08-19T00:32:33.303Z,1566174753.303 [Default:CheckIn:D] Stopped 2019-08-19T00:32:33.303Z,1566174753.303 [Default:CheckIn:E] Running Loop=1 2019-08-19T00:32:33.716Z,1566174753.716 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.230115 min 2019-08-19T00:32:33.716Z,1566174753.716 [Default:CheckIn:E] Stopped 2019-08-19T00:32:33.716Z,1566174753.716 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T00:32:33.716Z,1566174753.716 [Default:CheckIn] Stopped 2019-08-19T00:32:33.716Z,1566174753.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T00:32:33.717Z,1566174753.717 [Default:CheckIn](INFO): Running loop #12 2019-08-19T00:32:33.717Z,1566174753.717 [Default:CheckIn] Running Loop=12 2019-08-19T00:32:33.717Z,1566174753.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T00:32:33.717Z,1566174753.717 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T00:32:35.365Z,1566174755.365 [NAL9602](DEBUG): Fix Requested 2019-08-19T00:37:33.928Z,1566175053.928 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T00:32:33.7Z 2019-08-19T00:37:33.928Z,1566175053.928 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T00:37:33.928Z,1566175053.928 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T00:37:38.358Z,1566175058.358 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T00:37:39.856Z,1566175059.856 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190818T201300/Courier0147.lzma 2019-08-19T00:37:40.663Z,1566175060.663 [DataOverHttps](INFO): Moved sent file to Logs/20190818T201300/Courier0147.lzma.bak 2019-08-19T00:37:40.663Z,1566175060.663 [DataOverHttps](INFO): SBD MOMSN=11590689 2019-08-19T00:37:51.848Z,1566175071.848 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0000.lzma 2019-08-19T00:37:52.654Z,1566175072.654 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0000.lzma.bak 2019-08-19T00:37:52.654Z,1566175072.654 [DataOverHttps](INFO): SBD MOMSN=11590691 2019-08-19T00:38:03.805Z,1566175083.805 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0003.lzma 2019-08-19T00:38:04.611Z,1566175084.611 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0003.lzma.bak 2019-08-19T00:38:04.611Z,1566175084.611 [DataOverHttps](INFO): SBD MOMSN=11590694 2019-08-19T00:38:09.079Z,1566175089.079 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T00:38:19.993Z,1566175099.993 [DataOverHttps](INFO): Sending 95 bytes from file Logs/20190818T201300/Express0148.lzma 2019-08-19T00:38:20.799Z,1566175100.799 [DataOverHttps](INFO): Moved sent file to Logs/20190818T201300/Express0148.lzma.bak 2019-08-19T00:38:20.799Z,1566175100.799 [DataOverHttps](INFO): SBD MOMSN=11590696 2019-08-19T00:38:32.421Z,1566175112.421 [DataOverHttps](INFO): Sending 322 bytes from file Logs/20190819T003049/Express0001.lzma 2019-08-19T00:38:33.226Z,1566175113.226 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0001.lzma.bak 2019-08-19T00:38:33.226Z,1566175113.226 [DataOverHttps](INFO): SBD MOMSN=11590699 2019-08-19T00:38:44.704Z,1566175124.704 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190819T003049/Express0002.lzma 2019-08-19T00:38:45.510Z,1566175125.510 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0002.lzma.bak 2019-08-19T00:38:45.510Z,1566175125.510 [DataOverHttps](INFO): SBD MOMSN=11590703 2019-08-19T00:38:57.224Z,1566175137.224 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Express0004.lzma 2019-08-19T00:38:58.030Z,1566175138.030 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0004.lzma.bak 2019-08-19T00:38:58.030Z,1566175138.030 [DataOverHttps](INFO): SBD MOMSN=11590705 2019-08-19T00:38:59.238Z,1566175139.238 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T00:38:59.239Z,1566175139.239 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T00:38:59.239Z,1566175139.239 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T00:43:59.856Z,1566175439.856 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T00:43:59.856Z,1566175439.856 [Default:CheckIn:C.Wait] Stopped 2019-08-19T00:43:59.856Z,1566175439.856 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T00:43:59.857Z,1566175439.857 [Default:CheckIn:D] Running Loop=1 2019-08-19T00:44:00.239Z,1566175440.239 [Default:CheckIn:D] Stopped 2019-08-19T00:44:00.239Z,1566175440.239 [Default:CheckIn:E] Running Loop=1 2019-08-19T00:44:00.642Z,1566175440.642 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.679045 min 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn:E] Stopped 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn] Stopped 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn](INFO): Running loop #13 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn] Running Loop=13 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T00:44:00.643Z,1566175440.643 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T00:44:02.246Z,1566175442.246 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T00:44:02.246Z,1566175442.246 [NAL9602] Data Fault, FailCount= 1 2019-08-19T00:44:02.246Z,1566175442.246 [NAL9602](ERROR): Data Fault 2019-08-19T00:44:02.285Z,1566175442.285 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T00:44:02.644Z,1566175442.644 [NAL9602](INFO): Powering down 2019-08-19T00:44:03.499Z,1566175443.499 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T00:44:03.499Z,1566175443.499 [NAL9602] No Fault, FailCount= 1 2019-08-19T00:44:32.948Z,1566175472.948 [NAL9602](INFO): Powering up NAL9602 2019-08-19T00:44:43.852Z,1566175483.852 [NAL9602](INFO): NAL9602 initialized 2019-08-19T00:44:44.673Z,1566175484.673 [NAL9602](DEBUG): Fix Requested 2019-08-19T00:48:38.614Z,1566175718.614 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-19T00:48:38.615Z,1566175718.615 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-19T00:48:38.615Z,1566175718.615 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-08-19T00:48:38.618Z,1566175718.618 [BPC1](INFO): Received data from all battery sticks. 2019-08-19T00:49:00.842Z,1566175740.842 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T00:44:00.6Z 2019-08-19T00:49:00.842Z,1566175740.842 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T00:49:00.842Z,1566175740.842 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T00:49:06.516Z,1566175746.516 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20190819T003049/Courier0005.lzma 2019-08-19T00:49:07.326Z,1566175747.326 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0005.lzma.bak 2019-08-19T00:49:07.327Z,1566175747.327 [DataOverHttps](INFO): SBD MOMSN=11590716 2019-08-19T00:49:19.357Z,1566175759.357 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20190819T003049/Express0007.lzma 2019-08-19T00:49:20.167Z,1566175760.167 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0007.lzma.bak 2019-08-19T00:49:20.167Z,1566175760.167 [DataOverHttps](INFO): SBD MOMSN=11590718 2019-08-19T00:49:21.451Z,1566175761.451 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T00:49:21.451Z,1566175761.451 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T00:49:21.451Z,1566175761.451 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T00:49:46.852Z,1566175786.852 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T00:50:17.566Z,1566175817.566 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T00:54:22.001Z,1566176062.001 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T00:54:22.001Z,1566176062.001 [Default:CheckIn:C.Wait] Stopped 2019-08-19T00:54:22.001Z,1566176062.001 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T00:54:22.001Z,1566176062.001 [Default:CheckIn:D] Running Loop=1 2019-08-19T00:54:22.402Z,1566176062.402 [Default:CheckIn:D] Stopped 2019-08-19T00:54:22.402Z,1566176062.402 [Default:CheckIn:E] Running Loop=1 2019-08-19T00:54:22.811Z,1566176062.811 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.048429 min 2019-08-19T00:54:22.811Z,1566176062.811 [Default:CheckIn:E] Stopped 2019-08-19T00:54:22.812Z,1566176062.812 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T00:54:22.812Z,1566176062.812 [Default:CheckIn] Stopped 2019-08-19T00:54:22.812Z,1566176062.812 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T00:54:22.812Z,1566176062.812 [Default:CheckIn](INFO): Running loop #14 2019-08-19T00:54:22.812Z,1566176062.812 [Default:CheckIn] Running Loop=14 2019-08-19T00:54:22.812Z,1566176062.812 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T00:54:22.812Z,1566176062.812 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T00:54:24.421Z,1566176064.421 [NAL9602](DEBUG): Fix Requested 2019-08-19T00:54:55.514Z,1566176095.514 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T00:54:55.597Z,1566176095.597 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T00:54:55.597Z,1566176095.597 [NAL9602] Data Fault, FailCount= 2 2019-08-19T00:54:55.597Z,1566176095.597 [NAL9602](ERROR): Data Fault 2019-08-19T00:54:55.689Z,1566176095.689 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T00:54:55.912Z,1566176095.912 [NAL9602](INFO): Powering down 2019-08-19T00:54:56.755Z,1566176096.755 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T00:54:56.755Z,1566176096.755 [NAL9602] No Fault, FailCount= 2 2019-08-19T00:55:26.216Z,1566176126.216 [NAL9602](INFO): Powering up NAL9602 2019-08-19T00:55:37.124Z,1566176137.124 [NAL9602](INFO): NAL9602 initialized 2019-08-19T00:55:37.934Z,1566176137.934 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T00:55:37.934Z,1566176137.934 [NAL9602] Data Fault, FailCount= 3 2019-08-19T00:55:37.934Z,1566176137.934 [NAL9602](ERROR): Data Fault 2019-08-19T00:55:37.965Z,1566176137.965 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T00:55:38.334Z,1566176138.334 [NAL9602](INFO): Powering down 2019-08-19T00:55:39.181Z,1566176139.181 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T00:55:39.181Z,1566176139.181 [NAL9602] No Fault, FailCount= 3 2019-08-19T00:56:08.645Z,1566176168.645 [NAL9602](INFO): Powering up NAL9602 2019-08-19T00:56:19.552Z,1566176179.552 [NAL9602](INFO): NAL9602 initialized 2019-08-19T00:56:20.373Z,1566176180.373 [NAL9602](DEBUG): Fix Requested 2019-08-19T00:59:23.018Z,1566176363.018 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T00:54:22.8Z 2019-08-19T00:59:23.018Z,1566176363.018 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T00:59:23.018Z,1566176363.018 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T00:59:27.026Z,1566176367.026 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T00:59:28.676Z,1566176368.676 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0009.lzma 2019-08-19T00:59:29.482Z,1566176369.482 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0009.lzma.bak 2019-08-19T00:59:29.482Z,1566176369.482 [DataOverHttps](INFO): SBD MOMSN=11590730 2019-08-19T00:59:40.927Z,1566176380.927 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20190819T003049/Express0010.lzma 2019-08-19T00:59:41.730Z,1566176381.730 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0010.lzma.bak 2019-08-19T00:59:41.730Z,1566176381.730 [DataOverHttps](INFO): SBD MOMSN=11590732 2019-08-19T00:59:42.827Z,1566176382.827 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T00:59:42.827Z,1566176382.827 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T00:59:42.827Z,1566176382.827 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T00:59:57.715Z,1566176397.715 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T01:04:43.379Z,1566176683.379 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T01:04:43.379Z,1566176683.379 [Default:CheckIn:C.Wait] Stopped 2019-08-19T01:04:43.379Z,1566176683.379 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T01:04:43.380Z,1566176683.380 [Default:CheckIn:D] Running Loop=1 2019-08-19T01:04:43.784Z,1566176683.784 [Default:CheckIn:D] Stopped 2019-08-19T01:04:43.784Z,1566176683.784 [Default:CheckIn:E] Running Loop=1 2019-08-19T01:04:44.184Z,1566176684.184 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.404801 min 2019-08-19T01:04:44.184Z,1566176684.184 [Default:CheckIn:E] Stopped 2019-08-19T01:04:44.184Z,1566176684.184 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T01:04:44.184Z,1566176684.184 [Default:CheckIn] Stopped 2019-08-19T01:04:44.184Z,1566176684.184 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T01:04:44.185Z,1566176684.185 [Default:CheckIn](INFO): Running loop #15 2019-08-19T01:04:44.185Z,1566176684.185 [Default:CheckIn] Running Loop=15 2019-08-19T01:04:44.185Z,1566176684.185 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T01:04:44.185Z,1566176684.185 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T01:04:45.793Z,1566176685.793 [NAL9602](DEBUG): Fix Requested 2019-08-19T01:09:44.362Z,1566176984.362 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T01:04:44.2Z 2019-08-19T01:09:44.362Z,1566176984.362 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T01:09:44.364Z,1566176984.364 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T01:09:48.398Z,1566176988.398 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T01:09:50.312Z,1566176990.312 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0012.lzma 2019-08-19T01:09:51.118Z,1566176991.118 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0012.lzma.bak 2019-08-19T01:09:51.118Z,1566176991.118 [DataOverHttps](INFO): SBD MOMSN=11590743 2019-08-19T01:10:03.244Z,1566177003.244 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20190819T003049/Express0013.lzma 2019-08-19T01:10:04.050Z,1566177004.050 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0013.lzma.bak 2019-08-19T01:10:04.050Z,1566177004.050 [DataOverHttps](INFO): SBD MOMSN=11590745 2019-08-19T01:10:05.380Z,1566177005.380 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T01:10:05.380Z,1566177005.380 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T01:10:05.380Z,1566177005.380 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T01:10:19.132Z,1566177019.132 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T01:15:05.979Z,1566177305.979 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T01:15:05.980Z,1566177305.980 [Default:CheckIn:C.Wait] Stopped 2019-08-19T01:15:05.980Z,1566177305.980 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T01:15:05.980Z,1566177305.980 [Default:CheckIn:D] Running Loop=1 2019-08-19T01:15:06.383Z,1566177306.383 [Default:CheckIn:D] Stopped 2019-08-19T01:15:06.383Z,1566177306.383 [Default:CheckIn:E] Running Loop=1 2019-08-19T01:15:06.782Z,1566177306.782 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.781453 min 2019-08-19T01:15:06.782Z,1566177306.782 [Default:CheckIn:E] Stopped 2019-08-19T01:15:06.782Z,1566177306.782 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T01:15:06.782Z,1566177306.782 [Default:CheckIn] Stopped 2019-08-19T01:15:06.782Z,1566177306.782 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T01:15:06.783Z,1566177306.783 [Default:CheckIn](INFO): Running loop #16 2019-08-19T01:15:06.783Z,1566177306.783 [Default:CheckIn] Running Loop=16 2019-08-19T01:15:06.783Z,1566177306.783 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T01:15:06.783Z,1566177306.783 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T01:15:08.376Z,1566177308.376 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T01:15:08.376Z,1566177308.376 [NAL9602] Data Fault, FailCount= 4 2019-08-19T01:15:08.376Z,1566177308.376 [NAL9602](ERROR): Data Fault 2019-08-19T01:15:08.449Z,1566177308.449 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T01:15:08.786Z,1566177308.786 [NAL9602](INFO): Powering down 2019-08-19T01:15:09.618Z,1566177309.618 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T01:15:09.618Z,1566177309.618 [NAL9602] No Fault, FailCount= 4 2019-08-19T01:15:39.086Z,1566177339.086 [NAL9602](INFO): Powering up NAL9602 2019-08-19T01:15:49.990Z,1566177349.990 [NAL9602](INFO): NAL9602 initialized 2019-08-19T01:15:50.809Z,1566177350.809 [NAL9602](DEBUG): Fix Requested 2019-08-19T01:20:06.959Z,1566177606.959 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T01:15:06.8Z 2019-08-19T01:20:06.959Z,1566177606.959 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T01:20:06.960Z,1566177606.960 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T01:20:15.752Z,1566177615.752 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0015.lzma 2019-08-19T01:20:16.558Z,1566177616.558 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0015.lzma.bak 2019-08-19T01:20:16.559Z,1566177616.559 [DataOverHttps](INFO): SBD MOMSN=11590760 2019-08-19T01:20:29.897Z,1566177629.897 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20190819T003049/Express0016.lzma 2019-08-19T01:20:30.702Z,1566177630.702 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0016.lzma.bak 2019-08-19T01:20:30.702Z,1566177630.702 [DataOverHttps](INFO): SBD MOMSN=11590762 2019-08-19T01:20:32.052Z,1566177632.052 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T01:20:32.052Z,1566177632.052 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T01:20:32.052Z,1566177632.052 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T01:20:53.027Z,1566177653.027 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T01:21:23.727Z,1566177683.727 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T01:25:32.646Z,1566177932.646 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T01:25:32.646Z,1566177932.646 [Default:CheckIn:C.Wait] Stopped 2019-08-19T01:25:32.646Z,1566177932.646 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T01:25:32.646Z,1566177932.646 [Default:CheckIn:D] Running Loop=1 2019-08-19T01:25:33.061Z,1566177933.061 [Default:CheckIn:D] Stopped 2019-08-19T01:25:33.061Z,1566177933.061 [Default:CheckIn:E] Running Loop=1 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.226090 min 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn:E] Stopped 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn] Stopped 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn](INFO): Running loop #17 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn] Running Loop=17 2019-08-19T01:25:33.450Z,1566177933.450 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T01:25:33.451Z,1566177933.451 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T01:25:35.053Z,1566177935.053 [NAL9602](DEBUG): Fix Requested 2019-08-19T01:26:06.153Z,1566177966.153 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T01:26:06.237Z,1566177966.237 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T01:26:06.237Z,1566177966.237 [NAL9602] Data Fault, FailCount= 5 2019-08-19T01:26:06.237Z,1566177966.237 [NAL9602](ERROR): Data Fault 2019-08-19T01:26:06.345Z,1566177966.345 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T01:26:06.345Z,1566177966.345 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-08-19T01:26:06.552Z,1566177966.552 [NAL9602](INFO): Powering down 2019-08-19T01:26:06.600Z,1566177966.600 [CBIT](INFO): Critical error at 20190819T012606 2019-08-19T01:28:06.598Z,1566178086.598 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T01:28:06.598Z,1566178086.598 [NAL9602] No Fault, FailCount= 5 2019-08-19T01:28:06.982Z,1566178086.982 [NAL9602](INFO): Powering up NAL9602 2019-08-19T01:28:17.906Z,1566178097.906 [NAL9602](INFO): NAL9602 initialized 2019-08-19T01:28:18.712Z,1566178098.712 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T01:28:18.712Z,1566178098.712 [NAL9602] Data Fault, FailCount= 1 2019-08-19T01:28:18.712Z,1566178098.712 [NAL9602](ERROR): Data Fault 2019-08-19T01:28:18.784Z,1566178098.784 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T01:28:19.115Z,1566178099.115 [NAL9602](INFO): Powering down 2019-08-19T01:28:19.950Z,1566178099.950 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T01:28:19.950Z,1566178099.950 [NAL9602] No Fault, FailCount= 1 2019-08-19T01:28:49.411Z,1566178129.411 [NAL9602](INFO): Powering up NAL9602 2019-08-19T01:29:00.326Z,1566178140.326 [NAL9602](INFO): NAL9602 initialized 2019-08-19T01:29:01.141Z,1566178141.141 [NAL9602](DEBUG): Fix Requested 2019-08-19T01:30:33.682Z,1566178233.682 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T01:25:33.5Z 2019-08-19T01:30:33.682Z,1566178233.682 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T01:30:33.683Z,1566178233.683 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T01:30:36.892Z,1566178236.892 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T01:30:39.424Z,1566178239.424 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20190819T003049/Courier0018.lzma 2019-08-19T01:30:40.230Z,1566178240.230 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0018.lzma.bak 2019-08-19T01:30:40.231Z,1566178240.231 [DataOverHttps](INFO): SBD MOMSN=11590784 2019-08-19T01:30:52.721Z,1566178252.721 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20190819T003049/Express0019.lzma 2019-08-19T01:30:53.526Z,1566178253.526 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0019.lzma.bak 2019-08-19T01:30:53.527Z,1566178253.527 [DataOverHttps](INFO): SBD MOMSN=11590787 2019-08-19T01:30:54.715Z,1566178254.715 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T01:30:54.715Z,1566178254.715 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T01:30:54.715Z,1566178254.715 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T01:31:07.607Z,1566178267.607 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T01:35:55.275Z,1566178555.275 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T01:35:55.276Z,1566178555.276 [Default:CheckIn:C.Wait] Stopped 2019-08-19T01:35:55.276Z,1566178555.276 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T01:35:55.276Z,1566178555.276 [Default:CheckIn:D] Running Loop=1 2019-08-19T01:35:55.674Z,1566178555.674 [Default:CheckIn:D] Stopped 2019-08-19T01:35:55.674Z,1566178555.674 [Default:CheckIn:E] Running Loop=1 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 123.602962 min 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn:E] Stopped 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn] Stopped 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn](INFO): Running loop #18 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn] Running Loop=18 2019-08-19T01:35:56.078Z,1566178556.078 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T01:35:56.079Z,1566178556.079 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T01:35:57.685Z,1566178557.685 [NAL9602](DEBUG): Fix Requested 2019-08-19T01:36:28.779Z,1566178588.779 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T01:36:28.853Z,1566178588.853 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T01:36:28.853Z,1566178588.853 [NAL9602] Data Fault, FailCount= 2 2019-08-19T01:36:28.853Z,1566178588.853 [NAL9602](ERROR): Data Fault 2019-08-19T01:36:28.892Z,1566178588.892 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T01:36:29.190Z,1566178589.190 [NAL9602](INFO): Powering down 2019-08-19T01:36:30.049Z,1566178590.049 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T01:36:30.049Z,1566178590.049 [NAL9602] No Fault, FailCount= 2 2019-08-19T01:36:59.484Z,1566178619.484 [NAL9602](INFO): Powering up NAL9602 2019-08-19T01:37:10.396Z,1566178630.396 [NAL9602](INFO): NAL9602 initialized 2019-08-19T01:37:11.213Z,1566178631.213 [NAL9602](DEBUG): Fix Requested 2019-08-19T01:40:56.261Z,1566178856.261 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T01:35:56.1Z 2019-08-19T01:40:56.261Z,1566178856.261 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T01:40:56.262Z,1566178856.262 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T01:41:00.342Z,1566178860.342 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T01:41:01.852Z,1566178861.852 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0021.lzma 2019-08-19T01:41:02.658Z,1566178862.658 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0021.lzma.bak 2019-08-19T01:41:02.658Z,1566178862.658 [DataOverHttps](INFO): SBD MOMSN=11590798 2019-08-19T01:41:14.025Z,1566178874.025 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20190819T003049/Express0022.lzma 2019-08-19T01:41:14.830Z,1566178874.830 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0022.lzma.bak 2019-08-19T01:41:14.830Z,1566178874.830 [DataOverHttps](INFO): SBD MOMSN=11590800 2019-08-19T01:41:16.163Z,1566178876.163 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T01:41:16.163Z,1566178876.163 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T01:41:16.163Z,1566178876.163 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T01:41:31.044Z,1566178891.044 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T01:46:16.696Z,1566179176.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T01:46:16.696Z,1566179176.696 [Default:CheckIn:C.Wait] Stopped 2019-08-19T01:46:16.696Z,1566179176.696 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T01:46:16.696Z,1566179176.696 [Default:CheckIn:D] Running Loop=1 2019-08-19T01:46:17.124Z,1566179177.124 [Default:CheckIn:D] Stopped 2019-08-19T01:46:17.124Z,1566179177.124 [Default:CheckIn:E] Running Loop=1 2019-08-19T01:46:17.528Z,1566179177.528 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.960474 min 2019-08-19T01:46:17.528Z,1566179177.528 [Default:CheckIn:E] Stopped 2019-08-19T01:46:17.528Z,1566179177.528 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T01:46:17.528Z,1566179177.528 [Default:CheckIn] Stopped 2019-08-19T01:46:17.528Z,1566179177.528 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T01:46:17.528Z,1566179177.528 [Default:CheckIn](INFO): Running loop #19 2019-08-19T01:46:17.533Z,1566179177.533 [Default:CheckIn] Running Loop=19 2019-08-19T01:46:17.533Z,1566179177.533 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T01:46:17.533Z,1566179177.533 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T01:46:19.099Z,1566179179.099 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T01:46:19.099Z,1566179179.099 [NAL9602] Data Fault, FailCount= 3 2019-08-19T01:46:19.099Z,1566179179.099 [NAL9602](ERROR): Data Fault 2019-08-19T01:46:19.136Z,1566179179.136 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T01:46:19.506Z,1566179179.506 [NAL9602](INFO): Powering down 2019-08-19T01:46:20.343Z,1566179180.343 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T01:46:20.343Z,1566179180.343 [NAL9602] No Fault, FailCount= 3 2019-08-19T01:46:49.808Z,1566179209.808 [NAL9602](INFO): Powering up NAL9602 2019-08-19T01:47:00.712Z,1566179220.712 [NAL9602](INFO): NAL9602 initialized 2019-08-19T01:47:01.529Z,1566179221.529 [NAL9602](DEBUG): Fix Requested 2019-08-19T01:51:17.682Z,1566179477.682 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T01:46:17.5Z 2019-08-19T01:51:17.683Z,1566179477.683 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T01:51:17.683Z,1566179477.683 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T01:51:23.492Z,1566179483.492 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0024.lzma 2019-08-19T01:51:24.298Z,1566179484.298 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0024.lzma.bak 2019-08-19T01:51:24.299Z,1566179484.299 [DataOverHttps](INFO): SBD MOMSN=11590812 2019-08-19T01:51:36.309Z,1566179496.309 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20190819T003049/Express0025.lzma 2019-08-19T01:51:37.114Z,1566179497.114 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0025.lzma.bak 2019-08-19T01:51:37.115Z,1566179497.115 [DataOverHttps](INFO): SBD MOMSN=11590814 2019-08-19T01:51:38.302Z,1566179498.302 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T01:51:38.302Z,1566179498.302 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T01:51:38.302Z,1566179498.302 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T01:52:03.713Z,1566179523.713 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T01:52:34.411Z,1566179554.411 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T01:56:19.490Z,1566179779.490 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-19T01:56:19.491Z,1566179779.491 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-19T01:56:19.492Z,1566179779.492 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-08-19T01:56:19.498Z,1566179779.498 [BPC1](INFO): Received data from all battery sticks. 2019-08-19T01:56:38.887Z,1566179798.887 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T01:56:38.888Z,1566179798.888 [Default:CheckIn:C.Wait] Stopped 2019-08-19T01:56:38.888Z,1566179798.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T01:56:38.889Z,1566179798.889 [Default:CheckIn:D] Running Loop=1 2019-08-19T01:56:39.286Z,1566179799.286 [Default:CheckIn:D] Stopped 2019-08-19T01:56:39.286Z,1566179799.286 [Default:CheckIn:E] Running Loop=1 2019-08-19T01:56:39.692Z,1566179799.692 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 144.329834 min 2019-08-19T01:56:39.692Z,1566179799.692 [Default:CheckIn:E] Stopped 2019-08-19T01:56:39.692Z,1566179799.692 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T01:56:39.692Z,1566179799.692 [Default:CheckIn] Stopped 2019-08-19T01:56:39.692Z,1566179799.692 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T01:56:39.692Z,1566179799.692 [Default:CheckIn](INFO): Running loop #20 2019-08-19T01:56:39.692Z,1566179799.692 [Default:CheckIn] Running Loop=20 2019-08-19T01:56:39.693Z,1566179799.693 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T01:56:39.693Z,1566179799.693 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T01:56:41.297Z,1566179801.297 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:01:39.882Z,1566180099.882 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T01:56:39.7Z 2019-08-19T02:01:39.882Z,1566180099.882 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T02:01:39.882Z,1566180099.882 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T02:01:43.894Z,1566180103.894 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T02:01:45.644Z,1566180105.644 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20190819T003049/Courier0027.lzma 2019-08-19T02:01:46.450Z,1566180106.450 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0027.lzma.bak 2019-08-19T02:01:46.450Z,1566180106.450 [DataOverHttps](INFO): SBD MOMSN=11590826 2019-08-19T02:01:57.856Z,1566180117.856 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20190819T003049/Express0028.lzma 2019-08-19T02:01:58.662Z,1566180118.662 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0028.lzma.bak 2019-08-19T02:01:58.663Z,1566180118.663 [DataOverHttps](INFO): SBD MOMSN=11590828 2019-08-19T02:02:00.089Z,1566180120.089 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T02:02:00.089Z,1566180120.089 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T02:02:00.089Z,1566180120.089 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T02:02:14.586Z,1566180134.586 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T02:07:00.642Z,1566180420.642 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T02:07:00.642Z,1566180420.642 [Default:CheckIn:C.Wait] Stopped 2019-08-19T02:07:00.642Z,1566180420.642 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T02:07:00.643Z,1566180420.643 [Default:CheckIn:D] Running Loop=1 2019-08-19T02:07:01.052Z,1566180421.052 [Default:CheckIn:D] Stopped 2019-08-19T02:07:01.052Z,1566180421.052 [Default:CheckIn:E] Running Loop=1 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 154.692594 min 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn:E] Stopped 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn] Stopped 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn](INFO): Running loop #21 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn] Running Loop=21 2019-08-19T02:07:01.459Z,1566180421.459 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T02:07:01.460Z,1566180421.460 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T02:07:03.046Z,1566180423.046 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T02:07:03.046Z,1566180423.046 [NAL9602] Data Fault, FailCount= 4 2019-08-19T02:07:03.046Z,1566180423.046 [NAL9602](ERROR): Data Fault 2019-08-19T02:07:03.077Z,1566180423.077 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T02:07:03.450Z,1566180423.450 [NAL9602](INFO): Powering down 2019-08-19T02:07:04.285Z,1566180424.285 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T02:07:04.286Z,1566180424.286 [NAL9602] No Fault, FailCount= 4 2019-08-19T02:07:33.746Z,1566180453.746 [NAL9602](INFO): Powering up NAL9602 2019-08-19T02:07:44.652Z,1566180464.652 [NAL9602](INFO): NAL9602 initialized 2019-08-19T02:07:45.477Z,1566180465.477 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:12:01.628Z,1566180721.628 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T02:07:01.5Z 2019-08-19T02:12:01.628Z,1566180721.628 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T02:12:01.628Z,1566180721.628 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T02:12:07.992Z,1566180727.992 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0030.lzma 2019-08-19T02:12:08.798Z,1566180728.798 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0030.lzma.bak 2019-08-19T02:12:08.798Z,1566180728.798 [DataOverHttps](INFO): SBD MOMSN=11590848 2019-08-19T02:12:22.445Z,1566180742.445 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20190819T003049/Express0031.lzma 2019-08-19T02:12:23.250Z,1566180743.250 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0031.lzma.bak 2019-08-19T02:12:23.251Z,1566180743.251 [DataOverHttps](INFO): SBD MOMSN=11590850 2019-08-19T02:12:24.696Z,1566180744.696 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T02:12:24.696Z,1566180744.696 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T02:12:24.696Z,1566180744.696 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T02:12:47.692Z,1566180767.692 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T02:13:18.398Z,1566180798.398 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T02:17:25.270Z,1566181045.270 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T02:17:25.270Z,1566181045.270 [Default:CheckIn:C.Wait] Stopped 2019-08-19T02:17:25.270Z,1566181045.270 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T02:17:25.271Z,1566181045.271 [Default:CheckIn:D] Running Loop=1 2019-08-19T02:17:25.681Z,1566181045.681 [Default:CheckIn:D] Stopped 2019-08-19T02:17:25.681Z,1566181045.681 [Default:CheckIn:E] Running Loop=1 2019-08-19T02:17:26.086Z,1566181046.086 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 165.103076 min 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn:E] Stopped 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn] Stopped 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn](INFO): Running loop #22 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn] Running Loop=22 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T02:17:26.087Z,1566181046.087 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T02:17:27.685Z,1566181047.685 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:17:58.781Z,1566181078.781 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T02:17:58.865Z,1566181078.865 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T02:17:58.865Z,1566181078.865 [NAL9602] Data Fault, FailCount= 5 2019-08-19T02:17:58.865Z,1566181078.865 [NAL9602](ERROR): Data Fault 2019-08-19T02:17:58.988Z,1566181078.988 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T02:17:58.993Z,1566181078.993 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-08-19T02:17:59.184Z,1566181079.184 [NAL9602](INFO): Powering down 2019-08-19T02:17:59.238Z,1566181079.238 [CBIT](INFO): Critical error at 20190819T021758 2019-08-19T02:19:59.204Z,1566181199.204 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T02:19:59.204Z,1566181199.204 [NAL9602] No Fault, FailCount= 5 2019-08-19T02:19:59.584Z,1566181199.584 [NAL9602](INFO): Powering up NAL9602 2019-08-19T02:20:10.490Z,1566181210.490 [NAL9602](INFO): NAL9602 initialized 2019-08-19T02:20:11.296Z,1566181211.296 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T02:20:11.296Z,1566181211.296 [NAL9602] Data Fault, FailCount= 1 2019-08-19T02:20:11.296Z,1566181211.296 [NAL9602](ERROR): Data Fault 2019-08-19T02:20:11.328Z,1566181211.328 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T02:20:11.702Z,1566181211.702 [NAL9602](INFO): Powering down 2019-08-19T02:20:12.534Z,1566181212.534 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T02:20:12.534Z,1566181212.534 [NAL9602] No Fault, FailCount= 1 2019-08-19T02:20:41.999Z,1566181241.999 [NAL9602](INFO): Powering up NAL9602 2019-08-19T02:20:52.910Z,1566181252.910 [NAL9602](INFO): NAL9602 initialized 2019-08-19T02:20:53.725Z,1566181253.725 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:22:26.264Z,1566181346.264 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T02:17:26.1Z 2019-08-19T02:22:26.264Z,1566181346.264 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T02:22:26.264Z,1566181346.264 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T02:22:29.460Z,1566181349.460 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T02:22:32.004Z,1566181352.004 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20190819T003049/Courier0033.lzma 2019-08-19T02:22:32.810Z,1566181352.810 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0033.lzma.bak 2019-08-19T02:22:32.811Z,1566181352.811 [DataOverHttps](INFO): SBD MOMSN=11590864 2019-08-19T02:22:44.253Z,1566181364.253 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20190819T003049/Express0034.lzma 2019-08-19T02:22:45.058Z,1566181365.058 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0034.lzma.bak 2019-08-19T02:22:45.058Z,1566181365.058 [DataOverHttps](INFO): SBD MOMSN=11590867 2019-08-19T02:22:46.472Z,1566181366.472 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T02:22:46.472Z,1566181366.472 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T02:22:46.472Z,1566181366.472 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T02:23:00.166Z,1566181380.166 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T02:27:47.045Z,1566181667.045 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T02:27:47.045Z,1566181667.045 [Default:CheckIn:C.Wait] Stopped 2019-08-19T02:27:47.045Z,1566181667.045 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T02:27:47.046Z,1566181667.046 [Default:CheckIn:D] Running Loop=1 2019-08-19T02:27:47.454Z,1566181667.454 [Default:CheckIn:D] Stopped 2019-08-19T02:27:47.454Z,1566181667.454 [Default:CheckIn:E] Running Loop=1 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.465983 min 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn:E] Stopped 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn] Stopped 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn](INFO): Running loop #23 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn] Running Loop=23 2019-08-19T02:27:47.870Z,1566181667.870 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T02:27:47.871Z,1566181667.871 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T02:27:49.457Z,1566181669.457 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:28:20.560Z,1566181700.560 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T02:28:20.641Z,1566181700.641 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T02:28:20.641Z,1566181700.641 [NAL9602] Data Fault, FailCount= 2 2019-08-19T02:28:20.641Z,1566181700.641 [NAL9602](ERROR): Data Fault 2019-08-19T02:28:20.772Z,1566181700.772 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T02:28:20.958Z,1566181700.958 [NAL9602](INFO): Powering down 2019-08-19T02:28:21.813Z,1566181701.813 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T02:28:21.813Z,1566181701.813 [NAL9602] No Fault, FailCount= 2 2019-08-19T02:28:51.252Z,1566181731.252 [NAL9602](INFO): Powering up NAL9602 2019-08-19T02:29:02.164Z,1566181742.164 [NAL9602](INFO): NAL9602 initialized 2019-08-19T02:29:02.985Z,1566181742.985 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:32:48.031Z,1566181968.031 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T02:27:47.9Z 2019-08-19T02:32:48.031Z,1566181968.031 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T02:32:48.031Z,1566181968.031 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T02:32:51.662Z,1566181971.662 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T02:32:53.576Z,1566181973.576 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0036.lzma 2019-08-19T02:32:54.383Z,1566181974.383 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0036.lzma.bak 2019-08-19T02:32:54.383Z,1566181974.383 [DataOverHttps](INFO): SBD MOMSN=11590878 2019-08-19T02:33:05.853Z,1566181985.853 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20190819T003049/Express0037.lzma 2019-08-19T02:33:06.659Z,1566181986.659 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0037.lzma.bak 2019-08-19T02:33:06.659Z,1566181986.659 [DataOverHttps](INFO): SBD MOMSN=11590880 2019-08-19T02:33:08.240Z,1566181988.240 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T02:33:08.240Z,1566181988.240 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T02:33:08.240Z,1566181988.240 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T02:33:22.348Z,1566182002.348 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T02:38:08.850Z,1566182288.850 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T02:38:08.850Z,1566182288.850 [Default:CheckIn:C.Wait] Stopped 2019-08-19T02:38:08.850Z,1566182288.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T02:38:08.850Z,1566182288.850 [Default:CheckIn:D] Running Loop=1 2019-08-19T02:38:09.260Z,1566182289.260 [Default:CheckIn:D] Stopped 2019-08-19T02:38:09.260Z,1566182289.260 [Default:CheckIn:E] Running Loop=1 2019-08-19T02:38:09.658Z,1566182289.658 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 185.829395 min 2019-08-19T02:38:09.658Z,1566182289.658 [Default:CheckIn:E] Stopped 2019-08-19T02:38:09.658Z,1566182289.658 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T02:38:09.659Z,1566182289.659 [Default:CheckIn] Stopped 2019-08-19T02:38:09.659Z,1566182289.659 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T02:38:09.659Z,1566182289.659 [Default:CheckIn](INFO): Running loop #24 2019-08-19T02:38:09.659Z,1566182289.659 [Default:CheckIn] Running Loop=24 2019-08-19T02:38:09.659Z,1566182289.659 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T02:38:09.659Z,1566182289.659 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T02:38:11.252Z,1566182291.252 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T02:38:11.252Z,1566182291.252 [NAL9602] Data Fault, FailCount= 3 2019-08-19T02:38:11.252Z,1566182291.252 [NAL9602](ERROR): Data Fault 2019-08-19T02:38:11.321Z,1566182291.321 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T02:38:11.656Z,1566182291.656 [NAL9602](INFO): Powering down 2019-08-19T02:38:12.500Z,1566182292.500 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T02:38:12.500Z,1566182292.500 [NAL9602] No Fault, FailCount= 3 2019-08-19T02:38:41.975Z,1566182321.975 [NAL9602](INFO): Powering up NAL9602 2019-08-19T02:38:52.879Z,1566182332.879 [NAL9602](INFO): NAL9602 initialized 2019-08-19T02:38:53.701Z,1566182333.701 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:43:09.856Z,1566182589.856 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T02:38:09.7Z 2019-08-19T02:43:09.856Z,1566182589.856 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T02:43:09.856Z,1566182589.856 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T02:43:15.613Z,1566182595.613 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0039.lzma 2019-08-19T02:43:16.416Z,1566182596.416 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0039.lzma.bak 2019-08-19T02:43:16.416Z,1566182596.416 [DataOverHttps](INFO): SBD MOMSN=11590891 2019-08-19T02:43:27.877Z,1566182607.877 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20190819T003049/Express0040.lzma 2019-08-19T02:43:28.682Z,1566182608.682 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0040.lzma.bak 2019-08-19T02:43:28.683Z,1566182608.683 [DataOverHttps](INFO): SBD MOMSN=11590893 2019-08-19T02:43:30.071Z,1566182610.071 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T02:43:30.071Z,1566182610.071 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T02:43:30.072Z,1566182610.072 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T02:43:55.880Z,1566182635.880 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T02:44:26.588Z,1566182666.588 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T02:48:30.631Z,1566182910.631 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T02:48:30.631Z,1566182910.631 [Default:CheckIn:C.Wait] Stopped 2019-08-19T02:48:30.631Z,1566182910.631 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T02:48:30.631Z,1566182910.631 [Default:CheckIn:D] Running Loop=1 2019-08-19T02:48:31.033Z,1566182911.033 [Default:CheckIn:D] Stopped 2019-08-19T02:48:31.033Z,1566182911.033 [Default:CheckIn:E] Running Loop=1 2019-08-19T02:48:31.436Z,1566182911.436 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 196.192285 min 2019-08-19T02:48:31.437Z,1566182911.437 [Default:CheckIn:E] Stopped 2019-08-19T02:48:31.437Z,1566182911.437 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T02:48:31.437Z,1566182911.437 [Default:CheckIn] Stopped 2019-08-19T02:48:31.437Z,1566182911.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T02:48:31.437Z,1566182911.437 [Default:CheckIn](INFO): Running loop #25 2019-08-19T02:48:31.437Z,1566182911.437 [Default:CheckIn] Running Loop=25 2019-08-19T02:48:31.437Z,1566182911.437 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T02:48:31.438Z,1566182911.438 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T02:48:33.053Z,1566182913.053 [NAL9602](DEBUG): Fix Requested 2019-08-19T02:53:31.612Z,1566183211.612 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T02:48:31.4Z 2019-08-19T02:53:31.612Z,1566183211.612 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T02:53:31.613Z,1566183211.613 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T02:53:36.030Z,1566183216.030 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T02:53:38.516Z,1566183218.516 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0042.lzma 2019-08-19T02:53:39.322Z,1566183219.322 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0042.lzma.bak 2019-08-19T02:53:39.323Z,1566183219.323 [DataOverHttps](INFO): SBD MOMSN=11590907 2019-08-19T02:53:50.913Z,1566183230.913 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20190819T003049/Express0043.lzma 2019-08-19T02:53:51.718Z,1566183231.718 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0043.lzma.bak 2019-08-19T02:53:51.719Z,1566183231.719 [DataOverHttps](INFO): SBD MOMSN=11590909 2019-08-19T02:53:53.024Z,1566183233.024 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T02:53:53.024Z,1566183233.024 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T02:53:53.024Z,1566183233.024 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T02:54:06.738Z,1566183246.738 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T02:58:53.602Z,1566183533.602 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T02:58:53.602Z,1566183533.602 [Default:CheckIn:C.Wait] Stopped 2019-08-19T02:58:53.602Z,1566183533.602 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T02:58:53.602Z,1566183533.602 [Default:CheckIn:D] Running Loop=1 2019-08-19T02:58:54.016Z,1566183534.016 [Default:CheckIn:D] Stopped 2019-08-19T02:58:54.017Z,1566183534.017 [Default:CheckIn:E] Running Loop=1 2019-08-19T02:58:54.412Z,1566183534.412 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 206.575342 min 2019-08-19T02:58:54.412Z,1566183534.412 [Default:CheckIn:E] Stopped 2019-08-19T02:58:54.412Z,1566183534.412 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T02:58:54.412Z,1566183534.412 [Default:CheckIn] Stopped 2019-08-19T02:58:54.412Z,1566183534.412 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T02:58:54.412Z,1566183534.412 [Default:CheckIn](INFO): Running loop #26 2019-08-19T02:58:54.413Z,1566183534.413 [Default:CheckIn] Running Loop=26 2019-08-19T02:58:54.413Z,1566183534.413 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T02:58:54.413Z,1566183534.413 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T02:58:55.996Z,1566183535.996 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T02:58:55.996Z,1566183535.996 [NAL9602] Data Fault, FailCount= 4 2019-08-19T02:58:55.996Z,1566183535.996 [NAL9602](ERROR): Data Fault 2019-08-19T02:58:56.028Z,1566183536.028 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T02:58:56.406Z,1566183536.406 [NAL9602](INFO): Powering down 2019-08-19T02:58:57.251Z,1566183537.251 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T02:58:57.252Z,1566183537.252 [NAL9602] No Fault, FailCount= 4 2019-08-19T02:59:26.780Z,1566183566.780 [NAL9602](INFO): Powering up NAL9602 2019-08-19T02:59:37.684Z,1566183577.684 [NAL9602](INFO): NAL9602 initialized 2019-08-19T02:59:38.505Z,1566183578.505 [NAL9602](DEBUG): Fix Requested 2019-08-19T03:03:54.724Z,1566183834.724 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T02:58:54.4Z 2019-08-19T03:03:54.724Z,1566183834.724 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T03:03:54.725Z,1566183834.725 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T03:04:00.264Z,1566183840.264 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0045.lzma 2019-08-19T03:04:01.070Z,1566183841.070 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0045.lzma.bak 2019-08-19T03:04:01.071Z,1566183841.071 [DataOverHttps](INFO): SBD MOMSN=11590928 2019-08-19T03:04:01.159Z,1566183841.159 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-19T03:04:01.160Z,1566183841.160 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-19T03:04:01.160Z,1566183841.160 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-08-19T03:04:01.163Z,1566183841.163 [BPC1](INFO): Received data from all battery sticks. 2019-08-19T03:04:12.625Z,1566183852.625 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20190819T003049/Express0046.lzma 2019-08-19T03:04:13.430Z,1566183853.430 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0046.lzma.bak 2019-08-19T03:04:13.431Z,1566183853.431 [DataOverHttps](INFO): SBD MOMSN=11590930 2019-08-19T03:04:14.512Z,1566183854.512 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T03:04:14.512Z,1566183854.512 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T03:04:14.512Z,1566183854.512 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T03:04:40.775Z,1566183880.775 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T03:05:11.480Z,1566183911.480 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T03:09:15.129Z,1566184155.129 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T03:09:15.129Z,1566184155.129 [Default:CheckIn:C.Wait] Stopped 2019-08-19T03:09:15.130Z,1566184155.130 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T03:09:15.130Z,1566184155.130 [Default:CheckIn:D] Running Loop=1 2019-08-19T03:09:15.518Z,1566184155.518 [Default:CheckIn:D] Stopped 2019-08-19T03:09:15.518Z,1566184155.518 [Default:CheckIn:E] Running Loop=1 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 216.933708 min 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn:E] Stopped 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn] Stopped 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn](INFO): Running loop #27 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn] Running Loop=27 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T03:09:15.922Z,1566184155.922 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T03:09:17.533Z,1566184157.533 [NAL9602](DEBUG): Fix Requested 2019-08-19T03:09:48.638Z,1566184188.638 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T03:09:48.721Z,1566184188.721 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T03:09:48.721Z,1566184188.721 [NAL9602] Data Fault, FailCount= 5 2019-08-19T03:09:48.721Z,1566184188.721 [NAL9602](ERROR): Data Fault 2019-08-19T03:09:48.817Z,1566184188.817 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T03:09:48.818Z,1566184188.818 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-08-19T03:09:49.034Z,1566184189.034 [NAL9602](INFO): Powering down 2019-08-19T03:09:49.084Z,1566184189.084 [CBIT](INFO): Critical error at 20190819T030948 2019-08-19T03:11:49.047Z,1566184309.047 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T03:11:49.047Z,1566184309.047 [NAL9602] No Fault, FailCount= 5 2019-08-19T03:11:49.420Z,1566184309.420 [NAL9602](INFO): Powering up NAL9602 2019-08-19T03:12:00.328Z,1566184320.328 [NAL9602](INFO): NAL9602 initialized 2019-08-19T03:12:01.136Z,1566184321.136 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T03:12:01.136Z,1566184321.136 [NAL9602] Data Fault, FailCount= 1 2019-08-19T03:12:01.136Z,1566184321.136 [NAL9602](ERROR): Data Fault 2019-08-19T03:12:01.168Z,1566184321.168 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T03:12:01.548Z,1566184321.548 [NAL9602](INFO): Powering down 2019-08-19T03:12:02.383Z,1566184322.383 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T03:12:02.383Z,1566184322.383 [NAL9602] No Fault, FailCount= 1 2019-08-19T03:12:31.846Z,1566184351.846 [NAL9602](INFO): Powering up NAL9602 2019-08-19T03:12:42.751Z,1566184362.751 [NAL9602](INFO): NAL9602 initialized 2019-08-19T03:12:43.578Z,1566184363.578 [NAL9602](DEBUG): Fix Requested 2019-08-19T03:14:16.101Z,1566184456.101 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T03:09:15.9Z 2019-08-19T03:14:16.101Z,1566184456.101 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T03:14:16.102Z,1566184456.102 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T03:14:19.730Z,1566184459.730 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T03:14:24.281Z,1566184464.281 [DataOverHttps](INFO): Sending 88 bytes from file Logs/20190819T003049/Courier0048.lzma 2019-08-19T03:14:26.005Z,1566184466.005 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0048.lzma.bak 2019-08-19T03:14:26.005Z,1566184466.005 [DataOverHttps](INFO): SBD MOMSN=11590943 2019-08-19T03:14:37.732Z,1566184477.732 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20190819T003049/Express0049.lzma 2019-08-19T03:14:38.538Z,1566184478.538 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0049.lzma.bak 2019-08-19T03:14:38.539Z,1566184478.539 [DataOverHttps](INFO): SBD MOMSN=11590946 2019-08-19T03:14:39.980Z,1566184479.980 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T03:14:39.980Z,1566184479.980 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T03:14:39.980Z,1566184479.980 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T03:14:50.446Z,1566184490.446 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T03:19:40.581Z,1566184780.581 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T03:19:40.581Z,1566184780.581 [Default:CheckIn:C.Wait] Stopped 2019-08-19T03:19:40.582Z,1566184780.582 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T03:19:40.582Z,1566184780.582 [Default:CheckIn:D] Running Loop=1 2019-08-19T03:19:40.965Z,1566184780.965 [Default:CheckIn:D] Stopped 2019-08-19T03:19:40.966Z,1566184780.966 [Default:CheckIn:E] Running Loop=1 2019-08-19T03:19:41.376Z,1566184781.376 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 227.357829 min 2019-08-19T03:19:41.376Z,1566184781.376 [Default:CheckIn:E] Stopped 2019-08-19T03:19:41.376Z,1566184781.376 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T03:19:41.376Z,1566184781.376 [Default:CheckIn] Stopped 2019-08-19T03:19:41.376Z,1566184781.376 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T03:19:41.376Z,1566184781.376 [Default:CheckIn](INFO): Running loop #28 2019-08-19T03:19:41.377Z,1566184781.377 [Default:CheckIn] Running Loop=28 2019-08-19T03:19:41.377Z,1566184781.377 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T03:19:41.377Z,1566184781.377 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T03:19:42.981Z,1566184782.981 [NAL9602](DEBUG): Fix Requested 2019-08-19T03:20:14.072Z,1566184814.072 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T03:20:14.145Z,1566184814.145 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T03:20:14.145Z,1566184814.145 [NAL9602] Data Fault, FailCount= 2 2019-08-19T03:20:14.145Z,1566184814.145 [NAL9602](ERROR): Data Fault 2019-08-19T03:20:14.184Z,1566184814.184 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T03:20:14.482Z,1566184814.482 [NAL9602](INFO): Powering down 2019-08-19T03:20:15.317Z,1566184815.317 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T03:20:15.318Z,1566184815.318 [NAL9602] No Fault, FailCount= 2 2019-08-19T03:20:44.796Z,1566184844.796 [NAL9602](INFO): Powering up NAL9602 2019-08-19T03:20:55.752Z,1566184855.752 [NAL9602](INFO): NAL9602 initialized 2019-08-19T03:20:56.525Z,1566184856.525 [NAL9602](DEBUG): Fix Requested 2019-08-19T03:24:41.620Z,1566185081.620 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T03:19:41.4Z 2019-08-19T03:24:41.620Z,1566185081.620 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T03:24:41.621Z,1566185081.621 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T03:24:45.630Z,1566185085.630 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T03:24:47.200Z,1566185087.200 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0051.lzma 2019-08-19T03:24:48.006Z,1566185088.006 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0051.lzma.bak 2019-08-19T03:24:48.007Z,1566185088.007 [DataOverHttps](INFO): SBD MOMSN=11590956 2019-08-19T03:24:59.489Z,1566185099.489 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20190819T003049/Express0052.lzma 2019-08-19T03:25:00.294Z,1566185100.294 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0052.lzma.bak 2019-08-19T03:25:00.295Z,1566185100.295 [DataOverHttps](INFO): SBD MOMSN=11590958 2019-08-19T03:25:01.423Z,1566185101.423 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T03:25:01.424Z,1566185101.424 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T03:25:01.424Z,1566185101.424 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T03:25:16.332Z,1566185116.332 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T03:30:01.994Z,1566185401.994 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T03:30:01.994Z,1566185401.994 [Default:CheckIn:C.Wait] Stopped 2019-08-19T03:30:01.995Z,1566185401.995 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T03:30:01.995Z,1566185401.995 [Default:CheckIn:D] Running Loop=1 2019-08-19T03:30:02.404Z,1566185402.404 [Default:CheckIn:D] Stopped 2019-08-19T03:30:02.404Z,1566185402.404 [Default:CheckIn:E] Running Loop=1 2019-08-19T03:30:02.804Z,1566185402.804 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 237.715137 min 2019-08-19T03:30:02.804Z,1566185402.804 [Default:CheckIn:E] Stopped 2019-08-19T03:30:02.804Z,1566185402.804 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T03:30:02.804Z,1566185402.804 [Default:CheckIn] Stopped 2019-08-19T03:30:02.804Z,1566185402.804 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T03:30:02.809Z,1566185402.809 [Default:CheckIn](INFO): Running loop #29 2019-08-19T03:30:02.809Z,1566185402.809 [Default:CheckIn] Running Loop=29 2019-08-19T03:30:02.810Z,1566185402.810 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T03:30:02.810Z,1566185402.810 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T03:30:04.390Z,1566185404.390 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T03:30:04.390Z,1566185404.390 [NAL9602] Data Fault, FailCount= 3 2019-08-19T03:30:04.390Z,1566185404.390 [NAL9602](ERROR): Data Fault 2019-08-19T03:30:04.448Z,1566185404.448 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T03:30:04.788Z,1566185404.788 [NAL9602](INFO): Powering down 2019-08-19T03:30:05.637Z,1566185405.637 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T03:30:05.637Z,1566185405.637 [NAL9602] No Fault, FailCount= 3 2019-08-19T03:30:35.092Z,1566185435.092 [NAL9602](INFO): Powering up NAL9602 2019-08-19T03:30:46.000Z,1566185446.000 [NAL9602](INFO): NAL9602 initialized 2019-08-19T03:30:46.821Z,1566185446.821 [NAL9602](DEBUG): Fix Requested 2019-08-19T03:35:02.989Z,1566185702.989 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-19T03:30:02.8Z 2019-08-19T03:35:02.989Z,1566185702.989 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T03:35:02.990Z,1566185702.990 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-19T03:35:08.620Z,1566185708.620 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190819T003049/Courier0054.lzma 2019-08-19T03:35:09.427Z,1566185709.427 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Courier0054.lzma.bak 2019-08-19T03:35:09.427Z,1566185709.427 [DataOverHttps](INFO): SBD MOMSN=11590968 2019-08-19T03:35:22.729Z,1566185722.729 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20190819T003049/Express0055.lzma 2019-08-19T03:35:23.534Z,1566185723.534 [DataOverHttps](INFO): Moved sent file to Logs/20190819T003049/Express0055.lzma.bak 2019-08-19T03:35:23.535Z,1566185723.535 [DataOverHttps](INFO): SBD MOMSN=11590970 2019-08-19T03:35:24.848Z,1566185724.848 [Default:CheckIn:Read_Iridium] Stopped 2019-08-19T03:35:24.848Z,1566185724.848 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-19T03:35:24.848Z,1566185724.848 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-19T03:35:49.056Z,1566185749.056 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-19T03:36:19.761Z,1566185779.761 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-19T03:40:25.423Z,1566186025.423 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-19T03:40:25.423Z,1566186025.423 [Default:CheckIn:C.Wait] Stopped 2019-08-19T03:40:25.423Z,1566186025.423 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-19T03:40:25.424Z,1566186025.424 [Default:CheckIn:D] Running Loop=1 2019-08-19T03:40:25.828Z,1566186025.828 [Default:CheckIn:D] Stopped 2019-08-19T03:40:25.828Z,1566186025.828 [Default:CheckIn:E] Running Loop=1 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 248.105534 min 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn:E] Stopped 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn] Stopped 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn](INFO): Running loop #30 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn] Running Loop=30 2019-08-19T03:40:26.321Z,1566186026.321 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-19T03:40:26.322Z,1566186026.322 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-19T03:40:27.833Z,1566186027.833 [NAL9602](DEBUG): Fix Requested 2019-08-19T03:40:58.928Z,1566186058.928 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-19T03:40:59.001Z,1566186059.001 [NAL9602](FAULT): received: +CSQ:0 OK828, 0, 0, 0, 0 OK 2019-08-19T03:40:59.001Z,1566186059.001 [NAL9602] Data Fault, FailCount= 4 2019-08-19T03:40:59.001Z,1566186059.001 [NAL9602](ERROR): Data Fault 2019-08-19T03:40:59.092Z,1566186059.092 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T03:40:59.334Z,1566186059.334 [NAL9602](INFO): Powering down 2019-08-19T03:41:00.178Z,1566186060.178 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-19T03:41:00.178Z,1566186060.178 [NAL9602] No Fault, FailCount= 4 2019-08-19T03:41:25.606Z,1566186085.606 [CommandLine](IMPORTANT): got command configSet AHRS_M2.loadAtStartup 0.000000 bool persist 2019-08-19T03:41:25.607Z,1566186085.607 [CommandLine](IMPORTANT): configSet AHRS_M2.loadAtStartup requires a restart to take effect. 2019-08-19T03:41:29.639Z,1566186089.639 [NAL9602](INFO): Powering up NAL9602 2019-08-19T03:41:40.541Z,1566186100.541 [NAL9602](INFO): NAL9602 initialized 2019-08-19T03:41:41.364Z,1566186101.364 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-19T03:41:41.364Z,1566186101.364 [NAL9602] Data Fault, FailCount= 5 2019-08-19T03:41:41.365Z,1566186101.365 [NAL9602](ERROR): Data Fault 2019-08-19T03:41:41.418Z,1566186101.418 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-19T03:41:41.419Z,1566186101.419 [CBIT](CRITICAL): Data Fault in component: NAL9602 2019-08-19T03:41:41.758Z,1566186101.758 [NAL9602](INFO): Powering down 2019-08-19T03:41:41.788Z,1566186101.788 [CBIT](INFO): Critical error at 20190819T034141 2019-08-19T03:42:08.606Z,1566186128.606 [DataOverHttps](IMPORTANT): SBD MTMSN=20190819T034028 2019-08-19T03:42:13.968Z,1566186133.968 [DataOverHttps](INFO): Received command:restart app 2019-08-19T03:42:13.986Z,1566186133.986 [CommandLine](IMPORTANT): got command restart application 2019-08-19T03:42:14.989Z,1566186134.989 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:14.990Z,1566186134.990 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.137Z,1566186135.137 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-08-19T03:42:15.137Z,1566186135.137 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.138Z,1566186135.138 [CommandLine](INFO): Join timeout helper Thread ID is 779 2019-08-19T03:42:15.138Z,1566186135.138 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-08-19T03:42:15.138Z,1566186135.138 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.139Z,1566186135.139 [NavChartDb](INFO): Join timeout helper Thread ID is 781 2019-08-19T03:42:15.481Z,1566186135.481 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:15.481Z,1566186135.481 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.493Z,1566186135.493 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-08-19T03:42:15.493Z,1566186135.493 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.493Z,1566186135.493 [Radio_Surface](INFO): Join timeout helper Thread ID is 782 2019-08-19T03:42:15.494Z,1566186135.494 [Radio_Surface](INFO): Powering down 2019-08-19T03:42:15.495Z,1566186135.495 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:15.495Z,1566186135.495 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.495Z,1566186135.495 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-08-19T03:42:15.495Z,1566186135.495 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.496Z,1566186135.496 [DataOverHttps](INFO): Join timeout helper Thread ID is 783 2019-08-19T03:42:15.581Z,1566186135.581 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:15.581Z,1566186135.581 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.602Z,1566186135.602 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-08-19T03:42:15.602Z,1566186135.602 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.603Z,1566186135.603 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 784 2019-08-19T03:42:15.609Z,1566186135.609 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:15.609Z,1566186135.609 [WetLabsBB2FL](INFO): Powering down 2019-08-19T03:42:15.610Z,1566186135.610 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.622Z,1566186135.622 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-08-19T03:42:15.622Z,1566186135.622 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.622Z,1566186135.622 [CTD_Seabird](INFO): Join timeout helper Thread ID is 785 2019-08-19T03:42:15.677Z,1566186135.677 [CTD_Seabird](INFO): Powering down 2019-08-19T03:42:15.689Z,1566186135.689 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:15.689Z,1566186135.689 [CTD_Seabird](INFO): Powering down 2019-08-19T03:42:15.701Z,1566186135.701 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.702Z,1566186135.702 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-08-19T03:42:15.702Z,1566186135.702 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.703Z,1566186135.703 [logger](INFO): Join timeout helper Thread ID is 786 2019-08-19T03:42:15.781Z,1566186135.781 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:15.781Z,1566186135.781 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.790Z,1566186135.790 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-08-19T03:42:15.790Z,1566186135.790 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.790Z,1566186135.790 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-08-19T03:42:15.790Z,1566186135.790 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:15.790Z,1566186135.790 [controlThread](INFO): Join timeout helper Thread ID is 787 2019-08-19T03:42:16.073Z,1566186136.073 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-19T03:42:16.073Z,1566186136.073 [controlThread](DEBUG): Uninitializing ControlThread 2019-08-19T03:42:16.073Z,1566186136.073 [Aanderaa_O2](INFO): Powering down 2019-08-19T03:42:16.096Z,1566186136.096 [AHRS_M2](INFO): Powering down 2019-08-19T03:42:16.169Z,1566186136.169 [NAL9602](INFO): Powering down 2019-08-19T03:42:16.171Z,1566186136.171 [DAT](INFO): Powering down 2019-08-19T03:42:16.290Z,1566186136.290 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-08-19T03:42:16.291Z,1566186136.291 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-08-19T03:42:16.291Z,1566186136.291 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-08-19T03:42:16.291Z,1566186136.291 [MissionManager](INFO): Uninitializing Mission Default 2019-08-19T03:42:16.292Z,1566186136.292 [Default] Stopped 2019-08-19T03:42:16.292Z,1566186136.292 [Default](DEBUG): Aggregate::uninitialize Default 2019-08-19T03:42:16.292Z,1566186136.292 [Default:B.GoToSurface] Stopped 2019-08-19T03:42:16.292Z,1566186136.292 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-19T03:42:16.292Z,1566186136.292 [Default:CheckIn] Stopped 2019-08-19T03:42:16.292Z,1566186136.292 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-19T03:42:16.292Z,1566186136.292 [Default:CheckIn:Read_GPS] Stopped 2019-08-19T03:42:16.294Z,1566186136.294 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-08-19T03:42:16.295Z,1566186136.295 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-08-19T03:42:16.295Z,1566186136.295 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-08-19T03:42:16.295Z,1566186136.295 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-08-19T03:42:16.295Z,1566186136.295 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-08-19T03:42:16.296Z,1566186136.296 [BuoyancyServo](INFO): Powering down 2019-08-19T03:42:16.309Z,1566186136.309 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-08-19T03:42:16.309Z,1566186136.309 [ElevatorServo](INFO): Powering down 2019-08-19T03:42:16.310Z,1566186136.310 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-08-19T03:42:16.310Z,1566186136.310 [MassServo](INFO): Powering down 2019-08-19T03:42:16.311Z,1566186136.311 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-19T03:42:16.311Z,1566186136.311 [RudderServo](INFO): Powering down 2019-08-19T03:42:16.312Z,1566186136.312 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-08-19T03:42:16.312Z,1566186136.312 [ThrusterServo](INFO): Powering down 2019-08-19T03:42:16.312Z,1566186136.312 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-08-19T03:42:16.313Z,1566186136.313 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-08-19T03:42:16.313Z,1566186136.313 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-08-19T03:42:16.313Z,1566186136.313 [CBIT](DEBUG): Powering off loads. 2019-08-19T03:42:16.325Z,1566186136.325 [CBIT](DEBUG): Disabling WDT. 2019-08-19T03:42:16.337Z,1566186136.337 [CBIT](DEBUG): Opening all GF detection circuits. 2019-08-19T03:42:16.338Z,1566186136.338 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:16.377Z,1566186136.377 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:16.381Z,1566186136.381 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:16.444Z,1566186136.444 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:16.448Z,1566186136.448 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:16.498Z,1566186136.498 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-19T03:42:16.566Z,1566186136.566 [logger ThreadHandler](INFO): Thread cancelled.