2019-07-24T23:23:10.397Z,1564010590.397 [DataOverHttps](INFO): Received command:restart logs 2019-07-24T23:23:10.431Z,1564010590.431 [CommandLine](IMPORTANT): got command restart logs 2019-07-24T23:23:38.497Z,1564010618.497 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-24T23:25:04.539Z,1564010704.539 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-24T23:25:04.539Z,1564010704.539 [DVL_micro] Data Fault, FailCount= 1 2019-07-24T23:25:04.539Z,1564010704.539 [DVL_micro](ERROR): Data Fault 2019-07-24T23:25:04.572Z,1564010704.572 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-24T23:25:05.018Z,1564010705.018 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:25:05.791Z,1564010705.791 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:25:05.791Z,1564010705.791 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:25:06.161Z,1564010706.161 [DVL_micro](INFO): Initializing 2019-07-24T23:28:00.318Z,1564010880.318 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-24T23:28:00.318Z,1564010880.318 [Default:CheckIn:C.Wait] Stopped 2019-07-24T23:28:00.318Z,1564010880.318 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-24T23:28:00.318Z,1564010880.318 [Default:CheckIn:D] Running Loop=1 2019-07-24T23:28:00.745Z,1564010880.745 [Default:CheckIn:D] Stopped 2019-07-24T23:28:00.745Z,1564010880.745 [Default:CheckIn:E] Running Loop=1 2019-07-24T23:28:01.150Z,1564010881.150 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.346780 min 2019-07-24T23:28:01.150Z,1564010881.150 [Default:CheckIn:E] Stopped 2019-07-24T23:28:01.150Z,1564010881.150 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-24T23:28:01.150Z,1564010881.150 [Default:CheckIn] Stopped 2019-07-24T23:28:01.150Z,1564010881.150 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-24T23:28:01.150Z,1564010881.150 [Default:CheckIn](INFO): Running loop #2 2019-07-24T23:28:01.151Z,1564010881.151 [Default:CheckIn] Running Loop=2 2019-07-24T23:28:01.151Z,1564010881.151 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-24T23:28:01.151Z,1564010881.151 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-24T23:28:02.710Z,1564010882.710 [NAL9602](DEBUG): Fix Requested 2019-07-24T23:28:03.112Z,1564010883.112 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232751.00,A,3648.23771,N,12147.15625,W,4.335,199.31,240719,,,D*7F 2019-07-24T23:28:03.118Z,1564010883.118 [NAL9602](INFO): GPS fix at 20190724T232751: (36.803962, -121.785938) 2019-07-24T23:28:03.149Z,1564010883.149 [Default:CheckIn:Read_GPS] Stopped 2019-07-24T23:28:03.149Z,1564010883.149 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-24T23:28:08.577Z,1564010888.577 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T230929/Courier0018.lzma 2019-07-24T23:28:09.383Z,1564010889.383 [DataOverHttps](INFO): Moved sent file to Logs/20190724T230929/Courier0018.lzma.bak 2019-07-24T23:28:09.384Z,1564010889.384 [DataOverHttps](INFO): SBD MOMSN=11473231 2019-07-24T23:28:10.381Z,1564010890.381 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-24T23:28:10.381Z,1564010890.381 [DVL_micro] Data Fault, FailCount= 1 2019-07-24T23:28:10.381Z,1564010890.381 [DVL_micro](ERROR): Data Fault 2019-07-24T23:28:10.415Z,1564010890.415 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-24T23:28:10.866Z,1564010890.866 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:28:11.605Z,1564010891.605 [NAL9602](INFO): SBD MO Status=0, MOMSN=30025, MT Status=0, MTMSN=0 2019-07-24T23:28:11.605Z,1564010891.605 [NAL9602](INFO): No messages in MT queue 2019-07-24T23:28:11.659Z,1564010891.659 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:28:11.659Z,1564010891.659 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:28:12.021Z,1564010892.021 [DVL_micro](INFO): Initializing 2019-07-24T23:28:20.850Z,1564010900.850 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190724T232310/Courier0000.lzma 2019-07-24T23:28:21.655Z,1564010901.655 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Courier0000.lzma.bak 2019-07-24T23:28:21.655Z,1564010901.655 [DataOverHttps](INFO): SBD MOMSN=11473233 2019-07-24T23:28:32.953Z,1564010912.953 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190724T232310/Courier0003.lzma 2019-07-24T23:28:33.759Z,1564010913.759 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Courier0003.lzma.bak 2019-07-24T23:28:33.759Z,1564010913.759 [DataOverHttps](INFO): SBD MOMSN=11473237 2019-07-24T23:28:42.319Z,1564010922.319 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-24T23:28:45.423Z,1564010925.423 [DataOverHttps](INFO): Sending 301 bytes from file Logs/20190724T230929/Express0019.lzma 2019-07-24T23:28:46.227Z,1564010926.227 [DataOverHttps](INFO): Moved sent file to Logs/20190724T230929/Express0019.lzma.bak 2019-07-24T23:28:46.228Z,1564010926.228 [DataOverHttps](INFO): SBD MOMSN=11473239 2019-07-24T23:28:59.342Z,1564010939.342 [DataOverHttps](INFO): Sending 407 bytes from file Logs/20190724T232310/Express0001.lzma 2019-07-24T23:29:00.147Z,1564010940.147 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Express0001.lzma.bak 2019-07-24T23:29:00.148Z,1564010940.148 [DataOverHttps](INFO): SBD MOMSN=11473247 2019-07-24T23:29:11.597Z,1564010951.597 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T232310/Express0005.lzma 2019-07-24T23:29:12.403Z,1564010952.403 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Express0005.lzma.bak 2019-07-24T23:29:12.403Z,1564010952.404 [DataOverHttps](INFO): SBD MOMSN=11473252 2019-07-24T23:29:13.034Z,1564010953.034 [Default:CheckIn:Read_Iridium] Stopped 2019-07-24T23:29:13.035Z,1564010953.035 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-24T23:29:13.035Z,1564010953.035 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-24T23:31:16.245Z,1564011076.245 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-24T23:31:16.245Z,1564011076.245 [DVL_micro] Data Fault, FailCount= 1 2019-07-24T23:31:16.245Z,1564011076.245 [DVL_micro](ERROR): Data Fault 2019-07-24T23:31:16.303Z,1564011076.303 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-24T23:31:16.702Z,1564011076.702 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:31:17.520Z,1564011077.520 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:31:17.520Z,1564011077.520 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:31:17.849Z,1564011077.849 [DVL_micro](INFO): Initializing 2019-07-24T23:34:13.612Z,1564011253.612 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-24T23:34:13.613Z,1564011253.613 [Default:CheckIn:C.Wait] Stopped 2019-07-24T23:34:13.613Z,1564011253.613 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-24T23:34:13.613Z,1564011253.613 [Default:CheckIn:D] Running Loop=1 2019-07-24T23:34:14.025Z,1564011254.025 [Default:CheckIn:D] Stopped 2019-07-24T23:34:14.025Z,1564011254.025 [Default:CheckIn:E] Running Loop=1 2019-07-24T23:34:14.430Z,1564011254.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.568114 min 2019-07-24T23:34:14.430Z,1564011254.430 [Default:CheckIn:E] Stopped 2019-07-24T23:34:14.430Z,1564011254.430 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-24T23:34:14.431Z,1564011254.431 [Default:CheckIn] Stopped 2019-07-24T23:34:14.431Z,1564011254.431 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-24T23:34:14.431Z,1564011254.431 [Default:CheckIn](INFO): Running loop #3 2019-07-24T23:34:14.431Z,1564011254.431 [Default:CheckIn] Running Loop=3 2019-07-24T23:34:14.431Z,1564011254.431 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-24T23:34:14.431Z,1564011254.431 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-24T23:34:16.022Z,1564011256.022 [NAL9602](DEBUG): Fix Requested 2019-07-24T23:34:16.413Z,1564011256.413 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233403.00,A,3648.15151,N,12147.22218,W,0.058,276.66,240719,,,A*7C 2019-07-24T23:34:16.415Z,1564011256.415 [NAL9602](INFO): GPS fix at 20190724T233403: (36.802525, -121.787036) 2019-07-24T23:34:16.455Z,1564011256.455 [Default:CheckIn:Read_GPS] Stopped 2019-07-24T23:34:16.455Z,1564011256.455 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-24T23:34:19.863Z,1564011259.863 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T232310/Courier0004.lzma 2019-07-24T23:34:20.515Z,1564011260.515 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Courier0004.lzma.bak 2019-07-24T23:34:20.515Z,1564011260.515 [DataOverHttps](INFO): SBD MOMSN=11473264 2019-07-24T23:34:22.079Z,1564011262.079 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-24T23:34:22.079Z,1564011262.079 [DVL_micro] Data Fault, FailCount= 1 2019-07-24T23:34:22.079Z,1564011262.079 [DVL_micro](ERROR): Data Fault 2019-07-24T23:34:22.154Z,1564011262.154 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-24T23:34:22.554Z,1564011262.554 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:34:23.410Z,1564011263.410 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:34:23.410Z,1564011263.410 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:34:23.701Z,1564011263.701 [DVL_micro](INFO): Initializing 2019-07-24T23:34:31.918Z,1564011271.918 [DataOverHttps](INFO): Sending 190 bytes from file Logs/20190724T232310/Express0007.lzma 2019-07-24T23:34:32.596Z,1564011272.596 [BPC1](FAULT): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-07-24T23:34:32.597Z,1564011272.597 [BPC1](FAULT): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-07-24T23:34:32.598Z,1564011272.598 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-07-24T23:34:32.600Z,1564011272.600 [BPC1](INFO): Received data from all battery sticks. 2019-07-24T23:34:32.723Z,1564011272.723 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Express0007.lzma.bak 2019-07-24T23:34:32.724Z,1564011272.724 [DataOverHttps](INFO): SBD MOMSN=11473266 2019-07-24T23:34:33.427Z,1564011273.427 [Default:CheckIn:Read_Iridium] Stopped 2019-07-24T23:34:33.428Z,1564011273.428 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-24T23:34:33.428Z,1564011273.428 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-24T23:34:58.431Z,1564011298.431 [NAL9602](INFO): SBD MO Status=2, MOMSN=30026, MT Status=2, MTMSN=0 2019-07-24T23:34:58.431Z,1564011298.431 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-24T23:35:11.373Z,1564011311.373 [NAL9602](INFO): SBD MO Status=2, MOMSN=30026, MT Status=2, MTMSN=0 2019-07-24T23:35:11.373Z,1564011311.373 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-24T23:35:57.827Z,1564011357.827 [NAL9602](INFO): SBD MO Status=2, MOMSN=30026, MT Status=2, MTMSN=0 2019-07-24T23:35:57.827Z,1564011357.827 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-24T23:36:10.368Z,1564011370.368 [NAL9602](INFO): SBD MO Status=0, MOMSN=30026, MT Status=0, MTMSN=0 2019-07-24T23:36:10.368Z,1564011370.368 [NAL9602](INFO): No messages in MT queue 2019-07-24T23:36:41.051Z,1564011401.051 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-24T23:37:27.921Z,1564011447.921 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-24T23:37:27.921Z,1564011447.921 [DVL_micro] Data Fault, FailCount= 1 2019-07-24T23:37:27.921Z,1564011447.921 [DVL_micro](ERROR): Data Fault 2019-07-24T23:37:27.954Z,1564011447.954 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-24T23:37:28.398Z,1564011448.398 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:37:29.160Z,1564011449.160 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:37:29.160Z,1564011449.160 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:37:29.545Z,1564011449.545 [DVL_micro](INFO): Initializing 2019-07-24T23:39:33.989Z,1564011573.989 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-24T23:39:33.989Z,1564011573.989 [Default:CheckIn:C.Wait] Stopped 2019-07-24T23:39:33.989Z,1564011573.989 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-24T23:39:33.989Z,1564011573.989 [Default:CheckIn:D] Running Loop=1 2019-07-24T23:39:34.398Z,1564011574.398 [Default:CheckIn:D] Stopped 2019-07-24T23:39:34.398Z,1564011574.398 [Default:CheckIn:E] Running Loop=1 2019-07-24T23:39:34.801Z,1564011574.801 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.907654 min 2019-07-24T23:39:34.801Z,1564011574.801 [Default:CheckIn:E] Stopped 2019-07-24T23:39:34.801Z,1564011574.801 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-24T23:39:34.801Z,1564011574.801 [Default:CheckIn] Stopped 2019-07-24T23:39:34.801Z,1564011574.801 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-24T23:39:34.801Z,1564011574.801 [Default:CheckIn](INFO): Running loop #4 2019-07-24T23:39:34.801Z,1564011574.801 [Default:CheckIn] Running Loop=4 2019-07-24T23:39:34.802Z,1564011574.802 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-24T23:39:34.802Z,1564011574.802 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-24T23:39:36.426Z,1564011576.426 [NAL9602](DEBUG): Fix Requested 2019-07-24T23:39:36.809Z,1564011576.809 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233923.00,A,3648.16687,N,12147.27773,W,1.594,140.10,240719,,,A*72 2019-07-24T23:39:36.811Z,1564011576.811 [NAL9602](INFO): GPS fix at 20190724T233923: (36.802781, -121.787962) 2019-07-24T23:39:36.869Z,1564011576.869 [Default:CheckIn:Read_GPS] Stopped 2019-07-24T23:39:36.869Z,1564011576.869 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-24T23:39:40.790Z,1564011580.790 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20190724T232310/Courier0009.lzma 2019-07-24T23:39:41.595Z,1564011581.595 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Courier0009.lzma.bak 2019-07-24T23:39:41.595Z,1564011581.595 [DataOverHttps](INFO): SBD MOMSN=11473280 2019-07-24T23:39:52.794Z,1564011592.794 [DataOverHttps](INFO): Sending 309 bytes from file Logs/20190724T232310/Express0010.lzma 2019-07-24T23:39:53.599Z,1564011593.599 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Express0010.lzma.bak 2019-07-24T23:39:53.600Z,1564011593.600 [DataOverHttps](INFO): SBD MOMSN=11473283 2019-07-24T23:39:54.261Z,1564011594.261 [Default:CheckIn:Read_Iridium] Stopped 2019-07-24T23:39:54.261Z,1564011594.261 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-24T23:39:54.261Z,1564011594.261 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-24T23:40:33.827Z,1564011633.827 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-24T23:40:33.827Z,1564011633.827 [DVL_micro] Data Fault, FailCount= 1 2019-07-24T23:40:33.827Z,1564011633.827 [DVL_micro](ERROR): Data Fault 2019-07-24T23:40:33.866Z,1564011633.866 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-24T23:40:34.298Z,1564011634.298 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:40:35.081Z,1564011635.081 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:40:35.081Z,1564011635.081 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:40:35.451Z,1564011635.451 [DVL_micro](INFO): Initializing 2019-07-24T23:41:58.278Z,1564011718.278 [NAL9602](INFO): SBD MO Status=2, MOMSN=30027, MT Status=2, MTMSN=0 2019-07-24T23:41:58.278Z,1564011718.278 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-24T23:43:29.168Z,1564011809.168 [NAL9602](INFO): SBD MO Status=2, MOMSN=30027, MT Status=2, MTMSN=0 2019-07-24T23:43:29.168Z,1564011809.168 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-24T23:43:39.671Z,1564011819.671 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-07-24T23:43:39.671Z,1564011819.671 [DVL_micro] Data Fault, FailCount= 1 2019-07-24T23:43:39.671Z,1564011819.671 [DVL_micro](ERROR): Data Fault 2019-07-24T23:43:39.710Z,1564011819.710 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-07-24T23:43:40.150Z,1564011820.150 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:43:40.936Z,1564011820.936 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:43:40.936Z,1564011820.936 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:43:41.284Z,1564011821.284 [DVL_micro](INFO): Initializing 2019-07-24T23:44:08.351Z,1564011848.351 [NAL9602](INFO): SBD MO Status=2, MOMSN=30027, MT Status=2, MTMSN=0 2019-07-24T23:44:08.351Z,1564011848.351 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-07-24T23:44:38.649Z,1564011878.649 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-07-24T23:44:54.869Z,1564011894.869 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-07-24T23:44:54.869Z,1564011894.869 [Default:CheckIn:C.Wait] Stopped 2019-07-24T23:44:54.869Z,1564011894.869 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-24T23:44:54.869Z,1564011894.869 [Default:CheckIn:D] Running Loop=1 2019-07-24T23:44:55.241Z,1564011895.241 [Default:CheckIn:D] Stopped 2019-07-24T23:44:55.242Z,1564011895.242 [Default:CheckIn:E] Running Loop=1 2019-07-24T23:44:55.688Z,1564011895.688 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.255052 min 2019-07-24T23:44:55.688Z,1564011895.688 [Default:CheckIn:E] Stopped 2019-07-24T23:44:55.688Z,1564011895.688 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-07-24T23:44:55.688Z,1564011895.688 [Default:CheckIn] Stopped 2019-07-24T23:44:55.688Z,1564011895.688 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-24T23:44:55.689Z,1564011895.689 [Default:CheckIn](INFO): Running loop #5 2019-07-24T23:44:55.689Z,1564011895.689 [Default:CheckIn] Running Loop=5 2019-07-24T23:44:55.689Z,1564011895.689 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-07-24T23:44:55.689Z,1564011895.689 [Default:CheckIn:Read_GPS] Running Loop=1 2019-07-24T23:44:57.254Z,1564011897.254 [NAL9602](DEBUG): Fix Requested 2019-07-24T23:44:57.645Z,1564011897.645 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234444.00,A,3648.17590,N,12147.26131,W,2.527,176.79,240719,,,A*7D 2019-07-24T23:44:57.647Z,1564011897.647 [NAL9602](INFO): GPS fix at 20190724T234444: (36.802932, -121.787689) 2019-07-24T23:44:57.690Z,1564011897.690 [Default:CheckIn:Read_GPS] Stopped 2019-07-24T23:44:57.690Z,1564011897.690 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-07-24T23:45:00.600Z,1564011900.600 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190724T232310/Courier0012.lzma 2019-07-24T23:45:01.319Z,1564011901.319 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Courier0012.lzma.bak 2019-07-24T23:45:01.320Z,1564011901.320 [DataOverHttps](INFO): SBD MOMSN=11473297 2019-07-24T23:45:06.197Z,1564011906.197 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-07-24T23:45:06.197Z,1564011906.197 [DVL_micro] Communications Fault, FailCount= 1 2019-07-24T23:45:06.197Z,1564011906.197 [DVL_micro](ERROR): Communications Fault 2019-07-24T23:45:06.234Z,1564011906.234 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-07-24T23:45:06.682Z,1564011906.682 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:45:07.454Z,1564011907.454 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-07-24T23:45:07.454Z,1564011907.454 [DVL_micro] No Fault, FailCount= 1 2019-07-24T23:45:07.825Z,1564011907.825 [DVL_micro](INFO): Initializing 2019-07-24T23:45:12.306Z,1564011912.306 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20190724T232310/Express0013.lzma 2019-07-24T23:45:13.111Z,1564011913.111 [DataOverHttps](INFO): Moved sent file to Logs/20190724T232310/Express0013.lzma.bak 2019-07-24T23:45:13.112Z,1564011913.112 [DataOverHttps](INFO): SBD MOMSN=11473300 2019-07-24T23:45:13.913Z,1564011913.913 [Default:CheckIn:Read_Iridium] Stopped 2019-07-24T23:45:13.913Z,1564011913.913 [Default:CheckIn:C.Wait] Running Loop=1 2019-07-24T23:45:13.913Z,1564011913.913 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-07-24T23:45:30.485Z,1564011930.485 [NAL9602](INFO): Not Powering down - fast GPS 2019-07-24T23:46:37.603Z,1564011997.603 [CommandLine](IMPORTANT): got command quit 2019-07-24T23:46:38.610Z,1564011998.610 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:38.610Z,1564011998.610 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:38.650Z,1564011998.650 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-07-24T23:46:38.650Z,1564011998.650 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:38.651Z,1564011998.651 [CommandLine](INFO): Join timeout helper Thread ID is 1960 2019-07-24T23:46:38.651Z,1564011998.651 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-07-24T23:46:38.651Z,1564011998.651 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:38.652Z,1564011998.652 [NavChartDb](INFO): Join timeout helper Thread ID is 1961 2019-07-24T23:46:38.966Z,1564011998.966 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:38.966Z,1564011998.966 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:38.974Z,1564011998.974 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-07-24T23:46:38.974Z,1564011998.974 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:38.974Z,1564011998.974 [Radio_Surface](INFO): Join timeout helper Thread ID is 1962 2019-07-24T23:46:39.254Z,1564011999.254 [Radio_Surface](INFO): Powering down 2019-07-24T23:46:39.255Z,1564011999.255 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:39.255Z,1564011999.255 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:39.274Z,1564011999.274 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-07-24T23:46:39.274Z,1564011999.274 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:39.274Z,1564011999.274 [DataOverHttps](INFO): Join timeout helper Thread ID is 1963 2019-07-24T23:46:39.282Z,1564011999.282 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:39.282Z,1564011999.282 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:39.294Z,1564011999.294 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-07-24T23:46:39.294Z,1564011999.294 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:39.294Z,1564011999.294 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1964 2019-07-24T23:46:39.410Z,1564011999.410 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:39.410Z,1564011999.410 [WetLabsBB2FL](INFO): Powering down 2019-07-24T23:46:39.411Z,1564011999.411 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:39.415Z,1564011999.415 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-07-24T23:46:39.415Z,1564011999.415 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:39.415Z,1564011999.415 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1965 2019-07-24T23:46:40.106Z,1564012000.106 [CTD_Seabird](INFO): Powering down 2019-07-24T23:46:40.118Z,1564012000.118 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:40.118Z,1564012000.118 [CTD_Seabird](INFO): Powering down 2019-07-24T23:46:40.134Z,1564012000.134 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.147Z,1564012000.147 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-07-24T23:46:40.147Z,1564012000.147 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.147Z,1564012000.147 [logger](INFO): Join timeout helper Thread ID is 1966 2019-07-24T23:46:40.234Z,1564012000.234 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:40.234Z,1564012000.234 [logger ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.247Z,1564012000.247 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-07-24T23:46:40.247Z,1564012000.247 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.247Z,1564012000.247 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-07-24T23:46:40.247Z,1564012000.247 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.247Z,1564012000.247 [controlThread](INFO): Join timeout helper Thread ID is 1967 2019-07-24T23:46:40.310Z,1564012000.310 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-07-24T23:46:40.310Z,1564012000.310 [controlThread](DEBUG): Uninitializing ControlThread 2019-07-24T23:46:40.311Z,1564012000.311 [Aanderaa_O2](INFO): Powering down 2019-07-24T23:46:40.333Z,1564012000.333 [AHRS_M2](INFO): Powering down 2019-07-24T23:46:40.474Z,1564012000.474 [DVL_micro](INFO): uninitialize:Powering down 2019-07-24T23:46:40.475Z,1564012000.475 [NAL9602](INFO): Powering down 2019-07-24T23:46:40.476Z,1564012000.476 [DAT](INFO): Powering down 2019-07-24T23:46:40.595Z,1564012000.595 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-07-24T23:46:40.596Z,1564012000.596 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-07-24T23:46:40.596Z,1564012000.596 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-07-24T23:46:40.596Z,1564012000.596 [MissionManager](INFO): Uninitializing Mission Default 2019-07-24T23:46:40.597Z,1564012000.597 [Default] Stopped 2019-07-24T23:46:40.597Z,1564012000.597 [Default](DEBUG): Aggregate::uninitialize Default 2019-07-24T23:46:40.597Z,1564012000.597 [Default:B.GoToSurface] Stopped 2019-07-24T23:46:40.597Z,1564012000.597 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-07-24T23:46:40.597Z,1564012000.597 [Default:CheckIn] Stopped 2019-07-24T23:46:40.597Z,1564012000.597 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-07-24T23:46:40.597Z,1564012000.597 [Default:CheckIn:C.Wait] Stopped 2019-07-24T23:46:40.597Z,1564012000.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-07-24T23:46:40.600Z,1564012000.600 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-07-24T23:46:40.600Z,1564012000.600 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-07-24T23:46:40.600Z,1564012000.600 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-07-24T23:46:40.600Z,1564012000.600 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-07-24T23:46:40.601Z,1564012000.601 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-07-24T23:46:40.601Z,1564012000.601 [BuoyancyServo](INFO): Powering down 2019-07-24T23:46:40.614Z,1564012000.614 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-07-24T23:46:40.614Z,1564012000.614 [ElevatorServo](INFO): Powering down 2019-07-24T23:46:40.615Z,1564012000.615 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-07-24T23:46:40.615Z,1564012000.615 [MassServo](INFO): Powering down 2019-07-24T23:46:40.616Z,1564012000.616 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-07-24T23:46:40.616Z,1564012000.616 [RudderServo](INFO): Powering down 2019-07-24T23:46:40.617Z,1564012000.617 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-07-24T23:46:40.617Z,1564012000.617 [ThrusterServo](INFO): Powering down 2019-07-24T23:46:40.617Z,1564012000.617 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-07-24T23:46:40.618Z,1564012000.618 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-07-24T23:46:40.618Z,1564012000.618 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-07-24T23:46:40.618Z,1564012000.618 [CBIT](DEBUG): Powering off loads. 2019-07-24T23:46:40.630Z,1564012000.630 [CBIT](DEBUG): Disabling WDT. 2019-07-24T23:46:40.642Z,1564012000.642 [CBIT](DEBUG): Opening all GF detection circuits. 2019-07-24T23:46:40.643Z,1564012000.643 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.674Z,1564012000.674 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.679Z,1564012000.679 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.741Z,1564012000.741 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.749Z,1564012000.749 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.799Z,1564012000.799 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-07-24T23:46:40.868Z,1564012000.868 [logger ThreadHandler](INFO): Thread cancelled.