2019-02-19T23:39:07.947Z,1550619547.947 [Supervisor](DEBUG): Initializing supervisor.
2019-02-19T23:39:07.950Z,1550619547.950 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-02-19T23:39:07.950Z,1550619547.950 [SyncHandler](INFO): Protected caller Thread ID is 2252
2019-02-19T23:39:07.951Z,1550619547.951 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-02-19T23:39:07.952Z,1550619547.952 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-02-19T23:39:07.952Z,1550619547.952 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2253
2019-02-19T23:39:07.955Z,1550619547.955 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-02-19T23:39:07.966Z,1550619547.966 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-02-19T23:39:07.967Z,1550619547.967 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-02-19T23:39:07.967Z,1550619547.967 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2254
2019-02-19T23:39:07.968Z,1550619547.968 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-02-19T23:39:07.969Z,1550619547.969 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-02-19T23:39:07.969Z,1550619547.969 [logger ThreadHandler](INFO): Protected caller Thread ID is 2255
2019-02-19T23:39:07.971Z,1550619547.971 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-02-19T23:39:07.971Z,1550619547.971 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-02-19T23:39:07.973Z,1550619547.973 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-02-19T23:39:08.388Z,1550619548.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-02-19T23:39:08.388Z,1550619548.388 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-02-19T23:39:08.486Z,1550619548.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-02-19T23:39:08.486Z,1550619548.486 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-02-19T23:39:08.805Z,1550619548.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-02-19T23:39:08.806Z,1550619548.806 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-02-19T23:39:08.943Z,1550619548.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-02-19T23:39:08.943Z,1550619548.943 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-02-19T23:39:09.140Z,1550619549.140 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-02-19T23:39:09.140Z,1550619549.140 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-02-19T23:39:09.603Z,1550619549.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-02-19T23:39:09.603Z,1550619549.603 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-02-19T23:39:09.806Z,1550619549.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-02-19T23:39:09.806Z,1550619549.806 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-02-19T23:39:09.950Z,1550619549.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-02-19T23:39:09.950Z,1550619549.950 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-02-19T23:39:10.141Z,1550619550.141 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-02-19T23:39:10.141Z,1550619550.141 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-02-19T23:39:10.236Z,1550619550.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-02-19T23:39:10.236Z,1550619550.236 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-02-19T23:39:10.545Z,1550619550.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-02-19T23:39:10.546Z,1550619550.546 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-02-19T23:39:10.625Z,1550619550.625 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-02-19T23:39:10.726Z,1550619550.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-02-19T23:39:10.727Z,1550619550.727 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-02-19T23:39:11.214Z,1550619551.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-02-19T23:39:11.214Z,1550619551.214 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-02-19T23:39:11.607Z,1550619551.607 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-02-19T23:39:11.609Z,1550619551.609 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-02-19T23:39:11.610Z,1550619551.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-02-19T23:39:11.815Z,1550619551.815 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-02-19T23:39:11.913Z,1550619551.913 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-02-19T23:39:12.010Z,1550619552.010 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-02-19T23:39:12.237Z,1550619552.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-02-19T23:39:12.237Z,1550619552.237 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-02-19T23:39:12.320Z,1550619552.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-02-19T23:39:12.411Z,1550619552.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-02-19T23:39:12.507Z,1550619552.507 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-02-19T23:39:12.588Z,1550619552.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-02-19T23:39:12.771Z,1550619552.771 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-02-19T23:39:13.148Z,1550619553.148 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-02-19T23:39:13.437Z,1550619553.437 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-02-19T23:39:13.437Z,1550619553.437 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-02-19T23:39:13.439Z,1550619553.439 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-02-19T23:39:13.940Z,1550619553.940 [AHRS_M2] Loaded
2019-02-19T23:39:13.941Z,1550619553.941 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-02-19T23:39:14.012Z,1550619554.012 [DataOverHttps] Loaded
2019-02-19T23:39:14.012Z,1550619554.012 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-02-19T23:39:14.026Z,1550619554.026 [Depth_Keller] Loaded
2019-02-19T23:39:14.026Z,1550619554.026 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-02-19T23:39:14.031Z,1550619554.031 [DropWeight] Loaded
2019-02-19T23:39:14.031Z,1550619554.031 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-02-19T23:39:14.081Z,1550619554.081 [DUSBL_Hydroid] Loaded
2019-02-19T23:39:14.081Z,1550619554.081 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-02-19T23:39:14.123Z,1550619554.123 [Micromodem] Loaded
2019-02-19T23:39:14.123Z,1550619554.123 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-02-19T23:39:14.226Z,1550619554.226 [NAL9602] Loaded
2019-02-19T23:39:14.226Z,1550619554.226 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-02-19T23:39:14.242Z,1550619554.242 [Onboard] Loaded
2019-02-19T23:39:14.243Z,1550619554.243 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-02-19T23:39:14.253Z,1550619554.253 [Radio_Surface] Loaded
2019-02-19T23:39:14.253Z,1550619554.253 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-02-19T23:39:14.255Z,1550619554.255 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407534E0
2019-02-19T23:39:14.255Z,1550619554.255 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2334
2019-02-19T23:39:14.285Z,1550619554.285 [RDI_Pathfinder] Loaded
2019-02-19T23:39:14.285Z,1550619554.285 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-02-19T23:39:14.307Z,1550619554.307 [RDI_PathfinderUp] Loaded
2019-02-19T23:39:14.308Z,1550619554.308 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2019-02-19T23:39:16.187Z,1550619556.187 [BPC1] Loaded
2019-02-19T23:39:16.188Z,1550619556.188 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-02-19T23:39:16.188Z,1550619556.188 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-02-19T23:39:16.189Z,1550619556.189 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-02-19T23:39:16.202Z,1550619556.202 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-02-19T23:39:16.203Z,1550619556.203 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-02-19T23:39:16.313Z,1550619556.313 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-02-19T23:39:16.313Z,1550619556.313 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-02-19T23:39:16.375Z,1550619556.375 [DeadReckonUsingSpeedCalculator] Loaded
2019-02-19T23:39:16.375Z,1550619556.375 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-02-19T23:39:16.437Z,1550619556.437 [DeadReckonWithRespectToSeafloor] Loaded
2019-02-19T23:39:16.438Z,1550619556.438 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-02-19T23:39:16.454Z,1550619556.454 [NavChart] Loaded
2019-02-19T23:39:16.454Z,1550619556.454 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-02-19T23:39:16.458Z,1550619556.458 [UniversalFixResidualReporter] Loaded
2019-02-19T23:39:16.458Z,1550619556.458 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-02-19T23:39:16.459Z,1550619556.459 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-02-19T23:39:16.459Z,1550619556.459 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-02-19T23:39:16.568Z,1550619556.568 [BuoyancyServo] Loaded
2019-02-19T23:39:16.568Z,1550619556.568 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-02-19T23:39:16.584Z,1550619556.584 [ElevatorServo] Loaded
2019-02-19T23:39:16.584Z,1550619556.584 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-02-19T23:39:16.599Z,1550619556.599 [MassServo] Loaded
2019-02-19T23:39:16.599Z,1550619556.599 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-02-19T23:39:16.615Z,1550619556.615 [RudderServo] Loaded
2019-02-19T23:39:16.615Z,1550619556.615 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-02-19T23:39:16.630Z,1550619556.630 [ThrusterServo] Loaded
2019-02-19T23:39:16.630Z,1550619556.630 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-02-19T23:39:16.631Z,1550619556.631 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-02-19T23:39:16.631Z,1550619556.631 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-02-19T23:39:16.819Z,1550619556.819 [Aanderaa_O2] Loaded
2019-02-19T23:39:16.820Z,1550619556.820 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-02-19T23:39:16.907Z,1550619556.907 [CTD_NeilBrown] Loaded
2019-02-19T23:39:16.907Z,1550619556.907 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-02-19T23:39:16.909Z,1550619556.909 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408624E0
2019-02-19T23:39:16.909Z,1550619556.909 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2335
2019-02-19T23:39:16.955Z,1550619556.955 [WetLabsSeaOWL_UV_A] Loaded
2019-02-19T23:39:16.956Z,1550619556.956 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-02-19T23:39:16.957Z,1550619556.957 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408924E0
2019-02-19T23:39:16.957Z,1550619556.957 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2336
2019-02-19T23:39:16.958Z,1550619556.958 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-02-19T23:39:16.958Z,1550619556.958 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-02-19T23:39:17.215Z,1550619557.215 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-02-19T23:39:17.216Z,1550619557.216 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-02-19T23:39:17.259Z,1550619557.259 [DepthRateCalculator] Loaded
2019-02-19T23:39:17.259Z,1550619557.259 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-02-19T23:39:17.265Z,1550619557.265 [PitchRateCalculator] Loaded
2019-02-19T23:39:17.265Z,1550619557.265 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-02-19T23:39:17.278Z,1550619557.278 [SpeedCalculator] Loaded
2019-02-19T23:39:17.278Z,1550619557.278 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-02-19T23:39:17.300Z,1550619557.300 [TempGradientCalculator] Loaded
2019-02-19T23:39:17.300Z,1550619557.300 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-02-19T23:39:17.306Z,1550619557.306 [YawRateCalculator] Loaded
2019-02-19T23:39:17.306Z,1550619557.306 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-02-19T23:39:17.348Z,1550619557.348 [ElevatorOffsetCalculator] Loaded
2019-02-19T23:39:17.349Z,1550619557.349 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-02-19T23:39:17.349Z,1550619557.349 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-02-19T23:39:17.350Z,1550619557.350 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-02-19T23:39:17.496Z,1550619557.496 [SBIT](DEBUG): Construct Startup Built In Test.
2019-02-19T23:39:17.518Z,1550619557.518 [SBIT] Loaded
2019-02-19T23:39:17.519Z,1550619557.519 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-02-19T23:39:17.519Z,1550619557.519 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-02-19T23:39:17.531Z,1550619557.531 [IBIT] Loaded
2019-02-19T23:39:17.531Z,1550619557.531 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-02-19T23:39:17.534Z,1550619557.534 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-02-19T23:39:17.676Z,1550619557.676 [CBIT] Loaded
2019-02-19T23:39:17.676Z,1550619557.676 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-02-19T23:39:17.677Z,1550619557.677 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-02-19T23:39:17.677Z,1550619557.677 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-02-19T23:39:17.745Z,1550619557.745 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-02-19T23:39:17.746Z,1550619557.746 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-02-19T23:39:17.854Z,1550619557.854 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-02-19T23:39:17.854Z,1550619557.854 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-02-19T23:39:17.933Z,1550619557.933 [VerticalControl](DEBUG): Construct VerticalControl.
2019-02-19T23:39:18.019Z,1550619558.019 [VerticalControl] Loaded
2019-02-19T23:39:18.020Z,1550619558.020 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-02-19T23:39:18.020Z,1550619558.020 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-02-19T23:39:18.080Z,1550619558.080 [HorizontalControl] Loaded
2019-02-19T23:39:18.081Z,1550619558.081 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-02-19T23:39:18.081Z,1550619558.081 [SpeedControl](DEBUG): Construct SpeedControl.
2019-02-19T23:39:18.083Z,1550619558.083 [SpeedControl] Loaded
2019-02-19T23:39:18.083Z,1550619558.083 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-02-19T23:39:18.084Z,1550619558.084 [LoopControl](DEBUG): Construct LoopControl.
2019-02-19T23:39:18.084Z,1550619558.084 [LoopControl] Loaded
2019-02-19T23:39:18.085Z,1550619558.085 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-02-19T23:39:18.085Z,1550619558.085 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-02-19T23:39:18.086Z,1550619558.086 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-02-19T23:39:18.115Z,1550619558.115 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-02-19T23:39:18.118Z,1550619558.118 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-02-19T23:39:18.119Z,1550619558.119 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-02-19T23:39:18.126Z,1550619558.126 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-02-19T23:39:18.127Z,1550619558.127 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2019-02-19T23:39:18.127Z,1550619558.127 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2337
2019-02-19T23:39:18.132Z,1550619558.132 [Supervisor](INFO): Main Thread ID is 2251
2019-02-19T23:39:18.132Z,1550619558.132 [Supervisor](DEBUG): Running supervisor.
2019-02-19T23:39:18.132Z,1550619558.132 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2338
2019-02-19T23:39:18.135Z,1550619558.135 [controlThread ThreadHandler](INFO): Handler Thread ID is 2339
2019-02-19T23:39:18.135Z,1550619558.135 [controlThread](DEBUG): Initializing ControlThread
2019-02-19T23:39:18.144Z,1550619558.144 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-19T23:39:18.145Z,1550619558.145 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-02-19T23:39:18.145Z,1550619558.145 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-02-19T23:39:18.146Z,1550619558.146 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-02-19T23:39:18.147Z,1550619558.147 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-02-19T23:39:18.147Z,1550619558.147 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-02-19T23:39:18.147Z,1550619558.147 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-02-19T23:39:18.148Z,1550619558.148 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-02-19T23:39:18.148Z,1550619558.148 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-02-19T23:39:18.149Z,1550619558.149 [SBIT](INFO): Initialize SBIT Component.
2019-02-19T23:39:18.149Z,1550619558.149 [SBIT](IMPORTANT): git: 2019-02-11-5-g1cf9f4d
2019-02-19T23:39:18.150Z,1550619558.150 [SBIT](INFO): git hash: 1cf9f4d7aba313398a625168a3064bcf57d75169
2019-02-19T23:39:18.150Z,1550619558.150 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-02-19T23:39:18.150Z,1550619558.150 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2019-02-19T23:39:18.151Z,1550619558.151 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-02-19T23:39:18.152Z,1550619558.152 [IBIT](INFO): Initialize IBIT Component.
2019-02-19T23:39:18.152Z,1550619558.152 [CBIT](DEBUG): Initialize CBIT Component.
2019-02-19T23:39:18.154Z,1550619558.154 [logger ThreadHandler](INFO): Handler Thread ID is 2340
2019-02-19T23:39:18.165Z,1550619558.165 [CBIT](DEBUG): Initialized mux pins.
2019-02-19T23:39:18.165Z,1550619558.165 [CBIT](DEBUG): Initializing the watchdog timer.
2019-02-19T23:39:18.173Z,1550619558.173 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2341
2019-02-19T23:39:18.174Z,1550619558.174 [Radio_Surface](INFO): Powering up
2019-02-19T23:39:18.185Z,1550619558.185 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2342
2019-02-19T23:39:18.186Z,1550619558.186 [CTD_NeilBrown](INFO): Powering down
2019-02-19T23:39:18.193Z,1550619558.193 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-02-19T23:39:18.193Z,1550619558.193 [CBIT](DEBUG): Initializing heartbeat.
2019-02-19T23:39:18.213Z,1550619558.213 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2343
2019-02-19T23:39:18.214Z,1550619558.214 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-02-19T23:39:18.243Z,1550619558.243 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2344
2019-02-19T23:39:18.246Z,1550619558.246 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2019-02-19T23:39:18.254Z,1550619558.254 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-02-19T23:39:18.255Z,1550619558.255 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2019-02-19T23:39:18.255Z,1550619558.255 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-19T23:39:18.257Z,1550619558.257 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2019-02-19T23:39:18.257Z,1550619558.257 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-19T23:39:18.258Z,1550619558.258 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2019-02-19T23:39:18.259Z,1550619558.259 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-19T23:39:18.260Z,1550619558.260 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000
2019-02-19T23:39:18.260Z,1550619558.260 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-19T23:39:18.262Z,1550619558.262 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2019-02-19T23:39:18.262Z,1550619558.262 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-19T23:39:18.263Z,1550619558.263 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000
2019-02-19T23:39:18.264Z,1550619558.264 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-19T23:39:18.265Z,1550619558.265 [CBIT](DEBUG): Deactivating GF circuits.
2019-02-19T23:39:18.265Z,1550619558.265 [CBIT](DEBUG): Deactivating emergency mode.
2019-02-19T23:39:18.277Z,1550619558.277 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000
2019-02-19T23:39:18.277Z,1550619558.277 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-19T23:39:18.279Z,1550619558.279 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000
2019-02-19T23:39:18.301Z,1550619558.301 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-02-19T23:39:18.303Z,1550619558.303 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-02-19T23:39:18.303Z,1550619558.303 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-02-19T23:39:18.304Z,1550619558.304 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-02-19T23:39:18.305Z,1550619558.305 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-02-19T23:39:18.314Z,1550619558.314 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-19T23:39:18.325Z,1550619558.325 [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-02-19T23:39:18.326Z,1550619558.326 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-02-19T23:39:18.353Z,1550619558.353 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-19T23:39:18.393Z,1550619558.393 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-02-19T23:39:18.394Z,1550619558.394 [Default:A.Wait](DEBUG): Construct Wait.
2019-02-19T23:39:18.396Z,1550619558.396 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-19T23:39:18.419Z,1550619558.419 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-02-19T23:39:18.421Z,1550619558.421 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-02-19T23:39:18.453Z,1550619558.453 [Default:E.Execute](DEBUG): Construct Execute.
2019-02-19T23:39:18.481Z,1550619558.481 [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-02-19T23:39:18.486Z,1550619558.486 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,RDI_Pathfinder,RDI_PathfinderUp,BPC1,Aanderaa_O2,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-02-19T23:39:18.505Z,1550619558.505 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-02-19T23:39:18.535Z,1550619558.535 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-02-19T23:39:18.539Z,1550619558.539 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-02-19T23:39:18.540Z,1550619558.540 [DUSBL_Hydroid](INFO): Powering up
2019-02-19T23:39:18.540Z,1550619558.540 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-02-19T23:39:18.569Z,1550619558.569 [Micromodem](INFO): Start
2019-02-19T23:39:18.638Z,1550619558.638 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-02-19T23:39:18.663Z,1550619558.663 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:39:18.685Z,1550619558.685 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-19T23:39:18.686Z,1550619558.686 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:39:18.697Z,1550619558.697 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-02-19T23:39:18.698Z,1550619558.698 [MassServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:39:18.705Z,1550619558.705 [MassServo](DEBUG): Initializing MassServo.
2019-02-19T23:39:18.706Z,1550619558.706 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:39:18.713Z,1550619558.713 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-19T23:39:18.714Z,1550619558.714 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:39:18.717Z,1550619558.717 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-02-19T23:39:18.926Z,1550619558.926 [Micromodem](INFO): Starting
2019-02-19T23:39:18.927Z,1550619558.927 [Micromodem](INFO): Powering up
2019-02-19T23:39:18.927Z,1550619558.927 [Micromodem](DEBUG): Initializing Micromodem.
2019-02-19T23:39:19.029Z,1550619559.029 [RDI_PathfinderUp](INFO): Powering down
2019-02-19T23:39:19.073Z,1550619559.073 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-02-19T23:39:25.502Z,1550619565.502 [CommandLine](IMPORTANT): got command show variable depth
2019-02-19T23:39:25.586Z,1550619565.586 [CommandLine](IMPORTANT): depth (unknown)
2019-02-19T23:39:25.587Z,1550619565.587 [CommandLine](IMPORTANT): depth_rate (unknown)
2019-02-19T23:39:25.594Z,1550619565.594 [CommandLine](IMPORTANT): sea_floor_depth_below_geoid (unknown)
2019-02-19T23:39:25.599Z,1550619565.599 [CommandLine](IMPORTANT): Depth_Keller.loadControl (none)
2019-02-19T23:39:25.599Z,1550619565.599 [CommandLine](IMPORTANT): Depth_Keller.ad (none)
2019-02-19T23:39:25.599Z,1550619565.599 [CommandLine](IMPORTANT): Depth_Keller.adRes (bit)
2019-02-19T23:39:25.600Z,1550619565.600 [CommandLine](IMPORTANT): Depth_Keller.adTimeout (millisecond)
2019-02-19T23:39:25.600Z,1550619565.600 [CommandLine](IMPORTANT): Depth_Keller.adVref (volt)
2019-02-19T23:39:25.622Z,1550619565.622 [CommandLine](IMPORTANT): VerticalControl.buoyancyPumpDepth (meter)
2019-02-19T23:39:25.622Z,1550619565.622 [CommandLine](IMPORTANT): VerticalControl.depthDeadband (meter)
2019-02-19T23:39:25.622Z,1550619565.622 [CommandLine](IMPORTANT): VerticalControl.depthRateDeadband (meter_per_second)
2019-02-19T23:39:25.623Z,1550619565.623 [CommandLine](IMPORTANT): VerticalControl.depthRateSamples (count)
2019-02-19T23:39:25.623Z,1550619565.623 [CommandLine](IMPORTANT): VerticalControl.dropWtDepthExcursion (meter)
2019-02-19T23:39:25.624Z,1550619565.624 [CommandLine](IMPORTANT): VerticalControl.excursionDepthTimeout (second)
2019-02-19T23:39:25.624Z,1550619565.624 [CommandLine](IMPORTANT): VerticalControl.kdDepth (radian_second_per_meter)
2019-02-19T23:39:25.624Z,1550619565.624 [CommandLine](IMPORTANT): VerticalControl.kdDepthBuoy (second)
2019-02-19T23:39:25.657Z,1550619565.657 [CommandLine](IMPORTANT): VerticalControl.kdDepthRateBuoy (second)
2019-02-19T23:39:25.665Z,1550619565.665 [CommandLine](IMPORTANT): VerticalControl.kiDepth (radian_per_second_per_meter)
2019-02-19T23:39:25.666Z,1550619565.666 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy (reciprocal_second)
2019-02-19T23:39:25.666Z,1550619565.666 [CommandLine](IMPORTANT): VerticalControl.kiDepthOff (meter_per_second)
2019-02-19T23:39:25.666Z,1550619565.666 [CommandLine](IMPORTANT): VerticalControl.kiDepthRateBuoy (reciprocal_second)
2019-02-19T23:39:25.667Z,1550619565.667 [CommandLine](IMPORTANT): VerticalControl.kpDepth (radian_per_meter)
2019-02-19T23:39:25.667Z,1550619565.667 [CommandLine](IMPORTANT): VerticalControl.kpDepthBuoy (ratio)
2019-02-19T23:39:25.667Z,1550619565.667 [CommandLine](IMPORTANT): VerticalControl.kpDepthRateBuoy (ratio)
2019-02-19T23:39:25.668Z,1550619565.668 [CommandLine](IMPORTANT): VerticalControl.limitDepthTrajectory (bool)
2019-02-19T23:39:25.669Z,1550619565.669 [CommandLine](IMPORTANT): VerticalControl.maxDepthInt (angular_degree)
2019-02-19T23:39:25.669Z,1550619565.669 [CommandLine](IMPORTANT): VerticalControl.minDepthExcursion (meter)
2019-02-19T23:39:25.670Z,1550619565.670 [CommandLine](IMPORTANT): VerticalControl.stopDepthExcursion (meter)
2019-02-19T23:39:25.670Z,1550619565.670 [CommandLine](IMPORTANT): VerticalControl.useElevIntInDepthMode (bool)
2019-02-19T23:39:25.672Z,1550619565.672 [CommandLine](IMPORTANT): CBIT.stopDepth (meter)
2019-02-19T23:39:25.683Z,1550619565.683 [CommandLine](IMPORTANT): CBIT.abortDepth (meter)
2019-02-19T23:39:25.684Z,1550619565.684 [CommandLine](IMPORTANT): CBIT.abortDepthTimeout (second)
2019-02-19T23:39:25.705Z,1550619565.705 [CommandLine](IMPORTANT): Config/Simulator.mixedLayerDepth (meter)
2019-02-19T23:39:25.710Z,1550619565.710 [CommandLine](IMPORTANT): DepthRateCalculator.loadAtStartup (bool)
2019-02-19T23:39:25.711Z,1550619565.711 [CommandLine](IMPORTANT): TempGradientCalculator.numConsecutiveDepths (count)
2019-02-19T23:39:25.711Z,1550619565.711 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth1 (meter)
2019-02-19T23:39:25.712Z,1550619565.712 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth2 (meter)
2019-02-19T23:39:25.712Z,1550619565.712 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth3 (meter)
2019-02-19T23:39:25.733Z,1550619565.733 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depth4 (meter)
2019-02-19T23:39:25.733Z,1550619565.733 [CommandLine](IMPORTANT): VerticalTemperatureHomogeneityIndexCalculator.depthWindow (meter)
2019-02-19T23:39:25.735Z,1550619565.735 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth (meter)
2019-02-19T23:39:25.762Z,1550619565.762 [CommandLine](IMPORTANT): Config/workSite.beaconDepth (meter)
2019-02-19T23:39:25.766Z,1550619565.766 [CommandLine](IMPORTANT): Depth_Keller.loadAtStartup (bool)
2019-02-19T23:39:25.766Z,1550619565.766 [CommandLine](IMPORTANT): Depth_Keller.simulateHardware (bool)
2019-02-19T23:39:25.766Z,1550619565.766 [CommandLine](IMPORTANT): Depth_Keller.maxPressBound (decibar)
2019-02-19T23:39:25.767Z,1550619565.767 [CommandLine](IMPORTANT): Depth_Keller.minPressBound (decibar)
2019-02-19T23:39:25.767Z,1550619565.767 [CommandLine](IMPORTANT): Depth_Keller.offset (decibar)
2019-02-19T23:39:25.767Z,1550619565.767 [CommandLine](IMPORTANT): Depth_Keller.power (watt)
2019-02-19T23:39:25.768Z,1550619565.768 [CommandLine](IMPORTANT): Depth_Keller.scale (micropascal)
2019-02-19T23:39:25.789Z,1550619565.789 [CommandLine](IMPORTANT): Radio_Surface.maxDepth (meter)
2019-02-19T23:39:25.883Z,1550619565.883 [CommandLine](IMPORTANT): Depth_Keller.depth (meter)
2019-02-19T23:39:25.883Z,1550619565.883 [CommandLine](IMPORTANT): Depth_Keller.sea_water_pressure (decibar)
2019-02-19T23:39:25.922Z,1550619565.922 [CommandLine](IMPORTANT): DeadReckonUsingMultipleVelocitySources.depth (meter)
2019-02-19T23:39:25.924Z,1550619565.924 [CommandLine](IMPORTANT): DeadReckonUsingSpeedCalculator.depth (meter)
2019-02-19T23:39:25.942Z,1550619565.942 [CommandLine](IMPORTANT): DeadReckonWithRespectToSeafloor.depth (meter)
2019-02-19T23:39:25.943Z,1550619565.943 [CommandLine](IMPORTANT): NavChart.sea_floor_depth_below_geoid (meter)
2019-02-19T23:39:25.977Z,1550619565.977 [CommandLine](IMPORTANT): CTD_NeilBrown.depth (meter)
2019-02-19T23:39:25.979Z,1550619565.979 [CommandLine](IMPORTANT): DepthRateCalculator.depth_rate (meter_per_second)
2019-02-19T23:39:25.979Z,1550619565.979 [CommandLine](IMPORTANT): TempGradientCalculator.thermoclineDepth (meter)
2019-02-19T23:39:25.980Z,1550619565.980 [CommandLine](IMPORTANT): TempGradientCalculator.targetDepth (meter)
2019-02-19T23:39:25.981Z,1550619565.981 [CommandLine](IMPORTANT): CBIT.binnedDepthRate (meter_per_second)
2019-02-19T23:39:25.982Z,1550619565.982 [CommandLine](IMPORTANT): VerticalControl.depthRateCmd (meter_per_second)
2019-02-19T23:39:25.982Z,1550619565.982 [CommandLine](IMPORTANT): VerticalControl.depth2buoyIntInternal (cubic_centimeter)
2019-02-19T23:39:25.983Z,1550619565.983 [CommandLine](IMPORTANT): VerticalControl.depthErrorInternal (meter)
2019-02-19T23:39:25.983Z,1550619565.983 [CommandLine](IMPORTANT): VerticalControl.depthIntegralInternal (radian)
2019-02-19T23:39:25.984Z,1550619565.984 [CommandLine](IMPORTANT): VerticalControl.smoothDepthInternal (meter)
2019-02-19T23:39:26.001Z,1550619566.001 [CommandLine](IMPORTANT): NavChartDb.closestDepth (meter)
2019-02-19T23:39:26.002Z,1550619566.002 [CommandLine](IMPORTANT): NavChartDb.nextDepth (meter)
2019-02-19T23:39:27.379Z,1550619567.379 [Micromodem](INFO): Starting
2019-02-19T23:39:27.380Z,1550619567.380 [Micromodem](INFO): Starting
2019-02-19T23:39:27.380Z,1550619567.380 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:39:27.380Z,1550619567.380 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:39:27.381Z,1550619567.381 [Micromodem](INFO): Nmea out: $
2019-02-19T23:39:27.390Z,1550619567.390 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:39:27.390Z,1550619567.390 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:39:27.390Z,1550619567.390 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:39:27.390Z,1550619567.390 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:39:27.390Z,1550619567.390 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:39:27.390Z,1550619567.390 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:39:27.391Z,1550619567.391 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:39:27.391Z,1550619567.391 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:39:27.469Z,1550619567.469 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-02-19T23:39:27.897Z,1550619567.897 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:39:27.911Z,1550619567.911 [Micromodem](INFO): Starting
2019-02-19T23:39:27.945Z,1550619567.945 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-02-19T23:39:28.239Z,1550619568.239 [Micromodem](INFO): Starting
2019-02-19T23:39:28.385Z,1550619568.385 [Aanderaa_O2](INFO): Powering down
2019-02-19T23:39:28.607Z,1550619568.607 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004568
2019-02-19T23:39:28.610Z,1550619568.610 [Micromodem](INFO): Starting
2019-02-19T23:39:28.611Z,1550619568.611 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:39:28.611Z,1550619568.611 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:39:29.010Z,1550619569.010 [Micromodem](INFO): Starting
2019-02-19T23:39:29.454Z,1550619569.454 [AHRS_M2](FAULT): Failed to initialize within timeout.
2019-02-19T23:39:29.454Z,1550619569.454 [AHRS_M2] Communications Fault, FailCount= 1
2019-02-19T23:39:29.454Z,1550619569.454 [AHRS_M2](ERROR): Communications Fault
2019-02-19T23:39:29.458Z,1550619569.458 [Micromodem](INFO): Starting
2019-02-19T23:39:29.564Z,1550619569.564 [CBIT](ERROR): Communications Fault in component: AHRS_M2
2019-02-19T23:39:29.792Z,1550619569.792 [AHRS_M2](INFO): Powering down
2019-02-19T23:39:29.923Z,1550619569.923 [Micromodem](INFO): Starting
2019-02-19T23:39:30.218Z,1550619570.218 [Micromodem](INFO): Starting
2019-02-19T23:39:30.606Z,1550619570.606 [Micromodem](INFO): Starting
2019-02-19T23:39:30.845Z,1550619570.845 [CBIT](INFO): Clearing failed state for component AHRS_M2
2019-02-19T23:39:30.845Z,1550619570.845 [AHRS_M2] No Fault, FailCount= 1
2019-02-19T23:39:31.004Z,1550619571.004 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-02-19T23:39:31.030Z,1550619571.030 [Micromodem](INFO): Starting
2019-02-19T23:39:31.414Z,1550619571.414 [Micromodem](INFO): Starting
2019-02-19T23:39:31.818Z,1550619571.818 [Micromodem](INFO): Starting
2019-02-19T23:39:31.844Z,1550619571.844 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-02-19T23:39:32.222Z,1550619572.222 [Micromodem](INFO): Starting
2019-02-19T23:39:32.642Z,1550619572.642 [Micromodem](INFO): Starting
2019-02-19T23:39:33.030Z,1550619573.030 [Micromodem](INFO): Starting
2019-02-19T23:39:33.431Z,1550619573.431 [Micromodem](INFO): Starting
2019-02-19T23:39:33.448Z,1550619573.448 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-19T23:39:33.842Z,1550619573.842 [Micromodem](INFO): Starting
2019-02-19T23:39:34.557Z,1550619574.557 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:34.562Z,1550619574.562 [Micromodem](INFO): Starting
2019-02-19T23:39:34.977Z,1550619574.977 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:34.982Z,1550619574.982 [Micromodem](INFO): Starting
2019-02-19T23:39:35.437Z,1550619575.437 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:35.443Z,1550619575.443 [Micromodem](INFO): Starting
2019-02-19T23:39:35.921Z,1550619575.921 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:35.927Z,1550619575.927 [Micromodem](INFO): Starting
2019-02-19T23:39:36.381Z,1550619576.381 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:36.387Z,1550619576.387 [Micromodem](INFO): Starting
2019-02-19T23:39:36.889Z,1550619576.889 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:36.894Z,1550619576.894 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-02-19T23:39:36.909Z,1550619576.909 [Micromodem](INFO): Starting
2019-02-19T23:39:37.377Z,1550619577.377 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:37.386Z,1550619577.386 [Micromodem](INFO): Starting
2019-02-19T23:39:37.770Z,1550619577.770 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:37.774Z,1550619577.774 [Micromodem](INFO): Starting
2019-02-19T23:39:38.197Z,1550619578.197 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:38.199Z,1550619578.199 [Micromodem](INFO): Starting
2019-02-19T23:39:38.589Z,1550619578.589 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:38.594Z,1550619578.594 [Micromodem](INFO): Starting
2019-02-19T23:39:38.595Z,1550619578.595 [Micromodem](FAULT): failed to initialize; deviceResponse_ loaded: , available: $CAREV,025918,INIT,2.0.27690*4A
$CAREV,025918,SLOT1,2.0.27690*65
$CAREV,025918,AUV,2.0.27690*12
$CAREV,025918,COPROC,0.10.0.46*47
$CATMG,1902-02-23T02:59:18Z,RTC,RTC*70
$CAREV,025928,AUV,2.0.27690*11
$CAREV,025928,COPROC,0.10.0.46*44
!
2019-02-19T23:39:38.595Z,1550619578.595 [Micromodem] Communications Fault, FailCount= 1
2019-02-19T23:39:38.595Z,1550619578.595 [Micromodem](ERROR): Communications Fault
2019-02-19T23:39:38.654Z,1550619578.654 [CBIT](ERROR): Communications Fault in component: Micromodem
2019-02-19T23:39:38.989Z,1550619578.989 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:38.994Z,1550619578.994 [Micromodem](INFO): Stop
2019-02-19T23:39:38.994Z,1550619578.994 [Micromodem](INFO): uninitialize
2019-02-19T23:39:38.994Z,1550619578.994 [Micromodem](INFO): Powering down
2019-02-19T23:39:39.549Z,1550619579.549 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:39.554Z,1550619579.554 [Micromodem](INFO): Stopping
2019-02-19T23:39:39.949Z,1550619579.949 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:39.951Z,1550619579.951 [Micromodem](INFO): Stopped
2019-02-19T23:39:40.012Z,1550619580.012 [CBIT](INFO): Clearing failed state for component Micromodem
2019-02-19T23:39:40.012Z,1550619580.012 [Micromodem] No Fault, FailCount= 1
2019-02-19T23:39:40.349Z,1550619580.349 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:40.355Z,1550619580.355 [Micromodem](INFO): Start
2019-02-19T23:39:40.409Z,1550619580.409 [CommandLine](IMPORTANT): got command exit
2019-02-19T23:39:40.749Z,1550619580.749 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:40.754Z,1550619580.754 [Micromodem](INFO): Start
2019-02-19T23:39:41.153Z,1550619581.153 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:41.158Z,1550619581.158 [Micromodem](INFO): Start
2019-02-19T23:39:41.417Z,1550619581.417 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-02-19T23:39:41.417Z,1550619581.417 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:39:41.417Z,1550619581.417 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.565Z,1550619581.565 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:41.570Z,1550619581.570 [Micromodem](INFO): Start
2019-02-19T23:39:41.601Z,1550619581.601 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-02-19T23:39:41.601Z,1550619581.601 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.602Z,1550619581.602 [CommandLine](INFO): Join timeout helper Thread ID is 2357
2019-02-19T23:39:41.632Z,1550619581.632 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-02-19T23:39:41.632Z,1550619581.632 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.633Z,1550619581.633 [NavChartDb](INFO): Join timeout helper Thread ID is 2358
2019-02-19T23:39:41.650Z,1550619581.650 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:39:41.650Z,1550619581.650 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.665Z,1550619581.665 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-02-19T23:39:41.665Z,1550619581.665 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.665Z,1550619581.665 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2359
2019-02-19T23:39:41.681Z,1550619581.681 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:39:41.681Z,1550619581.681 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-02-19T23:39:41.682Z,1550619581.682 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.685Z,1550619581.685 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-02-19T23:39:41.685Z,1550619581.685 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.685Z,1550619581.685 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2360
2019-02-19T23:39:41.721Z,1550619581.721 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:39:41.721Z,1550619581.721 [CTD_NeilBrown](INFO): Powering down
2019-02-19T23:39:41.733Z,1550619581.733 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.733Z,1550619581.733 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-02-19T23:39:41.733Z,1550619581.733 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:41.734Z,1550619581.734 [Radio_Surface](INFO): Join timeout helper Thread ID is 2361
2019-02-19T23:39:41.961Z,1550619581.961 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:41.963Z,1550619581.963 [Micromodem](INFO): Start
2019-02-19T23:39:42.049Z,1550619582.049 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:39:42.049Z,1550619582.049 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.058Z,1550619582.058 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-02-19T23:39:42.058Z,1550619582.058 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.058Z,1550619582.058 [logger](INFO): Join timeout helper Thread ID is 2362
2019-02-19T23:39:42.137Z,1550619582.137 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:39:42.137Z,1550619582.137 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.157Z,1550619582.157 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-02-19T23:39:42.158Z,1550619582.158 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.158Z,1550619582.158 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-02-19T23:39:42.158Z,1550619582.158 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.158Z,1550619582.158 [controlThread](INFO): Join timeout helper Thread ID is 2363
2019-02-19T23:39:42.373Z,1550619582.373 [AHRS_M2](ERROR): Subscribe Roll UART error: serial timeout
2019-02-19T23:39:42.382Z,1550619582.382 [Micromodem](INFO): Start
2019-02-19T23:39:42.412Z,1550619582.412 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:39:42.412Z,1550619582.412 [controlThread](DEBUG): Uninitializing ControlThread
2019-02-19T23:39:42.412Z,1550619582.412 [AHRS_M2](INFO): Powering down
2019-02-19T23:39:42.486Z,1550619582.486 [DUSBL_Hydroid](INFO): Powering down
2019-02-19T23:39:42.577Z,1550619582.577 [Micromodem](INFO): uninitialize
2019-02-19T23:39:42.577Z,1550619582.577 [Micromodem](INFO): Powering down
2019-02-19T23:39:42.579Z,1550619582.579 [NAL9602](INFO): Powering down
2019-02-19T23:39:42.669Z,1550619582.669 [RDI_Pathfinder](INFO): Powering down
2019-02-19T23:39:42.670Z,1550619582.670 [RDI_PathfinderUp](INFO): Powering down
2019-02-19T23:39:42.671Z,1550619582.671 [Aanderaa_O2](INFO): Powering down
2019-02-19T23:39:42.672Z,1550619582.672 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-02-19T23:39:42.673Z,1550619582.673 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-02-19T23:39:42.674Z,1550619582.674 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-02-19T23:39:42.675Z,1550619582.675 [MissionManager](INFO): Uninitializing Mission Default
2019-02-19T23:39:42.677Z,1550619582.677 [MissionManager](INFO): Uninitializing Mission Startup
2019-02-19T23:39:42.678Z,1550619582.678 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-02-19T23:39:42.678Z,1550619582.678 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-02-19T23:39:42.679Z,1550619582.679 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-02-19T23:39:42.679Z,1550619582.679 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-02-19T23:39:42.679Z,1550619582.679 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-02-19T23:39:42.679Z,1550619582.679 [BuoyancyServo](INFO): Powering down
2019-02-19T23:39:42.693Z,1550619582.693 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-02-19T23:39:42.693Z,1550619582.693 [ElevatorServo](INFO): Powering down
2019-02-19T23:39:42.712Z,1550619582.712 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-02-19T23:39:42.712Z,1550619582.712 [MassServo](INFO): Powering down
2019-02-19T23:39:42.713Z,1550619582.713 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-02-19T23:39:42.713Z,1550619582.713 [RudderServo](INFO): Powering down
2019-02-19T23:39:42.714Z,1550619582.714 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-02-19T23:39:42.714Z,1550619582.714 [ThrusterServo](INFO): Powering down
2019-02-19T23:39:42.715Z,1550619582.715 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-02-19T23:39:42.715Z,1550619582.715 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-02-19T23:39:42.715Z,1550619582.715 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-02-19T23:39:42.715Z,1550619582.715 [CBIT](DEBUG): Powering off loads.
2019-02-19T23:39:42.729Z,1550619582.729 [CBIT](DEBUG): Disabling WDT.
2019-02-19T23:39:42.741Z,1550619582.741 [CBIT](DEBUG): Opening all GF detection circuits.
2019-02-19T23:39:42.742Z,1550619582.742 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.811Z,1550619582.811 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.978Z,1550619582.978 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:42.980Z,1550619582.980 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:43.033Z,1550619583.033 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:39:43.075Z,1550619583.075 [logger ThreadHandler](INFO): Thread cancelled.