2017-10-31T17:41:29.156Z,1509471689.156 [Supervisor](DEBUG): Initializing supervisor.
2017-10-31T17:41:29.159Z,1509471689.159 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2017-10-31T17:41:29.159Z,1509471689.159 [SyncHandler](INFO): Protected caller Thread ID is 8757
2017-10-31T17:41:29.160Z,1509471689.160 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2017-10-31T17:41:29.161Z,1509471689.161 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2017-10-31T17:41:29.161Z,1509471689.161 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8758
2017-10-31T17:41:29.164Z,1509471689.164 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2017-10-31T17:41:29.174Z,1509471689.174 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2017-10-31T17:41:29.175Z,1509471689.175 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2017-10-31T17:41:29.176Z,1509471689.176 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8759
2017-10-31T17:41:29.177Z,1509471689.177 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2017-10-31T17:41:29.177Z,1509471689.177 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2017-10-31T17:41:29.178Z,1509471689.178 [logger ThreadHandler](INFO): Protected caller Thread ID is 8760
2017-10-31T17:41:29.180Z,1509471689.180 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2017-10-31T17:41:29.180Z,1509471689.180 [Supervisor](INFO): Looking for Config files in directory: Config/
2017-10-31T17:41:29.181Z,1509471689.181 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2017-10-31T17:41:29.275Z,1509471689.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2017-10-31T17:41:29.276Z,1509471689.276 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2017-10-31T17:41:29.373Z,1509471689.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2017-10-31T17:41:29.374Z,1509471689.374 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2017-10-31T17:41:29.550Z,1509471689.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2017-10-31T17:41:29.550Z,1509471689.550 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2017-10-31T17:41:29.796Z,1509471689.796 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2017-10-31T17:41:29.797Z,1509471689.797 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2017-10-31T17:41:30.098Z,1509471690.098 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2017-10-31T17:41:30.099Z,1509471690.099 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2017-10-31T17:41:30.515Z,1509471690.515 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2017-10-31T17:41:30.515Z,1509471690.515 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2017-10-31T17:41:30.827Z,1509471690.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2017-10-31T17:41:30.827Z,1509471690.827 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2017-10-31T17:41:31.219Z,1509471691.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2017-10-31T17:41:31.220Z,1509471691.220 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2017-10-31T17:41:31.298Z,1509471691.298 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2017-10-31T17:41:31.569Z,1509471691.569 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2017-10-31T17:41:31.570Z,1509471691.570 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2017-10-31T17:41:31.694Z,1509471691.694 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2017-10-31T17:41:31.695Z,1509471691.695 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2017-10-31T17:41:31.887Z,1509471691.887 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2017-10-31T17:41:31.887Z,1509471691.887 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2017-10-31T17:41:32.073Z,1509471692.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2017-10-31T17:41:32.074Z,1509471692.074 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2017-10-31T17:41:32.168Z,1509471692.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2017-10-31T17:41:32.169Z,1509471692.169 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2017-10-31T17:41:32.301Z,1509471692.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2017-10-31T17:41:32.303Z,1509471692.303 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2017-10-31T17:41:32.304Z,1509471692.304 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2017-10-31T17:41:32.522Z,1509471692.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2017-10-31T17:41:32.522Z,1509471692.522 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2017-10-31T17:41:32.599Z,1509471692.599 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2017-10-31T17:41:32.732Z,1509471692.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2017-10-31T17:41:32.823Z,1509471692.823 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2017-10-31T17:41:32.906Z,1509471692.906 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2017-10-31T17:41:33.036Z,1509471693.036 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2017-10-31T17:41:33.191Z,1509471693.191 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2017-10-31T17:41:33.285Z,1509471693.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2017-10-31T17:41:33.376Z,1509471693.376 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2017-10-31T17:41:33.470Z,1509471693.470 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2017-10-31T17:41:33.551Z,1509471693.551 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2017-10-31T17:41:33.552Z,1509471693.552 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2017-10-31T17:41:33.648Z,1509471693.648 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2017-10-31T17:41:33.649Z,1509471693.649 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2017-10-31T17:41:33.661Z,1509471693.661 [Module Loader](CRITICAL): Could not find element LcmListener.loadAtStartup
2017-10-31T17:41:33.661Z,1509471693.661 [Module Loader](CRITICAL): Could not find element LcmPublisher.loadAtStartup
2017-10-31T17:41:33.661Z,1509471693.661 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2017-10-31T17:41:33.662Z,1509471693.662 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2017-10-31T17:41:33.686Z,1509471693.686 [DepthRateCalculator] Loaded
2017-10-31T17:41:33.686Z,1509471693.686 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2017-10-31T17:41:33.692Z,1509471693.692 [PitchRateCalculator] Loaded
2017-10-31T17:41:33.692Z,1509471693.692 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2017-10-31T17:41:33.707Z,1509471693.707 [SpeedCalculator] Loaded
2017-10-31T17:41:33.707Z,1509471693.707 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2017-10-31T17:41:33.728Z,1509471693.728 [TempGradientCalculator] Loaded
2017-10-31T17:41:33.728Z,1509471693.728 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2017-10-31T17:41:33.742Z,1509471693.742 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2017-10-31T17:41:33.743Z,1509471693.743 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2017-10-31T17:41:33.748Z,1509471693.748 [YawRateCalculator] Loaded
2017-10-31T17:41:33.748Z,1509471693.748 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2017-10-31T17:41:33.749Z,1509471693.749 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2017-10-31T17:41:33.749Z,1509471693.749 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2017-10-31T17:41:33.773Z,1509471693.773 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2017-10-31T17:41:33.774Z,1509471693.774 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2017-10-31T17:41:34.014Z,1509471694.014 [AcousticModem_Benthos_ATM900] Loaded
2017-10-31T17:41:34.014Z,1509471694.014 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2017-10-31T17:41:34.083Z,1509471694.083 [DataOverHttps] Loaded
2017-10-31T17:41:34.083Z,1509471694.083 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2017-10-31T17:41:34.097Z,1509471694.097 [Depth_Keller] Loaded
2017-10-31T17:41:34.097Z,1509471694.097 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2017-10-31T17:41:34.102Z,1509471694.102 [DropWeight] Loaded
2017-10-31T17:41:34.102Z,1509471694.102 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2017-10-31T17:41:34.197Z,1509471694.197 [NAL9602] Loaded
2017-10-31T17:41:34.197Z,1509471694.197 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2017-10-31T17:41:34.222Z,1509471694.222 [Onboard] Loaded
2017-10-31T17:41:34.223Z,1509471694.223 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2017-10-31T17:41:34.248Z,1509471694.248 [Radio_Surface] Loaded
2017-10-31T17:41:34.249Z,1509471694.249 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2017-10-31T17:41:34.252Z,1509471694.252 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407A44E0
2017-10-31T17:41:34.252Z,1509471694.252 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8839
2017-10-31T17:41:34.329Z,1509471694.329 [PNI_TCM] Loaded
2017-10-31T17:41:34.329Z,1509471694.329 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2017-10-31T17:41:34.564Z,1509471694.564 [Rowe_600LCM] Loaded
2017-10-31T17:41:34.564Z,1509471694.564 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2017-10-31T17:41:34.565Z,1509471694.565 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407D44E0
2017-10-31T17:41:34.565Z,1509471694.565 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 8840
2017-10-31T17:41:36.486Z,1509471696.486 [BPC1] Loaded
2017-10-31T17:41:36.486Z,1509471696.486 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2017-10-31T17:41:36.487Z,1509471696.487 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2017-10-31T17:41:36.487Z,1509471696.487 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2017-10-31T17:41:36.612Z,1509471696.612 [SBIT](DEBUG): Construct Startup Built In Test.
2017-10-31T17:41:36.638Z,1509471696.638 [SBIT] Loaded
2017-10-31T17:41:36.638Z,1509471696.638 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2017-10-31T17:41:36.639Z,1509471696.639 [IBIT](DEBUG): Construct Initiated Built In Test.
2017-10-31T17:41:36.649Z,1509471696.649 [IBIT] Loaded
2017-10-31T17:41:36.650Z,1509471696.650 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2017-10-31T17:41:36.653Z,1509471696.653 [CBIT](DEBUG): Construct Continuous Built In Test.
2017-10-31T17:41:36.796Z,1509471696.796 [CBIT] Loaded
2017-10-31T17:41:36.796Z,1509471696.796 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2017-10-31T17:41:36.797Z,1509471696.797 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2017-10-31T17:41:36.797Z,1509471696.797 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2017-10-31T17:41:36.925Z,1509471696.925 [Aanderaa_O2] Loaded
2017-10-31T17:41:36.925Z,1509471696.925 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2017-10-31T17:41:37.000Z,1509471697.000 [CTD_NeilBrown] Loaded
2017-10-31T17:41:37.001Z,1509471697.001 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2017-10-31T17:41:37.002Z,1509471697.002 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408944E0
2017-10-31T17:41:37.002Z,1509471697.002 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 8841
2017-10-31T17:41:37.018Z,1509471697.018 [ESPComponent] Loaded
2017-10-31T17:41:37.018Z,1509471697.018 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2017-10-31T17:41:37.032Z,1509471697.032 [PAR_Licor] Loaded
2017-10-31T17:41:37.032Z,1509471697.032 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2017-10-31T17:41:37.079Z,1509471697.079 [WetLabsBB2FL] Loaded
2017-10-31T17:41:37.079Z,1509471697.079 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2017-10-31T17:41:37.080Z,1509471697.080 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408C44E0
2017-10-31T17:41:37.081Z,1509471697.081 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8842
2017-10-31T17:41:37.081Z,1509471697.081 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2017-10-31T17:41:37.082Z,1509471697.082 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2017-10-31T17:41:37.309Z,1509471697.309 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2017-10-31T17:41:37.309Z,1509471697.309 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2017-10-31T17:41:37.374Z,1509471697.374 [VerticalControl](DEBUG): Construct VerticalControl.
2017-10-31T17:41:37.469Z,1509471697.469 [VerticalControl] Loaded
2017-10-31T17:41:37.469Z,1509471697.469 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2017-10-31T17:41:37.470Z,1509471697.470 [HorizontalControl](DEBUG): Construct HorizontalControl.
2017-10-31T17:41:37.528Z,1509471697.528 [HorizontalControl] Loaded
2017-10-31T17:41:37.529Z,1509471697.529 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2017-10-31T17:41:37.529Z,1509471697.529 [SpeedControl](DEBUG): Construct SpeedControl.
2017-10-31T17:41:37.534Z,1509471697.534 [SpeedControl] Loaded
2017-10-31T17:41:37.535Z,1509471697.535 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2017-10-31T17:41:37.535Z,1509471697.535 [LoopControl](DEBUG): Construct LoopControl.
2017-10-31T17:41:37.536Z,1509471697.536 [LoopControl] Loaded
2017-10-31T17:41:37.536Z,1509471697.536 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2017-10-31T17:41:37.537Z,1509471697.537 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2017-10-31T17:41:37.537Z,1509471697.537 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2017-10-31T17:41:37.616Z,1509471697.616 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2017-10-31T17:41:37.616Z,1509471697.616 [StratificationFrontDetector](DEBUG): (re)initializing
2017-10-31T17:41:37.616Z,1509471697.616 [StratificationFrontDetector] Loaded
2017-10-31T17:41:37.617Z,1509471697.617 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2017-10-31T17:41:37.617Z,1509471697.617 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2017-10-31T17:41:37.618Z,1509471697.618 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2017-10-31T17:41:37.711Z,1509471697.711 [BuoyancyServo] Loaded
2017-10-31T17:41:37.711Z,1509471697.711 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2017-10-31T17:41:37.722Z,1509471697.722 [ElevatorServo] Loaded
2017-10-31T17:41:37.722Z,1509471697.722 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2017-10-31T17:41:37.733Z,1509471697.733 [MassServo] Loaded
2017-10-31T17:41:37.733Z,1509471697.733 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2017-10-31T17:41:37.744Z,1509471697.744 [RudderServo] Loaded
2017-10-31T17:41:37.744Z,1509471697.744 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2017-10-31T17:41:37.754Z,1509471697.754 [ThrusterServo] Loaded
2017-10-31T17:41:37.754Z,1509471697.754 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2017-10-31T17:41:37.755Z,1509471697.755 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2017-10-31T17:41:37.755Z,1509471697.755 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2017-10-31T17:41:37.848Z,1509471697.848 [DeadReckonUsingMultipleVelocitySources] Loaded
2017-10-31T17:41:37.848Z,1509471697.848 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2017-10-31T17:41:37.901Z,1509471697.901 [DeadReckonUsingSpeedCalculator] Loaded
2017-10-31T17:41:37.901Z,1509471697.901 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2017-10-31T17:41:37.917Z,1509471697.917 [NavChart] Loaded
2017-10-31T17:41:37.917Z,1509471697.917 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2017-10-31T17:41:37.921Z,1509471697.921 [UniversalFixResidualReporter] Loaded
2017-10-31T17:41:37.921Z,1509471697.921 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2017-10-31T17:41:37.922Z,1509471697.922 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2017-10-31T17:41:37.925Z,1509471697.925 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2017-10-31T17:41:37.926Z,1509471697.926 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2017-10-31T17:41:37.932Z,1509471697.932 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2017-10-31T17:41:37.933Z,1509471697.933 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A154E0
2017-10-31T17:41:37.934Z,1509471697.934 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8843
2017-10-31T17:41:37.938Z,1509471697.938 [Supervisor](INFO): Main Thread ID is 8756
2017-10-31T17:41:37.939Z,1509471697.939 [Supervisor](DEBUG): Running supervisor.
2017-10-31T17:41:37.939Z,1509471697.939 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8844
2017-10-31T17:41:37.942Z,1509471697.942 [controlThread ThreadHandler](INFO): Handler Thread ID is 8845
2017-10-31T17:41:37.942Z,1509471697.942 [controlThread](DEBUG): Initializing ControlThread
2017-10-31T17:41:37.943Z,1509471697.943 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-10-31T17:41:37.943Z,1509471697.943 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2017-10-31T17:41:37.944Z,1509471697.944 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2017-10-31T17:41:37.944Z,1509471697.944 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2017-10-31T17:41:37.945Z,1509471697.945 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2017-10-31T17:41:37.945Z,1509471697.945 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2017-10-31T17:41:37.951Z,1509471697.951 [SBIT](INFO): Initialize SBIT Component.
2017-10-31T17:41:37.952Z,1509471697.952 [SBIT](IMPORTANT): git: 2017-10-16-91-g1cda494
2017-10-31T17:41:37.952Z,1509471697.952 [SBIT](INFO): git hash: 1cda4942dadce3e3c6eb9510eb040eaf1a2b49d6
2017-10-31T17:41:37.952Z,1509471697.952 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2017-10-31T17:41:37.953Z,1509471697.953 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #17 PREEMPT Fri Oct 6 17:22:04 PDT 2017
2017-10-31T17:41:37.954Z,1509471697.954 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2017-10-31T17:41:37.955Z,1509471697.955 [IBIT](INFO): Initialize IBIT Component.
2017-10-31T17:41:37.956Z,1509471697.956 [CBIT](DEBUG): Initialize CBIT Component.
2017-10-31T17:41:37.956Z,1509471697.956 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2017-10-31T17:41:37.956Z,1509471697.956 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2017-10-31T17:41:37.957Z,1509471697.957 [logger ThreadHandler](INFO): Handler Thread ID is 8846
2017-10-31T17:41:37.977Z,1509471697.977 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8847
2017-10-31T17:41:37.983Z,1509471697.983 [Radio_Surface](INFO): Powering up
2017-10-31T17:41:37.989Z,1509471697.989 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 8848
2017-10-31T17:41:37.990Z,1509471697.990 [Rowe_600LCM](INFO): Initializing
2017-10-31T17:41:37.990Z,1509471697.990 [Rowe_600LCM](INFO): Checking LCM
2017-10-31T17:41:37.999Z,1509471697.999 [Rowe_600LCM](INFO): LCM OK
2017-10-31T17:41:37.999Z,1509471697.999 [Rowe_600LCM](INFO): Powering up
2017-10-31T17:41:38.005Z,1509471698.005 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 8849
2017-10-31T17:41:38.006Z,1509471698.006 [CTD_NeilBrown](INFO): Powering down
2017-10-31T17:41:38.025Z,1509471698.025 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8850
2017-10-31T17:41:38.027Z,1509471698.027 [WetLabsBB2FL](INFO): Powering down
2017-10-31T17:41:38.045Z,1509471698.045 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2017-10-31T17:41:38.047Z,1509471698.047 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2017-10-31T17:41:38.047Z,1509471698.047 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2017-10-31T17:41:38.048Z,1509471698.048 [LoopControl](DEBUG): Initialize LoopControlComponent.
2017-10-31T17:41:38.050Z,1509471698.050 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-31T17:41:38.051Z,1509471698.051 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-31T17:41:38.051Z,1509471698.051 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-31T17:41:38.052Z,1509471698.052 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-31T17:41:38.052Z,1509471698.052 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-31T17:41:38.057Z,1509471698.057 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-31T17:41:38.057Z,1509471698.057 [NavChart](DEBUG): Initialize NavChart Navigation.
2017-10-31T17:41:38.058Z,1509471698.058 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2017-10-31T17:41:38.065Z,1509471698.065 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2017-10-31T17:41:38.084Z,1509471698.084 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2017-10-31T17:41:38.086Z,1509471698.086 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8851
2017-10-31T17:41:38.089Z,1509471698.089 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2017-10-31T17:41:38.089Z,1509471698.089 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2017-10-31T17:41:38.089Z,1509471698.089 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2017-10-31T17:41:38.089Z,1509471698.089 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2017-10-31T17:41:38.090Z,1509471698.090 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2017-10-31T17:41:38.090Z,1509471698.090 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2017-10-31T17:41:38.090Z,1509471698.090 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2017-10-31T17:41:38.090Z,1509471698.090 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2017-10-31T17:41:38.090Z,1509471698.090 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2017-10-31T17:41:38.091Z,1509471698.091 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2017-10-31T17:41:38.091Z,1509471698.091 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2017-10-31T17:41:38.091Z,1509471698.091 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2017-10-31T17:41:38.091Z,1509471698.091 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2017-10-31T17:41:38.091Z,1509471698.091 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2017-10-31T17:41:38.092Z,1509471698.092 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2017-10-31T17:41:38.092Z,1509471698.092 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2017-10-31T17:41:38.137Z,1509471698.137 [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-10-31T17:41:38.138Z,1509471698.138 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2017-10-31T17:41:38.209Z,1509471698.209 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2017-10-31T17:41:38.210Z,1509471698.210 [Default:A.Wait](DEBUG): Construct Wait.
2017-10-31T17:41:38.211Z,1509471698.211 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2017-10-31T17:41:38.257Z,1509471698.257 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2017-10-31T17:41:38.259Z,1509471698.259 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2017-10-31T17:41:38.281Z,1509471698.281 [Default:E.Execute](DEBUG): Construct Execute.
2017-10-31T17:41:38.284Z,1509471698.284 [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-10-31T17:41:38.296Z,1509471698.296 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2017-10-31T17:41:38.317Z,1509471698.317 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:41:38.317Z,1509471698.317 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:41:38.343Z,1509471698.343 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2017-10-31T17:41:38.679Z,1509471698.679 [ESPComponent](INFO): powering down ESP
2017-10-31T17:41:39.214Z,1509471699.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:39.238Z,1509471699.238 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:39.381Z,1509471699.381 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-10-31T17:41:39.389Z,1509471699.389 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-10-31T17:41:39.395Z,1509471699.395 [ElevatorServo](DEBUG): Initializing EZServoServo.
2017-10-31T17:41:39.401Z,1509471699.401 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2017-10-31T17:41:39.434Z,1509471699.434 [MassServo](DEBUG): Initializing EZServoServo.
2017-10-31T17:41:39.437Z,1509471699.437 [MassServo](DEBUG): Initializing MassServo.
2017-10-31T17:41:39.454Z,1509471699.454 [RudderServo](DEBUG): Initializing EZServoServo.
2017-10-31T17:41:39.461Z,1509471699.461 [RudderServo](DEBUG): Initializing RudderServo.
2017-10-31T17:41:39.474Z,1509471699.474 [ThrusterServo](DEBUG): Initializing EZServoServo.
2017-10-31T17:41:39.481Z,1509471699.481 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2017-10-31T17:41:39.526Z,1509471699.526 [CommandLine](FAULT): Scheduling is paused
2017-10-31T17:41:39.526Z,1509471699.526 [CBIT](INFO): Critical error at 20171031T174133
2017-10-31T17:41:39.526Z,1509471699.526 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2017-10-31T17:41:39.738Z,1509471699.738 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:39.739Z,1509471699.739 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:42.318Z,1509471702.318 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-10-31T17:41:42.451Z,1509471702.451 [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-10-31T17:41:42.510Z,1509471702.510 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-10-31T17:41:42.510Z,1509471702.510 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-10-31T17:41:42.511Z,1509471702.511 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-10-31T17:41:48.846Z,1509471708.846 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:48.847Z,1509471708.847 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:49.240Z,1509471709.240 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:49.241Z,1509471709.241 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:49.578Z,1509471709.578 [Aanderaa_O2](INFO): Powering down
2017-10-31T17:41:49.700Z,1509471709.700 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:49.701Z,1509471709.701 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:49.945Z,1509471709.945 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003263
2017-10-31T17:41:49.993Z,1509471709.993 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:49.994Z,1509471709.994 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:50.412Z,1509471710.412 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:50.421Z,1509471710.421 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:50.783Z,1509471710.783 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:50.784Z,1509471710.784 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-10-31T17:41:53.971Z,1509471713.971 [BPC1](FAULT): Failed to initialize
2017-10-31T17:41:53.971Z,1509471713.971 [BPC1] Communications Fault, FailCount= 1
2017-10-31T17:41:53.971Z,1509471713.971 [BPC1](ERROR): Communications Fault
2017-10-31T17:41:54.102Z,1509471714.102 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:41:55.304Z,1509471715.304 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:41:55.304Z,1509471715.304 [BPC1] No Fault, FailCount= 1
2017-10-31T17:41:58.340Z,1509471718.340 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:41:58.340Z,1509471718.340 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 1
2017-10-31T17:41:58.340Z,1509471718.340 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:41:58.474Z,1509471718.474 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:41:58.740Z,1509471718.740 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:41:59.710Z,1509471719.710 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-31T17:41:59.710Z,1509471719.710 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 1
2017-10-31T17:42:01.940Z,1509471721.940 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:42:01.940Z,1509471721.940 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:42:04.346Z,1509471724.346 [NAL9602](INFO): Powering up NAL9602
2017-10-31T17:42:09.179Z,1509471729.179 [BPC1](ERROR): Failed to parse bank A battery data
2017-10-31T17:42:09.179Z,1509471729.179 [BPC1] Data Fault, FailCount= 2
2017-10-31T17:42:09.179Z,1509471729.179 [BPC1](ERROR): Data Fault
2017-10-31T17:42:09.258Z,1509471729.258 [CBIT](ERROR): Data Fault in component: BPC1
2017-10-31T17:42:10.411Z,1509471730.411 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:42:10.411Z,1509471730.411 [BPC1] No Fault, FailCount= 2
2017-10-31T17:42:15.573Z,1509471735.573 [NAL9602](INFO): NAL9602 initialized
2017-10-31T17:42:22.340Z,1509471742.340 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:42:22.340Z,1509471742.340 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 2
2017-10-31T17:42:22.340Z,1509471742.340 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:42:22.456Z,1509471742.456 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:42:22.740Z,1509471742.740 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:42:23.653Z,1509471743.653 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-31T17:42:23.653Z,1509471743.653 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 2
2017-10-31T17:42:25.940Z,1509471745.940 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:42:25.940Z,1509471745.940 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:42:25.988Z,1509471745.988 [BPC1](FAULT): Failed to initialize
2017-10-31T17:42:25.988Z,1509471745.988 [BPC1] Communications Fault, FailCount= 3
2017-10-31T17:42:25.988Z,1509471745.988 [BPC1](ERROR): Communications Fault
2017-10-31T17:42:26.074Z,1509471746.074 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:42:27.251Z,1509471747.251 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:42:27.251Z,1509471747.251 [BPC1] No Fault, FailCount= 3
2017-10-31T17:42:42.956Z,1509471762.956 [BPC1](FAULT): Failed to initialize
2017-10-31T17:42:42.956Z,1509471762.956 [BPC1] Communications Fault, FailCount= 4
2017-10-31T17:42:42.956Z,1509471762.956 [BPC1](ERROR): Communications Fault
2017-10-31T17:42:43.027Z,1509471763.027 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:42:43.196Z,1509471763.196 [SBIT](IMPORTANT): Beginning Startup BIT
2017-10-31T17:42:43.210Z,1509471763.210 [CBIT](IMPORTANT): Beginning ground fault scan
2017-10-31T17:42:43.980Z,1509471763.980 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:42:43.980Z,1509471763.980 [BPC1] No Fault, FailCount= 4
2017-10-31T17:42:45.956Z,1509471765.956 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:42:45.956Z,1509471765.956 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 3
2017-10-31T17:42:45.956Z,1509471765.956 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:42:46.145Z,1509471766.145 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:42:46.356Z,1509471766.356 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:42:47.277Z,1509471767.277 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-31T17:42:47.277Z,1509471767.277 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 3
2017-10-31T17:42:49.556Z,1509471769.556 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:42:49.556Z,1509471769.556 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:42:54.048Z,1509471774.048 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007531
CHAN A1 (24V): 0.006851
CHAN A2 (12V): -0.004929
CHAN A3 (5V): -0.002342
CHAN B0 (3.3V): -0.000998
CHAN B1 (3.15aV): -0.001261
CHAN B2 (3.15bV): -0.001078
CHAN B3 (GND): -0.000118
OPEN: 0.004335
Full Scale Calc: 4.765 mA, -1.589 mA
2017-10-31T17:42:59.425Z,1509471779.425 [BPC1](FAULT): Failed to initialize
2017-10-31T17:42:59.425Z,1509471779.425 [BPC1] Communications Fault, FailCount= 5
2017-10-31T17:42:59.425Z,1509471779.425 [BPC1](ERROR): Communications Fault
2017-10-31T17:42:59.555Z,1509471779.555 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:43:00.721Z,1509471780.721 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:43:00.721Z,1509471780.721 [BPC1] No Fault, FailCount= 5
2017-10-31T17:43:09.748Z,1509471789.748 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:43:09.748Z,1509471789.748 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 4
2017-10-31T17:43:09.748Z,1509471789.748 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:43:09.867Z,1509471789.867 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:43:10.148Z,1509471790.148 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:43:11.026Z,1509471791.026 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-31T17:43:11.027Z,1509471791.027 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 4
2017-10-31T17:43:13.348Z,1509471793.348 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:43:13.348Z,1509471793.348 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:43:16.194Z,1509471796.194 [BPC1](FAULT): Failed to initialize
2017-10-31T17:43:16.194Z,1509471796.194 [BPC1] Communications Fault, FailCount= 6
2017-10-31T17:43:16.194Z,1509471796.194 [BPC1](ERROR): Communications Fault
2017-10-31T17:43:16.247Z,1509471796.247 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:43:17.411Z,1509471797.411 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:43:17.411Z,1509471797.411 [BPC1] No Fault, FailCount= 6
2017-10-31T17:43:33.123Z,1509471813.123 [BPC1](FAULT): Failed to initialize
2017-10-31T17:43:33.123Z,1509471813.123 [BPC1] Communications Fault, FailCount= 7
2017-10-31T17:43:33.123Z,1509471813.123 [BPC1](ERROR): Communications Fault
2017-10-31T17:43:33.144Z,1509471813.144 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:43:33.480Z,1509471813.480 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:43:33.480Z,1509471813.480 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 5
2017-10-31T17:43:33.480Z,1509471813.480 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:43:33.592Z,1509471813.592 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:43:33.880Z,1509471813.880 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:43:34.359Z,1509471814.359 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:43:34.359Z,1509471814.359 [BPC1] No Fault, FailCount= 7
2017-10-31T17:43:34.787Z,1509471814.787 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-31T17:43:34.787Z,1509471814.787 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 5
2017-10-31T17:43:37.080Z,1509471817.080 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:43:37.080Z,1509471817.080 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:43:37.167Z,1509471817.167 [SBIT](IMPORTANT): SBIT PASSED
2017-10-31T17:43:37.526Z,1509471817.526 [MissionManager](IMPORTANT): Started mission Startup
2017-10-31T17:43:37.526Z,1509471817.526 [Startup] Running Loop=1
2017-10-31T17:43:37.527Z,1509471817.527 [Startup](DEBUG): Aggregate::initialize Startup
2017-10-31T17:43:37.527Z,1509471817.527 [Startup:A.GoToSurface] Running Loop=1
2017-10-31T17:43:37.527Z,1509471817.527 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-10-31T17:43:37.527Z,1509471817.527 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-10-31T17:43:37.528Z,1509471817.528 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-10-31T17:43:37.528Z,1509471817.528 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-10-31T17:43:37.529Z,1509471817.529 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-10-31T17:43:37.529Z,1509471817.529 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-10-31T17:43:37.535Z,1509471817.535 [Startup:StartupSatComms] Running Loop=1
2017-10-31T17:43:37.535Z,1509471817.535 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2017-10-31T17:43:37.535Z,1509471817.535 [Startup:StartupSatComms:A] Running Loop=1
2017-10-31T17:43:37.926Z,1509471817.926 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2017-10-31T17:43:38.101Z,1509471818.101 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-10-31T17:43:38.101Z,1509471818.101 [Rowe_600LCM] Communications Fault, FailCount= 1
2017-10-31T17:43:38.101Z,1509471818.101 [Rowe_600LCM](ERROR): Communications Fault
2017-10-31T17:43:38.352Z,1509471818.352 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-10-31T17:43:38.505Z,1509471818.505 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-10-31T17:43:38.599Z,1509471818.599 [Rowe_600LCM](INFO): Powering down
2017-10-31T17:43:42.660Z,1509471822.660 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-10-31T17:43:42.660Z,1509471822.660 [Rowe_600LCM] No Fault, FailCount= 1
2017-10-31T17:43:43.061Z,1509471823.061 [Rowe_600LCM](INFO): Initializing
2017-10-31T17:43:43.061Z,1509471823.061 [Rowe_600LCM](INFO): Checking LCM
2017-10-31T17:43:43.061Z,1509471823.061 [Rowe_600LCM](INFO): LCM OK
2017-10-31T17:43:43.061Z,1509471823.061 [Rowe_600LCM](INFO): Powering up
2017-10-31T17:43:47.258Z,1509471827.258 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-10-31T17:43:47.319Z,1509471827.319 [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-10-31T17:43:47.320Z,1509471827.320 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-10-31T17:43:47.321Z,1509471827.321 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-10-31T17:43:47.321Z,1509471827.321 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-10-31T17:43:49.913Z,1509471829.913 [BPC1](FAULT): Failed to initialize
2017-10-31T17:43:49.913Z,1509471829.913 [BPC1] Communications Fault, FailCount= 8
2017-10-31T17:43:49.913Z,1509471829.913 [BPC1](ERROR): Communications Fault
2017-10-31T17:43:49.939Z,1509471829.939 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:43:51.222Z,1509471831.222 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:43:51.222Z,1509471831.222 [BPC1] No Fault, FailCount= 8
2017-10-31T17:43:57.472Z,1509471837.472 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:43:57.472Z,1509471837.472 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 6
2017-10-31T17:43:57.472Z,1509471837.472 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:43:57.565Z,1509471837.565 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:43:57.872Z,1509471837.872 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:43:58.768Z,1509471838.768 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-31T17:43:58.768Z,1509471838.768 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 6
2017-10-31T17:44:01.072Z,1509471841.072 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:44:01.072Z,1509471841.072 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:44:06.709Z,1509471846.709 [BPC1](FAULT): Failed to initialize
2017-10-31T17:44:06.709Z,1509471846.709 [BPC1] Communications Fault, FailCount= 9
2017-10-31T17:44:06.709Z,1509471846.709 [BPC1](ERROR): Communications Fault
2017-10-31T17:44:06.730Z,1509471846.730 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:44:07.938Z,1509471847.938 [CBIT](INFO): Clearing failed state for component BPC1
2017-10-31T17:44:07.938Z,1509471847.938 [BPC1] No Fault, FailCount= 9
2017-10-31T17:44:21.472Z,1509471861.472 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:44:21.472Z,1509471861.472 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 7
2017-10-31T17:44:21.472Z,1509471861.472 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:44:21.561Z,1509471861.561 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:44:21.872Z,1509471861.872 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:44:22.730Z,1509471862.730 [CBIT](INFO): Clearing failed state for component AcousticModem_Benthos_ATM900
2017-10-31T17:44:22.730Z,1509471862.730 [AcousticModem_Benthos_ATM900] No Fault, FailCount= 7
2017-10-31T17:44:23.503Z,1509471863.503 [BPC1](FAULT): Failed to initialize
2017-10-31T17:44:23.503Z,1509471863.503 [BPC1] Communications Fault, FailCount= 10
2017-10-31T17:44:23.503Z,1509471863.503 [BPC1](ERROR): Communications Fault
2017-10-31T17:44:23.561Z,1509471863.561 [CBIT](ERROR): Communications Fault in component: BPC1
2017-10-31T17:44:23.561Z,1509471863.561 [CBIT](CRITICAL): Communications Fault in component: BPC1
2017-10-31T17:44:23.947Z,1509471863.947 [CBIT](INFO): Critical error at 20171031T174423
2017-10-31T17:44:25.072Z,1509471865.072 [AcousticModem_Benthos_ATM900](INFO): Powering up
2017-10-31T17:44:25.072Z,1509471865.072 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2017-10-31T17:44:37.911Z,1509471877.911 [Startup:StartupSatComms:A](INFO): Timed out from 2017-10-31T17:43:37.5Z
2017-10-31T17:44:37.911Z,1509471877.911 [Startup:StartupSatComms:A] Stopped
2017-10-31T17:44:37.911Z,1509471877.911 [Startup:StartupSatComms:B] Running Loop=1
2017-10-31T17:44:38.311Z,1509471878.311 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-31T17:44:38.312Z,1509471878.312 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2017-10-31T17:44:38.312Z,1509471878.312 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-31T17:44:38.313Z,1509471878.313 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-31T17:44:38.314Z,1509471878.314 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2017-10-31T17:44:38.314Z,1509471878.314 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-31T17:44:38.316Z,1509471878.316 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-10-31T17:44:38.361Z,1509471878.361 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-31T17:44:38.361Z,1509471878.361 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-31T17:44:38.920Z,1509471878.920 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-31T17:44:38.920Z,1509471878.920 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2017-10-31T17:44:38.920Z,1509471878.920 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-31T17:44:38.921Z,1509471878.921 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2017-10-31T17:44:39.170Z,1509471879.170 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-31T17:44:39.170Z,1509471879.170 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-31T17:44:39.171Z,1509471879.171 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-31T17:44:39.171Z,1509471879.171 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-31T17:44:39.171Z,1509471879.171 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-31T17:44:39.172Z,1509471879.172 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-31T17:44:42.521Z,1509471882.521 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20171031T155434/Courier0004.lzma
2017-10-31T17:44:43.322Z,1509471883.322 [DataOverHttps](INFO): Moved sent file to Logs/20171031T155434/Courier0004.lzma.bak
2017-10-31T17:44:43.322Z,1509471883.322 [DataOverHttps](INFO): SBD MOMSN=5179709
2017-10-31T17:44:47.422Z,1509471887.422 [AcousticModem_Benthos_ATM900](FAULT): failed to initialize, no bytes available on serial interface
2017-10-31T17:44:47.422Z,1509471887.422 [AcousticModem_Benthos_ATM900] Communications Fault, FailCount= 8
2017-10-31T17:44:47.422Z,1509471887.422 [AcousticModem_Benthos_ATM900](ERROR): Communications Fault
2017-10-31T17:44:47.568Z,1509471887.568 [CBIT](ERROR): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:44:47.579Z,1509471887.579 [CBIT](FAULT): Communications Fault in component: AcousticModem_Benthos_ATM900
2017-10-31T17:44:47.796Z,1509471887.796 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:44:52.282Z,1509471892.282 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171031T174023/Courier0000.lzma
2017-10-31T17:44:53.078Z,1509471893.078 [DataOverHttps](INFO): Moved sent file to Logs/20171031T174023/Courier0000.lzma.bak
2017-10-31T17:44:53.079Z,1509471893.079 [DataOverHttps](INFO): SBD MOMSN=5179712
2017-10-31T17:44:58.823Z,1509471898.823 [CommandLine](IMPORTANT): got command configSet BPC1.loadAtStartup 0.000000 bool persist
2017-10-31T17:44:58.823Z,1509471898.823 [CommandLine](IMPORTANT): configSet BPC1.loadAtStartup requires a restart to take effect.
2017-10-31T17:45:02.231Z,1509471902.231 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20171031T174129/Courier0000.lzma
2017-10-31T17:45:03.029Z,1509471903.029 [DataOverHttps](INFO): Moved sent file to Logs/20171031T174129/Courier0000.lzma.bak
2017-10-31T17:45:03.029Z,1509471903.029 [DataOverHttps](INFO): SBD MOMSN=5179715
2017-10-31T17:45:08.835Z,1509471908.835 [PNI_TCM](ERROR): CRC does not match. Expected:0x46277 got:0x57018
2017-10-31T17:45:12.935Z,1509471912.935 [DataOverHttps](INFO): Sending 832 bytes from file Logs/20171031T155434/Express0001.lzma
2017-10-31T17:45:13.677Z,1509471913.677 [DataOverHttps](INFO): Moved sent file to Logs/20171031T155434/Express0001.lzma.bak
2017-10-31T17:45:13.678Z,1509471913.678 [DataOverHttps](INFO): SBD MOMSN=5179721
2017-10-31T17:45:22.975Z,1509471922.975 [DataOverHttps](INFO): Sending 282 bytes from file Logs/20171031T155434/Express0005.lzma
2017-10-31T17:45:23.773Z,1509471923.773 [DataOverHttps](INFO): Moved sent file to Logs/20171031T155434/Express0005.lzma.bak
2017-10-31T17:45:23.773Z,1509471923.773 [DataOverHttps](INFO): SBD MOMSN=5179743
2017-10-31T17:45:32.992Z,1509471932.992 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171031T174023/Express0001.lzma
2017-10-31T17:45:33.793Z,1509471933.793 [DataOverHttps](INFO): Moved sent file to Logs/20171031T174023/Express0001.lzma.bak
2017-10-31T17:45:33.793Z,1509471933.793 [DataOverHttps](INFO): SBD MOMSN=5179750
2017-10-31T17:45:38.379Z,1509471938.379 [Startup:StartupSatComms:B](INFO): Timed out from 2017-10-31T17:44:37.9Z
2017-10-31T17:45:38.379Z,1509471938.379 [Startup:StartupSatComms:B] Stopped
2017-10-31T17:45:38.379Z,1509471938.379 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2017-10-31T17:45:38.380Z,1509471938.380 [Startup:StartupSatComms] Stopped
2017-10-31T17:45:38.380Z,1509471938.380 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2017-10-31T17:45:38.381Z,1509471938.381 [Startup](INFO): Completed Startup
2017-10-31T17:45:38.381Z,1509471938.381 [MissionManager](INFO): Startup is completed.
2017-10-31T17:45:38.381Z,1509471938.381 [MissionManager](INFO): Uninitializing Mission Startup
2017-10-31T17:45:38.381Z,1509471938.381 [Startup] Stopped
2017-10-31T17:45:38.381Z,1509471938.381 [Startup](DEBUG): Aggregate::uninitialize Startup
2017-10-31T17:45:38.381Z,1509471938.381 [Startup:A.GoToSurface] Stopped
2017-10-31T17:45:38.381Z,1509471938.381 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-10-31T17:45:38.550Z,1509471938.550 [MissionManager](IMPORTANT): Started mission Default
2017-10-31T17:45:38.551Z,1509471938.551 [Default] Running Loop=1
2017-10-31T17:45:38.551Z,1509471938.551 [Default](DEBUG): Aggregate::initialize Default
2017-10-31T17:45:38.551Z,1509471938.551 [Default:B.GoToSurface] Running Loop=1
2017-10-31T17:45:38.551Z,1509471938.551 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-10-31T17:45:38.551Z,1509471938.551 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-10-31T17:45:38.551Z,1509471938.551 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-10-31T17:45:38.552Z,1509471938.552 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-10-31T17:45:38.552Z,1509471938.552 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-10-31T17:45:38.552Z,1509471938.552 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-10-31T17:45:38.569Z,1509471938.569 [Default:A.Wait] Running Loop=1
2017-10-31T17:45:38.569Z,1509471938.569 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-10-31T17:45:43.313Z,1509471943.313 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-10-31T17:45:43.313Z,1509471943.313 [Rowe_600LCM] Communications Fault, FailCount= 2
2017-10-31T17:45:43.313Z,1509471943.313 [Rowe_600LCM](ERROR): Communications Fault
2017-10-31T17:45:43.323Z,1509471943.323 [DataOverHttps](INFO): Sending 861 bytes from file Logs/20171031T174129/Express0001.lzma
2017-10-31T17:45:43.451Z,1509471943.451 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.2 s old, using for 20.0 s.
2017-10-31T17:45:43.465Z,1509471943.465 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-10-31T17:45:43.739Z,1509471943.739 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-10-31T17:45:43.830Z,1509471943.830 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.6 s old, using for 20.0 s.
2017-10-31T17:45:43.931Z,1509471943.931 [Rowe_600LCM](INFO): Powering down
2017-10-31T17:45:44.122Z,1509471944.122 [DataOverHttps](INFO): Moved sent file to Logs/20171031T174129/Express0001.lzma.bak
2017-10-31T17:45:44.122Z,1509471944.122 [DataOverHttps](INFO): SBD MOMSN=5179752
2017-10-31T17:45:44.194Z,1509471944.194 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.9 s old, using for 20.0 s.
2017-10-31T17:45:44.561Z,1509471944.561 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.3 s old, using for 20.0 s.
2017-10-31T17:45:44.967Z,1509471944.967 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.7 s old, using for 20.0 s.
2017-10-31T17:45:45.174Z,1509471945.174 [CommandLine](IMPORTANT): got command restart application
2017-10-31T17:45:45.367Z,1509471945.367 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.1 s old, using for 20.0 s.
2017-10-31T17:45:45.380Z,1509471945.380 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-10-31T17:45:45.380Z,1509471945.380 [Rowe_600LCM] No Fault, FailCount= 2
2017-10-31T17:45:45.546Z,1509471945.546 [Rowe_600LCM](INFO): Initializing
2017-10-31T17:45:45.546Z,1509471945.546 [Rowe_600LCM](INFO): Checking LCM
2017-10-31T17:45:45.546Z,1509471945.546 [Rowe_600LCM](INFO): LCM OK
2017-10-31T17:45:45.546Z,1509471945.546 [Rowe_600LCM](INFO): Powering up
2017-10-31T17:45:45.761Z,1509471945.761 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.5 s old, using for 20.0 s.
2017-10-31T17:45:46.163Z,1509471946.163 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.9 s old, using for 20.0 s.
2017-10-31T17:45:46.184Z,1509471946.184 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:46.184Z,1509471946.184 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:46.292Z,1509471946.292 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2017-10-31T17:45:46.293Z,1509471946.293 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:46.293Z,1509471946.293 [CommandLine](INFO): Join timeout helper Thread ID is 8902
2017-10-31T17:45:46.294Z,1509471946.294 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2017-10-31T17:45:46.294Z,1509471946.294 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:46.295Z,1509471946.295 [NavChartDb](INFO): Join timeout helper Thread ID is 8903
2017-10-31T17:45:46.571Z,1509471946.571 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.3 s old, using for 20.0 s.
2017-10-31T17:45:46.581Z,1509471946.581 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:46.581Z,1509471946.581 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:46.597Z,1509471946.597 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2017-10-31T17:45:46.597Z,1509471946.597 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:46.597Z,1509471946.597 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8904
2017-10-31T17:45:46.647Z,1509471946.647 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:46.647Z,1509471946.647 [WetLabsBB2FL](INFO): Powering down
2017-10-31T17:45:46.648Z,1509471946.648 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:46.661Z,1509471946.661 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2017-10-31T17:45:46.661Z,1509471946.661 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:46.661Z,1509471946.661 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 8905
2017-10-31T17:45:46.965Z,1509471946.965 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.7 s old, using for 20.0 s.
2017-10-31T17:45:47.051Z,1509471947.051 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:47.051Z,1509471947.051 [CTD_NeilBrown](INFO): Powering down
2017-10-31T17:45:47.052Z,1509471947.052 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.069Z,1509471947.069 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2017-10-31T17:45:47.069Z,1509471947.069 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.069Z,1509471947.069 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 8906
2017-10-31T17:45:47.161Z,1509471947.161 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:47.161Z,1509471947.161 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-10-31T17:45:47.260Z,1509471947.260 [Rowe_600LCM](INFO): Powering down
2017-10-31T17:45:47.261Z,1509471947.261 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.274Z,1509471947.274 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2017-10-31T17:45:47.274Z,1509471947.274 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.274Z,1509471947.274 [Radio_Surface](INFO): Join timeout helper Thread ID is 8908
2017-10-31T17:45:47.376Z,1509471947.376 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.1 s old, using for 20.0 s.
2017-10-31T17:45:47.429Z,1509471947.429 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:47.429Z,1509471947.429 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.441Z,1509471947.441 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2017-10-31T17:45:47.442Z,1509471947.442 [logger ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.442Z,1509471947.442 [logger](INFO): Join timeout helper Thread ID is 8909
2017-10-31T17:45:47.449Z,1509471947.449 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:47.449Z,1509471947.449 [logger ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.461Z,1509471947.461 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2017-10-31T17:45:47.462Z,1509471947.462 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.462Z,1509471947.462 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2017-10-31T17:45:47.462Z,1509471947.462 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.462Z,1509471947.462 [controlThread](INFO): Join timeout helper Thread ID is 8910
2017-10-31T17:45:47.717Z,1509471947.717 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2017-10-31T17:45:47.717Z,1509471947.717 [controlThread](DEBUG): Uninitializing ControlThread
2017-10-31T17:45:47.717Z,1509471947.717 [AcousticModem_Benthos_ATM900](INFO): Powering down
2017-10-31T17:45:47.719Z,1509471947.719 [NAL9602](INFO): Powering down
2017-10-31T17:45:47.720Z,1509471947.720 [PNI_TCM](INFO): Powering down
2017-10-31T17:45:47.809Z,1509471947.809 [Aanderaa_O2](INFO): Powering down
2017-10-31T17:45:47.812Z,1509471947.812 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-10-31T17:45:47.814Z,1509471947.814 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2017-10-31T17:45:47.814Z,1509471947.814 [MissionManager](INFO): Uninitializing Mission Default
2017-10-31T17:45:47.815Z,1509471947.815 [Default] Stopped
2017-10-31T17:45:47.815Z,1509471947.815 [Default](DEBUG): Aggregate::uninitialize Default
2017-10-31T17:45:47.815Z,1509471947.815 [Default:A.Wait] Stopped
2017-10-31T17:45:47.815Z,1509471947.815 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-10-31T17:45:47.815Z,1509471947.815 [Default:B.GoToSurface] Stopped
2017-10-31T17:45:47.815Z,1509471947.815 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-10-31T17:45:47.818Z,1509471947.818 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2017-10-31T17:45:47.818Z,1509471947.818 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2017-10-31T17:45:47.818Z,1509471947.818 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2017-10-31T17:45:47.819Z,1509471947.819 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2017-10-31T17:45:47.819Z,1509471947.819 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-10-31T17:45:47.819Z,1509471947.819 [BuoyancyServo](INFO): Powering down
2017-10-31T17:45:47.833Z,1509471947.833 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2017-10-31T17:45:47.833Z,1509471947.833 [ElevatorServo](INFO): Powering down
2017-10-31T17:45:47.834Z,1509471947.834 [MassServo](DEBUG): Uninitialize Mass Servo.
2017-10-31T17:45:47.834Z,1509471947.834 [MassServo](INFO): Powering down
2017-10-31T17:45:47.835Z,1509471947.835 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2017-10-31T17:45:47.835Z,1509471947.835 [RudderServo](INFO): Powering down
2017-10-31T17:45:47.836Z,1509471947.836 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2017-10-31T17:45:47.836Z,1509471947.836 [ThrusterServo](INFO): Powering down
2017-10-31T17:45:47.837Z,1509471947.837 [SBIT](DEBUG): Uninitialize SBIT Component.
2017-10-31T17:45:47.837Z,1509471947.837 [IBIT](DEBUG): Uninitialize IBIT Component.
2017-10-31T17:45:47.837Z,1509471947.837 [CBIT](DEBUG): Uninitialize CBIT Component.
2017-10-31T17:45:47.838Z,1509471947.838 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.919Z,1509471947.919 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.924Z,1509471947.924 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.960Z,1509471947.960 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:47.964Z,1509471947.964 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:48.009Z,1509471948.009 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-10-31T17:45:48.051Z,1509471948.051 [logger ThreadHandler](INFO): Thread cancelled.