2019-07-01T15:58:07.916Z,1561996687.916 [Supervisor](DEBUG): Initializing supervisor.
2019-07-01T15:58:07.918Z,1561996687.918 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-07-01T15:58:07.919Z,1561996687.919 [SyncHandler](INFO): Protected caller Thread ID is 808
2019-07-01T15:58:07.919Z,1561996687.919 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-07-01T15:58:07.920Z,1561996687.920 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-07-01T15:58:07.920Z,1561996687.920 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 809
2019-07-01T15:58:07.923Z,1561996687.923 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-07-01T15:58:07.934Z,1561996687.934 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-07-01T15:58:07.935Z,1561996687.935 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-07-01T15:58:07.935Z,1561996687.935 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 810
2019-07-01T15:58:07.936Z,1561996687.936 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-07-01T15:58:07.937Z,1561996687.937 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-07-01T15:58:07.937Z,1561996687.937 [logger ThreadHandler](INFO): Protected caller Thread ID is 811
2019-07-01T15:58:07.939Z,1561996687.939 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-07-01T15:58:07.940Z,1561996687.940 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-07-01T15:58:07.944Z,1561996687.944 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-07-01T15:58:08.380Z,1561996688.380 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-07-01T15:58:08.382Z,1561996688.382 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-07-01T15:58:08.481Z,1561996688.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-07-01T15:58:08.483Z,1561996688.483 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-07-01T15:58:08.806Z,1561996688.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-07-01T15:58:08.808Z,1561996688.808 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-07-01T15:58:08.950Z,1561996688.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-07-01T15:58:08.951Z,1561996688.951 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-07-01T15:58:09.145Z,1561996689.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-07-01T15:58:09.147Z,1561996689.147 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-07-01T15:58:09.610Z,1561996689.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-07-01T15:58:09.612Z,1561996689.612 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-07-01T15:58:09.823Z,1561996689.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-07-01T15:58:09.824Z,1561996689.824 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-07-01T15:58:09.970Z,1561996689.970 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-07-01T15:58:09.972Z,1561996689.972 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-07-01T15:58:10.170Z,1561996690.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-07-01T15:58:10.172Z,1561996690.172 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-07-01T15:58:10.268Z,1561996690.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-07-01T15:58:10.269Z,1561996690.269 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-07-01T15:58:10.590Z,1561996690.590 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-07-01T15:58:10.591Z,1561996690.591 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-07-01T15:58:10.673Z,1561996690.673 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-07-01T15:58:10.776Z,1561996690.776 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-07-01T15:58:10.777Z,1561996690.777 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-07-01T15:58:11.390Z,1561996691.390 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-07-01T15:58:11.681Z,1561996691.681 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-07-01T15:58:12.210Z,1561996692.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-07-01T15:58:12.212Z,1561996692.212 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-07-01T15:58:12.215Z,1561996692.215 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-07-01T15:58:12.429Z,1561996692.429 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-07-01T15:58:12.531Z,1561996692.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-07-01T15:58:12.630Z,1561996692.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-07-01T15:58:12.861Z,1561996692.861 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-07-01T15:58:12.861Z,1561996692.861 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-07-01T15:58:12.947Z,1561996692.947 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-07-01T15:58:13.041Z,1561996693.041 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-07-01T15:58:13.138Z,1561996693.138 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-07-01T15:58:13.222Z,1561996693.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-07-01T15:58:13.330Z,1561996693.330 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-07-01T15:58:13.514Z,1561996693.514 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-07-01T15:58:13.645Z,1561996693.645 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-07-01T15:58:13.653Z,1561996693.653 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-07-01T15:58:14.421Z,1561996694.421 [AHRS_M2] Loaded
2019-07-01T15:58:14.422Z,1561996694.422 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-07-01T15:58:14.563Z,1561996694.563 [DataOverHttps] Loaded
2019-07-01T15:58:14.563Z,1561996694.563 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-07-01T15:58:14.565Z,1561996694.565 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407654E0
2019-07-01T15:58:14.565Z,1561996694.565 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 890
2019-07-01T15:58:14.578Z,1561996694.578 [Depth_Keller] Loaded
2019-07-01T15:58:14.579Z,1561996694.579 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-07-01T15:58:14.583Z,1561996694.583 [DropWeight] Loaded
2019-07-01T15:58:14.584Z,1561996694.584 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-07-01T15:58:14.642Z,1561996694.642 [DUSBL_Hydroid] Loaded
2019-07-01T15:58:14.642Z,1561996694.642 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-07-01T15:58:14.744Z,1561996694.744 [NAL9602] Loaded
2019-07-01T15:58:14.744Z,1561996694.744 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-07-01T15:58:14.760Z,1561996694.760 [Onboard] Loaded
2019-07-01T15:58:14.761Z,1561996694.761 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-07-01T15:58:14.767Z,1561996694.767 [PowerOnly] Loaded
2019-07-01T15:58:14.767Z,1561996694.767 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-07-01T15:58:14.774Z,1561996694.774 [Radio_Surface] Loaded
2019-07-01T15:58:14.774Z,1561996694.774 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-07-01T15:58:14.775Z,1561996694.775 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407954E0
2019-07-01T15:58:14.775Z,1561996694.775 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 891
2019-07-01T15:58:14.820Z,1561996694.820 [RDI_Pathfinder] Loaded
2019-07-01T15:58:14.820Z,1561996694.820 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-07-01T15:58:16.342Z,1561996696.342 [BPC1] Loaded
2019-07-01T15:58:16.342Z,1561996696.342 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-07-01T15:58:16.343Z,1561996696.343 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-07-01T15:58:16.343Z,1561996696.343 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-07-01T15:58:16.368Z,1561996696.368 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-07-01T15:58:16.368Z,1561996696.368 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-07-01T15:58:16.493Z,1561996696.493 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-07-01T15:58:16.493Z,1561996696.493 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-07-01T15:58:16.514Z,1561996696.514 [NavChart] Loaded
2019-07-01T15:58:16.514Z,1561996696.514 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-07-01T15:58:16.518Z,1561996696.518 [UniversalFixResidualReporter] Loaded
2019-07-01T15:58:16.519Z,1561996696.519 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-07-01T15:58:16.519Z,1561996696.519 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-07-01T15:58:16.520Z,1561996696.520 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-07-01T15:58:17.120Z,1561996697.120 [BuoyancyServo] Loaded
2019-07-01T15:58:17.120Z,1561996697.120 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-07-01T15:58:17.135Z,1561996697.135 [ElevatorServo] Loaded
2019-07-01T15:58:17.136Z,1561996697.136 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-07-01T15:58:17.155Z,1561996697.155 [MassServo] Loaded
2019-07-01T15:58:17.155Z,1561996697.155 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-07-01T15:58:17.171Z,1561996697.171 [RudderServo] Loaded
2019-07-01T15:58:17.171Z,1561996697.171 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-07-01T15:58:17.185Z,1561996697.185 [ThrusterServo] Loaded
2019-07-01T15:58:17.186Z,1561996697.186 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-07-01T15:58:17.186Z,1561996697.186 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-07-01T15:58:17.187Z,1561996697.187 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-07-01T15:58:17.516Z,1561996697.516 [CTD_NeilBrown] Loaded
2019-07-01T15:58:17.516Z,1561996697.516 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-07-01T15:58:17.517Z,1561996697.517 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408E04E0
2019-07-01T15:58:17.517Z,1561996697.517 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 892
2019-07-01T15:58:17.562Z,1561996697.562 [WetLabsSeaOWL_UV_A] Loaded
2019-07-01T15:58:17.563Z,1561996697.563 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-07-01T15:58:17.564Z,1561996697.564 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409104E0
2019-07-01T15:58:17.564Z,1561996697.564 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 893
2019-07-01T15:58:17.565Z,1561996697.565 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-07-01T15:58:17.565Z,1561996697.565 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-07-01T15:58:17.918Z,1561996697.918 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-07-01T15:58:17.919Z,1561996697.919 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-07-01T15:58:17.975Z,1561996697.975 [DepthRateCalculator] Loaded
2019-07-01T15:58:17.976Z,1561996697.976 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-07-01T15:58:17.981Z,1561996697.981 [PitchRateCalculator] Loaded
2019-07-01T15:58:17.982Z,1561996697.982 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-07-01T15:58:17.994Z,1561996697.994 [SpeedCalculator] Loaded
2019-07-01T15:58:17.994Z,1561996697.994 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-07-01T15:58:18.015Z,1561996698.015 [TempGradientCalculator] Loaded
2019-07-01T15:58:18.016Z,1561996698.016 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-07-01T15:58:18.021Z,1561996698.021 [YawRateCalculator] Loaded
2019-07-01T15:58:18.022Z,1561996698.022 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-07-01T15:58:18.063Z,1561996698.063 [ElevatorOffsetCalculator] Loaded
2019-07-01T15:58:18.063Z,1561996698.063 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-07-01T15:58:18.063Z,1561996698.063 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-07-01T15:58:18.064Z,1561996698.064 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-07-01T15:58:18.230Z,1561996698.230 [SBIT](DEBUG): Construct Startup Built In Test.
2019-07-01T15:58:18.252Z,1561996698.252 [SBIT] Loaded
2019-07-01T15:58:18.252Z,1561996698.252 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-07-01T15:58:18.253Z,1561996698.253 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-07-01T15:58:18.265Z,1561996698.265 [IBIT] Loaded
2019-07-01T15:58:18.265Z,1561996698.265 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-07-01T15:58:18.268Z,1561996698.268 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-07-01T15:58:18.408Z,1561996698.408 [CBIT] Loaded
2019-07-01T15:58:18.409Z,1561996698.409 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-07-01T15:58:18.409Z,1561996698.409 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-07-01T15:58:18.410Z,1561996698.410 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-07-01T15:58:18.534Z,1561996698.534 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-07-01T15:58:18.535Z,1561996698.535 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-07-01T15:58:18.663Z,1561996698.663 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-07-01T15:58:18.664Z,1561996698.664 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-07-01T15:58:18.752Z,1561996698.752 [VerticalControl](DEBUG): Construct VerticalControl.
2019-07-01T15:58:18.837Z,1561996698.837 [VerticalControl] Loaded
2019-07-01T15:58:18.838Z,1561996698.838 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-07-01T15:58:18.838Z,1561996698.838 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-07-01T15:58:18.897Z,1561996698.897 [HorizontalControl] Loaded
2019-07-01T15:58:18.897Z,1561996698.897 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-07-01T15:58:18.898Z,1561996698.898 [SpeedControl](DEBUG): Construct SpeedControl.
2019-07-01T15:58:18.900Z,1561996698.900 [SpeedControl] Loaded
2019-07-01T15:58:18.900Z,1561996698.900 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-07-01T15:58:18.901Z,1561996698.901 [LoopControl](DEBUG): Construct LoopControl.
2019-07-01T15:58:18.901Z,1561996698.901 [LoopControl] Loaded
2019-07-01T15:58:18.901Z,1561996698.901 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-07-01T15:58:18.902Z,1561996698.902 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-07-01T15:58:18.903Z,1561996698.903 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-07-01T15:58:18.952Z,1561996698.952 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-07-01T15:58:18.956Z,1561996698.956 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-07-01T15:58:18.957Z,1561996698.957 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-07-01T15:58:18.963Z,1561996698.963 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-07-01T15:58:18.964Z,1561996698.964 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2019-07-01T15:58:18.965Z,1561996698.965 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 894
2019-07-01T15:58:18.969Z,1561996698.969 [Supervisor](INFO): Main Thread ID is 804
2019-07-01T15:58:18.969Z,1561996698.969 [Supervisor](DEBUG): Running supervisor.
2019-07-01T15:58:18.970Z,1561996698.970 [CommandLine ThreadHandler](INFO): Handler Thread ID is 895
2019-07-01T15:58:18.972Z,1561996698.972 [controlThread ThreadHandler](INFO): Handler Thread ID is 896
2019-07-01T15:58:18.973Z,1561996698.973 [controlThread](DEBUG): Initializing ControlThread
2019-07-01T15:58:18.980Z,1561996698.980 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-07-01T15:58:18.981Z,1561996698.981 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-07-01T15:58:18.982Z,1561996698.982 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-07-01T15:58:18.982Z,1561996698.982 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-07-01T15:58:18.982Z,1561996698.982 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-07-01T15:58:18.983Z,1561996698.983 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-07-01T15:58:18.983Z,1561996698.983 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-07-01T15:58:18.984Z,1561996698.984 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-07-01T15:58:18.984Z,1561996698.984 [SBIT](INFO): Initialize SBIT Component.
2019-07-01T15:58:18.985Z,1561996698.985 [SBIT](IMPORTANT): git: 2019-07-01
2019-07-01T15:58:18.985Z,1561996698.985 [SBIT](INFO): git hash: 66ee1f914ed66d399bd38d45ccca9e12ca50b60d
2019-07-01T15:58:18.985Z,1561996698.985 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-07-01T15:58:18.986Z,1561996698.986 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-07-01T15:58:18.987Z,1561996698.987 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-07-01T15:58:18.988Z,1561996698.988 [IBIT](INFO): Initialize IBIT Component.
2019-07-01T15:58:18.989Z,1561996698.989 [CBIT](DEBUG): Initialize CBIT Component.
2019-07-01T15:58:18.990Z,1561996698.990 [logger ThreadHandler](INFO): Handler Thread ID is 897
2019-07-01T15:58:19.001Z,1561996699.001 [CBIT](DEBUG): Initialized mux pins.
2019-07-01T15:58:19.001Z,1561996699.001 [CBIT](DEBUG): Initializing the watchdog timer.
2019-07-01T15:58:19.009Z,1561996699.009 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 898
2019-07-01T15:58:19.010Z,1561996699.010 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-07-01T15:58:19.021Z,1561996699.021 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 899
2019-07-01T15:58:19.025Z,1561996699.025 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-07-01T15:58:19.025Z,1561996699.025 [CBIT](DEBUG): Initializing heartbeat.
2019-07-01T15:58:19.033Z,1561996699.033 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 900
2019-07-01T15:58:19.034Z,1561996699.034 [CTD_NeilBrown](INFO): Powering down
2019-07-01T15:58:19.063Z,1561996699.063 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 901
2019-07-01T15:58:19.064Z,1561996699.064 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-07-01T15:58:19.096Z,1561996699.096 [CBIT](DEBUG): Deactivating GF circuits.
2019-07-01T15:58:19.097Z,1561996699.097 [CBIT](DEBUG): Deactivating emergency mode.
2019-07-01T15:58:19.097Z,1561996699.097 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 902
2019-07-01T15:58:19.105Z,1561996699.105 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-07-01T15:58:19.106Z,1561996699.106 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-07-01T15:58:19.106Z,1561996699.106 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-07-01T15:58:19.106Z,1561996699.106 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-07-01T15:58:19.106Z,1561996699.106 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-07-01T15:58:19.106Z,1561996699.106 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-07-01T15:58:19.107Z,1561996699.107 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-07-01T15:58:19.107Z,1561996699.107 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-07-01T15:58:19.107Z,1561996699.107 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-07-01T15:58:19.107Z,1561996699.107 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-07-01T15:58:19.107Z,1561996699.107 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-07-01T15:58:19.107Z,1561996699.107 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-07-01T15:58:19.108Z,1561996699.108 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-07-01T15:58:19.108Z,1561996699.108 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-07-01T15:58:19.108Z,1561996699.108 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-07-01T15:58:19.108Z,1561996699.108 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-07-01T15:58:19.132Z,1561996699.132 [CBIT](DEBUG): Backplane powered.
2019-07-01T15:58:19.133Z,1561996699.133 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-07-01T15:58:19.135Z,1561996699.135 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-07-01T15:58:19.135Z,1561996699.135 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-07-01T15:58:19.136Z,1561996699.136 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-07-01T15:58:19.137Z,1561996699.137 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-07-01T15:58:19.160Z,1561996699.160 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-01T15:58:19.182Z,1561996699.182 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2019-07-01T15:58:19.183Z,1561996699.183 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-07-01T15:58:19.264Z,1561996699.264 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-07-01T15:58:19.277Z,1561996699.277 [Default:A.Wait](DEBUG): Construct Wait.
2019-07-01T15:58:19.278Z,1561996699.278 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-07-01T15:58:19.317Z,1561996699.317 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-07-01T15:58:19.319Z,1561996699.319 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-07-01T15:58:19.335Z,1561996699.335 [Default:E.Execute](DEBUG): Construct Execute.
2019-07-01T15:58:19.338Z,1561996699.338 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2019-07-01T15:58:19.364Z,1561996699.364 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-07-01T15:58:19.378Z,1561996699.378 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-07-01T15:58:19.425Z,1561996699.425 [Radio_Surface](INFO): Powering up
2019-07-01T15:58:19.452Z,1561996699.452 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-07-01T15:58:19.453Z,1561996699.453 [DUSBL_Hydroid](INFO): Powering up
2019-07-01T15:58:19.453Z,1561996699.453 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-07-01T15:58:19.541Z,1561996699.541 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-07-01T15:58:19.581Z,1561996699.581 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-07-01T15:58:19.589Z,1561996699.589 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-07-01T15:58:19.590Z,1561996699.590 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-07-01T15:58:19.597Z,1561996699.597 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-07-01T15:58:19.598Z,1561996699.598 [MassServo](DEBUG): Initializing EZServoServo.
2019-07-01T15:58:19.605Z,1561996699.605 [MassServo](DEBUG): Initializing MassServo.
2019-07-01T15:58:19.606Z,1561996699.606 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-01T15:58:19.613Z,1561996699.613 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-01T15:58:19.614Z,1561996699.614 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-07-01T15:58:19.621Z,1561996699.621 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-07-01T15:58:19.789Z,1561996699.789 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-07-01T15:58:19.789Z,1561996699.789 [DropWeight] Hardware Fault, FailCount= 1
2019-07-01T15:58:19.789Z,1561996699.789 [DropWeight](ERROR): Hardware Fault
2019-07-01T15:58:19.809Z,1561996699.809 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-07-01T15:58:19.829Z,1561996699.829 [CommandLine](FAULT): Scheduling is paused
2019-07-01T15:58:19.830Z,1561996699.830 [CBIT](INFO): Critical error at 20190701T155819
2019-07-01T15:58:19.830Z,1561996699.830 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-07-01T15:58:19.832Z,1561996699.832 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-07-01T15:58:19.833Z,1561996699.833 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-07-01T15:58:20.505Z,1561996700.505 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-07-01T15:58:20.505Z,1561996700.505 [RudderServo](FAULT): Rudder failed to initialize
2019-07-01T15:58:20.505Z,1561996700.505 [RudderServo] Communications Fault, FailCount= 1
2019-07-01T15:58:20.505Z,1561996700.505 [RudderServo](ERROR): Communications Fault
2019-07-01T15:58:20.614Z,1561996700.614 [CBIT](INFO): Critical error at 20190701T155819
2019-07-01T15:58:20.617Z,1561996700.617 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-07-01T15:58:20.786Z,1561996700.786 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-01T15:58:20.786Z,1561996700.786 [RudderServo](INFO): Powering down
2019-07-01T15:58:21.460Z,1561996701.460 [RudderServo](DEBUG): Initializing EZServoServo.
2019-07-01T15:58:21.581Z,1561996701.581 [RudderServo](DEBUG): Initializing RudderServo.
2019-07-01T15:58:21.586Z,1561996701.586 [CBIT](INFO): Clearing failed state for component RudderServo
2019-07-01T15:58:21.586Z,1561996701.586 [RudderServo] No Fault, FailCount= 1
2019-07-01T15:58:32.882Z,1561996712.882 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-07-01T15:58:37.298Z,1561996717.298 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-07-01T15:58:44.970Z,1561996724.970 [NAL9602](INFO): Powering up NAL9602
2019-07-01T15:58:47.427Z,1561996727.427 [SBIT](IMPORTANT): Beginning Startup BIT
2019-07-01T15:58:47.434Z,1561996727.434 [CBIT](IMPORTANT): Beginning ground fault scan
2019-07-01T15:58:55.978Z,1561996735.978 [NAL9602](INFO): NAL9602 initialized
2019-07-01T15:58:56.797Z,1561996736.797 [NAL9602](DEBUG): Fix Requested
2019-07-01T15:58:58.473Z,1561996738.473 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.010262
CHAN A1 (24V): -0.196816
CHAN A2 (12V): -0.007214
CHAN A3 (5V): -0.002307
CHAN B0 (3.3V): 0.000222
CHAN B1 (3.15aV): 0.000017
CHAN B2 (3.15bV): -0.000099
CHAN B3 (GND): 0.002147
OPEN: 0.006339
Full Scale Calc: 4.765 mA, -1.589 mA
2019-07-01T15:59:40.676Z,1561996780.676 [SBIT](IMPORTANT): SBIT PASSED
2019-07-01T15:59:40.714Z,1561996780.714 [CommandLine](IMPORTANT): got command configSet list
2019-07-01T15:59:40.715Z,1561996780.715 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-01T15:59:40.717Z,1561996780.717 [CommandLine](IMPORTANT): Micromodem.loadAtStartup=0 bool;

2019-07-01T15:59:41.095Z,1561996781.095 [MissionManager](IMPORTANT): Started mission Startup
2019-07-01T15:59:41.095Z,1561996781.095 [Startup] Running Loop=1
2019-07-01T15:59:41.095Z,1561996781.095 [Startup](DEBUG): Aggregate::initialize Startup
2019-07-01T15:59:41.095Z,1561996781.095 [Startup:A.GoToSurface] Running Loop=1
2019-07-01T15:59:41.095Z,1561996781.095 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-01T15:59:41.096Z,1561996781.096 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-01T15:59:41.097Z,1561996781.097 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-01T15:59:41.097Z,1561996781.097 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-01T15:59:41.097Z,1561996781.097 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-01T15:59:41.098Z,1561996781.098 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-01T15:59:41.099Z,1561996781.099 [Startup:StartupSatComms] Running Loop=1
2019-07-01T15:59:41.099Z,1561996781.099 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-07-01T15:59:41.099Z,1561996781.099 [Startup:StartupSatComms:A] Running Loop=1
2019-07-01T15:59:41.470Z,1561996781.470 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-07-01T16:00:08.593Z,1561996808.593 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T16:00:41.259Z,1561996841.259 [Startup:StartupSatComms:A](INFO): Timed out from 2019-07-01T15:59:41.1Z
2019-07-01T16:00:41.259Z,1561996841.259 [Startup:StartupSatComms:A] Stopped
2019-07-01T16:00:41.259Z,1561996841.259 [Startup:StartupSatComms:B] Running Loop=1
2019-07-01T16:00:41.651Z,1561996841.651 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-01T16:00:48.363Z,1561996848.363 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005080
2019-07-01T16:00:54.219Z,1561996854.219 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190701T154840/Courier0007.lzma
2019-07-01T16:00:54.998Z,1561996854.998 [DataOverHttps](INFO): Moved sent file to Logs/20190701T154840/Courier0007.lzma.bak
2019-07-01T16:00:54.998Z,1561996854.998 [DataOverHttps](INFO): SBD MOMSN=11416636
2019-07-01T16:01:06.584Z,1561996866.584 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20190701T155807/Courier0000.lzma
2019-07-01T16:01:07.390Z,1561996867.390 [DataOverHttps](INFO): Moved sent file to Logs/20190701T155807/Courier0000.lzma.bak
2019-07-01T16:01:07.390Z,1561996867.390 [DataOverHttps](INFO): SBD MOMSN=11416638
2019-07-01T16:01:19.327Z,1561996879.327 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-07-01T16:01:19.327Z,1561996879.327 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:01:19.341Z,1561996879.341 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:01:19.722Z,1561996879.722 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:01:19.722Z,1561996879.722 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-07-01T16:01:23.769Z,1561996883.769 [DataOverHttps](INFO): Sending 625 bytes from file Logs/20190701T154840/Express0001.lzma
2019-07-01T16:01:24.506Z,1561996884.506 [DataOverHttps](INFO): Moved sent file to Logs/20190701T154840/Express0001.lzma.bak
2019-07-01T16:01:24.506Z,1561996884.506 [DataOverHttps](INFO): SBD MOMSN=11416643
2019-07-01T16:01:41.541Z,1561996901.541 [Startup:StartupSatComms:B](INFO): Timed out from 2019-07-01T16:00:41.3Z
2019-07-01T16:01:41.541Z,1561996901.541 [Startup:StartupSatComms:B] Stopped
2019-07-01T16:01:41.542Z,1561996901.542 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-07-01T16:01:41.542Z,1561996901.542 [Startup:StartupSatComms] Stopped
2019-07-01T16:01:41.542Z,1561996901.542 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-07-01T16:01:41.543Z,1561996901.543 [Startup](INFO): Completed Startup
2019-07-01T16:01:41.543Z,1561996901.543 [MissionManager](INFO): Startup is completed.
2019-07-01T16:01:41.543Z,1561996901.543 [MissionManager](INFO): Uninitializing Mission Startup
2019-07-01T16:01:41.543Z,1561996901.543 [Startup] Stopped
2019-07-01T16:01:41.543Z,1561996901.543 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-07-01T16:01:41.543Z,1561996901.543 [Startup:A.GoToSurface] Stopped
2019-07-01T16:01:41.543Z,1561996901.543 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-01T16:01:41.961Z,1561996901.961 [MissionManager](IMPORTANT): Started mission Default
2019-07-01T16:01:41.961Z,1561996901.961 [Default] Running Loop=1
2019-07-01T16:01:41.961Z,1561996901.961 [Default](DEBUG): Aggregate::initialize Default
2019-07-01T16:01:41.961Z,1561996901.961 [Default:B.GoToSurface] Running Loop=1
2019-07-01T16:01:41.961Z,1561996901.961 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-07-01T16:01:41.961Z,1561996901.961 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-07-01T16:01:41.962Z,1561996901.962 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-07-01T16:01:41.962Z,1561996901.962 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-07-01T16:01:41.962Z,1561996901.962 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-07-01T16:01:41.963Z,1561996901.963 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-07-01T16:01:41.963Z,1561996901.963 [Default:A.Wait] Running Loop=1
2019-07-01T16:01:41.963Z,1561996901.963 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-07-01T16:01:43.734Z,1561996903.734 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20190701T154840/Express0005.lzma
2019-07-01T16:01:44.538Z,1561996904.538 [DataOverHttps](INFO): Moved sent file to Logs/20190701T154840/Express0005.lzma.bak
2019-07-01T16:01:44.538Z,1561996904.538 [DataOverHttps](INFO): SBD MOMSN=11416659
2019-07-01T16:01:55.266Z,1561996915.266 [Default:A.Wait](INFO): Done Waiting.
2019-07-01T16:01:55.267Z,1561996915.267 [Default:A.Wait] Stopped
2019-07-01T16:01:55.267Z,1561996915.267 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T16:01:55.706Z,1561996915.706 [Default:CheckIn] Running Loop=1
2019-07-01T16:01:55.706Z,1561996915.706 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T16:01:55.707Z,1561996915.707 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T16:01:56.079Z,1561996916.079 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-07-01T16:02:43.019Z,1561996963.019 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-07-01T16:03:06.069Z,1561996986.069 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T16:03:59.274Z,1561997039.274 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-07-01T16:04:00.089Z,1561997040.089 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:02.921Z,1561997042.921 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:05.749Z,1561997045.749 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:08.981Z,1561997048.981 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:11.809Z,1561997051.809 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:15.037Z,1561997055.037 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:17.865Z,1561997057.865 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:20.298Z,1561997060.298 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-07-01T16:04:20.298Z,1561997060.298 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:04:20.333Z,1561997060.333 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:04:20.693Z,1561997060.693 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:20.741Z,1561997060.741 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:04:20.741Z,1561997060.741 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-07-01T16:04:23.925Z,1561997063.925 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:26.753Z,1561997066.753 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:26.847Z,1561997066.847 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T16:04:29.985Z,1561997069.985 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:32.816Z,1561997072.816 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:36.048Z,1561997076.048 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:38.873Z,1561997078.873 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:42.105Z,1561997082.105 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:44.933Z,1561997084.933 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:47.761Z,1561997087.761 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:50.993Z,1561997090.993 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:53.821Z,1561997093.821 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:57.053Z,1561997097.053 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:04:59.889Z,1561997099.889 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:03.121Z,1561997103.121 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:05.945Z,1561997105.945 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:08.785Z,1561997108.785 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:12.005Z,1561997112.005 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:14.829Z,1561997114.829 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:18.061Z,1561997118.061 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:20.893Z,1561997120.893 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:24.121Z,1561997124.121 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:26.957Z,1561997126.957 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:30.183Z,1561997130.183 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:33.013Z,1561997133.013 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:35.837Z,1561997135.837 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:39.073Z,1561997139.073 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:41.897Z,1561997141.897 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:45.133Z,1561997145.133 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:47.957Z,1561997147.957 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:51.189Z,1561997151.189 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:54.017Z,1561997154.017 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:05:56.845Z,1561997156.845 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:00.081Z,1561997160.081 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:02.909Z,1561997162.909 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:06.141Z,1561997166.141 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:08.965Z,1561997168.965 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:11.797Z,1561997171.797 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:15.037Z,1561997175.037 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:15.143Z,1561997175.143 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-07-01T16:06:17.881Z,1561997177.881 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:21.085Z,1561997181.085 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:21.154Z,1561997181.154 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-07-01T16:06:21.166Z,1561997181.166 [BPC1](INFO): Received data from all battery sticks.
2019-07-01T16:06:23.925Z,1561997183.925 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:27.145Z,1561997187.145 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:29.973Z,1561997189.973 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:32.805Z,1561997192.805 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:36.033Z,1561997196.033 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:38.861Z,1561997198.861 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:42.093Z,1561997202.093 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:44.921Z,1561997204.921 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:48.153Z,1561997208.153 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:50.985Z,1561997210.985 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:53.809Z,1561997213.809 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:55.860Z,1561997215.860 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-01T16:01:55.7Z
2019-07-01T16:06:55.861Z,1561997215.861 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T16:06:55.861Z,1561997215.861 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T16:06:56.258Z,1561997216.258 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-07-01T16:06:57.037Z,1561997217.037 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:06:59.886Z,1561997219.886 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:01.720Z,1561997221.720 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20190701T155807/Courier0004.lzma
2019-07-01T16:07:02.526Z,1561997222.526 [DataOverHttps](INFO): Moved sent file to Logs/20190701T155807/Courier0004.lzma.bak
2019-07-01T16:07:02.526Z,1561997222.526 [DataOverHttps](INFO): SBD MOMSN=11416688
2019-07-01T16:07:03.101Z,1561997223.101 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:05.936Z,1561997225.936 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:09.161Z,1561997229.161 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:11.993Z,1561997231.993 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:14.541Z,1561997234.541 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190701T154840/Express0008.lzma
2019-07-01T16:07:14.817Z,1561997234.817 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:15.342Z,1561997235.342 [DataOverHttps](INFO): Moved sent file to Logs/20190701T154840/Express0008.lzma.bak
2019-07-01T16:07:15.342Z,1561997235.342 [DataOverHttps](INFO): SBD MOMSN=11416690
2019-07-01T16:07:18.049Z,1561997238.049 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:20.881Z,1561997240.881 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:21.311Z,1561997241.311 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-07-01T16:07:21.311Z,1561997241.311 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:07:21.322Z,1561997241.322 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:07:21.718Z,1561997241.718 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:07:21.719Z,1561997241.719 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-07-01T16:07:24.113Z,1561997244.113 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:26.941Z,1561997246.941 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:27.021Z,1561997247.021 [DataOverHttps](INFO): Sending 662 bytes from file Logs/20190701T155807/Express0001.lzma
2019-07-01T16:07:27.846Z,1561997247.846 [DataOverHttps](INFO): Moved sent file to Logs/20190701T155807/Express0001.lzma.bak
2019-07-01T16:07:27.846Z,1561997247.846 [DataOverHttps](INFO): SBD MOMSN=11416692
2019-07-01T16:07:30.169Z,1561997250.169 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:32.997Z,1561997252.997 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:35.825Z,1561997255.825 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:39.057Z,1561997259.057 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:39.932Z,1561997259.932 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20190701T155807/Express0005.lzma
2019-07-01T16:07:40.738Z,1561997260.738 [DataOverHttps](INFO): Moved sent file to Logs/20190701T155807/Express0005.lzma.bak
2019-07-01T16:07:40.738Z,1561997260.738 [DataOverHttps](INFO): SBD MOMSN=11416707
2019-07-01T16:07:41.885Z,1561997261.885 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:42.333Z,1561997262.333 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T16:07:42.333Z,1561997262.333 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T16:07:42.333Z,1561997262.333 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T16:07:45.121Z,1561997265.121 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:47.945Z,1561997267.945 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:50.773Z,1561997270.773 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:54.005Z,1561997274.005 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:07:56.833Z,1561997276.833 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:00.065Z,1561997280.065 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:02.897Z,1561997282.897 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:06.125Z,1561997286.125 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:08.953Z,1561997288.953 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:12.185Z,1561997292.185 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:15.013Z,1561997295.013 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:17.841Z,1561997297.841 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:21.073Z,1561997301.073 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:23.904Z,1561997303.904 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:27.133Z,1561997307.133 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:29.961Z,1561997309.961 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:33.193Z,1561997313.193 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:36.025Z,1561997316.025 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:38.861Z,1561997318.861 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:42.081Z,1561997322.081 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:44.909Z,1561997324.909 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:48.145Z,1561997328.145 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:50.969Z,1561997330.969 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:54.205Z,1561997334.205 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:08:57.014Z,1561997337.014 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-01T16:08:57.015Z,1561997337.015 [NAL9602] Data Fault, FailCount= 1
2019-07-01T16:08:57.015Z,1561997337.015 [NAL9602](ERROR): Data Fault
2019-07-01T16:08:57.090Z,1561997337.090 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-01T16:08:57.422Z,1561997337.422 [NAL9602](INFO): Powering down
2019-07-01T16:08:58.254Z,1561997338.254 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-01T16:08:58.255Z,1561997338.255 [NAL9602] No Fault, FailCount= 1
2019-07-01T16:09:27.726Z,1561997367.726 [NAL9602](INFO): Powering up NAL9602
2019-07-01T16:09:38.626Z,1561997378.626 [NAL9602](INFO): NAL9602 initialized
2019-07-01T16:09:39.449Z,1561997379.449 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:09:42.276Z,1561997382.276 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:09:45.508Z,1561997385.508 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:09:48.336Z,1561997388.336 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:09:51.568Z,1561997391.568 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:09:54.397Z,1561997394.397 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:09:57.231Z,1561997397.231 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:09:59.244Z,1561997399.244 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:01.264Z,1561997401.264 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:04.496Z,1561997404.496 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:07.325Z,1561997407.325 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:10.559Z,1561997410.559 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:13.441Z,1561997413.441 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:16.233Z,1561997416.233 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:18.249Z,1561997418.249 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:20.264Z,1561997420.264 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:22.315Z,1561997422.315 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-07-01T16:10:22.315Z,1561997422.315 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:10:22.325Z,1561997422.325 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:10:22.766Z,1561997422.766 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:10:22.766Z,1561997422.766 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-07-01T16:10:23.501Z,1561997423.501 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:26.329Z,1561997426.329 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:29.556Z,1561997429.556 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:32.393Z,1561997432.393 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:34.808Z,1561997434.808 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:37.233Z,1561997437.233 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:40.060Z,1561997440.060 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:42.889Z,1561997442.889 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:45.716Z,1561997445.716 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:48.949Z,1561997448.949 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:51.784Z,1561997451.784 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:55.021Z,1561997455.020 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:10:57.841Z,1561997457.841 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:01.077Z,1561997461.077 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:03.896Z,1561997463.896 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:07.128Z,1561997467.128 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:09.956Z,1561997469.956 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:13.188Z,1561997473.188 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:16.021Z,1561997476.021 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:18.845Z,1561997478.845 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:21.681Z,1561997481.681 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:23.709Z,1561997483.709 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:26.924Z,1561997486.924 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:29.757Z,1561997489.757 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:32.993Z,1561997492.993 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:35.821Z,1561997495.821 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:38.640Z,1561997498.640 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:40.661Z,1561997500.661 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:43.084Z,1561997503.084 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:45.924Z,1561997505.924 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:49.145Z,1561997509.145 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:51.977Z,1561997511.977 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:55.204Z,1561997515.204 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:11:58.033Z,1561997518.033 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:00.860Z,1561997520.860 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:03.709Z,1561997523.709 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:06.925Z,1561997526.925 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:09.750Z,1561997529.750 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:12.989Z,1561997532.989 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:15.808Z,1561997535.808 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:19.045Z,1561997539.045 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:21.868Z,1561997541.868 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:25.100Z,1561997545.100 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:27.933Z,1561997547.933 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:31.165Z,1561997551.165 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:33.989Z,1561997553.989 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:37.225Z,1561997557.225 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:40.049Z,1561997560.049 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:42.909Z,1561997562.909 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T16:12:42.910Z,1561997562.910 [Default:CheckIn:C.Wait] Stopped
2019-07-01T16:12:42.910Z,1561997562.910 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T16:12:42.910Z,1561997562.910 [Default:CheckIn:D] Running Loop=1
2019-07-01T16:12:43.285Z,1561997563.285 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:43.314Z,1561997563.314 [Default:CheckIn:D] Stopped
2019-07-01T16:12:43.314Z,1561997563.314 [Default:CheckIn:E] Running Loop=1
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.022545 min 
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn:E] Stopped
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn] Stopped
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn](INFO): Running loop #2
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn] Running Loop=2
2019-07-01T16:12:43.747Z,1561997563.747 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T16:12:43.748Z,1561997563.748 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T16:12:46.109Z,1561997566.109 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:48.941Z,1561997568.941 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:52.168Z,1561997572.168 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:54.996Z,1561997574.996 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:12:57.824Z,1561997577.824 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:01.065Z,1561997581.065 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:03.884Z,1561997583.884 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:07.116Z,1561997587.116 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:09.949Z,1561997589.949 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:12.780Z,1561997592.780 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:16.009Z,1561997596.009 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:18.837Z,1561997598.837 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:20.082Z,1561997600.082 [CBIT](INFO): Clearing failed state for component DropWeight
2019-07-01T16:13:20.082Z,1561997600.082 [DropWeight] No Fault, FailCount= 1
2019-07-01T16:13:22.070Z,1561997602.070 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:23.297Z,1561997603.297 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-07-01T16:13:23.297Z,1561997603.297 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:13:23.306Z,1561997603.306 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:13:23.733Z,1561997603.733 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:13:23.733Z,1561997603.733 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-07-01T16:13:24.897Z,1561997604.897 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:28.129Z,1561997608.129 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:30.960Z,1561997610.960 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:33.789Z,1561997613.789 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:37.017Z,1561997617.017 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:39.857Z,1561997619.857 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:43.081Z,1561997623.081 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:45.905Z,1561997625.905 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:49.144Z,1561997629.144 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:51.965Z,1561997631.965 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:54.793Z,1561997634.793 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:13:58.040Z,1561997638.040 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:00.857Z,1561997640.857 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:04.080Z,1561997644.080 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:06.916Z,1561997646.916 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:10.145Z,1561997650.145 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:12.973Z,1561997652.973 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:15.801Z,1561997655.801 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:19.029Z,1561997659.029 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:21.864Z,1561997661.864 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:25.088Z,1561997665.088 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:27.929Z,1561997667.929 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:31.156Z,1561997671.156 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:33.996Z,1561997673.996 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:36.813Z,1561997676.813 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:40.041Z,1561997680.041 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:42.873Z,1561997682.873 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:46.101Z,1561997686.101 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:48.924Z,1561997688.924 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:52.161Z,1561997692.161 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:54.992Z,1561997694.992 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:14:57.817Z,1561997697.817 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:01.057Z,1561997701.057 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:03.872Z,1561997703.872 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:07.108Z,1561997707.108 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:09.933Z,1561997709.933 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:13.168Z,1561997713.168 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:15.996Z,1561997715.996 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:18.828Z,1561997718.828 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:22.065Z,1561997722.065 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:24.889Z,1561997724.889 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:28.121Z,1561997728.121 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:30.945Z,1561997730.945 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:34.176Z,1561997734.176 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:37.004Z,1561997737.004 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:39.837Z,1561997739.837 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:43.064Z,1561997743.064 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:45.896Z,1561997745.896 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:49.124Z,1561997749.124 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:51.961Z,1561997751.961 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:55.185Z,1561997755.185 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:15:57.603Z,1561997757.603 [CommandLine](IMPORTANT): got command get CBIT.stopDepth
2019-07-01T16:15:57.604Z,1561997757.604 [CommandLine](IMPORTANT): CBIT.stopDepth 215.000000 m
2019-07-01T16:15:58.013Z,1561997758.013 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:00.841Z,1561997760.841 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:04.069Z,1561997764.069 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:06.897Z,1561997766.897 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:10.137Z,1561997770.137 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:10.874Z,1561997770.874 [CommandLine](IMPORTANT): got command get CBIT.abortDepth
2019-07-01T16:16:10.875Z,1561997770.875 [CommandLine](IMPORTANT): CBIT.abortDepth 255.000000 m
2019-07-01T16:16:12.956Z,1561997772.956 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:16.192Z,1561997776.192 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:19.021Z,1561997779.021 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:19.861Z,1561997779.861 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2019-07-01T16:16:19.862Z,1561997779.862 [RDI_Pathfinder](ERROR): Failed to parse:
:BS,32768,-32768,V
2019-07-01T16:16:21.857Z,1561997781.857 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:24.285Z,1561997784.285 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2019-07-01T16:16:24.285Z,1561997784.285 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:16:24.294Z,1561997784.294 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:16:24.725Z,1561997784.725 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:16:24.725Z,1561997784.725 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2019-07-01T16:16:25.080Z,1561997785.080 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:27.925Z,1561997787.925 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:31.173Z,1561997791.173 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:33.985Z,1561997793.985 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:37.213Z,1561997797.213 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:40.037Z,1561997800.037 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:42.861Z,1561997802.861 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:46.097Z,1561997806.097 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:46.750Z,1561997806.750 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral
2019-07-01T16:16:46.751Z,1561997806.751 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 410.000000 cc
2019-07-01T16:16:48.925Z,1561997808.925 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:52.160Z,1561997812.160 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:54.989Z,1561997814.989 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:16:57.817Z,1561997817.817 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:01.060Z,1561997821.060 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:02.765Z,1561997822.765 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault
2019-07-01T16:17:02.766Z,1561997822.766 [CommandLine](IMPORTANT): VerticalControl.massDefault 0.200000 cm
2019-07-01T16:17:03.880Z,1561997823.880 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:07.113Z,1561997827.113 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:09.937Z,1561997829.937 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:13.172Z,1561997833.172 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:15.997Z,1561997835.997 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:18.828Z,1561997838.828 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:22.069Z,1561997842.069 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:24.896Z,1561997844.896 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:28.128Z,1561997848.128 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:30.949Z,1561997850.949 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:34.184Z,1561997854.184 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:37.013Z,1561997857.013 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:39.845Z,1561997859.845 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:43.069Z,1561997863.069 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:43.909Z,1561997863.909 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-07-01T16:12:43.7Z
2019-07-01T16:17:43.909Z,1561997863.909 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T16:17:43.909Z,1561997863.909 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-07-01T16:17:45.892Z,1561997865.892 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:46.349Z,1561997866.349 [CommandLine](IMPORTANT): got command show variable limit
2019-07-01T16:17:46.390Z,1561997866.390 [CommandLine](IMPORTANT): HorizontalControl.rudLimit (angular_degree)
2019-07-01T16:17:46.391Z,1561997866.391 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitHiCC (cubic_centimeter)
2019-07-01T16:17:46.392Z,1561997866.392 [CommandLine](IMPORTANT): VerticalControl.buoyancyLimitLoCC (cubic_centimeter)
2019-07-01T16:17:46.393Z,1561997866.393 [CommandLine](IMPORTANT): VerticalControl.elevLimit (angular_degree)
2019-07-01T16:17:46.395Z,1561997866.395 [CommandLine](IMPORTANT): VerticalControl.limitDepthTrajectory (bool)
2019-07-01T16:17:46.396Z,1561997866.396 [CommandLine](IMPORTANT): VerticalControl.massFilterLimit (degree)
2019-07-01T16:17:46.397Z,1561997866.397 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft (millimeter)
2019-07-01T16:17:46.397Z,1561997866.397 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter)
2019-07-01T16:17:46.398Z,1561997866.398 [CommandLine](IMPORTANT): VerticalControl.pitchLimit (angular_degree)
2019-07-01T16:17:46.418Z,1561997866.418 [CommandLine](IMPORTANT): BuoyancyServo.currLimit (percent)
2019-07-01T16:17:46.418Z,1561997866.418 [CommandLine](IMPORTANT): BuoyancyServo.limitHi (count)
2019-07-01T16:17:46.419Z,1561997866.419 [CommandLine](IMPORTANT): BuoyancyServo.limitLo (count)
2019-07-01T16:17:46.420Z,1561997866.420 [CommandLine](IMPORTANT): ElevatorServo.currLimit (percent)
2019-07-01T16:17:46.420Z,1561997866.420 [CommandLine](IMPORTANT): ElevatorServo.limitHi (count)
2019-07-01T16:17:46.421Z,1561997866.421 [CommandLine](IMPORTANT): ElevatorServo.limitLo (count)
2019-07-01T16:17:46.422Z,1561997866.422 [CommandLine](IMPORTANT): MassServo.currLimit (percent)
2019-07-01T16:17:46.422Z,1561997866.422 [CommandLine](IMPORTANT): MassServo.limitHi (count)
2019-07-01T16:17:46.422Z,1561997866.422 [CommandLine](IMPORTANT): MassServo.limitLo (count)
2019-07-01T16:17:46.423Z,1561997866.423 [CommandLine](IMPORTANT): RudderServo.currLimit (percent)
2019-07-01T16:17:46.424Z,1561997866.424 [CommandLine](IMPORTANT): RudderServo.limitHi (count)
2019-07-01T16:17:46.424Z,1561997866.424 [CommandLine](IMPORTANT): RudderServo.limitLo (count)
2019-07-01T16:17:46.425Z,1561997866.425 [CommandLine](IMPORTANT): ThrusterServo.currLimit (percent)
2019-07-01T16:17:46.468Z,1561997866.468 [CommandLine](IMPORTANT): VeritcalControl.buoyancyLimitHiCC (cubic_centimeter)
2019-07-01T16:17:49.129Z,1561997869.129 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:49.148Z,1561997869.148 [RDI_Pathfinder](ERROR): Failed to parse:
00,   0.00,   0.00,   0.00,   0.00
2019-07-01T16:17:50.544Z,1561997870.544 [DataOverHttps](INFO): Sending 316 bytes from file Logs/20190701T155807/Express0008.lzma
2019-07-01T16:17:51.350Z,1561997871.350 [DataOverHttps](INFO): Moved sent file to Logs/20190701T155807/Express0008.lzma.bak
2019-07-01T16:17:51.350Z,1561997871.350 [DataOverHttps](INFO): SBD MOMSN=11416729
2019-07-01T16:17:51.957Z,1561997871.957 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:53.177Z,1561997873.177 [Default:CheckIn:Read_Iridium] Stopped
2019-07-01T16:17:53.178Z,1561997873.178 [Default:CheckIn:C.Wait] Running Loop=1
2019-07-01T16:17:53.178Z,1561997873.178 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-07-01T16:17:55.189Z,1561997875.189 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:58.013Z,1561997878.013 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:17:59.894Z,1561997879.894 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft
2019-07-01T16:17:59.895Z,1561997879.895 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -22.000000 mm
2019-07-01T16:18:00.857Z,1561997880.857 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:04.072Z,1561997884.072 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:06.900Z,1561997886.900 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:09.749Z,1561997889.749 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd
2019-07-01T16:18:09.750Z,1561997889.750 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 33.000000 mm
2019-07-01T16:18:10.137Z,1561997890.137 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:12.969Z,1561997892.969 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:16.197Z,1561997896.197 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:19.020Z,1561997899.020 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:21.853Z,1561997901.853 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:25.081Z,1561997905.081 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:27.937Z,1561997907.937 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:28.101Z,1561997908.101 [CommandLine](IMPORTANT): got command configSet list
2019-07-01T16:18:28.101Z,1561997908.101 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-07-01T16:18:28.102Z,1561997908.102 [CommandLine](IMPORTANT): Micromodem.loadAtStartup=0 bool;

2019-07-01T16:18:31.145Z,1561997911.145 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:33.976Z,1561997913.976 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:37.201Z,1561997917.201 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:40.033Z,1561997920.033 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:42.865Z,1561997922.865 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:46.093Z,1561997926.093 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:48.921Z,1561997928.921 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:52.153Z,1561997932.153 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:54.984Z,1561997934.984 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:18:58.213Z,1561997938.213 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:01.052Z,1561997941.052 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:03.869Z,1561997943.869 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:07.101Z,1561997947.101 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:09.929Z,1561997949.929 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:13.157Z,1561997953.157 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:15.989Z,1561997955.989 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:19.237Z,1561997959.237 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:22.053Z,1561997962.053 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:22.550Z,1561997962.550 [CommandLine](IMPORTANT): got command configSet Micromodem.loadAtStartup 1.000000 bool persist
2019-07-01T16:19:22.550Z,1561997962.550 [CommandLine](IMPORTANT): configSet Micromodem.loadAtStartup requires a restart to take effect.
2019-07-01T16:19:24.884Z,1561997964.884 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:25.305Z,1561997965.305 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2019-07-01T16:19:25.305Z,1561997965.305 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:19:25.314Z,1561997965.314 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:19:25.732Z,1561997965.732 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:19:25.732Z,1561997965.732 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2019-07-01T16:19:28.109Z,1561997968.109 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:30.937Z,1561997970.937 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:34.173Z,1561997974.173 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:37.016Z,1561997977.016 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:19:40.214Z,1561997980.214 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-07-01T16:19:40.214Z,1561997980.214 [NAL9602] Data Fault, FailCount= 2
2019-07-01T16:19:40.214Z,1561997980.214 [NAL9602](ERROR): Data Fault
2019-07-01T16:19:40.250Z,1561997980.250 [CBIT](ERROR): Data Fault in component: NAL9602
2019-07-01T16:19:40.618Z,1561997980.618 [NAL9602](INFO): Powering down
2019-07-01T16:19:41.461Z,1561997981.461 [CBIT](INFO): Clearing failed state for component NAL9602
2019-07-01T16:19:41.461Z,1561997981.461 [NAL9602] No Fault, FailCount= 2
2019-07-01T16:20:10.922Z,1561998010.922 [NAL9602](INFO): Powering up NAL9602
2019-07-01T16:20:21.826Z,1561998021.826 [NAL9602](INFO): NAL9602 initialized
2019-07-01T16:20:22.649Z,1561998022.649 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:25.481Z,1561998025.481 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:27.900Z,1561998027.900 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:31.137Z,1561998031.137 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:33.961Z,1561998033.961 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:37.200Z,1561998037.200 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:40.020Z,1561998040.020 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:42.849Z,1561998042.849 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:45.693Z,1561998045.693 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:47.717Z,1561998047.717 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:49.716Z,1561998049.716 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:52.948Z,1561998052.948 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:55.781Z,1561998055.781 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:20:59.009Z,1561998059.009 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:01.837Z,1561998061.837 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:04.689Z,1561998064.689 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:07.104Z,1561998067.104 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:09.916Z,1561998069.916 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:13.144Z,1561998073.144 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:15.973Z,1561998075.973 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:19.205Z,1561998079.205 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:22.049Z,1561998082.049 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:24.869Z,1561998084.869 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:27.717Z,1561998087.717 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:30.929Z,1561998090.929 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:33.757Z,1561998093.757 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:36.989Z,1561998096.989 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:39.813Z,1561998099.813 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:43.049Z,1561998103.049 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:45.868Z,1561998105.868 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:49.104Z,1561998109.104 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:51.933Z,1561998111.933 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:55.164Z,1561998115.164 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:21:57.989Z,1561998117.989 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:00.820Z,1561998120.820 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:03.653Z,1561998123.653 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:05.680Z,1561998125.680 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:07.705Z,1561998127.705 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:10.921Z,1561998130.921 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:13.744Z,1561998133.744 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:16.985Z,1561998136.985 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:19.817Z,1561998139.817 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:23.040Z,1561998143.040 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:25.873Z,1561998145.873 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:26.296Z,1561998146.296 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2019-07-01T16:22:26.297Z,1561998146.297 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-07-01T16:22:26.306Z,1561998146.306 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-07-01T16:22:26.749Z,1561998146.749 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-07-01T16:22:26.749Z,1561998146.749 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2019-07-01T16:22:28.697Z,1561998148.697 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:31.120Z,1561998151.120 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:33.953Z,1561998153.953 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:37.180Z,1561998157.180 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:40.008Z,1561998160.008 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:42.837Z,1561998162.837 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:45.697Z,1561998165.697 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:47.701Z,1561998167.701 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:50.916Z,1561998170.916 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:53.756Z,1561998173.756 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:53.788Z,1561998173.788 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-07-01T16:22:53.804Z,1561998173.804 [Default:CheckIn:C.Wait] Stopped
2019-07-01T16:22:53.805Z,1561998173.805 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-07-01T16:22:53.805Z,1561998173.805 [Default:CheckIn:D] Running Loop=1
2019-07-01T16:22:54.174Z,1561998174.174 [Default:CheckIn:D] Stopped
2019-07-01T16:22:54.174Z,1561998174.174 [Default:CheckIn:E] Running Loop=1
2019-07-01T16:22:54.578Z,1561998174.578 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.203548 min 
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn:E] Stopped
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn] Stopped
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn](INFO): Running loop #3
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn] Running Loop=3
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-07-01T16:22:54.579Z,1561998174.579 [Default:CheckIn:Read_GPS] Running Loop=1
2019-07-01T16:22:56.981Z,1561998176.981 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:22:59.615Z,1561998179.615 [CommandLine](IMPORTANT): got command configSet HorizontalControl.rudDeadband 0.050000 degree
2019-07-01T16:22:59.801Z,1561998179.801 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:23:03.036Z,1561998183.036 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:23:04.150Z,1561998184.150 [CommandLine](IMPORTANT): got command configSet HorizontalControl.rudDeadband 0.050000 degree persist
2019-07-01T16:23:05.867Z,1561998185.867 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:23:08.697Z,1561998188.697 [NAL9602](DEBUG): Fix Requested
2019-07-01T16:23:09.206Z,1561998189.206 [CommandLine](IMPORTANT): got command restart application
2019-07-01T16:23:10.213Z,1561998190.213 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:10.213Z,1561998190.213 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.380Z,1561998190.380 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-07-01T16:23:10.381Z,1561998190.381 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.381Z,1561998190.381 [CommandLine](INFO): Join timeout helper Thread ID is 961
2019-07-01T16:23:10.382Z,1561998190.382 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-07-01T16:23:10.382Z,1561998190.382 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.382Z,1561998190.382 [NavChartDb](INFO): Join timeout helper Thread ID is 962
2019-07-01T16:23:10.469Z,1561998190.469 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:10.469Z,1561998190.469 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.481Z,1561998190.481 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-07-01T16:23:10.481Z,1561998190.481 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.481Z,1561998190.481 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 963
2019-07-01T16:23:10.717Z,1561998190.717 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:10.717Z,1561998190.717 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-07-01T16:23:10.717Z,1561998190.717 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.721Z,1561998190.721 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-07-01T16:23:10.721Z,1561998190.721 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.721Z,1561998190.721 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 964
2019-07-01T16:23:10.722Z,1561998190.722 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:10.722Z,1561998190.722 [CTD_NeilBrown](INFO): Powering down
2019-07-01T16:23:10.737Z,1561998190.737 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.741Z,1561998190.741 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-07-01T16:23:10.741Z,1561998190.741 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.741Z,1561998190.741 [Radio_Surface](INFO): Join timeout helper Thread ID is 965
2019-07-01T16:23:10.873Z,1561998190.873 [Radio_Surface](INFO): Powering down
2019-07-01T16:23:10.874Z,1561998190.874 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:10.874Z,1561998190.874 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.894Z,1561998190.894 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-07-01T16:23:10.894Z,1561998190.894 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.894Z,1561998190.894 [DataOverHttps](INFO): Join timeout helper Thread ID is 966
2019-07-01T16:23:10.895Z,1561998190.895 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:10.895Z,1561998190.895 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.896Z,1561998190.896 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-07-01T16:23:10.896Z,1561998190.896 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.897Z,1561998190.897 [logger](INFO): Join timeout helper Thread ID is 967
2019-07-01T16:23:10.965Z,1561998190.965 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:10.965Z,1561998190.965 [logger ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.978Z,1561998190.978 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-07-01T16:23:10.979Z,1561998190.979 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.979Z,1561998190.979 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-07-01T16:23:10.979Z,1561998190.979 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:10.981Z,1561998190.981 [controlThread](INFO): Join timeout helper Thread ID is 968
2019-07-01T16:23:11.093Z,1561998191.093 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-07-01T16:23:11.093Z,1561998191.093 [controlThread](DEBUG): Uninitializing ControlThread
2019-07-01T16:23:11.093Z,1561998191.093 [AHRS_M2](INFO): Powering down
2019-07-01T16:23:11.165Z,1561998191.165 [DUSBL_Hydroid](INFO): Powering down
2019-07-01T16:23:11.257Z,1561998191.257 [NAL9602](INFO): Powering down
2019-07-01T16:23:11.329Z,1561998191.329 [RDI_Pathfinder](INFO): Powering down
2019-07-01T16:23:11.330Z,1561998191.330 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-07-01T16:23:11.331Z,1561998191.331 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-07-01T16:23:11.331Z,1561998191.331 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-07-01T16:23:11.332Z,1561998191.332 [MissionManager](INFO): Uninitializing Mission Default
2019-07-01T16:23:11.332Z,1561998191.332 [Default] Stopped
2019-07-01T16:23:11.332Z,1561998191.332 [Default](DEBUG): Aggregate::uninitialize Default
2019-07-01T16:23:11.332Z,1561998191.332 [Default:B.GoToSurface] Stopped
2019-07-01T16:23:11.332Z,1561998191.332 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-07-01T16:23:11.332Z,1561998191.332 [Default:CheckIn] Stopped
2019-07-01T16:23:11.332Z,1561998191.332 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-07-01T16:23:11.333Z,1561998191.333 [Default:CheckIn:Read_GPS] Stopped
2019-07-01T16:23:11.335Z,1561998191.335 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-07-01T16:23:11.335Z,1561998191.335 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-07-01T16:23:11.335Z,1561998191.335 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-07-01T16:23:11.336Z,1561998191.336 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-07-01T16:23:11.336Z,1561998191.336 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-07-01T16:23:11.336Z,1561998191.336 [BuoyancyServo](INFO): Powering down
2019-07-01T16:23:11.349Z,1561998191.349 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-07-01T16:23:11.349Z,1561998191.349 [ElevatorServo](INFO): Powering down
2019-07-01T16:23:11.350Z,1561998191.350 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-07-01T16:23:11.350Z,1561998191.350 [MassServo](INFO): Powering down
2019-07-01T16:23:11.350Z,1561998191.350 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-07-01T16:23:11.350Z,1561998191.350 [RudderServo](INFO): Powering down
2019-07-01T16:23:11.351Z,1561998191.351 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-07-01T16:23:11.351Z,1561998191.351 [ThrusterServo](INFO): Powering down
2019-07-01T16:23:11.352Z,1561998191.352 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-07-01T16:23:11.353Z,1561998191.353 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-07-01T16:23:11.353Z,1561998191.353 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-07-01T16:23:11.353Z,1561998191.353 [CBIT](DEBUG): Powering off loads.
2019-07-01T16:23:11.364Z,1561998191.364 [CBIT](DEBUG): Disabling WDT.
2019-07-01T16:23:11.376Z,1561998191.376 [CBIT](DEBUG): Opening all GF detection circuits.
2019-07-01T16:23:11.377Z,1561998191.377 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:11.419Z,1561998191.419 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:11.427Z,1561998191.427 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:11.468Z,1561998191.468 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:11.470Z,1561998191.470 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:11.528Z,1561998191.528 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-07-01T16:23:11.588Z,1561998191.588 [logger ThreadHandler](INFO): Thread cancelled.