2019-08-06T23:59:44.353Z,1565135984.353 [CommandLine](IMPORTANT): got command restart logs 2019-08-07T00:02:57.592Z,1565136177.592 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-07T00:02:57.592Z,1565136177.592 [Default:CheckIn:C.Wait] Stopped 2019-08-07T00:02:57.592Z,1565136177.592 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-07T00:02:57.592Z,1565136177.592 [Default:CheckIn:D] Running Loop=1 2019-08-07T00:02:58.009Z,1565136178.009 [Default:CheckIn:D] Stopped 2019-08-07T00:02:58.009Z,1565136178.009 [Default:CheckIn:E] Running Loop=1 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.656588 min 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn:E] Stopped 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn] Stopped 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn](INFO): Running loop #2 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn] Running Loop=2 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-07T00:02:58.414Z,1565136178.414 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-07T00:03:00.021Z,1565136180.021 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:03:00.406Z,1565136180.406 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000150.00,A,3648.16418,N,12147.28350,W,0.428,337.28,070819,,,A*72 2019-08-07T00:03:00.408Z,1565136180.408 [NAL9602](INFO): GPS fix at 20190807T000150: (36.802736, -121.788058) 2019-08-07T00:03:00.433Z,1565136180.433 [Default:CheckIn:Read_GPS] Stopped 2019-08-07T00:03:00.433Z,1565136180.433 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-07T00:03:07.784Z,1565136187.784 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T225425/Courier0028.lzma 2019-08-07T00:03:08.590Z,1565136188.590 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Courier0028.lzma.bak 2019-08-07T00:03:08.591Z,1565136188.591 [DataOverHttps](INFO): SBD MOMSN=11530401 2019-08-07T00:03:20.796Z,1565136200.796 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20190806T235944/Courier0000.lzma 2019-08-07T00:03:21.602Z,1565136201.602 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Courier0000.lzma.bak 2019-08-07T00:03:21.602Z,1565136201.602 [DataOverHttps](INFO): SBD MOMSN=11530403 2019-08-07T00:03:31.110Z,1565136211.110 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-07T00:03:31.205Z,1565136211.205 [NAL9602](FAULT): received: +CSQ:0 OK852, 2, 0, 0, 0 OK 2019-08-07T00:03:31.205Z,1565136211.205 [NAL9602] Data Fault, FailCount= 3 2019-08-07T00:03:31.206Z,1565136211.206 [NAL9602](ERROR): Data Fault 2019-08-07T00:03:31.339Z,1565136211.339 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-07T00:03:31.518Z,1565136211.518 [NAL9602](INFO): Powering down 2019-08-07T00:03:32.479Z,1565136212.479 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-07T00:03:32.479Z,1565136212.479 [NAL9602] No Fault, FailCount= 3 2019-08-07T00:03:36.664Z,1565136216.664 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190806T235944/Courier0003.lzma 2019-08-07T00:03:37.470Z,1565136217.470 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Courier0003.lzma.bak 2019-08-07T00:03:37.470Z,1565136217.470 [DataOverHttps](INFO): SBD MOMSN=11530407 2019-08-07T00:03:49.912Z,1565136229.912 [DataOverHttps](INFO): Sending 95 bytes from file Logs/20190806T225425/Express0029.lzma 2019-08-07T00:03:50.718Z,1565136230.718 [DataOverHttps](INFO): Moved sent file to Logs/20190806T225425/Express0029.lzma.bak 2019-08-07T00:03:50.718Z,1565136230.718 [DataOverHttps](INFO): SBD MOMSN=11530409 2019-08-07T00:04:01.830Z,1565136241.830 [NAL9602](INFO): Powering up NAL9602 2019-08-07T00:04:03.385Z,1565136243.385 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20190806T235944/Express0001.lzma 2019-08-07T00:04:04.190Z,1565136244.190 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Express0001.lzma.bak 2019-08-07T00:04:04.190Z,1565136244.190 [DataOverHttps](INFO): SBD MOMSN=11530412 2019-08-07T00:04:12.742Z,1565136252.742 [NAL9602](INFO): NAL9602 initialized 2019-08-07T00:04:16.956Z,1565136256.956 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190806T235944/Express0005.lzma 2019-08-07T00:04:17.762Z,1565136257.762 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Express0005.lzma.bak 2019-08-07T00:04:17.762Z,1565136257.762 [DataOverHttps](INFO): SBD MOMSN=11530416 2019-08-07T00:04:19.659Z,1565136259.659 [Default:CheckIn:Read_Iridium] Stopped 2019-08-07T00:04:19.659Z,1565136259.659 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-07T00:04:19.659Z,1565136259.659 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-07T00:04:43.862Z,1565136283.862 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-07T00:07:27.478Z,1565136447.478 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-08-07T00:07:58.182Z,1565136478.182 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-08-07T00:08:28.885Z,1565136508.885 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-08-07T00:08:28.893Z,1565136508.893 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-08-07T00:08:28.896Z,1565136508.896 [BPC1](INFO): Received data from all battery sticks. 2019-08-07T00:08:59.590Z,1565136539.590 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-08-07T00:09:20.203Z,1565136560.203 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-07T00:09:20.203Z,1565136560.203 [Default:CheckIn:C.Wait] Stopped 2019-08-07T00:09:20.203Z,1565136560.203 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-07T00:09:20.204Z,1565136560.204 [Default:CheckIn:D] Running Loop=1 2019-08-07T00:09:20.608Z,1565136560.608 [Default:CheckIn:D] Stopped 2019-08-07T00:09:20.608Z,1565136560.608 [Default:CheckIn:E] Running Loop=1 2019-08-07T00:09:21.021Z,1565136561.021 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.033243 min 2019-08-07T00:09:21.021Z,1565136561.021 [Default:CheckIn:E] Stopped 2019-08-07T00:09:21.021Z,1565136561.021 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-07T00:09:21.021Z,1565136561.021 [Default:CheckIn] Stopped 2019-08-07T00:09:21.021Z,1565136561.021 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-07T00:09:21.022Z,1565136561.022 [Default:CheckIn](INFO): Running loop #3 2019-08-07T00:09:21.022Z,1565136561.022 [Default:CheckIn] Running Loop=3 2019-08-07T00:09:21.022Z,1565136561.022 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-07T00:09:21.022Z,1565136561.022 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-07T00:09:22.621Z,1565136562.621 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:25.045Z,1565136565.045 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-07T00:09:25.858Z,1565136565.858 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:28.681Z,1565136568.681 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:30.293Z,1565136570.293 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-08-07T00:09:31.509Z,1565136571.509 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:32.718Z,1565136572.718 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.184113 2019-08-07T00:09:34.737Z,1565136574.737 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:37.565Z,1565136577.565 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:40.401Z,1565136580.401 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:43.229Z,1565136583.229 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:46.461Z,1565136586.461 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:49.289Z,1565136589.289 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:52.529Z,1565136592.529 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:55.349Z,1565136595.349 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:09:58.589Z,1565136598.589 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:01.409Z,1565136601.409 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:04.641Z,1565136604.641 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:07.469Z,1565136607.469 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:07.692Z,1565136607.692 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002817 2019-08-07T00:10:10.705Z,1565136610.705 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:13.529Z,1565136613.529 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:16.769Z,1565136616.769 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:19.589Z,1565136619.589 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:22.421Z,1565136622.421 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:25.653Z,1565136625.653 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:28.477Z,1565136628.477 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:31.305Z,1565136631.305 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:34.549Z,1565136634.549 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:37.369Z,1565136637.369 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:40.601Z,1565136640.601 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:43.429Z,1565136643.429 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:46.661Z,1565136646.661 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:49.489Z,1565136649.489 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:52.720Z,1565136652.720 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:55.557Z,1565136655.557 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:10:58.777Z,1565136658.777 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:01.605Z,1565136661.605 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:04.837Z,1565136664.837 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:07.665Z,1565136667.665 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:10.901Z,1565136670.901 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:13.725Z,1565136673.725 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:16.553Z,1565136676.553 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:19.385Z,1565136679.385 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:22.613Z,1565136682.613 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:25.445Z,1565136685.445 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:28.685Z,1565136688.685 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:31.501Z,1565136691.501 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:34.757Z,1565136694.757 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:37.617Z,1565136697.617 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:40.857Z,1565136700.857 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:43.677Z,1565136703.677 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:46.909Z,1565136706.909 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:49.737Z,1565136709.737 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:52.973Z,1565136712.973 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:55.797Z,1565136715.797 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:11:58.629Z,1565136718.629 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:12:01.865Z,1565136721.865 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:12:04.685Z,1565136724.685 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:12:07.917Z,1565136727.917 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:12:08.318Z,1565136728.318 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001057.00,A,3648.16475,N,12147.28394,W,1.108,52.42,070819,,,A*4C 2019-08-07T00:12:08.320Z,1565136728.320 [NAL9602](INFO): GPS fix at 20190807T001057: (36.802746, -121.788066) 2019-08-07T00:12:08.349Z,1565136728.349 [Default:CheckIn:Read_GPS] Stopped 2019-08-07T00:12:08.349Z,1565136728.349 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-07T00:12:14.736Z,1565136734.736 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T235944/Courier0004.lzma 2019-08-07T00:12:15.542Z,1565136735.542 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Courier0004.lzma.bak 2019-08-07T00:12:15.542Z,1565136735.542 [DataOverHttps](INFO): SBD MOMSN=11530452 2019-08-07T00:12:27.912Z,1565136747.912 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T235944/Express0006.lzma 2019-08-07T00:12:28.718Z,1565136748.718 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Express0006.lzma.bak 2019-08-07T00:12:28.718Z,1565136748.718 [DataOverHttps](INFO): SBD MOMSN=11530454 2019-08-07T00:12:30.580Z,1565136750.580 [Default:CheckIn:Read_Iridium] Stopped 2019-08-07T00:12:30.580Z,1565136750.580 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-07T00:12:30.580Z,1565136750.580 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-07T00:12:40.630Z,1565136760.630 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-07T00:17:31.166Z,1565137051.166 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-07T00:17:31.166Z,1565137051.166 [Default:CheckIn:C.Wait] Stopped 2019-08-07T00:17:31.166Z,1565137051.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-07T00:17:31.167Z,1565137051.167 [Default:CheckIn:D] Running Loop=1 2019-08-07T00:17:31.571Z,1565137051.571 [Default:CheckIn:D] Stopped 2019-08-07T00:17:31.571Z,1565137051.571 [Default:CheckIn:E] Running Loop=1 2019-08-07T00:17:31.985Z,1565137051.985 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.215953 min 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn:E] Stopped 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn] Stopped 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn](INFO): Running loop #4 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn] Running Loop=4 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-07T00:17:31.986Z,1565137051.986 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-07T00:17:33.581Z,1565137053.581 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:17:33.980Z,1565137053.980 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001623.00,A,3648.16260,N,12147.27730,W,0.350,52.42,070819,,,A*40 2019-08-07T00:17:33.982Z,1565137053.982 [NAL9602](INFO): GPS fix at 20190807T001623: (36.802710, -121.787955) 2019-08-07T00:17:34.013Z,1565137054.013 [Default:CheckIn:Read_GPS] Stopped 2019-08-07T00:17:34.013Z,1565137054.013 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-07T00:17:39.984Z,1565137059.984 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190806T235944/Courier0009.lzma 2019-08-07T00:17:40.790Z,1565137060.790 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Courier0009.lzma.bak 2019-08-07T00:17:40.791Z,1565137060.791 [DataOverHttps](INFO): SBD MOMSN=11530493 2019-08-07T00:17:53.064Z,1565137073.064 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20190806T235944/Express0010.lzma 2019-08-07T00:17:53.871Z,1565137073.871 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Express0010.lzma.bak 2019-08-07T00:17:53.871Z,1565137073.871 [DataOverHttps](INFO): SBD MOMSN=11530496 2019-08-07T00:17:55.456Z,1565137075.456 [Default:CheckIn:Read_Iridium] Stopped 2019-08-07T00:17:55.456Z,1565137075.456 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-07T00:17:55.456Z,1565137075.456 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-07T00:21:08.107Z,1565137268.107 [NAL9602](INFO): SBD MO Status=2, MOMSN=15852, MT Status=2, MTMSN=0 2019-08-07T00:21:08.107Z,1565137268.107 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-08-07T00:22:18.003Z,1565137338.003 [NAL9602](INFO): SBD MO Status=2, MOMSN=15852, MT Status=2, MTMSN=0 2019-08-07T00:22:18.003Z,1565137338.003 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-08-07T00:22:36.178Z,1565137356.178 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-07T00:22:56.011Z,1565137376.011 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-07T00:22:56.011Z,1565137376.011 [Default:CheckIn:C.Wait] Stopped 2019-08-07T00:22:56.011Z,1565137376.011 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-07T00:22:56.012Z,1565137376.012 [Default:CheckIn:D] Running Loop=1 2019-08-07T00:22:56.399Z,1565137376.399 [Default:CheckIn:D] Stopped 2019-08-07T00:22:56.399Z,1565137376.399 [Default:CheckIn:E] Running Loop=1 2019-08-07T00:22:56.810Z,1565137376.810 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.629761 min 2019-08-07T00:22:56.810Z,1565137376.810 [Default:CheckIn:E] Stopped 2019-08-07T00:22:56.810Z,1565137376.810 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-07T00:22:56.810Z,1565137376.810 [Default:CheckIn] Stopped 2019-08-07T00:22:56.810Z,1565137376.810 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-07T00:22:56.810Z,1565137376.810 [Default:CheckIn](INFO): Running loop #5 2019-08-07T00:22:56.811Z,1565137376.811 [Default:CheckIn] Running Loop=5 2019-08-07T00:22:56.811Z,1565137376.811 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-07T00:22:56.811Z,1565137376.811 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-07T00:22:58.409Z,1565137378.409 [NAL9602](DEBUG): Fix Requested 2019-08-07T00:22:58.803Z,1565137378.803 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002147.00,A,3648.16288,N,12147.28514,W,0.311,52.42,070819,,,A*4E 2019-08-07T00:22:58.805Z,1565137378.805 [NAL9602](INFO): GPS fix at 20190807T002147: (36.802715, -121.788086) 2019-08-07T00:22:58.830Z,1565137378.830 [Default:CheckIn:Read_GPS] Stopped 2019-08-07T00:22:58.830Z,1565137378.830 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-07T00:23:05.116Z,1565137385.116 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190806T235944/Courier0012.lzma 2019-08-07T00:23:05.922Z,1565137385.922 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Courier0012.lzma.bak 2019-08-07T00:23:05.922Z,1565137385.922 [DataOverHttps](INFO): SBD MOMSN=11530499 2019-08-07T00:23:18.540Z,1565137398.540 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20190806T235944/Express0013.lzma 2019-08-07T00:23:19.346Z,1565137399.346 [DataOverHttps](INFO): Moved sent file to Logs/20190806T235944/Express0013.lzma.bak 2019-08-07T00:23:19.346Z,1565137399.346 [DataOverHttps](INFO): SBD MOMSN=11530502 2019-08-07T00:23:21.096Z,1565137401.096 [Default:CheckIn:Read_Iridium] Stopped 2019-08-07T00:23:21.096Z,1565137401.096 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-07T00:23:21.096Z,1565137401.096 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-07T00:23:30.718Z,1565137410.718 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-07T00:26:10.942Z,1565137570.942 [CommandLine](IMPORTANT): got command restart system 2019-08-07T00:26:13.090Z,1565137573.090 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:13.090Z,1565137573.090 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:13.177Z,1565137573.177 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-08-07T00:26:13.178Z,1565137573.178 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:13.178Z,1565137573.178 [CommandLine](INFO): Join timeout helper Thread ID is 1195 2019-08-07T00:26:13.179Z,1565137573.179 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-08-07T00:26:13.179Z,1565137573.179 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:13.180Z,1565137573.180 [NavChartDb](INFO): Join timeout helper Thread ID is 1196 2019-08-07T00:26:13.301Z,1565137573.301 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:13.301Z,1565137573.301 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:13.305Z,1565137573.305 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-08-07T00:26:13.305Z,1565137573.305 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:13.305Z,1565137573.305 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1197 2019-08-07T00:26:13.697Z,1565137573.697 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:13.698Z,1565137573.698 [WetLabsBB2FL](INFO): Powering down 2019-08-07T00:26:13.699Z,1565137573.699 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:13.713Z,1565137573.713 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-08-07T00:26:13.713Z,1565137573.713 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:13.714Z,1565137573.714 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1198 2019-08-07T00:26:14.281Z,1565137574.281 [CTD_Seabird](INFO): Powering down 2019-08-07T00:26:14.293Z,1565137574.293 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:14.293Z,1565137574.293 [CTD_Seabird](INFO): Powering down 2019-08-07T00:26:14.305Z,1565137574.305 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.325Z,1565137574.325 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-08-07T00:26:14.325Z,1565137574.325 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.326Z,1565137574.326 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1199 2019-08-07T00:26:14.381Z,1565137574.381 [CTD_NeilBrown](INFO): Powering down 2019-08-07T00:26:14.393Z,1565137574.393 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:14.393Z,1565137574.393 [CTD_NeilBrown](INFO): Powering down 2019-08-07T00:26:14.405Z,1565137574.405 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.407Z,1565137574.407 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-08-07T00:26:14.407Z,1565137574.407 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.407Z,1565137574.407 [Radio_Surface](INFO): Join timeout helper Thread ID is 1200 2019-08-07T00:26:14.569Z,1565137574.569 [Radio_Surface](INFO): Powering down 2019-08-07T00:26:14.570Z,1565137574.570 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:14.571Z,1565137574.571 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.587Z,1565137574.587 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-08-07T00:26:14.587Z,1565137574.587 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.587Z,1565137574.587 [DataOverHttps](INFO): Join timeout helper Thread ID is 1201 2019-08-07T00:26:14.609Z,1565137574.609 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:14.610Z,1565137574.610 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.618Z,1565137574.618 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-08-07T00:26:14.618Z,1565137574.618 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.618Z,1565137574.618 [logger](INFO): Join timeout helper Thread ID is 1202 2019-08-07T00:26:14.645Z,1565137574.645 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:14.645Z,1565137574.645 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.658Z,1565137574.658 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-08-07T00:26:14.658Z,1565137574.658 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.658Z,1565137574.658 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-08-07T00:26:14.658Z,1565137574.658 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:14.659Z,1565137574.659 [controlThread](INFO): Join timeout helper Thread ID is 1203 2019-08-07T00:26:14.734Z,1565137574.734 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-07T00:26:14.734Z,1565137574.734 [controlThread](DEBUG): Uninitializing ControlThread 2019-08-07T00:26:14.735Z,1565137574.735 [AHRS_M2](INFO): Powering down 2019-08-07T00:26:14.806Z,1565137574.806 [NAL9602](INFO): Powering down 2019-08-07T00:26:14.808Z,1565137574.808 [Aanderaa_O2](INFO): Powering down 2019-08-07T00:26:14.810Z,1565137574.810 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-08-07T00:26:14.811Z,1565137574.811 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-08-07T00:26:14.812Z,1565137574.812 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-08-07T00:26:14.813Z,1565137574.813 [MissionManager](INFO): Uninitializing Mission Default 2019-08-07T00:26:14.813Z,1565137574.813 [Default] Stopped 2019-08-07T00:26:14.813Z,1565137574.813 [Default](DEBUG): Aggregate::uninitialize Default 2019-08-07T00:26:14.813Z,1565137574.813 [Default:B.GoToSurface] Stopped 2019-08-07T00:26:14.813Z,1565137574.813 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-07T00:26:14.813Z,1565137574.813 [Default:CheckIn] Stopped 2019-08-07T00:26:14.813Z,1565137574.813 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-07T00:26:14.813Z,1565137574.813 [Default:CheckIn:C.Wait] Stopped 2019-08-07T00:26:14.814Z,1565137574.814 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-07T00:26:14.816Z,1565137574.816 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-08-07T00:26:14.817Z,1565137574.817 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-08-07T00:26:14.817Z,1565137574.817 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-08-07T00:26:14.817Z,1565137574.817 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-08-07T00:26:14.818Z,1565137574.818 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-08-07T00:26:14.818Z,1565137574.819 [BuoyancyServo](INFO): Powering down 2019-08-07T00:26:14.834Z,1565137574.834 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-08-07T00:26:14.834Z,1565137574.834 [ElevatorServo](INFO): Powering down 2019-08-07T00:26:14.835Z,1565137574.835 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-08-07T00:26:14.835Z,1565137574.835 [MassServo](INFO): Powering down 2019-08-07T00:26:14.836Z,1565137574.836 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-07T00:26:14.836Z,1565137574.836 [RudderServo](INFO): Powering down 2019-08-07T00:26:14.837Z,1565137574.837 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-08-07T00:26:14.837Z,1565137574.837 [ThrusterServo](INFO): Powering down 2019-08-07T00:26:14.838Z,1565137574.838 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-08-07T00:26:14.838Z,1565137574.838 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-08-07T00:26:14.838Z,1565137574.838 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-08-07T00:26:14.838Z,1565137574.838 [CBIT](DEBUG): Powering off loads. 2019-08-07T00:26:14.854Z,1565137574.854 [CBIT](DEBUG): Disabling WDT. 2019-08-07T00:26:14.865Z,1565137574.865 [CBIT](DEBUG): Opening all GF detection circuits. 2019-08-07T00:26:14.871Z,1565137574.871 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:15.070Z,1565137575.070 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:15.084Z,1565137575.084 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:15.194Z,1565137575.194 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:15.197Z,1565137575.197 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:15.209Z,1565137575.209 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:15.327Z,1565137575.327 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-07T00:26:15.467Z,1565137575.467 [logger ThreadHandler](INFO): Thread cancelled.