2019-12-18T23:12:39.815Z,1576710759.815 [CommandLine](IMPORTANT): got command restart logs 2019-12-18T23:12:53.371Z,1576710773.371 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-18T23:13:00.399Z,1576710780.399 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.250576 2019-12-18T23:13:31.567Z,1576710811.567 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-12-18T23:14:05.361Z,1576710845.361 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005806 2019-12-18T23:14:13.042Z,1576710853.042 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191217T160010/Courier0186.lzma 2019-12-18T23:14:15.048Z,1576710855.048 [DataOverHttps](INFO): Moved sent file to Logs/20191217T160010/Courier0186.lzma.bak 2019-12-18T23:14:15.048Z,1576710855.048 [DataOverHttps](INFO): SBD MOMSN=12182277 2019-12-18T23:14:22.995Z,1576710862.995 [NAL9602](INFO): SBD MO Status=1, MOMSN=6578, MT Status=0, MTMSN=0 2019-12-18T23:14:23.051Z,1576710863.051 [NAL9602](INFO): Sent 62 bytes from file Logs/20191217T160010/Courier0186.lzma 2019-12-18T23:14:23.051Z,1576710863.051 [NAL9602](INFO): Packets left to send: 0 2019-12-18T23:14:32.034Z,1576710872.034 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20191217T160010/Express0187.lzma 2019-12-18T23:14:34.040Z,1576710874.040 [DataOverHttps](INFO): Moved sent file to Logs/20191217T160010/Express0187.lzma.bak 2019-12-18T23:14:34.040Z,1576710874.040 [DataOverHttps](INFO): SBD MOMSN=12182280 2019-12-18T23:14:54.094Z,1576710894.094 [DataOverHttps](INFO): Sending 107 bytes from file Logs/20191217T160010/Express0190.lzma 2019-12-18T23:14:54.119Z,1576710894.119 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-18T23:14:56.100Z,1576710896.100 [DataOverHttps](INFO): Moved sent file to Logs/20191217T160010/Express0190.lzma.bak 2019-12-18T23:14:56.100Z,1576710896.100 [DataOverHttps](INFO): SBD MOMSN=12182283 2019-12-18T23:15:13.038Z,1576710913.038 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20191218T231239/Express0001.lzma 2019-12-18T23:15:15.044Z,1576710915.044 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0001.lzma.bak 2019-12-18T23:15:15.044Z,1576710915.044 [DataOverHttps](INFO): SBD MOMSN=12182287 2019-12-18T23:15:16.780Z,1576710916.780 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:15:16.780Z,1576710916.780 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:15:16.780Z,1576710916.780 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:20:17.366Z,1576711217.366 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:20:17.366Z,1576711217.366 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:20:17.366Z,1576711217.366 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:20:17.366Z,1576711217.366 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:20:17.769Z,1576711217.769 [Default:CheckIn:D] Stopped 2019-12-18T23:20:17.769Z,1576711217.769 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:20:18.185Z,1576711218.185 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.625444 min 2019-12-18T23:20:18.186Z,1576711218.186 [Default:CheckIn:E] Stopped 2019-12-18T23:20:18.186Z,1576711218.186 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:20:18.186Z,1576711218.186 [Default:CheckIn] Stopped 2019-12-18T23:20:18.186Z,1576711218.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:20:18.186Z,1576711218.186 [Default:CheckIn](INFO): Running loop #4 2019-12-18T23:20:18.186Z,1576711218.186 [Default:CheckIn] Running Loop=4 2019-12-18T23:20:18.187Z,1576711218.187 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:20:18.187Z,1576711218.187 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:20:20.162Z,1576711220.162 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232008.00,A,3648.13933,N,12147.20531,W,0.019,237.02,181219,,,D*7A 2019-12-18T23:20:20.164Z,1576711220.164 [NAL9602](INFO): GPS fix at 20191218T232008: (36.802322, -121.786755) 2019-12-18T23:20:20.192Z,1576711220.192 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:20:20.192Z,1576711220.192 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:20:28.182Z,1576711228.182 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20191218T231239/Courier0003.lzma 2019-12-18T23:20:30.188Z,1576711230.188 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0003.lzma.bak 2019-12-18T23:20:30.188Z,1576711230.188 [DataOverHttps](INFO): SBD MOMSN=12182295 2019-12-18T23:20:48.445Z,1576711248.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=6579, MT Status=2, MTMSN=0 2019-12-18T23:20:48.445Z,1576711248.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-12-18T23:20:49.246Z,1576711249.246 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20191218T231239/Express0004.lzma 2019-12-18T23:20:51.252Z,1576711251.252 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0004.lzma.bak 2019-12-18T23:20:51.252Z,1576711251.252 [DataOverHttps](INFO): SBD MOMSN=12182298 2019-12-18T23:20:52.931Z,1576711252.931 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:20:52.932Z,1576711252.932 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:20:52.932Z,1576711252.932 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:23:23.989Z,1576711403.989 [NAL9602](INFO): SBD MO Status=0, MOMSN=6579, MT Status=0, MTMSN=0 2019-12-18T23:23:23.989Z,1576711403.989 [NAL9602](INFO): No messages in MT queue 2019-12-18T23:23:54.695Z,1576711434.695 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-18T23:25:53.503Z,1576711553.503 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:25:53.503Z,1576711553.503 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:25:53.503Z,1576711553.503 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:25:53.504Z,1576711553.504 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:25:53.910Z,1576711553.910 [Default:CheckIn:D] Stopped 2019-12-18T23:25:53.910Z,1576711553.910 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:25:54.298Z,1576711554.298 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 26.227799 min 2019-12-18T23:25:54.298Z,1576711554.298 [Default:CheckIn:E] Stopped 2019-12-18T23:25:54.298Z,1576711554.298 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:25:54.298Z,1576711554.298 [Default:CheckIn] Stopped 2019-12-18T23:25:54.299Z,1576711554.299 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:25:54.300Z,1576711554.300 [Default:CheckIn](INFO): Running loop #5 2019-12-18T23:25:54.300Z,1576711554.300 [Default:CheckIn] Running Loop=5 2019-12-18T23:25:54.301Z,1576711554.301 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:25:54.301Z,1576711554.301 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:25:56.297Z,1576711556.297 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232544.00,A,3648.14035,N,12147.20848,W,0.369,138.51,181219,,,D*72 2019-12-18T23:25:56.299Z,1576711556.299 [NAL9602](INFO): GPS fix at 20191218T232544: (36.802339, -121.786808) 2019-12-18T23:25:56.332Z,1576711556.332 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:25:56.332Z,1576711556.332 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:26:03.322Z,1576711563.322 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191218T231239/Courier0006.lzma 2019-12-18T23:26:05.328Z,1576711565.328 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0006.lzma.bak 2019-12-18T23:26:05.328Z,1576711565.328 [DataOverHttps](INFO): SBD MOMSN=12182302 2019-12-18T23:26:09.665Z,1576711569.665 [NAL9602](INFO): SBD MO Status=0, MOMSN=6580, MT Status=0, MTMSN=0 2019-12-18T23:26:09.665Z,1576711569.665 [NAL9602](INFO): No messages in MT queue 2019-12-18T23:26:22.322Z,1576711582.322 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20191218T231239/Express0007.lzma 2019-12-18T23:26:24.328Z,1576711584.328 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0007.lzma.bak 2019-12-18T23:26:24.328Z,1576711584.328 [DataOverHttps](INFO): SBD MOMSN=12182306 2019-12-18T23:26:26.720Z,1576711586.720 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:26:26.720Z,1576711586.720 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:26:26.720Z,1576711586.720 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:26:40.367Z,1576711600.367 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-18T23:31:27.281Z,1576711887.281 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:31:27.281Z,1576711887.281 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:31:27.281Z,1576711887.281 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:31:27.282Z,1576711887.282 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:31:27.687Z,1576711887.687 [Default:CheckIn:D] Stopped 2019-12-18T23:31:27.687Z,1576711887.687 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:31:28.101Z,1576711888.101 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.790745 min 2019-12-18T23:31:28.101Z,1576711888.101 [Default:CheckIn:E] Stopped 2019-12-18T23:31:28.101Z,1576711888.101 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:31:28.102Z,1576711888.102 [Default:CheckIn] Stopped 2019-12-18T23:31:28.102Z,1576711888.102 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:31:28.102Z,1576711888.102 [Default:CheckIn](INFO): Running loop #6 2019-12-18T23:31:28.102Z,1576711888.102 [Default:CheckIn] Running Loop=6 2019-12-18T23:31:28.102Z,1576711888.102 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:31:28.102Z,1576711888.102 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:31:30.081Z,1576711890.081 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233118.00,A,3648.17117,N,12147.27968,W,0.408,241.71,181219,,,D*77 2019-12-18T23:31:30.084Z,1576711890.084 [NAL9602](INFO): GPS fix at 20191218T233118: (36.802853, -121.787995) 2019-12-18T23:31:30.111Z,1576711890.111 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:31:30.111Z,1576711890.111 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:31:39.371Z,1576711899.371 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191218T231239/Courier0009.lzma 2019-12-18T23:31:41.380Z,1576711901.380 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0009.lzma.bak 2019-12-18T23:31:41.380Z,1576711901.380 [DataOverHttps](INFO): SBD MOMSN=12182309 2019-12-18T23:31:58.434Z,1576711918.434 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191218T231239/Express0010.lzma 2019-12-18T23:32:00.440Z,1576711920.440 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0010.lzma.bak 2019-12-18T23:32:00.440Z,1576711920.440 [DataOverHttps](INFO): SBD MOMSN=12182312 2019-12-18T23:32:02.445Z,1576711922.445 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:32:02.445Z,1576711922.445 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:32:02.445Z,1576711922.445 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:36:32.338Z,1576712192.338 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-18T23:37:03.047Z,1576712223.047 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-18T23:37:03.098Z,1576712223.098 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:37:03.098Z,1576712223.098 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:37:03.098Z,1576712223.098 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:37:03.099Z,1576712223.099 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:37:03.485Z,1576712223.485 [Default:CheckIn:D] Stopped 2019-12-18T23:37:03.485Z,1576712223.485 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:37:03.882Z,1576712223.882 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.387378 min 2019-12-18T23:37:03.882Z,1576712223.882 [Default:CheckIn:E] Stopped 2019-12-18T23:37:03.882Z,1576712223.882 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:37:03.882Z,1576712223.882 [Default:CheckIn] Stopped 2019-12-18T23:37:03.882Z,1576712223.882 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:37:03.898Z,1576712223.898 [Default:CheckIn](INFO): Running loop #7 2019-12-18T23:37:03.898Z,1576712223.898 [Default:CheckIn] Running Loop=7 2019-12-18T23:37:03.899Z,1576712223.899 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:37:03.899Z,1576712223.899 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:37:05.877Z,1576712225.877 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233654.00,A,3648.16207,N,12147.28476,W,1.827,172.03,181219,,,D*70 2019-12-18T23:37:05.879Z,1576712225.879 [NAL9602](INFO): GPS fix at 20191218T233654: (36.802701, -121.788079) 2019-12-18T23:37:05.906Z,1576712225.906 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:37:05.907Z,1576712225.907 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:37:13.574Z,1576712233.574 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191218T231239/Courier0012.lzma 2019-12-18T23:37:15.580Z,1576712235.580 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0012.lzma.bak 2019-12-18T23:37:15.580Z,1576712235.580 [DataOverHttps](INFO): SBD MOMSN=12182315 2019-12-18T23:37:24.939Z,1576712244.939 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-12-18T23:37:30.967Z,1576712250.967 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-12-18T23:37:30.969Z,1576712250.969 [BPC1](INFO): Received data from all battery sticks. 2019-12-18T23:37:32.666Z,1576712252.666 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20191218T231239/Express0013.lzma 2019-12-18T23:37:34.672Z,1576712254.672 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0013.lzma.bak 2019-12-18T23:37:34.672Z,1576712254.672 [DataOverHttps](INFO): SBD MOMSN=12182318 2019-12-18T23:37:36.613Z,1576712256.613 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:37:36.613Z,1576712256.613 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:37:36.613Z,1576712256.613 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:42:08.495Z,1576712528.495 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-18T23:42:37.241Z,1576712557.241 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:42:37.241Z,1576712557.241 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:42:37.241Z,1576712557.241 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:42:37.241Z,1576712557.241 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:42:37.617Z,1576712557.617 [Default:CheckIn:D] Stopped 2019-12-18T23:42:37.618Z,1576712557.618 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:42:38.034Z,1576712558.034 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.956258 min 2019-12-18T23:42:38.038Z,1576712558.038 [Default:CheckIn:E] Stopped 2019-12-18T23:42:38.039Z,1576712558.039 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:42:38.039Z,1576712558.039 [Default:CheckIn] Stopped 2019-12-18T23:42:38.039Z,1576712558.039 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:42:38.039Z,1576712558.039 [Default:CheckIn](INFO): Running loop #8 2019-12-18T23:42:38.039Z,1576712558.039 [Default:CheckIn] Running Loop=8 2019-12-18T23:42:38.039Z,1576712558.039 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:42:38.039Z,1576712558.039 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:42:40.013Z,1576712560.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234228.00,A,3648.17346,N,12147.28754,W,1.419,172.03,181219,,,A*7A 2019-12-18T23:42:40.016Z,1576712560.016 [NAL9602](INFO): GPS fix at 20191218T234228: (36.802891, -121.788126) 2019-12-18T23:42:40.063Z,1576712560.063 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:42:40.063Z,1576712560.063 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:42:47.730Z,1576712567.730 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20191218T231239/Courier0015.lzma 2019-12-18T23:42:49.736Z,1576712569.736 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0015.lzma.bak 2019-12-18T23:42:49.736Z,1576712569.736 [DataOverHttps](INFO): SBD MOMSN=12182330 2019-12-18T23:43:06.666Z,1576712586.666 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191218T231239/Express0016.lzma 2019-12-18T23:43:08.672Z,1576712588.672 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0016.lzma.bak 2019-12-18T23:43:08.672Z,1576712588.672 [DataOverHttps](INFO): SBD MOMSN=12182333 2019-12-18T23:43:10.339Z,1576712590.339 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:43:10.339Z,1576712590.339 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:43:10.339Z,1576712590.339 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:43:12.327Z,1576712592.327 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-18T23:48:10.939Z,1576712890.939 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:48:10.939Z,1576712890.939 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:48:10.940Z,1576712890.940 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:48:10.940Z,1576712890.940 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:48:11.325Z,1576712891.325 [Default:CheckIn:D] Stopped 2019-12-18T23:48:11.325Z,1576712891.325 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:48:11.731Z,1576712891.731 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.518046 min 2019-12-18T23:48:11.731Z,1576712891.731 [Default:CheckIn:E] Stopped 2019-12-18T23:48:11.731Z,1576712891.731 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:48:11.731Z,1576712891.731 [Default:CheckIn] Stopped 2019-12-18T23:48:11.732Z,1576712891.732 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:48:11.732Z,1576712891.732 [Default:CheckIn](INFO): Running loop #9 2019-12-18T23:48:11.732Z,1576712891.732 [Default:CheckIn] Running Loop=9 2019-12-18T23:48:11.732Z,1576712891.732 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:48:11.732Z,1576712891.732 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:48:13.725Z,1576712893.725 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234802.00,A,3648.17034,N,12147.28233,W,0.525,255.30,181219,,,A*73 2019-12-18T23:48:13.735Z,1576712893.735 [NAL9602](INFO): GPS fix at 20191218T234802: (36.802839, -121.788039) 2019-12-18T23:48:13.764Z,1576712893.764 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:48:13.764Z,1576712893.764 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:48:21.494Z,1576712901.494 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191218T231239/Courier0018.lzma 2019-12-18T23:48:24.131Z,1576712904.131 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0018.lzma.bak 2019-12-18T23:48:24.131Z,1576712904.131 [DataOverHttps](INFO): SBD MOMSN=12182337 2019-12-18T23:48:44.436Z,1576712924.436 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-12-18T23:48:44.514Z,1576712924.514 [NAL9602](FAULT): received: +CSQ:0 OK80, 0, 0, 0, 0 OK 2019-12-18T23:48:44.514Z,1576712924.514 [NAL9602] Data Fault, FailCount= 1 2019-12-18T23:48:44.514Z,1576712924.514 [NAL9602](ERROR): Data Fault 2019-12-18T23:48:44.574Z,1576712924.574 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191218T231239/Express0019.lzma 2019-12-18T23:48:44.596Z,1576712924.596 [CBIT](ERROR): Data Fault in component: NAL9602 2019-12-18T23:48:44.836Z,1576712924.836 [NAL9602](INFO): Powering down 2019-12-18T23:48:45.247Z,1576712925.247 [NAL9602](FAULT): LCB fault: Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated. 2019-12-18T23:48:45.247Z,1576712925.247 [NAL9602] Hardware Fault, FailCount= 1 2019-12-18T23:48:45.247Z,1576712925.247 [NAL9602](ERROR): Hardware Fault 2019-12-18T23:48:45.697Z,1576712925.697 [CBIT](INFO): Clearing failed state for component NAL9602 2019-12-18T23:48:45.697Z,1576712925.697 [NAL9602] No Fault, FailCount= 1 2019-12-18T23:48:46.580Z,1576712926.580 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0019.lzma.bak 2019-12-18T23:48:46.580Z,1576712926.580 [DataOverHttps](INFO): SBD MOMSN=12182340 2019-12-18T23:48:48.503Z,1576712928.503 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:48:48.503Z,1576712928.503 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:48:48.503Z,1576712928.503 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:49:15.133Z,1576712955.133 [NAL9602](INFO): Powering up NAL9602 2019-12-18T23:49:26.041Z,1576712966.041 [NAL9602](INFO): NAL9602 initialized 2019-12-18T23:49:57.155Z,1576712997.155 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-18T23:53:49.088Z,1576713229.088 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:53:49.089Z,1576713229.089 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:53:49.089Z,1576713229.089 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:53:49.089Z,1576713229.089 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:53:49.500Z,1576713229.500 [Default:CheckIn:D] Stopped 2019-12-18T23:53:49.500Z,1576713229.500 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:53:49.909Z,1576713229.909 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.154297 min 2019-12-18T23:53:49.909Z,1576713229.909 [Default:CheckIn:E] Stopped 2019-12-18T23:53:49.910Z,1576713229.910 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:53:49.910Z,1576713229.910 [Default:CheckIn] Stopped 2019-12-18T23:53:49.910Z,1576713229.910 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:53:49.910Z,1576713229.910 [Default:CheckIn](INFO): Running loop #10 2019-12-18T23:53:49.910Z,1576713229.910 [Default:CheckIn] Running Loop=10 2019-12-18T23:53:49.910Z,1576713229.910 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:53:49.910Z,1576713229.910 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:53:51.894Z,1576713231.894 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235339.00,A,3648.16405,N,12147.28863,W,0.641,247.41,181219,,,D*78 2019-12-18T23:53:51.896Z,1576713231.896 [NAL9602](INFO): GPS fix at 20191218T235339: (36.802734, -121.788144) 2019-12-18T23:53:51.939Z,1576713231.939 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:53:51.939Z,1576713231.939 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:53:53.953Z,1576713233.953 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-18T23:53:58.886Z,1576713238.886 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191218T231239/Courier0021.lzma 2019-12-18T23:54:00.892Z,1576713240.892 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0021.lzma.bak 2019-12-18T23:54:00.892Z,1576713240.892 [DataOverHttps](INFO): SBD MOMSN=12182343 2019-12-18T23:54:17.790Z,1576713257.790 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20191218T231239/Express0022.lzma 2019-12-18T23:54:19.800Z,1576713259.800 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0022.lzma.bak 2019-12-18T23:54:19.800Z,1576713259.800 [DataOverHttps](INFO): SBD MOMSN=12182346 2019-12-18T23:54:21.465Z,1576713261.465 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:54:21.465Z,1576713261.465 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:54:21.465Z,1576713261.465 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-18T23:54:24.667Z,1576713264.667 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-18T23:59:22.049Z,1576713562.049 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-18T23:59:22.049Z,1576713562.049 [Default:CheckIn:C.Wait] Stopped 2019-12-18T23:59:22.049Z,1576713562.049 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-18T23:59:22.049Z,1576713562.049 [Default:CheckIn:D] Running Loop=1 2019-12-18T23:59:22.460Z,1576713562.460 [Default:CheckIn:D] Stopped 2019-12-18T23:59:22.460Z,1576713562.460 [Default:CheckIn:E] Running Loop=1 2019-12-18T23:59:22.869Z,1576713562.869 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.703638 min 2019-12-18T23:59:22.869Z,1576713562.869 [Default:CheckIn:E] Stopped 2019-12-18T23:59:22.870Z,1576713562.870 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-18T23:59:22.870Z,1576713562.870 [Default:CheckIn] Stopped 2019-12-18T23:59:22.871Z,1576713562.871 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-18T23:59:22.871Z,1576713562.871 [Default:CheckIn](INFO): Running loop #11 2019-12-18T23:59:22.871Z,1576713562.871 [Default:CheckIn] Running Loop=11 2019-12-18T23:59:22.871Z,1576713562.871 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-18T23:59:22.871Z,1576713562.871 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-18T23:59:24.857Z,1576713564.857 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235913.00,A,3648.17060,N,12147.28046,W,0.097,127.77,181219,,,A*7B 2019-12-18T23:59:24.859Z,1576713564.859 [NAL9602](INFO): GPS fix at 20191218T235913: (36.802843, -121.788008) 2019-12-18T23:59:24.915Z,1576713564.915 [Default:CheckIn:Read_GPS] Stopped 2019-12-18T23:59:24.915Z,1576713564.915 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-18T23:59:32.842Z,1576713572.842 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191218T231239/Courier0024.lzma 2019-12-18T23:59:34.848Z,1576713574.848 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0024.lzma.bak 2019-12-18T23:59:34.848Z,1576713574.848 [DataOverHttps](INFO): SBD MOMSN=12182351 2019-12-18T23:59:51.810Z,1576713591.810 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191218T231239/Express0025.lzma 2019-12-18T23:59:53.816Z,1576713593.816 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0025.lzma.bak 2019-12-18T23:59:53.816Z,1576713593.816 [DataOverHttps](INFO): SBD MOMSN=12182355 2019-12-18T23:59:55.599Z,1576713595.599 [Default:CheckIn:Read_Iridium] Stopped 2019-12-18T23:59:55.599Z,1576713595.599 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-18T23:59:55.599Z,1576713595.599 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-19T00:02:17.771Z,1576713737.771 [NAL9602](INFO): SBD MO Status=0, MOMSN=6581, MT Status=0, MTMSN=0 2019-12-19T00:02:17.771Z,1576713737.771 [NAL9602](INFO): No messages in MT queue 2019-12-19T00:02:48.473Z,1576713768.473 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-19T00:04:56.184Z,1576713896.184 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-19T00:04:56.184Z,1576713896.184 [Default:CheckIn:C.Wait] Stopped 2019-12-19T00:04:56.184Z,1576713896.184 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-19T00:04:56.184Z,1576713896.184 [Default:CheckIn:D] Running Loop=1 2019-12-19T00:04:56.580Z,1576713896.580 [Default:CheckIn:D] Stopped 2019-12-19T00:04:56.580Z,1576713896.580 [Default:CheckIn:E] Running Loop=1 2019-12-19T00:04:56.990Z,1576713896.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.272302 min 2019-12-19T00:04:56.990Z,1576713896.990 [Default:CheckIn:E] Stopped 2019-12-19T00:04:56.991Z,1576713896.991 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-19T00:04:56.991Z,1576713896.991 [Default:CheckIn] Stopped 2019-12-19T00:04:56.991Z,1576713896.991 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-19T00:04:56.991Z,1576713896.991 [Default:CheckIn](INFO): Running loop #12 2019-12-19T00:04:56.991Z,1576713896.991 [Default:CheckIn] Running Loop=12 2019-12-19T00:04:56.991Z,1576713896.991 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-19T00:04:56.991Z,1576713896.991 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-19T00:04:58.969Z,1576713898.969 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000447.00,A,3648.16250,N,12147.28774,W,1.011,186.78,191219,,,D*7A 2019-12-19T00:04:58.972Z,1576713898.972 [NAL9602](INFO): GPS fix at 20191219T000447: (36.802708, -121.788129) 2019-12-19T00:04:59.007Z,1576713899.007 [Default:CheckIn:Read_GPS] Stopped 2019-12-19T00:04:59.007Z,1576713899.007 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-19T00:05:12.118Z,1576713912.118 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191218T231239/Courier0027.lzma 2019-12-19T00:05:14.124Z,1576713914.124 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0027.lzma.bak 2019-12-19T00:05:14.124Z,1576713914.124 [DataOverHttps](INFO): SBD MOMSN=12182359 2019-12-19T00:05:31.158Z,1576713931.158 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20191218T231239/Express0028.lzma 2019-12-19T00:05:33.164Z,1576713933.164 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0028.lzma.bak 2019-12-19T00:05:33.164Z,1576713933.164 [DataOverHttps](INFO): SBD MOMSN=12182362 2019-12-19T00:05:34.977Z,1576713934.977 [Default:CheckIn:Read_Iridium] Stopped 2019-12-19T00:05:34.977Z,1576713934.977 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-19T00:05:34.977Z,1576713934.977 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-19T00:10:01.170Z,1576714201.170 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-12-19T00:10:31.895Z,1576714231.895 [NAL9602](INFO): Not Powering down - fast GPS 2019-12-19T00:10:35.555Z,1576714235.555 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-12-19T00:10:35.555Z,1576714235.555 [Default:CheckIn:C.Wait] Stopped 2019-12-19T00:10:35.555Z,1576714235.555 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-19T00:10:35.555Z,1576714235.555 [Default:CheckIn:D] Running Loop=1 2019-12-19T00:10:35.942Z,1576714235.942 [Default:CheckIn:D] Stopped 2019-12-19T00:10:35.942Z,1576714235.942 [Default:CheckIn:E] Running Loop=1 2019-12-19T00:10:36.359Z,1576714236.359 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.928337 min 2019-12-19T00:10:36.359Z,1576714236.359 [Default:CheckIn:E] Stopped 2019-12-19T00:10:36.360Z,1576714236.360 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-12-19T00:10:36.360Z,1576714236.360 [Default:CheckIn] Stopped 2019-12-19T00:10:36.360Z,1576714236.360 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-19T00:10:36.360Z,1576714236.360 [Default:CheckIn](INFO): Running loop #13 2019-12-19T00:10:36.360Z,1576714236.360 [Default:CheckIn] Running Loop=13 2019-12-19T00:10:36.360Z,1576714236.360 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-12-19T00:10:36.360Z,1576714236.360 [Default:CheckIn:Read_GPS] Running Loop=1 2019-12-19T00:10:38.345Z,1576714238.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001026.00,A,3648.16146,N,12147.28514,W,0.350,95.89,191219,,,D*42 2019-12-19T00:10:38.357Z,1576714238.357 [NAL9602](INFO): GPS fix at 20191219T001026: (36.802691, -121.788086) 2019-12-19T00:10:38.385Z,1576714238.385 [Default:CheckIn:Read_GPS] Stopped 2019-12-19T00:10:38.385Z,1576714238.385 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-12-19T00:10:45.382Z,1576714245.382 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191218T231239/Courier0030.lzma 2019-12-19T00:10:47.388Z,1576714247.388 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Courier0030.lzma.bak 2019-12-19T00:10:47.388Z,1576714247.388 [DataOverHttps](INFO): SBD MOMSN=12182366 2019-12-19T00:11:04.402Z,1576714264.402 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20191218T231239/Express0031.lzma 2019-12-19T00:11:06.408Z,1576714266.408 [DataOverHttps](INFO): Moved sent file to Logs/20191218T231239/Express0031.lzma.bak 2019-12-19T00:11:06.408Z,1576714266.408 [DataOverHttps](INFO): SBD MOMSN=12182369 2019-12-19T00:11:08.365Z,1576714268.365 [Default:CheckIn:Read_Iridium] Stopped 2019-12-19T00:11:08.365Z,1576714268.365 [Default:CheckIn:C.Wait] Running Loop=1 2019-12-19T00:11:08.365Z,1576714268.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-12-19T00:13:04.724Z,1576714384.724 [CommandLine](IMPORTANT): got command quit 2019-12-19T00:13:05.730Z,1576714385.730 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:05.731Z,1576714385.731 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:05.838Z,1576714385.838 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-12-19T00:13:05.838Z,1576714385.838 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:05.839Z,1576714385.839 [CommandLine](INFO): Join timeout helper Thread ID is 2899 2019-12-19T00:13:05.839Z,1576714385.839 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-12-19T00:13:05.840Z,1576714385.840 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:05.840Z,1576714385.840 [NavChartDb](INFO): Join timeout helper Thread ID is 2900 2019-12-19T00:13:06.006Z,1576714386.006 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:06.007Z,1576714386.007 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:06.014Z,1576714386.014 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2019-12-19T00:13:06.015Z,1576714386.015 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:06.015Z,1576714386.015 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 2901 2019-12-19T00:13:06.415Z,1576714386.415 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:06.416Z,1576714386.416 [WetLabsUBAT](INFO): Powering down 2019-12-19T00:13:06.416Z,1576714386.416 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:06.434Z,1576714386.434 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-12-19T00:13:06.434Z,1576714386.434 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:06.435Z,1576714386.435 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2902 2019-12-19T00:13:06.919Z,1576714386.919 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:06.919Z,1576714386.919 [WetLabsBB2FL](INFO): Powering down 2019-12-19T00:13:06.920Z,1576714386.920 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:06.934Z,1576714386.934 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-12-19T00:13:06.934Z,1576714386.934 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:06.935Z,1576714386.935 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2903 2019-12-19T00:13:07.619Z,1576714387.619 [CTD_Seabird](INFO): Powering down 2019-12-19T00:13:07.630Z,1576714387.630 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:07.631Z,1576714387.631 [CTD_Seabird](INFO): Powering down 2019-12-19T00:13:07.642Z,1576714387.642 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:07.659Z,1576714387.659 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler 2019-12-19T00:13:07.659Z,1576714387.659 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:07.660Z,1576714387.660 [BackSeatDriver](INFO): Join timeout helper Thread ID is 2904 2019-12-19T00:13:08.034Z,1576714388.034 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:08.035Z,1576714388.035 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.043Z,1576714388.043 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-12-19T00:13:08.043Z,1576714388.043 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.044Z,1576714388.044 [Radio_Surface](INFO): Join timeout helper Thread ID is 2905 2019-12-19T00:13:08.044Z,1576714388.044 [Radio_Surface](INFO): Powering down 2019-12-19T00:13:08.045Z,1576714388.045 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:08.045Z,1576714388.045 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.054Z,1576714388.054 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-12-19T00:13:08.055Z,1576714388.055 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.055Z,1576714388.055 [DataOverHttps](INFO): Join timeout helper Thread ID is 2906 2019-12-19T00:13:08.290Z,1576714388.290 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:08.291Z,1576714388.291 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.311Z,1576714388.311 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-12-19T00:13:08.311Z,1576714388.311 [logger ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.312Z,1576714388.312 [logger](INFO): Join timeout helper Thread ID is 2907 2019-12-19T00:13:08.312Z,1576714388.312 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:08.312Z,1576714388.312 [logger ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.317Z,1576714388.317 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-12-19T00:13:08.319Z,1576714388.319 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.321Z,1576714388.321 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-12-19T00:13:08.321Z,1576714388.321 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.325Z,1576714388.325 [controlThread](INFO): Join timeout helper Thread ID is 2908 2019-12-19T00:13:08.357Z,1576714388.357 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-12-19T00:13:08.357Z,1576714388.357 [controlThread](DEBUG): Uninitializing ControlThread 2019-12-19T00:13:08.357Z,1576714388.357 [AHRS_M2](INFO): Powering down 2019-12-19T00:13:08.427Z,1576714388.427 [NAL9602](INFO): Powering down 2019-12-19T00:13:08.428Z,1576714388.428 [DAT](INFO): Powering down 2019-12-19T00:13:08.547Z,1576714388.547 [BR_Ping1D](INFO): Powering down 2019-12-19T00:13:08.619Z,1576714388.619 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-12-19T00:13:08.620Z,1576714388.620 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-12-19T00:13:08.620Z,1576714388.620 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-12-19T00:13:08.621Z,1576714388.621 [MissionManager](INFO): Uninitializing Mission Default 2019-12-19T00:13:08.621Z,1576714388.621 [Default] Stopped 2019-12-19T00:13:08.621Z,1576714388.621 [Default](DEBUG): Aggregate::uninitialize Default 2019-12-19T00:13:08.621Z,1576714388.621 [Default:B.GoToSurface] Stopped 2019-12-19T00:13:08.621Z,1576714388.621 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-12-19T00:13:08.621Z,1576714388.621 [Default:CheckIn] Stopped 2019-12-19T00:13:08.621Z,1576714388.621 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-12-19T00:13:08.621Z,1576714388.621 [Default:CheckIn:C.Wait] Stopped 2019-12-19T00:13:08.621Z,1576714388.621 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-12-19T00:13:08.624Z,1576714388.624 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-12-19T00:13:08.624Z,1576714388.624 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-12-19T00:13:08.624Z,1576714388.624 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-12-19T00:13:08.625Z,1576714388.625 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-12-19T00:13:08.625Z,1576714388.625 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-12-19T00:13:08.625Z,1576714388.625 [BuoyancyServo](INFO): Powering down 2019-12-19T00:13:08.638Z,1576714388.638 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-12-19T00:13:08.638Z,1576714388.638 [ElevatorServo](INFO): Powering down 2019-12-19T00:13:08.639Z,1576714388.639 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-12-19T00:13:08.639Z,1576714388.639 [MassServo](INFO): Powering down 2019-12-19T00:13:08.640Z,1576714388.640 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-12-19T00:13:08.640Z,1576714388.640 [RudderServo](INFO): Powering down 2019-12-19T00:13:08.641Z,1576714388.641 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-12-19T00:13:08.641Z,1576714388.641 [ThrusterServo](INFO): Powering down 2019-12-19T00:13:08.642Z,1576714388.642 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-12-19T00:13:08.642Z,1576714388.642 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-12-19T00:13:08.643Z,1576714388.643 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-12-19T00:13:08.643Z,1576714388.643 [CBIT](DEBUG): Powering off loads. 2019-12-19T00:13:08.654Z,1576714388.654 [CBIT](DEBUG): Disabling WDT. 2019-12-19T00:13:08.666Z,1576714388.666 [CBIT](DEBUG): Opening all GF detection circuits. 2019-12-19T00:13:08.667Z,1576714388.667 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.770Z,1576714388.770 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.776Z,1576714388.776 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.840Z,1576714388.840 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.841Z,1576714388.841 [WetLabsUBAT](INFO): WetLabs destructor: dataLog is open - close it 2019-12-19T00:13:08.841Z,1576714388.841 [WetLabsUBAT](INFO): WetLabs destructor: done 2019-12-19T00:13:08.892Z,1576714388.892 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.896Z,1576714388.896 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.899Z,1576714388.899 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.908Z,1576714388.908 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-12-19T00:13:08.994Z,1576714388.994 [logger ThreadHandler](INFO): Thread cancelled.