2017-09-18T21:35:13.938Z,1505770513.938 [Supervisor](DEBUG): Initializing supervisor.
2017-09-18T21:35:13.942Z,1505770513.942 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0
2017-09-18T21:35:13.942Z,1505770513.942 [SyncHandler](INFO): Protected caller Thread ID is 770
2017-09-18T21:35:13.943Z,1505770513.943 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2017-09-18T21:35:13.944Z,1505770513.944 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0
2017-09-18T21:35:13.944Z,1505770513.944 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 771
2017-09-18T21:35:13.948Z,1505770513.948 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2017-09-18T21:35:13.963Z,1505770513.963 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2017-09-18T21:35:13.964Z,1505770513.964 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0
2017-09-18T21:35:13.965Z,1505770513.965 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 772
2017-09-18T21:35:13.966Z,1505770513.966 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2017-09-18T21:35:13.967Z,1505770513.967 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0
2017-09-18T21:35:13.967Z,1505770513.967 [logger ThreadHandler](INFO): Protected caller Thread ID is 773
2017-09-18T21:35:13.970Z,1505770513.970 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2017-09-18T21:35:13.970Z,1505770513.970 [Supervisor](INFO): Looking for Config files in directory: Config/
2017-09-18T21:35:13.973Z,1505770513.973 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2017-09-18T21:35:14.178Z,1505770514.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2017-09-18T21:35:14.178Z,1505770514.178 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2017-09-18T21:35:14.321Z,1505770514.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2017-09-18T21:35:14.322Z,1505770514.322 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2017-09-18T21:35:14.735Z,1505770514.735 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2017-09-18T21:35:14.735Z,1505770514.735 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2017-09-18T21:35:14.889Z,1505770514.889 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2017-09-18T21:35:14.889Z,1505770514.889 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2017-09-18T21:35:14.976Z,1505770514.976 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2017-09-18T21:35:15.200Z,1505770515.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2017-09-18T21:35:15.200Z,1505770515.200 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2017-09-18T21:35:15.310Z,1505770515.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2017-09-18T21:35:15.311Z,1505770515.311 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2017-09-18T21:35:15.646Z,1505770515.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2017-09-18T21:35:15.647Z,1505770515.647 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2017-09-18T21:35:16.075Z,1505770516.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2017-09-18T21:35:16.075Z,1505770516.075 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2017-09-18T21:35:16.452Z,1505770516.452 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2017-09-18T21:35:16.452Z,1505770516.452 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2017-09-18T21:35:17.319Z,1505770517.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2017-09-18T21:35:18.242Z,1505770518.242 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2017-09-18T21:35:18.514Z,1505770518.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2017-09-18T21:35:18.515Z,1505770518.515 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2017-09-18T21:35:18.622Z,1505770518.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2017-09-18T21:35:18.623Z,1505770518.623 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2017-09-18T21:35:19.178Z,1505770519.178 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2017-09-18T21:35:19.179Z,1505770519.179 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2017-09-18T21:35:19.296Z,1505770519.296 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2017-09-18T21:35:19.298Z,1505770519.298 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2017-09-18T21:35:19.301Z,1505770519.301 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2017-09-18T21:35:19.601Z,1505770519.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2017-09-18T21:35:19.602Z,1505770519.602 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2017-09-18T21:35:19.711Z,1505770519.711 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2017-09-18T21:35:19.809Z,1505770519.809 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2017-09-18T21:35:19.921Z,1505770519.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2017-09-18T21:35:20.013Z,1505770520.013 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2017-09-18T21:35:20.153Z,1505770520.153 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2017-09-18T21:35:20.325Z,1505770520.325 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2017-09-18T21:35:20.428Z,1505770520.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2017-09-18T21:35:20.527Z,1505770520.527 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2017-09-18T21:35:20.618Z,1505770520.618 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2017-09-18T21:35:20.819Z,1505770520.819 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2017-09-18T21:35:20.900Z,1505770520.900 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2017-09-18T21:35:20.904Z,1505770520.904 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2017-09-18T21:35:21.077Z,1505770521.077 [SBIT](DEBUG): Construct Startup Built In Test.
2017-09-18T21:35:21.113Z,1505770521.113 [SBIT] Loaded
2017-09-18T21:35:21.113Z,1505770521.113 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2017-09-18T21:35:21.114Z,1505770521.114 [IBIT](DEBUG): Construct Initiated Built In Test.
2017-09-18T21:35:21.150Z,1505770521.150 [IBIT] Loaded
2017-09-18T21:35:21.150Z,1505770521.150 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2017-09-18T21:35:21.154Z,1505770521.154 [CBIT](DEBUG): Construct Continuous Built In Test.
2017-09-18T21:35:21.349Z,1505770521.349 [CBIT] Loaded
2017-09-18T21:35:21.349Z,1505770521.349 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2017-09-18T21:35:21.350Z,1505770521.350 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2017-09-18T21:35:21.351Z,1505770521.351 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2017-09-18T21:35:21.451Z,1505770521.451 [VerticalControl](DEBUG): Construct VerticalControl.
2017-09-18T21:35:21.572Z,1505770521.572 [VerticalControl] Loaded
2017-09-18T21:35:21.572Z,1505770521.572 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2017-09-18T21:35:21.573Z,1505770521.573 [HorizontalControl](DEBUG): Construct HorizontalControl.
2017-09-18T21:35:21.652Z,1505770521.652 [HorizontalControl] Loaded
2017-09-18T21:35:21.652Z,1505770521.652 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2017-09-18T21:35:21.653Z,1505770521.653 [SpeedControl](DEBUG): Construct SpeedControl.
2017-09-18T21:35:21.660Z,1505770521.660 [SpeedControl] Loaded
2017-09-18T21:35:21.661Z,1505770521.661 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2017-09-18T21:35:21.662Z,1505770521.662 [LoopControl](DEBUG): Construct LoopControl.
2017-09-18T21:35:21.662Z,1505770521.662 [LoopControl] Loaded
2017-09-18T21:35:21.663Z,1505770521.663 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2017-09-18T21:35:21.663Z,1505770521.663 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2017-09-18T21:35:21.664Z,1505770521.664 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2017-09-18T21:35:21.725Z,1505770521.725 [DepthRateCalculator] Loaded
2017-09-18T21:35:21.725Z,1505770521.725 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2017-09-18T21:35:21.732Z,1505770521.732 [PitchRateCalculator] Loaded
2017-09-18T21:35:21.733Z,1505770521.733 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2017-09-18T21:35:21.752Z,1505770521.752 [SpeedCalculator] Loaded
2017-09-18T21:35:21.752Z,1505770521.752 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2017-09-18T21:35:21.778Z,1505770521.778 [TempGradientCalculator] Loaded
2017-09-18T21:35:21.778Z,1505770521.778 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2017-09-18T21:35:21.797Z,1505770521.797 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2017-09-18T21:35:21.798Z,1505770521.798 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2017-09-18T21:35:21.804Z,1505770521.804 [YawRateCalculator] Loaded
2017-09-18T21:35:21.804Z,1505770521.804 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2017-09-18T21:35:21.805Z,1505770521.805 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2017-09-18T21:35:28.298Z,1505770528.298 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2017-09-18T21:35:28.595Z,1505770528.595 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2017-09-18T21:35:28.595Z,1505770528.595 [StratificationFrontDetector](DEBUG): (re)initializing
2017-09-18T21:35:28.595Z,1505770528.595 [StratificationFrontDetector] Loaded
2017-09-18T21:35:28.595Z,1505770528.595 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2017-09-18T21:35:28.596Z,1505770528.596 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2017-09-18T21:35:28.597Z,1505770528.597 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2017-09-18T21:35:28.886Z,1505770528.886 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2017-09-18T21:35:28.887Z,1505770528.887 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2017-09-18T21:35:29.024Z,1505770529.024 [DeadReckonUsingMultipleVelocitySources] Loaded
2017-09-18T21:35:29.024Z,1505770529.024 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2017-09-18T21:35:29.093Z,1505770529.093 [DeadReckonUsingSpeedCalculator] Loaded
2017-09-18T21:35:29.093Z,1505770529.093 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2017-09-18T21:35:29.115Z,1505770529.115 [NavChart] Loaded
2017-09-18T21:35:29.115Z,1505770529.115 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2017-09-18T21:35:29.121Z,1505770529.121 [UniversalFixResidualReporter] Loaded
2017-09-18T21:35:29.121Z,1505770529.121 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2017-09-18T21:35:29.121Z,1505770529.121 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2017-09-18T21:35:29.122Z,1505770529.122 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2017-09-18T21:35:29.152Z,1505770529.152 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2017-09-18T21:35:29.153Z,1505770529.153 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2017-09-18T21:35:29.370Z,1505770529.370 [Aanderaa_O2] Loaded
2017-09-18T21:35:29.370Z,1505770529.370 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2017-09-18T21:35:29.476Z,1505770529.476 [CTD_NeilBrown] Loaded
2017-09-18T21:35:29.476Z,1505770529.476 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2017-09-18T21:35:29.478Z,1505770529.478 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408134E0
2017-09-18T21:35:29.478Z,1505770529.478 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 856
2017-09-18T21:35:29.522Z,1505770529.522 [CTD_Seabird] Loaded
2017-09-18T21:35:29.523Z,1505770529.523 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2017-09-18T21:35:29.524Z,1505770529.524 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408434E0
2017-09-18T21:35:29.524Z,1505770529.524 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 857
2017-09-18T21:35:29.543Z,1505770529.543 [PAR_Licor] Loaded
2017-09-18T21:35:29.543Z,1505770529.543 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2017-09-18T21:35:29.601Z,1505770529.601 [WetLabsBB2FL] Loaded
2017-09-18T21:35:29.602Z,1505770529.602 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2017-09-18T21:35:29.603Z,1505770529.603 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408734E0
2017-09-18T21:35:29.603Z,1505770529.603 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 858
2017-09-18T21:35:29.604Z,1505770529.604 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2017-09-18T21:35:29.605Z,1505770529.605 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2017-09-18T21:35:30.254Z,1505770530.254 [DataOverHttps] Loaded
2017-09-18T21:35:30.254Z,1505770530.254 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2017-09-18T21:35:30.271Z,1505770530.271 [Depth_Keller] Loaded
2017-09-18T21:35:30.271Z,1505770530.271 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2017-09-18T21:35:30.277Z,1505770530.277 [DropWeight] Loaded
2017-09-18T21:35:30.278Z,1505770530.278 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2017-09-18T21:35:30.390Z,1505770530.390 [NAL9602] Loaded
2017-09-18T21:35:30.391Z,1505770530.391 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2017-09-18T21:35:30.402Z,1505770530.402 [Onboard] Loaded
2017-09-18T21:35:30.403Z,1505770530.403 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2017-09-18T21:35:30.411Z,1505770530.411 [Radio_Surface] Loaded
2017-09-18T21:35:30.412Z,1505770530.412 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2017-09-18T21:35:30.413Z,1505770530.413 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AF74E0
2017-09-18T21:35:30.413Z,1505770530.413 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 859
2017-09-18T21:35:30.587Z,1505770530.587 [DAT] Loaded
2017-09-18T21:35:30.587Z,1505770530.587 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2017-09-18T21:35:30.790Z,1505770530.790 [PNI_TCM] Loaded
2017-09-18T21:35:30.790Z,1505770530.790 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2017-09-18T21:35:30.865Z,1505770530.865 [Rowe_600LCM] Loaded
2017-09-18T21:35:30.865Z,1505770530.865 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2017-09-18T21:35:30.866Z,1505770530.866 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40B274E0
2017-09-18T21:35:30.867Z,1505770530.867 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 860
2017-09-18T21:35:33.314Z,1505770533.314 [BPC1] Loaded
2017-09-18T21:35:33.315Z,1505770533.315 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2017-09-18T21:35:33.315Z,1505770533.315 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2017-09-18T21:35:33.316Z,1505770533.316 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2017-09-18T21:35:33.492Z,1505770533.492 [BuoyancyServo] Loaded
2017-09-18T21:35:33.493Z,1505770533.493 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2017-09-18T21:35:33.508Z,1505770533.508 [ElevatorServo] Loaded
2017-09-18T21:35:33.508Z,1505770533.508 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2017-09-18T21:35:33.523Z,1505770533.523 [MassServo] Loaded
2017-09-18T21:35:33.523Z,1505770533.523 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2017-09-18T21:35:33.538Z,1505770533.538 [RudderServo] Loaded
2017-09-18T21:35:33.539Z,1505770533.539 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2017-09-18T21:35:33.553Z,1505770533.553 [ThrusterServo] Loaded
2017-09-18T21:35:33.553Z,1505770533.553 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2017-09-18T21:35:33.554Z,1505770533.554 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2017-09-18T21:35:33.555Z,1505770533.555 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2017-09-18T21:35:33.696Z,1505770533.696 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2017-09-18T21:35:33.697Z,1505770533.697 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2017-09-18T21:35:33.743Z,1505770533.743 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2017-09-18T21:35:33.748Z,1505770533.748 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2017-09-18T21:35:33.750Z,1505770533.750 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2017-09-18T21:35:33.760Z,1505770533.760 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2017-09-18T21:35:33.761Z,1505770533.761 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BFB4E0
2017-09-18T21:35:33.762Z,1505770533.762 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 861
2017-09-18T21:35:33.769Z,1505770533.769 [Supervisor](INFO): Main Thread ID is 765
2017-09-18T21:35:33.769Z,1505770533.769 [Supervisor](DEBUG): Running supervisor.
2017-09-18T21:35:33.770Z,1505770533.770 [CommandLine ThreadHandler](INFO): Handler Thread ID is 862
2017-09-18T21:35:33.773Z,1505770533.773 [controlThread ThreadHandler](INFO): Handler Thread ID is 863
2017-09-18T21:35:33.773Z,1505770533.773 [controlThread](DEBUG): Initializing ControlThread
2017-09-18T21:35:33.774Z,1505770533.774 [SBIT](INFO): Initialize SBIT Component.
2017-09-18T21:35:33.775Z,1505770533.775 [SBIT](IMPORTANT): git: 2017-08-02-115-g578c285
2017-09-18T21:35:33.775Z,1505770533.775 [SBIT](INFO): git hash: 578c285a2bbd310b0721fe6585a19844c60a5fcb
2017-09-18T21:35:33.777Z,1505770533.777 [SBIT](INFO): Kernel Reporting Different Release From Configuration.
Kernel Expected: 2.6.27.8
Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty
2017-09-18T21:35:33.778Z,1505770533.778 [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-09-18T21:35:33.779Z,1505770533.779 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2017-09-18T21:35:33.779Z,1505770533.779 [IBIT](INFO): Initialize IBIT Component.
2017-09-18T21:35:33.780Z,1505770533.780 [CBIT](DEBUG): Initialize CBIT Component.
2017-09-18T21:35:33.781Z,1505770533.781 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2017-09-18T21:35:33.781Z,1505770533.781 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2017-09-18T21:35:33.782Z,1505770533.782 [logger ThreadHandler](INFO): Handler Thread ID is 864
2017-09-18T21:35:33.806Z,1505770533.806 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 865
2017-09-18T21:35:33.807Z,1505770533.807 [CTD_NeilBrown](INFO): Powering down
2017-09-18T21:35:33.842Z,1505770533.842 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 866
2017-09-18T21:35:33.842Z,1505770533.842 [CTD_Seabird](INFO): Initializing
2017-09-18T21:35:33.884Z,1505770533.884 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2017-09-18T21:35:33.888Z,1505770533.888 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2017-09-18T21:35:33.889Z,1505770533.889 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2017-09-18T21:35:33.890Z,1505770533.890 [LoopControl](DEBUG): Initialize LoopControlComponent.
2017-09-18T21:35:33.890Z,1505770533.890 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-09-18T21:35:33.890Z,1505770533.890 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2017-09-18T21:35:33.891Z,1505770533.891 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2017-09-18T21:35:33.891Z,1505770533.891 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2017-09-18T21:35:33.892Z,1505770533.892 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2017-09-18T21:35:33.896Z,1505770533.896 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2017-09-18T21:35:33.897Z,1505770533.897 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-09-18T21:35:33.898Z,1505770533.898 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-09-18T21:35:33.899Z,1505770533.899 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-09-18T21:35:33.899Z,1505770533.899 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-09-18T21:35:33.900Z,1505770533.900 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-09-18T21:35:33.900Z,1505770533.900 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-09-18T21:35:33.901Z,1505770533.901 [NavChart](DEBUG): Initialize NavChart Navigation.
2017-09-18T21:35:33.901Z,1505770533.901 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2017-09-18T21:35:33.884Z,1505770533.884 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 868
2017-09-18T21:35:33.907Z,1505770533.907 [WetLabsBB2FL](INFO): Powering down
2017-09-18T21:35:33.934Z,1505770533.934 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 869
2017-09-18T21:35:33.942Z,1505770533.942 [Radio_Surface](INFO): Powering up
2017-09-18T21:35:33.958Z,1505770533.958 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 870
2017-09-18T21:35:33.959Z,1505770533.959 [Rowe_600LCM](INFO): Initializing
2017-09-18T21:35:33.960Z,1505770533.960 [Rowe_600LCM](INFO): Checking LCM
2017-09-18T21:35:33.986Z,1505770533.986 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2017-09-18T21:35:34.047Z,1505770534.047 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 871
2017-09-18T21:35:34.059Z,1505770534.059 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2017-09-18T21:35:34.059Z,1505770534.059 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2017-09-18T21:35:34.060Z,1505770534.060 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2017-09-18T21:35:34.060Z,1505770534.060 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2017-09-18T21:35:34.060Z,1505770534.060 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2017-09-18T21:35:34.060Z,1505770534.060 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2017-09-18T21:35:34.060Z,1505770534.060 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2017-09-18T21:35:34.060Z,1505770534.060 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2017-09-18T21:35:34.061Z,1505770534.061 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2017-09-18T21:35:34.061Z,1505770534.061 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2017-09-18T21:35:34.061Z,1505770534.061 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2017-09-18T21:35:34.061Z,1505770534.061 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2017-09-18T21:35:34.062Z,1505770534.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2017-09-18T21:35:34.062Z,1505770534.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2017-09-18T21:35:34.062Z,1505770534.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2017-09-18T21:35:34.062Z,1505770534.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2017-09-18T21:35:34.093Z,1505770534.093 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2017-09-18T21:35:34.165Z,1505770534.165 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-09-18T21:35:34.165Z,1505770534.165 [CTD_Seabird](INFO): Powering down
2017-09-18T21:35:34.245Z,1505770534.245 [MissionManager](DEBUG):
2017-09-18T21:35:34.254Z,1505770534.254 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2017-09-18T21:35:34.445Z,1505770534.445 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2017-09-18T21:35:34.447Z,1505770534.447 [Default:A.Wait](DEBUG): Construct Wait.
2017-09-18T21:35:34.449Z,1505770534.449 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2017-09-18T21:35:34.507Z,1505770534.507 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2017-09-18T21:35:34.538Z,1505770534.538 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2017-09-18T21:35:34.546Z,1505770534.546 [Default:E.Execute](DEBUG): Construct Execute.
2017-09-18T21:35:34.667Z,1505770534.667 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn 300
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2017-09-18T21:35:34.673Z,1505770534.673 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,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-09-18T21:35:34.787Z,1505770534.787 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2017-09-18T21:35:34.816Z,1505770534.816 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2017-09-18T21:35:34.920Z,1505770534.920 [DAT](INFO): Powering up
2017-09-18T21:35:34.920Z,1505770534.920 [DAT](DEBUG): Initializing DAT.
2017-09-18T21:35:34.925Z,1505770534.925 [Rowe_600LCM](INFO): LCM OK
2017-09-18T21:35:34.925Z,1505770534.925 [Rowe_600LCM](INFO): Powering up
2017-09-18T21:35:35.088Z,1505770535.088 [DepthRateCalculator](ERROR): Depth measurement is not active
2017-09-18T21:35:35.216Z,1505770535.216 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:35.476Z,1505770535.476 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:35.614Z,1505770535.614 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-09-18T21:35:35.620Z,1505770535.620 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-09-18T21:35:35.652Z,1505770535.652 [ElevatorServo](DEBUG): Initializing EZServoServo.
2017-09-18T21:35:35.660Z,1505770535.660 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2017-09-18T21:35:35.675Z,1505770535.675 [MassServo](DEBUG): Initializing EZServoServo.
2017-09-18T21:35:35.684Z,1505770535.684 [MassServo](DEBUG): Initializing MassServo.
2017-09-18T21:35:35.707Z,1505770535.707 [RudderServo](DEBUG): Initializing EZServoServo.
2017-09-18T21:35:35.716Z,1505770535.716 [RudderServo](DEBUG): Initializing RudderServo.
2017-09-18T21:35:35.731Z,1505770535.731 [ThrusterServo](DEBUG): Initializing EZServoServo.
2017-09-18T21:35:35.737Z,1505770535.737 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2017-09-18T21:35:36.152Z,1505770536.152 [NAL9602](INFO): Powering up NAL9602
2017-09-18T21:35:36.208Z,1505770536.208 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:36.217Z,1505770536.217 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:36.557Z,1505770536.557 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2017-09-18T21:35:36.557Z,1505770536.557 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2017-09-18T21:35:36.558Z,1505770536.558 [BuoyancyServo] Communications Fault, FailCount= 1
2017-09-18T21:35:36.558Z,1505770536.558 [BuoyancyServo](ERROR): Communications Fault
2017-09-18T21:35:36.770Z,1505770536.770 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2017-09-18T21:35:36.849Z,1505770536.849 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:36.854Z,1505770536.854 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:36.876Z,1505770536.876 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-09-18T21:35:36.876Z,1505770536.876 [BuoyancyServo](INFO): Powering down
2017-09-18T21:35:37.235Z,1505770537.235 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:37.236Z,1505770537.236 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:37.639Z,1505770537.639 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:37.641Z,1505770537.641 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:38.100Z,1505770538.100 [Aanderaa_O2](INFO): Powering down
2017-09-18T21:35:38.318Z,1505770538.318 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:38.320Z,1505770538.320 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:38.570Z,1505770538.570 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-09-18T21:35:38.599Z,1505770538.599 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:38.621Z,1505770538.621 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-09-18T21:35:38.720Z,1505770538.720 [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-09-18T21:35:39.235Z,1505770539.235 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2017-09-18T21:35:39.235Z,1505770539.235 [BuoyancyServo] No Fault, FailCount= 1
2017-09-18T21:35:39.455Z,1505770539.455 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-09-18T21:35:39.456Z,1505770539.456 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-09-18T21:35:39.659Z,1505770539.659 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-09-18T21:35:39.660Z,1505770539.660 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-09-18T21:35:39.661Z,1505770539.661 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-09-18T21:35:40.291Z,1505770540.291 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2017-09-18T21:35:40.291Z,1505770540.291 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2017-09-18T21:35:40.291Z,1505770540.291 [BuoyancyServo] Communications Fault, FailCount= 2
2017-09-18T21:35:40.292Z,1505770540.292 [BuoyancyServo](ERROR): Communications Fault
2017-09-18T21:35:40.370Z,1505770540.369 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2017-09-18T21:35:40.559Z,1505770540.559 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-09-18T21:35:40.568Z,1505770540.568 [BuoyancyServo](INFO): Powering down
2017-09-18T21:35:42.528Z,1505770542.528 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2017-09-18T21:35:42.528Z,1505770542.528 [BuoyancyServo] No Fault, FailCount= 2
2017-09-18T21:35:42.896Z,1505770542.896 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-09-18T21:35:42.897Z,1505770542.897 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-09-18T21:35:47.220Z,1505770547.220 [NAL9602](INFO): NAL9602 initialized
2017-09-18T21:35:47.243Z,1505770547.243 [DAT](DEBUG):
Teledyne Benthos DAT-900 Series
MF Frequency Band
Directional Acoustic Transponder version 8.12.5
Sep 18 2017 21:32:25
WARNING: battery low
Features enabled [Bearing]
CONNECT
2017-09-18T21:35:47.243Z,1505770547.243 [DAT](INFO): Got CONNECT
2017-09-18T21:35:47.254Z,1505770547.254 [DAT](INFO): entering command mode
2017-09-18T21:35:47.674Z,1505770547.674 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-18T21:35:48.056Z,1505770548.056 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-18T21:35:48.453Z,1505770548.453 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-18T21:35:48.866Z,1505770548.866 [DAT](DEBUG): checking for command mode acknowledgment
2017-09-18T21:35:48.867Z,1505770548.867 [DAT](DEBUG): read user prompt 1: user:1>
2017-09-18T21:35:48.867Z,1505770548.867 [DAT](INFO): command mode acknowledged
2017-09-18T21:35:49.241Z,1505770549.241 [DAT](INFO): setting local address to 2
2017-09-18T21:35:49.642Z,1505770549.642 [DAT](DEBUG): checking for local address setting acknowledgment
2017-09-18T21:35:49.643Z,1505770549.643 [DAT](INFO): set local address to 2
2017-09-18T21:35:50.056Z,1505770550.056 [DAT](DEBUG): read user prompt 2: user:2>
2017-09-18T21:35:50.471Z,1505770550.471 [BPC1](FAULT): Failed to initialize
2017-09-18T21:35:50.471Z,1505770550.471 [BPC1] Communications Fault, FailCount= 1
2017-09-18T21:35:50.472Z,1505770550.472 [BPC1](ERROR): Communications Fault
2017-09-18T21:35:50.581Z,1505770550.581 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:35:51.785Z,1505770551.785 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:35:51.785Z,1505770551.785 [BPC1] No Fault, FailCount= 1
2017-09-18T21:35:56.666Z,1505770556.666 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:35:57.413Z,1505770557.413 [SBIT](IMPORTANT): Beginning Startup BIT
2017-09-18T21:35:57.418Z,1505770557.418 [CBIT](IMPORTANT): Beginning ground fault scan
2017-09-18T21:35:57.459Z,1505770557.459 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:36:07.746Z,1505770567.746 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.005442
CHAN A1 (24V): 0.121875
CHAN A2 (12V): -0.001405
CHAN A3 (5V): 4.753929
CHAN B0 (3.3V): 0.001483
CHAN B1 (3.15aV): 0.000016
CHAN B2 (3.15bV): -0.000691
CHAN B3 (GND): -0.000706
OPEN: -0.000321
Full Scale Calc: 4.765 mA, -1.589 mA
2017-09-18T21:36:08.048Z,1505770568.048 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:36:08.048Z,1505770568.048 [BPC1] Communications Fault, FailCount= 2
2017-09-18T21:36:08.049Z,1505770568.049 [BPC1](ERROR): Communications Fault
2017-09-18T21:36:08.131Z,1505770568.131 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:36:09.324Z,1505770569.324 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:36:09.324Z,1505770569.324 [BPC1] No Fault, FailCount= 2
2017-09-18T21:36:25.512Z,1505770585.512 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:36:25.512Z,1505770585.512 [BPC1] Communications Fault, FailCount= 3
2017-09-18T21:36:25.512Z,1505770585.512 [BPC1](ERROR): Communications Fault
2017-09-18T21:36:25.618Z,1505770585.618 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:36:26.800Z,1505770586.800 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:36:26.800Z,1505770586.800 [BPC1] No Fault, FailCount= 3
2017-09-18T21:36:42.872Z,1505770602.872 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:36:42.872Z,1505770602.872 [BPC1] Communications Fault, FailCount= 4
2017-09-18T21:36:42.872Z,1505770602.872 [BPC1](ERROR): Communications Fault
2017-09-18T21:36:42.961Z,1505770602.961 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:36:44.192Z,1505770604.192 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:36:44.200Z,1505770604.200 [BPC1] No Fault, FailCount= 4
2017-09-18T21:36:51.326Z,1505770611.326 [SBIT](IMPORTANT): SBIT PASSED
2017-09-18T21:36:51.703Z,1505770611.703 [MissionManager](IMPORTANT): Started mission Startup
2017-09-18T21:36:51.703Z,1505770611.703 [Startup] Running Loop=1
2017-09-18T21:36:51.703Z,1505770611.703 [Startup](DEBUG): Aggregate::initialize Startup
2017-09-18T21:36:51.703Z,1505770611.703 [Startup:A.GoToSurface] Running Loop=1
2017-09-18T21:36:51.703Z,1505770611.703 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-09-18T21:36:51.712Z,1505770611.712 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-09-18T21:36:51.713Z,1505770611.713 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-09-18T21:36:51.713Z,1505770611.713 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-09-18T21:36:51.714Z,1505770611.714 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-09-18T21:36:51.714Z,1505770611.714 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-09-18T21:36:51.738Z,1505770611.738 [Startup:StartupSatComms] Running Loop=1
2017-09-18T21:36:51.738Z,1505770611.738 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2017-09-18T21:36:51.738Z,1505770611.738 [Startup:StartupSatComms:A] Running Loop=1
2017-09-18T21:36:52.109Z,1505770612.109 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2017-09-18T21:37:00.450Z,1505770620.450 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:37:00.450Z,1505770620.450 [BPC1] Communications Fault, FailCount= 5
2017-09-18T21:37:00.450Z,1505770620.450 [BPC1](ERROR): Communications Fault
2017-09-18T21:37:00.539Z,1505770620.539 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:37:01.722Z,1505770621.722 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:37:01.722Z,1505770621.722 [BPC1] No Fault, FailCount= 5
2017-09-18T21:37:19.965Z,1505770639.965 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:37:19.965Z,1505770639.965 [BPC1] Communications Fault, FailCount= 6
2017-09-18T21:37:19.965Z,1505770639.965 [BPC1](ERROR): Communications Fault
2017-09-18T21:37:19.992Z,1505770639.992 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:37:20.816Z,1505770640.816 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003606
2017-09-18T21:37:20.935Z,1505770640.935 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:37:20.935Z,1505770640.935 [BPC1] No Fault, FailCount= 6
2017-09-18T21:37:37.654Z,1505770657.654 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:37:37.654Z,1505770657.654 [BPC1] Communications Fault, FailCount= 7
2017-09-18T21:37:37.654Z,1505770657.654 [BPC1](ERROR): Communications Fault
2017-09-18T21:37:37.697Z,1505770657.697 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:37:38.883Z,1505770658.883 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:37:38.883Z,1505770658.883 [BPC1] No Fault, FailCount= 7
2017-09-18T21:37:52.071Z,1505770672.071 [Startup:StartupSatComms:A](INFO): Timed out from 2017-09-18T21:36:51.7Z
2017-09-18T21:37:52.071Z,1505770672.071 [Startup:StartupSatComms:A] Stopped
2017-09-18T21:37:52.071Z,1505770672.071 [Startup:StartupSatComms:B] Running Loop=1
2017-09-18T21:37:52.460Z,1505770672.460 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-09-18T21:37:57.258Z,1505770677.258 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:37:57.258Z,1505770677.258 [BPC1] Communications Fault, FailCount= 8
2017-09-18T21:37:57.258Z,1505770677.258 [BPC1](ERROR): Communications Fault
2017-09-18T21:37:57.324Z,1505770677.324 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:37:57.365Z,1505770677.365 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170918T191351/Courier0048.lzma
2017-09-18T21:37:58.144Z,1505770678.144 [DataOverHttps](INFO): Moved sent file to Logs/20170918T191351/Courier0048.lzma.bak
2017-09-18T21:37:58.144Z,1505770678.144 [DataOverHttps](INFO): SBD MOMSN=5094849
2017-09-18T21:37:58.333Z,1505770678.333 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:37:58.333Z,1505770678.333 [BPC1] No Fault, FailCount= 8
2017-09-18T21:38:07.852Z,1505770687.852 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170918T212948/Courier0000.lzma
2017-09-18T21:38:08.641Z,1505770688.641 [DataOverHttps](INFO): Moved sent file to Logs/20170918T212948/Courier0000.lzma.bak
2017-09-18T21:38:08.650Z,1505770688.650 [DataOverHttps](INFO): SBD MOMSN=5094851
2017-09-18T21:38:09.424Z,1505770689.424 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:38:10.217Z,1505770690.217 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:38:11.011Z,1505770691.011 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:38:11.803Z,1505770691.803 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:38:20.624Z,1505770700.624 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:38:20.624Z,1505770700.624 [BPC1] Communications Fault, FailCount= 9
2017-09-18T21:38:20.625Z,1505770700.625 [BPC1](ERROR): Communications Fault
2017-09-18T21:38:20.682Z,1505770700.682 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:38:21.594Z,1505770701.594 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:38:21.594Z,1505770701.594 [BPC1] No Fault, FailCount= 9
2017-09-18T21:38:28.181Z,1505770708.181 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170918T191351/Express0049.lzma
2017-09-18T21:38:28.924Z,1505770708.924 [DataOverHttps](INFO): Moved sent file to Logs/20170918T191351/Express0049.lzma.bak
2017-09-18T21:38:28.925Z,1505770708.925 [DataOverHttps](INFO): SBD MOMSN=5094854
2017-09-18T21:38:34.224Z,1505770714.224 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-18T21:38:34.225Z,1505770714.225 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2017-09-18T21:38:34.225Z,1505770714.225 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-09-18T21:38:34.235Z,1505770714.235 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-09-18T21:38:34.235Z,1505770714.235 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2017-09-18T21:38:34.235Z,1505770714.235 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-09-18T21:38:34.287Z,1505770714.287 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-09-18T21:38:34.288Z,1505770714.288 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-09-18T21:38:34.564Z,1505770714.564 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-09-18T21:38:34.564Z,1505770714.564 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2017-09-18T21:38:34.565Z,1505770714.565 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-09-18T21:38:34.565Z,1505770714.565 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2017-09-18T21:38:34.932Z,1505770714.932 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-09-18T21:38:34.932Z,1505770714.932 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-09-18T21:38:34.933Z,1505770714.933 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-09-18T21:38:34.933Z,1505770714.933 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-09-18T21:38:34.934Z,1505770714.934 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-09-18T21:38:34.934Z,1505770714.934 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-09-18T21:38:38.978Z,1505770718.978 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170918T212948/Express0001.lzma
2017-09-18T21:38:39.737Z,1505770719.737 [DataOverHttps](INFO): Moved sent file to Logs/20170918T212948/Express0001.lzma.bak
2017-09-18T21:38:39.738Z,1505770719.738 [DataOverHttps](INFO): SBD MOMSN=5094856
2017-09-18T21:38:44.350Z,1505770724.350 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:38:44.350Z,1505770724.350 [BPC1] Communications Fault, FailCount= 10
2017-09-18T21:38:44.350Z,1505770724.350 [BPC1](ERROR): Communications Fault
2017-09-18T21:38:44.407Z,1505770724.407 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:38:44.407Z,1505770724.407 [CBIT](CRITICAL): Communications Fault in component: BPC1
2017-09-18T21:38:44.549Z,1505770724.549 [CommandLine](FAULT): Scheduling is paused
2017-09-18T21:38:44.549Z,1505770724.549 [CBIT](INFO): Critical error at 20170918T213844
2017-09-18T21:38:44.549Z,1505770724.549 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2017-09-18T21:38:49.656Z,1505770729.656 [DataOverHttps](INFO): Sending 618 bytes from file Logs/20170918T213513/Express0001.lzma
2017-09-18T21:39:00.650Z,1505770740.650 [DataOverHttps](INFO): Moved sent file to Logs/20170918T213513/Express0001.lzma.bak
2017-09-18T21:39:00.650Z,1505770740.650 [DataOverHttps](INFO): SBD MOMSN=5094858
2017-09-18T21:39:00.711Z,1505770740.711 [Startup:StartupSatComms:B](INFO): Timed out from 2017-09-18T21:37:52.1Z
2017-09-18T21:39:00.711Z,1505770740.711 [Startup:StartupSatComms:B] Stopped
2017-09-18T21:39:00.712Z,1505770740.712 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2017-09-18T21:39:00.712Z,1505770740.712 [Startup:StartupSatComms] Stopped
2017-09-18T21:39:00.712Z,1505770740.712 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2017-09-18T21:39:00.713Z,1505770740.713 [Startup](INFO): Completed Startup
2017-09-18T21:39:00.713Z,1505770740.713 [MissionManager](INFO): Startup is completed.
2017-09-18T21:39:00.713Z,1505770740.713 [MissionManager](INFO): Uninitializing Mission Startup
2017-09-18T21:39:00.713Z,1505770740.713 [Startup] Stopped
2017-09-18T21:39:00.714Z,1505770740.714 [Startup](DEBUG): Aggregate::uninitialize Startup
2017-09-18T21:39:00.714Z,1505770740.714 [Startup:A.GoToSurface] Stopped
2017-09-18T21:39:00.714Z,1505770740.714 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-09-18T21:39:00.852Z,1505770740.852 [MissionManager](IMPORTANT): Started mission Default
2017-09-18T21:39:00.852Z,1505770740.852 [Default] Running Loop=1
2017-09-18T21:39:00.852Z,1505770740.852 [Default](DEBUG): Aggregate::initialize Default
2017-09-18T21:39:00.852Z,1505770740.852 [Default:B.GoToSurface] Running Loop=1
2017-09-18T21:39:00.852Z,1505770740.852 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-09-18T21:39:00.853Z,1505770740.853 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-09-18T21:39:00.853Z,1505770740.853 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-09-18T21:39:00.853Z,1505770740.853 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-09-18T21:39:00.854Z,1505770740.854 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-09-18T21:39:00.854Z,1505770740.854 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-09-18T21:39:00.854Z,1505770740.854 [Default:A.Wait] Running Loop=1
2017-09-18T21:39:00.854Z,1505770740.854 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-09-18T21:39:14.100Z,1505770754.100 [Default:A.Wait](INFO): Done Waiting.
2017-09-18T21:39:14.100Z,1505770754.100 [Default:A.Wait] Stopped
2017-09-18T21:39:14.100Z,1505770754.100 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-09-18T21:39:14.513Z,1505770754.513 [Default:CheckIn] Running Loop=1
2017-09-18T21:39:14.513Z,1505770754.513 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-09-18T21:39:14.513Z,1505770754.513 [Default:CheckIn:Read_GPS] Running Loop=1
2017-09-18T21:39:14.915Z,1505770754.915 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2017-09-18T21:39:53.416Z,1505770793.416 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:39:54.209Z,1505770794.209 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:39:54.638Z,1505770794.638 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:39:55.432Z,1505770795.432 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:39:56.225Z,1505770796.225 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:39:56.629Z,1505770796.629 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:40:50.111Z,1505770850.111 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2017-09-18T21:40:51.315Z,1505770851.315 [NAL9602](INFO): GPS fix at 20170918T213745: (36.802698, -121.787973)
2017-09-18T21:40:51.403Z,1505770851.403 [Default:CheckIn:Read_GPS] Stopped
2017-09-18T21:40:51.403Z,1505770851.403 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-09-18T21:40:51.833Z,1505770851.833 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-09-18T21:40:57.419Z,1505770857.419 [DataOverHttps](INFO): Sending 274 bytes from file Logs/20170918T213513/Courier0004.lzma
2017-09-18T21:40:57.819Z,1505770857.819 [NAL9602](INFO): Powering down
2017-09-18T21:40:58.204Z,1505770858.204 [DataOverHttps](INFO): Moved sent file to Logs/20170918T213513/Courier0004.lzma.bak
2017-09-18T21:40:58.204Z,1505770858.204 [DataOverHttps](INFO): SBD MOMSN=5094872
2017-09-18T21:41:10.807Z,1505770870.807 [DataOverHttps](INFO): Sending 332 bytes from file Logs/20170918T213513/Express0005.lzma
2017-09-18T21:41:11.582Z,1505770871.582 [DataOverHttps](INFO): Moved sent file to Logs/20170918T213513/Express0005.lzma.bak
2017-09-18T21:41:11.582Z,1505770871.582 [DataOverHttps](INFO): SBD MOMSN=5094876
2017-09-18T21:41:12.750Z,1505770872.750 [Default:CheckIn:Read_Iridium] Stopped
2017-09-18T21:41:12.750Z,1505770872.750 [Default:CheckIn:C.Wait] Running Loop=1
2017-09-18T21:41:12.750Z,1505770872.750 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-09-18T21:41:27.409Z,1505770887.409 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:28.202Z,1505770888.202 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:28.619Z,1505770888.619 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:29.412Z,1505770889.412 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:30.205Z,1505770890.205 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:30.618Z,1505770890.618 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:31.411Z,1505770891.411 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:32.205Z,1505770892.205 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:32.617Z,1505770892.617 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:33.411Z,1505770893.411 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:34.204Z,1505770894.204 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:34.628Z,1505770894.628 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:35.422Z,1505770895.422 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:36.215Z,1505770896.215 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:36.635Z,1505770896.635 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:37.429Z,1505770897.429 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:38.222Z,1505770898.222 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:41:38.626Z,1505770898.626 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:43:44.421Z,1505771024.421 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:43:44.421Z,1505771024.421 [BPC1] No Fault, FailCount= 10
2017-09-18T21:43:55.991Z,1505771035.991 [BPC1](INFO): Failure count cleared after critical for BPC1
2017-09-18T21:44:13.563Z,1505771053.563 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:44:13.563Z,1505771053.563 [BPC1] Communications Fault, FailCount= 1
2017-09-18T21:44:13.563Z,1505771053.563 [BPC1](ERROR): Communications Fault
2017-09-18T21:44:13.615Z,1505771053.615 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:44:17.593Z,1505771057.593 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:44:17.597Z,1505771057.597 [BPC1] No Fault, FailCount= 1
2017-09-18T21:44:33.898Z,1505771073.898 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:44:33.898Z,1505771073.898 [BPC1] Communications Fault, FailCount= 2
2017-09-18T21:44:33.898Z,1505771073.898 [BPC1](ERROR): Communications Fault
2017-09-18T21:44:33.928Z,1505771073.928 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:44:35.157Z,1505771075.157 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:44:35.157Z,1505771075.157 [BPC1] No Fault, FailCount= 2
2017-09-18T21:44:45.398Z,1505771085.398 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:46.191Z,1505771086.191 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:46.600Z,1505771086.600 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:47.393Z,1505771087.393 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:48.188Z,1505771088.188 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:48.603Z,1505771088.603 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:49.396Z,1505771089.396 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:50.190Z,1505771090.190 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:50.602Z,1505771090.602 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:51.396Z,1505771091.396 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:51.498Z,1505771091.498 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:44:51.498Z,1505771091.498 [BPC1] Communications Fault, FailCount= 3
2017-09-18T21:44:51.498Z,1505771091.498 [BPC1](ERROR): Communications Fault
2017-09-18T21:44:51.538Z,1505771091.538 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:44:52.190Z,1505771092.190 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:52.605Z,1505771092.605 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:52.758Z,1505771092.758 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:44:52.758Z,1505771092.758 [BPC1] No Fault, FailCount= 3
2017-09-18T21:44:53.399Z,1505771093.399 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:54.192Z,1505771094.192 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:54.608Z,1505771094.608 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:55.402Z,1505771095.402 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:56.197Z,1505771096.197 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:56.612Z,1505771096.612 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:57.405Z,1505771097.405 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:58.198Z,1505771098.198 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:58.615Z,1505771098.615 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:44:59.408Z,1505771099.408 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:45:00.201Z,1505771100.201 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:45:00.606Z,1505771100.606 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent.
2017-09-18T21:45:09.111Z,1505771109.111 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:45:09.112Z,1505771109.112 [BPC1] Communications Fault, FailCount= 4
2017-09-18T21:45:09.112Z,1505771109.112 [BPC1](ERROR): Communications Fault
2017-09-18T21:45:09.251Z,1505771109.251 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:45:10.392Z,1505771110.392 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:45:10.392Z,1505771110.392 [BPC1] No Fault, FailCount= 4
2017-09-18T21:45:26.605Z,1505771126.605 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:45:26.605Z,1505771126.605 [BPC1] Communications Fault, FailCount= 5
2017-09-18T21:45:26.605Z,1505771126.605 [BPC1](ERROR): Communications Fault
2017-09-18T21:45:26.709Z,1505771126.709 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:45:27.914Z,1505771127.914 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:45:27.914Z,1505771127.914 [BPC1] No Fault, FailCount= 5
2017-09-18T21:45:33.909Z,1505771133.909 [CBIT](DEBUG): EFC running - data check-sum false
2017-09-18T21:45:44.201Z,1505771144.201 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:45:44.202Z,1505771144.202 [BPC1] Communications Fault, FailCount= 6
2017-09-18T21:45:44.202Z,1505771144.202 [BPC1](ERROR): Communications Fault
2017-09-18T21:45:44.324Z,1505771144.324 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:45:45.474Z,1505771145.474 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:45:45.474Z,1505771145.474 [BPC1] No Fault, FailCount= 6
2017-09-18T21:46:01.800Z,1505771161.800 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:46:01.800Z,1505771161.800 [BPC1] Communications Fault, FailCount= 7
2017-09-18T21:46:01.800Z,1505771161.800 [BPC1](ERROR): Communications Fault
2017-09-18T21:46:01.919Z,1505771161.919 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:46:03.116Z,1505771163.116 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:46:03.116Z,1505771163.116 [BPC1] No Fault, FailCount= 7
2017-09-18T21:46:13.080Z,1505771173.080 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-09-18T21:46:13.081Z,1505771173.081 [Default:CheckIn:C.Wait] Stopped
2017-09-18T21:46:13.081Z,1505771173.081 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-09-18T21:46:13.081Z,1505771173.081 [Default:CheckIn:D] Running Loop=1
2017-09-18T21:46:13.508Z,1505771173.508 [Default:CheckIn:D] Stopped
2017-09-18T21:46:13.508Z,1505771173.508 [Default:CheckIn:E] Running Loop=1
2017-09-18T21:46:13.886Z,1505771173.886 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.210887 min
2017-09-18T21:46:13.898Z,1505771173.898 [Default:CheckIn:E] Stopped
2017-09-18T21:46:13.898Z,1505771173.898 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-09-18T21:46:13.898Z,1505771173.898 [Default:CheckIn] Stopped
2017-09-18T21:46:13.898Z,1505771173.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-09-18T21:46:13.898Z,1505771173.898 [Default:CheckIn](INFO): Running loop #2
2017-09-18T21:46:13.898Z,1505771173.898 [Default:CheckIn] Running Loop=2
2017-09-18T21:46:13.899Z,1505771173.899 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-09-18T21:46:13.899Z,1505771173.899 [Default:CheckIn:Read_GPS] Running Loop=1
2017-09-18T21:46:14.596Z,1505771174.596 [NAL9602](INFO): Powering up
2017-09-18T21:46:23.292Z,1505771183.292 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:46:23.292Z,1505771183.292 [BPC1] Communications Fault, FailCount= 8
2017-09-18T21:46:23.292Z,1505771183.292 [BPC1](ERROR): Communications Fault
2017-09-18T21:46:23.425Z,1505771183.425 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:46:24.457Z,1505771184.457 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:46:24.457Z,1505771184.457 [BPC1] No Fault, FailCount= 8
2017-09-18T21:46:25.445Z,1505771185.445 [NAL9602](INFO): NAL9602 initialized
2017-09-18T21:46:40.724Z,1505771200.724 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:46:40.724Z,1505771200.724 [BPC1] Communications Fault, FailCount= 9
2017-09-18T21:46:40.724Z,1505771200.724 [BPC1](ERROR): Communications Fault
2017-09-18T21:46:40.834Z,1505771200.834 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:46:42.076Z,1505771202.076 [CBIT](INFO): Clearing failed state for component BPC1
2017-09-18T21:46:42.076Z,1505771202.076 [BPC1] No Fault, FailCount= 9
2017-09-18T21:46:57.444Z,1505771217.444 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2017-09-18T21:46:57.522Z,1505771217.522 [NAL9602](FAULT): received:
+CSQ:0
OK
2017-09-18T21:46:57.522Z,1505771217.522 [NAL9602] Data Fault, FailCount= 1
2017-09-18T21:46:57.522Z,1505771217.522 [NAL9602](ERROR): Data Fault
2017-09-18T21:46:57.670Z,1505771217.670 [CBIT](ERROR): Data Fault in component: NAL9602
2017-09-18T21:46:57.844Z,1505771217.844 [NAL9602](INFO): Powering down
2017-09-18T21:46:58.275Z,1505771218.275 [BPC1](ERROR): Failed to receive battery data
2017-09-18T21:46:58.275Z,1505771218.275 [BPC1] Communications Fault, FailCount= 10
2017-09-18T21:46:58.275Z,1505771218.275 [BPC1](ERROR): Communications Fault
2017-09-18T21:46:58.334Z,1505771218.334 [CBIT](ERROR): Communications Fault in component: BPC1
2017-09-18T21:46:58.335Z,1505771218.335 [CBIT](CRITICAL): Communications Fault in component: BPC1
2017-09-18T21:46:58.722Z,1505771218.722 [CBIT](INFO): Critical error at 20170918T214658
2017-09-18T21:46:58.728Z,1505771218.728 [CBIT](INFO): Clearing failed state for component NAL9602
2017-09-18T21:46:58.728Z,1505771218.728 [NAL9602] No Fault, FailCount= 1
2017-09-18T21:47:03.059Z,1505771223.059 [NAL9602](INFO): Powering up NAL9602
2017-09-18T21:47:14.242Z,1505771234.242 [NAL9602](INFO): NAL9602 initialized
2017-09-18T21:47:22.756Z,1505771242.756 [CommandLine](IMPORTANT): got command restart application
2017-09-18T21:47:24.366Z,1505771244.366 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:24.366Z,1505771244.366 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:24.549Z,1505771244.549 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2017-09-18T21:47:24.549Z,1505771244.549 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:24.550Z,1505771244.550 [CommandLine](INFO): Join timeout helper Thread ID is 912
2017-09-18T21:47:24.557Z,1505771244.557 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2017-09-18T21:47:24.557Z,1505771244.557 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:24.557Z,1505771244.557 [NavChartDb](INFO): Join timeout helper Thread ID is 913
2017-09-18T21:47:24.901Z,1505771244.901 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:24.902Z,1505771244.902 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:24.913Z,1505771244.913 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2017-09-18T21:47:24.913Z,1505771244.913 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:24.914Z,1505771244.914 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 914
2017-09-18T21:47:25.058Z,1505771245.058 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:25.058Z,1505771245.058 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-09-18T21:47:25.162Z,1505771245.162 [Rowe_600LCM](INFO): Powering down
2017-09-18T21:47:25.164Z,1505771245.164 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.178Z,1505771245.178 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2017-09-18T21:47:25.178Z,1505771245.178 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.178Z,1505771245.178 [Radio_Surface](INFO): Join timeout helper Thread ID is 916
2017-09-18T21:47:25.354Z,1505771245.354 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:25.355Z,1505771245.355 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.366Z,1505771245.366 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2017-09-18T21:47:25.366Z,1505771245.366 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.367Z,1505771245.367 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 917
2017-09-18T21:47:25.747Z,1505771245.747 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:25.747Z,1505771245.747 [WetLabsBB2FL](INFO): Powering down
2017-09-18T21:47:25.748Z,1505771245.748 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.756Z,1505771245.756 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2017-09-18T21:47:25.756Z,1505771245.756 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.756Z,1505771245.756 [CTD_Seabird](INFO): Join timeout helper Thread ID is 918
2017-09-18T21:47:25.875Z,1505771245.875 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:25.965Z,1505771245.965 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-09-18T21:47:25.965Z,1505771245.965 [CTD_Seabird](INFO): Powering down
2017-09-18T21:47:25.967Z,1505771245.967 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.972Z,1505771245.972 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2017-09-18T21:47:25.972Z,1505771245.972 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:25.973Z,1505771245.973 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 920
2017-09-18T21:47:26.156Z,1505771246.156 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:26.156Z,1505771246.156 [CTD_NeilBrown](INFO): Powering down
2017-09-18T21:47:26.157Z,1505771246.157 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.176Z,1505771246.176 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2017-09-18T21:47:26.176Z,1505771246.176 [logger ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.177Z,1505771246.177 [logger](INFO): Join timeout helper Thread ID is 921
2017-09-18T21:47:26.220Z,1505771246.220 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:26.220Z,1505771246.220 [logger ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.232Z,1505771246.232 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2017-09-18T21:47:26.232Z,1505771246.232 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.233Z,1505771246.233 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2017-09-18T21:47:26.233Z,1505771246.233 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.233Z,1505771246.233 [controlThread](INFO): Join timeout helper Thread ID is 922
2017-09-18T21:47:26.436Z,1505771246.436 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2017-09-18T21:47:26.436Z,1505771246.436 [controlThread](DEBUG): Uninitializing ControlThread
2017-09-18T21:47:26.437Z,1505771246.437 [Aanderaa_O2](INFO): Powering down
2017-09-18T21:47:26.440Z,1505771246.440 [NAL9602](INFO): Powering down
2017-09-18T21:47:26.442Z,1505771246.442 [DAT](INFO): Powering down
2017-09-18T21:47:26.564Z,1505771246.564 [PNI_TCM](INFO): Powering down
2017-09-18T21:47:26.653Z,1505771246.653 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-09-18T21:47:26.655Z,1505771246.655 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2017-09-18T21:47:26.655Z,1505771246.655 [MissionManager](INFO): Uninitializing Mission Default
2017-09-18T21:47:26.655Z,1505771246.655 [Default] Stopped
2017-09-18T21:47:26.656Z,1505771246.656 [Default](DEBUG): Aggregate::uninitialize Default
2017-09-18T21:47:26.656Z,1505771246.656 [Default:B.GoToSurface] Stopped
2017-09-18T21:47:26.656Z,1505771246.656 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-09-18T21:47:26.656Z,1505771246.656 [Default:CheckIn] Stopped
2017-09-18T21:47:26.656Z,1505771246.656 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-09-18T21:47:26.656Z,1505771246.656 [Default:CheckIn:Read_GPS] Stopped
2017-09-18T21:47:26.660Z,1505771246.660 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2017-09-18T21:47:26.661Z,1505771246.661 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2017-09-18T21:47:26.661Z,1505771246.661 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2017-09-18T21:47:26.661Z,1505771246.661 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2017-09-18T21:47:26.661Z,1505771246.661 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-09-18T21:47:26.662Z,1505771246.662 [BuoyancyServo](INFO): Powering down
2017-09-18T21:47:26.676Z,1505771246.676 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2017-09-18T21:47:26.676Z,1505771246.676 [ElevatorServo](INFO): Powering down
2017-09-18T21:47:26.677Z,1505771246.677 [MassServo](DEBUG): Uninitialize Mass Servo.
2017-09-18T21:47:26.677Z,1505771246.677 [MassServo](INFO): Powering down
2017-09-18T21:47:26.678Z,1505771246.678 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2017-09-18T21:47:26.679Z,1505771246.679 [RudderServo](INFO): Powering down
2017-09-18T21:47:26.680Z,1505771246.680 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2017-09-18T21:47:26.680Z,1505771246.680 [ThrusterServo](INFO): Powering down
2017-09-18T21:47:26.681Z,1505771246.681 [SBIT](DEBUG): Uninitialize SBIT Component.
2017-09-18T21:47:26.681Z,1505771246.681 [IBIT](DEBUG): Uninitialize IBIT Component.
2017-09-18T21:47:26.682Z,1505771246.682 [CBIT](DEBUG): Uninitialize CBIT Component.
2017-09-18T21:47:26.683Z,1505771246.683 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.874Z,1505771246.874 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.881Z,1505771246.881 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:26.884Z,1505771246.884 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:27.009Z,1505771247.009 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:27.025Z,1505771247.025 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:27.090Z,1505771247.090 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-09-18T21:47:27.191Z,1505771247.191 [logger ThreadHandler](INFO): Thread cancelled.