2015-03-26T22:27:50.616Z,1427408870.616 [Supervisor](DEBUG): Initializing supervisor.
2015-03-26T22:27:50.619Z,1427408870.619 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-03-26T22:27:50.619Z,1427408870.619 [SyncHandler](INFO): Protected caller Thread ID is 8193
2015-03-26T22:27:50.620Z,1427408870.620 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-03-26T22:27:50.621Z,1427408870.621 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-03-26T22:27:50.621Z,1427408870.621 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8194
2015-03-26T22:27:50.624Z,1427408870.624 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-03-26T22:27:50.635Z,1427408870.635 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-03-26T22:27:50.636Z,1427408870.636 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-03-26T22:27:50.636Z,1427408870.636 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8195
2015-03-26T22:27:50.637Z,1427408870.637 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-03-26T22:27:50.638Z,1427408870.638 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-03-26T22:27:50.639Z,1427408870.639 [logger ThreadHandler](INFO): Protected caller Thread ID is 8196
2015-03-26T22:27:50.641Z,1427408870.641 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-03-26T22:27:50.641Z,1427408870.641 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-03-26T22:27:50.643Z,1427408870.643 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-03-26T22:27:50.967Z,1427408870.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-03-26T22:27:50.968Z,1427408870.968 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-03-26T22:27:51.126Z,1427408871.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-03-26T22:27:51.127Z,1427408871.127 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-03-26T22:27:51.233Z,1427408871.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-03-26T22:27:51.234Z,1427408871.234 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-03-26T22:27:51.355Z,1427408871.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-03-26T22:27:51.356Z,1427408871.356 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-03-26T22:27:51.439Z,1427408871.439 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-03-26T22:27:51.599Z,1427408871.599 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-03-26T22:27:51.600Z,1427408871.600 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-03-26T22:27:51.686Z,1427408871.686 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-03-26T22:27:51.687Z,1427408871.687 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-03-26T22:27:51.892Z,1427408871.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-03-26T22:27:51.892Z,1427408871.892 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-03-26T22:27:52.244Z,1427408872.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-03-26T22:27:52.245Z,1427408872.245 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-03-26T22:27:52.547Z,1427408872.547 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-03-26T22:27:52.548Z,1427408872.548 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-03-26T22:27:53.042Z,1427408873.042 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-03-26T22:27:53.042Z,1427408873.042 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-03-26T22:27:53.281Z,1427408873.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-03-26T22:27:53.281Z,1427408873.281 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-03-26T22:27:53.383Z,1427408873.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-03-26T22:27:53.384Z,1427408873.384 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-03-26T22:27:53.833Z,1427408873.833 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-03-26T22:27:53.834Z,1427408873.834 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-03-26T22:27:53.946Z,1427408873.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-03-26T22:27:53.949Z,1427408873.949 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2015-03-26T22:27:53.949Z,1427408873.949 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2015-03-26T22:27:54.051Z,1427408874.051 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2015-03-26T22:27:54.167Z,1427408874.167 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2015-03-26T22:27:54.263Z,1427408874.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2015-03-26T22:27:54.370Z,1427408874.370 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2015-03-26T22:27:54.464Z,1427408874.464 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2015-03-26T22:27:54.591Z,1427408874.591 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2015-03-26T22:27:54.743Z,1427408874.743 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2015-03-26T22:27:54.844Z,1427408874.844 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2015-03-26T22:27:54.933Z,1427408874.933 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2015-03-26T22:27:55.014Z,1427408875.014 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2015-03-26T22:27:55.109Z,1427408875.109 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2015-03-26T22:27:55.221Z,1427408875.221 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2015-03-26T22:27:55.457Z,1427408875.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-03-26T22:27:55.458Z,1427408875.458 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2015-03-26T22:27:55.459Z,1427408875.459 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-03-26T22:27:55.462Z,1427408875.462 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-03-26T22:27:55.536Z,1427408875.536 [VerticalControl](DEBUG): Construct VerticalControl.
2015-03-26T22:27:55.655Z,1427408875.655 [VerticalControl] Loaded
2015-03-26T22:27:55.656Z,1427408875.656 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-03-26T22:27:55.656Z,1427408875.656 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-03-26T22:27:55.728Z,1427408875.728 [HorizontalControl] Loaded
2015-03-26T22:27:55.728Z,1427408875.728 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-03-26T22:27:55.729Z,1427408875.729 [SpeedControl](DEBUG): Construct SpeedControl.
2015-03-26T22:27:55.735Z,1427408875.735 [SpeedControl] Loaded
2015-03-26T22:27:55.735Z,1427408875.735 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-03-26T22:27:55.736Z,1427408875.736 [LoopControl](DEBUG): Construct LoopControl.
2015-03-26T22:27:55.736Z,1427408875.736 [LoopControl] Loaded
2015-03-26T22:27:55.737Z,1427408875.737 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-03-26T22:27:55.737Z,1427408875.737 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-03-26T22:27:55.738Z,1427408875.738 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-03-26T22:27:55.892Z,1427408875.892 [SBIT](DEBUG): Construct Startup Built In Test.
2015-03-26T22:27:55.903Z,1427408875.903 [SBIT] Loaded
2015-03-26T22:27:55.903Z,1427408875.903 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-03-26T22:27:55.904Z,1427408875.904 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-03-26T22:27:55.933Z,1427408875.933 [IBIT] Loaded
2015-03-26T22:27:55.933Z,1427408875.933 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-03-26T22:27:55.936Z,1427408875.936 [CBIT](DEBUG): Construct Continuous Built In Test.
2015-03-26T22:27:56.069Z,1427408876.069 [CBIT] Loaded
2015-03-26T22:27:56.069Z,1427408876.069 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-03-26T22:27:56.070Z,1427408876.070 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-03-26T22:27:56.070Z,1427408876.070 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-03-26T22:27:56.101Z,1427408876.101 [DepthRateCalculator] Loaded
2015-03-26T22:27:56.101Z,1427408876.101 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-03-26T22:27:56.107Z,1427408876.107 [PitchRateCalculator] Loaded
2015-03-26T22:27:56.107Z,1427408876.107 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-03-26T22:27:56.119Z,1427408876.119 [SpeedCalculator] Loaded
2015-03-26T22:27:56.119Z,1427408876.119 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-03-26T22:27:56.136Z,1427408876.136 [TempGradientCalculator] Loaded
2015-03-26T22:27:56.136Z,1427408876.136 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-03-26T22:27:56.141Z,1427408876.141 [YawRateCalculator] Loaded
2015-03-26T22:27:56.141Z,1427408876.141 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-03-26T22:27:56.142Z,1427408876.142 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-03-26T22:27:56.143Z,1427408876.143 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-03-26T22:27:56.234Z,1427408876.234 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-03-26T22:27:56.235Z,1427408876.235 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-03-26T22:27:56.540Z,1427408876.540 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-03-26T22:27:56.541Z,1427408876.541 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-03-26T22:27:56.648Z,1427408876.648 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-03-26T22:27:56.648Z,1427408876.648 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-03-26T22:27:56.694Z,1427408876.694 [DeadReckonUsingSpeedCalculator] Loaded
2015-03-26T22:27:56.694Z,1427408876.694 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-03-26T22:27:56.711Z,1427408876.711 [NavChart] Loaded
2015-03-26T22:27:56.712Z,1427408876.712 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-03-26T22:27:56.716Z,1427408876.716 [UniversalFixResidualReporter] Loaded
2015-03-26T22:27:56.717Z,1427408876.717 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-03-26T22:27:56.717Z,1427408876.717 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-03-26T22:27:56.718Z,1427408876.718 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-03-26T22:27:56.726Z,1427408876.726 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-03-26T22:27:56.727Z,1427408876.727 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-03-26T22:27:56.920Z,1427408876.920 [Aanderaa_O2] Loaded
2015-03-26T22:27:56.920Z,1427408876.920 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2015-03-26T22:27:56.998Z,1427408876.998 [CTD_NeilBrown] Loaded
2015-03-26T22:27:56.998Z,1427408876.998 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2015-03-26T22:27:56.000Z,1427408877.000 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405754E0
2015-03-26T22:27:57.000Z,1427408877.000 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 8281
2015-03-26T22:27:57.013Z,1427408877.013 [ISUS] Loaded
2015-03-26T22:27:57.013Z,1427408877.013 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2015-03-26T22:27:57.028Z,1427408877.028 [PAR_Licor] Loaded
2015-03-26T22:27:57.028Z,1427408877.028 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2015-03-26T22:27:57.076Z,1427408877.076 [WetLabsBB2FL] Loaded
2015-03-26T22:27:57.076Z,1427408877.076 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2015-03-26T22:27:57.077Z,1427408877.077 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405A54E0
2015-03-26T22:27:57.078Z,1427408877.078 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8282
2015-03-26T22:27:57.078Z,1427408877.078 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-03-26T22:27:57.079Z,1427408877.079 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-03-26T22:27:57.641Z,1427408877.641 [AHRS_sp3003D] Loaded
2015-03-26T22:27:57.642Z,1427408877.642 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2015-03-26T22:27:57.744Z,1427408877.744 [DataOverHttps] Loaded
2015-03-26T22:27:57.744Z,1427408877.744 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-03-26T22:27:57.757Z,1427408877.757 [Depth_Keller] Loaded
2015-03-26T22:27:57.758Z,1427408877.758 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-03-26T22:27:57.763Z,1427408877.763 [DropWeight] Loaded
2015-03-26T22:27:57.763Z,1427408877.763 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2015-03-26T22:27:57.900Z,1427408877.900 [DVL_micro] Loaded
2015-03-26T22:27:57.900Z,1427408877.900 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2015-03-26T22:27:57.996Z,1427408877.996 [NAL9602] Loaded
2015-03-26T22:27:57.997Z,1427408877.997 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-03-26T22:27:58.040Z,1427408878.040 [Onboard] Loaded
2015-03-26T22:27:58.040Z,1427408878.040 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-03-26T22:27:58.047Z,1427408878.047 [Radio_Surface] Loaded
2015-03-26T22:27:58.048Z,1427408878.048 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-03-26T22:27:58.049Z,1427408878.049 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F54E0
2015-03-26T22:27:58.049Z,1427408878.049 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8283
2015-03-26T22:27:59.966Z,1427408879.966 [BPC1] Loaded
2015-03-26T22:27:59.966Z,1427408879.966 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-03-26T22:27:59.966Z,1427408879.966 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-03-26T22:27:59.967Z,1427408879.967 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-03-26T22:28:00.131Z,1427408880.131 [BuoyancyServo] Loaded
2015-03-26T22:28:00.132Z,1427408880.132 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-03-26T22:28:00.144Z,1427408880.144 [ElevatorServo] Loaded
2015-03-26T22:28:00.144Z,1427408880.144 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-03-26T22:28:00.156Z,1427408880.156 [MassServo] Loaded
2015-03-26T22:28:00.157Z,1427408880.157 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-03-26T22:28:00.169Z,1427408880.169 [RudderServo] Loaded
2015-03-26T22:28:00.169Z,1427408880.169 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-03-26T22:28:00.181Z,1427408880.181 [ThrusterServo] Loaded
2015-03-26T22:28:00.181Z,1427408880.181 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-03-26T22:28:00.182Z,1427408880.182 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-03-26T22:28:00.182Z,1427408880.182 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-03-26T22:28:00.321Z,1427408880.321 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-03-26T22:28:00.322Z,1427408880.322 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-03-26T22:28:00.362Z,1427408880.362 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-03-26T22:28:00.364Z,1427408880.364 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-03-26T22:28:00.365Z,1427408880.365 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-03-26T22:28:00.371Z,1427408880.371 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-03-26T22:28:00.374Z,1427408880.374 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408A64E0
2015-03-26T22:28:00.374Z,1427408880.374 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8284
2015-03-26T22:28:00.379Z,1427408880.379 [Supervisor](INFO): Main Thread ID is 8192
2015-03-26T22:28:00.380Z,1427408880.380 [Supervisor](DEBUG): Running supervisor.
2015-03-26T22:28:00.380Z,1427408880.380 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8285
2015-03-26T22:28:00.384Z,1427408880.384 [controlThread ThreadHandler](INFO): Handler Thread ID is 8286
2015-03-26T22:28:00.384Z,1427408880.384 [controlThread](DEBUG): Initializing ControlThread
2015-03-26T22:28:00.385Z,1427408880.385 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-03-26T22:28:00.387Z,1427408880.387 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-03-26T22:28:00.388Z,1427408880.388 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-03-26T22:28:00.388Z,1427408880.388 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-03-26T22:28:00.389Z,1427408880.389 [SBIT](INFO): Initialize SBIT Component.
2015-03-26T22:28:00.389Z,1427408880.389 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12051
2015-03-26T22:28:00.389Z,1427408880.389 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-03-26T22:28:00.390Z,1427408880.390 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-03-26T22:28:00.390Z,1427408880.390 [IBIT](INFO): Initialize IBIT Component.
2015-03-26T22:28:00.391Z,1427408880.391 [CBIT](DEBUG): Initialize CBIT Component.
2015-03-26T22:28:00.391Z,1427408880.391 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-03-26T22:28:00.391Z,1427408880.391 [CBIT](CRITICAL): Watchdog Timer failed to initialize.
2015-03-26T22:28:00.391Z,1427408880.391 [CBIT] Hardware Fault, FailCount= 1
2015-03-26T22:28:00.391Z,1427408880.391 [CBIT](ERROR): Hardware Fault
2015-03-26T22:28:00.392Z,1427408880.392 [logger ThreadHandler](INFO): Handler Thread ID is 8287
2015-03-26T22:28:00.418Z,1427408880.418 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-03-26T22:28:00.418Z,1427408880.418 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-03-26T22:28:00.419Z,1427408880.419 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-03-26T22:28:00.419Z,1427408880.419 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-03-26T22:28:00.420Z,1427408880.420 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-03-26T22:28:00.420Z,1427408880.420 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-03-26T22:28:00.420Z,1427408880.420 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-03-26T22:28:00.421Z,1427408880.421 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-03-26T22:28:00.421Z,1427408880.421 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-03-26T22:28:00.430Z,1427408880.430 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 8288
2015-03-26T22:28:00.431Z,1427408880.431 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2015-03-26T22:28:00.435Z,1427408880.435 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2015-03-26T22:28:00.447Z,1427408880.447 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-03-26T22:28:00.462Z,1427408880.462 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8290
2015-03-26T22:28:00.464Z,1427408880.464 [WetLabsBB2FL](INFO): Powering down
2015-03-26T22:28:00.491Z,1427408880.491 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-03-26T22:28:00.502Z,1427408880.502 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8291
2015-03-26T22:28:00.509Z,1427408880.509 [Radio_Surface](INFO): Powering up
2015-03-26T22:28:00.519Z,1427408880.519 [MissionManager](DEBUG):
2015-03-26T22:28:00.519Z,1427408880.519 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-03-26T22:28:00.521Z,1427408880.521 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8292
2015-03-26T22:28:00.535Z,1427408880.535 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-03-26T22:28:00.537Z,1427408880.537 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-03-26T22:28:00.538Z,1427408880.538 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-03-26T22:28:00.538Z,1427408880.538 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-03-26T22:28:00.538Z,1427408880.538 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-03-26T22:28:00.539Z,1427408880.539 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-03-26T22:28:00.539Z,1427408880.539 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-03-26T22:28:00.539Z,1427408880.539 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-03-26T22:28:00.539Z,1427408880.539 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-03-26T22:28:00.632Z,1427408880.632 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-03-26T22:28:00.643Z,1427408880.643 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-03-26T22:28:00.652Z,1427408880.652 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-03-26T22:28:00.681Z,1427408880.681 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-03-26T22:28:00.713Z,1427408880.713 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-03-26T22:28:00.733Z,1427408880.733 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-03-26T22:28:00.767Z,1427408880.767 [MissionManager](DEBUG):
0
0
5.0
1.0
400
Burn 300
Dropped drop weight due to communications timeout
5.0
Default mission has been running for
5
2015-03-26T22:28:00.779Z,1427408880.779 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ISUS,PAR_Licor,AHRS_sp3003D,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-03-26T22:28:00.871Z,1427408880.871 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout
2015-03-26T22:28:00.871Z,1427408880.871 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.435677
2015-03-26T22:28:00.989Z,1427408880.989 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-03-26T22:28:01.034Z,1427408881.034 [Depth_Keller](ERROR): Pressure reading out of range: 915.616455 decibar
2015-03-26T22:28:01.095Z,1427408881.095 [DVL_micro](INFO): Initializing
2015-03-26T22:28:01.266Z,1427408881.266 [DepthRateCalculator](ERROR): Depth measurement is not active
2015-03-26T22:28:01.336Z,1427408881.336 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-03-26T22:28:01.460Z,1427408881.460 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:01.468Z,1427408881.468 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-03-26T22:28:01.482Z,1427408881.482 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:01.488Z,1427408881.488 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-03-26T22:28:01.502Z,1427408881.502 [MassServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:01.516Z,1427408881.516 [MassServo](DEBUG): Initializing MassServo.
2015-03-26T22:28:01.537Z,1427408881.537 [RudderServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:01.544Z,1427408881.544 [RudderServo](DEBUG): Initializing RudderServo.
2015-03-26T22:28:01.557Z,1427408881.557 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:01.564Z,1427408881.564 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-03-26T22:28:01.608Z,1427408881.608 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-03-26T22:28:02.168Z,1427408882.168 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-03-26T22:28:02.517Z,1427408882.517 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2015-03-26T22:28:02.517Z,1427408882.517 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2015-03-26T22:28:02.517Z,1427408882.517 [BuoyancyServo] Communications Fault, FailCount= 1
2015-03-26T22:28:02.517Z,1427408882.517 [BuoyancyServo](ERROR): Communications Fault
2015-03-26T22:28:02.829Z,1427408882.829 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout
2015-03-26T22:28:02.830Z,1427408882.830 [ElevatorServo](FAULT): Elevator failed to initialize
2015-03-26T22:28:02.830Z,1427408882.830 [ElevatorServo] Communications Fault, FailCount= 1
2015-03-26T22:28:02.830Z,1427408882.830 [ElevatorServo](ERROR): Communications Fault
2015-03-26T22:28:03.138Z,1427408883.138 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2015-03-26T22:28:03.138Z,1427408883.138 [RudderServo](FAULT): Rudder failed to initialize
2015-03-26T22:28:03.138Z,1427408883.138 [RudderServo] Communications Fault, FailCount= 1
2015-03-26T22:28:03.138Z,1427408883.138 [RudderServo](ERROR): Communications Fault
2015-03-26T22:28:03.451Z,1427408883.451 [ThrusterServo](ERROR): Thruster halt for initialization uart error serial timeout
2015-03-26T22:28:03.763Z,1427408883.763 [ThrusterServo](ERROR): Thruster initialization uart error serial timeout
2015-03-26T22:28:03.763Z,1427408883.763 [ThrusterServo](FAULT): Thruster failed to initialize
2015-03-26T22:28:03.763Z,1427408883.763 [ThrusterServo] Communications Fault, FailCount= 1
2015-03-26T22:28:03.763Z,1427408883.763 [ThrusterServo](ERROR): Communications Fault
2015-03-26T22:28:04.119Z,1427408884.119 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2015-03-26T22:28:04.120Z,1427408884.120 [AHRS_sp3003D](FAULT): SP3003D failed to initialize
2015-03-26T22:28:04.120Z,1427408884.120 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2015-03-26T22:28:04.120Z,1427408884.120 [AHRS_sp3003D](ERROR): Hardware Fault
2015-03-26T22:28:04.126Z,1427408884.126 [NAL9602](INFO): Powering up NAL9602
2015-03-26T22:28:04.163Z,1427408884.163 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-03-26T22:28:04.185Z,1427408884.185 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-03-26T22:28:04.186Z,1427408884.186 [BuoyancyServo](INFO): Powering down
2015-03-26T22:28:04.272Z,1427408884.272 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-03-26T22:28:04.272Z,1427408884.272 [ElevatorServo](INFO): Powering down
2015-03-26T22:28:04.632Z,1427408884.632 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout
2015-03-26T22:28:04.633Z,1427408884.633 [MassServo] Communications Fault, FailCount= 1
2015-03-26T22:28:04.633Z,1427408884.633 [MassServo](ERROR): Communications Fault
2015-03-26T22:28:04.633Z,1427408884.633 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-03-26T22:28:04.633Z,1427408884.633 [RudderServo](INFO): Powering down
2015-03-26T22:28:04.666Z,1427408884.666 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-03-26T22:28:04.666Z,1427408884.666 [ThrusterServo](INFO): Powering down
2015-03-26T22:28:04.742Z,1427408884.742 [AHRS_sp3003D](INFO): Powering down
2015-03-26T22:28:05.101Z,1427408885.101 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-03-26T22:28:05.124Z,1427408885.124 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-03-26T22:28:05.124Z,1427408885.124 [MassServo](INFO): Powering down
2015-03-26T22:28:05.305Z,1427408885.305 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-03-26T22:28:05.320Z,1427408885.320 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:05.441Z,1427408885.441 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-03-26T22:28:05.443Z,1427408885.443 [RudderServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:05.563Z,1427408885.563 [RudderServo](DEBUG): Initializing RudderServo.
2015-03-26T22:28:05.742Z,1427408885.742 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-03-26T22:28:05.765Z,1427408885.765 [MassServo](DEBUG): Initializing EZServoServo.
2015-03-26T22:28:05.883Z,1427408885.883 [MassServo](DEBUG): Initializing MassServo.
2015-03-26T22:28:10.889Z,1427408890.889 [Aanderaa_O2](FAULT): Timed out starting
2015-03-26T22:28:10.890Z,1427408890.890 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-03-26T22:28:10.890Z,1427408890.890 [Aanderaa_O2](ERROR): Communications Fault
2015-03-26T22:28:11.411Z,1427408891.411 [Aanderaa_O2](INFO): Powering down
2015-03-26T22:28:12.498Z,1427408892.498 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-03-26T22:28:12.498Z,1427408892.498 [DVL_micro] Communications Fault, FailCount= 1
2015-03-26T22:28:12.498Z,1427408892.498 [DVL_micro](ERROR): Communications Fault
2015-03-26T22:28:12.997Z,1427408892.997 [DVL_micro](INFO): uninitialize:Powering down
2015-03-26T22:28:13.300Z,1427408893.300 [DVL_micro](DEBUG): LCB error: Software Overcurrent. Current Limiter Activated.
2015-03-26T22:28:16.164Z,1427408896.164 [SBIT](IMPORTANT): Beginning Startup BIT
2015-03-26T22:28:25.298Z,1427408905.298 [NAL9602](ERROR): NAL9602 initialization error.
2015-03-26T22:28:25.298Z,1427408905.298 [NAL9602] Communications Fault, FailCount= 1
2015-03-26T22:28:25.299Z,1427408905.299 [NAL9602](ERROR): Communications Fault
2015-03-26T22:28:25.695Z,1427408905.695 [NAL9602](INFO): Powering down
2015-03-26T22:28:29.364Z,1427408909.364 [SBIT](ERROR): Could not read elevatorAngleReader_.
2015-03-26T22:28:29.365Z,1427408909.365 [SBIT](ERROR): Could not read rudderAngleReader_.
2015-03-26T22:28:29.365Z,1427408909.365 [SBIT](ERROR): Could not read massPosReader_.
2015-03-26T22:28:56.124Z,1427408936.124 [SBIT](ERROR): Could not read elevatorAngleReader_.
2015-03-26T22:28:56.124Z,1427408936.124 [SBIT](ERROR): Could not read rudderAngleReader_.
2015-03-26T22:28:56.124Z,1427408936.124 [SBIT](ERROR): Could not read massPosReader_.
2015-03-26T22:28:56.124Z,1427408936.124 [SBIT](FAULT): Control surface position failure.
2015-03-26T22:29:09.722Z,1427408949.722 [SBIT](ERROR): Could not read elevatorAngleReader_.
2015-03-26T22:29:09.722Z,1427408949.722 [SBIT](ERROR): Could not read rudderAngleReader_.
2015-03-26T22:29:09.722Z,1427408949.722 [SBIT](ERROR): Could not read massPosReader_.
2015-03-26T22:29:09.722Z,1427408949.722 [SBIT](FAULT): Control surface position failure.
2015-03-26T22:29:10.122Z,1427408950.122 [SBIT](CRITICAL): SBIT FAILED
2015-03-26T22:29:10.547Z,1427408950.547 [MissionManager](IMPORTANT): Started mission Startup
2015-03-26T22:29:10.548Z,1427408950.548 [Startup] Running Loop=1
2015-03-26T22:29:10.548Z,1427408950.548 [Startup](INFO): Aggregate::initialize Startup
2015-03-26T22:29:10.548Z,1427408950.548 [Startup:A.GoToSurface] Running Loop=1
2015-03-26T22:29:10.548Z,1427408950.548 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-03-26T22:29:10.549Z,1427408950.549 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-03-26T22:29:10.549Z,1427408950.549 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-03-26T22:29:10.549Z,1427408950.549 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-03-26T22:29:10.588Z,1427408950.588 [Startup:StartupSatComms] Running Loop=1
2015-03-26T22:29:10.589Z,1427408950.589 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-03-26T22:29:10.589Z,1427408950.589 [Startup:StartupSatComms:A] Running Loop=1
2015-03-26T22:29:10.919Z,1427408950.919 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-03-26T22:29:15.698Z,1427408955.698 [BPC1](ERROR): Failed to receive battery data
2015-03-26T22:29:15.699Z,1427408955.699 [BPC1] Communications Fault, FailCount= 1
2015-03-26T22:29:15.699Z,1427408955.699 [BPC1](ERROR): Communications Fault
2015-03-26T22:30:10.919Z,1427409010.919 [Startup:StartupSatComms:A](INFO): Timed out from 2015-03-26T22:29:10.6Z
2015-03-26T22:30:10.919Z,1427409010.919 [Startup:StartupSatComms:A] Stopped
2015-03-26T22:30:10.919Z,1427409010.919 [Startup:StartupSatComms:B] Running Loop=1
2015-03-26T22:30:11.315Z,1427409011.315 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-03-26T22:31:00.513Z,1427409060.513 [DeadReckonUsingMultipleVelocitySources](FAULT): The allowance for input measurements to start up has expired, but I still cannot determine the rotation from vehicle frame to navigation frame.
2015-03-26T22:31:00.513Z,1427409060.513 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-03-26T22:31:00.513Z,1427409060.513 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-03-26T22:31:00.515Z,1427409060.515 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-03-26T22:31:00.516Z,1427409060.516 [DeadReckonUsingSpeedCalculator](FAULT): The allowance for input measurements to start up has expired, but I still cannot determine the rotation from vehicle frame to navigation frame.
2015-03-26T22:31:00.516Z,1427409060.516 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2015-03-26T22:31:00.516Z,1427409060.516 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-03-26T22:31:00.517Z,1427409060.517 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-03-26T22:31:11.315Z,1427409071.315 [Startup:StartupSatComms:B](INFO): Timed out from 2015-03-26T22:30:10.9Z
2015-03-26T22:31:11.315Z,1427409071.315 [Star