2019-02-19T23:35:37.624Z,1550619337.624 [Supervisor](DEBUG): Initializing supervisor.
2019-02-19T23:35:37.627Z,1550619337.627 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-02-19T23:35:37.627Z,1550619337.627 [SyncHandler](INFO): Protected caller Thread ID is 1184
2019-02-19T23:35:37.628Z,1550619337.628 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-02-19T23:35:37.629Z,1550619337.629 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-02-19T23:35:37.629Z,1550619337.629 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1185
2019-02-19T23:35:37.632Z,1550619337.632 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-02-19T23:35:37.643Z,1550619337.643 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-02-19T23:35:37.644Z,1550619337.644 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-02-19T23:35:37.644Z,1550619337.644 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1186
2019-02-19T23:35:37.645Z,1550619337.645 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-02-19T23:35:37.646Z,1550619337.646 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-02-19T23:35:37.646Z,1550619337.646 [logger ThreadHandler](INFO): Protected caller Thread ID is 1187
2019-02-19T23:35:37.648Z,1550619337.648 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-02-19T23:35:37.649Z,1550619337.649 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-02-19T23:35:37.650Z,1550619337.650 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-02-19T23:35:38.062Z,1550619338.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-02-19T23:35:38.062Z,1550619338.062 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-02-19T23:35:38.158Z,1550619338.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-02-19T23:35:38.158Z,1550619338.158 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-02-19T23:35:38.476Z,1550619338.476 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-02-19T23:35:38.477Z,1550619338.477 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-02-19T23:35:38.614Z,1550619338.614 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-02-19T23:35:38.615Z,1550619338.615 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-02-19T23:35:38.803Z,1550619338.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-02-19T23:35:38.804Z,1550619338.804 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-02-19T23:35:39.259Z,1550619339.259 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-02-19T23:35:39.259Z,1550619339.259 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-02-19T23:35:39.461Z,1550619339.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-02-19T23:35:39.461Z,1550619339.461 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-02-19T23:35:39.604Z,1550619339.604 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-02-19T23:35:39.604Z,1550619339.604 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-02-19T23:35:39.795Z,1550619339.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-02-19T23:35:39.795Z,1550619339.795 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-02-19T23:35:39.889Z,1550619339.889 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-02-19T23:35:39.890Z,1550619339.890 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-02-19T23:35:40.198Z,1550619340.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-02-19T23:35:40.198Z,1550619340.198 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-02-19T23:35:40.277Z,1550619340.277 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-02-19T23:35:40.379Z,1550619340.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-02-19T23:35:40.379Z,1550619340.379 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-02-19T23:35:40.862Z,1550619340.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-02-19T23:35:40.863Z,1550619340.863 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-02-19T23:35:41.254Z,1550619341.254 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-02-19T23:35:41.257Z,1550619341.257 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-02-19T23:35:41.257Z,1550619341.257 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-02-19T23:35:41.462Z,1550619341.462 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-02-19T23:35:41.560Z,1550619341.560 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-02-19T23:35:41.657Z,1550619341.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-02-19T23:35:41.881Z,1550619341.881 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-02-19T23:35:41.881Z,1550619341.881 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-02-19T23:35:41.964Z,1550619341.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-02-19T23:35:42.056Z,1550619342.056 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-02-19T23:35:42.152Z,1550619342.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-02-19T23:35:42.233Z,1550619342.233 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-02-19T23:35:42.339Z,1550619342.339 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-02-19T23:35:42.521Z,1550619342.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-02-19T23:35:42.836Z,1550619342.836 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2019-02-19T23:35:42.837Z,1550619342.837 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-02-19T23:35:42.838Z,1550619342.838 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-02-19T23:35:43.339Z,1550619343.339 [AHRS_M2] Loaded
2019-02-19T23:35:43.339Z,1550619343.339 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-02-19T23:35:43.410Z,1550619343.410 [DataOverHttps] Loaded
2019-02-19T23:35:43.411Z,1550619343.411 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-02-19T23:35:43.424Z,1550619343.424 [Depth_Keller] Loaded
2019-02-19T23:35:43.424Z,1550619343.424 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-02-19T23:35:43.429Z,1550619343.429 [DropWeight] Loaded
2019-02-19T23:35:43.429Z,1550619343.429 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-02-19T23:35:43.477Z,1550619343.477 [DUSBL_Hydroid] Loaded
2019-02-19T23:35:43.477Z,1550619343.477 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-02-19T23:35:43.517Z,1550619343.517 [Micromodem] Loaded
2019-02-19T23:35:43.517Z,1550619343.517 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-02-19T23:35:43.614Z,1550619343.614 [NAL9602] Loaded
2019-02-19T23:35:43.615Z,1550619343.615 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-02-19T23:35:43.630Z,1550619343.630 [Onboard] Loaded
2019-02-19T23:35:43.631Z,1550619343.631 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-02-19T23:35:43.641Z,1550619343.641 [Radio_Surface] Loaded
2019-02-19T23:35:43.641Z,1550619343.641 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-02-19T23:35:43.642Z,1550619343.642 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407534E0
2019-02-19T23:35:43.643Z,1550619343.643 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1266
2019-02-19T23:35:43.671Z,1550619343.671 [RDI_Pathfinder] Loaded
2019-02-19T23:35:43.671Z,1550619343.671 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-02-19T23:35:43.693Z,1550619343.693 [RDI_PathfinderUp] Loaded
2019-02-19T23:35:43.693Z,1550619343.693 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2019-02-19T23:35:45.487Z,1550619345.487 [BPC1] Loaded
2019-02-19T23:35:45.487Z,1550619345.487 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-02-19T23:35:45.488Z,1550619345.488 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-02-19T23:35:45.488Z,1550619345.488 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-02-19T23:35:45.502Z,1550619345.502 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-02-19T23:35:45.502Z,1550619345.502 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-02-19T23:35:45.608Z,1550619345.608 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-02-19T23:35:45.608Z,1550619345.608 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-02-19T23:35:45.667Z,1550619345.667 [DeadReckonUsingSpeedCalculator] Loaded
2019-02-19T23:35:45.667Z,1550619345.667 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-02-19T23:35:45.727Z,1550619345.727 [DeadReckonWithRespectToSeafloor] Loaded
2019-02-19T23:35:45.728Z,1550619345.728 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-02-19T23:35:45.743Z,1550619345.743 [NavChart] Loaded
2019-02-19T23:35:45.743Z,1550619345.743 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-02-19T23:35:45.748Z,1550619345.748 [UniversalFixResidualReporter] Loaded
2019-02-19T23:35:45.748Z,1550619345.748 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-02-19T23:35:45.748Z,1550619345.748 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-02-19T23:35:45.749Z,1550619345.749 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-02-19T23:35:45.851Z,1550619345.851 [BuoyancyServo] Loaded
2019-02-19T23:35:45.851Z,1550619345.851 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-02-19T23:35:45.866Z,1550619345.866 [ElevatorServo] Loaded
2019-02-19T23:35:45.866Z,1550619345.866 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-02-19T23:35:45.881Z,1550619345.881 [MassServo] Loaded
2019-02-19T23:35:45.881Z,1550619345.881 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-02-19T23:35:45.897Z,1550619345.897 [RudderServo] Loaded
2019-02-19T23:35:45.897Z,1550619345.897 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-02-19T23:35:45.912Z,1550619345.912 [ThrusterServo] Loaded
2019-02-19T23:35:45.912Z,1550619345.912 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-02-19T23:35:45.912Z,1550619345.912 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-02-19T23:35:45.913Z,1550619345.913 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-02-19T23:35:46.090Z,1550619346.090 [Aanderaa_O2] Loaded
2019-02-19T23:35:46.090Z,1550619346.090 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-02-19T23:35:46.174Z,1550619346.174 [CTD_NeilBrown] Loaded
2019-02-19T23:35:46.174Z,1550619346.174 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-02-19T23:35:46.175Z,1550619346.175 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408624E0
2019-02-19T23:35:46.176Z,1550619346.176 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1267
2019-02-19T23:35:46.220Z,1550619346.220 [WetLabsSeaOWL_UV_A] Loaded
2019-02-19T23:35:46.221Z,1550619346.221 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-02-19T23:35:46.222Z,1550619346.222 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408924E0
2019-02-19T23:35:46.222Z,1550619346.222 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1268
2019-02-19T23:35:46.223Z,1550619346.223 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-02-19T23:35:46.223Z,1550619346.223 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-02-19T23:35:46.462Z,1550619346.462 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-02-19T23:35:46.462Z,1550619346.462 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-02-19T23:35:46.503Z,1550619346.503 [DepthRateCalculator] Loaded
2019-02-19T23:35:46.503Z,1550619346.503 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-02-19T23:35:46.509Z,1550619346.509 [PitchRateCalculator] Loaded
2019-02-19T23:35:46.509Z,1550619346.509 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-02-19T23:35:46.521Z,1550619346.521 [SpeedCalculator] Loaded
2019-02-19T23:35:46.522Z,1550619346.522 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-02-19T23:35:46.543Z,1550619346.543 [TempGradientCalculator] Loaded
2019-02-19T23:35:46.543Z,1550619346.543 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-02-19T23:35:46.549Z,1550619346.549 [YawRateCalculator] Loaded
2019-02-19T23:35:46.549Z,1550619346.549 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-02-19T23:35:46.590Z,1550619346.590 [ElevatorOffsetCalculator] Loaded
2019-02-19T23:35:46.590Z,1550619346.590 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-02-19T23:35:46.590Z,1550619346.590 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-02-19T23:35:46.591Z,1550619346.591 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-02-19T23:35:46.726Z,1550619346.726 [SBIT](DEBUG): Construct Startup Built In Test.
2019-02-19T23:35:46.748Z,1550619346.748 [SBIT] Loaded
2019-02-19T23:35:46.748Z,1550619346.748 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-02-19T23:35:46.749Z,1550619346.749 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-02-19T23:35:46.760Z,1550619346.760 [IBIT] Loaded
2019-02-19T23:35:46.760Z,1550619346.760 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-02-19T23:35:46.763Z,1550619346.763 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-02-19T23:35:46.902Z,1550619346.902 [CBIT] Loaded
2019-02-19T23:35:46.902Z,1550619346.902 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-02-19T23:35:46.903Z,1550619346.903 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-02-19T23:35:46.903Z,1550619346.903 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-02-19T23:35:46.967Z,1550619346.967 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-02-19T23:35:46.968Z,1550619346.968 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-02-19T23:35:47.069Z,1550619347.069 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-02-19T23:35:47.069Z,1550619347.069 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-02-19T23:35:47.136Z,1550619347.136 [VerticalControl](DEBUG): Construct VerticalControl.
2019-02-19T23:35:47.220Z,1550619347.220 [VerticalControl] Loaded
2019-02-19T23:35:47.220Z,1550619347.220 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-02-19T23:35:47.221Z,1550619347.221 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-02-19T23:35:47.278Z,1550619347.278 [HorizontalControl] Loaded
2019-02-19T23:35:47.279Z,1550619347.279 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-02-19T23:35:47.279Z,1550619347.279 [SpeedControl](DEBUG): Construct SpeedControl.
2019-02-19T23:35:47.281Z,1550619347.281 [SpeedControl] Loaded
2019-02-19T23:35:47.282Z,1550619347.282 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-02-19T23:35:47.282Z,1550619347.282 [LoopControl](DEBUG): Construct LoopControl.
2019-02-19T23:35:47.283Z,1550619347.283 [LoopControl] Loaded
2019-02-19T23:35:47.283Z,1550619347.283 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-02-19T23:35:47.283Z,1550619347.283 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-02-19T23:35:47.284Z,1550619347.284 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-02-19T23:35:47.311Z,1550619347.311 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-02-19T23:35:47.315Z,1550619347.315 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-02-19T23:35:47.316Z,1550619347.316 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-02-19T23:35:47.322Z,1550619347.322 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-02-19T23:35:47.323Z,1550619347.323 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2019-02-19T23:35:47.324Z,1550619347.324 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1269
2019-02-19T23:35:47.328Z,1550619347.328 [Supervisor](INFO): Main Thread ID is 1183
2019-02-19T23:35:47.329Z,1550619347.329 [Supervisor](DEBUG): Running supervisor.
2019-02-19T23:35:47.329Z,1550619347.329 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1270
2019-02-19T23:35:47.332Z,1550619347.332 [controlThread ThreadHandler](INFO): Handler Thread ID is 1271
2019-02-19T23:35:47.332Z,1550619347.332 [controlThread](DEBUG): Initializing ControlThread
2019-02-19T23:35:47.340Z,1550619347.340 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-19T23:35:47.341Z,1550619347.341 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-02-19T23:35:47.341Z,1550619347.341 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-02-19T23:35:47.343Z,1550619347.343 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-02-19T23:35:47.343Z,1550619347.343 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-02-19T23:35:47.343Z,1550619347.343 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-02-19T23:35:47.343Z,1550619347.343 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-02-19T23:35:47.344Z,1550619347.344 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-02-19T23:35:47.344Z,1550619347.344 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-02-19T23:35:47.345Z,1550619347.345 [SBIT](INFO): Initialize SBIT Component.
2019-02-19T23:35:47.346Z,1550619347.346 [SBIT](IMPORTANT): git: 2019-02-11-5-g1cf9f4d
2019-02-19T23:35:47.346Z,1550619347.346 [SBIT](INFO): git hash: 1cf9f4d7aba313398a625168a3064bcf57d75169
2019-02-19T23:35:47.346Z,1550619347.346 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-02-19T23:35:47.346Z,1550619347.346 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2019-02-19T23:35:47.347Z,1550619347.347 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-02-19T23:35:47.348Z,1550619347.348 [IBIT](INFO): Initialize IBIT Component.
2019-02-19T23:35:47.349Z,1550619347.349 [CBIT](DEBUG): Initialize CBIT Component.
2019-02-19T23:35:47.350Z,1550619347.350 [logger ThreadHandler](INFO): Handler Thread ID is 1272
2019-02-19T23:35:47.361Z,1550619347.361 [CBIT](DEBUG): Initialized mux pins.
2019-02-19T23:35:47.361Z,1550619347.361 [CBIT](DEBUG): Initializing the watchdog timer.
2019-02-19T23:35:47.369Z,1550619347.369 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1273
2019-02-19T23:35:47.370Z,1550619347.370 [Radio_Surface](INFO): Powering up
2019-02-19T23:35:47.381Z,1550619347.381 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1274
2019-02-19T23:35:47.382Z,1550619347.382 [CTD_NeilBrown](INFO): Powering down
2019-02-19T23:35:47.389Z,1550619347.389 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-02-19T23:35:47.389Z,1550619347.389 [CBIT](DEBUG): Initializing heartbeat.
2019-02-19T23:35:47.409Z,1550619347.409 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1275
2019-02-19T23:35:47.410Z,1550619347.410 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-02-19T23:35:47.440Z,1550619347.440 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1276
2019-02-19T23:35:47.443Z,1550619347.443 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2019-02-19T23:35:47.450Z,1550619347.450 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-02-19T23:35:47.451Z,1550619347.451 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2019-02-19T23:35:47.451Z,1550619347.451 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-19T23:35:47.453Z,1550619347.453 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2019-02-19T23:35:47.453Z,1550619347.453 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-19T23:35:47.454Z,1550619347.454 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2019-02-19T23:35:47.455Z,1550619347.455 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-19T23:35:47.456Z,1550619347.456 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000
2019-02-19T23:35:47.456Z,1550619347.456 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-19T23:35:47.458Z,1550619347.458 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2019-02-19T23:35:47.458Z,1550619347.458 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-19T23:35:47.459Z,1550619347.459 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000
2019-02-19T23:35:47.460Z,1550619347.460 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-19T23:35:47.461Z,1550619347.461 [CBIT](DEBUG): Deactivating GF circuits.
2019-02-19T23:35:47.461Z,1550619347.461 [CBIT](DEBUG): Deactivating emergency mode.
2019-02-19T23:35:47.469Z,1550619347.469 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000
2019-02-19T23:35:47.469Z,1550619347.469 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-19T23:35:47.471Z,1550619347.471 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000
2019-02-19T23:35:47.497Z,1550619347.497 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-02-19T23:35:47.499Z,1550619347.499 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-02-19T23:35:47.499Z,1550619347.499 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-02-19T23:35:47.500Z,1550619347.500 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-02-19T23:35:47.501Z,1550619347.501 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-02-19T23:35:47.511Z,1550619347.511 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-19T23:35:47.521Z,1550619347.521 [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:35:47.522Z,1550619347.522 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-02-19T23:35:47.549Z,1550619347.549 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-19T23:35:47.620Z,1550619347.620 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-02-19T23:35:47.621Z,1550619347.621 [Default:A.Wait](DEBUG): Construct Wait.
2019-02-19T23:35:47.623Z,1550619347.623 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-19T23:35:47.693Z,1550619347.693 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-02-19T23:35:47.695Z,1550619347.695 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-02-19T23:35:47.717Z,1550619347.717 [Default:E.Execute](DEBUG): Construct Execute.
2019-02-19T23:35:47.720Z,1550619347.720 [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:35:47.727Z,1550619347.727 [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:35:47.732Z,1550619347.732 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-02-19T23:35:47.774Z,1550619347.774 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-02-19T23:35:47.777Z,1550619347.777 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-02-19T23:35:47.786Z,1550619347.786 [DUSBL_Hydroid](INFO): Powering up
2019-02-19T23:35:47.786Z,1550619347.786 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-02-19T23:35:47.813Z,1550619347.813 [Micromodem](INFO): Start
2019-02-19T23:35:47.889Z,1550619347.889 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-02-19T23:35:47.916Z,1550619347.916 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:35:47.921Z,1550619347.921 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-19T23:35:47.922Z,1550619347.922 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:35:47.929Z,1550619347.929 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-02-19T23:35:47.930Z,1550619347.930 [MassServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:35:47.937Z,1550619347.937 [MassServo](DEBUG): Initializing MassServo.
2019-02-19T23:35:47.938Z,1550619347.938 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:35:47.945Z,1550619347.945 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-19T23:35:47.946Z,1550619347.946 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-02-19T23:35:47.953Z,1550619347.953 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-02-19T23:35:48.166Z,1550619348.166 [Micromodem](INFO): Starting
2019-02-19T23:35:48.167Z,1550619348.167 [Micromodem](INFO): Powering up
2019-02-19T23:35:48.167Z,1550619348.167 [Micromodem](DEBUG): Initializing Micromodem.
2019-02-19T23:35:48.265Z,1550619348.265 [RDI_PathfinderUp](INFO): Powering down
2019-02-19T23:35:48.345Z,1550619348.345 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-02-19T23:35:56.682Z,1550619356.682 [Micromodem](INFO): Starting
2019-02-19T23:35:56.682Z,1550619356.682 [Micromodem](INFO): Starting
2019-02-19T23:35:56.683Z,1550619356.683 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:35:56.683Z,1550619356.683 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:35:56.683Z,1550619356.683 [Micromodem](INFO): Nmea out: $
2019-02-19T23:35:56.684Z,1550619356.684 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:35:56.684Z,1550619356.684 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:35:56.689Z,1550619356.689 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:35:56.689Z,1550619356.689 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:35:56.689Z,1550619356.689 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:35:56.689Z,1550619356.689 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:35:56.690Z,1550619356.690 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:35:56.690Z,1550619356.690 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:35:56.742Z,1550619356.742 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-02-19T23:35:57.365Z,1550619357.365 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:35:57.375Z,1550619357.375 [Micromodem](INFO): Starting
2019-02-19T23:35:57.773Z,1550619357.773 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:35:57.778Z,1550619357.778 [Micromodem](INFO): Starting
2019-02-19T23:35:57.909Z,1550619357.909 [Aanderaa_O2](INFO): Powering down
2019-02-19T23:35:58.317Z,1550619358.317 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:35:58.323Z,1550619358.323 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004527
2019-02-19T23:35:58.326Z,1550619358.326 [Micromodem](INFO): Starting
2019-02-19T23:35:58.327Z,1550619358.327 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:35:58.327Z,1550619358.327 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:35:58.821Z,1550619358.821 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:35:58.821Z,1550619358.821 [AHRS_M2](FAULT): Failed to initialize within timeout.
2019-02-19T23:35:58.821Z,1550619358.821 [AHRS_M2] Communications Fault, FailCount= 1
2019-02-19T23:35:58.821Z,1550619358.821 [AHRS_M2](ERROR): Communications Fault
2019-02-19T23:35:58.826Z,1550619358.826 [Micromodem](INFO): Starting
2019-02-19T23:35:58.880Z,1550619358.880 [CBIT](ERROR): Communications Fault in component: AHRS_M2
2019-02-19T23:35:58.900Z,1550619358.900 [AHRS_M2](INFO): Powering down
2019-02-19T23:35:59.031Z,1550619359.031 [Micromodem](INFO): Starting
2019-02-19T23:35:59.310Z,1550619359.310 [Micromodem](INFO): Starting
2019-02-19T23:35:59.714Z,1550619359.714 [Micromodem](INFO): Starting
2019-02-19T23:35:59.977Z,1550619359.977 [CBIT](INFO): Clearing failed state for component AHRS_M2
2019-02-19T23:35:59.977Z,1550619359.977 [AHRS_M2] No Fault, FailCount= 1
2019-02-19T23:36:00.112Z,1550619360.112 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-02-19T23:36:00.126Z,1550619360.126 [Micromodem](INFO): Starting
2019-02-19T23:36:00.539Z,1550619360.539 [Micromodem](INFO): Starting
2019-02-19T23:36:00.926Z,1550619360.926 [Micromodem](INFO): Starting
2019-02-19T23:36:01.331Z,1550619361.331 [Micromodem](INFO): Starting
2019-02-19T23:36:01.357Z,1550619361.357 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-02-19T23:36:01.734Z,1550619361.734 [Micromodem](INFO): Starting
2019-02-19T23:36:02.150Z,1550619362.150 [Micromodem](INFO): Starting
2019-02-19T23:36:02.550Z,1550619362.550 [Micromodem](INFO): Starting
2019-02-19T23:36:02.866Z,1550619362.866 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-19T23:36:02.954Z,1550619362.954 [Micromodem](INFO): Starting
2019-02-19T23:36:03.669Z,1550619363.669 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:03.674Z,1550619363.674 [Micromodem](INFO): Starting
2019-02-19T23:36:04.101Z,1550619364.101 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:04.118Z,1550619364.118 [Micromodem](INFO): Starting
2019-02-19T23:36:04.521Z,1550619364.521 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:04.542Z,1550619364.542 [Micromodem](INFO): Starting
2019-02-19T23:36:04.957Z,1550619364.957 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:04.963Z,1550619364.963 [Micromodem](INFO): Starting
2019-02-19T23:36:05.409Z,1550619365.409 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:05.415Z,1550619365.415 [Micromodem](INFO): Starting
2019-02-19T23:36:05.857Z,1550619365.857 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:05.860Z,1550619365.860 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-02-19T23:36:05.873Z,1550619365.873 [Micromodem](INFO): Starting
2019-02-19T23:36:06.353Z,1550619366.353 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:06.358Z,1550619366.358 [Micromodem](INFO): Starting
2019-02-19T23:36:06.789Z,1550619366.789 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:06.791Z,1550619366.791 [Micromodem](INFO): Starting
2019-02-19T23:36:07.241Z,1550619367.241 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:07.247Z,1550619367.247 [Micromodem](INFO): Starting
2019-02-19T23:36:07.661Z,1550619367.661 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:07.666Z,1550619367.666 [Micromodem](INFO): Starting
2019-02-19T23:36:08.073Z,1550619368.073 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:08.086Z,1550619368.086 [Micromodem](INFO): Starting
2019-02-19T23:36:08.087Z,1550619368.087 [Micromodem](FAULT): failed to initialize; deviceResponse_ loaded: , available: $CAREV,025547,INIT,2.0.27690*4C
$CAREV,025547,SLOT1,2.0.27690*63
$CAREV,025547,AUV,2.0.27690*14
$CAREV,025547,COPROC,0.10.0.46*41
$CATMG,1902-02-23T02:55:47Z,RTC,RTC*76
$CAREV,025557,AUV,2.0.27690*15
$CAREV,025557,COPROC,0.10.0.46*40
!
2019-02-19T23:36:08.087Z,1550619368.087 [Micromodem] Communications Fault, FailCount= 1
2019-02-19T23:36:08.087Z,1550619368.087 [Micromodem](ERROR): Communications Fault
2019-02-19T23:36:08.241Z,1550619368.241 [CBIT](ERROR): Communications Fault in component: Micromodem
2019-02-19T23:36:08.561Z,1550619368.561 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:08.563Z,1550619368.563 [Micromodem](INFO): Stop
2019-02-19T23:36:08.563Z,1550619368.563 [Micromodem](INFO): uninitialize
2019-02-19T23:36:08.563Z,1550619368.563 [Micromodem](INFO): Powering down
2019-02-19T23:36:09.141Z,1550619369.141 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:09.146Z,1550619369.146 [Micromodem](INFO): Stopping
2019-02-19T23:36:09.545Z,1550619369.545 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:09.557Z,1550619369.557 [Micromodem](INFO): Stopped
2019-02-19T23:36:09.709Z,1550619369.709 [CBIT](INFO): Clearing failed state for component Micromodem
2019-02-19T23:36:09.709Z,1550619369.709 [Micromodem] No Fault, FailCount= 1
2019-02-19T23:36:10.029Z,1550619370.029 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:10.031Z,1550619370.031 [Micromodem](INFO): Start
2019-02-19T23:36:10.457Z,1550619370.457 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:10.462Z,1550619370.462 [Micromodem](INFO): Start
2019-02-19T23:36:10.925Z,1550619370.925 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:10.930Z,1550619370.930 [Micromodem](INFO): Start
2019-02-19T23:36:11.357Z,1550619371.357 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:11.362Z,1550619371.362 [Micromodem](INFO): Start
2019-02-19T23:36:11.773Z,1550619371.773 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:11.778Z,1550619371.778 [Micromodem](INFO): Start
2019-02-19T23:36:12.213Z,1550619372.213 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:12.218Z,1550619372.218 [Micromodem](INFO): Starting
2019-02-19T23:36:12.218Z,1550619372.218 [Micromodem](INFO): Powering up
2019-02-19T23:36:12.219Z,1550619372.219 [Micromodem](DEBUG): Initializing Micromodem.
2019-02-19T23:36:12.673Z,1550619372.673 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:12.686Z,1550619372.686 [Micromodem](INFO): Starting
2019-02-19T23:36:13.101Z,1550619373.101 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:13.101Z,1550619373.101 [AHRS_M2](FAULT): Failed to initialize within timeout.
2019-02-19T23:36:13.101Z,1550619373.101 [AHRS_M2] Communications Fault, FailCount= 2
2019-02-19T23:36:13.101Z,1550619373.101 [AHRS_M2](ERROR): Communications Fault
2019-02-19T23:36:13.106Z,1550619373.106 [Micromodem](INFO): Starting
2019-02-19T23:36:13.254Z,1550619373.254 [CBIT](ERROR): Communications Fault in component: AHRS_M2
2019-02-19T23:36:13.260Z,1550619373.260 [AHRS_M2](INFO): Powering down
2019-02-19T23:36:13.334Z,1550619373.334 [Micromodem](INFO): Starting
2019-02-19T23:36:13.666Z,1550619373.666 [Micromodem](INFO): Starting
2019-02-19T23:36:13.667Z,1550619373.667 [NAL9602](INFO): Powering up NAL9602
2019-02-19T23:36:14.070Z,1550619374.070 [Micromodem](INFO): Starting
2019-02-19T23:36:14.111Z,1550619374.111 [CBIT](INFO): Clearing failed state for component AHRS_M2
2019-02-19T23:36:14.111Z,1550619374.111 [AHRS_M2] No Fault, FailCount= 2
2019-02-19T23:36:14.468Z,1550619374.468 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-02-19T23:36:14.482Z,1550619374.482 [Micromodem](INFO): Starting
2019-02-19T23:36:14.878Z,1550619374.878 [Micromodem](INFO): Starting
2019-02-19T23:36:15.282Z,1550619375.282 [Micromodem](INFO): Starting
2019-02-19T23:36:15.686Z,1550619375.686 [Micromodem](INFO): Starting
2019-02-19T23:36:16.090Z,1550619376.090 [Micromodem](INFO): Starting
2019-02-19T23:36:16.176Z,1550619376.176 [SBIT](IMPORTANT): Beginning Startup BIT
2019-02-19T23:36:16.190Z,1550619376.190 [CBIT](IMPORTANT): Beginning ground fault scan
2019-02-19T23:36:16.502Z,1550619376.502 [Micromodem](INFO): Starting
2019-02-19T23:36:16.898Z,1550619376.898 [Micromodem](INFO): Starting
2019-02-19T23:36:16.898Z,1550619376.898 [Micromodem](INFO): Starting
2019-02-19T23:36:16.898Z,1550619376.898 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:36:16.899Z,1550619376.899 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:36:16.899Z,1550619376.899 [Micromodem](INFO): Nmea out: $
2019-02-19T23:36:16.899Z,1550619376.899 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:36:16.899Z,1550619376.899 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:36:16.900Z,1550619376.900 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:36:16.900Z,1550619376.900 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:36:16.900Z,1550619376.900 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:36:16.900Z,1550619376.900 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:36:16.900Z,1550619376.900 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:36:16.902Z,1550619376.902 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:36:17.302Z,1550619377.302 [Micromodem](INFO): Starting
2019-02-19T23:36:17.541Z,1550619377.541 [CommandLine](IMPORTANT): got command quit
2019-02-19T23:36:18.017Z,1550619378.017 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:18.019Z,1550619378.019 [Micromodem](INFO): Starting
2019-02-19T23:36:18.545Z,1550619378.545 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-02-19T23:36:18.545Z,1550619378.545 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:36:18.545Z,1550619378.545 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:18.577Z,1550619378.577 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:18.582Z,1550619378.582 [Micromodem](INFO): Starting
2019-02-19T23:36:18.583Z,1550619378.583 [Micromodem](INFO): Nmea cmd: $
2019-02-19T23:36:18.583Z,1550619378.583 [Micromodem](INFO): Nmea buf: $
2019-02-19T23:36:18.598Z,1550619378.598 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2019-02-19T23:36:18.598Z,1550619378.598 [RDI_Pathfinder] Communications Fault, FailCount= 1
2019-02-19T23:36:18.598Z,1550619378.598 [RDI_Pathfinder](ERROR): Communications Fault
2019-02-19T23:36:18.705Z,1550619378.705 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-02-19T23:36:18.705Z,1550619378.705 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:18.706Z,1550619378.706 [CommandLine](INFO): Join timeout helper Thread ID is 1293
2019-02-19T23:36:18.717Z,1550619378.717 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-02-19T23:36:18.718Z,1550619378.718 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:18.718Z,1550619378.718 [NavChartDb](INFO): Join timeout helper Thread ID is 1294
2019-02-19T23:36:18.720Z,1550619378.720 [NavChartDb](INFO): # of records loaded: 3354
2019-02-19T23:36:18.731Z,1550619378.731 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA83M.000
2019-02-19T23:36:18.731Z,1550619378.731 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:36:18.732Z,1550619378.732 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:18.745Z,1550619378.745 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-02-19T23:36:18.745Z,1550619378.745 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:18.745Z,1550619378.745 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1295
2019-02-19T23:36:18.949Z,1550619378.949 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:36:18.949Z,1550619378.949 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-02-19T23:36:18.950Z,1550619378.950 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:18.965Z,1550619378.965 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-02-19T23:36:18.965Z,1550619378.965 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:18.965Z,1550619378.965 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1296
2019-02-19T23:36:19.037Z,1550619379.037 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2019-02-19T23:36:19.081Z,1550619379.081 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:36:19.081Z,1550619379.081 [CTD_NeilBrown](INFO): Powering down
2019-02-19T23:36:19.093Z,1550619379.093 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:19.109Z,1550619379.109 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-02-19T23:36:19.109Z,1550619379.109 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:19.109Z,1550619379.109 [Radio_Surface](INFO): Join timeout helper Thread ID is 1297
2019-02-19T23:36:19.325Z,1550619379.325 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:36:19.325Z,1550619379.325 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:19.334Z,1550619379.334 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-02-19T23:36:19.334Z,1550619379.334 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:19.334Z,1550619379.334 [logger](INFO): Join timeout helper Thread ID is 1298
2019-02-19T23:36:19.357Z,1550619379.357 [AHRS_M2](ERROR): setBoresightMatrix UART error: serial timeout
2019-02-19T23:36:19.359Z,1550619379.359 [Micromodem](INFO): Starting
2019-02-19T23:36:19.433Z,1550619379.433 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:36:19.433Z,1550619379.433 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:19.445Z,1550619379.445 [RDI_Pathfinder](INFO): Powering down
2019-02-19T23:36:19.454Z,1550619379.454 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-02-19T23:36:19.454Z,1550619379.454 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:19.454Z,1550619379.454 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-02-19T23:36:19.454Z,1550619379.454 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:19.454Z,1550619379.454 [controlThread](INFO): Join timeout helper Thread ID is 1299
2019-02-19T23:36:19.618Z,1550619379.618 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-19T23:36:19.618Z,1550619379.618 [controlThread](DEBUG): Uninitializing ControlThread
2019-02-19T23:36:19.618Z,1550619379.618 [AHRS_M2](INFO): Powering down
2019-02-19T23:36:19.690Z,1550619379.690 [DUSBL_Hydroid](INFO): Powering down
2019-02-19T23:36:19.781Z,1550619379.781 [Micromodem](INFO): uninitialize
2019-02-19T23:36:19.781Z,1550619379.781 [Micromodem](INFO): Powering down
2019-02-19T23:36:19.877Z,1550619379.877 [NAL9602](INFO): Powering down
2019-02-19T23:36:19.898Z,1550619379.898 [RDI_Pathfinder](INFO): Powering down
2019-02-19T23:36:19.899Z,1550619379.899 [RDI_PathfinderUp](INFO): Powering down
2019-02-19T23:36:19.900Z,1550619379.900 [Aanderaa_O2](INFO): Powering down
2019-02-19T23:36:19.901Z,1550619379.901 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-02-19T23:36:19.902Z,1550619379.902 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-02-19T23:36:19.903Z,1550619379.903 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-02-19T23:36:19.904Z,1550619379.904 [MissionManager](INFO): Uninitializing Mission Default
2019-02-19T23:36:19.906Z,1550619379.906 [MissionManager](INFO): Uninitializing Mission Startup
2019-02-19T23:36:19.907Z,1550619379.907 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-02-19T23:36:19.907Z,1550619379.907 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-02-19T23:36:19.908Z,1550619379.908 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-02-19T23:36:19.908Z,1550619379.908 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-02-19T23:36:19.908Z,1550619379.908 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-02-19T23:36:19.908Z,1550619379.908 [BuoyancyServo](INFO): Powering down
2019-02-19T23:36:19.921Z,1550619379.921 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-02-19T23:36:19.921Z,1550619379.921 [ElevatorServo](INFO): Powering down
2019-02-19T23:36:19.922Z,1550619379.922 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-02-19T23:36:19.922Z,1550619379.922 [MassServo](INFO): Powering down
2019-02-19T23:36:19.923Z,1550619379.923 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-02-19T23:36:19.923Z,1550619379.923 [RudderServo](INFO): Powering down
2019-02-19T23:36:19.924Z,1550619379.924 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-02-19T23:36:19.924Z,1550619379.924 [ThrusterServo](INFO): Powering down
2019-02-19T23:36:19.925Z,1550619379.925 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-02-19T23:36:19.925Z,1550619379.925 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-02-19T23:36:19.925Z,1550619379.925 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-02-19T23:36:19.925Z,1550619379.925 [CBIT](DEBUG): Powering off loads.
2019-02-19T23:36:19.937Z,1550619379.937 [CBIT](DEBUG): Disabling WDT.
2019-02-19T23:36:19.949Z,1550619379.949 [CBIT](DEBUG): Opening all GF detection circuits.
2019-02-19T23:36:19.950Z,1550619379.950 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:20.008Z,1550619380.008 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:20.295Z,1550619380.295 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:20.297Z,1550619380.297 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:20.350Z,1550619380.350 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-19T23:36:20.397Z,1550619380.397 [logger ThreadHandler](INFO): Thread cancelled.