2017-04-25T20:18:09.850Z,1493151489.849 [Supervisor](DEBUG): Initializing supervisor.
2017-04-25T20:18:09.854Z,1493151489.854 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0
2017-04-25T20:18:09.854Z,1493151489.855 [SyncHandler](INFO): Protected caller Thread ID is 769
2017-04-25T20:18:09.855Z,1493151489.855 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2017-04-25T20:18:09.858Z,1493151489.858 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0
2017-04-25T20:18:09.858Z,1493151489.858 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 770
2017-04-25T20:18:09.861Z,1493151489.861 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2017-04-25T20:18:09.874Z,1493151489.874 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2017-04-25T20:18:09.878Z,1493151489.878 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0
2017-04-25T20:18:09.878Z,1493151489.878 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 771
2017-04-25T20:18:09.879Z,1493151489.879 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2017-04-25T20:18:09.882Z,1493151489.882 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0
2017-04-25T20:18:09.882Z,1493151489.882 [logger ThreadHandler](INFO): Protected caller Thread ID is 772
2017-04-25T20:18:09.884Z,1493151489.884 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2017-04-25T20:18:09.885Z,1493151489.885 [Supervisor](INFO): Looking for Config files in directory: Config/
2017-04-25T20:18:09.889Z,1493151489.889 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2017-04-25T20:18:09.987Z,1493151489.987 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2017-04-25T20:18:10.391Z,1493151490.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2017-04-25T20:18:10.393Z,1493151490.393 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2017-04-25T20:18:10.554Z,1493151490.554 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2017-04-25T20:18:10.555Z,1493151490.555 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2017-04-25T20:18:10.795Z,1493151490.795 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2017-04-25T20:18:10.795Z,1493151490.795 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2017-04-25T20:18:10.906Z,1493151490.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2017-04-25T20:18:10.907Z,1493151490.907 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2017-04-25T20:18:11.142Z,1493151491.142 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2017-04-25T20:18:11.145Z,1493151491.145 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2017-04-25T20:18:11.727Z,1493151491.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2017-04-25T20:18:11.728Z,1493151491.728 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2017-04-25T20:18:12.081Z,1493151492.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2017-04-25T20:18:12.082Z,1493151492.082 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2017-04-25T20:18:12.373Z,1493151492.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2017-04-25T20:18:12.374Z,1493151492.374 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2017-04-25T20:18:16.558Z,1493151496.559 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2017-04-25T20:18:16.559Z,1493151496.559 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2017-04-25T20:18:16.803Z,1493151496.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2017-04-25T20:18:16.803Z,1493151496.803 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2017-04-25T20:18:17.340Z,1493151497.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2017-04-25T20:18:17.341Z,1493151497.341 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2017-04-25T20:18:20.663Z,1493151500.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2017-04-25T20:18:20.664Z,1493151500.664 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2017-04-25T20:18:21.043Z,1493151501.043 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2017-04-25T20:18:21.043Z,1493151501.043 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2017-04-25T20:18:21.174Z,1493151501.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2017-04-25T20:18:21.176Z,1493151501.176 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2017-04-25T20:18:21.181Z,1493151501.181 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2017-04-25T20:18:21.298Z,1493151501.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2017-04-25T20:18:21.407Z,1493151501.407 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2017-04-25T20:18:21.507Z,1493151501.507 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2017-04-25T20:18:21.626Z,1493151501.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2017-04-25T20:18:21.730Z,1493151501.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2017-04-25T20:18:21.883Z,1493151501.883 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2017-04-25T20:18:21.995Z,1493151501.995 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2017-04-25T20:18:22.215Z,1493151502.215 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2017-04-25T20:18:22.509Z,1493151502.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2017-04-25T20:18:22.510Z,1493151502.510 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2017-04-25T20:18:24.190Z,1493151504.190 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2017-04-25T20:18:25.329Z,1493151505.329 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2017-04-25T20:18:25.411Z,1493151505.411 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2017-04-25T20:18:25.415Z,1493151505.415 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2017-04-25T20:18:25.497Z,1493151505.497 [VerticalControl](DEBUG): Construct VerticalControl.
2017-04-25T20:18:25.630Z,1493151505.630 [VerticalControl] Loaded
2017-04-25T20:18:25.630Z,1493151505.630 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2017-04-25T20:18:25.631Z,1493151505.631 [HorizontalControl](DEBUG): Construct HorizontalControl.
2017-04-25T20:18:25.710Z,1493151505.710 [HorizontalControl] Loaded
2017-04-25T20:18:25.711Z,1493151505.711 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2017-04-25T20:18:25.711Z,1493151505.711 [SpeedControl](DEBUG): Construct SpeedControl.
2017-04-25T20:18:25.718Z,1493151505.718 [SpeedControl] Loaded
2017-04-25T20:18:25.718Z,1493151505.718 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2017-04-25T20:18:25.719Z,1493151505.719 [LoopControl](DEBUG): Construct LoopControl.
2017-04-25T20:18:25.719Z,1493151505.719 [LoopControl] Loaded
2017-04-25T20:18:25.720Z,1493151505.720 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2017-04-25T20:18:25.720Z,1493151505.720 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2017-04-25T20:18:25.721Z,1493151505.721 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2017-04-25T20:18:25.905Z,1493151505.905 [SBIT](DEBUG): Construct Startup Built In Test.
2017-04-25T20:18:25.917Z,1493151505.917 [SBIT] Loaded
2017-04-25T20:18:25.918Z,1493151505.918 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2017-04-25T20:18:25.919Z,1493151505.918 [IBIT](DEBUG): Construct Initiated Built In Test.
2017-04-25T20:18:25.950Z,1493151505.950 [IBIT] Loaded
2017-04-25T20:18:25.951Z,1493151505.951 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2017-04-25T20:18:25.955Z,1493151505.954 [CBIT](DEBUG): Construct Continuous Built In Test.
2017-04-25T20:18:26.121Z,1493151506.121 [CBIT] Loaded
2017-04-25T20:18:26.122Z,1493151506.122 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2017-04-25T20:18:26.122Z,1493151506.122 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2017-04-25T20:18:26.123Z,1493151506.123 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2017-04-25T20:18:26.167Z,1493151506.167 [DepthRateCalculator] Loaded
2017-04-25T20:18:26.167Z,1493151506.167 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2017-04-25T20:18:26.174Z,1493151506.174 [PitchRateCalculator] Loaded
2017-04-25T20:18:26.174Z,1493151506.174 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2017-04-25T20:18:26.186Z,1493151506.187 [SpeedCalculator] Loaded
2017-04-25T20:18:26.187Z,1493151506.187 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2017-04-25T20:18:26.212Z,1493151506.211 [TempGradientCalculator] Loaded
2017-04-25T20:18:26.212Z,1493151506.212 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2017-04-25T20:18:26.230Z,1493151506.230 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2017-04-25T20:18:26.230Z,1493151506.230 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2017-04-25T20:18:26.236Z,1493151506.236 [YawRateCalculator] Loaded
2017-04-25T20:18:26.236Z,1493151506.236 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2017-04-25T20:18:26.237Z,1493151506.237 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2017-04-25T20:18:26.237Z,1493151506.237 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2017-04-25T20:18:26.373Z,1493151506.373 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2017-04-25T20:18:26.373Z,1493151506.373 [StratificationFrontDetector](DEBUG): (re)initializing
2017-04-25T20:18:26.373Z,1493151506.373 [StratificationFrontDetector] Loaded
2017-04-25T20:18:26.374Z,1493151506.374 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2017-04-25T20:18:26.400Z,1493151506.400 [DepAvgTempFrontDetector] Loaded
2017-04-25T20:18:26.401Z,1493151506.401 [ComponentRegistry](DEBUG): SyncComponent "DepAvgTempFrontDetector" handled in the control thread.
2017-04-25T20:18:26.401Z,1493151506.401 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2017-04-25T20:18:26.402Z,1493151506.402 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2017-04-25T20:18:26.725Z,1493151506.725 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2017-04-25T20:18:26.726Z,1493151506.726 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2017-04-25T20:18:26.860Z,1493151506.860 [DeadReckonUsingMultipleVelocitySources] Loaded
2017-04-25T20:18:26.860Z,1493151506.861 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2017-04-25T20:18:26.922Z,1493151506.922 [DeadReckonUsingSpeedCalculator] Loaded
2017-04-25T20:18:26.923Z,1493151506.923 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2017-04-25T20:18:26.942Z,1493151506.941 [NavChart] Loaded
2017-04-25T20:18:26.942Z,1493151506.942 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2017-04-25T20:18:26.946Z,1493151506.946 [UniversalFixResidualReporter] Loaded
2017-04-25T20:18:26.947Z,1493151506.947 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2017-04-25T20:18:26.947Z,1493151506.947 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2017-04-25T20:18:26.948Z,1493151506.948 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2017-04-25T20:18:26.957Z,1493151506.957 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2017-04-25T20:18:26.958Z,1493151506.958 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2017-04-25T20:18:27.175Z,1493151507.175 [Aanderaa_O2] Loaded
2017-04-25T20:18:27.176Z,1493151507.175 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2017-04-25T20:18:27.266Z,1493151507.266 [CTD_NeilBrown] Loaded
2017-04-25T20:18:27.266Z,1493151507.266 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2017-04-25T20:18:27.268Z,1493151507.267 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407734E0
2017-04-25T20:18:27.268Z,1493151507.268 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 855
2017-04-25T20:18:27.603Z,1493151507.603 [CTD_Seabird] Loaded
2017-04-25T20:18:27.603Z,1493151507.603 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2017-04-25T20:18:27.604Z,1493151507.604 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 407A34E0
2017-04-25T20:18:27.605Z,1493151507.605 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 856
2017-04-25T20:18:27.622Z,1493151507.622 [PAR_Licor] Loaded
2017-04-25T20:18:27.622Z,1493151507.622 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2017-04-25T20:18:27.702Z,1493151507.702 [WetLabsBB2FL] Loaded
2017-04-25T20:18:27.702Z,1493151507.702 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2017-04-25T20:18:27.703Z,1493151507.703 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407D34E0
2017-04-25T20:18:27.704Z,1493151507.704 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 857
2017-04-25T20:18:27.704Z,1493151507.704 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2017-04-25T20:18:27.758Z,1493151507.758 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2017-04-25T20:18:28.431Z,1493151508.431 [DataOverHttps] Loaded
2017-04-25T20:18:28.431Z,1493151508.431 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2017-04-25T20:18:28.447Z,1493151508.447 [Depth_Keller] Loaded
2017-04-25T20:18:28.447Z,1493151508.447 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2017-04-25T20:18:28.452Z,1493151508.452 [DropWeight] Loaded
2017-04-25T20:18:28.453Z,1493151508.453 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2017-04-25T20:18:28.557Z,1493151508.557 [NAL9602] Loaded
2017-04-25T20:18:28.558Z,1493151508.558 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2017-04-25T20:18:28.568Z,1493151508.568 [Onboard] Loaded
2017-04-25T20:18:28.568Z,1493151508.568 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2017-04-25T20:18:28.576Z,1493151508.576 [Radio_Surface] Loaded
2017-04-25T20:18:28.576Z,1493151508.576 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2017-04-25T20:18:28.578Z,1493151508.578 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1E4E0
2017-04-25T20:18:28.578Z,1493151508.578 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 858
2017-04-25T20:18:28.778Z,1493151508.778 [PNI_TCM] Loaded
2017-04-25T20:18:28.778Z,1493151508.778 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2017-04-25T20:18:28.849Z,1493151508.849 [Rowe_600LCM] Loaded
2017-04-25T20:18:28.850Z,1493151508.849 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2017-04-25T20:18:28.851Z,1493151508.851 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A4E4E0
2017-04-25T20:18:28.851Z,1493151508.851 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 859
2017-04-25T20:18:30.901Z,1493151510.901 [BPC1] Loaded
2017-04-25T20:18:30.902Z,1493151510.902 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2017-04-25T20:18:30.902Z,1493151510.902 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2017-04-25T20:18:30.903Z,1493151510.903 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2017-04-25T20:18:31.043Z,1493151511.043 [BuoyancyServo] Loaded
2017-04-25T20:18:31.043Z,1493151511.043 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2017-04-25T20:18:31.056Z,1493151511.056 [ElevatorServo] Loaded
2017-04-25T20:18:31.056Z,1493151511.056 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2017-04-25T20:18:31.069Z,1493151511.069 [MassServo] Loaded
2017-04-25T20:18:31.069Z,1493151511.069 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2017-04-25T20:18:31.082Z,1493151511.082 [RudderServo] Loaded
2017-04-25T20:18:31.083Z,1493151511.083 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2017-04-25T20:18:31.095Z,1493151511.095 [ThrusterServo] Loaded
2017-04-25T20:18:31.095Z,1493151511.095 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2017-04-25T20:18:31.096Z,1493151511.096 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2017-04-25T20:18:31.096Z,1493151511.096 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2017-04-25T20:18:31.248Z,1493151511.248 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2017-04-25T20:18:31.249Z,1493151511.249 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2017-04-25T20:18:31.293Z,1493151511.293 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2017-04-25T20:18:31.296Z,1493151511.296 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2017-04-25T20:18:31.297Z,1493151511.297 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2017-04-25T20:18:31.304Z,1493151511.304 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2017-04-25T20:18:31.306Z,1493151511.306 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFC4E0
2017-04-25T20:18:31.306Z,1493151511.306 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 860
2017-04-25T20:18:31.311Z,1493151511.311 [Supervisor](INFO): Main Thread ID is 765
2017-04-25T20:18:31.311Z,1493151511.311 [Supervisor](DEBUG): Running supervisor.
2017-04-25T20:18:31.312Z,1493151511.312 [CommandLine ThreadHandler](INFO): Handler Thread ID is 861
2017-04-25T20:18:31.314Z,1493151511.314 [controlThread ThreadHandler](INFO): Handler Thread ID is 862
2017-04-25T20:18:31.315Z,1493151511.315 [controlThread](DEBUG): Initializing ControlThread
2017-04-25T20:18:31.316Z,1493151511.316 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2017-04-25T20:18:31.317Z,1493151511.318 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2017-04-25T20:18:31.318Z,1493151511.318 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2017-04-25T20:18:31.319Z,1493151511.319 [LoopControl](DEBUG): Initialize LoopControlComponent.
2017-04-25T20:18:31.319Z,1493151511.319 [SBIT](INFO): Initialize SBIT Component.
2017-04-25T20:18:31.320Z,1493151511.320 [SBIT](IMPORTANT): git: 2017-04-19-5-g443ab08
2017-04-25T20:18:31.320Z,1493151511.320 [SBIT](INFO): git hash: 443ab0852958b11c27b2467e632b948d2f0b0b23
2017-04-25T20:18:31.322Z,1493151511.322 [SBIT](INFO): Kernel Reporting Different Release From Configuration.
Kernel Expected: 2.6.27.8
Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty
2017-04-25T20:18:31.322Z,1493151511.322 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016
2017-04-25T20:18:31.323Z,1493151511.323 [SBIT](INFO): Beginning SBIT in 32.000000 seconds.
2017-04-25T20:18:31.324Z,1493151511.323 [IBIT](INFO): Initialize IBIT Component.
2017-04-25T20:18:31.324Z,1493151511.324 [CBIT](DEBUG): Initialize CBIT Component.
2017-04-25T20:18:31.325Z,1493151511.325 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2017-04-25T20:18:31.325Z,1493151511.325 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2017-04-25T20:18:31.326Z,1493151511.326 [logger ThreadHandler](INFO): Handler Thread ID is 863
2017-04-25T20:18:31.355Z,1493151511.355 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 864
2017-04-25T20:18:31.356Z,1493151511.355 [CTD_NeilBrown](INFO): Powering down
2017-04-25T20:18:31.382Z,1493151511.382 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 865
2017-04-25T20:18:31.383Z,1493151511.383 [CTD_Seabird](INFO): Initializing
2017-04-25T20:18:31.426Z,1493151511.426 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-04-25T20:18:31.427Z,1493151511.427 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2017-04-25T20:18:31.427Z,1493151511.427 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2017-04-25T20:18:31.428Z,1493151511.428 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2017-04-25T20:18:31.429Z,1493151511.429 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2017-04-25T20:18:31.430Z,1493151511.430 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2017-04-25T20:18:31.431Z,1493151511.431 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-25T20:18:31.432Z,1493151511.432 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-25T20:18:31.432Z,1493151511.432 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-25T20:18:31.433Z,1493151511.433 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-04-25T20:18:31.433Z,1493151511.433 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-04-25T20:18:31.434Z,1493151511.434 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-04-25T20:18:31.434Z,1493151511.434 [NavChart](DEBUG): Initialize NavChart Navigation.
2017-04-25T20:18:31.435Z,1493151511.435 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2017-04-25T20:18:31.450Z,1493151511.450 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 867
2017-04-25T20:18:31.452Z,1493151511.452 [WetLabsBB2FL](INFO): Powering down
2017-04-25T20:18:31.478Z,1493151511.478 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2017-04-25T20:18:31.491Z,1493151511.491 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 868
2017-04-25T20:18:31.499Z,1493151511.499 [Radio_Surface](INFO): Powering up
2017-04-25T20:18:31.500Z,1493151511.500 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 869
2017-04-25T20:18:31.501Z,1493151511.501 [Rowe_600LCM](INFO): Initializing
2017-04-25T20:18:31.502Z,1493151511.502 [Rowe_600LCM](INFO): Checking LCM
2017-04-25T20:18:31.502Z,1493151511.502 [Rowe_600LCM](INFO): LCM OK
2017-04-25T20:18:31.502Z,1493151511.503 [Rowe_600LCM](INFO): Powering up
2017-04-25T20:18:31.504Z,1493151511.504 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 870
2017-04-25T20:18:31.524Z,1493151511.523 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2017-04-25T20:18:31.524Z,1493151511.524 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2017-04-25T20:18:31.524Z,1493151511.524 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2017-04-25T20:18:31.524Z,1493151511.524 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2017-04-25T20:18:31.524Z,1493151511.524 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2017-04-25T20:18:31.525Z,1493151511.524 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2017-04-25T20:18:31.525Z,1493151511.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2017-04-25T20:18:31.525Z,1493151511.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2017-04-25T20:18:31.525Z,1493151511.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2017-04-25T20:18:31.525Z,1493151511.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2017-04-25T20:18:31.525Z,1493151511.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2017-04-25T20:18:31.526Z,1493151511.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2017-04-25T20:18:31.526Z,1493151511.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2017-04-25T20:18:31.526Z,1493151511.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2017-04-25T20:18:31.527Z,1493151511.527 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2017-04-25T20:18:31.527Z,1493151511.527 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2017-04-25T20:18:31.556Z,1493151511.556 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2017-04-25T20:18:31.586Z,1493151511.586 [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>


2017-04-25T20:18:31.587Z,1493151511.587 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2017-04-25T20:18:31.680Z,1493151511.680 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2017-04-25T20:18:31.681Z,1493151511.681 [Default:A.Wait](DEBUG): Construct Wait.
2017-04-25T20:18:31.704Z,1493151511.704 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-04-25T20:18:31.704Z,1493151511.704 [CTD_Seabird](INFO): Powering down
2017-04-25T20:18:31.727Z,1493151511.727 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2017-04-25T20:18:31.753Z,1493151511.753 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2017-04-25T20:18:31.756Z,1493151511.756 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2017-04-25T20:18:31.778Z,1493151511.778 [Default:E.Execute](DEBUG): Construct Execute.
2017-04-25T20:18:31.781Z,1493151511.781 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
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/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="Default">

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

    <Guidance:Wait>
        <Sequence/>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <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">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</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>


2017-04-25T20:18:31.799Z,1493151511.799 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DepAvgTempFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2017-04-25T20:18:31.959Z,1493151511.958 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2017-04-25T20:18:31.971Z,1493151511.971 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2017-04-25T20:18:32.206Z,1493151512.206 [DepthRateCalculator](ERROR): Depth measurement is not active
2017-04-25T20:18:32.323Z,1493151512.323 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:32.550Z,1493151512.550 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:32.656Z,1493151512.657 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-04-25T20:18:32.662Z,1493151512.662 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-04-25T20:18:32.681Z,1493151512.681 [ElevatorServo](DEBUG): Initializing EZServoServo.
2017-04-25T20:18:32.687Z,1493151512.687 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2017-04-25T20:18:32.709Z,1493151512.709 [MassServo](DEBUG): Initializing EZServoServo.
2017-04-25T20:18:32.726Z,1493151512.726 [MassServo](DEBUG): Initializing MassServo.
2017-04-25T20:18:32.732Z,1493151512.732 [RudderServo](DEBUG): Initializing EZServoServo.
2017-04-25T20:18:32.738Z,1493151512.738 [RudderServo](DEBUG): Initializing RudderServo.
2017-04-25T20:18:32.752Z,1493151512.752 [ThrusterServo](DEBUG): Initializing EZServoServo.
2017-04-25T20:18:32.758Z,1493151512.758 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2017-04-25T20:18:32.795Z,1493151512.795 [CommandLine](FAULT): Scheduling is paused
2017-04-25T20:18:32.795Z,1493151512.795 [CBIT](INFO): Critical error at 20170425T201831
2017-04-25T20:18:32.796Z,1493151512.796 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2017-04-25T20:18:33.100Z,1493151513.100 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:33.110Z,1493151513.110 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:33.280Z,1493151513.280 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:33.281Z,1493151513.281 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:33.630Z,1493151513.630 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2017-04-25T20:18:33.630Z,1493151513.630 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2017-04-25T20:18:33.630Z,1493151513.630 [BuoyancyServo] Communications Fault, FailCount= 1
2017-04-25T20:18:33.630Z,1493151513.630 [BuoyancyServo](ERROR): Communications Fault
2017-04-25T20:18:33.841Z,1493151513.841 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2017-04-25T20:18:33.872Z,1493151513.872 [NAL9602](INFO): Powering up NAL9602
2017-04-25T20:18:33.950Z,1493151513.950 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:33.951Z,1493151513.951 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:33.964Z,1493151513.964 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-04-25T20:18:33.965Z,1493151513.965 [BuoyancyServo](INFO): Powering down
2017-04-25T20:18:34.307Z,1493151514.307 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:34.308Z,1493151514.308 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:34.702Z,1493151514.702 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:34.703Z,1493151514.703 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:35.170Z,1493151515.170 [Aanderaa_O2](INFO): Powering down
2017-04-25T20:18:35.290Z,1493151515.290 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:35.291Z,1493151515.291 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:35.498Z,1493151515.498 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:35.499Z,1493151515.499 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-25T20:18:35.788Z,1493151515.788 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-04-25T20:18:35.945Z,1493151515.945 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-04-25T20:18:36.490Z,1493151516.490 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2017-04-25T20:18:36.490Z,1493151516.490 [BuoyancyServo] No Fault, FailCount= 1
2017-04-25T20:18:36.816Z,1493151516.816 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-04-25T20:18:36.817Z,1493151516.817 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-04-25T20:18:36.818Z,1493151516.818 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-04-25T20:18:36.829Z,1493151516.829 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-04-25T20:18:36.834Z,1493151516.834 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-04-25T20:18:37.157Z,1493151517.157 [Radio_Surface](INFO): Powering down
2017-04-25T20:18:37.682Z,1493151517.682 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2017-04-25T20:18:37.682Z,1493151517.682 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2017-04-25T20:18:37.682Z,1493151517.682 [BuoyancyServo] Communications Fault, FailCount= 2
2017-04-25T20:18:37.682Z,1493151517.682 [BuoyancyServo](ERROR): Communications Fault
2017-04-25T20:18:37.715Z,1493151517.715 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2017-04-25T20:18:37.844Z,1493151517.844 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-04-25T20:18:37.845Z,1493151517.845 [BuoyancyServo](INFO): Powering down
2017-04-25T20:18:39.850Z,1493151519.850 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2017-04-25T20:18:39.850Z,1493151519.850 [BuoyancyServo] No Fault, FailCount= 2
2017-04-25T20:18:40.222Z,1493151520.222 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-04-25T20:18:40.223Z,1493151520.223 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-04-25T20:18:44.932Z,1493151524.932 [NAL9602](INFO): NAL9602 initialized
2017-04-25T20:19:03.818Z,1493151543.818 [SBIT](IMPORTANT): Beginning Startup BIT
2017-04-25T20:19:03.830Z,1493151543.830 [CBIT](IMPORTANT): Beginning ground fault scan
2017-04-25T20:19:14.324Z,1493151554.324 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): 0.027061
CHAN A2 (12V): -0.005976
CHAN A3 (5V): -0.000979
CHAN B0 (3.3V): 4.766929
CHAN B1 (3.15aV): 0.002277
CHAN B2 (3.15bV): -0.001152
CHAN B3 (GND): 0.000877
OPEN: -0.001165
Full Scale Calc: 4.765 mA, -1.589 mA
2017-04-25T20:19:17.861Z,1493151557.861 [PNI_TCM](ERROR): CRC does not match. Expected:0x45115 got:0x60580
2017-04-25T20:19:57.893Z,1493151597.893 [SBIT](IMPORTANT): SBIT PASSED
2017-04-25T20:19:58.247Z,1493151598.247 [MissionManager](IMPORTANT): Started mission Startup
2017-04-25T20:19:58.247Z,1493151598.247 [Startup] Running Loop=1
2017-04-25T20:19:58.247Z,1493151598.247 [Startup](DEBUG): Aggregate::initialize Startup
2017-04-25T20:19:58.247Z,1493151598.247 [Startup:A.GoToSurface] Running Loop=1
2017-04-25T20:19:58.247Z,1493151598.247 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-04-25T20:19:58.248Z,1493151598.248 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-04-25T20:19:58.248Z,1493151598.248 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-04-25T20:19:58.249Z,1493151598.249 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-04-25T20:19:58.249Z,1493151598.249 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-04-25T20:19:58.249Z,1493151598.249 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-04-25T20:19:58.255Z,1493151598.255 [Startup:StartupSatComms] Running Loop=1
2017-04-25T20:19:58.255Z,1493151598.256 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2017-04-25T20:19:58.256Z,1493151598.256 [Startup:StartupSatComms:A] Running Loop=1
2017-04-25T20:19:58.549Z,1493151598.549 [Radio_Surface](INFO): Powering up
2017-04-25T20:19:58.683Z,1493151598.683 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2017-04-25T20:20:10.668Z,1493151610.668 [BPC1](ERROR): Failed to parse bank A battery data
2017-04-25T20:20:10.668Z,1493151610.668 [BPC1] Data Fault, FailCount= 1
2017-04-25T20:20:10.668Z,1493151610.668 [BPC1](ERROR): Data Fault
2017-04-25T20:20:10.742Z,1493151610.742 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-25T20:20:11.858Z,1493151611.858 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-25T20:20:11.858Z,1493151611.858 [BPC1] No Fault, FailCount= 1
2017-04-25T20:20:52.233Z,1493151652.233 [BPC1](ERROR): Failed to parse bank A battery data
2017-04-25T20:20:52.233Z,1493151652.233 [BPC1] Data Fault, FailCount= 1
2017-04-25T20:20:52.233Z,1493151652.233 [BPC1](ERROR): Data Fault
2017-04-25T20:20:52.293Z,1493151652.293 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-25T20:20:53.448Z,1493151653.448 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-25T20:20:53.448Z,1493151653.448 [BPC1] No Fault, FailCount= 1
2017-04-25T20:20:58.263Z,1493151658.263 [Startup:StartupSatComms:A](INFO): Timed out from 2017-04-25T20:19:58.3Z
2017-04-25T20:20:58.263Z,1493151658.263 [Startup:StartupSatComms:A] Stopped
2017-04-25T20:20:58.263Z,1493151658.263 [Startup:StartupSatComms:B] Running Loop=1
2017-04-25T20:20:58.624Z,1493151658.624 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-04-25T20:21:26.985Z,1493151686.985 [NAL9602](INFO): SBD MO Status=0, MOMSN=63439, MT Status=0, MTMSN=0
2017-04-25T20:21:26.985Z,1493151686.985 [NAL9602](INFO): No messages in MT queue
2017-04-25T20:21:28.184Z,1493151688.184 [NAL9602](INFO): GPS fix at 20170425T202125: (36.802743, -121.788023)
2017-04-25T20:21:41.381Z,1493151701.381 [NAL9602](INFO): SBD MO Status=2, MOMSN=63440, MT Status=2, MTMSN=0
2017-04-25T20:21:41.381Z,1493151701.381 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-04-25T20:21:58.483Z,1493151718.483 [Startup:StartupSatComms:B](INFO): Timed out from 2017-04-25T20:20:58.3Z
2017-04-25T20:21:58.483Z,1493151718.483 [Startup:StartupSatComms:B] Stopped
2017-04-25T20:21:58.483Z,1493151718.483 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2017-04-25T20:21:58.483Z,1493151718.483 [Startup:StartupSatComms] Stopped
2017-04-25T20:21:58.483Z,1493151718.483 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2017-04-25T20:21:58.484Z,1493151718.484 [Startup](INFO): Completed Startup
2017-04-25T20:21:58.484Z,1493151718.484 [MissionManager](INFO): Startup is completed.
2017-04-25T20:21:58.485Z,1493151718.485 [MissionManager](INFO): Uninitializing Mission Startup
2017-04-25T20:21:58.485Z,1493151718.485 [Startup] Stopped
2017-04-25T20:21:58.485Z,1493151718.485 [Startup](DEBUG): Aggregate::uninitialize Startup
2017-04-25T20:21:58.485Z,1493151718.485 [Startup:A.GoToSurface] Stopped
2017-04-25T20:21:58.485Z,1493151718.485 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-04-25T20:21:58.837Z,1493151718.838 [MissionManager](IMPORTANT): Started mission Default
2017-04-25T20:21:58.838Z,1493151718.838 [Default] Running Loop=1
2017-04-25T20:21:58.839Z,1493151718.839 [Default](DEBUG): Aggregate::initialize Default
2017-04-25T20:21:58.839Z,1493151718.839 [Default:B.GoToSurface] Running Loop=1
2017-04-25T20:21:58.839Z,1493151718.839 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-04-25T20:21:58.839Z,1493151718.839 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-04-25T20:21:58.839Z,1493151718.839 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-04-25T20:21:58.840Z,1493151718.840 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-04-25T20:21:58.840Z,1493151718.840 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-04-25T20:21:58.840Z,1493151718.840 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-04-25T20:21:58.840Z,1493151718.841 [Default:A.Wait] Running Loop=1
2017-04-25T20:21:58.841Z,1493151718.841 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-04-25T20:22:06.393Z,1493151726.393 [NAL9602](INFO): SBD MO Status=2, MOMSN=63440, MT Status=2, MTMSN=0
2017-04-25T20:22:06.393Z,1493151726.393 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-04-25T20:22:11.943Z,1493151731.943 [NAL9602](INFO): Powering down
2017-04-25T20:22:12.015Z,1493151732.015 [Default:A.Wait](INFO): Done Waiting.
2017-04-25T20:22:12.015Z,1493151732.015 [Default:A.Wait] Stopped
2017-04-25T20:22:12.015Z,1493151732.015 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-04-25T20:22:12.455Z,1493151732.455 [Default:CheckIn] Running Loop=1
2017-04-25T20:22:12.455Z,1493151732.455 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-04-25T20:22:12.455Z,1493151732.455 [Default:CheckIn:Read_GPS] Running Loop=1
2017-04-25T20:22:15.859Z,1493151735.859 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2017-04-25T20:22:15.956Z,1493151735.956 [NAL9602](INFO): Powering up
2017-04-25T20:22:16.699Z,1493151736.699 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003500
2017-04-25T20:22:27.087Z,1493151747.087 [NAL9602](INFO): NAL9602 initialized
2017-04-25T20:22:46.263Z,1493151766.263 [CommandLine](IMPORTANT): got command failComponent
2017-04-25T20:22:46.263Z,1493151766.263 [CommandLine](IMPORTANT): Failed components:
2017-04-25T20:22:46.263Z,1493151766.263 [CommandLine](IMPORTANT): No failed Components.
2017-04-25T20:22:55.098Z,1493151775.098 [NAL9602](INFO): SBD MO Status=2, MOMSN=63440, MT Status=2, MTMSN=0
2017-04-25T20:22:55.098Z,1493151775.098 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-04-25T20:23:01.131Z,1493151781.131 [PNI_TCM](ERROR): CRC does not match. Expected:0x581 got:0x46619
2017-04-25T20:23:42.801Z,1493151822.801 [NAL9602](INFO): SBD MO Status=2, MOMSN=63440, MT Status=2, MTMSN=0
2017-04-25T20:23:42.802Z,1493151822.802 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-04-25T20:25:09.756Z,1493151909.756 [BPC1](ERROR): Failed to receive battery data
2017-04-25T20:25:09.757Z,1493151909.757 [BPC1] Communications Fault, FailCount= 1
2017-04-25T20:25:09.757Z,1493151909.757 [BPC1](ERROR): Communications Fault
2017-04-25T20:25:09.856Z,1493151909.856 [CBIT](ERROR): Communications Fault in component: BPC1
2017-04-25T20:25:10.814Z,1493151910.814 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-25T20:25:10.814Z,1493151910.814 [BPC1] No Fault, FailCount= 1
2017-04-25T20:25:40.343Z,1493151940.343 [PNI_TCM](ERROR): CRC does not match. Expected:0x56240 got:0x7361
2017-04-25T20:26:54.409Z,1493152014.409 [BPC1](ERROR): Failed to receive battery data
2017-04-25T20:26:54.409Z,1493152014.409 [BPC1] Communications Fault, FailCount= 1
2017-04-25T20:26:54.409Z,1493152014.409 [BPC1](ERROR): Communications Fault
2017-04-25T20:26:54.433Z,1493152014.433 [CBIT](ERROR): Communications Fault in component: BPC1
2017-04-25T20:26:55.648Z,1493152015.648 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-25T20:26:55.648Z,1493152015.648 [BPC1] No Fault, FailCount= 1
2017-04-25T20:27:12.812Z,1493152032.812 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-04-25T20:22:12.5Z
2017-04-25T20:27:12.812Z,1493152032.812 [Default:CheckIn:Read_GPS] Stopped
2017-04-25T20:27:12.812Z,1493152032.812 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-04-25T20:27:13.218Z,1493152033.218 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-04-25T20:27:17.815Z,1493152037.815 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170425T200945/Courier0004.lzma
2017-04-25T20:27:18.616Z,1493152038.616 [DataOverHttps](INFO): Moved sent file to Logs/20170425T200945/Courier0004.lzma.bak
2017-04-25T20:27:18.617Z,1493152038.616 [DataOverHttps](INFO): SBD MOMSN=4963477
2017-04-25T20:27:28.406Z,1493152048.406 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20170425T201809/Courier0000.lzma
2017-04-25T20:27:29.184Z,1493152049.184 [DataOverHttps](INFO): Moved sent file to Logs/20170425T201809/Courier0000.lzma.bak
2017-04-25T20:27:29.184Z,1493152049.184 [DataOverHttps](INFO): SBD MOMSN=4963480
2017-04-25T20:27:29.984Z,1493152049.984 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-04-25T20:27:39.064Z,1493152059.064 [NAL9602](INFO): Powering down
2017-04-25T20:27:39.235Z,1493152059.235 [DataOverHttps](INFO): Sending 307 bytes from file Logs/20170425T201809/Courier0004.lzma
2017-04-25T20:27:39.992Z,1493152059.992 [DataOverHttps](INFO): Moved sent file to Logs/20170425T201809/Courier0004.lzma.bak
2017-04-25T20:27:39.992Z,1493152059.992 [DataOverHttps](INFO): SBD MOMSN=4963484
2017-04-25T20:27:49.624Z,1493152069.624 [DataOverHttps](INFO): Sending 305 bytes from file Logs/20170425T195031/Express0013.lzma
2017-04-25T20:27:50.408Z,1493152070.408 [DataOverHttps](INFO): Moved sent file to Logs/20170425T195031/Express0013.lzma.bak
2017-04-25T20:27:50.409Z,1493152070.409 [DataOverHttps](INFO): SBD MOMSN=4963487
2017-04-25T20:28:00.164Z,1493152080.164 [DataOverHttps](INFO): Sending 512 bytes from file Logs/20170425T200945/Express0001.lzma
2017-04-25T20:28:00.912Z,1493152080.912 [DataOverHttps](INFO): Moved sent file to Logs/20170425T200945/Express0001.lzma.bak
2017-04-25T20:28:00.912Z,1493152080.912 [DataOverHttps](INFO): SBD MOMSN=4963497
2017-04-25T20:28:10.590Z,1493152090.590 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170425T200945/Express0005.lzma
2017-04-25T20:28:11.352Z,1493152091.352 [DataOverHttps](INFO): Moved sent file to Logs/20170425T200945/Express0005.lzma.bak
2017-04-25T20:28:11.352Z,1493152091.352 [DataOverHttps](INFO): SBD MOMSN=4963506
2017-04-25T20:28:20.960Z,1493152100.960 [DataOverHttps](INFO): Sending 633 bytes from file Logs/20170425T201809/Express0001.lzma
2017-04-25T20:28:21.728Z,1493152101.728 [DataOverHttps](INFO): Moved sent file to Logs/20170425T201809/Express0001.lzma.bak
2017-04-25T20:28:21.728Z,1493152101.728 [DataOverHttps](INFO): SBD MOMSN=4963508
2017-04-25T20:28:33.359Z,1493152113.359 [DataOverHttps](INFO): Sending 278 bytes from file Logs/20170425T201809/Express0005.lzma
2017-04-25T20:28:34.109Z,1493152114.109 [DataOverHttps](INFO): Moved sent file to Logs/20170425T201809/Express0005.lzma.bak
2017-04-25T20:28:34.109Z,1493152114.109 [DataOverHttps](INFO): SBD MOMSN=4963521
2017-04-25T20:28:34.580Z,1493152114.580 [Default:CheckIn:Read_Iridium] Stopped
2017-04-25T20:28:34.580Z,1493152114.580 [Default:CheckIn:C.Wait] Running Loop=1
2017-04-25T20:28:34.580Z,1493152114.580 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-04-25T20:28:39.001Z,1493152119.001 [BPC1](ERROR): Failed to parse message.
2017-04-25T20:28:39.001Z,1493152119.001 [BPC1](ERROR): Failed to parse bank A battery data
2017-04-25T20:28:39.001Z,1493152119.001 [BPC1] Data Fault, FailCount= 1
2017-04-25T20:28:39.001Z,1493152119.001 [BPC1](ERROR): Data Fault
2017-04-25T20:28:39.061Z,1493152119.061 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-25T20:28:40.249Z,1493152120.249 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-25T20:28:40.249Z,1493152120.249 [BPC1] No Fault, FailCount= 1
2017-04-25T20:29:39.424Z,1493152179.424 [DataOverHttps](IMPORTANT): SBD MTMSN=20170425T202938
2017-04-25T20:29:43.915Z,1493152183.915 [DataOverHttps](INFO): Received command:restart sys
2017-04-25T20:29:43.946Z,1493152183.946 [CommandLine](IMPORTANT): got command restart system
2017-04-25T20:29:46.246Z,1493152186.246 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:46.246Z,1493152186.246 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:46.306Z,1493152186.306 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2017-04-25T20:29:46.306Z,1493152186.306 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:46.307Z,1493152186.307 [CommandLine](INFO): Join timeout helper Thread ID is 934
2017-04-25T20:29:46.309Z,1493152186.309 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2017-04-25T20:29:46.309Z,1493152186.309 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:46.318Z,1493152186.318 [NavChartDb](INFO): Join timeout helper Thread ID is 935
2017-04-25T20:29:46.518Z,1493152186.518 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:46.518Z,1493152186.518 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:46.543Z,1493152186.543 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2017-04-25T20:29:46.543Z,1493152186.543 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:46.543Z,1493152186.543 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 936
2017-04-25T20:29:46.954Z,1493152186.954 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:46.954Z,1493152186.954 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-04-25T20:29:47.050Z,1493152187.050 [Rowe_600LCM](INFO): Powering down
2017-04-25T20:29:47.051Z,1493152187.051 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.066Z,1493152187.066 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2017-04-25T20:29:47.066Z,1493152187.066 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.067Z,1493152187.067 [Radio_Surface](INFO): Join timeout helper Thread ID is 938
2017-04-25T20:29:47.130Z,1493152187.130 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:47.131Z,1493152187.131 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.131Z,1493152187.131 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2017-04-25T20:29:47.131Z,1493152187.131 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.132Z,1493152187.132 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 939
2017-04-25T20:29:47.356Z,1493152187.356 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:47.357Z,1493152187.357 [WetLabsBB2FL](INFO): Powering down
2017-04-25T20:29:47.358Z,1493152187.358 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.371Z,1493152187.371 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2017-04-25T20:29:47.371Z,1493152187.371 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.371Z,1493152187.371 [CTD_Seabird](INFO): Join timeout helper Thread ID is 940
2017-04-25T20:29:47.642Z,1493152187.642 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:47.733Z,1493152187.733 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-04-25T20:29:47.733Z,1493152187.733 [CTD_Seabird](INFO): Powering down
2017-04-25T20:29:47.734Z,1493152187.734 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.736Z,1493152187.736 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2017-04-25T20:29:47.736Z,1493152187.736 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:47.737Z,1493152187.737 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 942
2017-04-25T20:29:48.126Z,1493152188.126 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:48.126Z,1493152188.126 [CTD_NeilBrown](INFO): Powering down
2017-04-25T20:29:48.127Z,1493152188.127 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.135Z,1493152188.135 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2017-04-25T20:29:48.135Z,1493152188.135 [logger ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.135Z,1493152188.135 [logger](INFO): Join timeout helper Thread ID is 943
2017-04-25T20:29:48.162Z,1493152188.162 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:48.162Z,1493152188.162 [logger ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.175Z,1493152188.175 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2017-04-25T20:29:48.175Z,1493152188.175 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.175Z,1493152188.175 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2017-04-25T20:29:48.175Z,1493152188.175 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.176Z,1493152188.175 [controlThread](INFO): Join timeout helper Thread ID is 944
2017-04-25T20:29:48.262Z,1493152188.262 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-25T20:29:48.262Z,1493152188.262 [controlThread](DEBUG): Uninitializing ControlThread
2017-04-25T20:29:48.263Z,1493152188.263 [Aanderaa_O2](INFO): Powering down
2017-04-25T20:29:48.264Z,1493152188.264 [NAL9602](INFO): Powering down
2017-04-25T20:29:48.266Z,1493152188.266 [PNI_TCM](INFO): Powering down
2017-04-25T20:29:48.355Z,1493152188.355 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-04-25T20:29:48.357Z,1493152188.357 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2017-04-25T20:29:48.357Z,1493152188.358 [MissionManager](INFO): Uninitializing Mission Default
2017-04-25T20:29:48.358Z,1493152188.358 [Default] Stopped
2017-04-25T20:29:48.358Z,1493152188.358 [Default](DEBUG): Aggregate::uninitialize Default
2017-04-25T20:29:48.358Z,1493152188.358 [Default:B.GoToSurface] Stopped
2017-04-25T20:29:48.358Z,1493152188.358 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-04-25T20:29:48.358Z,1493152188.358 [Default:CheckIn] Stopped
2017-04-25T20:29:48.358Z,1493152188.358 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-04-25T20:29:48.358Z,1493152188.358 [Default:CheckIn:C.Wait] Stopped
2017-04-25T20:29:48.358Z,1493152188.358 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-04-25T20:29:48.361Z,1493152188.361 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2017-04-25T20:29:48.361Z,1493152188.361 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2017-04-25T20:29:48.362Z,1493152188.362 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2017-04-25T20:29:48.362Z,1493152188.362 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2017-04-25T20:29:48.362Z,1493152188.362 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-04-25T20:29:48.363Z,1493152188.362 [BuoyancyServo](INFO): Powering down
2017-04-25T20:29:48.374Z,1493152188.374 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2017-04-25T20:29:48.374Z,1493152188.374 [ElevatorServo](INFO): Powering down
2017-04-25T20:29:48.375Z,1493152188.375 [MassServo](DEBUG): Uninitialize Mass Servo.
2017-04-25T20:29:48.375Z,1493152188.375 [MassServo](INFO): Powering down
2017-04-25T20:29:48.376Z,1493152188.376 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2017-04-25T20:29:48.376Z,1493152188.376 [RudderServo](INFO): Powering down
2017-04-25T20:29:48.377Z,1493152188.377 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2017-04-25T20:29:48.377Z,1493152188.377 [ThrusterServo](INFO): Powering down
2017-04-25T20:29:48.378Z,1493152188.378 [SBIT](DEBUG): Uninitialize SBIT Component.
2017-04-25T20:29:48.379Z,1493152188.378 [IBIT](DEBUG): Uninitialize IBIT Component.
2017-04-25T20:29:48.379Z,1493152188.379 [CBIT](DEBUG): Uninitialize CBIT Component.
2017-04-25T20:29:48.380Z,1493152188.380 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.457Z,1493152188.457 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.461Z,1493152188.461 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.464Z,1493152188.464 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.532Z,1493152188.532 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.564Z,1493152188.564 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.615Z,1493152188.615 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-04-25T20:29:48.680Z,1493152188.680 [logger ThreadHandler](INFO): Thread cancelled.