2018-03-14T23:22:12.447Z,1521069732.447 [Supervisor](DEBUG): Initializing supervisor.
2018-03-14T23:22:12.451Z,1521069732.451 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-03-14T23:22:12.452Z,1521069732.452 [SyncHandler](INFO): Protected caller Thread ID is 1186
2018-03-14T23:22:12.452Z,1521069732.452 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-03-14T23:22:12.453Z,1521069732.453 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-03-14T23:22:12.453Z,1521069732.453 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1187
2018-03-14T23:22:12.456Z,1521069732.456 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-03-14T23:22:12.468Z,1521069732.468 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-03-14T23:22:12.469Z,1521069732.469 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-03-14T23:22:12.469Z,1521069732.469 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1188
2018-03-14T23:22:12.470Z,1521069732.470 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-03-14T23:22:12.471Z,1521069732.471 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-03-14T23:22:12.471Z,1521069732.471 [logger ThreadHandler](INFO): Protected caller Thread ID is 1189
2018-03-14T23:22:12.473Z,1521069732.473 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-03-14T23:22:12.474Z,1521069732.474 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-03-14T23:22:12.476Z,1521069732.476 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-03-14T23:22:12.774Z,1521069732.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-03-14T23:22:12.775Z,1521069732.775 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-03-14T23:22:12.961Z,1521069732.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-03-14T23:22:12.961Z,1521069732.961 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-03-14T23:22:13.229Z,1521069733.229 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-03-14T23:22:13.229Z,1521069733.229 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-03-14T23:22:13.366Z,1521069733.366 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-03-14T23:22:13.366Z,1521069733.366 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-03-14T23:22:13.461Z,1521069733.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-03-14T23:22:13.462Z,1521069733.462 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-03-14T23:22:13.888Z,1521069733.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-03-14T23:22:13.889Z,1521069733.889 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-03-14T23:22:14.210Z,1521069734.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-03-14T23:22:14.211Z,1521069734.211 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-03-14T23:22:14.619Z,1521069734.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-03-14T23:22:14.619Z,1521069734.619 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-03-14T23:22:14.719Z,1521069734.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-03-14T23:22:14.720Z,1521069734.720 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-03-14T23:22:14.814Z,1521069734.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-03-14T23:22:14.815Z,1521069734.815 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-03-14T23:22:15.011Z,1521069735.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-03-14T23:22:15.011Z,1521069735.011 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-03-14T23:22:15.207Z,1521069735.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-03-14T23:22:15.208Z,1521069735.208 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-03-14T23:22:15.525Z,1521069735.525 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-03-14T23:22:15.526Z,1521069735.526 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-03-14T23:22:15.662Z,1521069735.662 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-03-14T23:22:15.662Z,1521069735.662 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-03-14T23:22:15.743Z,1521069735.743 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-03-14T23:22:15.744Z,1521069735.744 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-03-14T23:22:15.841Z,1521069735.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-03-14T23:22:15.929Z,1521069735.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-03-14T23:22:16.020Z,1521069736.020 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-03-14T23:22:16.103Z,1521069736.103 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-03-14T23:22:16.244Z,1521069736.244 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-03-14T23:22:16.415Z,1521069736.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-03-14T23:22:16.647Z,1521069736.647 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-03-14T23:22:17.002Z,1521069737.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-03-14T23:22:17.003Z,1521069737.003 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-03-14T23:22:17.131Z,1521069737.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-03-14T23:22:17.293Z,1521069737.293 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-03-14T23:22:17.449Z,1521069737.449 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-03-14T23:22:17.570Z,1521069737.570 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-03-14T23:22:17.570Z,1521069737.570 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-03-14T23:22:17.576Z,1521069737.576 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-03-14T23:22:17.816Z,1521069737.816 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-03-14T23:22:17.816Z,1521069737.816 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-03-14T23:22:17.858Z,1521069737.858 [DepthRateCalculator] Loaded
2018-03-14T23:22:17.858Z,1521069737.858 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-03-14T23:22:17.864Z,1521069737.864 [PitchRateCalculator] Loaded
2018-03-14T23:22:17.865Z,1521069737.865 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-03-14T23:22:17.881Z,1521069737.881 [SpeedCalculator] Loaded
2018-03-14T23:22:17.881Z,1521069737.881 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-03-14T23:22:17.902Z,1521069737.902 [TempGradientCalculator] Loaded
2018-03-14T23:22:17.902Z,1521069737.902 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-03-14T23:22:17.918Z,1521069737.918 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-03-14T23:22:17.918Z,1521069737.918 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-03-14T23:22:17.924Z,1521069737.924 [YawRateCalculator] Loaded
2018-03-14T23:22:17.924Z,1521069737.924 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-03-14T23:22:17.924Z,1521069737.924 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-03-14T23:22:17.925Z,1521069737.925 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-03-14T23:22:18.007Z,1521069738.007 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-03-14T23:22:18.007Z,1521069738.007 [StratificationFrontDetector](DEBUG): (re)initializing
2018-03-14T23:22:18.008Z,1521069738.008 [StratificationFrontDetector] Loaded
2018-03-14T23:22:18.008Z,1521069738.008 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-03-14T23:22:18.009Z,1521069738.009 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-03-14T23:22:18.009Z,1521069738.009 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-03-14T23:22:18.123Z,1521069738.123 [BuoyancyServo] Loaded
2018-03-14T23:22:18.124Z,1521069738.124 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-03-14T23:22:18.139Z,1521069738.139 [ElevatorServo] Loaded
2018-03-14T23:22:18.139Z,1521069738.139 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-03-14T23:22:18.154Z,1521069738.154 [MassServo] Loaded
2018-03-14T23:22:18.154Z,1521069738.154 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-03-14T23:22:18.169Z,1521069738.169 [RudderServo] Loaded
2018-03-14T23:22:18.169Z,1521069738.169 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-03-14T23:22:18.183Z,1521069738.183 [ThrusterServo] Loaded
2018-03-14T23:22:18.183Z,1521069738.183 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-03-14T23:22:18.184Z,1521069738.184 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-03-14T23:22:18.184Z,1521069738.184 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-03-14T23:22:18.198Z,1521069738.198 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-03-14T23:22:18.199Z,1521069738.199 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-03-14T23:22:18.296Z,1521069738.296 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-03-14T23:22:18.296Z,1521069738.296 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-03-14T23:22:18.574Z,1521069738.574 [DataOverHttps] Loaded
2018-03-14T23:22:18.575Z,1521069738.575 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-03-14T23:22:18.588Z,1521069738.588 [Depth_Keller] Loaded
2018-03-14T23:22:18.588Z,1521069738.588 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-03-14T23:22:18.593Z,1521069738.593 [DropWeight] Loaded
2018-03-14T23:22:18.593Z,1521069738.593 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-03-14T23:22:18.692Z,1521069738.692 [NAL9602] Loaded
2018-03-14T23:22:18.692Z,1521069738.692 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-03-14T23:22:18.708Z,1521069738.708 [Onboard] Loaded
2018-03-14T23:22:18.708Z,1521069738.708 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-03-14T23:22:18.718Z,1521069738.718 [Radio_Surface] Loaded
2018-03-14T23:22:18.718Z,1521069738.718 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-03-14T23:22:18.719Z,1521069738.719 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408714E0
2018-03-14T23:22:18.720Z,1521069738.720 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1271
2018-03-14T23:22:18.768Z,1521069738.768 [PNI_TCM] Loaded
2018-03-14T23:22:18.768Z,1521069738.768 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-03-14T23:22:20.523Z,1521069740.523 [BPC1] Loaded
2018-03-14T23:22:20.523Z,1521069740.523 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-03-14T23:22:20.524Z,1521069740.524 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-03-14T23:22:20.524Z,1521069740.524 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-03-14T23:22:20.654Z,1521069740.654 [SBIT](DEBUG): Construct Startup Built In Test.
2018-03-14T23:22:20.679Z,1521069740.679 [SBIT] Loaded
2018-03-14T23:22:20.680Z,1521069740.680 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-03-14T23:22:20.680Z,1521069740.680 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-03-14T23:22:20.691Z,1521069740.691 [IBIT] Loaded
2018-03-14T23:22:20.692Z,1521069740.692 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-03-14T23:22:20.695Z,1521069740.695 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-03-14T23:22:20.845Z,1521069740.845 [CBIT] Loaded
2018-03-14T23:22:20.845Z,1521069740.845 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-03-14T23:22:20.846Z,1521069740.846 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-03-14T23:22:20.846Z,1521069740.846 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-03-14T23:22:20.993Z,1521069740.993 [Aanderaa_O2] Loaded
2018-03-14T23:22:20.993Z,1521069740.993 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-03-14T23:22:21.005Z,1521069741.005 [CANONSampler] Loaded
2018-03-14T23:22:21.005Z,1521069741.005 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2018-03-14T23:22:21.019Z,1521069741.019 [PAR_Licor] Loaded
2018-03-14T23:22:21.019Z,1521069741.019 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-03-14T23:22:21.068Z,1521069741.068 [WetLabsBB2FL] Loaded
2018-03-14T23:22:21.069Z,1521069741.069 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-03-14T23:22:21.070Z,1521069741.070 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409314E0
2018-03-14T23:22:21.070Z,1521069741.070 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1272
2018-03-14T23:22:21.071Z,1521069741.071 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-03-14T23:22:21.071Z,1521069741.071 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-03-14T23:22:21.141Z,1521069741.141 [VerticalControl](DEBUG): Construct VerticalControl.
2018-03-14T23:22:21.227Z,1521069741.227 [VerticalControl] Loaded
2018-03-14T23:22:21.227Z,1521069741.227 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-03-14T23:22:21.228Z,1521069741.228 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-03-14T23:22:21.285Z,1521069741.285 [HorizontalControl] Loaded
2018-03-14T23:22:21.285Z,1521069741.285 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-03-14T23:22:21.286Z,1521069741.286 [SpeedControl](DEBUG): Construct SpeedControl.
2018-03-14T23:22:21.287Z,1521069741.287 [SpeedControl] Loaded
2018-03-14T23:22:21.288Z,1521069741.288 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-03-14T23:22:21.288Z,1521069741.288 [LoopControl](DEBUG): Construct LoopControl.
2018-03-14T23:22:21.289Z,1521069741.289 [LoopControl] Loaded
2018-03-14T23:22:21.289Z,1521069741.289 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-03-14T23:22:21.290Z,1521069741.290 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-03-14T23:22:21.290Z,1521069741.290 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-03-14T23:22:21.315Z,1521069741.315 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-03-14T23:22:21.315Z,1521069741.315 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-03-14T23:22:21.406Z,1521069741.406 [DeadReckonUsingSpeedCalculator] Loaded
2018-03-14T23:22:21.406Z,1521069741.406 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-03-14T23:22:21.460Z,1521069741.460 [DeadReckonWithRespectToSeafloor] Loaded
2018-03-14T23:22:21.460Z,1521069741.460 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2018-03-14T23:22:21.477Z,1521069741.477 [NavChart] Loaded
2018-03-14T23:22:21.477Z,1521069741.477 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-03-14T23:22:21.481Z,1521069741.481 [UniversalFixResidualReporter] Loaded
2018-03-14T23:22:21.481Z,1521069741.481 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-03-14T23:22:21.482Z,1521069741.482 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-03-14T23:22:21.499Z,1521069741.499 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-03-14T23:22:21.500Z,1521069741.500 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-03-14T23:22:21.515Z,1521069741.515 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-03-14T23:22:21.516Z,1521069741.516 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409BD4E0
2018-03-14T23:22:21.516Z,1521069741.516 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1273
2018-03-14T23:22:21.521Z,1521069741.521 [Supervisor](INFO): Main Thread ID is 9710
2018-03-14T23:22:21.521Z,1521069741.521 [Supervisor](DEBUG): Running supervisor.
2018-03-14T23:22:21.522Z,1521069741.522 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1274
2018-03-14T23:22:21.531Z,1521069741.531 [controlThread ThreadHandler](INFO): Handler Thread ID is 1275
2018-03-14T23:22:21.531Z,1521069741.531 [controlThread](DEBUG): Initializing ControlThread
2018-03-14T23:22:21.532Z,1521069741.532 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-03-14T23:22:21.532Z,1521069741.532 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-03-14T23:22:21.533Z,1521069741.533 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-03-14T23:22:21.533Z,1521069741.533 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-03-14T23:22:21.533Z,1521069741.533 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-03-14T23:22:21.534Z,1521069741.534 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-03-14T23:22:21.541Z,1521069741.541 [SBIT](INFO): Initialize SBIT Component.
2018-03-14T23:22:21.542Z,1521069741.542 [SBIT](IMPORTANT): git: 2018-03-10-3-g1088291
2018-03-14T23:22:21.542Z,1521069741.542 [SBIT](INFO): git hash: 10882917f95cfba58cc6008bb2c6cc253db9d857
2018-03-14T23:22:21.542Z,1521069741.542 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-03-14T23:22:21.543Z,1521069741.543 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-03-14T23:22:21.544Z,1521069741.544 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-03-14T23:22:21.545Z,1521069741.545 [IBIT](INFO): Initialize IBIT Component.
2018-03-14T23:22:21.546Z,1521069741.546 [CBIT](DEBUG): Initialize CBIT Component.
2018-03-14T23:22:21.546Z,1521069741.546 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-03-14T23:22:21.555Z,1521069741.555 [logger ThreadHandler](INFO): Handler Thread ID is 1276
2018-03-14T23:22:21.579Z,1521069741.579 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1277
2018-03-14T23:22:21.586Z,1521069741.586 [Radio_Surface](INFO): Powering up
2018-03-14T23:22:21.588Z,1521069741.588 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1278
2018-03-14T23:22:21.625Z,1521069741.625 [WetLabsBB2FL](INFO): Powering down
2018-03-14T23:22:21.643Z,1521069741.643 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1279
2018-03-14T23:22:21.646Z,1521069741.646 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-03-14T23:22:21.646Z,1521069741.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-03-14T23:22:21.647Z,1521069741.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-03-14T23:22:21.647Z,1521069741.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-03-14T23:22:21.647Z,1521069741.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-03-14T23:22:21.647Z,1521069741.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-03-14T23:22:21.647Z,1521069741.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-03-14T23:22:21.647Z,1521069741.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-03-14T23:22:21.648Z,1521069741.648 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-03-14T23:22:21.648Z,1521069741.648 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-03-14T23:22:21.648Z,1521069741.648 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-03-14T23:22:21.648Z,1521069741.648 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-03-14T23:22:21.648Z,1521069741.648 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-03-14T23:22:21.648Z,1521069741.648 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-03-14T23:22:21.649Z,1521069741.649 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-03-14T23:22:21.649Z,1521069741.649 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-03-14T23:22:21.655Z,1521069741.655 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-03-14T23:22:21.657Z,1521069741.657 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-03-14T23:22:21.657Z,1521069741.657 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-03-14T23:22:21.658Z,1521069741.658 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-03-14T23:22:21.658Z,1521069741.658 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-03-14T23:22:21.663Z,1521069741.663 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-03-14T23:22:21.663Z,1521069741.663 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-03-14T23:22:21.664Z,1521069741.664 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-03-14T23:22:21.664Z,1521069741.664 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-03-14T23:22:21.665Z,1521069741.665 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-03-14T23:22:21.665Z,1521069741.665 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-03-14T23:22:21.666Z,1521069741.666 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-03-14T23:22:21.671Z,1521069741.671 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-03-14T23:22:21.709Z,1521069741.709 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-03-14T23:22:21.755Z,1521069741.755 [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>


2018-03-14T23:22:21.756Z,1521069741.756 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-03-14T23:22:21.833Z,1521069741.833 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-03-14T23:22:21.834Z,1521069741.834 [Default:A.Wait](DEBUG): Construct Wait.
2018-03-14T23:22:21.836Z,1521069741.836 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-03-14T23:22:21.866Z,1521069741.866 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-03-14T23:22:21.884Z,1521069741.884 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-03-14T23:22:21.890Z,1521069741.890 [Default:E.Execute](DEBUG): Construct Execute.
2018-03-14T23:22:21.906Z,1521069741.906 [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>


2018-03-14T23:22:21.911Z,1521069741.911 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-03-14T23:22:21.923Z,1521069741.923 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-03-14T23:22:21.967Z,1521069741.967 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-03-14T23:22:22.040Z,1521069742.040 [BPC1](INFO): Start
2018-03-14T23:22:22.168Z,1521069742.168 [CANONSampler](INFO): Powering down
2018-03-14T23:22:22.297Z,1521069742.297 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-03-14T23:22:22.391Z,1521069742.391 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:22.415Z,1521069742.415 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:22.515Z,1521069742.515 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-03-14T23:22:22.523Z,1521069742.523 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-03-14T23:22:22.545Z,1521069742.545 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-03-14T23:22:22.551Z,1521069742.551 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-03-14T23:22:22.557Z,1521069742.557 [MassServo](DEBUG): Initializing EZServoServo.
2018-03-14T23:22:22.563Z,1521069742.563 [MassServo](DEBUG): Initializing MassServo.
2018-03-14T23:22:22.568Z,1521069742.568 [RudderServo](DEBUG): Initializing EZServoServo.
2018-03-14T23:22:22.575Z,1521069742.575 [RudderServo](DEBUG): Initializing RudderServo.
2018-03-14T23:22:22.603Z,1521069742.603 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-03-14T23:22:22.611Z,1521069742.611 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-03-14T23:22:22.895Z,1521069742.895 [BPC1](INFO): Starting
2018-03-14T23:22:22.923Z,1521069742.923 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:22.924Z,1521069742.924 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:23.125Z,1521069743.125 [BPC1](INFO): Starting
2018-03-14T23:22:23.170Z,1521069743.170 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:23.171Z,1521069743.171 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:23.594Z,1521069743.594 [BPC1](INFO): Starting
2018-03-14T23:22:23.601Z,1521069743.601 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:23.601Z,1521069743.601 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:24.007Z,1521069744.007 [BPC1](INFO): Starting
2018-03-14T23:22:24.018Z,1521069744.018 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:24.023Z,1521069744.023 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:24.396Z,1521069744.396 [BPC1](INFO): Starting
2018-03-14T23:22:24.442Z,1521069744.442 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:24.442Z,1521069744.442 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:24.797Z,1521069744.797 [BPC1](INFO): Starting
2018-03-14T23:22:24.823Z,1521069744.823 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:24.824Z,1521069744.824 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:25.211Z,1521069745.211 [BPC1](INFO): Starting
2018-03-14T23:22:25.331Z,1521069745.331 [Aanderaa_O2](INFO): Powering down
2018-03-14T23:22:25.449Z,1521069745.449 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:25.450Z,1521069745.450 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-03-14T23:22:25.613Z,1521069745.613 [BPC1](INFO): Starting
2018-03-14T23:22:26.030Z,1521069746.030 [BPC1](INFO): Starting
2018-03-14T23:22:26.548Z,1521069746.548 [BPC1](INFO): Starting
2018-03-14T23:22:26.904Z,1521069746.904 [BPC1](INFO): Starting
2018-03-14T23:22:27.297Z,1521069747.297 [BPC1](INFO): Starting
2018-03-14T23:22:27.721Z,1521069747.721 [BPC1](INFO): Starting
2018-03-14T23:22:28.096Z,1521069748.096 [BPC1](INFO): Starting
2018-03-14T23:22:28.499Z,1521069748.499 [BPC1](INFO): Starting
2018-03-14T23:22:28.897Z,1521069748.897 [BPC1](INFO): Starting
2018-03-14T23:22:29.310Z,1521069749.310 [BPC1](INFO): Starting
2018-03-14T23:22:29.696Z,1521069749.696 [BPC1](INFO): Starting
2018-03-14T23:22:30.118Z,1521069750.118 [BPC1](INFO): Starting
2018-03-14T23:22:30.503Z,1521069750.503 [BPC1](INFO): Starting
2018-03-14T23:22:30.896Z,1521069750.896 [BPC1](INFO): Starting
2018-03-14T23:22:31.297Z,1521069751.297 [BPC1](INFO): Starting
2018-03-14T23:22:31.699Z,1521069751.699 [BPC1](INFO): Starting
2018-03-14T23:22:32.096Z,1521069752.096 [BPC1](INFO): Starting
2018-03-14T23:22:32.496Z,1521069752.496 [BPC1](INFO): Starting
2018-03-14T23:22:32.497Z,1521069752.497 [BPC1](INFO): Initialized.
2018-03-14T23:22:32.907Z,1521069752.907 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:22:34.899Z,1521069754.899 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:22:38.497Z,1521069758.497 [BPC1](INFO): Bank B valid message: 1596 bytes.
2018-03-14T23:22:38.520Z,1521069758.520 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:22:38.520Z,1521069758.520 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:22:38.911Z,1521069758.911 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:22:40.528Z,1521069760.528 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:22:44.499Z,1521069764.499 [BPC1](INFO): Bank B valid message: 1824 bytes.
2018-03-14T23:22:44.506Z,1521069764.506 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:22:44.506Z,1521069764.506 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:22:44.910Z,1521069764.911 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:22:44.937Z,1521069764.937 [SBIT](IMPORTANT): Beginning Startup BIT
2018-03-14T23:22:44.949Z,1521069764.949 [CBIT](IMPORTANT): Beginning ground fault scan
2018-03-14T23:22:48.996Z,1521069768.996 [NAL9602](INFO): Powering up NAL9602
2018-03-14T23:22:52.227Z,1521069772.227 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:22:55.892Z,1521069775.892 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002150
CHAN A1 (24V): -0.005969
CHAN A2 (12V): -0.002506
CHAN A3 (5V): -0.001556
CHAN B0 (3.3V): -0.000177
CHAN B1 (3.15aV): -0.000105
CHAN B2 (3.15bV): -0.000287
CHAN B3 (GND): 0.000055
OPEN: -0.000418
Full Scale Calc: 4.765 mA, -1.589 mA
2018-03-14T23:22:57.025Z,1521069777.025 [BPC1](INFO): Bank B valid message: 1824 bytes.
2018-03-14T23:22:57.064Z,1521069777.064 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:22:57.064Z,1521069777.064 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:22:57.447Z,1521069777.447 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:23:00.196Z,1521069780.196 [NAL9602](INFO): NAL9602 initialized
2018-03-14T23:23:04.865Z,1521069784.865 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:23:09.654Z,1521069789.654 [BPC1](INFO): Bank B valid message: 1824 bytes.
2018-03-14T23:23:09.669Z,1521069789.669 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:23:09.669Z,1521069789.669 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:23:10.079Z,1521069790.079 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:23:17.643Z,1521069797.643 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:23:21.647Z,1521069801.647 [BPC1](INFO): Bank B valid message: 1596 bytes.
2018-03-14T23:23:21.663Z,1521069801.663 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:23:21.663Z,1521069801.663 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:23:22.066Z,1521069802.066 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:23:23.670Z,1521069803.670 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:23:26.854Z,1521069806.854 [BPC1](INFO): Bank B valid message: 1596 bytes.
2018-03-14T23:23:26.861Z,1521069806.861 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:23:26.861Z,1521069806.861 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:23:27.262Z,1521069807.262 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:23:33.818Z,1521069813.818 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:23:37.797Z,1521069817.797 [BPC1](INFO): Bank B valid message: 1596 bytes.
2018-03-14T23:23:37.803Z,1521069817.803 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:23:37.803Z,1521069817.803 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:23:38.210Z,1521069818.210 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:23:39.022Z,1521069819.022 [SBIT](IMPORTANT): SBIT PASSED
2018-03-14T23:23:39.420Z,1521069819.420 [MissionManager](IMPORTANT): Started mission Startup
2018-03-14T23:23:39.420Z,1521069819.420 [Startup] Running Loop=1
2018-03-14T23:23:39.420Z,1521069819.420 [Startup](DEBUG): Aggregate::initialize Startup
2018-03-14T23:23:39.420Z,1521069819.420 [Startup:A.GoToSurface] Running Loop=1
2018-03-14T23:23:39.420Z,1521069819.420 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-03-14T23:23:39.421Z,1521069819.421 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-03-14T23:23:39.421Z,1521069819.421 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-03-14T23:23:39.422Z,1521069819.422 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-03-14T23:23:39.422Z,1521069819.422 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 30.000000 seconds.
2018-03-14T23:23:39.423Z,1521069819.423 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-03-14T23:23:39.428Z,1521069819.428 [Startup:StartupSatComms] Running Loop=1
2018-03-14T23:23:39.428Z,1521069819.428 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-03-14T23:23:39.428Z,1521069819.428 [Startup:StartupSatComms:A] Running Loop=1
2018-03-14T23:23:39.811Z,1521069819.811 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:23:39.825Z,1521069819.825 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-03-14T23:23:43.792Z,1521069823.792 [BPC1](INFO): Bank B valid message: 1824 bytes.
2018-03-14T23:23:43.799Z,1521069823.799 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:23:43.800Z,1521069823.800 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:23:44.220Z,1521069824.220 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:23:51.797Z,1521069831.797 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:23:56.193Z,1521069836.193 [BPC1](INFO): Bank B valid message: 1824 bytes.
2018-03-14T23:23:56.200Z,1521069836.200 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:23:56.200Z,1521069836.200 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:23:56.607Z,1521069836.607 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:24:02.598Z,1521069842.598 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 31 sticks.
2018-03-14T23:24:02.598Z,1521069842.598 [BPC1] Data Fault, FailCount= 1
2018-03-14T23:24:02.598Z,1521069842.598 [BPC1](ERROR): Data Fault
2018-03-14T23:24:02.655Z,1521069842.655 [CBIT](ERROR): Data Fault in component: BPC1
2018-03-14T23:24:02.988Z,1521069842.988 [BPC1](INFO): Stop
2018-03-14T23:24:02.988Z,1521069842.988 [BPC1](INFO): uninitialize
2018-03-14T23:24:03.392Z,1521069843.392 [BPC1](INFO): Stopping
2018-03-14T23:24:03.788Z,1521069843.788 [BPC1](INFO): Stopped
2018-03-14T23:24:03.789Z,1521069843.789 [BPC1](INFO): Data requested. Hibernation time: 431532.053333 hours.
2018-03-14T23:24:03.833Z,1521069843.833 [CBIT](INFO): Clearing failed state for component BPC1
2018-03-14T23:24:03.833Z,1521069843.833 [BPC1] No Fault, FailCount= 1
2018-03-14T23:24:04.192Z,1521069844.192 [BPC1](INFO): Start
2018-03-14T23:24:04.588Z,1521069844.588 [BPC1](INFO): Starting
2018-03-14T23:24:05.015Z,1521069845.015 [BPC1](INFO): Starting
2018-03-14T23:24:05.399Z,1521069845.399 [BPC1](INFO): Starting
2018-03-14T23:24:05.818Z,1521069845.818 [BPC1](INFO): Starting
2018-03-14T23:24:06.203Z,1521069846.203 [BPC1](INFO): Starting
2018-03-14T23:24:06.596Z,1521069846.596 [BPC1](INFO): Starting
2018-03-14T23:24:06.995Z,1521069846.995 [BPC1](INFO): Starting
2018-03-14T23:24:07.399Z,1521069847.399 [BPC1](INFO): Starting
2018-03-14T23:24:07.796Z,1521069847.796 [BPC1](INFO): Starting
2018-03-14T23:24:08.199Z,1521069848.199 [BPC1](INFO): Starting
2018-03-14T23:24:08.596Z,1521069848.596 [BPC1](INFO): Starting
2018-03-14T23:24:08.996Z,1521069848.996 [BPC1](INFO): Starting
2018-03-14T23:24:09.399Z,1521069849.399 [BPC1](INFO): Starting
2018-03-14T23:24:09.796Z,1521069849.796 [BPC1](INFO): Starting
2018-03-14T23:24:10.213Z,1521069850.213 [BPC1](INFO): Starting
2018-03-14T23:24:10.610Z,1521069850.610 [BPC1](INFO): Starting
2018-03-14T23:24:11.013Z,1521069851.013 [BPC1](INFO): Starting
2018-03-14T23:24:11.410Z,1521069851.410 [BPC1](INFO): Starting
2018-03-14T23:24:11.802Z,1521069851.802 [BPC1](INFO): Starting
2018-03-14T23:24:12.189Z,1521069852.189 [BPC1](INFO): Starting
2018-03-14T23:24:12.588Z,1521069852.588 [BPC1](INFO): Starting
2018-03-14T23:24:12.992Z,1521069852.992 [BPC1](INFO): Starting
2018-03-14T23:24:13.388Z,1521069853.388 [BPC1](INFO): Starting
2018-03-14T23:24:13.792Z,1521069853.792 [BPC1](INFO): Starting
2018-03-14T23:24:14.196Z,1521069854.196 [BPC1](INFO): Starting
2018-03-14T23:24:14.592Z,1521069854.592 [BPC1](INFO): Starting
2018-03-14T23:24:14.592Z,1521069854.592 [BPC1](INFO): Initialized.
2018-03-14T23:24:15.018Z,1521069855.018 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:24:22.199Z,1521069862.199 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:24:26.075Z,1521069866.075 [CommandLine](IMPORTANT): got command show variable missing
2018-03-14T23:24:26.138Z,1521069866.138 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold (count)
2018-03-14T23:24:26.219Z,1521069866.219 [BPC1](INFO): Bank B valid message: 1596 bytes.
2018-03-14T23:24:26.229Z,1521069866.229 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:24:26.229Z,1521069866.229 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:24:26.623Z,1521069866.623 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:24:33.799Z,1521069873.799 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:24:38.197Z,1521069878.197 [BPC1](INFO): Bank B valid message: 1824 bytes.
2018-03-14T23:24:38.203Z,1521069878.203 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:24:38.204Z,1521069878.204 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:24:38.614Z,1521069878.614 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:24:39.819Z,1521069879.819 [Startup:StartupSatComms:A](INFO): Timed out from 2018-03-14T23:23:39.4Z
2018-03-14T23:24:39.819Z,1521069879.819 [Startup:StartupSatComms:A] Stopped
2018-03-14T23:24:39.819Z,1521069879.819 [Startup:StartupSatComms:B] Running Loop=1
2018-03-14T23:24:40.220Z,1521069880.220 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-03-14T23:24:46.124Z,1521069886.124 [CommandLine](IMPORTANT): got command configSet IBIT.batteryMissingStickThreshold 34.000000 count
2018-03-14T23:24:46.125Z,1521069886.125 [CommandLine](FAULT): configSet IBIT.batteryMissingStickThreshold without persist will have no effect.
2018-03-14T23:24:46.200Z,1521069886.200 [BPC1](INFO): Bank B: sending IBPS break.
2018-03-14T23:24:50.594Z,1521069890.594 [BPC1](INFO): Bank B valid message: 1824 bytes.
2018-03-14T23:24:50.633Z,1521069890.633 [BPC1](INFO): Bank B: data parsed.
2018-03-14T23:24:50.633Z,1521069890.633 [BPC1](INFO): A OR B has been parsed ******
2018-03-14T23:24:51.010Z,1521069891.010 [BPC1](INFO): Bank B: initialized.
2018-03-14T23:24:52.668Z,1521069892.668 [CommandLine](IMPORTANT): got command configSet IBIT.batteryMissingStickThreshold 34.000000 count persist
2018-03-14T23:24:52.668Z,1521069892.668 [CommandLine](IMPORTANT): configSet IBIT.batteryMissingStickThreshold requires a restart to take effect.
2018-03-14T23:24:55.492Z,1521069895.492 [CommandLine](IMPORTANT): got command restart application
2018-03-14T23:24:56.498Z,1521069896.498 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-03-14T23:24:56.501Z,1521069896.501 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-03-14T23:24:56.502Z,1521069896.502 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:56.694Z,1521069896.694 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-03-14T23:24:56.695Z,1521069896.695 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:56.695Z,1521069896.695 [CommandLine](INFO): Join timeout helper Thread ID is 1295
2018-03-14T23:24:56.696Z,1521069896.696 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-03-14T23:24:56.696Z,1521069896.696 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:56.696Z,1521069896.696 [NavChartDb](INFO): Join timeout helper Thread ID is 1296
2018-03-14T23:24:57.091Z,1521069897.091 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-03-14T23:24:57.091Z,1521069897.091 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.106Z,1521069897.106 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-03-14T23:24:57.107Z,1521069897.107 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.107Z,1521069897.107 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1297
2018-03-14T23:24:57.151Z,1521069897.151 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-03-14T23:24:57.151Z,1521069897.151 [WetLabsBB2FL](INFO): Powering down
2018-03-14T23:24:57.152Z,1521069897.152 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.166Z,1521069897.166 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-03-14T23:24:57.167Z,1521069897.167 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.167Z,1521069897.167 [Radio_Surface](INFO): Join timeout helper Thread ID is 1298
2018-03-14T23:24:57.255Z,1521069897.255 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-03-14T23:24:57.255Z,1521069897.255 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.267Z,1521069897.267 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-03-14T23:24:57.267Z,1521069897.267 [logger ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.267Z,1521069897.267 [logger](INFO): Join timeout helper Thread ID is 1299
2018-03-14T23:24:57.279Z,1521069897.279 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-03-14T23:24:57.279Z,1521069897.279 [logger ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.287Z,1521069897.287 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-03-14T23:24:57.287Z,1521069897.287 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.288Z,1521069897.288 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-03-14T23:24:57.288Z,1521069897.288 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.288Z,1521069897.288 [controlThread](INFO): Join timeout helper Thread ID is 1300
2018-03-14T23:24:57.359Z,1521069897.359 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-03-14T23:24:57.359Z,1521069897.359 [controlThread](DEBUG): Uninitializing ControlThread
2018-03-14T23:24:57.360Z,1521069897.360 [NAL9602](INFO): Powering down
2018-03-14T23:24:57.361Z,1521069897.361 [PNI_TCM](INFO): Powering down
2018-03-14T23:24:57.447Z,1521069897.447 [BPC1](INFO): uninitialize
2018-03-14T23:24:57.447Z,1521069897.447 [Aanderaa_O2](INFO): Powering down
2018-03-14T23:24:57.449Z,1521069897.449 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-03-14T23:24:57.451Z,1521069897.451 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-03-14T23:24:57.451Z,1521069897.451 [MissionManager](INFO): Uninitializing Mission Default
2018-03-14T23:24:57.454Z,1521069897.454 [MissionManager](INFO): Uninitializing Mission Startup
2018-03-14T23:24:57.454Z,1521069897.454 [Startup] Stopped
2018-03-14T23:24:57.454Z,1521069897.454 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-03-14T23:24:57.454Z,1521069897.454 [Startup:A.GoToSurface] Stopped
2018-03-14T23:24:57.454Z,1521069897.454 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-03-14T23:24:57.454Z,1521069897.454 [Startup:StartupSatComms] Stopped
2018-03-14T23:24:57.454Z,1521069897.454 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-03-14T23:24:57.454Z,1521069897.454 [Startup:StartupSatComms:B] Stopped
2018-03-14T23:24:57.456Z,1521069897.456 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-03-14T23:24:57.456Z,1521069897.456 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-03-14T23:24:57.457Z,1521069897.457 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-03-14T23:24:57.457Z,1521069897.457 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-03-14T23:24:57.457Z,1521069897.457 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-03-14T23:24:57.457Z,1521069897.457 [BuoyancyServo](INFO): Powering down
2018-03-14T23:24:57.471Z,1521069897.471 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-03-14T23:24:57.471Z,1521069897.471 [ElevatorServo](INFO): Powering down
2018-03-14T23:24:57.472Z,1521069897.472 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-03-14T23:24:57.472Z,1521069897.472 [MassServo](INFO): Powering down
2018-03-14T23:24:57.472Z,1521069897.472 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-03-14T23:24:57.472Z,1521069897.472 [RudderServo](INFO): Powering down
2018-03-14T23:24:57.473Z,1521069897.473 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-03-14T23:24:57.473Z,1521069897.473 [ThrusterServo](INFO): Powering down
2018-03-14T23:24:57.474Z,1521069897.474 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-03-14T23:24:57.474Z,1521069897.474 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-03-14T23:24:57.475Z,1521069897.475 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-03-14T23:24:57.475Z,1521069897.475 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.519Z,1521069897.519 [BPC1](INFO): uninitialize
2018-03-14T23:24:57.565Z,1521069897.565 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.597Z,1521069897.597 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.622Z,1521069897.622 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-03-14T23:24:57.672Z,1521069897.672 [logger ThreadHandler](INFO): Thread cancelled.