2019-07-24T16:08:57.073Z,1563984537.073 [CommandLine](IMPORTANT): got command restart logs
2019-07-24T16:09:27.849Z,1563984567.849 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:09:27.849Z,1563984567.849 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0 0.2 2.0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.07 -107 0.2 18.3 0.005 35.0 1489 111
2019-07-24T16:09:28.635Z,1563984568.635 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-24T16:09:28.635Z,1563984568.635 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0 0.2 2.0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.07 -10.88 226.4 0.2 18.3 0.005 35.0 1489 103
2019-07-24T16:12:35.330Z,1563984755.330 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-24T16:12:35.331Z,1563984755.331 [Default:CheckIn:C.Wait] Stopped
2019-07-24T16:12:35.331Z,1563984755.331 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-24T16:12:35.331Z,1563984755.331 [Default:CheckIn:D] Running Loop=1
2019-07-24T16:12:35.722Z,1563984755.722 [Default:CheckIn:D] Stopped
2019-07-24T16:12:35.722Z,1563984755.722 [Default:CheckIn:E] Running Loop=1
2019-07-24T16:12:36.160Z,1563984756.160 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.017320 min 
2019-07-24T16:12:36.160Z,1563984756.160 [Default:CheckIn:E] Stopped
2019-07-24T16:12:36.165Z,1563984756.165 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-24T16:12:36.165Z,1563984756.165 [Default:CheckIn] Stopped
2019-07-24T16:12:36.165Z,1563984756.165 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-24T16:12:36.165Z,1563984756.165 [Default:CheckIn](INFO): Running loop #2
2019-07-24T16:12:36.165Z,1563984756.165 [Default:CheckIn] Running Loop=2
2019-07-24T16:12:36.165Z,1563984756.165 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-24T16:12:36.165Z,1563984756.165 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-24T16:12:37.720Z,1563984757.720 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-24T16:12:37.720Z,1563984757.720 [NAL9602] Data Fault, FailCount= 1
2019-07-24T16:12:37.720Z,1563984757.720 [NAL9602](ERROR): Data Fault
2019-07-24T16:12:37.753Z,1563984757.753 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-24T16:12:38.116Z,1563984758.116 [NAL9602](INFO): Powering down
2019-07-24T16:12:38.955Z,1563984758.955 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-24T16:12:38.955Z,1563984758.955 [NAL9602] No Fault, FailCount= 1
2019-07-24T16:12:49.457Z,1563984769.457 [CBIT](INFO): Clearing failed state for component BPC1
2019-07-24T16:12:49.457Z,1563984769.457 [BPC1] No Fault, FailCount= 9
2019-07-24T16:13:08.428Z,1563984788.428 [NAL9602](INFO): Powering up NAL9602
2019-07-24T16:13:19.321Z,1563984799.321 [NAL9602](INFO): NAL9602 initialized
2019-07-24T16:13:20.145Z,1563984800.145 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:13:43.560Z,1563984823.560 [NAL9602](INFO): SBD MO Status=2, MOMSN=29953, MT Status=2, MTMSN=0
2019-07-24T16:13:43.560Z,1563984823.560 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:13:54.468Z,1563984834.468 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-24T16:13:54.469Z,1563984834.469 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 0.2 9.5 0.2 0 61.7 -84.6 -389.9 0 0 -341 0 777 0 1 0 2 602.7 212.2 -177.0 1 -350.4 -560.6 -49.9 1 0 -1492 0 0 0 0 0 0 3.18 -10.71 218.7 0.2 18.4 0.005 35.0 
2019-07-24T16:16:02.168Z,1563984962.168 [DVL_micro](ERROR): only read 41 of 46 data items
2019-07-24T16:16:02.169Z,1563984962.169 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.02 -10.77 208.3 0.2 18.2 0.005 35.0 1489 108
2019-07-24T16:16:07.818Z,1563984967.818 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-24T16:16:07.819Z,1563984967.819 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0 0.2 0.6 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.14 -10.69 207.2 0.2 18.3 0.005 35.0 1489 107
2019-07-24T16:16:21.599Z,1563984981.599 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:16:21.599Z,1563984981.599 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1.2 0.5 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2.97 -10.74 205.7 0.2 18.3 0.005 35.0 1489 105
2019-07-24T16:17:16.567Z,1563985036.567 [NAL9602](INFO): SBD MO Status=0, MOMSN=29953, MT Status=0, MTMSN=0
2019-07-24T16:17:16.567Z,1563985036.567 [NAL9602](INFO): No messages in MT queue
2019-07-24T16:17:17.389Z,1563985037.389 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:17:20.197Z,1563985040.197 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:17:23.033Z,1563985043.033 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:17:26.269Z,1563985046.269 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:17:29.073Z,1563985049.073 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:17:31.917Z,1563985051.917 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:17:35.149Z,1563985055.149 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:17:36.367Z,1563985056.367 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-24T16:12:36.2Z
2019-07-24T16:17:36.368Z,1563985056.368 [Default:CheckIn:Read_GPS] Stopped
2019-07-24T16:17:36.368Z,1563985056.368 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-24T16:17:45.496Z,1563985065.496 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T003100/Courier0424.lzma
2019-07-24T16:17:46.303Z,1563985066.303 [DataOverHttps](INFO): Moved sent file to Logs/20190724T003100/Courier0424.lzma.bak
2019-07-24T16:17:46.303Z,1563985066.303 [DataOverHttps](INFO): SBD MOMSN=11471414
2019-07-24T16:18:00.166Z,1563985080.166 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-07-24T16:18:00.166Z,1563985080.166 [DVL_micro] Communications Fault, FailCount= 1
2019-07-24T16:18:00.166Z,1563985080.166 [DVL_micro](ERROR): Communications Fault
2019-07-24T16:18:00.282Z,1563985080.282 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-07-24T16:18:00.472Z,1563985080.472 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T160857/Courier0000.lzma
2019-07-24T16:18:00.633Z,1563985080.633 [DVL_micro](INFO): uninitialize:Powering down
2019-07-24T16:18:01.278Z,1563985081.278 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0000.lzma.bak
2019-07-24T16:18:01.278Z,1563985081.278 [DataOverHttps](INFO): SBD MOMSN=11471416
2019-07-24T16:18:01.498Z,1563985081.498 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-24T16:18:01.498Z,1563985081.498 [DVL_micro] No Fault, FailCount= 1
2019-07-24T16:18:01.804Z,1563985081.804 [DVL_micro](INFO): Initializing
2019-07-24T16:18:07.847Z,1563985087.847 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-24T16:18:15.808Z,1563985095.808 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T160857/Courier0003.lzma
2019-07-24T16:18:16.614Z,1563985096.614 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0003.lzma.bak
2019-07-24T16:18:16.614Z,1563985096.614 [DataOverHttps](INFO): SBD MOMSN=11471419
2019-07-24T16:18:32.502Z,1563985112.502 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-24T16:18:32.502Z,1563985112.502 [DVL_micro] Data Fault, FailCount= 1
2019-07-24T16:18:32.502Z,1563985112.502 [DVL_micro](ERROR): Data Fault
2019-07-24T16:18:32.567Z,1563985112.567 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-24T16:18:32.977Z,1563985112.977 [DVL_micro](INFO): uninitialize:Powering down
2019-07-24T16:18:33.791Z,1563985113.791 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-24T16:18:33.791Z,1563985113.791 [DVL_micro] No Fault, FailCount= 1
2019-07-24T16:18:34.124Z,1563985114.124 [DVL_micro](INFO): Initializing
2019-07-24T16:18:38.040Z,1563985118.040 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T003100/Express0426.lzma
2019-07-24T16:18:38.847Z,1563985118.847 [DataOverHttps](INFO): Moved sent file to Logs/20190724T003100/Express0426.lzma.bak
2019-07-24T16:18:38.847Z,1563985118.847 [DataOverHttps](INFO): SBD MOMSN=11471421
2019-07-24T16:18:49.481Z,1563985129.481 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:18:49.481Z,1563985129.481 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0 0.2 1.3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.07 -1.5 0.2 18.3 0.005 35.0 1489 99
2019-07-24T16:18:52.718Z,1563985132.718 [DVL_micro](ERROR): only read 44 of 46 data items
2019-07-24T16:18:52.718Z,1563985132.718 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0008 1 1 1 1 0.2 0 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.11 -10.74 211.7 0.2 18.3 0.005 35.0 1489 100
2019-07-24T16:18:56.369Z,1563985136.369 [DataOverHttps](INFO): Sending 418 bytes from file Logs/20190724T160857/Express0001.lzma
2019-07-24T16:18:57.174Z,1563985137.174 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0001.lzma.bak
2019-07-24T16:18:57.174Z,1563985137.174 [DataOverHttps](INFO): SBD MOMSN=11471423
2019-07-24T16:19:06.442Z,1563985146.442 [DVL_micro](ERROR): only read 2 of 46 data items
2019-07-24T16:19:06.443Z,1563985146.443 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0001 0.2 0 0.2 1.5 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.04 -3.7 0.2 18.3 0.005 35.0 1489 98
2019-07-24T16:19:31.164Z,1563985171.164 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20190724T160857/Express0002.lzma
2019-07-24T16:19:31.984Z,1563985171.984 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0002.lzma.bak
2019-07-24T16:19:31.984Z,1563985171.984 [DataOverHttps](INFO): SBD MOMSN=11471429
2019-07-24T16:20:01.236Z,1563985201.236 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T160857/Express0004.lzma
2019-07-24T16:20:02.042Z,1563985202.042 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0004.lzma.bak
2019-07-24T16:20:02.043Z,1563985202.043 [DataOverHttps](INFO): SBD MOMSN=11471431
2019-07-24T16:20:07.696Z,1563985207.696 [Default:CheckIn:Read_Iridium] Stopped
2019-07-24T16:20:07.701Z,1563985207.701 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-24T16:20:07.701Z,1563985207.701 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-24T16:20:28.771Z,1563985228.771 [DVL_micro](ERROR): only read 4 of 46 data items
2019-07-24T16:20:28.772Z,1563985228.772 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X 1 1 0.2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.07 -10.78 222.4 0.2 18.3 0.005 35.0 1489 109
2019-07-24T16:21:35.047Z,1563985295.047 [DVL_micro](ERROR): only read 2 of 46 data items
2019-07-24T16:21:35.047Z,1563985295.047 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0.2 10.0 128.3 26.2 -383.7 -111.8 0 360 0 240 0 1 0 2 683.3 184.2 -92.0 1 -262.2 -662.0 47.4 1 0 160 0 0 0 0 0 0 3.01 -10.80 233.3 0.2 18.3 0.005 35.0 1489 89
2019-07-24T16:21:39.438Z,1563985299.438 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:21:39.438Z,1563985299.438 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 2.7 138.6 -46.7 -386.8 685.0 0 -210 0 0 0 1 0 0 701.2 -976.6 105.2 1 -1192.8 29.0 182.3 1 0 0 0 0 0 0 0 0 3.7 234.2 0.2 18.3 0.005 35.0 1489 105
2019-07-24T16:21:41.006Z,1563985301.006 [DVL_micro](ERROR): checksum mismatch: reported69 , calculated:74
2019-07-24T16:21:41.006Z,1563985301.006 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 2.8 137.2 36.9 -371.7 -22.8 0 -219 0 0 0 1 0 0 679.29.5 1 -328.1 -598.6 72.4 1 0 0 0 0 0 0 0 0 3.09 -10.74 234.6 0.2 18.4 0.005 35.0 1489 69
2019-07-24T16:21:42.658Z,1563985302.658 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:21:42.658Z,1563985302.658 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 10.1 136.6 -55.9 -374.0 -71.9 0 -89 0 -511 0 1 0 2 681.5 21.4 -98.5 1 -375.6 -576.7 32.4 1 0 563 0 0 0 0 0 0 3.04 -10.82 235.0 0.2 18.3 .0 1489 75
2019-07-24T16:21:50.702Z,1563985310.702 [DVL_micro](ERROR): checksum mismatch: reported71 , calculated:66
2019-07-24T16:21:50.703Z,1563985310.703 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.9 130.9 71.8 -382.7 503.9 0 43 0 0 0 1 0 0 685.5 -576.7 87.3 1 -849.9 -232.5 183.6 1 0 0 0 0 0 0 0 0 3.02 -10.79 236.8 0.2 18.3 0.005 35.0 1489 71
2019-07-24T16:22:14.935Z,1563985334.935 [DVL_micro](ERROR): only read 26 of 46 data items
2019-07-24T16:22:14.935Z,1563985334.935 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 .2 -60.0 1 0 0 0 0 0 0 0 0 3.10 -10.74 241.6 0.2 18.4 0.005 35.0 1489 76
2019-07-24T16:22:25.500Z,1563985345.500 [DVL_micro](ERROR): only read 4 of 46 data items
2019-07-24T16:22:25.505Z,1563985345.505 [DVL_micro](ERROR): Failed to parse:$#NQ.RES1 1 1 1 0.2 9.6 0.2 3.7 134.6 -69.7 -372.7 154.0 0 -405 0 0 0 1 0 0 677.1 -298.6 -41.5 1 -568.1 -471.1 68.6 1 0 0 0 0 0 0 0 0 3.05 -10.66 243.6 0.2 18.3 0.005 35.0 1489 108
2019-07-24T16:22:33.598Z,1563985353.598 [DVL_micro](ERROR): checksum mismatch: reported125 , calculated:123
2019-07-24T16:22:33.598Z,1563985353.598 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 3.6 134.5 -238.4 -381.9 -7.2 0 83 0 0 0 1 0 0308.6 -132.9 1 -575.1 -506.7 -19.2 1 0 0 0 0 0 0 0 0 3.03 -10.66 244.8 0.2 18.3 0.005 35.0 1489 125
2019-07-24T16:22:57.823Z,1563985377.823 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:22:57.823Z,1563985377.823 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 10.0 122.3 -192.1 -383.7 -14.9 0 30 1 0 1 675.3 -236.5 -126.3 1 -462.0 -560.7 -9.0 1 0 413 0 0 0 0 0 0 3.14 -10.91 249.2 0.2 18.4 0.005 35.0 1489 82
2019-07-24T16:23:26.183Z,1563985406.183 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:23:26.183Z,1563985406.183 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.6 0.2 10.0 129.2 26.0 -382.9 -124.9 0 238 0 -404 0 1 0 1 683.5 201.4 -95.1 1 -9.8 -717.6 41.1 1 0 856 0 0 0 0 0 0 3.09 -10.43.2 18.3 0.005 35.0 1489 123
2019-07-24T16:23:26.972Z,1563985406.972 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:23:26.972Z,1563985406.972 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.6 0.2 10.1 127.4 69.0 -370.3 -109.3 0 15 0 -541 0 1 0 2 664.2 238.0 -76.4 1 28.4 -706.6 59.1 1 0 742 0 0 0 0 0 0 3.13252.6 0.2 18.3 0.005 35.0 1489 90
2019-07-24T16:23:30.217Z,1563985410.217 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:23:30.217Z,1563985410.217 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.6 0.2 4.4 118.1 48.3 -383.4 -193.4 0 323 0 0 0 1 0 0 669.3 322.6 -110.7 1 110.2 -742.3 31.5 1 0 0 0 0 0 0 0 0 3.12 -2.8 0.2 18.3 0.005 35.0 1489 125
2019-07-24T16:25:06.355Z,1563985506.355 [DVL_micro](ERROR): checksum mismatch: reported102 , calculated:120
2019-07-24T16:25:06.355Z,1563985506.355 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 4.4 14.5 -367.0 -52.9 0 -19 0 0 0 1 0 0 671.1 -215.7 -134.5 1 -424.1 -578.5 -19.5 1 0 0 0 0 0 0 0 0 3.12 -10.67 250.9 0.2 18.4 0.005 35.0 1489 102
2019-07-24T16:25:08.125Z,1563985508.125 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-24T16:25:08.125Z,1563985508.125 [Default:CheckIn:C.Wait] Stopped
2019-07-24T16:25:08.125Z,1563985508.125 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-24T16:25:08.125Z,1563985508.125 [Default:CheckIn:D] Running Loop=1
2019-07-24T16:25:08.417Z,1563985508.417 [Default:CheckIn:D] Stopped
2019-07-24T16:25:08.417Z,1563985508.417 [Default:CheckIn:E] Running Loop=1
2019-07-24T16:25:08.873Z,1563985508.873 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.562091 min 
2019-07-24T16:25:08.873Z,1563985508.873 [Default:CheckIn:E] Stopped
2019-07-24T16:25:08.873Z,1563985508.873 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-24T16:25:08.874Z,1563985508.874 [Default:CheckIn] Stopped
2019-07-24T16:25:08.874Z,1563985508.874 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-24T16:25:08.874Z,1563985508.874 [Default:CheckIn](INFO): Running loop #3
2019-07-24T16:25:08.874Z,1563985508.874 [Default:CheckIn] Running Loop=3
2019-07-24T16:25:08.874Z,1563985508.874 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-24T16:25:08.874Z,1563985508.874 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-24T16:25:10.433Z,1563985510.433 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-24T16:25:10.434Z,1563985510.434 [NAL9602] Data Fault, FailCount= 1
2019-07-24T16:25:10.434Z,1563985510.434 [NAL9602](ERROR): Data Fault
2019-07-24T16:25:10.546Z,1563985510.546 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-24T16:25:10.794Z,1563985510.794 [NAL9602](INFO): Powering down
2019-07-24T16:25:11.690Z,1563985511.690 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-24T16:25:11.690Z,1563985511.690 [NAL9602] No Fault, FailCount= 1
2019-07-24T16:25:20.915Z,1563985520.915 [DVL_micro](ERROR): checksum mismatch: reported114 , calculated:124
2019-07-24T16:25:20.915Z,1563985520.915 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.6 0.2 4.4 139.1 -74.4 -379.2 435.6 0 -254 0 0 0 1 0 0 691.7 -680.7 372.9 -406.0 126.0 1 0 0 0 0 0 0 0 0 3.07 -10.87 250.3 0.2 18.4 0.005 35.0 1489 114
2019-07-24T16:25:23.338Z,1563985523.338 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:25:23.339Z,1563985523.339 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 4.4 121.3 -11.9 -382.0 479.6 0 311 0 0 0 1 0 0 671.7 -656.0 55.8 1 -842.6 -391.3 147.1 1 0 0 0 0 0 0 0 0 2.99 -10.86 250.3 0.2 18.45.0 1489 93
2019-07-24T16:25:30.594Z,1563985530.594 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:25:30.595Z,1563985530.595 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 4.4 136.4 66.3 -383.6 -630.0 0 502 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 3.04 -10.83 249.9 0.2 18.35.0 1489 74
2019-07-24T16:25:41.143Z,1563985541.143 [NAL9602](INFO): Powering up NAL9602
2019-07-24T16:25:52.007Z,1563985552.007 [NAL9602](INFO): NAL9602 initialized
2019-07-24T16:25:52.837Z,1563985552.837 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:25:56.470Z,1563985556.470 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:25:56.470Z,1563985556.470 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.4 0.2 9.9 134.2 939.5 -381.6 868.9 0 5 0 -182 0 1 0 1 688.4 94.2 420.9 1 -161.7 -578.5 546.9 1 0 249 0 0 0 0 0 0 3.09247.9 0.2 18.3 0.005 35.0 1489 65
2019-07-24T16:25:58.074Z,1563985558.074 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-24T16:25:58.074Z,1563985558.074 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 10.1 132.4 326.0 -383.8 -7.2 0 -306 0 -459 0 1 0 2 688.9 444.7 18.1 1 154.7 -787.3 170.2 1 0 204 0 0 3.06 -10.77 247.9 0.2 18.3 0.005 35.0 1489 91
2019-07-24T16:26:18.390Z,1563985578.390 [DVL_micro](ERROR): only read 38 of 46 data items
2019-07-24T16:26:18.390Z,1563985578.390 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 10.1 124.2 2219.8 -389.1 125.7 0 -580 -1418.7 0 0 0 0 0 0 0 -1418 0 0 0 0 0 0 3.09 -10.62 246.2 0.2005 35.0 1489 108
2019-07-24T16:26:35.758Z,1563985595.758 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:26:35.758Z,1563985595.758 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:27:11.346Z,1563985631.346 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:27:11.346Z,1563985631.346 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:27:14.136Z,1563985634.136 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:27:14.136Z,1563985634.136 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 3.8 138.5 -68.2 -378.7 -214.4 0 32 0 0 0 1 0 0 690.3 195.1 -141.0 1 -147.2 -716.1 0.4 1 0 0 0 0 0 0 0 0 3.05 -10.72 242.6 0.2 18.35.0 1489 121
2019-07-24T16:27:28.747Z,1563985648.747 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:27:28.747Z,1563985648.747 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:27:30.298Z,1563985650.298 [DVL_micro](ERROR): checksum mismatch: reported126 , calculated:114
2019-07-24T16:27:30.299Z,1563985650.299 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 3.8 143.4 -36.6 -3920 0 135 0 0 0 1 0 0 714.8 319.5 -151.4 1 -53.8 -795.6 3.1 1 0 0 0 0 0 0 0 0 3.08 -10.84 242.2 0.2 18.4 0.005 35.0 1489 126
2019-07-24T16:27:37.162Z,1563985657.162 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:27:37.162Z,1563985657.162 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:27:45.731Z,1563985665.731 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:27:45.731Z,1563985665.731 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:27:53.835Z,1563985673.835 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:27:53.836Z,1563985673.836 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:27:58.627Z,1563985678.627 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:27:58.627Z,1563985678.627 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.6 0.2 9.8 127.4 -70.9 -387.7 2263.5 0 184 0 407 0 1 0 1 687.5 -3110 1 -3059.3 929.7 475.2 1 0 -297 0 0 0 0 0 0 3.03 -10.77 242.4 0.2 05 35.0 1489 86
2019-07-24T16:28:11.134Z,1563985691.134 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:28:11.135Z,1563985691.135 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:28:28.527Z,1563985708.527 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:28:28.527Z,1563985708.527 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:28:36.653Z,1563985716.653 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:28:36.654Z,1563985716.654 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:28:39.027Z,1563985719.027 [DVL_micro](ERROR): checksum mismatch: reported121 , calculated:122
2019-07-24T16:28:39.027Z,1563985719.027 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.7 0.2 10.0 132.7 40.9 -387.4 25.8 0 -337 0 254 0 1 0 2 694.1 20.1 -308.6 -619.0 80.0 1 0 -788 0 0 0 0 0 0 3.08 -10.69 241.9 0.2 18.4 0.005 35.0 1489 121
2019-07-24T16:28:50.354Z,1563985730.354 [DVL_micro](ERROR): checksum mismatch: reported89 , calculated:83
2019-07-24T16:28:50.354Z,1563985730.354 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 3.8 124.4 -524.2 -386.3 -351.9 0 -534 0 0 0 1 0 0230.0 -306.9 1 -536.5 -537.2 -187.4 1 0 0 0 0 0 0 0 0 3.15 -10.68 241.6 0.2 18.4 0.005 35.0 1489 89
2019-07-24T16:29:02.046Z,1563985742.046 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:29:02.046Z,1563985742.046 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:29:18.609Z,1563985758.609 [DVL_micro](ERROR): only read 4 of 46 data items
2019-07-24T16:29:18.610Z,1563985758.610 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 01 1 1 0.2 9.6 0.2 10.0 138.0 -325.7 -371.1 41.0 0 550 0 617 0 1 0 2 679.5 -489.4 -139.6 1 -760.7 -375.1 -36.5 1 0 -89 0 0 0 0 0 0 3.06 -10.74 241.1 0.2 18.3 0.005 35.0 1489 118
2019-07-24T16:29:21.448Z,1563985761.448 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:29:21.448Z,1563985761.448 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:30:09.165Z,1563985809.165 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-24T16:25:08.9Z
2019-07-24T16:30:09.165Z,1563985809.165 [Default:CheckIn:Read_GPS] Stopped
2019-07-24T16:30:09.166Z,1563985809.166 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-24T16:30:21.305Z,1563985821.305 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T160857/Courier0005.lzma
2019-07-24T16:30:22.616Z,1563985822.616 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0005.lzma.bak
2019-07-24T16:30:22.616Z,1563985822.616 [DataOverHttps](INFO): SBD MOMSN=11471442
2019-07-24T16:30:30.192Z,1563985830.192 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:30:30.192Z,1563985830.192 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:30:47.175Z,1563985847.175 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:30:47.175Z,1563985847.175 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:30:50.141Z,1563985850.141 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20190724T160857/Express0007.lzma
2019-07-24T16:30:50.946Z,1563985850.946 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0007.lzma.bak
2019-07-24T16:30:50.946Z,1563985850.946 [DataOverHttps](INFO): SBD MOMSN=11471444
2019-07-24T16:30:55.222Z,1563985855.222 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-24T16:30:58.136Z,1563985858.136 [Default:CheckIn:Read_Iridium] Stopped
2019-07-24T16:30:58.136Z,1563985858.136 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-24T16:30:58.136Z,1563985858.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-24T16:31:05.775Z,1563985865.775 [DVL_micro](ERROR): checksum mismatch: reported79 , calculated:93
2019-07-24T16:31:05.775Z,1563985865.775 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 3.8 138.5 81.6 -367.3 36 0 0 0 1 0 0 675.1 -384.2 59.9 1 -643.3 -408.0 163.1 1 0 0 0 0 0 0 0 0 3.05 -10.65 243.2 0.2 18.3 0.005 35.0 1489 79
2019-07-24T16:31:25.942Z,1563985885.942 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-24T16:32:03.880Z,1563985923.880 [DVL_micro](ERROR): checksum mismatch: reported122 , calculated:112
2019-07-24T16:32:03.880Z,1563985923.880 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 5 0.2 10.0 130.4 -239.6 -376.3 163.5 0 -31 0 -243 0 1 0 2 676.3 -538.0 -86.8 1 -759.0 -422.2 12.0 1 0 282 0 0 0 0 0 0 3.12 -10.77 247.2 0.2 18.4 0.005 35.0 1489 122
2019-07-24T16:32:13.582Z,1563985933.582 [DVL_micro](ERROR): checksum mismatch: reported123 , calculated:121
2019-07-24T16:32:13.583Z,1563985933.583 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.7 0.2 10.1 122.7 288.2 -371.0 62.6 0 -178 0 -565 0 1 0 2 658.9 3011 34.3 -704.9 165.9 1 0 516 0 0 0 0 0 0 3.06 -10.74 248.0 0.2 18.4 0.005 35.0 1489 123
2019-07-24T16:34:18.138Z,1563986058.138 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-07-24T16:34:18.138Z,1563986058.138 [DVL_micro] Communications Fault, FailCount= 1
2019-07-24T16:34:18.138Z,1563986058.138 [DVL_micro](ERROR): Communications Fault
2019-07-24T16:34:18.293Z,1563986058.293 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-07-24T16:34:18.617Z,1563986058.617 [DVL_micro](INFO): uninitialize:Powering down
2019-07-24T16:34:19.408Z,1563986059.408 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-24T16:34:19.408Z,1563986059.408 [DVL_micro] No Fault, FailCount= 1
2019-07-24T16:34:19.759Z,1563986059.759 [DVL_micro](INFO): Initializing
2019-07-24T16:34:31.894Z,1563986071.894 [DVL_micro](ERROR): checksum mismatch: reported82 , calculated:73
2019-07-24T16:34:31.895Z,1563986071.895 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.6 0.2 10 -18.0 -396.9 365.7 0 544 0 58 0 1 0 2 705.8 -512.1 22.3 1 -681.2 -529.8 126.9 1 0 648 0 0 0 0 0 0 3.05 -10.80 254.6 0.2 18.4 0.005 35.0 1489 82
2019-07-24T16:35:01.797Z,1563986101.797 [DVL_micro](ERROR): checksum mismatch: reported126 , calculated:106
2019-07-24T16:35:01.798Z,1563986101.798 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.4 0.2 10.1 136.0 675.1 -390.4 283.5 0 -54 0 448 0 1 0 2 702.6 528 1 318.1 -763.5 344.3 1 0 -670 0 0 0 0 0 0 3.05 -10.69 254.7 0.2 18.4 0.005 35.0 1489 126
2019-07-24T16:35:30.886Z,1563986130.886 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:35:30.886Z,1563986130.886 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 10.1 127.9 183.6 -382.1 -236.1 0 808 0 -343 0 1 0 2 0 1536.2 0 0 0 0 0 0 0 1536 0 0 0 0 0 0 3.07 -10.72 255.4 0.2 18.3 0.005 35.0 1489 118
2019-07-24T16:35:58.772Z,1563986158.772 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-24T16:35:58.772Z,1563986158.772 [Default:CheckIn:C.Wait] Stopped
2019-07-24T16:35:58.773Z,1563986158.773 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-24T16:35:58.773Z,1563986158.773 [Default:CheckIn:D] Running Loop=1
2019-07-24T16:35:59.216Z,1563986159.216 [Default:CheckIn:D] Stopped
2019-07-24T16:35:59.216Z,1563986159.216 [Default:CheckIn:E] Running Loop=1
2019-07-24T16:35:59.566Z,1563986159.566 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.408883 min 
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn:E] Stopped
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn] Stopped
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn](INFO): Running loop #4
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn] Running Loop=4
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-24T16:35:59.567Z,1563986159.567 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-24T16:36:01.164Z,1563986161.164 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-24T16:36:01.164Z,1563986161.164 [NAL9602] Data Fault, FailCount= 2
2019-07-24T16:36:01.164Z,1563986161.164 [NAL9602](ERROR): Data Fault
2019-07-24T16:36:01.201Z,1563986161.201 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-24T16:36:01.592Z,1563986161.592 [NAL9602](INFO): Powering down
2019-07-24T16:36:02.517Z,1563986162.517 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-24T16:36:02.517Z,1563986162.517 [NAL9602] No Fault, FailCount= 2
2019-07-24T16:36:31.921Z,1563986191.921 [NAL9602](INFO): Powering up NAL9602
2019-07-24T16:36:42.836Z,1563986202.836 [NAL9602](INFO): NAL9602 initialized
2019-07-24T16:36:43.685Z,1563986203.685 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:37:13.930Z,1563986233.930 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:37:13.930Z,1563986233.930 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:37:22.460Z,1563986242.460 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:37:22.460Z,1563986242.460 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:37:28.911Z,1563986248.911 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:37:28.912Z,1563986248.912 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:37:42.637Z,1563986262.637 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:37:42.638Z,1563986262.638 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:37:58.370Z,1563986278.370 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:37:58.370Z,1563986278.370 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:38:16.956Z,1563986296.956 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:38:16.956Z,1563986296.956 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:38:33.942Z,1563986313.942 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:38:33.942Z,1563986313.942 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:38:42.832Z,1563986322.832 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:38:42.832Z,1563986322.832 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:39:01.023Z,1563986341.023 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:39:01.023Z,1563986341.023 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:39:17.207Z,1563986357.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:39:17.207Z,1563986357.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:39:29.688Z,1563986369.688 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:39:29.688Z,1563986369.688 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:40:00.815Z,1563986400.815 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:40:00.816Z,1563986400.816 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:40:34.335Z,1563986434.335 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:40:34.335Z,1563986434.335 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:40:59.837Z,1563986459.837 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-24T16:35:59.6Z
2019-07-24T16:40:59.837Z,1563986459.837 [Default:CheckIn:Read_GPS] Stopped
2019-07-24T16:40:59.837Z,1563986459.837 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-24T16:41:07.920Z,1563986467.920 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T160857/Courier0009.lzma
2019-07-24T16:41:07.953Z,1563986467.953 [DVL_micro](ERROR): only read 45 of 46 data items
2019-07-24T16:41:07.953Z,1563986467.953 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.6 0.2 19 55.3 -400.5 547.3 0 -740 0 22 0 1 0 2 709.2 -656.6 89.8 1 -532.5 -790.5 0 -1017 0 0 0 0 0 0 3.09 -10.66 280.2 0.2 18.3 0.005 35.0 1489 71
2019-07-24T16:41:08.733Z,1563986468.733 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0009.lzma.bak
2019-07-24T16:41:08.733Z,1563986468.733 [DataOverHttps](INFO): SBD MOMSN=11471460
2019-07-24T16:41:28.309Z,1563986488.309 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20190724T160857/Express0010.lzma
2019-07-24T16:41:29.114Z,1563986489.114 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0010.lzma.bak
2019-07-24T16:41:29.114Z,1563986489.114 [DataOverHttps](INFO): SBD MOMSN=11471462
2019-07-24T16:41:30.572Z,1563986490.572 [DVL_micro](ERROR): only read 3 of 46 data items
2019-07-24T16:41:30.573Z,1563986490.573 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X01 1 0.2 10.0 131.5 98.7 -404.1 -348.3 0 -77 0 -577 0 1 0 1 714.8 596.6 -140.8 1 701.4 -627.7 24.5 1 0 667 0 0 0 0 0 0 3.07 -10.55 278.6 0.2 18.3 0.005 35.0 1489 118
2019-07-24T16:41:34.206Z,1563986494.206 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:41:34.206Z,1563986494.206 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:41:37.259Z,1563986497.259 [Default:CheckIn:Read_Iridium] Stopped
2019-07-24T16:41:37.259Z,1563986497.259 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-24T16:41:37.259Z,1563986497.259 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-24T16:41:46.750Z,1563986506.750 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-24T16:42:17.454Z,1563986537.454 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-24T16:42:53.796Z,1563986573.796 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-24T16:42:53.796Z,1563986573.796 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.4 0.2 10.1 132.2 -989.4 -390.3 71.7 0 357 0 158 0 265.6 0 0 0 0 0 0 0 265 0 0 0 0 0 0 3.01 -10.94 265.1 0.2 18.4 0.005 35.0 1489 96
2019-07-24T16:43:50.436Z,1563986630.436 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-24T16:43:50.436Z,1563986630.436 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2019-07-24T16:43:50.437Z,1563986630.437 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-07-24T16:43:50.440Z,1563986630.440 [BPC1](FAULT): Failed to receive data from 2 sticks prior to timeout. Missing stick IDs are: 38, 39.
2019-07-24T16:43:50.440Z,1563986630.440 [BPC1] Data Fault, FailCount= 10
2019-07-24T16:43:50.440Z,1563986630.440 [BPC1](ERROR): Data Fault
2019-07-24T16:43:50.470Z,1563986630.470 [CBIT](ERROR): Data Fault in component: BPC1
2019-07-24T16:43:50.470Z,1563986630.470 [CBIT](CRITICAL): Data Fault in component: BPC1
2019-07-24T16:43:50.829Z,1563986630.829 [CBIT](INFO): Critical error at 20190724T164350
2019-07-24T16:43:50.829Z,1563986630.829 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-07-24T16:46:37.684Z,1563986797.684 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-24T16:46:37.684Z,1563986797.684 [Default:CheckIn:C.Wait] Stopped
2019-07-24T16:46:37.684Z,1563986797.684 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-24T16:46:37.689Z,1563986797.689 [Default:CheckIn:D] Running Loop=1
2019-07-24T16:46:38.034Z,1563986798.034 [Default:CheckIn:D] Stopped
2019-07-24T16:46:38.034Z,1563986798.034 [Default:CheckIn:E] Running Loop=1
2019-07-24T16:46:38.461Z,1563986798.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.055843 min 
2019-07-24T16:46:38.461Z,1563986798.461 [Default:CheckIn:E] Stopped
2019-07-24T16:46:38.461Z,1563986798.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-24T16:46:38.461Z,1563986798.461 [Default:CheckIn] Stopped
2019-07-24T16:46:38.461Z,1563986798.461 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-24T16:46:38.462Z,1563986798.462 [Default:CheckIn](INFO): Running loop #5
2019-07-24T16:46:38.462Z,1563986798.462 [Default:CheckIn] Running Loop=5
2019-07-24T16:46:38.462Z,1563986798.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-24T16:46:38.462Z,1563986798.462 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-24T16:46:40.065Z,1563986800.065 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:46:40.440Z,1563986800.440 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164456.00,A,3648.15428,N,12147.28272,W,0.175,336.40,240719,,,A*7F
2019-07-24T16:46:40.451Z,1563986800.451 [NAL9602](INFO): GPS fix at 20190724T164456: (36.802571, -121.788045)
2019-07-24T16:46:40.490Z,1563986800.490 [UniversalFixResidualReporter](INFO): Fix residual: 56.4 %DT, over the last 3757.6 m. Residual distance 2120.3 m at bearing 121.4 degrees. Fix at (36.8026, -121.7880) with 13.5 m made good.
2019-07-24T16:46:40.491Z,1563986800.491 [Default:CheckIn:Read_GPS] Stopped
2019-07-24T16:46:40.491Z,1563986800.491 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-24T16:46:48.946Z,1563986808.946 [DVL_micro](ERROR): only read 43 of 46 data items
2019-07-24T16:46:48.947Z,1563986808.947 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.5 0.2 10.0 138.6 91.7 11.6 0 239 0 638 0 1 0 1 697.6 -26.6 -11.4 1 -46.3 -687.0 115.3 1 0 -532 0 0 0.14 -10.57 268.6 0.2 18.3 0.005 35.0 1489 75
2019-07-24T16:46:49.261Z,1563986809.261 [DataOverHttps](INFO): Sending 406 bytes from file Logs/20190724T160857/Courier0012.lzma
2019-07-24T16:46:50.066Z,1563986810.066 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0012.lzma.bak
2019-07-24T16:46:50.066Z,1563986810.066 [DataOverHttps](INFO): SBD MOMSN=11471477
2019-07-24T16:46:53.778Z,1563986813.778 [DVL_micro](ERROR): checksum mismatch: reported110 , calculated:120
2019-07-24T16:46:53.779Z,1563986813.779 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 0 0.2 9.5 0.2 0 135.4 237.6 -381.9 0 0 -254 0 -357 0 1 0 2 690.4 963.2 -941.7 -729.9 48.1 1 0 137 0 0 0 0 0 0 3.08 -10.60 268.1 0.2 18.3 0.005 35.0 1489 110
2019-07-24T16:47:03.069Z,1563986823.069 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:47:03.069Z,1563986823.069 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:47:08.233Z,1563986828.233 [DataOverHttps](INFO): Sending 311 bytes from file Logs/20190724T160857/Express0013.lzma
2019-07-24T16:47:09.038Z,1563986829.038 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0013.lzma.bak
2019-07-24T16:47:09.038Z,1563986829.038 [DataOverHttps](INFO): SBD MOMSN=11471481
2019-07-24T16:47:14.437Z,1563986834.437 [Default:CheckIn:Read_Iridium] Stopped
2019-07-24T16:47:14.437Z,1563986834.437 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-24T16:47:14.437Z,1563986834.437 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-24T16:47:31.358Z,1563986851.358 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:47:31.358Z,1563986851.358 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:47:39.430Z,1563986859.430 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:47:39.431Z,1563986859.431 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:48:06.088Z,1563986886.088 [NAL9602](INFO): SBD MO Status=2, MOMSN=29954, MT Status=2, MTMSN=0
2019-07-24T16:48:06.088Z,1563986886.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-07-24T16:51:42.641Z,1563987102.641 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-24T16:52:13.340Z,1563987133.340 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-24T16:52:14.983Z,1563987134.983 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-24T16:52:14.984Z,1563987134.984 [Default:CheckIn:C.Wait] Stopped
2019-07-24T16:52:14.984Z,1563987134.984 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-24T16:52:14.984Z,1563987134.984 [Default:CheckIn:D] Running Loop=1
2019-07-24T16:52:15.405Z,1563987135.405 [Default:CheckIn:D] Stopped
2019-07-24T16:52:15.405Z,1563987135.405 [Default:CheckIn:E] Running Loop=1
2019-07-24T16:52:15.793Z,1563987135.793 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.678691 min 
2019-07-24T16:52:15.793Z,1563987135.793 [Default:CheckIn:E] Stopped
2019-07-24T16:52:15.794Z,1563987135.794 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-24T16:52:15.794Z,1563987135.794 [Default:CheckIn] Stopped
2019-07-24T16:52:15.794Z,1563987135.794 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-24T16:52:15.794Z,1563987135.794 [Default:CheckIn](INFO): Running loop #6
2019-07-24T16:52:15.794Z,1563987135.794 [Default:CheckIn] Running Loop=6
2019-07-24T16:52:15.794Z,1563987135.794 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-24T16:52:15.794Z,1563987135.794 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-24T16:52:17.393Z,1563987137.393 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:52:17.798Z,1563987137.798 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165033.00,A,3648.16003,N,12147.28387,W,0.136,336.40,240719,,,A*7B
2019-07-24T16:52:17.800Z,1563987137.800 [NAL9602](INFO): GPS fix at 20190724T165033: (36.802667, -121.788065)
2019-07-24T16:52:17.824Z,1563987137.824 [Default:CheckIn:Read_GPS] Stopped
2019-07-24T16:52:17.824Z,1563987137.824 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-24T16:52:27.388Z,1563987147.388 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190724T160857/Courier0015.lzma
2019-07-24T16:52:28.195Z,1563987148.195 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0015.lzma.bak
2019-07-24T16:52:28.195Z,1563987148.195 [DataOverHttps](IMPORTANT): SBD MOMSN=11471526, MTMSN=20190724T165043
2019-07-24T16:52:41.505Z,1563987161.505 [DataOverHttps](INFO): Received command:configSet BPC1.batteryMissingStickThreshold 2 count persist
2019-07-24T16:52:41.785Z,1563987161.785 [CommandLine](IMPORTANT): got command configSet BPC1.batteryMissingStickThreshold 2.000000 count persist
2019-07-24T16:52:47.773Z,1563987167.773 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20190724T160857/Express0016.lzma
2019-07-24T16:52:48.506Z,1563987168.506 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-07-24T16:52:48.578Z,1563987168.578 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0016.lzma.bak
2019-07-24T16:52:48.579Z,1563987168.579 [DataOverHttps](INFO): SBD MOMSN=11471530
2019-07-24T16:52:48.593Z,1563987168.593 [NAL9602](FAULT): received: 
+CSQ:0

OK954, 2, 0, 0, 0

OK
2019-07-24T16:52:48.593Z,1563987168.593 [NAL9602] Data Fault, FailCount= 3
2019-07-24T16:52:48.593Z,1563987168.593 [NAL9602](ERROR): Data Fault
2019-07-24T16:52:48.661Z,1563987168.661 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-24T16:52:48.886Z,1563987168.886 [NAL9602](INFO): Powering down
2019-07-24T16:52:49.753Z,1563987169.753 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-24T16:52:49.753Z,1563987169.753 [NAL9602] No Fault, FailCount= 3
2019-07-24T16:53:03.243Z,1563987183.243 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T160857/Courier0018.lzma
2019-07-24T16:53:04.047Z,1563987184.047 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0018.lzma.bak
2019-07-24T16:53:04.047Z,1563987184.047 [DataOverHttps](IMPORTANT): SBD MOMSN=11471535, MTMSN=20190724T165119
2019-07-24T16:53:15.912Z,1563987195.912 [DataOverHttps](INFO): Received command:configSet VerticalControl.buoyancyNeutral 200 cc persist
2019-07-24T16:53:16.227Z,1563987196.227 [CommandLine](IMPORTANT): got command configSet VerticalControl.buoyancyNeutral 200.000000 cubic_centimeter persist
2019-07-24T16:53:19.218Z,1563987199.218 [NAL9602](INFO): Powering up NAL9602
2019-07-24T16:53:22.200Z,1563987202.200 [DataOverHttps](INFO): Sending 211 bytes from file Logs/20190724T160857/Express0019.lzma
2019-07-24T16:53:23.006Z,1563987203.006 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0019.lzma.bak
2019-07-24T16:53:23.006Z,1563987203.006 [DataOverHttps](INFO): SBD MOMSN=11471538
2019-07-24T16:53:27.284Z,1563987207.284 [DVL_micro](ERROR): only read 12 of 46 data items
2019-07-24T16:53:27.285Z,1563987207.285 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 1 1 1 1 0.2 9.7 0.2 5.0 161.1 775.6 -412.5 --173 0 0 0 1 0 0 765.5 1694.2 8.2 1 -1425.5 1177.4 194.6 1 0 0 0 0 0 0 0 0 6.294.9 0.2 18.3 0.005 35.0 1489 64
2019-07-24T16:53:30.096Z,1563987210.096 [NAL9602](INFO): NAL9602 initialized
2019-07-24T16:53:38.472Z,1563987218.472 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190724T160857/Courier0021.lzma
2019-07-24T16:53:39.278Z,1563987219.278 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0021.lzma.bak
2019-07-24T16:53:39.278Z,1563987219.278 [DataOverHttps](INFO): SBD MOMSN=11471542
2019-07-24T16:53:51.568Z,1563987231.568 [CBIT](INFO): Clearing failed state for component BPC1
2019-07-24T16:53:51.568Z,1563987231.568 [BPC1] No Fault, FailCount= 10
2019-07-24T16:53:56.257Z,1563987236.257 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20190724T160857/Express0022.lzma
2019-07-24T16:53:57.062Z,1563987237.062 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0022.lzma.bak
2019-07-24T16:53:57.062Z,1563987237.062 [DataOverHttps](INFO): SBD MOMSN=11471544
2019-07-24T16:54:01.232Z,1563987241.232 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-24T16:54:02.908Z,1563987242.908 [Default:CheckIn:Read_Iridium] Stopped
2019-07-24T16:54:02.917Z,1563987242.917 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-24T16:54:02.917Z,1563987242.917 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-24T16:57:26.880Z,1563987446.880 [CBIT](FAULT): WATER ALARM AUX.
2019-07-24T16:57:26.881Z,1563987446.881 [CBIT](ERROR): WATER DETECTED IN PRESSURE HULL. Alarm Count: 1
2019-07-24T16:57:27.277Z,1563987447.277 [CBIT](FAULT): WATER ALARM AUX.
2019-07-24T16:57:27.277Z,1563987447.277 [CBIT](ERROR): WATER DETECTED IN PRESSURE HULL. Alarm Count: 2
2019-07-24T16:57:27.746Z,1563987447.746 [CBIT](FAULT): WATER ALARM AUX.
2019-07-24T16:57:27.746Z,1563987447.746 [CBIT](ERROR): WATER DETECTED IN PRESSURE HULL. Alarm Count: 3
2019-07-24T16:57:28.104Z,1563987448.104 [CBIT](FAULT): WATER ALARM AUX.
2019-07-24T16:57:28.117Z,1563987448.117 [CBIT](CRITICAL): WATER DETECTED IN PRESSURE HULL. BURNWIRE ACTIVATED
2019-07-24T16:57:28.119Z,1563987448.119 [CBIT](IMPORTANT): Powered off ESP with command: ! echo 0 > /dev/loadA6
2019-07-24T16:57:28.142Z,1563987448.142 [CommandLine](IMPORTANT): got command ! echo 0 > /dev/loadA6
2019-07-24T16:57:28.519Z,1563987448.519 [CBIT](INFO): Critical error at 20190724T165728
2019-07-24T16:58:44.870Z,1563987524.870 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-07-24T16:58:44.870Z,1563987524.870 [DVL_micro] Data Fault, FailCount= 1
2019-07-24T16:58:44.870Z,1563987524.870 [DVL_micro](ERROR): Data Fault
2019-07-24T16:58:44.935Z,1563987524.935 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-07-24T16:58:45.337Z,1563987525.337 [DVL_micro](INFO): uninitialize:Powering down
2019-07-24T16:58:46.110Z,1563987526.110 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-07-24T16:58:46.110Z,1563987526.110 [DVL_micro] No Fault, FailCount= 1
2019-07-24T16:58:46.492Z,1563987526.492 [DVL_micro](INFO): Initializing
2019-07-24T16:59:03.485Z,1563987543.485 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-24T16:59:03.485Z,1563987543.485 [Default:CheckIn:C.Wait] Stopped
2019-07-24T16:59:03.485Z,1563987543.485 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-24T16:59:03.485Z,1563987543.485 [Default:CheckIn:D] Running Loop=1
2019-07-24T16:59:03.916Z,1563987543.916 [Default:CheckIn:D] Stopped
2019-07-24T16:59:03.916Z,1563987543.916 [Default:CheckIn:E] Running Loop=1
2019-07-24T16:59:04.314Z,1563987544.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.487211 min 
2019-07-24T16:59:04.314Z,1563987544.314 [Default:CheckIn:E] Stopped
2019-07-24T16:59:04.314Z,1563987544.314 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-24T16:59:04.315Z,1563987544.315 [Default:CheckIn] Stopped
2019-07-24T16:59:04.315Z,1563987544.315 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-24T16:59:04.315Z,1563987544.315 [Default:CheckIn](INFO): Running loop #7
2019-07-24T16:59:04.315Z,1563987544.315 [Default:CheckIn] Running Loop=7
2019-07-24T16:59:04.315Z,1563987544.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-24T16:59:04.315Z,1563987544.315 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-24T16:59:05.905Z,1563987545.905 [NAL9602](DEBUG): Fix Requested
2019-07-24T16:59:06.302Z,1563987546.302 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165721.00,A,3648.16871,N,12147.28074,W,0.622,0.00,240719,,,A*7D
2019-07-24T16:59:06.305Z,1563987546.305 [NAL9602](INFO): GPS fix at 20190724T165721: (36.802812, -121.788012)
2019-07-24T16:59:06.354Z,1563987546.354 [Default:CheckIn:Read_GPS] Stopped
2019-07-24T16:59:06.354Z,1563987546.354 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-24T16:59:08.394Z,1563987548.394 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-24T16:59:14.328Z,1563987554.328 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20190724T160857/Courier0024.lzma
2019-07-24T16:59:15.135Z,1563987555.135 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Courier0024.lzma.bak
2019-07-24T16:59:15.136Z,1563987555.136 [DataOverHttps](INFO): SBD MOMSN=11471584
2019-07-24T16:59:37.421Z,1563987577.421 [DataOverHttps](INFO): Sending 334 bytes from file Logs/20190724T160857/Express0025.lzma
2019-07-24T16:59:38.227Z,1563987578.227 [DataOverHttps](INFO): Moved sent file to Logs/20190724T160857/Express0025.lzma.bak
2019-07-24T16:59:38.227Z,1563987578.227 [DataOverHttps](INFO): SBD MOMSN=11471588
2019-07-24T16:59:39.128Z,1563987579.128 [NAL9602](INFO): Not Powering down - fast GPS
2019-07-24T16:59:43.747Z,1563987583.747 [Default:CheckIn:Read_Iridium] Stopped
2019-07-24T16:59:43.747Z,1563987583.747 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-24T16:59:43.748Z,1563987583.748 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-24T17:00:02.598Z,1563987602.598 [DataOverHttps](IMPORTANT): SBD MTMSN=20190724T165817
2019-07-24T17:00:08.992Z,1563987608.992 [DataOverHttps](INFO): Received command:restart sys
2019-07-24T17:00:09.014Z,1563987609.014 [CommandLine](IMPORTANT): got command restart system
2019-07-24T17:00:11.117Z,1563987611.117 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:11.117Z,1563987611.117 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.225Z,1563987611.225 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-07-24T17:00:11.225Z,1563987611.225 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.226Z,1563987611.226 [CommandLine](INFO): Join timeout helper Thread ID is 4224
2019-07-24T17:00:11.227Z,1563987611.227 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-07-24T17:00:11.227Z,1563987611.227 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.227Z,1563987611.227 [NavChartDb](INFO): Join timeout helper Thread ID is 4225
2019-07-24T17:00:11.517Z,1563987611.517 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:11.517Z,1563987611.517 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.525Z,1563987611.525 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-07-24T17:00:11.525Z,1563987611.525 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.525Z,1563987611.525 [Radio_Surface](INFO): Join timeout helper Thread ID is 4226
2019-07-24T17:00:11.561Z,1563987611.561 [Radio_Surface](INFO): Powering down
2019-07-24T17:00:11.562Z,1563987611.562 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:11.562Z,1563987611.562 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.565Z,1563987611.565 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-07-24T17:00:11.565Z,1563987611.565 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.565Z,1563987611.565 [DataOverHttps](INFO): Join timeout helper Thread ID is 4227
2019-07-24T17:00:11.817Z,1563987611.817 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:11.817Z,1563987611.817 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.825Z,1563987611.825 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-07-24T17:00:11.825Z,1563987611.825 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:11.825Z,1563987611.825 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4228
2019-07-24T17:00:12.129Z,1563987612.129 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:12.130Z,1563987612.130 [WetLabsBB2FL](INFO): Powering down
2019-07-24T17:00:12.130Z,1563987612.130 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:12.162Z,1563987612.162 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-07-24T17:00:12.162Z,1563987612.162 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:12.162Z,1563987612.162 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4229
2019-07-24T17:00:12.705Z,1563987612.705 [CTD_Seabird](INFO): Powering down
2019-07-24T17:00:12.717Z,1563987612.717 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:12.717Z,1563987612.717 [CTD_Seabird](INFO): Powering down
2019-07-24T17:00:12.729Z,1563987612.729 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:12.737Z,1563987612.737 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-07-24T17:00:12.738Z,1563987612.738 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:12.738Z,1563987612.738 [logger](INFO): Join timeout helper Thread ID is 4230
2019-07-24T17:00:12.769Z,1563987612.769 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:12.769Z,1563987612.769 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:12.777Z,1563987612.777 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-07-24T17:00:12.778Z,1563987612.778 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:12.778Z,1563987612.778 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-07-24T17:00:12.778Z,1563987612.778 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:12.778Z,1563987612.778 [controlThread](INFO): Join timeout helper Thread ID is 4231
2019-07-24T17:00:12.805Z,1563987612.805 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-24T17:00:12.805Z,1563987612.805 [controlThread](DEBUG): Uninitializing ControlThread
2019-07-24T17:00:12.806Z,1563987612.806 [Aanderaa_O2](INFO): Powering down
2019-07-24T17:00:12.829Z,1563987612.829 [AHRS_M2](INFO): Powering down
2019-07-24T17:00:12.973Z,1563987612.973 [DVL_micro](INFO): uninitialize:Powering down
2019-07-24T17:00:12.974Z,1563987612.974 [NAL9602](INFO): Powering down
2019-07-24T17:00:12.975Z,1563987612.975 [DAT](INFO): Powering down
2019-07-24T17:00:13.094Z,1563987613.094 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-07-24T17:00:13.095Z,1563987613.095 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-07-24T17:00:13.095Z,1563987613.095 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-07-24T17:00:13.096Z,1563987613.096 [MissionManager](INFO): Uninitializing Mission Default
2019-07-24T17:00:13.096Z,1563987613.096 [Default] Stopped
2019-07-24T17:00:13.096Z,1563987613.096 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-24T17:00:13.096Z,1563987613.096 [Default:B.GoToSurface] Stopped
2019-07-24T17:00:13.096Z,1563987613.096 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-24T17:00:13.096Z,1563987613.096 [Default:CheckIn] Stopped
2019-07-24T17:00:13.096Z,1563987613.096 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-24T17:00:13.096Z,1563987613.096 [Default:CheckIn:C.Wait] Stopped
2019-07-24T17:00:13.097Z,1563987613.097 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-24T17:00:13.099Z,1563987613.099 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-07-24T17:00:13.099Z,1563987613.099 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-07-24T17:00:13.099Z,1563987613.099 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-07-24T17:00:13.100Z,1563987613.100 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-07-24T17:00:13.100Z,1563987613.100 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-07-24T17:00:13.100Z,1563987613.100 [BuoyancyServo](INFO): Powering down
2019-07-24T17:00:13.113Z,1563987613.113 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-07-24T17:00:13.113Z,1563987613.113 [ElevatorServo](INFO): Powering down
2019-07-24T17:00:13.114Z,1563987613.114 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-07-24T17:00:13.114Z,1563987613.114 [MassServo](INFO): Powering down
2019-07-24T17:00:13.115Z,1563987613.115 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-24T17:00:13.115Z,1563987613.115 [RudderServo](INFO): Powering down
2019-07-24T17:00:13.116Z,1563987613.116 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-07-24T17:00:13.116Z,1563987613.116 [ThrusterServo](INFO): Powering down
2019-07-24T17:00:13.117Z,1563987613.117 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-07-24T17:00:13.117Z,1563987613.117 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-07-24T17:00:13.117Z,1563987613.117 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-07-24T17:00:13.118Z,1563987613.118 [CBIT](DEBUG): Powering off loads.
2019-07-24T17:00:13.129Z,1563987613.129 [CBIT](DEBUG): Disabling WDT.
2019-07-24T17:00:13.141Z,1563987613.141 [CBIT](DEBUG): Opening all GF detection circuits.
2019-07-24T17:00:13.142Z,1563987613.142 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:13.190Z,1563987613.190 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:13.196Z,1563987613.196 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:13.266Z,1563987613.266 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:13.273Z,1563987613.273 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:13.323Z,1563987613.323 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-24T17:00:13.392Z,1563987613.392 [logger ThreadHandler](INFO): Thread cancelled.