2018-07-27T20:13:31.386Z,1532722411.386 [CommandLine](IMPORTANT): got command restart logs 2018-07-27T20:15:58.187Z,1532722558.187 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2018-07-27T20:16:22.233Z,1532722582.233 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T20:16:22.233Z,1532722582.233 [Default:CheckIn:C.Wait] Stopped 2018-07-27T20:16:22.233Z,1532722582.233 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T20:16:22.234Z,1532722582.234 [Default:CheckIn:D] Running Loop=1 2018-07-27T20:16:22.630Z,1532722582.630 [Default:CheckIn:D] Stopped 2018-07-27T20:16:22.630Z,1532722582.630 [Default:CheckIn:E] Running Loop=1 2018-07-27T20:16:23.035Z,1532722583.035 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.841264 min 2018-07-27T20:16:23.035Z,1532722583.035 [Default:CheckIn:E] Stopped 2018-07-27T20:16:23.035Z,1532722583.035 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T20:16:23.035Z,1532722583.035 [Default:CheckIn] Stopped 2018-07-27T20:16:23.036Z,1532722583.036 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T20:16:23.036Z,1532722583.036 [Default:CheckIn](INFO): Running loop #2 2018-07-27T20:16:23.036Z,1532722583.036 [Default:CheckIn] Running Loop=2 2018-07-27T20:16:23.036Z,1532722583.036 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T20:16:23.036Z,1532722583.036 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T20:16:23.786Z,1532722583.786 [NAL9602](INFO): Powering up 2018-07-27T20:16:34.582Z,1532722594.582 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:16:53.132Z,1532722613.132 [NAL9602](INFO): SBD MO Status=0, MOMSN=500, MT Status=0, MTMSN=0 2018-07-27T20:16:53.132Z,1532722613.132 [NAL9602](INFO): No messages in MT queue 2018-07-27T20:16:59.918Z,1532722619.918 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T20:16:59.918Z,1532722619.918 [NAL9602] Data Fault, FailCount= 1 2018-07-27T20:16:59.918Z,1532722619.918 [NAL9602](ERROR): Data Fault 2018-07-27T20:17:00.019Z,1532722620.019 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T20:17:00.322Z,1532722620.322 [NAL9602](INFO): Powering down 2018-07-27T20:17:01.209Z,1532722621.209 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T20:17:01.209Z,1532722621.209 [NAL9602] No Fault, FailCount= 1 2018-07-27T20:17:31.914Z,1532722651.914 [NAL9602](INFO): Powering up NAL9602 2018-07-27T20:17:42.871Z,1532722662.871 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:18:51.386Z,1532722731.386 [NAL9602](INFO): GPS fix at 20180727T201850: (36.805711, -121.792303) 2018-07-27T20:18:51.445Z,1532722731.445 [UniversalFixResidualReporter](INFO): Fix residual: 231.5 %DT, over the last 1153.5 m. Residual distance 2670.0 m at bearing -97.4 degrees. Fix at (36.8057, -121.7923) with 2692.2 m made good. 2018-07-27T20:18:51.446Z,1532722731.446 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T20:18:51.447Z,1532722731.447 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T20:18:58.754Z,1532722738.754 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T183049/Courier0052.lzma 2018-07-27T20:18:59.552Z,1532722739.552 [DataOverHttps](INFO): Moved sent file to Logs/20180727T183049/Courier0052.lzma.bak 2018-07-27T20:18:59.552Z,1532722739.552 [DataOverHttps](INFO): SBD MOMSN=8381149 2018-07-27T20:19:10.712Z,1532722750.712 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20180727T201331/Courier0000.lzma 2018-07-27T20:19:11.508Z,1532722751.508 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0000.lzma.bak 2018-07-27T20:19:11.508Z,1532722751.508 [DataOverHttps](INFO): SBD MOMSN=8381151 2018-07-27T20:19:23.710Z,1532722763.710 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0003.lzma 2018-07-27T20:19:23.714Z,1532722763.714 [NAL9602](INFO): Powering down 2018-07-27T20:19:24.139Z,1532722764.139 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-27T20:19:24.508Z,1532722764.508 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0003.lzma.bak 2018-07-27T20:19:24.508Z,1532722764.508 [DataOverHttps](INFO): SBD MOMSN=8381155 2018-07-27T20:19:33.587Z,1532722773.587 [DataOverHttps](INFO): Sending 109 bytes from file Logs/20180727T183049/Express0053.lzma 2018-07-27T20:19:34.368Z,1532722774.368 [DataOverHttps](INFO): Moved sent file to Logs/20180727T183049/Express0053.lzma.bak 2018-07-27T20:19:34.368Z,1532722774.368 [DataOverHttps](INFO): SBD MOMSN=8381157 2018-07-27T20:19:44.325Z,1532722784.325 [DataOverHttps](INFO): Sending 398 bytes from file Logs/20180727T201331/Express0001.lzma 2018-07-27T20:19:45.116Z,1532722785.116 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0001.lzma.bak 2018-07-27T20:19:45.116Z,1532722785.116 [DataOverHttps](INFO): SBD MOMSN=8381160 2018-07-27T20:19:45.161Z,1532722785.161 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-27T20:19:54.588Z,1532722794.588 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Express0004.lzma 2018-07-27T20:19:55.364Z,1532722795.364 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0004.lzma.bak 2018-07-27T20:19:55.365Z,1532722795.365 [DataOverHttps](INFO): SBD MOMSN=8381165 2018-07-27T20:19:55.834Z,1532722795.834 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T20:19:55.834Z,1532722795.834 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T20:19:55.835Z,1532722795.835 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T20:24:56.457Z,1532723096.457 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T20:24:56.457Z,1532723096.457 [Default:CheckIn:C.Wait] Stopped 2018-07-27T20:24:56.457Z,1532723096.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T20:24:56.458Z,1532723096.458 [Default:CheckIn:D] Running Loop=1 2018-07-27T20:24:56.855Z,1532723096.855 [Default:CheckIn:D] Stopped 2018-07-27T20:24:56.855Z,1532723096.855 [Default:CheckIn:E] Running Loop=1 2018-07-27T20:25:00.064Z,1532723100.064 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.411686 min 2018-07-27T20:25:00.064Z,1532723100.064 [Default:CheckIn:E] Stopped 2018-07-27T20:25:00.065Z,1532723100.065 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T20:25:00.065Z,1532723100.065 [Default:CheckIn] Stopped 2018-07-27T20:25:00.065Z,1532723100.065 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T20:25:00.065Z,1532723100.065 [Default:CheckIn](INFO): Running loop #3 2018-07-27T20:25:00.066Z,1532723100.066 [Default:CheckIn] Running Loop=3 2018-07-27T20:25:00.066Z,1532723100.066 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T20:25:00.066Z,1532723100.066 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T20:25:00.522Z,1532723100.522 [NAL9602](INFO): Powering up 2018-07-27T20:25:11.718Z,1532723111.718 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:25:52.120Z,1532723152.120 [NAL9602](INFO): SBD MO Status=0, MOMSN=501, MT Status=0, MTMSN=0 2018-07-27T20:25:52.120Z,1532723152.120 [NAL9602](INFO): No messages in MT queue 2018-07-27T20:25:53.326Z,1532723153.326 [NAL9602](INFO): GPS fix at 20180727T202552: (36.802750, -121.786839) 2018-07-27T20:25:53.385Z,1532723153.385 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T20:25:53.386Z,1532723153.386 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T20:25:59.104Z,1532723159.104 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180727T201331/Courier0006.lzma 2018-07-27T20:25:59.900Z,1532723159.900 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0006.lzma.bak 2018-07-27T20:25:59.900Z,1532723159.900 [DataOverHttps](INFO): SBD MOMSN=8381201 2018-07-27T20:26:10.992Z,1532723170.992 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20180727T201331/Express0007.lzma 2018-07-27T20:26:11.759Z,1532723171.759 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0007.lzma.bak 2018-07-27T20:26:11.759Z,1532723171.759 [DataOverHttps](INFO): SBD MOMSN=8381205 2018-07-27T20:26:12.234Z,1532723172.234 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T20:26:12.234Z,1532723172.234 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T20:26:12.234Z,1532723172.234 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T20:26:25.518Z,1532723185.518 [NAL9602](INFO): Powering down 2018-07-27T20:31:12.988Z,1532723472.988 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T20:31:12.988Z,1532723472.988 [Default:CheckIn:C.Wait] Stopped 2018-07-27T20:31:12.993Z,1532723472.993 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T20:31:12.993Z,1532723472.993 [Default:CheckIn:D] Running Loop=1 2018-07-27T20:31:13.386Z,1532723473.386 [Default:CheckIn:D] Stopped 2018-07-27T20:31:13.386Z,1532723473.386 [Default:CheckIn:E] Running Loop=1 2018-07-27T20:31:16.593Z,1532723476.593 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.687213 min 2018-07-27T20:31:16.594Z,1532723476.594 [Default:CheckIn:E] Stopped 2018-07-27T20:31:16.594Z,1532723476.594 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T20:31:16.594Z,1532723476.594 [Default:CheckIn] Stopped 2018-07-27T20:31:16.594Z,1532723476.594 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T20:31:16.594Z,1532723476.594 [Default:CheckIn](INFO): Running loop #4 2018-07-27T20:31:16.594Z,1532723476.594 [Default:CheckIn] Running Loop=4 2018-07-27T20:31:16.595Z,1532723476.595 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T20:31:16.595Z,1532723476.595 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T20:31:17.042Z,1532723477.042 [NAL9602](INFO): Powering up 2018-07-27T20:31:28.234Z,1532723488.234 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:32:06.628Z,1532723526.628 [NAL9602](INFO): SBD MO Status=2, MOMSN=502, MT Status=2, MTMSN=0 2018-07-27T20:32:06.628Z,1532723526.628 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-27T20:36:17.273Z,1532723777.273 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T20:31:16.6Z 2018-07-27T20:36:17.273Z,1532723777.273 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T20:36:17.274Z,1532723777.274 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T20:36:17.740Z,1532723777.740 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0009.lzma 2018-07-27T20:36:18.528Z,1532723778.528 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0009.lzma.bak 2018-07-27T20:36:18.528Z,1532723778.528 [DataOverHttps](INFO): SBD MOMSN=8381245 2018-07-27T20:36:29.051Z,1532723789.051 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20180727T201331/Express0010.lzma 2018-07-27T20:36:29.843Z,1532723789.843 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0010.lzma.bak 2018-07-27T20:36:29.843Z,1532723789.843 [DataOverHttps](INFO): SBD MOMSN=8381247 2018-07-27T20:36:30.300Z,1532723790.300 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T20:36:30.300Z,1532723790.300 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T20:36:30.300Z,1532723790.300 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T20:36:33.869Z,1532723793.869 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T20:37:04.387Z,1532723824.387 [NAL9602](INFO): Powering down 2018-07-27T20:41:30.975Z,1532724090.975 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T20:41:30.975Z,1532724090.975 [Default:CheckIn:C.Wait] Stopped 2018-07-27T20:41:30.975Z,1532724090.975 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T20:41:30.975Z,1532724090.975 [Default:CheckIn:D] Running Loop=1 2018-07-27T20:41:31.374Z,1532724091.374 [Default:CheckIn:D] Stopped 2018-07-27T20:41:31.374Z,1532724091.374 [Default:CheckIn:E] Running Loop=1 2018-07-27T20:41:34.580Z,1532724094.580 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.987000 min 2018-07-27T20:41:34.585Z,1532724094.585 [Default:CheckIn:E] Stopped 2018-07-27T20:41:34.585Z,1532724094.585 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T20:41:34.585Z,1532724094.585 [Default:CheckIn] Stopped 2018-07-27T20:41:34.585Z,1532724094.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T20:41:34.586Z,1532724094.586 [Default:CheckIn](INFO): Running loop #5 2018-07-27T20:41:34.586Z,1532724094.586 [Default:CheckIn] Running Loop=5 2018-07-27T20:41:34.586Z,1532724094.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T20:41:34.586Z,1532724094.586 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T20:41:35.036Z,1532724095.036 [NAL9602](INFO): Powering up 2018-07-27T20:41:46.232Z,1532724106.232 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:41:47.038Z,1532724107.038 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T20:41:47.039Z,1532724107.039 [NAL9602] Data Fault, FailCount= 1 2018-07-27T20:41:47.039Z,1532724107.039 [NAL9602](ERROR): Data Fault 2018-07-27T20:41:47.117Z,1532724107.117 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T20:41:47.430Z,1532724107.430 [NAL9602](INFO): Powering down 2018-07-27T20:41:48.305Z,1532724108.305 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T20:41:48.305Z,1532724108.305 [NAL9602] No Fault, FailCount= 1 2018-07-27T20:42:17.838Z,1532724137.838 [NAL9602](INFO): Powering up NAL9602 2018-07-27T20:42:28.634Z,1532724148.634 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:46:35.283Z,1532724395.283 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T20:41:34.6Z 2018-07-27T20:46:35.284Z,1532724395.284 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T20:46:35.284Z,1532724395.284 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T20:46:40.846Z,1532724400.846 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0012.lzma 2018-07-27T20:46:41.604Z,1532724401.604 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0012.lzma.bak 2018-07-27T20:46:41.605Z,1532724401.605 [DataOverHttps](INFO): SBD MOMSN=8381285 2018-07-27T20:46:51.915Z,1532724411.915 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20180727T201331/Express0013.lzma 2018-07-27T20:46:53.112Z,1532724413.112 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0013.lzma.bak 2018-07-27T20:46:53.112Z,1532724413.112 [DataOverHttps](INFO): SBD MOMSN=8381287 2018-07-27T20:46:53.577Z,1532724413.577 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T20:46:53.577Z,1532724413.577 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T20:46:53.577Z,1532724413.577 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T20:47:34.838Z,1532724454.838 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T20:48:05.462Z,1532724485.462 [NAL9602](INFO): Powering down 2018-07-27T20:51:54.002Z,1532724714.002 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T20:51:54.002Z,1532724714.002 [Default:CheckIn:C.Wait] Stopped 2018-07-27T20:51:54.002Z,1532724714.002 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T20:51:54.002Z,1532724714.002 [Default:CheckIn:D] Running Loop=1 2018-07-27T20:51:54.388Z,1532724714.388 [Default:CheckIn:D] Stopped 2018-07-27T20:51:54.388Z,1532724714.388 [Default:CheckIn:E] Running Loop=1 2018-07-27T20:51:54.790Z,1532724714.790 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.370569 min 2018-07-27T20:51:54.790Z,1532724714.790 [Default:CheckIn:E] Stopped 2018-07-27T20:51:54.791Z,1532724714.791 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T20:51:54.791Z,1532724714.791 [Default:CheckIn] Stopped 2018-07-27T20:51:54.791Z,1532724714.791 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T20:51:54.791Z,1532724714.791 [Default:CheckIn](INFO): Running loop #6 2018-07-27T20:51:54.791Z,1532724714.791 [Default:CheckIn] Running Loop=6 2018-07-27T20:51:54.791Z,1532724714.791 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T20:51:54.791Z,1532724714.791 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T20:51:58.255Z,1532724718.255 [NAL9602](INFO): Powering up 2018-07-27T20:52:09.050Z,1532724729.050 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:52:41.051Z,1532724761.051 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T20:52:41.133Z,1532724761.133 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T20:52:41.133Z,1532724761.133 [NAL9602] Data Fault, FailCount= 2 2018-07-27T20:52:41.133Z,1532724761.133 [NAL9602](ERROR): Data Fault 2018-07-27T20:52:41.257Z,1532724761.257 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T20:52:41.466Z,1532724761.466 [NAL9602](INFO): Powering down 2018-07-27T20:52:42.313Z,1532724762.313 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T20:52:42.313Z,1532724762.313 [NAL9602] No Fault, FailCount= 2 2018-07-27T20:53:11.646Z,1532724791.646 [NAL9602](INFO): Powering up NAL9602 2018-07-27T20:53:22.442Z,1532724802.442 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:53:23.246Z,1532724803.246 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T20:53:23.247Z,1532724803.247 [NAL9602] Data Fault, FailCount= 3 2018-07-27T20:53:23.247Z,1532724803.247 [NAL9602](ERROR): Data Fault 2018-07-27T20:53:23.321Z,1532724803.321 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T20:53:23.642Z,1532724803.642 [NAL9602](INFO): Powering down 2018-07-27T20:53:24.520Z,1532724804.520 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T20:53:24.520Z,1532724804.520 [NAL9602] No Fault, FailCount= 3 2018-07-27T20:53:54.046Z,1532724834.046 [NAL9602](INFO): Powering up NAL9602 2018-07-27T20:54:05.166Z,1532724845.166 [NAL9602](INFO): NAL9602 initialized 2018-07-27T20:54:34.768Z,1532724874.768 [NAL9602](INFO): SBD MO Status=2, MOMSN=502, MT Status=2, MTMSN=0 2018-07-27T20:54:34.768Z,1532724874.768 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-27T20:56:55.067Z,1532725015.067 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T20:51:54.8Z 2018-07-27T20:56:55.067Z,1532725015.067 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T20:56:55.067Z,1532725015.067 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T20:57:00.714Z,1532725020.714 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0015.lzma 2018-07-27T20:57:01.911Z,1532725021.911 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0015.lzma.bak 2018-07-27T20:57:01.912Z,1532725021.912 [DataOverHttps](INFO): SBD MOMSN=8381328 2018-07-27T20:57:12.796Z,1532725032.796 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T20:57:13.548Z,1532725033.548 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20180727T201331/Express0016.lzma 2018-07-27T20:57:16.744Z,1532725036.744 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0016.lzma.bak 2018-07-27T20:57:16.744Z,1532725036.744 [DataOverHttps](INFO): SBD MOMSN=8381330 2018-07-27T20:57:17.246Z,1532725037.246 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T20:57:17.246Z,1532725037.246 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T20:57:17.247Z,1532725037.247 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T20:57:43.266Z,1532725063.266 [NAL9602](INFO): Powering down 2018-07-27T21:02:17.648Z,1532725337.648 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T21:02:17.649Z,1532725337.649 [Default:CheckIn:C.Wait] Stopped 2018-07-27T21:02:17.649Z,1532725337.649 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T21:02:17.649Z,1532725337.649 [Default:CheckIn:D] Running Loop=1 2018-07-27T21:02:18.046Z,1532725338.046 [Default:CheckIn:D] Stopped 2018-07-27T21:02:18.046Z,1532725338.046 [Default:CheckIn:E] Running Loop=1 2018-07-27T21:02:18.454Z,1532725338.454 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.764876 min 2018-07-27T21:02:18.454Z,1532725338.454 [Default:CheckIn:E] Stopped 2018-07-27T21:02:18.455Z,1532725338.455 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T21:02:18.455Z,1532725338.455 [Default:CheckIn] Stopped 2018-07-27T21:02:18.455Z,1532725338.455 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T21:02:18.455Z,1532725338.455 [Default:CheckIn](INFO): Running loop #7 2018-07-27T21:02:18.455Z,1532725338.455 [Default:CheckIn] Running Loop=7 2018-07-27T21:02:18.455Z,1532725338.455 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T21:02:18.455Z,1532725338.455 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T21:02:19.202Z,1532725339.202 [NAL9602](INFO): Powering up 2018-07-27T21:02:30.118Z,1532725350.118 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:07:18.495Z,1532725638.495 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T21:02:18.5Z 2018-07-27T21:07:18.495Z,1532725638.495 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T21:07:18.496Z,1532725638.496 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T21:07:23.506Z,1532725643.506 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0018.lzma 2018-07-27T21:07:24.704Z,1532725644.704 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0018.lzma.bak 2018-07-27T21:07:24.704Z,1532725644.704 [DataOverHttps](INFO): SBD MOMSN=8381367 2018-07-27T21:07:33.645Z,1532725653.645 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T21:07:40.708Z,1532725660.708 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20180727T201331/Express0019.lzma 2018-07-27T21:07:45.906Z,1532725665.906 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0019.lzma.bak 2018-07-27T21:07:45.906Z,1532725665.906 [DataOverHttps](INFO): SBD MOMSN=8381369 2018-07-27T21:07:46.379Z,1532725666.379 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T21:07:46.379Z,1532725666.379 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T21:07:46.379Z,1532725666.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T21:08:04.380Z,1532725684.380 [NAL9602](INFO): Powering down 2018-07-27T21:10:56.216Z,1532725856.216 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-27T21:11:55.135Z,1532725915.135 [RDI_Pathfinder](ERROR): Failed to parse: 2018-07-27T21:12:46.765Z,1532725966.765 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T21:12:46.765Z,1532725966.765 [Default:CheckIn:C.Wait] Stopped 2018-07-27T21:12:46.765Z,1532725966.765 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T21:12:46.766Z,1532725966.766 [Default:CheckIn:D] Running Loop=1 2018-07-27T21:12:47.197Z,1532725967.197 [Default:CheckIn:D] Stopped 2018-07-27T21:12:47.197Z,1532725967.197 [Default:CheckIn:E] Running Loop=1 2018-07-27T21:12:47.571Z,1532725967.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.250728 min 2018-07-27T21:12:47.572Z,1532725967.572 [Default:CheckIn:E] Stopped 2018-07-27T21:12:47.572Z,1532725967.572 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T21:12:47.572Z,1532725967.572 [Default:CheckIn] Stopped 2018-07-27T21:12:47.572Z,1532725967.572 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T21:12:47.572Z,1532725967.572 [Default:CheckIn](INFO): Running loop #8 2018-07-27T21:12:47.572Z,1532725967.572 [Default:CheckIn] Running Loop=8 2018-07-27T21:12:47.574Z,1532725967.574 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T21:12:47.574Z,1532725967.574 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T21:12:48.314Z,1532725968.314 [NAL9602](INFO): Powering up 2018-07-27T21:12:59.198Z,1532725979.198 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:12:59.990Z,1532725979.990 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T21:12:59.991Z,1532725979.991 [NAL9602] Data Fault, FailCount= 4 2018-07-27T21:12:59.991Z,1532725979.991 [NAL9602](ERROR): Data Fault 2018-07-27T21:13:00.105Z,1532725980.105 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T21:13:00.392Z,1532725980.392 [NAL9602](INFO): Powering down 2018-07-27T21:13:01.268Z,1532725981.268 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T21:13:01.273Z,1532725981.273 [NAL9602] No Fault, FailCount= 4 2018-07-27T21:13:30.804Z,1532726010.804 [NAL9602](INFO): Powering up NAL9602 2018-07-27T21:13:41.598Z,1532726021.598 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:17:47.625Z,1532726267.625 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T21:12:47.6Z 2018-07-27T21:17:47.625Z,1532726267.625 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T21:17:47.625Z,1532726267.625 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T21:17:52.485Z,1532726272.485 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0021.lzma 2018-07-27T21:17:53.268Z,1532726273.268 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0021.lzma.bak 2018-07-27T21:17:53.268Z,1532726273.268 [DataOverHttps](INFO): SBD MOMSN=8381413 2018-07-27T21:17:59.055Z,1532726279.055 [RDI_Pathfinder](ERROR): Failed to parse: 2018-07-27T21:18:04.351Z,1532726284.351 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20180727T201331/Express0022.lzma 2018-07-27T21:18:05.128Z,1532726285.128 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0022.lzma.bak 2018-07-27T21:18:05.128Z,1532726285.128 [DataOverHttps](INFO): SBD MOMSN=8381415 2018-07-27T21:18:05.602Z,1532726285.602 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T21:18:05.602Z,1532726285.602 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T21:18:05.602Z,1532726285.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T21:18:45.302Z,1532726325.302 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T21:19:15.813Z,1532726355.813 [NAL9602](INFO): Powering down 2018-07-27T21:23:06.330Z,1532726586.330 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T21:23:06.330Z,1532726586.330 [Default:CheckIn:C.Wait] Stopped 2018-07-27T21:23:06.331Z,1532726586.331 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T21:23:06.331Z,1532726586.331 [Default:CheckIn:D] Running Loop=1 2018-07-27T21:23:06.705Z,1532726586.705 [Default:CheckIn:D] Stopped 2018-07-27T21:23:06.705Z,1532726586.705 [Default:CheckIn:E] Running Loop=1 2018-07-27T21:23:09.996Z,1532726589.996 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.575854 min 2018-07-27T21:23:09.996Z,1532726589.996 [Default:CheckIn:E] Stopped 2018-07-27T21:23:09.996Z,1532726589.996 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T21:23:09.996Z,1532726589.996 [Default:CheckIn] Stopped 2018-07-27T21:23:09.997Z,1532726589.997 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T21:23:09.997Z,1532726589.997 [Default:CheckIn](INFO): Running loop #9 2018-07-27T21:23:09.997Z,1532726589.997 [Default:CheckIn] Running Loop=9 2018-07-27T21:23:09.997Z,1532726589.997 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T21:23:09.997Z,1532726589.997 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T21:23:10.442Z,1532726590.442 [NAL9602](INFO): Powering up 2018-07-27T21:23:21.630Z,1532726601.630 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:23:53.638Z,1532726633.638 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T21:23:53.713Z,1532726633.713 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T21:23:53.713Z,1532726633.713 [NAL9602] Data Fault, FailCount= 5 2018-07-27T21:23:53.713Z,1532726633.713 [NAL9602](ERROR): Data Fault 2018-07-27T21:23:53.760Z,1532726633.760 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T21:23:53.794Z,1532726633.794 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-07-27T21:23:54.038Z,1532726634.038 [NAL9602](INFO): Powering down 2018-07-27T21:23:54.130Z,1532726634.130 [CommandLine](FAULT): Scheduling is paused 2018-07-27T21:23:54.131Z,1532726634.131 [CBIT](INFO): Critical error at 20180727T212353 2018-07-27T21:25:54.094Z,1532726754.094 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T21:25:54.094Z,1532726754.094 [NAL9602] No Fault, FailCount= 5 2018-07-27T21:25:54.406Z,1532726754.406 [NAL9602](INFO): Powering up NAL9602 2018-07-27T21:26:05.210Z,1532726765.210 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:26:06.018Z,1532726766.018 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T21:26:06.018Z,1532726766.018 [NAL9602] Data Fault, FailCount= 1 2018-07-27T21:26:06.018Z,1532726766.018 [NAL9602](ERROR): Data Fault 2018-07-27T21:26:06.113Z,1532726766.113 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T21:26:06.406Z,1532726766.406 [NAL9602](INFO): Powering down 2018-07-27T21:26:07.312Z,1532726767.312 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T21:26:07.312Z,1532726767.312 [NAL9602] No Fault, FailCount= 1 2018-07-27T21:26:36.570Z,1532726796.570 [NAL9602](INFO): Powering up NAL9602 2018-07-27T21:26:47.766Z,1532726807.766 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:27:43.181Z,1532726863.181 [RDI_Pathfinder](ERROR): only read 3 of 5 data items 2018-07-27T21:27:43.182Z,1532726863.182 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-3276,-32768,V 2018-07-27T21:28:10.831Z,1532726890.831 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T21:23:09.0Z 2018-07-27T21:28:10.831Z,1532726890.831 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T21:28:10.832Z,1532726890.832 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T21:28:12.106Z,1532726892.106 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2018-07-27T21:28:15.938Z,1532726895.938 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20180727T201331/Courier0024.lzma 2018-07-27T21:28:16.716Z,1532726896.716 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0024.lzma.bak 2018-07-27T21:28:16.716Z,1532726896.716 [DataOverHttps](INFO): SBD MOMSN=8381453 2018-07-27T21:28:26.487Z,1532726906.487 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T21:28:26.621Z,1532726906.621 [DataOverHttps](INFO): Sending 276 bytes from file Logs/20180727T201331/Express0025.lzma 2018-07-27T21:28:27.384Z,1532726907.384 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0025.lzma.bak 2018-07-27T21:28:27.384Z,1532726907.384 [DataOverHttps](INFO): SBD MOMSN=8381456 2018-07-27T21:28:27.855Z,1532726907.855 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T21:28:27.855Z,1532726907.855 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T21:28:27.855Z,1532726907.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T21:28:56.830Z,1532726936.830 [NAL9602](INFO): Powering down 2018-07-27T21:30:33.104Z,1532727033.104 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-27T21:31:09.454Z,1532727069.454 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2018-07-27T21:31:09.454Z,1532727069.454 [DropWeight] Hardware Fault, FailCount= 1 2018-07-27T21:31:09.454Z,1532727069.454 [DropWeight](ERROR): Hardware Fault 2018-07-27T21:31:09.543Z,1532727069.543 [CBIT](INFO): Critical error at 20180727T213109 2018-07-27T21:31:09.546Z,1532727069.546 [CBIT](ERROR): Hardware Fault in component: DropWeight 2018-07-27T21:31:09.546Z,1532727069.546 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2018-07-27T21:31:09.938Z,1532727069.938 [CBIT](INFO): Critical error at 20180727T213109 2018-07-27T21:33:28.576Z,1532727208.576 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T21:33:28.576Z,1532727208.576 [Default:CheckIn:C.Wait] Stopped 2018-07-27T21:33:28.576Z,1532727208.576 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T21:33:28.577Z,1532727208.577 [Default:CheckIn:D] Running Loop=1 2018-07-27T21:33:28.978Z,1532727208.978 [Default:CheckIn:D] Stopped 2018-07-27T21:33:28.978Z,1532727208.978 [Default:CheckIn:E] Running Loop=1 2018-07-27T21:33:29.382Z,1532727209.382 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.947078 min 2018-07-27T21:33:29.382Z,1532727209.382 [Default:CheckIn:E] Stopped 2018-07-27T21:33:29.382Z,1532727209.382 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T21:33:29.382Z,1532727209.382 [Default:CheckIn] Stopped 2018-07-27T21:33:29.382Z,1532727209.382 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T21:33:29.383Z,1532727209.383 [Default:CheckIn](INFO): Running loop #10 2018-07-27T21:33:29.383Z,1532727209.383 [Default:CheckIn] Running Loop=10 2018-07-27T21:33:29.383Z,1532727209.383 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T21:33:29.383Z,1532727209.383 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T21:33:32.895Z,1532727212.895 [NAL9602](INFO): Powering up 2018-07-27T21:33:43.836Z,1532727223.836 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:34:15.834Z,1532727255.834 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T21:34:15.909Z,1532727255.909 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T21:34:15.909Z,1532727255.909 [NAL9602] Data Fault, FailCount= 2 2018-07-27T21:34:15.909Z,1532727255.909 [NAL9602](ERROR): Data Fault 2018-07-27T21:34:16.017Z,1532727256.017 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T21:34:16.238Z,1532727256.238 [NAL9602](INFO): Powering down 2018-07-27T21:34:17.085Z,1532727257.085 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T21:34:17.085Z,1532727257.085 [NAL9602] No Fault, FailCount= 2 2018-07-27T21:34:46.426Z,1532727286.426 [NAL9602](INFO): Powering up NAL9602 2018-07-27T21:34:57.230Z,1532727297.230 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:35:44.164Z,1532727344.164 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2018-07-27T21:35:44.164Z,1532727344.164 [RDI_Pathfinder](ERROR): Failed to parse: :TS,18072721365291,35.0, -0.1,448.9, 0 2018-07-27T21:38:29.646Z,1532727509.646 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T21:33:29.4Z 2018-07-27T21:38:29.647Z,1532727509.647 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T21:38:29.647Z,1532727509.647 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T21:38:33.853Z,1532727513.853 [DataOverHttps](INFO): Sending 126 bytes from file Logs/20180727T201331/Courier0027.lzma 2018-07-27T21:38:34.619Z,1532727514.619 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0027.lzma.bak 2018-07-27T21:38:34.619Z,1532727514.619 [DataOverHttps](INFO): SBD MOMSN=8381499 2018-07-27T21:38:44.439Z,1532727524.439 [DataOverHttps](INFO): Sending 239 bytes from file Logs/20180727T201331/Express0028.lzma 2018-07-27T21:38:45.200Z,1532727525.200 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0028.lzma.bak 2018-07-27T21:38:45.200Z,1532727525.200 [DataOverHttps](INFO): SBD MOMSN=8381503 2018-07-27T21:38:45.682Z,1532727525.682 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T21:38:45.682Z,1532727525.682 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T21:38:45.683Z,1532727525.683 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T21:38:50.010Z,1532727530.010 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T21:39:20.598Z,1532727560.598 [NAL9602](INFO): Powering down 2018-07-27T21:39:39.580Z,1532727579.580 [CommandLine](IMPORTANT): got command show best depth 2018-07-27T21:39:39.580Z,1532727579.580 [CommandLine](IMPORTANT): depth best is Depth_Keller.depth 2018-07-27T21:39:42.315Z,1532727582.315 [CommandLine](IMPORTANT): got command get depth 2018-07-27T21:39:42.316Z,1532727582.316 [CommandLine](IMPORTANT): depth 0.124940 m 2018-07-27T21:40:14.076Z,1532727614.076 [BPC1](ERROR): Bank B: No match for stick 1 serial number:1717 in the onboard configuration file. 2018-07-27T21:40:14.077Z,1532727614.077 [BPC1](ERROR): Failed to parse Bank B battery data 2018-07-27T21:43:46.298Z,1532727826.298 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T21:43:46.298Z,1532727826.298 [Default:CheckIn:C.Wait] Stopped 2018-07-27T21:43:46.299Z,1532727826.299 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T21:43:46.299Z,1532727826.299 [Default:CheckIn:D] Running Loop=1 2018-07-27T21:43:46.683Z,1532727826.683 [Default:CheckIn:D] Stopped 2018-07-27T21:43:46.683Z,1532727826.683 [Default:CheckIn:E] Running Loop=1 2018-07-27T21:43:47.083Z,1532727827.083 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.242155 min 2018-07-27T21:43:47.083Z,1532727827.083 [Default:CheckIn:E] Stopped 2018-07-27T21:43:47.083Z,1532727827.083 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T21:43:47.084Z,1532727827.084 [Default:CheckIn] Stopped 2018-07-27T21:43:47.084Z,1532727827.084 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T21:43:47.084Z,1532727827.084 [Default:CheckIn](INFO): Running loop #11 2018-07-27T21:43:47.084Z,1532727827.084 [Default:CheckIn] Running Loop=11 2018-07-27T21:43:47.084Z,1532727827.084 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T21:43:47.084Z,1532727827.084 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T21:43:50.366Z,1532727830.366 [NAL9602](INFO): Powering up 2018-07-27T21:44:01.558Z,1532727841.558 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:44:02.352Z,1532727842.352 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T21:44:02.353Z,1532727842.353 [NAL9602] Data Fault, FailCount= 3 2018-07-27T21:44:02.353Z,1532727842.353 [NAL9602](ERROR): Data Fault 2018-07-27T21:44:02.414Z,1532727842.414 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T21:44:02.767Z,1532727842.767 [NAL9602](INFO): Powering down 2018-07-27T21:44:03.615Z,1532727843.615 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T21:44:03.615Z,1532727843.615 [NAL9602] No Fault, FailCount= 3 2018-07-27T21:44:33.150Z,1532727873.150 [NAL9602](INFO): Powering up NAL9602 2018-07-27T21:44:44.354Z,1532727884.354 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:46:09.834Z,1532727969.834 [CBIT](INFO): Clearing failed state for component DropWeight 2018-07-27T21:46:09.834Z,1532727969.834 [DropWeight] No Fault, FailCount= 1 2018-07-27T21:48:47.212Z,1532728127.212 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T21:43:47.1Z 2018-07-27T21:48:47.212Z,1532728127.212 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T21:48:47.217Z,1532728127.217 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T21:48:51.442Z,1532728131.442 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20180727T201331/Courier0030.lzma 2018-07-27T21:48:52.221Z,1532728132.221 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0030.lzma.bak 2018-07-27T21:48:52.221Z,1532728132.221 [DataOverHttps](INFO): SBD MOMSN=8381547 2018-07-27T21:49:01.350Z,1532728141.350 [DataOverHttps](INFO): Sending 290 bytes from file Logs/20180727T201331/Express0031.lzma 2018-07-27T21:49:02.120Z,1532728142.120 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0031.lzma.bak 2018-07-27T21:49:02.120Z,1532728142.120 [DataOverHttps](INFO): SBD MOMSN=8381549 2018-07-27T21:49:02.593Z,1532728142.593 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T21:49:02.593Z,1532728142.593 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T21:49:02.593Z,1532728142.593 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T21:49:50.801Z,1532728190.801 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T21:50:21.310Z,1532728221.310 [NAL9602](INFO): Powering down 2018-07-27T21:54:03.084Z,1532728443.084 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T21:54:03.084Z,1532728443.084 [Default:CheckIn:C.Wait] Stopped 2018-07-27T21:54:03.085Z,1532728443.085 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T21:54:03.085Z,1532728443.085 [Default:CheckIn:D] Running Loop=1 2018-07-27T21:54:03.474Z,1532728443.474 [Default:CheckIn:D] Stopped 2018-07-27T21:54:03.474Z,1532728443.474 [Default:CheckIn:E] Running Loop=1 2018-07-27T21:54:03.913Z,1532728443.913 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.521997 min 2018-07-27T21:54:03.914Z,1532728443.914 [Default:CheckIn:E] Stopped 2018-07-27T21:54:03.914Z,1532728443.914 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T21:54:03.914Z,1532728443.914 [Default:CheckIn] Stopped 2018-07-27T21:54:03.914Z,1532728443.914 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T21:54:03.914Z,1532728443.914 [Default:CheckIn](INFO): Running loop #12 2018-07-27T21:54:03.914Z,1532728443.914 [Default:CheckIn] Running Loop=12 2018-07-27T21:54:03.914Z,1532728443.914 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T21:54:03.915Z,1532728443.915 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T21:54:04.626Z,1532728444.626 [NAL9602](INFO): Powering up 2018-07-27T21:54:15.494Z,1532728455.494 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:54:47.503Z,1532728487.503 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T21:54:47.577Z,1532728487.577 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T21:54:47.577Z,1532728487.577 [NAL9602] Data Fault, FailCount= 4 2018-07-27T21:54:47.577Z,1532728487.577 [NAL9602](ERROR): Data Fault 2018-07-27T21:54:47.681Z,1532728487.681 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T21:54:47.890Z,1532728487.890 [NAL9602](INFO): Powering down 2018-07-27T21:54:48.775Z,1532728488.775 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T21:54:48.775Z,1532728488.775 [NAL9602] No Fault, FailCount= 4 2018-07-27T21:55:18.124Z,1532728518.124 [NAL9602](INFO): Powering up NAL9602 2018-07-27T21:55:28.914Z,1532728528.914 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:55:29.714Z,1532728529.714 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T21:55:29.714Z,1532728529.714 [NAL9602] Data Fault, FailCount= 5 2018-07-27T21:55:29.714Z,1532728529.714 [NAL9602](ERROR): Data Fault 2018-07-27T21:55:29.817Z,1532728529.817 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T21:55:29.817Z,1532728529.817 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-07-27T21:55:30.114Z,1532728530.114 [NAL9602](INFO): Powering down 2018-07-27T21:55:30.204Z,1532728530.204 [CBIT](INFO): Critical error at 20180727T215529 2018-07-27T21:57:29.717Z,1532728649.717 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T21:57:29.717Z,1532728649.717 [NAL9602] No Fault, FailCount= 5 2018-07-27T21:57:30.066Z,1532728650.066 [NAL9602](INFO): Powering up NAL9602 2018-07-27T21:57:41.271Z,1532728661.271 [NAL9602](INFO): NAL9602 initialized 2018-07-27T21:59:04.219Z,1532728744.219 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T21:54:03.9Z 2018-07-27T21:59:04.219Z,1532728744.219 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T21:59:04.219Z,1532728744.219 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T21:59:08.825Z,1532728748.825 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180727T201331/Courier0033.lzma 2018-07-27T21:59:09.580Z,1532728749.580 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0033.lzma.bak 2018-07-27T21:59:09.580Z,1532728749.580 [DataOverHttps](INFO): SBD MOMSN=8381595 2018-07-27T21:59:19.487Z,1532728759.487 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T21:59:19.650Z,1532728759.650 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20180727T201331/Express0034.lzma 2018-07-27T21:59:20.416Z,1532728760.416 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0034.lzma.bak 2018-07-27T21:59:20.416Z,1532728760.416 [DataOverHttps](INFO): SBD MOMSN=8381598 2018-07-27T21:59:20.895Z,1532728760.895 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T21:59:20.895Z,1532728760.895 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T21:59:20.895Z,1532728760.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T21:59:49.839Z,1532728789.839 [NAL9602](INFO): Powering down 2018-07-27T22:01:02.166Z,1532728862.166 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2018-07-27T22:01:02.166Z,1532728862.166 [RDI_Pathfinder](ERROR): Failed to parse: :TS,180727225.0, -0.1, 0.0,1448.9, 0 2018-07-27T22:02:35.970Z,1532728955.970 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2018-07-27T22:02:35.971Z,1532728955.971 [RDI_Pathfinder](ERROR): Failed to parse: :TS8,V 2018-07-27T22:04:21.416Z,1532729061.416 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T22:04:21.416Z,1532729061.416 [Default:CheckIn:C.Wait] Stopped 2018-07-27T22:04:21.416Z,1532729061.416 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T22:04:21.416Z,1532729061.416 [Default:CheckIn:D] Running Loop=1 2018-07-27T22:04:21.865Z,1532729061.865 [Default:CheckIn:D] Stopped 2018-07-27T22:04:21.866Z,1532729061.866 [Default:CheckIn:E] Running Loop=1 2018-07-27T22:04:22.226Z,1532729062.226 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.828532 min 2018-07-27T22:04:22.226Z,1532729062.226 [Default:CheckIn:E] Stopped 2018-07-27T22:04:22.227Z,1532729062.227 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T22:04:22.227Z,1532729062.227 [Default:CheckIn] Stopped 2018-07-27T22:04:22.227Z,1532729062.227 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T22:04:22.227Z,1532729062.227 [Default:CheckIn](INFO): Running loop #13 2018-07-27T22:04:22.227Z,1532729062.227 [Default:CheckIn] Running Loop=13 2018-07-27T22:04:22.227Z,1532729062.227 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T22:04:22.227Z,1532729062.227 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T22:04:22.978Z,1532729062.978 [NAL9602](INFO): Powering up 2018-07-27T22:04:33.862Z,1532729073.862 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:05:05.859Z,1532729105.859 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T22:05:05.937Z,1532729105.937 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T22:05:05.938Z,1532729105.938 [NAL9602] Data Fault, FailCount= 1 2018-07-27T22:05:05.938Z,1532729105.938 [NAL9602](ERROR): Data Fault 2018-07-27T22:05:06.040Z,1532729106.040 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:05:06.255Z,1532729106.255 [NAL9602](INFO): Powering down 2018-07-27T22:05:07.148Z,1532729107.148 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:05:07.148Z,1532729107.148 [NAL9602] No Fault, FailCount= 1 2018-07-27T22:05:36.402Z,1532729136.402 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:05:47.210Z,1532729147.210 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:08:27.234Z,1532729307.234 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e88,0e87,*16.061,*0.028,*65.535 2018-07-27T22:09:22.469Z,1532729362.469 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T22:04:22.2Z 2018-07-27T22:09:22.470Z,1532729362.470 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T22:09:22.470Z,1532729362.470 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T22:09:26.995Z,1532729366.995 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0036.lzma 2018-07-27T22:09:27.772Z,1532729367.772 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0036.lzma.bak 2018-07-27T22:09:27.772Z,1532729367.772 [DataOverHttps](INFO): SBD MOMSN=8381635 2018-07-27T22:09:38.257Z,1532729378.257 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T22:09:38.498Z,1532729378.498 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20180727T201331/Express0037.lzma 2018-07-27T22:09:39.251Z,1532729379.251 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0037.lzma.bak 2018-07-27T22:09:39.252Z,1532729379.252 [DataOverHttps](INFO): SBD MOMSN=8381637 2018-07-27T22:09:39.719Z,1532729379.719 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T22:09:39.719Z,1532729379.719 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T22:09:39.719Z,1532729379.719 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T22:10:08.674Z,1532729408.674 [NAL9602](INFO): Powering down 2018-07-27T22:11:44.136Z,1532729504.136 [RDI_Pathfinder](ERROR): DVL BIT error. See manual. Result code: 32768 2018-07-27T22:11:44.141Z,1532729504.141 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-32768,V 2018-07-27T22:14:40.457Z,1532729680.457 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T22:14:40.457Z,1532729680.457 [Default:CheckIn:C.Wait] Stopped 2018-07-27T22:14:40.457Z,1532729680.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T22:14:40.458Z,1532729680.458 [Default:CheckIn:D] Running Loop=1 2018-07-27T22:14:40.864Z,1532729680.864 [Default:CheckIn:D] Stopped 2018-07-27T22:14:40.864Z,1532729680.864 [Default:CheckIn:E] Running Loop=1 2018-07-27T22:14:44.049Z,1532729684.049 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.145174 min 2018-07-27T22:14:44.049Z,1532729684.049 [Default:CheckIn:E] Stopped 2018-07-27T22:14:44.049Z,1532729684.049 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T22:14:44.050Z,1532729684.050 [Default:CheckIn] Stopped 2018-07-27T22:14:44.050Z,1532729684.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T22:14:44.050Z,1532729684.050 [Default:CheckIn](INFO): Running loop #14 2018-07-27T22:14:44.050Z,1532729684.050 [Default:CheckIn] Running Loop=14 2018-07-27T22:14:44.050Z,1532729684.050 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T22:14:44.050Z,1532729684.050 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T22:14:44.494Z,1532729684.494 [NAL9602](INFO): Powering up 2018-07-27T22:14:55.682Z,1532729695.682 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:14:56.483Z,1532729696.483 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T22:14:56.483Z,1532729696.483 [NAL9602] Data Fault, FailCount= 2 2018-07-27T22:14:56.483Z,1532729696.483 [NAL9602](ERROR): Data Fault 2018-07-27T22:14:56.568Z,1532729696.568 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:14:56.882Z,1532729696.882 [NAL9602](INFO): Powering down 2018-07-27T22:14:57.743Z,1532729697.743 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:14:57.743Z,1532729697.743 [NAL9602] No Fault, FailCount= 2 2018-07-27T22:15:26.894Z,1532729726.894 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:15:38.108Z,1532729738.108 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:16:11.150Z,1532729771.150 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2018-07-27T22:16:11.150Z,1532729771.150 [DropWeight] Hardware Fault, FailCount= 1 2018-07-27T22:16:11.150Z,1532729771.150 [DropWeight](ERROR): Hardware Fault 2018-07-27T22:16:11.222Z,1532729771.222 [CBIT](INFO): Critical error at 20180727T221611 2018-07-27T22:16:11.225Z,1532729771.225 [CBIT](ERROR): Hardware Fault in component: DropWeight 2018-07-27T22:16:11.225Z,1532729771.225 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2018-07-27T22:16:11.619Z,1532729771.619 [CBIT](INFO): Critical error at 20180727T221611 2018-07-27T22:19:45.786Z,1532729985.786 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T22:14:44.1Z 2018-07-27T22:19:45.786Z,1532729985.786 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T22:19:45.787Z,1532729985.787 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T22:19:51.976Z,1532729991.976 [DataOverHttps](INFO): Sending 103 bytes from file Logs/20180727T201331/Courier0039.lzma 2018-07-27T22:19:52.759Z,1532729992.759 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0039.lzma.bak 2018-07-27T22:19:52.759Z,1532729992.759 [DataOverHttps](INFO): SBD MOMSN=8381642 2018-07-27T22:20:03.666Z,1532730003.666 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20180727T201331/Express0040.lzma 2018-07-27T22:20:04.446Z,1532730004.446 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0040.lzma.bak 2018-07-27T22:20:04.447Z,1532730004.447 [DataOverHttps](INFO): SBD MOMSN=8381646 2018-07-27T22:20:04.928Z,1532730004.928 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T22:20:04.928Z,1532730004.928 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T22:20:04.928Z,1532730004.928 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T22:20:41.362Z,1532730041.362 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T22:21:11.991Z,1532730071.991 [NAL9602](INFO): Powering down 2018-07-27T22:25:05.389Z,1532730305.389 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T22:25:05.390Z,1532730305.390 [Default:CheckIn:C.Wait] Stopped 2018-07-27T22:25:05.390Z,1532730305.390 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T22:25:05.390Z,1532730305.390 [Default:CheckIn:D] Running Loop=1 2018-07-27T22:25:05.791Z,1532730305.791 [Default:CheckIn:D] Stopped 2018-07-27T22:25:05.791Z,1532730305.791 [Default:CheckIn:E] Running Loop=1 2018-07-27T22:25:06.221Z,1532730306.221 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 140.560628 min 2018-07-27T22:25:06.221Z,1532730306.221 [Default:CheckIn:E] Stopped 2018-07-27T22:25:06.221Z,1532730306.221 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T22:25:06.222Z,1532730306.222 [Default:CheckIn] Stopped 2018-07-27T22:25:06.222Z,1532730306.222 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T22:25:06.222Z,1532730306.222 [Default:CheckIn](INFO): Running loop #15 2018-07-27T22:25:06.222Z,1532730306.222 [Default:CheckIn] Running Loop=15 2018-07-27T22:25:06.222Z,1532730306.222 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T22:25:06.222Z,1532730306.222 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T22:25:09.634Z,1532730309.634 [NAL9602](INFO): Powering up 2018-07-27T22:25:20.794Z,1532730320.794 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:25:52.794Z,1532730352.794 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T22:25:52.877Z,1532730352.877 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T22:25:52.877Z,1532730352.877 [NAL9602] Data Fault, FailCount= 3 2018-07-27T22:25:52.877Z,1532730352.877 [NAL9602](ERROR): Data Fault 2018-07-27T22:25:52.970Z,1532730352.970 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:25:53.194Z,1532730353.194 [NAL9602](INFO): Powering down 2018-07-27T22:25:54.086Z,1532730354.086 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:25:54.086Z,1532730354.086 [NAL9602] No Fault, FailCount= 3 2018-07-27T22:26:23.309Z,1532730383.309 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:26:34.502Z,1532730394.502 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:26:35.302Z,1532730395.302 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T22:26:35.302Z,1532730395.302 [NAL9602] Data Fault, FailCount= 4 2018-07-27T22:26:35.302Z,1532730395.302 [NAL9602](ERROR): Data Fault 2018-07-27T22:26:35.382Z,1532730395.382 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:26:35.706Z,1532730395.706 [NAL9602](INFO): Powering down 2018-07-27T22:26:36.574Z,1532730396.574 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:26:36.574Z,1532730396.574 [NAL9602] No Fault, FailCount= 4 2018-07-27T22:27:06.102Z,1532730426.102 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:27:16.978Z,1532730436.978 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:30:06.526Z,1532730606.526 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T22:25:06.2Z 2018-07-27T22:30:06.526Z,1532730606.526 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T22:30:06.526Z,1532730606.526 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T22:30:10.236Z,1532730610.236 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0042.lzma 2018-07-27T22:30:11.012Z,1532730611.012 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0042.lzma.bak 2018-07-27T22:30:11.012Z,1532730611.012 [DataOverHttps](INFO): SBD MOMSN=8381651 2018-07-27T22:30:24.705Z,1532730624.705 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T22:30:25.045Z,1532730625.045 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20180727T201331/Express0043.lzma 2018-07-27T22:30:25.816Z,1532730625.816 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0043.lzma.bak 2018-07-27T22:30:25.817Z,1532730625.817 [DataOverHttps](INFO): SBD MOMSN=8381653 2018-07-27T22:30:26.347Z,1532730626.347 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T22:30:26.347Z,1532730626.347 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T22:30:26.347Z,1532730626.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T22:30:55.154Z,1532730655.154 [NAL9602](INFO): Powering down 2018-07-27T22:31:11.203Z,1532730671.203 [CBIT](INFO): Clearing failed state for component DropWeight 2018-07-27T22:31:11.203Z,1532730671.203 [DropWeight] No Fault, FailCount= 1 2018-07-27T22:35:26.685Z,1532730926.685 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T22:35:26.686Z,1532730926.686 [Default:CheckIn:C.Wait] Stopped 2018-07-27T22:35:26.686Z,1532730926.686 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T22:35:26.686Z,1532730926.686 [Default:CheckIn:D] Running Loop=1 2018-07-27T22:35:27.050Z,1532730927.050 [Default:CheckIn:D] Stopped 2018-07-27T22:35:27.050Z,1532730927.050 [Default:CheckIn:E] Running Loop=1 2018-07-27T22:35:27.443Z,1532730927.443 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 150.914941 min 2018-07-27T22:35:27.444Z,1532730927.444 [Default:CheckIn:E] Stopped 2018-07-27T22:35:27.444Z,1532730927.444 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T22:35:27.444Z,1532730927.444 [Default:CheckIn] Stopped 2018-07-27T22:35:27.444Z,1532730927.444 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T22:35:27.444Z,1532730927.444 [Default:CheckIn](INFO): Running loop #16 2018-07-27T22:35:27.444Z,1532730927.444 [Default:CheckIn] Running Loop=16 2018-07-27T22:35:27.469Z,1532730927.469 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T22:35:27.469Z,1532730927.469 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T22:35:30.770Z,1532730930.770 [NAL9602](INFO): Powering up 2018-07-27T22:35:41.931Z,1532730941.931 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:35:59.182Z,1532730959.182 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e88, 16.068, 0.025, 65.535 2018-07-27T22:36:13.926Z,1532730973.926 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T22:36:14.005Z,1532730974.005 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T22:36:14.005Z,1532730974.005 [NAL9602] Data Fault, FailCount= 5 2018-07-27T22:36:14.005Z,1532730974.005 [NAL9602](ERROR): Data Fault 2018-07-27T22:36:14.126Z,1532730974.126 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:36:14.126Z,1532730974.126 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-07-27T22:36:14.314Z,1532730974.314 [NAL9602](INFO): Powering down 2018-07-27T22:36:14.393Z,1532730974.393 [CBIT](INFO): Critical error at 20180727T223614 2018-07-27T22:38:14.337Z,1532731094.337 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:38:14.337Z,1532731094.337 [NAL9602] No Fault, FailCount= 5 2018-07-27T22:38:14.670Z,1532731094.670 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:38:25.470Z,1532731105.470 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:38:26.278Z,1532731106.278 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T22:38:26.278Z,1532731106.278 [NAL9602] Data Fault, FailCount= 1 2018-07-27T22:38:26.278Z,1532731106.278 [NAL9602](ERROR): Data Fault 2018-07-27T22:38:26.391Z,1532731106.391 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:38:26.682Z,1532731106.682 [NAL9602](INFO): Powering down 2018-07-27T22:38:27.556Z,1532731107.556 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:38:27.556Z,1532731107.556 [NAL9602] No Fault, FailCount= 1 2018-07-27T22:38:56.782Z,1532731136.782 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:39:07.586Z,1532731147.586 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:40:27.821Z,1532731227.821 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T22:35:27.5Z 2018-07-27T22:40:27.822Z,1532731227.822 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T22:40:27.822Z,1532731227.822 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T22:40:32.858Z,1532731232.858 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20180727T201331/Courier0045.lzma 2018-07-27T22:40:33.629Z,1532731233.629 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0045.lzma.bak 2018-07-27T22:40:33.629Z,1532731233.629 [DataOverHttps](INFO): SBD MOMSN=8381659 2018-07-27T22:40:43.562Z,1532731243.562 [DataOverHttps](INFO): Sending 253 bytes from file Logs/20180727T201331/Express0046.lzma 2018-07-27T22:40:44.348Z,1532731244.348 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0046.lzma.bak 2018-07-27T22:40:44.348Z,1532731244.348 [DataOverHttps](INFO): SBD MOMSN=8381662 2018-07-27T22:40:44.863Z,1532731244.863 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T22:40:44.863Z,1532731244.863 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T22:40:44.863Z,1532731244.863 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T22:40:45.158Z,1532731245.158 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T22:41:15.794Z,1532731275.794 [NAL9602](INFO): Powering down 2018-07-27T22:45:45.223Z,1532731545.223 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T22:45:45.223Z,1532731545.223 [Default:CheckIn:C.Wait] Stopped 2018-07-27T22:45:45.223Z,1532731545.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T22:45:45.224Z,1532731545.224 [Default:CheckIn:D] Running Loop=1 2018-07-27T22:45:45.626Z,1532731545.626 [Default:CheckIn:D] Stopped 2018-07-27T22:45:45.626Z,1532731545.626 [Default:CheckIn:E] Running Loop=1 2018-07-27T22:45:46.037Z,1532731546.037 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 161.224544 min 2018-07-27T22:45:46.037Z,1532731546.037 [Default:CheckIn:E] Stopped 2018-07-27T22:45:46.037Z,1532731546.037 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T22:45:46.037Z,1532731546.037 [Default:CheckIn] Stopped 2018-07-27T22:45:46.038Z,1532731546.038 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T22:45:46.038Z,1532731546.038 [Default:CheckIn](INFO): Running loop #17 2018-07-27T22:45:46.038Z,1532731546.038 [Default:CheckIn] Running Loop=17 2018-07-27T22:45:46.038Z,1532731546.038 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T22:45:46.038Z,1532731546.038 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T22:45:49.349Z,1532731549.349 [NAL9602](INFO): Powering up 2018-07-27T22:46:00.522Z,1532731560.522 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:46:32.519Z,1532731592.519 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T22:46:32.593Z,1532731592.593 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T22:46:32.593Z,1532731592.593 [NAL9602] Data Fault, FailCount= 2 2018-07-27T22:46:32.593Z,1532731592.593 [NAL9602](ERROR): Data Fault 2018-07-27T22:46:32.673Z,1532731592.673 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:46:32.914Z,1532731592.914 [NAL9602](INFO): Powering down 2018-07-27T22:46:33.818Z,1532731593.818 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:46:33.818Z,1532731593.818 [NAL9602] No Fault, FailCount= 2 2018-07-27T22:47:03.154Z,1532731623.154 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:47:14.354Z,1532731634.354 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:50:46.121Z,1532731846.121 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T22:45:46.0Z 2018-07-27T22:50:46.121Z,1532731846.121 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T22:50:46.122Z,1532731846.122 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T22:50:50.203Z,1532731850.203 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0048.lzma 2018-07-27T22:50:50.972Z,1532731850.972 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0048.lzma.bak 2018-07-27T22:50:50.972Z,1532731850.972 [DataOverHttps](INFO): SBD MOMSN=8381668 2018-07-27T22:51:01.102Z,1532731861.102 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20180727T201331/Express0049.lzma 2018-07-27T22:51:01.876Z,1532731861.876 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0049.lzma.bak 2018-07-27T22:51:01.876Z,1532731861.876 [DataOverHttps](INFO): SBD MOMSN=8381670 2018-07-27T22:51:02.348Z,1532731862.348 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T22:51:02.353Z,1532731862.353 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T22:51:02.353Z,1532731862.353 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T22:51:05.851Z,1532731865.851 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T22:51:36.414Z,1532731896.414 [NAL9602](INFO): Powering down 2018-07-27T22:56:03.055Z,1532732163.055 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T22:56:03.055Z,1532732163.055 [Default:CheckIn:C.Wait] Stopped 2018-07-27T22:56:03.055Z,1532732163.055 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T22:56:03.056Z,1532732163.056 [Default:CheckIn:D] Running Loop=1 2018-07-27T22:56:03.451Z,1532732163.451 [Default:CheckIn:D] Stopped 2018-07-27T22:56:03.451Z,1532732163.451 [Default:CheckIn:E] Running Loop=1 2018-07-27T22:56:03.852Z,1532732163.852 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 171.521631 min 2018-07-27T22:56:03.853Z,1532732163.853 [Default:CheckIn:E] Stopped 2018-07-27T22:56:03.853Z,1532732163.853 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T22:56:03.853Z,1532732163.853 [Default:CheckIn] Stopped 2018-07-27T22:56:03.853Z,1532732163.853 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T22:56:03.853Z,1532732163.853 [Default:CheckIn](INFO): Running loop #18 2018-07-27T22:56:03.854Z,1532732163.854 [Default:CheckIn] Running Loop=18 2018-07-27T22:56:03.854Z,1532732163.854 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T22:56:03.854Z,1532732163.854 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T22:56:07.495Z,1532732167.495 [NAL9602](INFO): Powering up 2018-07-27T22:56:18.426Z,1532732178.426 [NAL9602](INFO): NAL9602 initialized 2018-07-27T22:56:19.226Z,1532732179.226 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T22:56:19.227Z,1532732179.227 [NAL9602] Data Fault, FailCount= 3 2018-07-27T22:56:19.227Z,1532732179.227 [NAL9602](ERROR): Data Fault 2018-07-27T22:56:19.295Z,1532732179.295 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T22:56:19.626Z,1532732179.626 [NAL9602](INFO): Powering down 2018-07-27T22:56:20.487Z,1532732180.487 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T22:56:20.487Z,1532732180.487 [NAL9602] No Fault, FailCount= 3 2018-07-27T22:56:49.635Z,1532732209.635 [NAL9602](INFO): Powering up NAL9602 2018-07-27T22:57:00.830Z,1532732220.830 [NAL9602](INFO): NAL9602 initialized 2018-07-27T23:01:03.951Z,1532732463.951 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-27T22:56:03.9Z 2018-07-27T23:01:03.951Z,1532732463.951 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T23:01:03.951Z,1532732463.951 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-27T23:01:07.604Z,1532732467.604 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180727T201331/Courier0051.lzma 2018-07-27T23:01:08.380Z,1532732468.380 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Courier0051.lzma.bak 2018-07-27T23:01:08.380Z,1532732468.380 [DataOverHttps](INFO): SBD MOMSN=8381675 2018-07-27T23:01:13.857Z,1532732473.857 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2018-07-27T23:01:13.858Z,1532732473.858 [DropWeight] Hardware Fault, FailCount= 1 2018-07-27T23:01:13.858Z,1532732473.858 [DropWeight](ERROR): Hardware Fault 2018-07-27T23:01:13.970Z,1532732473.970 [CBIT](INFO): Critical error at 20180727T230113 2018-07-27T23:01:13.977Z,1532732473.977 [CBIT](ERROR): Hardware Fault in component: DropWeight 2018-07-27T23:01:13.977Z,1532732473.977 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2018-07-27T23:01:14.339Z,1532732474.339 [CBIT](INFO): Critical error at 20180727T230113 2018-07-27T23:01:18.365Z,1532732478.365 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20180727T201331/Express0052.lzma 2018-07-27T23:01:19.124Z,1532732479.124 [DataOverHttps](INFO): Moved sent file to Logs/20180727T201331/Express0052.lzma.bak 2018-07-27T23:01:19.128Z,1532732479.128 [DataOverHttps](INFO): SBD MOMSN=8381677 2018-07-27T23:01:19.602Z,1532732479.602 [Default:CheckIn:Read_Iridium] Stopped 2018-07-27T23:01:19.602Z,1532732479.602 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-27T23:01:19.602Z,1532732479.602 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-27T23:02:07.253Z,1532732527.253 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-07-27T23:02:37.774Z,1532732557.774 [NAL9602](INFO): Powering down 2018-07-27T23:06:20.173Z,1532732780.173 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-27T23:06:20.173Z,1532732780.173 [Default:CheckIn:C.Wait] Stopped 2018-07-27T23:06:20.173Z,1532732780.173 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-27T23:06:20.174Z,1532732780.174 [Default:CheckIn:D] Running Loop=1 2018-07-27T23:06:20.573Z,1532732780.573 [Default:CheckIn:D] Stopped 2018-07-27T23:06:20.573Z,1532732780.573 [Default:CheckIn:E] Running Loop=1 2018-07-27T23:06:23.925Z,1532732783.925 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 181.806982 min 2018-07-27T23:06:23.925Z,1532732783.925 [Default:CheckIn:E] Stopped 2018-07-27T23:06:23.925Z,1532732783.925 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-27T23:06:23.925Z,1532732783.925 [Default:CheckIn] Stopped 2018-07-27T23:06:23.925Z,1532732783.925 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T23:06:23.926Z,1532732783.926 [Default:CheckIn](INFO): Running loop #19 2018-07-27T23:06:23.926Z,1532732783.926 [Default:CheckIn] Running Loop=19 2018-07-27T23:06:23.926Z,1532732783.926 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-27T23:06:23.926Z,1532732783.926 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-27T23:06:24.370Z,1532732784.370 [NAL9602](INFO): Powering up 2018-07-27T23:06:35.570Z,1532732795.570 [NAL9602](INFO): NAL9602 initialized 2018-07-27T23:07:07.558Z,1532732827.558 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2018-07-27T23:07:07.633Z,1532732827.633 [NAL9602](FAULT): received: +CSQ:0 OK2, 2, 0, 0, 0 OK 2018-07-27T23:07:07.633Z,1532732827.633 [NAL9602] Data Fault, FailCount= 4 2018-07-27T23:07:07.633Z,1532732827.633 [NAL9602](ERROR): Data Fault 2018-07-27T23:07:07.698Z,1532732827.698 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T23:07:07.958Z,1532732827.958 [NAL9602](INFO): Powering down 2018-07-27T23:07:08.830Z,1532732828.830 [CBIT](INFO): Clearing failed state for component NAL9602 2018-07-27T23:07:08.830Z,1532732828.830 [NAL9602] No Fault, FailCount= 4 2018-07-27T23:07:38.226Z,1532732858.226 [NAL9602](INFO): Powering up NAL9602 2018-07-27T23:07:49.040Z,1532732869.040 [NAL9602](INFO): NAL9602 initialized 2018-07-27T23:07:49.838Z,1532732869.838 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-07-27T23:07:49.838Z,1532732869.838 [NAL9602] Data Fault, FailCount= 5 2018-07-27T23:07:49.838Z,1532732869.838 [NAL9602](ERROR): Data Fault 2018-07-27T23:07:49.930Z,1532732869.930 [CBIT](ERROR): Data Fault in component: NAL9602 2018-07-27T23:07:49.931Z,1532732869.931 [CBIT](CRITICAL): Data Fault in component: NAL9602 2018-07-27T23:07:50.226Z,1532732870.226 [NAL9602](INFO): Powering down 2018-07-27T23:07:50.300Z,1532732870.300 [CBIT](INFO): Critical error at 20180727T230749 2018-07-27T23:09:15.818Z,1532732955.818 [CommandLine](IMPORTANT): got command quit 2018-07-27T23:09:16.828Z,1532732956.828 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2018-07-27T23:09:16.828Z,1532732956.828 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:16.925Z,1532732956.925 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2018-07-27T23:09:16.925Z,1532732956.925 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:16.926Z,1532732956.926 [CommandLine](INFO): Join timeout helper Thread ID is 1443 2018-07-27T23:09:16.926Z,1532732956.926 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2018-07-27T23:09:16.926Z,1532732956.926 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:16.927Z,1532732956.927 [NavChartDb](INFO): Join timeout helper Thread ID is 1444 2018-07-27T23:09:17.086Z,1532732957.086 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2018-07-27T23:09:17.086Z,1532732957.086 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.105Z,1532732957.105 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2018-07-27T23:09:17.105Z,1532732957.105 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.105Z,1532732957.105 [Radio_Surface](INFO): Join timeout helper Thread ID is 1445 2018-07-27T23:09:17.137Z,1532732957.137 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2018-07-27T23:09:17.138Z,1532732957.138 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.147Z,1532732957.147 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2018-07-27T23:09:17.147Z,1532732957.147 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.147Z,1532732957.147 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1446 2018-07-27T23:09:17.397Z,1532732957.397 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2018-07-27T23:09:17.397Z,1532732957.397 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.405Z,1532732957.405 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2018-07-27T23:09:17.405Z,1532732957.405 [logger ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.405Z,1532732957.405 [logger](INFO): Join timeout helper Thread ID is 1447 2018-07-27T23:09:17.433Z,1532732957.433 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2018-07-27T23:09:17.433Z,1532732957.433 [logger ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.446Z,1532732957.446 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2018-07-27T23:09:17.446Z,1532732957.446 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.446Z,1532732957.446 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2018-07-27T23:09:17.446Z,1532732957.446 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.446Z,1532732957.446 [controlThread](INFO): Join timeout helper Thread ID is 1448 2018-07-27T23:09:17.505Z,1532732957.505 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2018-07-27T23:09:17.505Z,1532732957.505 [controlThread](DEBUG): Uninitializing ControlThread 2018-07-27T23:09:17.506Z,1532732957.506 [Aanderaa_O2](INFO): Powering down 2018-07-27T23:09:17.507Z,1532732957.507 [AHRS_M2](INFO): Powering down 2018-07-27T23:09:17.578Z,1532732957.578 [NAL9602](INFO): Powering down 2018-07-27T23:09:17.649Z,1532732957.649 [RDI_Pathfinder](INFO): Powering down 2018-07-27T23:09:17.650Z,1532732957.650 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-07-27T23:09:17.652Z,1532732957.652 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2018-07-27T23:09:17.652Z,1532732957.652 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2018-07-27T23:09:17.653Z,1532732957.653 [MissionManager](INFO): Uninitializing Mission Default 2018-07-27T23:09:17.653Z,1532732957.653 [Default] Stopped 2018-07-27T23:09:17.653Z,1532732957.653 [Default](DEBUG): Aggregate::uninitialize Default 2018-07-27T23:09:17.653Z,1532732957.653 [Default:B.GoToSurface] Stopped 2018-07-27T23:09:17.654Z,1532732957.654 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-07-27T23:09:17.654Z,1532732957.654 [Default:CheckIn] Stopped 2018-07-27T23:09:17.654Z,1532732957.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-27T23:09:17.654Z,1532732957.654 [Default:CheckIn:Read_GPS] Stopped 2018-07-27T23:09:17.657Z,1532732957.657 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2018-07-27T23:09:17.658Z,1532732957.658 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2018-07-27T23:09:17.658Z,1532732957.658 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2018-07-27T23:09:17.658Z,1532732957.658 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2018-07-27T23:09:17.659Z,1532732957.659 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-07-27T23:09:17.659Z,1532732957.659 [BuoyancyServo](INFO): Powering down 2018-07-27T23:09:17.673Z,1532732957.673 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2018-07-27T23:09:17.673Z,1532732957.673 [ElevatorServo](INFO): Powering down 2018-07-27T23:09:17.674Z,1532732957.674 [MassServo](DEBUG): Uninitialize Mass Servo. 2018-07-27T23:09:17.674Z,1532732957.674 [MassServo](INFO): Powering down 2018-07-27T23:09:17.675Z,1532732957.675 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2018-07-27T23:09:17.675Z,1532732957.675 [RudderServo](INFO): Powering down 2018-07-27T23:09:17.676Z,1532732957.676 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2018-07-27T23:09:17.676Z,1532732957.676 [ThrusterServo](INFO): Powering down 2018-07-27T23:09:17.677Z,1532732957.677 [SBIT](DEBUG): Uninitialize SBIT Component. 2018-07-27T23:09:17.677Z,1532732957.677 [IBIT](DEBUG): Uninitialize IBIT Component. 2018-07-27T23:09:17.678Z,1532732957.678 [CBIT](DEBUG): Uninitialize CBIT Component. 2018-07-27T23:09:17.679Z,1532732957.679 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.732Z,1532732957.732 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.790Z,1532732957.790 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.832Z,1532732957.832 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-07-27T23:09:17.900Z,1532732957.900 [logger ThreadHandler](INFO): Thread cancelled.