2019-06-06T17:46:45.879Z,1559843205.879 [NAL9602](INFO): Received command:restart logs
2019-06-06T17:46:45.881Z,1559843205.881 [CommandLine](IMPORTANT): got command restart logs
2019-06-06T17:46:49.039Z,1559843209.039 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-06-06T17:46:52.864Z,1559843212.864 [DVL_micro](ERROR): only read 44 of 46 data items
2019-06-06T17:46:52.864Z,1559843212.864 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1756 1455 -1430 -1771 2 2 2 2 -435.1 4305.5 -944.3 2 3906.8 1861.0 -944.3 2 -435 4305 -944 2 3906 1861 -944 2 -9.90 5.57 289.7 -3.0 14.7 0.00589 68
2019-06-06T17:47:02.535Z,1559843222.535 [DVL_micro](ERROR): only read 45 of 46 data items
2019-06-06T17:47:02.535Z,1559843222.535 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1690 1277 -1672 -535 2 2 2 2 -24.0 2418.4 -706.5 2 2198.0 1009.4 -706.5 2 -24 2418 -706 2 219806 2 1.46 6.43 294.1 -3.0 14.7 0.005 35.0 1489 80
2019-06-06T17:47:05.788Z,1559843225.788 [NAL9602](INFO): SBD MO Status=2, MOMSN=15836, MT Status=2, MTMSN=0
2019-06-06T17:47:05.788Z,1559843225.788 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T17:47:15.255Z,1559843235.255 [DVL_micro](ERROR): only read 42 of 46 data items
2019-06-06T17:47:15.255Z,1559843235.255 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 739 307 -68 2 2 28 2902.8 -1335.5 2 2753.8 924.8 -1335.5 2 -114 2902 -1335 2 2753 924 -1335 2 -4.05 2.35 286.3 -3.0 14.7 0.005 35.0 1489 121
2019-06-06T17:47:19.743Z,1559843239.743 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-06-06T17:47:27.543Z,1559843247.543 [DVL_micro](ERROR): only read 43 of 46 data items
2019-06-06T17:47:27.543Z,1559843247.543 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -1743 -490 -1623 -1584 2 2 2 2 -160.2 1460.1 -1466.8 2 1331.7 619.8 -1466.8 2 -160 1460 -1466 2 1331 619 -1466 2 1.13 2.48 288.7 -3.0 14.7 0.005 35.0 1489 123
2019-06-06T17:47:33.269Z,1559843253.269 [NAL9602](INFO): SBD MO Status=1, MOMSN=15836, MT Status=0, MTMSN=0
2019-06-06T17:47:33.319Z,1559843253.319 [NAL9602](INFO): Sent 25 bytes from file Logs/20190605T224910/Courier0100.lzma
2019-06-06T17:47:33.319Z,1559843253.319 [NAL9602](INFO): Packets left to send: 0
2019-06-06T17:47:49.388Z,1559843269.388 [NAL9602](INFO): SBD MO Status=1, MOMSN=15837, MT Status=0, MTMSN=0
2019-06-06T17:47:49.435Z,1559843269.435 [NAL9602](INFO): Sent 120 bytes from file Logs/20190605T224910/Express0098.lzma
2019-06-06T17:47:49.435Z,1559843269.435 [NAL9602](INFO): Packets left to send: 0
2019-06-06T17:47:50.190Z,1559843270.190 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002903
2019-06-06T17:47:51.028Z,1559843271.028 [DVL_micro](ERROR): only read 45 of 46 data items
2019-06-06T17:47:51.028Z,1559843271.028 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1533 -1565 -1789 1153 2 2 2 -3627.5 -1006.8 2 -3490.1 -1045.8 -1006.8 2 341 -3627 -1006 2 -34 -1006 2 -10.89 1.65 281.3 -3.0 14.7 0.005 35.0 1489 126
2019-06-06T17:47:59.286Z,1559843279.286 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20190605T224910/Express0101.lzma
2019-06-06T17:47:59.981Z,1559843279.981 [NAL9602](INFO): SBD MO Status=1, MOMSN=15838, MT Status=0, MTMSN=0
2019-06-06T17:48:00.031Z,1559843280.031 [NAL9602](INFO): Sent 161 bytes from file Logs/20190605T224910/Express0101.lzma
2019-06-06T17:48:00.031Z,1559843280.031 [NAL9602](INFO): Packets left to send: 0
2019-06-06T17:48:00.715Z,1559843280.715 [DataOverHttps](FAULT): Server acknowledged file Logs/20190605T224910/Express0101.lzma, notLogs/20190606T174645/Courier0000.lzma
2019-06-06T17:48:00.720Z,1559843280.720 [DataOverHttps](INFO): SBD MOMSN=11343091
2019-06-06T17:48:14.770Z,1559843294.770 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190606T174645/Courier0000.lzma
2019-06-06T17:48:15.576Z,1559843295.576 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0000.lzma.bak
2019-06-06T17:48:15.576Z,1559843295.576 [DataOverHttps](INFO): SBD MOMSN=11343100
2019-06-06T17:48:27.554Z,1559843307.554 [DataOverHttps](INFO): Sending 257 bytes from file Logs/20190606T174645/Express0001.lzma
2019-06-06T17:48:28.360Z,1559843308.360 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0001.lzma.bak
2019-06-06T17:48:28.360Z,1559843308.360 [DataOverHttps](INFO): SBD MOMSN=11343103
2019-06-06T17:48:29.492Z,1559843309.492 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T17:48:29.493Z,1559843309.493 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T17:48:29.493Z,1559843309.493 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T17:48:31.436Z,1559843311.436 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T17:49:37.696Z,1559843377.696 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T17:49:37.696Z,1559843377.696 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T17:49:37.696Z,1559843377.696 [DVL_micro](ERROR): Data Fault
2019-06-06T17:49:37.755Z,1559843377.755 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T17:49:38.162Z,1559843378.162 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T17:49:38.975Z,1559843378.975 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T17:49:38.975Z,1559843378.975 [DVL_micro] No Fault, FailCount= 1
2019-06-06T17:49:39.313Z,1559843379.313 [DVL_micro](INFO): Initializing
2019-06-06T17:52:43.555Z,1559843563.555 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T17:52:43.556Z,1559843563.556 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T17:52:43.556Z,1559843563.556 [DVL_micro](ERROR): Data Fault
2019-06-06T17:52:43.628Z,1559843563.628 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T17:52:44.026Z,1559843564.026 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T17:52:44.805Z,1559843564.805 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T17:52:44.805Z,1559843564.805 [DVL_micro] No Fault, FailCount= 1
2019-06-06T17:52:45.178Z,1559843565.178 [DVL_micro](INFO): Initializing
2019-06-06T17:53:30.046Z,1559843610.046 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T17:53:30.046Z,1559843610.046 [Default:CheckIn:C.Wait] Stopped
2019-06-06T17:53:30.046Z,1559843610.046 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T17:53:30.047Z,1559843610.047 [Default:CheckIn:D] Running Loop=1
2019-06-06T17:53:30.471Z,1559843610.471 [Default:CheckIn:D] Stopped
2019-06-06T17:53:30.471Z,1559843610.471 [Default:CheckIn:E] Running Loop=1
2019-06-06T17:53:30.863Z,1559843610.863 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.717456 min 
2019-06-06T17:53:30.863Z,1559843610.863 [Default:CheckIn:E] Stopped
2019-06-06T17:53:30.863Z,1559843610.863 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T17:53:30.863Z,1559843610.863 [Default:CheckIn] Stopped
2019-06-06T17:53:30.864Z,1559843610.864 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T17:53:30.864Z,1559843610.864 [Default:CheckIn](INFO): Running loop #3
2019-06-06T17:53:30.864Z,1559843610.864 [Default:CheckIn] Running Loop=3
2019-06-06T17:53:30.864Z,1559843610.864 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T17:53:30.864Z,1559843610.864 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T17:53:32.458Z,1559843612.458 [NAL9602](DEBUG): Fix Requested
2019-06-06T17:53:32.861Z,1559843612.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174814.00,A,3648.46636,N,12147.11570,W,5.132,171.10,060619,,,D*76
2019-06-06T17:53:32.868Z,1559843612.868 [NAL9602](INFO): GPS fix at 20190606T174814: (36.807773, -121.785262)
2019-06-06T17:53:32.919Z,1559843612.919 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T17:53:32.919Z,1559843612.919 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T17:53:34.472Z,1559843614.472 [NAL9602](ERROR): parseGSV uart error: serial buffer full
2019-06-06T17:53:39.008Z,1559843619.008 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190606T174645/Courier0003.lzma
2019-06-06T17:53:39.808Z,1559843619.808 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0003.lzma.bak
2019-06-06T17:53:39.808Z,1559843619.808 [DataOverHttps](INFO): SBD MOMSN=11343106
2019-06-06T17:53:51.433Z,1559843631.433 [NAL9602](INFO): SBD MO Status=2, MOMSN=15839, MT Status=2, MTMSN=0
2019-06-06T17:53:51.434Z,1559843631.434 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T17:53:52.507Z,1559843632.507 [DataOverHttps](INFO): Sending 336 bytes from file Logs/20190606T174645/Express0004.lzma
2019-06-06T17:53:53.312Z,1559843633.312 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0004.lzma.bak
2019-06-06T17:53:53.312Z,1559843633.312 [DataOverHttps](INFO): SBD MOMSN=11343109
2019-06-06T17:53:54.703Z,1559843634.703 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T17:53:54.703Z,1559843634.703 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T17:53:54.703Z,1559843634.703 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T17:54:31.025Z,1559843671.025 [NAL9602](INFO): SBD MO Status=2, MOMSN=15839, MT Status=2, MTMSN=0
2019-06-06T17:54:31.025Z,1559843671.026 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T17:55:24.769Z,1559843724.769 [NAL9602](INFO): SBD MO Status=2, MOMSN=15839, MT Status=2, MTMSN=0
2019-06-06T17:55:24.769Z,1559843724.769 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T17:55:45.365Z,1559843745.365 [NAL9602](INFO): SBD MO Status=0, MOMSN=15839, MT Status=0, MTMSN=0
2019-06-06T17:55:45.365Z,1559843745.365 [NAL9602](INFO): No messages in MT queue
2019-06-06T17:55:49.403Z,1559843749.403 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T17:55:49.404Z,1559843749.404 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T17:55:49.404Z,1559843749.404 [DVL_micro](ERROR): Data Fault
2019-06-06T17:55:49.478Z,1559843749.478 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T17:55:49.891Z,1559843749.891 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T17:55:50.645Z,1559843750.645 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T17:55:50.645Z,1559843750.645 [DVL_micro] No Fault, FailCount= 1
2019-06-06T17:55:51.019Z,1559843751.019 [DVL_micro](INFO): Initializing
2019-06-06T17:56:16.064Z,1559843776.064 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T17:57:31.225Z,1559843851.225 [DVL_micro](ERROR): only read 43 of 46 data items
2019-06-06T17:57:31.225Z,1559843851.225 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -1335 860 -1594 -1644 2 2 2 2 345.7 3341.9 -1001.2 2 -982.6 -3212.7 -1001.2 2 345 3341 -1001 2 -982 -3212 -1001 2 -3.78 3.35 168.9 -3.0 15.1 0.005 35.0 1489 126
2019-06-06T17:58:55.247Z,1559843935.247 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T17:58:55.247Z,1559843935.247 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T17:58:55.248Z,1559843935.248 [DVL_micro](ERROR): Data Fault
2019-06-06T17:58:55.273Z,1559843935.273 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T17:58:55.273Z,1559843935.273 [Default:CheckIn:C.Wait] Stopped
2019-06-06T17:58:55.273Z,1559843935.273 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T17:58:55.274Z,1559843935.274 [Default:CheckIn:D] Running Loop=1
2019-06-06T17:58:55.283Z,1559843935.283 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T17:58:55.711Z,1559843935.711 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T17:58:55.743Z,1559843935.743 [Default:CheckIn:D] Stopped
2019-06-06T17:58:55.743Z,1559843935.743 [Default:CheckIn:E] Running Loop=1
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.138656 min 
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn:E] Stopped
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn] Stopped
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn](INFO): Running loop #4
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn] Running Loop=4
2019-06-06T17:58:56.091Z,1559843936.091 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T17:58:56.092Z,1559843936.092 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T17:58:56.484Z,1559843936.484 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T17:58:56.484Z,1559843936.484 [DVL_micro] No Fault, FailCount= 1
2019-06-06T17:58:56.862Z,1559843936.862 [DVL_micro](INFO): Initializing
2019-06-06T17:58:57.674Z,1559843937.674 [NAL9602](DEBUG): Fix Requested
2019-06-06T17:58:58.069Z,1559843938.069 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175339.00,A,3648.16222,N,12147.21526,W,0.175,239.06,060619,,,D*79
2019-06-06T17:58:58.071Z,1559843938.071 [NAL9602](INFO): GPS fix at 20190606T175339: (36.802704, -121.786921)
2019-06-06T17:58:58.104Z,1559843938.104 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T17:58:58.104Z,1559843938.104 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T17:59:04.106Z,1559843944.106 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190606T174645/Courier0006.lzma
2019-06-06T17:59:04.912Z,1559843944.912 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0006.lzma.bak
2019-06-06T17:59:04.912Z,1559843944.912 [DataOverHttps](INFO): SBD MOMSN=11343123
2019-06-06T17:59:17.035Z,1559843957.035 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20190606T174645/Express0007.lzma
2019-06-06T17:59:17.840Z,1559843957.840 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0007.lzma.bak
2019-06-06T17:59:17.840Z,1559843957.840 [DataOverHttps](INFO): SBD MOMSN=11343126
2019-06-06T17:59:19.139Z,1559843959.139 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T17:59:19.139Z,1559843959.139 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T17:59:19.139Z,1559843959.139 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:00:16.457Z,1559844016.457 [NAL9602](INFO): SBD MO Status=2, MOMSN=15840, MT Status=2, MTMSN=0
2019-06-06T18:00:16.458Z,1559844016.458 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T18:00:49.593Z,1559844049.593 [NAL9602](INFO): SBD MO Status=2, MOMSN=15840, MT Status=2, MTMSN=0
2019-06-06T18:00:49.593Z,1559844049.593 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T18:01:16.251Z,1559844076.251 [NAL9602](INFO): SBD MO Status=0, MOMSN=15840, MT Status=0, MTMSN=0
2019-06-06T18:01:16.251Z,1559844076.251 [NAL9602](INFO): No messages in MT queue
2019-06-06T18:01:46.952Z,1559844106.952 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:02:01.096Z,1559844121.096 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:02:01.096Z,1559844121.096 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:02:01.096Z,1559844121.096 [DVL_micro](ERROR): Data Fault
2019-06-06T18:02:01.167Z,1559844121.167 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:02:01.578Z,1559844121.578 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:02:02.336Z,1559844122.336 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:02:02.336Z,1559844122.336 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:02:02.713Z,1559844122.713 [DVL_micro](INFO): Initializing
2019-06-06T18:04:19.699Z,1559844259.699 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:04:19.700Z,1559844259.700 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:04:19.700Z,1559844259.700 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:04:19.700Z,1559844259.700 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:04:20.106Z,1559844260.106 [Default:CheckIn:D] Stopped
2019-06-06T18:04:20.106Z,1559844260.106 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:04:20.508Z,1559844260.508 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.544714 min 
2019-06-06T18:04:20.508Z,1559844260.508 [Default:CheckIn:E] Stopped
2019-06-06T18:04:20.508Z,1559844260.508 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:04:20.508Z,1559844260.508 [Default:CheckIn] Stopped
2019-06-06T18:04:20.508Z,1559844260.508 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:04:20.508Z,1559844260.508 [Default:CheckIn](INFO): Running loop #5
2019-06-06T18:04:20.508Z,1559844260.508 [Default:CheckIn] Running Loop=5
2019-06-06T18:04:20.509Z,1559844260.509 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:04:20.509Z,1559844260.509 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:04:22.110Z,1559844262.110 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:04:22.501Z,1559844262.501 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175903.00,A,3648.16756,N,12147.21627,W,0.058,137.65,060619,,,A*7D
2019-06-06T18:04:22.504Z,1559844262.504 [NAL9602](INFO): GPS fix at 20190606T175903: (36.802793, -121.786938)
2019-06-06T18:04:22.562Z,1559844262.562 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:04:22.562Z,1559844262.562 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:04:28.498Z,1559844268.498 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190606T174645/Courier0009.lzma
2019-06-06T18:04:29.304Z,1559844269.304 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0009.lzma.bak
2019-06-06T18:04:29.304Z,1559844269.304 [DataOverHttps](INFO): SBD MOMSN=11343134
2019-06-06T18:04:41.394Z,1559844281.394 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20190606T174645/Express0010.lzma
2019-06-06T18:04:42.200Z,1559844282.200 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0010.lzma.bak
2019-06-06T18:04:42.200Z,1559844282.200 [DataOverHttps](INFO): SBD MOMSN=11343137
2019-06-06T18:04:43.157Z,1559844283.157 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:04:43.157Z,1559844283.157 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:04:43.157Z,1559844283.157 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:05:06.940Z,1559844306.940 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:05:06.940Z,1559844306.940 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:05:06.940Z,1559844306.940 [DVL_micro](ERROR): Data Fault
2019-06-06T18:05:07.015Z,1559844307.015 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:05:07.431Z,1559844307.431 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:05:08.191Z,1559844308.191 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:05:08.191Z,1559844308.191 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:05:08.562Z,1559844308.562 [DVL_micro](INFO): Initializing
2019-06-06T18:06:01.081Z,1559844361.081 [NAL9602](INFO): SBD MO Status=2, MOMSN=15841, MT Status=2, MTMSN=0
2019-06-06T18:06:01.082Z,1559844361.082 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T18:06:08.754Z,1559844368.754 [NAL9602](INFO): SBD MO Status=0, MOMSN=15841, MT Status=0, MTMSN=0
2019-06-06T18:06:08.754Z,1559844368.754 [NAL9602](INFO): No messages in MT queue
2019-06-06T18:06:39.457Z,1559844399.457 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:08:12.777Z,1559844492.777 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:08:12.777Z,1559844492.777 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:08:12.777Z,1559844492.777 [DVL_micro](ERROR): Data Fault
2019-06-06T18:08:12.843Z,1559844492.843 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:08:13.247Z,1559844493.247 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:08:14.027Z,1559844494.027 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:08:14.027Z,1559844494.027 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:08:14.406Z,1559844494.406 [DVL_micro](INFO): Initializing
2019-06-06T18:09:43.703Z,1559844583.703 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:09:43.703Z,1559844583.703 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:09:43.703Z,1559844583.703 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:09:43.703Z,1559844583.703 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:09:44.119Z,1559844584.119 [Default:CheckIn:D] Stopped
2019-06-06T18:09:44.119Z,1559844584.119 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:09:44.517Z,1559844584.517 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.944922 min 
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn:E] Stopped
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn] Stopped
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn](INFO): Running loop #6
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn] Running Loop=6
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:09:44.518Z,1559844584.518 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:09:46.146Z,1559844586.146 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:09:46.510Z,1559844586.510 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180426.00,A,3648.17272,N,12147.28008,W,0.019,295.77,060619,,,A*70
2019-06-06T18:09:46.512Z,1559844586.512 [NAL9602](INFO): GPS fix at 20190606T180426: (36.802879, -121.788001)
2019-06-06T18:09:46.549Z,1559844586.549 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:09:46.549Z,1559844586.549 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:09:50.519Z,1559844590.519 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190606T174645/Courier0012.lzma
2019-06-06T18:09:50.992Z,1559844590.992 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0012.lzma.bak
2019-06-06T18:09:50.992Z,1559844590.992 [DataOverHttps](INFO): SBD MOMSN=11343149
2019-06-06T18:10:03.006Z,1559844603.006 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20190606T174645/Express0013.lzma
2019-06-06T18:10:03.812Z,1559844603.812 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0013.lzma.bak
2019-06-06T18:10:03.812Z,1559844603.812 [DataOverHttps](INFO): SBD MOMSN=11343152
2019-06-06T18:10:05.218Z,1559844605.218 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:10:05.218Z,1559844605.218 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:10:05.218Z,1559844605.218 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:10:12.053Z,1559844612.053 [NAL9602](INFO): SBD MO Status=0, MOMSN=15842, MT Status=0, MTMSN=0
2019-06-06T18:10:12.053Z,1559844612.053 [NAL9602](INFO): No messages in MT queue
2019-06-06T18:10:42.748Z,1559844642.748 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:11:18.707Z,1559844678.707 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:11:18.707Z,1559844678.707 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:11:18.708Z,1559844678.708 [DVL_micro](ERROR): Data Fault
2019-06-06T18:11:18.742Z,1559844678.742 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:11:19.178Z,1559844679.178 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:11:19.957Z,1559844679.957 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:11:19.957Z,1559844679.957 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:11:20.325Z,1559844680.325 [DVL_micro](INFO): Initializing
2019-06-06T18:14:24.544Z,1559844864.544 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:14:24.544Z,1559844864.544 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:14:24.544Z,1559844864.544 [DVL_micro](ERROR): Data Fault
2019-06-06T18:14:24.603Z,1559844864.603 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:14:25.018Z,1559844865.018 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:14:25.795Z,1559844865.795 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:14:25.795Z,1559844865.795 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:14:26.169Z,1559844866.169 [DVL_micro](INFO): Initializing
2019-06-06T18:15:05.775Z,1559844905.775 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:15:05.775Z,1559844905.775 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:15:05.775Z,1559844905.775 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:15:05.776Z,1559844905.776 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:15:06.180Z,1559844906.180 [Default:CheckIn:D] Stopped
2019-06-06T18:15:06.180Z,1559844906.180 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:15:06.591Z,1559844906.591 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.312602 min 
2019-06-06T18:15:06.591Z,1559844906.591 [Default:CheckIn:E] Stopped
2019-06-06T18:15:06.591Z,1559844906.591 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:15:06.592Z,1559844906.592 [Default:CheckIn] Stopped
2019-06-06T18:15:06.592Z,1559844906.592 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:15:06.592Z,1559844906.592 [Default:CheckIn](INFO): Running loop #7
2019-06-06T18:15:06.592Z,1559844906.592 [Default:CheckIn] Running Loop=7
2019-06-06T18:15:06.592Z,1559844906.592 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:15:06.592Z,1559844906.592 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:15:08.206Z,1559844908.206 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:15:08.584Z,1559844908.584 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180948.00,A,3648.17771,N,12147.28011,W,0.058,326.05,060619,,,D*77
2019-06-06T18:15:08.586Z,1559844908.586 [NAL9602](INFO): GPS fix at 20190606T180948: (36.802962, -121.788002)
2019-06-06T18:15:08.610Z,1559844908.610 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:15:08.610Z,1559844908.610 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:15:14.302Z,1559844914.302 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190606T174645/Courier0015.lzma
2019-06-06T18:15:15.249Z,1559844915.249 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0015.lzma.bak
2019-06-06T18:15:15.249Z,1559844915.249 [DataOverHttps](INFO): SBD MOMSN=11343165
2019-06-06T18:15:27.082Z,1559844927.082 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20190606T174645/Express0016.lzma
2019-06-06T18:15:27.888Z,1559844927.888 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0016.lzma.bak
2019-06-06T18:15:27.888Z,1559844927.888 [DataOverHttps](INFO): SBD MOMSN=11343168
2019-06-06T18:15:29.232Z,1559844929.232 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:15:29.232Z,1559844929.232 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:15:29.232Z,1559844929.232 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:15:31.207Z,1559844931.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=15843, MT Status=2, MTMSN=0
2019-06-06T18:15:31.207Z,1559844931.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T18:16:24.129Z,1559844984.129 [NAL9602](INFO): SBD MO Status=2, MOMSN=15843, MT Status=2, MTMSN=0
2019-06-06T18:16:24.130Z,1559844984.130 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T18:16:33.829Z,1559844993.829 [NAL9602](INFO): SBD MO Status=0, MOMSN=15843, MT Status=0, MTMSN=0
2019-06-06T18:16:33.829Z,1559844993.829 [NAL9602](INFO): No messages in MT queue
2019-06-06T18:17:04.576Z,1559845024.576 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:17:30.381Z,1559845050.381 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:17:30.381Z,1559845050.381 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:17:30.381Z,1559845050.381 [DVL_micro](ERROR): Data Fault
2019-06-06T18:17:30.441Z,1559845050.441 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:17:30.859Z,1559845050.859 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:17:31.624Z,1559845051.624 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:17:31.624Z,1559845051.624 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:17:32.009Z,1559845052.009 [DVL_micro](INFO): Initializing
2019-06-06T18:20:29.835Z,1559845229.835 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:20:29.835Z,1559845229.835 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:20:29.835Z,1559845229.835 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:20:29.835Z,1559845229.835 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:20:30.207Z,1559845230.207 [Default:CheckIn:D] Stopped
2019-06-06T18:20:30.207Z,1559845230.207 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:20:30.592Z,1559845230.592 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.713053 min 
2019-06-06T18:20:30.592Z,1559845230.592 [Default:CheckIn:E] Stopped
2019-06-06T18:20:30.592Z,1559845230.592 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:20:30.592Z,1559845230.592 [Default:CheckIn] Stopped
2019-06-06T18:20:30.593Z,1559845230.593 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:20:30.593Z,1559845230.593 [Default:CheckIn](INFO): Running loop #8
2019-06-06T18:20:30.593Z,1559845230.593 [Default:CheckIn] Running Loop=8
2019-06-06T18:20:30.593Z,1559845230.593 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:20:30.593Z,1559845230.593 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:20:32.202Z,1559845232.202 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:20:32.587Z,1559845232.587 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181511.00,A,3648.17785,N,12147.28005,W,0.000,326.05,060619,,,D*75
2019-06-06T18:20:32.590Z,1559845232.590 [NAL9602](INFO): GPS fix at 20190606T181511: (36.802964, -121.788001)
2019-06-06T18:20:32.647Z,1559845232.647 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:20:32.647Z,1559845232.647 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:20:36.224Z,1559845236.224 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:20:36.224Z,1559845236.224 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:20:36.224Z,1559845236.224 [DVL_micro](ERROR): Data Fault
2019-06-06T18:20:36.307Z,1559845236.307 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:20:36.698Z,1559845236.698 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:20:37.484Z,1559845237.484 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:20:37.484Z,1559845237.484 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:20:37.846Z,1559845237.846 [DVL_micro](INFO): Initializing
2019-06-06T18:20:38.778Z,1559845238.778 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190606T174645/Courier0018.lzma
2019-06-06T18:20:39.584Z,1559845239.584 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0018.lzma.bak
2019-06-06T18:20:39.584Z,1559845239.584 [DataOverHttps](INFO): SBD MOMSN=11343192
2019-06-06T18:20:51.730Z,1559845251.730 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20190606T174645/Express0019.lzma
2019-06-06T18:20:52.536Z,1559845252.536 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0019.lzma.bak
2019-06-06T18:20:52.536Z,1559845252.536 [DataOverHttps](INFO): SBD MOMSN=11343195
2019-06-06T18:20:53.644Z,1559845253.644 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:20:53.644Z,1559845253.644 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:20:53.644Z,1559845253.644 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:21:36.058Z,1559845296.058 [NAL9602](INFO): SBD MO Status=0, MOMSN=15844, MT Status=0, MTMSN=0
2019-06-06T18:21:36.058Z,1559845296.058 [NAL9602](INFO): No messages in MT queue
2019-06-06T18:22:06.720Z,1559845326.720 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:23:42.063Z,1559845422.063 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:23:42.063Z,1559845422.063 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:23:42.064Z,1559845422.064 [DVL_micro](ERROR): Data Fault
2019-06-06T18:23:42.107Z,1559845422.107 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:23:42.549Z,1559845422.549 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:23:43.321Z,1559845423.321 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:23:43.321Z,1559845423.321 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:23:43.697Z,1559845423.697 [DVL_micro](INFO): Initializing
2019-06-06T18:25:54.192Z,1559845554.192 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:25:54.192Z,1559845554.192 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:25:54.192Z,1559845554.192 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:25:54.193Z,1559845554.193 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:25:54.597Z,1559845554.597 [Default:CheckIn:D] Stopped
2019-06-06T18:25:54.597Z,1559845554.597 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.119556 min 
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn:E] Stopped
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn] Stopped
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn](INFO): Running loop #9
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn] Running Loop=9
2019-06-06T18:25:55.008Z,1559845555.008 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:25:55.009Z,1559845555.009 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:25:56.610Z,1559845556.610 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:25:57.002Z,1559845557.002 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182035.00,A,3648.17647,N,12147.27959,W,0.058,326.05,060619,,,D*78
2019-06-06T18:25:57.004Z,1559845557.004 [NAL9602](INFO): GPS fix at 20190606T182035: (36.802941, -121.787993)
2019-06-06T18:25:57.028Z,1559845557.028 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:25:57.028Z,1559845557.028 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:26:03.246Z,1559845563.246 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190606T174645/Courier0021.lzma
2019-06-06T18:26:04.052Z,1559845564.052 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0021.lzma.bak
2019-06-06T18:26:04.052Z,1559845564.052 [DataOverHttps](INFO): SBD MOMSN=11343201
2019-06-06T18:26:16.270Z,1559845576.270 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20190606T174645/Express0022.lzma
2019-06-06T18:26:17.076Z,1559845577.076 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0022.lzma.bak
2019-06-06T18:26:17.076Z,1559845577.076 [DataOverHttps](INFO): SBD MOMSN=11343204
2019-06-06T18:26:18.054Z,1559845578.054 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:26:18.054Z,1559845578.054 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:26:18.054Z,1559845578.054 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:26:22.082Z,1559845582.082 [NAL9602](INFO): SBD MO Status=0, MOMSN=15845, MT Status=0, MTMSN=0
2019-06-06T18:26:22.082Z,1559845582.082 [NAL9602](INFO): No messages in MT queue
2019-06-06T18:26:47.911Z,1559845607.911 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:26:47.911Z,1559845607.911 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:26:47.912Z,1559845607.912 [DVL_micro](ERROR): Data Fault
2019-06-06T18:26:47.945Z,1559845607.945 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:26:48.375Z,1559845608.375 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:26:49.144Z,1559845609.144 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:26:49.144Z,1559845609.144 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:26:49.529Z,1559845609.529 [DVL_micro](INFO): Initializing
2019-06-06T18:26:52.752Z,1559845612.752 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:29:53.747Z,1559845793.747 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:29:53.747Z,1559845793.747 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:29:53.748Z,1559845793.748 [DVL_micro](ERROR): Data Fault
2019-06-06T18:29:53.782Z,1559845793.782 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:29:54.222Z,1559845794.222 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:29:55.000Z,1559845795.000 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:29:55.000Z,1559845795.000 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:29:55.365Z,1559845795.365 [DVL_micro](INFO): Initializing
2019-06-06T18:31:12.936Z,1559845872.936 [DVL_micro](ERROR): only read 45 of 46 data items
2019-06-06T18:31:12.936Z,1559845872.936 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1197 -2415 -1143 -1788 2 2 2 2 -72.1 -836.8 -1764.2 2 -829.0 134.7 -1764.2 2 -72 -836 -1764 2 -829 134 -1764 2 7.34 1.21 265.7 -3.0 17.5 00 1489 75
2019-06-06T18:31:18.622Z,1559845878.622 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:31:18.622Z,1559845878.622 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:31:18.622Z,1559845878.622 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:31:18.622Z,1559845878.622 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:31:19.021Z,1559845879.021 [Default:CheckIn:D] Stopped
2019-06-06T18:31:19.021Z,1559845879.021 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:31:19.442Z,1559845879.442 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.526632 min 
2019-06-06T18:31:19.442Z,1559845879.442 [Default:CheckIn:E] Stopped
2019-06-06T18:31:19.442Z,1559845879.442 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:31:19.442Z,1559845879.442 [Default:CheckIn] Stopped
2019-06-06T18:31:19.443Z,1559845879.443 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:31:19.443Z,1559845879.443 [Default:CheckIn](INFO): Running loop #10
2019-06-06T18:31:19.443Z,1559845879.443 [Default:CheckIn] Running Loop=10
2019-06-06T18:31:19.443Z,1559845879.443 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:31:19.443Z,1559845879.443 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:31:21.026Z,1559845881.026 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:31:21.417Z,1559845881.417 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182559.00,A,3648.17644,N,12147.28012,W,0.019,326.05,060619,,,A*7D
2019-06-06T18:31:21.420Z,1559845881.420 [NAL9602](INFO): GPS fix at 20190606T182559: (36.802941, -121.788002)
2019-06-06T18:31:21.444Z,1559845881.444 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:31:21.444Z,1559845881.444 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:31:27.378Z,1559845887.378 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190606T174645/Courier0024.lzma
2019-06-06T18:31:28.184Z,1559845888.184 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0024.lzma.bak
2019-06-06T18:31:28.184Z,1559845888.184 [DataOverHttps](INFO): SBD MOMSN=11343219
2019-06-06T18:31:40.262Z,1559845900.262 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20190606T174645/Express0025.lzma
2019-06-06T18:31:41.068Z,1559845901.068 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0025.lzma.bak
2019-06-06T18:31:41.068Z,1559845901.068 [DataOverHttps](INFO): SBD MOMSN=11343222
2019-06-06T18:31:42.194Z,1559845902.194 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:31:42.194Z,1559845902.194 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:31:42.194Z,1559845902.194 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:31:50.545Z,1559845910.545 [NAL9602](INFO): SBD MO Status=0, MOMSN=15846, MT Status=0, MTMSN=0
2019-06-06T18:31:50.545Z,1559845910.545 [NAL9602](INFO): No messages in MT queue
2019-06-06T18:32:21.245Z,1559845941.245 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:32:59.624Z,1559845979.624 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:32:59.624Z,1559845979.624 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:32:59.624Z,1559845979.624 [DVL_micro](ERROR): Data Fault
2019-06-06T18:32:59.688Z,1559845979.688 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:33:00.102Z,1559845980.102 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:33:00.879Z,1559845980.879 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:33:00.879Z,1559845980.879 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:33:01.244Z,1559845981.244 [DVL_micro](INFO): Initializing
2019-06-06T18:36:05.467Z,1559846165.467 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:36:05.467Z,1559846165.467 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:36:05.467Z,1559846165.467 [DVL_micro](ERROR): Data Fault
2019-06-06T18:36:05.526Z,1559846165.526 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:36:05.943Z,1559846165.943 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:36:06.705Z,1559846166.705 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:36:06.705Z,1559846166.705 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:36:07.090Z,1559846167.090 [DVL_micro](INFO): Initializing
2019-06-06T18:36:42.676Z,1559846202.676 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:36:42.676Z,1559846202.676 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:36:42.676Z,1559846202.676 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:36:42.677Z,1559846202.677 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:36:43.066Z,1559846203.066 [Default:CheckIn:D] Stopped
2019-06-06T18:36:43.066Z,1559846203.066 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:36:43.468Z,1559846203.468 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.927380 min 
2019-06-06T18:36:43.468Z,1559846203.468 [Default:CheckIn:E] Stopped
2019-06-06T18:36:43.468Z,1559846203.468 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:36:43.469Z,1559846203.469 [Default:CheckIn] Stopped
2019-06-06T18:36:43.469Z,1559846203.469 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:36:43.469Z,1559846203.469 [Default:CheckIn](INFO): Running loop #11
2019-06-06T18:36:43.469Z,1559846203.469 [Default:CheckIn] Running Loop=11
2019-06-06T18:36:43.469Z,1559846203.469 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:36:43.469Z,1559846203.469 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:36:45.070Z,1559846205.070 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:36:45.465Z,1559846205.465 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183123.00,A,3648.17284,N,12147.27980,W,0.700,196.26,060619,,,A*77
2019-06-06T18:36:45.468Z,1559846205.468 [NAL9602](INFO): GPS fix at 20190606T183123: (36.802881, -121.787997)
2019-06-06T18:36:45.498Z,1559846205.498 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:36:45.498Z,1559846205.498 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:36:51.246Z,1559846211.246 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190606T174645/Courier0027.lzma
2019-06-06T18:36:52.052Z,1559846212.052 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0027.lzma.bak
2019-06-06T18:36:52.052Z,1559846212.052 [DataOverHttps](INFO): SBD MOMSN=11343228
2019-06-06T18:37:04.046Z,1559846224.046 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20190606T174645/Express0028.lzma
2019-06-06T18:37:04.852Z,1559846224.852 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0028.lzma.bak
2019-06-06T18:37:04.852Z,1559846224.852 [DataOverHttps](INFO): SBD MOMSN=11343231
2019-06-06T18:37:06.172Z,1559846226.172 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:37:06.172Z,1559846226.172 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:37:06.172Z,1559846226.172 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:38:58.437Z,1559846338.437 [NAL9602](INFO): SBD MO Status=2, MOMSN=15847, MT Status=2, MTMSN=0
2019-06-06T18:38:58.437Z,1559846338.437 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-06-06T18:39:11.344Z,1559846351.344 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:39:11.344Z,1559846351.344 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:39:11.344Z,1559846351.344 [DVL_micro](ERROR): Data Fault
2019-06-06T18:39:11.384Z,1559846351.384 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:39:11.810Z,1559846351.810 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:39:12.604Z,1559846352.604 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:39:12.604Z,1559846352.604 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:39:12.957Z,1559846352.957 [DVL_micro](INFO): Initializing
2019-06-06T18:41:48.147Z,1559846508.147 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-06-06T18:42:06.711Z,1559846526.711 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:42:06.711Z,1559846526.711 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:42:06.711Z,1559846526.711 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:42:06.711Z,1559846526.711 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:42:07.112Z,1559846527.112 [Default:CheckIn:D] Stopped
2019-06-06T18:42:07.112Z,1559846527.112 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:42:07.540Z,1559846527.540 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.328137 min 
2019-06-06T18:42:07.540Z,1559846527.540 [Default:CheckIn:E] Stopped
2019-06-06T18:42:07.541Z,1559846527.541 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:42:07.541Z,1559846527.541 [Default:CheckIn] Stopped
2019-06-06T18:42:07.541Z,1559846527.541 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:42:07.541Z,1559846527.541 [Default:CheckIn](INFO): Running loop #12
2019-06-06T18:42:07.541Z,1559846527.541 [Default:CheckIn] Running Loop=12
2019-06-06T18:42:07.541Z,1559846527.541 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:42:07.541Z,1559846527.541 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:42:09.118Z,1559846529.118 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:42:09.507Z,1559846529.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183646.00,A,3648.16100,N,12147.26780,W,1.166,155.82,060619,,,A*74
2019-06-06T18:42:09.510Z,1559846529.510 [NAL9602](INFO): GPS fix at 20190606T183646: (36.802683, -121.787797)
2019-06-06T18:42:09.534Z,1559846529.534 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:42:09.534Z,1559846529.534 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:42:15.542Z,1559846535.542 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190606T174645/Courier0030.lzma
2019-06-06T18:42:16.348Z,1559846536.348 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0030.lzma.bak
2019-06-06T18:42:16.348Z,1559846536.348 [DataOverHttps](INFO): SBD MOMSN=11343242
2019-06-06T18:42:17.183Z,1559846537.183 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:42:17.183Z,1559846537.183 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:42:17.183Z,1559846537.183 [DVL_micro](ERROR): Data Fault
2019-06-06T18:42:17.287Z,1559846537.287 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:42:17.658Z,1559846537.658 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:42:18.467Z,1559846538.467 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:42:18.467Z,1559846538.467 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:42:18.805Z,1559846538.805 [DVL_micro](INFO): Initializing
2019-06-06T18:42:28.306Z,1559846548.306 [DataOverHttps](INFO): Sending 249 bytes from file Logs/20190606T174645/Express0031.lzma
2019-06-06T18:42:29.112Z,1559846549.112 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0031.lzma.bak
2019-06-06T18:42:29.112Z,1559846549.112 [DataOverHttps](INFO): SBD MOMSN=11343245
2019-06-06T18:42:30.147Z,1559846550.147 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:42:30.147Z,1559846550.147 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:42:30.147Z,1559846550.147 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:42:41.451Z,1559846561.451 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:45:23.021Z,1559846723.021 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:45:23.021Z,1559846723.021 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:45:23.021Z,1559846723.021 [DVL_micro](ERROR): Data Fault
2019-06-06T18:45:23.054Z,1559846723.054 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:45:23.503Z,1559846723.503 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:45:24.268Z,1559846724.268 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:45:24.268Z,1559846724.268 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:45:24.657Z,1559846724.657 [DVL_micro](INFO): Initializing
2019-06-06T18:47:30.744Z,1559846850.744 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:47:30.745Z,1559846850.745 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:47:30.745Z,1559846850.745 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:47:30.745Z,1559846850.745 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:47:31.129Z,1559846851.129 [Default:CheckIn:D] Stopped
2019-06-06T18:47:31.129Z,1559846851.129 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:47:31.535Z,1559846851.535 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.728426 min 
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn:E] Stopped
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn] Stopped
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn](INFO): Running loop #13
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn] Running Loop=13
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:47:31.536Z,1559846851.536 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:47:33.130Z,1559846853.130 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:47:33.525Z,1559846853.525 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184210.00,A,3648.16763,N,12147.32058,W,1.808,52.03,060619,,,A*4E
2019-06-06T18:47:33.528Z,1559846853.528 [NAL9602](INFO): GPS fix at 20190606T184210: (36.802794, -121.788676)
2019-06-06T18:47:33.559Z,1559846853.559 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:47:33.559Z,1559846853.559 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-06-06T18:47:39.466Z,1559846859.466 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190606T174645/Courier0033.lzma
2019-06-06T18:47:40.272Z,1559846860.272 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Courier0033.lzma.bak
2019-06-06T18:47:40.272Z,1559846860.272 [DataOverHttps](INFO): SBD MOMSN=11343310
2019-06-06T18:47:54.170Z,1559846874.170 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20190606T174645/Express0034.lzma
2019-06-06T18:47:54.976Z,1559846874.976 [DataOverHttps](INFO): Moved sent file to Logs/20190606T174645/Express0034.lzma.bak
2019-06-06T18:47:54.976Z,1559846874.976 [DataOverHttps](INFO): SBD MOMSN=11343313
2019-06-06T18:47:56.263Z,1559846876.263 [Default:CheckIn:Read_Iridium] Stopped
2019-06-06T18:47:56.263Z,1559846876.263 [Default:CheckIn:C.Wait] Running Loop=1
2019-06-06T18:47:56.263Z,1559846876.263 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-06-06T18:48:04.312Z,1559846884.312 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-06-06T18:48:04.390Z,1559846884.390 [NAL9602](FAULT): received: 
+CSQ:0

OK847, 2, 0, 0, 0

OK
2019-06-06T18:48:04.390Z,1559846884.390 [NAL9602] Data Fault, FailCount= 1
2019-06-06T18:48:04.390Z,1559846884.390 [NAL9602](ERROR): Data Fault
2019-06-06T18:48:04.487Z,1559846884.487 [CBIT](ERROR): Data Fault in component: NAL9602
2019-06-06T18:48:04.716Z,1559846884.716 [NAL9602](INFO): Powering down
2019-06-06T18:48:05.610Z,1559846885.610 [CBIT](INFO): Clearing failed state for component NAL9602
2019-06-06T18:48:05.610Z,1559846885.610 [NAL9602] No Fault, FailCount= 1
2019-06-06T18:48:28.959Z,1559846908.959 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:48:28.959Z,1559846908.959 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:48:28.960Z,1559846908.960 [DVL_micro](ERROR): Data Fault
2019-06-06T18:48:28.995Z,1559846908.995 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:48:29.430Z,1559846909.430 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:48:30.220Z,1559846910.220 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:48:30.220Z,1559846910.220 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:48:30.577Z,1559846910.577 [DVL_micro](INFO): Initializing
2019-06-06T18:48:35.020Z,1559846915.020 [NAL9602](INFO): Powering up NAL9602
2019-06-06T18:48:45.932Z,1559846925.932 [NAL9602](INFO): NAL9602 initialized
2019-06-06T18:49:17.032Z,1559846957.032 [NAL9602](INFO): Not Powering down - fast GPS
2019-06-06T18:49:48.148Z,1559846988.148 [DVL_micro](ERROR): only read 45 of 46 data items
2019-06-06T18:49:48.149Z,1559846988.149 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -1648 -894 -825 -1584 2 2 2 2 -1098.4 920.9 -1335.0 2 1373.1 -411.4 -1335.0 2 -1098 920 1373 -411 -1335 2 6.28 -1.97 203.3 -3.0 18.7 0.005 35.0 1489 108
2019-06-06T18:51:34.796Z,1559847094.796 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:51:34.796Z,1559847094.796 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:51:34.796Z,1559847094.796 [DVL_micro](ERROR): Data Fault
2019-06-06T18:51:34.907Z,1559847094.907 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:51:35.270Z,1559847095.270 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:51:36.092Z,1559847096.092 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:51:36.092Z,1559847096.092 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:51:36.417Z,1559847096.417 [DVL_micro](INFO): Initializing
2019-06-06T18:52:56.838Z,1559847176.838 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-06-06T18:52:56.839Z,1559847176.839 [Default:CheckIn:C.Wait] Stopped
2019-06-06T18:52:56.839Z,1559847176.839 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-06-06T18:52:56.839Z,1559847176.839 [Default:CheckIn:D] Running Loop=1
2019-06-06T18:52:57.310Z,1559847177.310 [Default:CheckIn:D] Stopped
2019-06-06T18:52:57.310Z,1559847177.310 [Default:CheckIn:E] Running Loop=1
2019-06-06T18:52:57.655Z,1559847177.655 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.164771 min 
2019-06-06T18:52:57.655Z,1559847177.655 [Default:CheckIn:E] Stopped
2019-06-06T18:52:57.655Z,1559847177.655 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-06-06T18:52:57.655Z,1559847177.655 [Default:CheckIn] Stopped
2019-06-06T18:52:57.655Z,1559847177.655 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:52:57.656Z,1559847177.656 [Default:CheckIn](INFO): Running loop #14
2019-06-06T18:52:57.656Z,1559847177.656 [Default:CheckIn] Running Loop=14
2019-06-06T18:52:57.656Z,1559847177.656 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-06-06T18:52:57.656Z,1559847177.656 [Default:CheckIn:Read_GPS] Running Loop=1
2019-06-06T18:52:59.242Z,1559847179.242 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:01.660Z,1559847181.660 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-06-06T18:53:02.474Z,1559847182.474 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:04.898Z,1559847184.898 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:07.726Z,1559847187.726 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:09.754Z,1559847189.754 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:12.982Z,1559847192.982 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:15.810Z,1559847195.810 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:19.042Z,1559847199.042 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:21.866Z,1559847201.866 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:25.102Z,1559847205.102 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:27.934Z,1559847207.934 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:30.758Z,1559847210.758 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:32.818Z,1559847212.818 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:36.058Z,1559847216.058 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:38.842Z,1559847218.842 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:42.074Z,1559847222.074 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:44.894Z,1559847224.894 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:48.130Z,1559847228.130 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:50.954Z,1559847230.954 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:53.786Z,1559847233.786 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:55.806Z,1559847235.806 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:53:57.826Z,1559847237.826 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:01.058Z,1559847241.058 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:03.890Z,1559847243.890 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:07.114Z,1559847247.114 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:09.946Z,1559847249.946 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:13.178Z,1559847253.178 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:16.006Z,1559847256.006 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:18.830Z,1559847258.830 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:20.858Z,1559847260.858 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:24.082Z,1559847264.082 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:26.510Z,1559847266.510 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:29.746Z,1559847269.746 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:32.570Z,1559847272.570 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:35.802Z,1559847275.802 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:38.638Z,1559847278.638 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:40.643Z,1559847280.643 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-06-06T18:54:40.643Z,1559847280.643 [DVL_micro] Data Fault, FailCount= 1
2019-06-06T18:54:40.643Z,1559847280.643 [DVL_micro](ERROR): Data Fault
2019-06-06T18:54:40.679Z,1559847280.679 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-06-06T18:54:41.107Z,1559847281.107 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:54:41.454Z,1559847281.454 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:41.910Z,1559847281.910 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-06-06T18:54:41.910Z,1559847281.910 [DVL_micro] No Fault, FailCount= 1
2019-06-06T18:54:42.261Z,1559847282.261 [DVL_micro](INFO): Initializing
2019-06-06T18:54:44.690Z,1559847284.690 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:47.518Z,1559847287.518 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:50.750Z,1559847290.750 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:53.578Z,1559847293.578 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:56.814Z,1559847296.814 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:54:59.638Z,1559847299.638 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:55:02.466Z,1559847302.466 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:55:04.486Z,1559847304.486 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:55:06.032Z,1559847306.032 [CommandLine](IMPORTANT): got command quit
2019-06-06T18:55:06.906Z,1559847306.906 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:55:07.047Z,1559847307.047 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:07.047Z,1559847307.047 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.230Z,1559847307.230 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-06-06T18:55:07.230Z,1559847307.230 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.231Z,1559847307.231 [CommandLine](INFO): Join timeout helper Thread ID is 9298
2019-06-06T18:55:07.250Z,1559847307.250 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-06-06T18:55:07.250Z,1559847307.250 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.251Z,1559847307.251 [NavChartDb](INFO): Join timeout helper Thread ID is 9299
2019-06-06T18:55:07.566Z,1559847307.566 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:07.567Z,1559847307.567 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.582Z,1559847307.582 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-06-06T18:55:07.582Z,1559847307.582 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.583Z,1559847307.583 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9300
2019-06-06T18:55:07.743Z,1559847307.743 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:07.743Z,1559847307.743 [WetLabsBB2FL](INFO): Powering down
2019-06-06T18:55:07.744Z,1559847307.744 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.754Z,1559847307.754 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-06-06T18:55:07.755Z,1559847307.755 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.755Z,1559847307.755 [CTD_Seabird](INFO): Join timeout helper Thread ID is 9301
2019-06-06T18:55:07.779Z,1559847307.779 [CTD_Seabird](INFO): Powering down
2019-06-06T18:55:07.791Z,1559847307.791 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:07.792Z,1559847307.792 [CTD_Seabird](INFO): Powering down
2019-06-06T18:55:07.806Z,1559847307.806 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.814Z,1559847307.814 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-06-06T18:55:07.814Z,1559847307.814 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.815Z,1559847307.815 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 9302
2019-06-06T18:55:07.907Z,1559847307.907 [CTD_NeilBrown](INFO): Powering down
2019-06-06T18:55:07.918Z,1559847307.918 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:07.919Z,1559847307.919 [CTD_NeilBrown](INFO): Powering down
2019-06-06T18:55:07.930Z,1559847307.930 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.947Z,1559847307.947 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-06-06T18:55:07.947Z,1559847307.947 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:07.948Z,1559847307.948 [Radio_Surface](INFO): Join timeout helper Thread ID is 9303
2019-06-06T18:55:08.286Z,1559847308.286 [Radio_Surface](INFO): Powering down
2019-06-06T18:55:08.287Z,1559847308.287 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:08.288Z,1559847308.288 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:08.303Z,1559847308.303 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-06-06T18:55:08.303Z,1559847308.303 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:08.304Z,1559847308.304 [DataOverHttps](INFO): Join timeout helper Thread ID is 9304
2019-06-06T18:55:09.638Z,1559847309.638 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:09.641Z,1559847309.641 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:09.655Z,1559847309.655 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-06-06T18:55:09.655Z,1559847309.655 [logger ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:09.656Z,1559847309.656 [logger](INFO): Join timeout helper Thread ID is 9305
2019-06-06T18:55:09.724Z,1559847309.724 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:09.725Z,1559847309.725 [logger ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:09.734Z,1559847309.734 [NAL9602](DEBUG): Fix Requested
2019-06-06T18:55:09.740Z,1559847309.740 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-06-06T18:55:09.740Z,1559847309.740 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:09.740Z,1559847309.740 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-06-06T18:55:09.740Z,1559847309.740 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:09.741Z,1559847309.741 [controlThread](INFO): Join timeout helper Thread ID is 9306
2019-06-06T18:55:09.774Z,1559847309.774 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-06-06T18:55:09.774Z,1559847309.774 [controlThread](DEBUG): Uninitializing ControlThread
2019-06-06T18:55:09.775Z,1559847309.775 [AHRS_M2](INFO): Powering down
2019-06-06T18:55:09.918Z,1559847309.918 [DVL_micro](INFO): uninitialize:Powering down
2019-06-06T18:55:09.919Z,1559847309.919 [NAL9602](INFO): Powering down
2019-06-06T18:55:09.921Z,1559847309.921 [Aanderaa_O2](INFO): Powering down
2019-06-06T18:55:09.943Z,1559847309.943 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-06-06T18:55:09.944Z,1559847309.944 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-06-06T18:55:09.945Z,1559847309.945 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-06-06T18:55:09.945Z,1559847309.945 [MissionManager](INFO): Uninitializing Mission Default
2019-06-06T18:55:09.945Z,1559847309.945 [Default] Stopped
2019-06-06T18:55:09.945Z,1559847309.945 [Default](DEBUG): Aggregate::uninitialize Default
2019-06-06T18:55:09.945Z,1559847309.945 [Default:B.GoToSurface] Stopped
2019-06-06T18:55:09.946Z,1559847309.946 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-06-06T18:55:09.946Z,1559847309.946 [Default:CheckIn] Stopped
2019-06-06T18:55:09.946Z,1559847309.946 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-06-06T18:55:09.946Z,1559847309.946 [Default:CheckIn:Read_GPS] Stopped
2019-06-06T18:55:09.950Z,1559847309.950 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-06-06T18:55:09.950Z,1559847309.950 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-06-06T18:55:09.950Z,1559847309.950 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-06-06T18:55:09.951Z,1559847309.951 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-06-06T18:55:09.951Z,1559847309.951 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-06-06T18:55:09.951Z,1559847309.951 [BuoyancyServo](INFO): Powering down
2019-06-06T18:55:09.962Z,1559847309.962 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-06-06T18:55:09.963Z,1559847309.963 [ElevatorServo](INFO): Powering down
2019-06-06T18:55:09.963Z,1559847309.963 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-06-06T18:55:09.963Z,1559847309.963 [MassServo](INFO): Powering down
2019-06-06T18:55:09.964Z,1559847309.964 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-06-06T18:55:09.964Z,1559847309.964 [RudderServo](INFO): Powering down
2019-06-06T18:55:09.965Z,1559847309.965 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-06-06T18:55:09.965Z,1559847309.965 [ThrusterServo](INFO): Powering down
2019-06-06T18:55:09.966Z,1559847309.966 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-06-06T18:55:09.966Z,1559847309.966 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-06-06T18:55:09.967Z,1559847309.967 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-06-06T18:55:09.967Z,1559847309.967 [CBIT](DEBUG): Powering off loads.
2019-06-06T18:55:09.978Z,1559847309.978 [CBIT](DEBUG): Disabling WDT.
2019-06-06T18:55:09.990Z,1559847309.990 [CBIT](DEBUG): Opening all GF detection circuits.
2019-06-06T18:55:09.991Z,1559847309.991 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:10.072Z,1559847310.072 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:10.080Z,1559847310.080 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:10.110Z,1559847310.110 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:10.114Z,1559847310.114 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:10.120Z,1559847310.120 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:10.157Z,1559847310.157 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-06-06T18:55:10.246Z,1559847310.246 [logger ThreadHandler](INFO): Thread cancelled.