2018-01-22T19:41:53.314Z,1516650113.314 [Supervisor](DEBUG): Initializing supervisor.
2018-01-22T19:41:53.317Z,1516650113.317 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-01-22T19:41:53.317Z,1516650113.317 [SyncHandler](INFO): Protected caller Thread ID is 803
2018-01-22T19:41:53.318Z,1516650113.318 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-01-22T19:41:53.319Z,1516650113.319 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-01-22T19:41:53.319Z,1516650113.319 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 804
2018-01-22T19:41:53.321Z,1516650113.321 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-01-22T19:41:53.332Z,1516650113.332 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-01-22T19:41:53.333Z,1516650113.333 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-01-22T19:41:53.334Z,1516650113.334 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 805
2018-01-22T19:41:53.334Z,1516650113.334 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-01-22T19:41:53.335Z,1516650113.335 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-01-22T19:41:53.336Z,1516650113.336 [logger ThreadHandler](INFO): Protected caller Thread ID is 806
2018-01-22T19:41:53.338Z,1516650113.338 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-01-22T19:41:53.338Z,1516650113.338 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-01-22T19:41:53.341Z,1516650113.341 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-01-22T19:41:53.437Z,1516650113.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-01-22T19:41:53.439Z,1516650113.439 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-01-22T19:41:53.538Z,1516650113.538 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-01-22T19:41:53.540Z,1516650113.540 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-01-22T19:41:53.723Z,1516650113.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-01-22T19:41:53.724Z,1516650113.724 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-01-22T19:41:54.014Z,1516650114.014 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-01-22T19:41:54.016Z,1516650114.016 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-01-22T19:41:54.325Z,1516650114.325 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-01-22T19:41:54.326Z,1516650114.326 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-01-22T19:41:54.760Z,1516650114.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-01-22T19:41:54.761Z,1516650114.761 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-01-22T19:41:55.086Z,1516650115.086 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-01-22T19:41:55.088Z,1516650115.088 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-01-22T19:41:55.505Z,1516650115.505 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-01-22T19:41:55.507Z,1516650115.507 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-01-22T19:41:55.587Z,1516650115.587 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-01-22T19:41:55.870Z,1516650115.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-01-22T19:41:55.871Z,1516650115.871 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-01-22T19:41:56.011Z,1516650116.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-01-22T19:41:56.012Z,1516650116.012 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-01-22T19:41:56.206Z,1516650116.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-01-22T19:41:56.208Z,1516650116.208 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-01-22T19:41:56.401Z,1516650116.401 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-01-22T19:41:56.402Z,1516650116.402 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-01-22T19:41:56.501Z,1516650116.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-01-22T19:41:56.502Z,1516650116.502 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-01-22T19:41:56.983Z,1516650116.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-01-22T19:41:56.985Z,1516650116.985 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-01-22T19:41:57.060Z,1516650117.060 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-01-22T19:41:57.496Z,1516650117.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-01-22T19:41:57.497Z,1516650117.497 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-01-22T19:41:57.575Z,1516650117.575 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-01-22T19:41:57.713Z,1516650117.713 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-01-22T19:41:57.804Z,1516650117.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-01-22T19:41:57.889Z,1516650117.889 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-01-22T19:41:58.023Z,1516650118.023 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-01-22T19:41:58.185Z,1516650118.185 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-01-22T19:41:58.281Z,1516650118.281 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-01-22T19:41:58.373Z,1516650118.373 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-01-22T19:41:58.469Z,1516650118.469 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-01-22T19:41:58.551Z,1516650118.551 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2018-01-22T19:41:58.556Z,1516650118.556 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-01-22T19:41:58.680Z,1516650118.680 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-01-22T19:41:58.681Z,1516650118.681 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-01-22T19:41:58.704Z,1516650118.704 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-01-22T19:41:58.706Z,1516650118.706 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-01-22T19:41:58.761Z,1516650118.761 [DepthRateCalculator] Loaded
2018-01-22T19:41:58.761Z,1516650118.761 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-01-22T19:41:58.767Z,1516650118.767 [PitchRateCalculator] Loaded
2018-01-22T19:41:58.767Z,1516650118.767 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-01-22T19:41:58.783Z,1516650118.783 [SpeedCalculator] Loaded
2018-01-22T19:41:58.783Z,1516650118.783 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-01-22T19:41:58.804Z,1516650118.804 [TempGradientCalculator] Loaded
2018-01-22T19:41:58.804Z,1516650118.804 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-01-22T19:41:58.819Z,1516650118.819 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-01-22T19:41:58.819Z,1516650118.819 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-01-22T19:41:58.824Z,1516650118.824 [YawRateCalculator] Loaded
2018-01-22T19:41:58.825Z,1516650118.825 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-01-22T19:41:58.825Z,1516650118.825 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-01-22T19:41:58.826Z,1516650118.826 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-01-22T19:41:58.862Z,1516650118.862 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-01-22T19:41:58.863Z,1516650118.863 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-01-22T19:41:59.305Z,1516650119.305 [AcousticModem_Benthos_ATM900] Loaded
2018-01-22T19:41:59.306Z,1516650119.306 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-01-22T19:41:59.448Z,1516650119.448 [DataOverHttps] Loaded
2018-01-22T19:41:59.448Z,1516650119.448 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-01-22T19:41:59.462Z,1516650119.462 [Depth_Keller] Loaded
2018-01-22T19:41:59.462Z,1516650119.462 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-01-22T19:41:59.467Z,1516650119.467 [DropWeight] Loaded
2018-01-22T19:41:59.467Z,1516650119.467 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-01-22T19:41:59.561Z,1516650119.561 [NAL9602] Loaded
2018-01-22T19:41:59.561Z,1516650119.561 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-01-22T19:41:59.576Z,1516650119.576 [Onboard] Loaded
2018-01-22T19:41:59.576Z,1516650119.576 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-01-22T19:41:59.586Z,1516650119.586 [Radio_Surface] Loaded
2018-01-22T19:41:59.586Z,1516650119.586 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-01-22T19:41:59.588Z,1516650119.588 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407A44E0
2018-01-22T19:41:59.588Z,1516650119.588 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 885
2018-01-22T19:41:59.740Z,1516650119.740 [PNI_TCM] Loaded
2018-01-22T19:41:59.740Z,1516650119.740 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-01-22T19:41:59.799Z,1516650119.799 [Rowe_600LCM] Loaded
2018-01-22T19:41:59.799Z,1516650119.799 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-01-22T19:41:59.800Z,1516650119.800 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407D44E0
2018-01-22T19:41:59.800Z,1516650119.800 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 886
2018-01-22T19:42:01.529Z,1516650121.529 [BPC1] Loaded
2018-01-22T19:42:01.529Z,1516650121.529 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-01-22T19:42:01.529Z,1516650121.529 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-01-22T19:42:01.531Z,1516650121.531 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-01-22T19:42:01.681Z,1516650121.681 [SBIT](DEBUG): Construct Startup Built In Test.
2018-01-22T19:42:01.707Z,1516650121.707 [SBIT] Loaded
2018-01-22T19:42:01.707Z,1516650121.707 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-01-22T19:42:01.708Z,1516650121.708 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-01-22T19:42:01.719Z,1516650121.719 [IBIT] Loaded
2018-01-22T19:42:01.719Z,1516650121.719 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-01-22T19:42:01.722Z,1516650121.722 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-01-22T19:42:01.870Z,1516650121.870 [CBIT] Loaded
2018-01-22T19:42:01.870Z,1516650121.870 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-01-22T19:42:01.870Z,1516650121.870 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-01-22T19:42:01.871Z,1516650121.871 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-01-22T19:42:02.269Z,1516650122.269 [Aanderaa_O2] Loaded
2018-01-22T19:42:02.269Z,1516650122.269 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-01-22T19:42:02.302Z,1516650122.302 [CTD_Seabird] Loaded
2018-01-22T19:42:02.302Z,1516650122.302 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-01-22T19:42:02.303Z,1516650122.303 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4089A4E0
2018-01-22T19:42:02.303Z,1516650122.303 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 888
2018-01-22T19:42:02.319Z,1516650122.319 [ESPComponent] Loaded
2018-01-22T19:42:02.320Z,1516650122.320 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-01-22T19:42:02.333Z,1516650122.333 [PAR_Licor] Loaded
2018-01-22T19:42:02.333Z,1516650122.333 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-01-22T19:42:02.380Z,1516650122.380 [WetLabsBB2FL] Loaded
2018-01-22T19:42:02.381Z,1516650122.381 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-01-22T19:42:02.382Z,1516650122.382 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408CA4E0
2018-01-22T19:42:02.382Z,1516650122.382 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 889
2018-01-22T19:42:02.382Z,1516650122.382 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-01-22T19:42:02.383Z,1516650122.383 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-01-22T19:42:02.651Z,1516650122.651 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-01-22T19:42:02.651Z,1516650122.651 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-01-22T19:42:02.736Z,1516650122.736 [VerticalControl](DEBUG): Construct VerticalControl.
2018-01-22T19:42:02.829Z,1516650122.829 [VerticalControl] Loaded
2018-01-22T19:42:02.830Z,1516650122.830 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-01-22T19:42:02.830Z,1516650122.830 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-01-22T19:42:02.889Z,1516650122.889 [HorizontalControl] Loaded
2018-01-22T19:42:02.889Z,1516650122.889 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-01-22T19:42:02.890Z,1516650122.890 [SpeedControl](DEBUG): Construct SpeedControl.
2018-01-22T19:42:02.895Z,1516650122.895 [SpeedControl] Loaded
2018-01-22T19:42:02.895Z,1516650122.895 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-01-22T19:42:02.896Z,1516650122.896 [LoopControl](DEBUG): Construct LoopControl.
2018-01-22T19:42:02.897Z,1516650122.897 [LoopControl] Loaded
2018-01-22T19:42:02.897Z,1516650122.897 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-01-22T19:42:02.897Z,1516650122.897 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-01-22T19:42:02.898Z,1516650122.898 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-01-22T19:42:03.015Z,1516650123.015 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-01-22T19:42:03.015Z,1516650123.015 [StratificationFrontDetector](DEBUG): (re)initializing
2018-01-22T19:42:03.015Z,1516650123.015 [StratificationFrontDetector] Loaded
2018-01-22T19:42:03.015Z,1516650123.015 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-01-22T19:42:03.016Z,1516650123.016 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-01-22T19:42:03.017Z,1516650123.017 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-01-22T19:42:03.132Z,1516650123.132 [BuoyancyServo] Loaded
2018-01-22T19:42:03.132Z,1516650123.132 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-01-22T19:42:03.143Z,1516650123.143 [ElevatorServo] Loaded
2018-01-22T19:42:03.143Z,1516650123.143 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-01-22T19:42:03.154Z,1516650123.154 [MassServo] Loaded
2018-01-22T19:42:03.154Z,1516650123.154 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-01-22T19:42:03.165Z,1516650123.165 [RudderServo] Loaded
2018-01-22T19:42:03.165Z,1516650123.165 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-01-22T19:42:03.176Z,1516650123.176 [ThrusterServo] Loaded
2018-01-22T19:42:03.176Z,1516650123.176 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-01-22T19:42:03.176Z,1516650123.176 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-01-22T19:42:03.177Z,1516650123.177 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-01-22T19:42:03.287Z,1516650123.287 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-01-22T19:42:03.288Z,1516650123.288 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-01-22T19:42:03.340Z,1516650123.340 [DeadReckonUsingSpeedCalculator] Loaded
2018-01-22T19:42:03.341Z,1516650123.341 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-01-22T19:42:03.356Z,1516650123.356 [NavChart] Loaded
2018-01-22T19:42:03.357Z,1516650123.357 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-01-22T19:42:03.361Z,1516650123.361 [UniversalFixResidualReporter] Loaded
2018-01-22T19:42:03.361Z,1516650123.361 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-01-22T19:42:03.361Z,1516650123.361 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-01-22T19:42:03.365Z,1516650123.365 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-01-22T19:42:03.366Z,1516650123.366 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-01-22T19:42:03.372Z,1516650123.372 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-01-22T19:42:03.373Z,1516650123.373 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A1C4E0
2018-01-22T19:42:03.374Z,1516650123.374 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 890
2018-01-22T19:42:03.378Z,1516650123.378 [Supervisor](INFO): Main Thread ID is 795
2018-01-22T19:42:03.379Z,1516650123.379 [Supervisor](DEBUG): Running supervisor.
2018-01-22T19:42:03.379Z,1516650123.379 [CommandLine ThreadHandler](INFO): Handler Thread ID is 891
2018-01-22T19:42:03.382Z,1516650123.382 [controlThread ThreadHandler](INFO): Handler Thread ID is 892
2018-01-22T19:42:03.382Z,1516650123.382 [controlThread](DEBUG): Initializing ControlThread
2018-01-22T19:42:03.383Z,1516650123.383 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-01-22T19:42:03.383Z,1516650123.383 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-01-22T19:42:03.384Z,1516650123.384 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-01-22T19:42:03.384Z,1516650123.384 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-01-22T19:42:03.385Z,1516650123.385 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-01-22T19:42:03.385Z,1516650123.385 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-01-22T19:42:03.392Z,1516650123.392 [SBIT](INFO): Initialize SBIT Component.
2018-01-22T19:42:03.392Z,1516650123.392 [SBIT](IMPORTANT): git: 2017-12-12
2018-01-22T19:42:03.392Z,1516650123.392 [SBIT](INFO): git hash: 18638d31f033e3fa0cb90b26256f5481d37f00cc
2018-01-22T19:42:03.393Z,1516650123.393 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-01-22T19:42:03.394Z,1516650123.394 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #1 PREEMPT Wed Nov 29 17:23:09 PST 2017
2018-01-22T19:42:03.395Z,1516650123.395 [SBIT](INFO): Beginning SBIT in 63.000000 seconds.
2018-01-22T19:42:03.395Z,1516650123.395 [IBIT](INFO): Initialize IBIT Component.
2018-01-22T19:42:03.396Z,1516650123.396 [CBIT](DEBUG): Initialize CBIT Component.
2018-01-22T19:42:03.396Z,1516650123.396 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2018-01-22T19:42:03.397Z,1516650123.397 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-01-22T19:42:03.397Z,1516650123.397 [logger ThreadHandler](INFO): Handler Thread ID is 893
2018-01-22T19:42:03.417Z,1516650123.417 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 894
2018-01-22T19:42:03.423Z,1516650123.423 [Radio_Surface](INFO): Powering up
2018-01-22T19:42:03.429Z,1516650123.429 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 895
2018-01-22T19:42:03.430Z,1516650123.430 [Rowe_600LCM](INFO): Initializing
2018-01-22T19:42:03.430Z,1516650123.430 [Rowe_600LCM](INFO): Checking LCM
2018-01-22T19:42:03.485Z,1516650123.485 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-01-22T19:42:03.487Z,1516650123.487 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-01-22T19:42:03.487Z,1516650123.487 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-01-22T19:42:03.488Z,1516650123.488 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-01-22T19:42:03.490Z,1516650123.490 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-01-22T19:42:03.490Z,1516650123.490 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-01-22T19:42:03.491Z,1516650123.491 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-01-22T19:42:03.491Z,1516650123.491 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-22T19:42:03.492Z,1516650123.492 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-22T19:42:03.492Z,1516650123.492 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-22T19:42:03.492Z,1516650123.492 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-01-22T19:42:03.493Z,1516650123.493 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-01-22T19:42:03.546Z,1516650123.546 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-01-22T19:42:03.548Z,1516650123.548 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 896
2018-01-22T19:42:03.548Z,1516650123.548 [CTD_Seabird](INFO): Initializing
2018-01-22T19:42:03.581Z,1516650123.581 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 898
2018-01-22T19:42:03.584Z,1516650123.584 [WetLabsBB2FL](INFO): Powering down
2018-01-22T19:42:03.585Z,1516650123.585 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 899
2018-01-22T19:42:03.717Z,1516650123.717 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-22T19:42:03.743Z,1516650123.743 [MissionManager](DEBUG):
2018-01-22T19:42:03.744Z,1516650123.744 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-01-22T19:42:03.752Z,1516650123.752 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-01-22T19:42:03.769Z,1516650123.769 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-01-22T19:42:03.769Z,1516650123.769 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-01-22T19:42:03.769Z,1516650123.769 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-01-22T19:42:03.769Z,1516650123.769 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-01-22T19:42:03.769Z,1516650123.769 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-01-22T19:42:03.770Z,1516650123.770 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-01-22T19:42:03.770Z,1516650123.770 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-01-22T19:42:03.770Z,1516650123.770 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-01-22T19:42:03.770Z,1516650123.770 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-01-22T19:42:03.770Z,1516650123.770 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-01-22T19:42:03.771Z,1516650123.771 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-01-22T19:42:03.771Z,1516650123.771 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-01-22T19:42:03.771Z,1516650123.771 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-01-22T19:42:03.771Z,1516650123.771 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-01-22T19:42:03.771Z,1516650123.771 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-01-22T19:42:03.831Z,1516650123.831 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-01-22T19:42:03.831Z,1516650123.831 [CTD_Seabird](INFO): Powering down
2018-01-22T19:42:03.914Z,1516650123.914 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-01-22T19:42:03.915Z,1516650123.915 [Default:A.Wait](DEBUG): Construct Wait.
2018-01-22T19:42:03.932Z,1516650123.932 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-22T19:42:03.988Z,1516650123.988 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-01-22T19:42:03.990Z,1516650123.990 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-01-22T19:42:03.993Z,1516650123.993 [Rowe_600LCM](INFO): LCM OK
2018-01-22T19:42:03.993Z,1516650123.993 [Rowe_600LCM](INFO): Powering up
2018-01-22T19:42:04.017Z,1516650124.017 [Default:E.Execute](DEBUG): Construct Execute.
2018-01-22T19:42:04.020Z,1516650124.020 [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
2018-01-22T19:42:04.041Z,1516650124.041 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-01-22T19:42:04.053Z,1516650124.053 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-01-22T19:42:04.053Z,1516650124.053 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-01-22T19:42:04.080Z,1516650124.080 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-01-22T19:42:04.455Z,1516650124.455 [ESPComponent](INFO): powering down ESP
2018-01-22T19:42:04.922Z,1516650124.922 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:05.012Z,1516650125.012 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:05.129Z,1516650125.129 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-01-22T19:42:05.137Z,1516650125.137 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-01-22T19:42:05.148Z,1516650125.148 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-01-22T19:42:05.153Z,1516650125.153 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-01-22T19:42:05.175Z,1516650125.175 [MassServo](DEBUG): Initializing EZServoServo.
2018-01-22T19:42:05.181Z,1516650125.181 [MassServo](DEBUG): Initializing MassServo.
2018-01-22T19:42:05.195Z,1516650125.195 [RudderServo](DEBUG): Initializing EZServoServo.
2018-01-22T19:42:05.201Z,1516650125.201 [RudderServo](DEBUG): Initializing RudderServo.
2018-01-22T19:42:05.211Z,1516650125.211 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-01-22T19:42:05.217Z,1516650125.217 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-01-22T19:42:05.246Z,1516650125.246 [CommandLine](FAULT): Scheduling is paused
2018-01-22T19:42:05.246Z,1516650125.246 [CBIT](INFO): Critical error at 20180122T194203
2018-01-22T19:42:05.247Z,1516650125.247 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-01-22T19:42:05.356Z,1516650125.356 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-01-22T19:42:05.356Z,1516650125.356 [DropWeight] Hardware Fault, FailCount= 1
2018-01-22T19:42:05.356Z,1516650125.356 [DropWeight](ERROR): Hardware Fault
2018-01-22T19:42:05.416Z,1516650125.416 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:05.421Z,1516650125.421 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:05.450Z,1516650125.450 [CBIT](INFO): Critical error at 20180122T194205
2018-01-22T19:42:05.452Z,1516650125.452 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-01-22T19:42:05.453Z,1516650125.453 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-01-22T19:42:05.740Z,1516650125.740 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:05.749Z,1516650125.749 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:06.097Z,1516650126.097 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-01-22T19:42:06.097Z,1516650126.097 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-01-22T19:42:06.097Z,1516650126.097 [BuoyancyServo] Communications Fault, FailCount= 1
2018-01-22T19:42:06.097Z,1516650126.097 [BuoyancyServo](ERROR): Communications Fault
2018-01-22T19:42:06.302Z,1516650126.302 [CBIT](INFO): Critical error at 20180122T194205
2018-01-22T19:42:06.305Z,1516650126.305 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-01-22T19:42:06.388Z,1516650126.388 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:06.393Z,1516650126.393 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:06.414Z,1516650126.414 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-01-22T19:42:06.415Z,1516650126.415 [BuoyancyServo](INFO): Powering down
2018-01-22T19:42:06.792Z,1516650126.792 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:06.793Z,1516650126.793 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:07.164Z,1516650127.164 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:07.173Z,1516650127.173 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:07.546Z,1516650127.546 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:07.547Z,1516650127.547 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:07.852Z,1516650127.852 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-22T19:42:07.953Z,1516650127.953 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:07.955Z,1516650127.955 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:07.976Z,1516650127.976 [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 &
2018-01-22T19:42:08.162Z,1516650128.162 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-22T19:42:08.163Z,1516650128.163 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-22T19:42:08.164Z,1516650128.164 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-22T19:42:08.378Z,1516650128.378 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:08.379Z,1516650128.379 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:08.438Z,1516650128.438 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-01-22T19:42:08.438Z,1516650128.438 [BuoyancyServo] No Fault, FailCount= 1
2018-01-22T19:42:08.784Z,1516650128.784 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:08.785Z,1516650128.785 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:08.803Z,1516650128.803 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-01-22T19:42:08.803Z,1516650128.803 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-01-22T19:42:09.164Z,1516650129.164 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:09.173Z,1516650129.173 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:09.589Z,1516650129.589 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:09.590Z,1516650129.590 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:09.965Z,1516650129.965 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:09.973Z,1516650129.973 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:10.385Z,1516650130.385 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:10.386Z,1516650130.386 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:10.764Z,1516650130.764 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:10.773Z,1516650130.773 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:11.165Z,1516650131.165 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:11.166Z,1516650131.166 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:11.514Z,1516650131.514 [AcousticModem_Benthos_ATM900](DEBUG):
2018-01-22T19:42:11.558Z,1516650131.558 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:11.559Z,1516650131.559 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:11.935Z,1516650131.935 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-01-22T19:42:11.935Z,1516650131.935 [PNI_TCM] Data Fault, FailCount= 1
2018-01-22T19:42:11.935Z,1516650131.935 [PNI_TCM](ERROR): Data Fault
2018-01-22T19:42:11.978Z,1516650131.978 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:11.979Z,1516650131.979 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:12.086Z,1516650132.086 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-01-22T19:42:12.334Z,1516650132.334 [PNI_TCM](INFO): Powering down
2018-01-22T19:42:12.396Z,1516650132.396 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:12.413Z,1516650132.413 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:12.749Z,1516650132.749 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:12.750Z,1516650132.750 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:13.113Z,1516650133.113 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-01-22T19:42:13.114Z,1516650133.114 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-01-22T19:42:13.115Z,1516650133.115 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-01-22T19:42:13.115Z,1516650133.115 [AcousticModem_Benthos_ATM900](DEBUG): Feb 20 2000 17:32:41
2018-01-22T19:42:13.165Z,1516650133.165 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:13.166Z,1516650133.166 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-22T19:42:13.513Z,1516650133.513 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low