2018-08-20T16:55:43.353Z,1534784143.353 [Supervisor](DEBUG): Initializing supervisor.
2018-08-20T16:55:43.355Z,1534784143.355 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-08-20T16:55:43.356Z,1534784143.356 [SyncHandler](INFO): Protected caller Thread ID is 797
2018-08-20T16:55:43.357Z,1534784143.357 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-08-20T16:55:43.357Z,1534784143.357 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-08-20T16:55:43.358Z,1534784143.358 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 798
2018-08-20T16:55:43.361Z,1534784143.361 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-08-20T16:55:43.373Z,1534784143.373 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-08-20T16:55:43.374Z,1534784143.374 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-08-20T16:55:43.374Z,1534784143.374 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 799
2018-08-20T16:55:43.375Z,1534784143.375 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-08-20T16:55:43.376Z,1534784143.376 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-08-20T16:55:43.377Z,1534784143.377 [logger ThreadHandler](INFO): Protected caller Thread ID is 800
2018-08-20T16:55:43.379Z,1534784143.379 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-08-20T16:55:43.379Z,1534784143.379 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-08-20T16:55:43.383Z,1534784143.383 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-08-20T16:55:43.741Z,1534784143.741 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-08-20T16:55:43.742Z,1534784143.742 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-08-20T16:55:43.960Z,1534784143.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-08-20T16:55:43.961Z,1534784143.961 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-08-20T16:55:44.263Z,1534784144.263 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-08-20T16:55:44.265Z,1534784144.265 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-08-20T16:55:44.411Z,1534784144.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-08-20T16:55:44.413Z,1534784144.413 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-08-20T16:55:44.513Z,1534784144.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-08-20T16:55:44.515Z,1534784144.515 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-08-20T16:55:45.008Z,1534784145.008 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-08-20T16:55:45.010Z,1534784145.010 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-08-20T16:55:45.457Z,1534784145.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-08-20T16:55:45.459Z,1534784145.459 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-08-20T16:55:45.943Z,1534784145.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-08-20T16:55:45.944Z,1534784145.944 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-08-20T16:55:46.061Z,1534784146.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-08-20T16:55:46.062Z,1534784146.062 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-08-20T16:55:46.162Z,1534784146.162 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-08-20T16:55:46.163Z,1534784146.163 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-08-20T16:55:46.379Z,1534784146.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-08-20T16:55:46.381Z,1534784146.381 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-08-20T16:55:46.603Z,1534784146.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-08-20T16:55:46.603Z,1534784146.603 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-08-20T16:55:46.972Z,1534784146.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-08-20T16:55:46.973Z,1534784146.973 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-08-20T16:55:47.198Z,1534784147.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-08-20T16:55:47.199Z,1534784147.199 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-08-20T16:55:48.064Z,1534784148.064 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-08-20T16:55:48.066Z,1534784148.066 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-08-20T16:55:48.174Z,1534784148.174 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-08-20T16:55:48.298Z,1534784148.298 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-08-20T16:55:48.396Z,1534784148.396 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-08-20T16:55:48.485Z,1534784148.485 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-08-20T16:55:48.651Z,1534784148.651 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-08-20T16:55:48.839Z,1534784148.839 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-08-20T16:55:48.916Z,1534784148.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-08-20T16:55:49.153Z,1534784149.153 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-08-20T16:55:49.154Z,1534784149.154 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-08-20T16:55:49.239Z,1534784149.239 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-08-20T16:55:49.332Z,1534784149.332 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-08-20T16:55:49.438Z,1534784149.438 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-08-20T16:55:49.571Z,1534784149.571 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-08-20T16:55:49.580Z,1534784149.580 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-08-20T16:55:49.860Z,1534784149.860 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-08-20T16:55:49.861Z,1534784149.861 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-08-20T16:55:49.917Z,1534784149.917 [DepthRateCalculator] Loaded
2018-08-20T16:55:49.917Z,1534784149.917 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-08-20T16:55:49.923Z,1534784149.923 [PitchRateCalculator] Loaded
2018-08-20T16:55:49.924Z,1534784149.924 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-08-20T16:55:49.940Z,1534784149.940 [SpeedCalculator] Loaded
2018-08-20T16:55:49.940Z,1534784149.940 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-08-20T16:55:49.963Z,1534784149.963 [TempGradientCalculator] Loaded
2018-08-20T16:55:49.963Z,1534784149.963 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-08-20T16:55:49.980Z,1534784149.980 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-08-20T16:55:49.981Z,1534784149.981 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-08-20T16:55:49.987Z,1534784149.987 [YawRateCalculator] Loaded
2018-08-20T16:55:49.987Z,1534784149.987 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-08-20T16:55:50.028Z,1534784150.028 [ElevatorOffsetCalculator] Loaded
2018-08-20T16:55:50.028Z,1534784150.028 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-08-20T16:55:50.029Z,1534784150.029 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-08-20T16:55:50.031Z,1534784150.031 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-08-20T16:55:50.152Z,1534784150.152 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-08-20T16:55:50.152Z,1534784150.152 [StratificationFrontDetector](DEBUG): (re)initializing
2018-08-20T16:55:50.152Z,1534784150.152 [StratificationFrontDetector] Loaded
2018-08-20T16:55:50.153Z,1534784150.153 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-08-20T16:55:50.153Z,1534784150.153 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-08-20T16:55:50.155Z,1534784150.155 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-08-20T16:55:50.291Z,1534784150.291 [BuoyancyServo] Loaded
2018-08-20T16:55:50.291Z,1534784150.291 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-08-20T16:55:50.306Z,1534784150.306 [ElevatorServo] Loaded
2018-08-20T16:55:50.307Z,1534784150.307 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-08-20T16:55:50.322Z,1534784150.322 [MassServo] Loaded
2018-08-20T16:55:50.323Z,1534784150.323 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-08-20T16:55:50.338Z,1534784150.338 [RudderServo] Loaded
2018-08-20T16:55:50.339Z,1534784150.339 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-08-20T16:55:50.353Z,1534784150.353 [ThrusterServo] Loaded
2018-08-20T16:55:50.353Z,1534784150.353 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-08-20T16:55:50.354Z,1534784150.354 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-08-20T16:55:50.356Z,1534784150.356 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-08-20T16:55:50.380Z,1534784150.380 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-08-20T16:55:50.380Z,1534784150.380 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-08-20T16:55:50.505Z,1534784150.505 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-08-20T16:55:50.507Z,1534784150.507 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-08-20T16:55:51.071Z,1534784151.071 [DataOverHttps] Loaded
2018-08-20T16:55:51.072Z,1534784151.072 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-08-20T16:55:51.086Z,1534784151.086 [Depth_Keller] Loaded
2018-08-20T16:55:51.086Z,1534784151.086 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-08-20T16:55:51.092Z,1534784151.092 [DropWeight] Loaded
2018-08-20T16:55:51.092Z,1534784151.092 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-08-20T16:55:51.193Z,1534784151.193 [NAL9602] Loaded
2018-08-20T16:55:51.193Z,1534784151.193 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-08-20T16:55:51.210Z,1534784151.210 [Onboard] Loaded
2018-08-20T16:55:51.210Z,1534784151.210 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-08-20T16:55:51.221Z,1534784151.221 [Radio_Surface] Loaded
2018-08-20T16:55:51.221Z,1534784151.221 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-08-20T16:55:51.222Z,1534784151.222 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408854E0
2018-08-20T16:55:51.223Z,1534784151.223 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 882
2018-08-20T16:55:51.376Z,1534784151.376 [PNI_TCM] Loaded
2018-08-20T16:55:51.377Z,1534784151.377 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-08-20T16:55:51.439Z,1534784151.439 [Rowe_600LCM] Loaded
2018-08-20T16:55:51.439Z,1534784151.439 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-08-20T16:55:51.440Z,1534784151.440 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408B54E0
2018-08-20T16:55:51.441Z,1534784151.441 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 883
2018-08-20T16:55:53.496Z,1534784153.496 [BPC1] Loaded
2018-08-20T16:55:53.496Z,1534784153.496 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-08-20T16:55:53.497Z,1534784153.497 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-08-20T16:55:53.497Z,1534784153.497 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-08-20T16:55:53.651Z,1534784153.651 [SBIT](DEBUG): Construct Startup Built In Test.
2018-08-20T16:55:53.674Z,1534784153.674 [SBIT] Loaded
2018-08-20T16:55:53.675Z,1534784153.675 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-08-20T16:55:53.675Z,1534784153.675 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-08-20T16:55:53.688Z,1534784153.688 [IBIT] Loaded
2018-08-20T16:55:53.688Z,1534784153.688 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-08-20T16:55:53.691Z,1534784153.691 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-08-20T16:55:53.845Z,1534784153.845 [CBIT] Loaded
2018-08-20T16:55:53.846Z,1534784153.846 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-08-20T16:55:53.846Z,1534784153.846 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-08-20T16:55:53.848Z,1534784153.848 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-08-20T16:55:54.038Z,1534784154.038 [Aanderaa_O2] Loaded
2018-08-20T16:55:54.038Z,1534784154.038 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-08-20T16:55:54.053Z,1534784154.053 [PAR_Licor] Loaded
2018-08-20T16:55:54.054Z,1534784154.054 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-08-20T16:55:54.104Z,1534784154.104 [WetLabsBB2FL] Loaded
2018-08-20T16:55:54.105Z,1534784154.105 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-08-20T16:55:54.106Z,1534784154.106 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409794E0
2018-08-20T16:55:54.106Z,1534784154.106 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 884
2018-08-20T16:55:54.107Z,1534784154.107 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-08-20T16:55:54.107Z,1534784154.107 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-08-20T16:55:54.196Z,1534784154.196 [VerticalControl](DEBUG): Construct VerticalControl.
2018-08-20T16:55:54.283Z,1534784154.283 [VerticalControl] Loaded
2018-08-20T16:55:54.283Z,1534784154.283 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-08-20T16:55:54.284Z,1534784154.284 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-08-20T16:55:54.342Z,1534784154.342 [HorizontalControl] Loaded
2018-08-20T16:55:54.343Z,1534784154.343 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-08-20T16:55:54.343Z,1534784154.343 [SpeedControl](DEBUG): Construct SpeedControl.
2018-08-20T16:55:54.345Z,1534784154.345 [SpeedControl] Loaded
2018-08-20T16:55:54.345Z,1534784154.345 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-08-20T16:55:54.346Z,1534784154.346 [LoopControl](DEBUG): Construct LoopControl.
2018-08-20T16:55:54.347Z,1534784154.347 [LoopControl] Loaded
2018-08-20T16:55:54.347Z,1534784154.347 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-08-20T16:55:54.348Z,1534784154.348 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-08-20T16:55:54.349Z,1534784154.349 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-08-20T16:55:54.387Z,1534784154.387 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-08-20T16:55:54.388Z,1534784154.388 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-08-20T16:55:54.495Z,1534784154.495 [DeadReckonUsingSpeedCalculator] Loaded
2018-08-20T16:55:54.496Z,1534784154.496 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-08-20T16:55:54.513Z,1534784154.513 [NavChart] Loaded
2018-08-20T16:55:54.513Z,1534784154.513 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-08-20T16:55:54.517Z,1534784154.517 [UniversalFixResidualReporter] Loaded
2018-08-20T16:55:54.518Z,1534784154.518 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-08-20T16:55:54.518Z,1534784154.518 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-08-20T16:55:54.522Z,1534784154.522 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-08-20T16:55:54.523Z,1534784154.523 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-08-20T16:55:54.530Z,1534784154.530 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-08-20T16:55:54.531Z,1534784154.531 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A054E0
2018-08-20T16:55:54.531Z,1534784154.531 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 885
2018-08-20T16:55:54.536Z,1534784154.536 [Supervisor](INFO): Main Thread ID is 796
2018-08-20T16:55:54.536Z,1534784154.536 [Supervisor](DEBUG): Running supervisor.
2018-08-20T16:55:54.537Z,1534784154.537 [CommandLine ThreadHandler](INFO): Handler Thread ID is 886
2018-08-20T16:55:54.539Z,1534784154.539 [controlThread ThreadHandler](INFO): Handler Thread ID is 887
2018-08-20T16:55:54.540Z,1534784154.540 [controlThread](DEBUG): Initializing ControlThread
2018-08-20T16:55:54.541Z,1534784154.541 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-08-20T16:55:54.541Z,1534784154.541 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-08-20T16:55:54.542Z,1534784154.542 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-08-20T16:55:54.542Z,1534784154.542 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-08-20T16:55:54.542Z,1534784154.542 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-08-20T16:55:54.543Z,1534784154.543 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-08-20T16:55:54.544Z,1534784154.544 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-08-20T16:55:54.551Z,1534784154.551 [SBIT](INFO): Initialize SBIT Component.
2018-08-20T16:55:54.552Z,1534784154.552 [SBIT](IMPORTANT): git: 2018-08-20
2018-08-20T16:55:54.552Z,1534784154.552 [SBIT](INFO): git hash: 695b514009632b0c9b638e65628c1e5f155de51b
2018-08-20T16:55:54.553Z,1534784154.553 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-08-20T16:55:54.554Z,1534784154.554 [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-08-20T16:55:54.555Z,1534784154.555 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-08-20T16:55:54.555Z,1534784154.555 [IBIT](INFO): Initialize IBIT Component.
2018-08-20T16:55:54.556Z,1534784154.556 [CBIT](DEBUG): Initialize CBIT Component.
2018-08-20T16:55:54.557Z,1534784154.557 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-08-20T16:55:54.558Z,1534784154.558 [logger ThreadHandler](INFO): Handler Thread ID is 888
2018-08-20T16:55:54.577Z,1534784154.577 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 889
2018-08-20T16:55:54.583Z,1534784154.583 [Radio_Surface](INFO): Powering up
2018-08-20T16:55:54.589Z,1534784154.589 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 890
2018-08-20T16:55:54.590Z,1534784154.590 [Rowe_600LCM](INFO): Initializing
2018-08-20T16:55:54.590Z,1534784154.590 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T16:55:54.693Z,1534784154.693 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-08-20T16:55:54.695Z,1534784154.695 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-08-20T16:55:54.696Z,1534784154.696 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-08-20T16:55:54.696Z,1534784154.696 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-08-20T16:55:54.696Z,1534784154.696 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-08-20T16:55:54.697Z,1534784154.697 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-08-20T16:55:54.698Z,1534784154.698 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-08-20T16:55:54.698Z,1534784154.698 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-08-20T16:55:54.699Z,1534784154.699 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-08-20T16:55:54.700Z,1534784154.700 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-08-20T16:55:54.710Z,1534784154.710 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 891
2018-08-20T16:55:54.711Z,1534784154.711 [WetLabsBB2FL](INFO): Powering down
2018-08-20T16:55:54.833Z,1534784154.833 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-20T16:55:54.837Z,1534784154.837 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 892
2018-08-20T16:55:54.846Z,1534784154.846 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-08-20T16:55:54.846Z,1534784154.846 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-08-20T16:55:54.846Z,1534784154.846 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-08-20T16:55:54.847Z,1534784154.847 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-08-20T16:55:54.847Z,1534784154.847 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-08-20T16:55:54.847Z,1534784154.847 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-08-20T16:55:54.847Z,1534784154.847 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-08-20T16:55:54.847Z,1534784154.847 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-08-20T16:55:54.848Z,1534784154.848 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-08-20T16:55:54.848Z,1534784154.848 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-08-20T16:55:54.848Z,1534784154.848 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-08-20T16:55:54.848Z,1534784154.848 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-08-20T16:55:54.849Z,1534784154.849 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-08-20T16:55:54.849Z,1534784154.849 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-08-20T16:55:54.849Z,1534784154.849 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-08-20T16:55:54.849Z,1534784154.849 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-08-20T16:55:54.949Z,1534784154.949 [MissionManager](DEBUG):
2018-08-20T16:55:54.950Z,1534784154.950 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-08-20T16:55:55.041Z,1534784155.041 [Rowe_600LCM](INFO): LCM OK
2018-08-20T16:55:55.041Z,1534784155.041 [Rowe_600LCM](INFO): Powering up
2018-08-20T16:55:55.070Z,1534784155.070 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-08-20T16:55:55.071Z,1534784155.071 [Default:A.Wait](DEBUG): Construct Wait.
2018-08-20T16:55:55.094Z,1534784155.094 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-08-20T16:55:55.125Z,1534784155.125 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-08-20T16:55:55.127Z,1534784155.127 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-08-20T16:55:55.157Z,1534784155.157 [Default:E.Execute](DEBUG): Construct Execute.
2018-08-20T16:55:55.160Z,1534784155.160 [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-08-20T16:55:55.172Z,1534784155.172 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-08-20T16:55:55.201Z,1534784155.201 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-08-20T16:55:55.762Z,1534784155.762 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:55.937Z,1534784155.937 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-20T16:55:55.941Z,1534784155.941 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-20T16:55:55.966Z,1534784155.966 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-08-20T16:55:55.973Z,1534784155.973 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-08-20T16:55:55.987Z,1534784155.987 [MassServo](DEBUG): Initializing EZServoServo.
2018-08-20T16:55:55.993Z,1534784155.993 [MassServo](DEBUG): Initializing MassServo.
2018-08-20T16:55:56.007Z,1534784156.007 [RudderServo](DEBUG): Initializing EZServoServo.
2018-08-20T16:55:56.013Z,1534784156.013 [RudderServo](DEBUG): Initializing RudderServo.
2018-08-20T16:55:56.035Z,1534784156.035 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-08-20T16:55:56.041Z,1534784156.041 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-08-20T16:55:56.259Z,1534784156.259 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:56.589Z,1534784156.589 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:56.937Z,1534784156.937 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-08-20T16:55:56.937Z,1534784156.937 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-08-20T16:55:56.937Z,1534784156.937 [BuoyancyServo] Communications Fault, FailCount= 1
2018-08-20T16:55:56.937Z,1534784156.937 [BuoyancyServo](ERROR): Communications Fault
2018-08-20T16:55:57.145Z,1534784157.145 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-08-20T16:55:57.203Z,1534784157.203 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:57.225Z,1534784157.225 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-08-20T16:55:57.226Z,1534784157.226 [BuoyancyServo](INFO): Powering down
2018-08-20T16:55:57.609Z,1534784157.609 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:58.025Z,1534784158.025 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:58.409Z,1534784158.409 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:58.805Z,1534784158.805 [Aanderaa_O2](INFO): Powering down
2018-08-20T16:55:58.916Z,1534784158.916 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-08-20T16:55:59.093Z,1534784159.093 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T16:55:59.204Z,1534784159.204 [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 9600 >& /dev/null &
2018-08-20T16:55:59.431Z,1534784159.431 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T16:55:59.432Z,1534784159.432 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T16:55:59.442Z,1534784159.442 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-08-20T16:55:59.442Z,1534784159.442 [BuoyancyServo] No Fault, FailCount= 1
2018-08-20T16:55:59.445Z,1534784159.445 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T16:55:59.653Z,1534784159.653 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-08-20T16:55:59.654Z,1534784159.654 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-08-20T16:56:18.115Z,1534784178.115 [SBIT](IMPORTANT): Beginning Startup BIT
2018-08-20T16:56:18.130Z,1534784178.130 [CBIT](IMPORTANT): Beginning ground fault scan
2018-08-20T16:56:21.320Z,1534784181.320 [NAL9602](INFO): Powering up NAL9602
2018-08-20T16:56:29.023Z,1534784189.023 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): -0.009265
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001612
CHAN B0 (3.3V): 0.000226
CHAN B1 (3.15aV): -0.000096
CHAN B2 (3.15bV): -0.000045
CHAN B3 (GND): 0.000034
OPEN: -0.000242
Full Scale Calc: 4.765 mA, -1.589 mA
2018-08-20T16:56:32.515Z,1534784192.515 [NAL9602](INFO): NAL9602 initialized
2018-08-20T16:57:11.892Z,1534784231.892 [SBIT](IMPORTANT): SBIT PASSED
2018-08-20T16:57:11.983Z,1534784231.983 [CommandLine](IMPORTANT): got command configSet list
2018-08-20T16:57:11.983Z,1534784231.983 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-08-20T16:57:11.984Z,1534784231.984 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;
2018-08-20T16:57:11.986Z,1534784231.986 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;
2018-08-20T16:57:12.276Z,1534784232.276 [MissionManager](IMPORTANT): Started mission Startup
2018-08-20T16:57:12.285Z,1534784232.285 [Startup] Running Loop=1
2018-08-20T16:57:12.285Z,1534784232.285 [Startup](DEBUG): Aggregate::initialize Startup
2018-08-20T16:57:12.285Z,1534784232.285 [Startup:A.GoToSurface] Running Loop=1
2018-08-20T16:57:12.285Z,1534784232.285 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-08-20T16:57:12.286Z,1534784232.286 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-08-20T16:57:12.287Z,1534784232.287 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-08-20T16:57:12.287Z,1534784232.287 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-08-20T16:57:12.288Z,1534784232.288 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-08-20T16:57:12.288Z,1534784232.288 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-08-20T16:57:12.329Z,1534784232.329 [Startup:StartupSatComms] Running Loop=1
2018-08-20T16:57:12.329Z,1534784232.329 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-08-20T16:57:12.329Z,1534784232.329 [Startup:StartupSatComms:A] Running Loop=1
2018-08-20T16:57:12.653Z,1534784232.653 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-08-20T16:57:29.416Z,1534784249.416 [BPC1](ERROR): Failed to parse Bank B battery data
2018-08-20T16:57:55.757Z,1534784275.757 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-08-20T16:57:55.757Z,1534784275.757 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-08-20T16:57:55.757Z,1534784275.757 [Rowe_600LCM](ERROR): Communications Fault
2018-08-20T16:57:55.927Z,1534784275.927 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-08-20T16:57:56.161Z,1534784276.161 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-08-20T16:57:56.547Z,1534784276.547 [Rowe_600LCM](INFO): Powering down
2018-08-20T16:57:57.838Z,1534784277.838 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-08-20T16:57:57.839Z,1534784277.839 [Rowe_600LCM] No Fault, FailCount= 1
2018-08-20T16:57:58.173Z,1534784278.173 [Rowe_600LCM](INFO): Initializing
2018-08-20T16:57:58.173Z,1534784278.173 [Rowe_600LCM](INFO): Checking LCM
2018-08-20T16:57:58.173Z,1534784278.173 [Rowe_600LCM](INFO): LCM OK
2018-08-20T16:57:58.174Z,1534784278.174 [Rowe_600LCM](INFO): Powering up
2018-08-20T16:58:02.360Z,1534784282.360 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-08-20T16:58:02.420Z,1534784282.420 [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 9600 >& /dev/null &
2018-08-20T16:58:02.422Z,1534784282.422 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-08-20T16:58:02.423Z,1534784282.423 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-08-20T16:58:02.424Z,1534784282.424 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-08-20T16:58:12.620Z,1534784292.620 [Startup:StartupSatComms:A](INFO): Timed out from 2018-08-20T16:57:12.3Z
2018-08-20T16:58:12.620Z,1534784292.620 [Startup:StartupSatComms:A] Stopped
2018-08-20T16:58:12.620Z,1534784292.620 [Startup:StartupSatComms:B] Running Loop=1
2018-08-20T16:58:13.023Z,1534784293.023 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-08-20T16:58:21.721Z,1534784301.721 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005088
2018-08-20T16:58:26.090Z,1534784306.090 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180820T164933/Courier0004.lzma
2018-08-20T16:58:26.876Z,1534784306.876 [DataOverHttps](INFO): Moved sent file to Logs/20180820T164933/Courier0004.lzma.bak
2018-08-20T16:58:26.877Z,1534784306.877 [DataOverHttps](INFO): SBD MOMSN=8430105
2018-08-20T16:58:42.762Z,1534784322.762 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20180820T164933/Express0005.lzma
2018-08-20T16:58:43.548Z,1534784323.548 [DataOverHttps](INFO): Moved sent file to Logs/20180820T164933/Express0005.lzma.bak
2018-08-20T16:58:43.548Z,1534784323.548 [DataOverHttps](INFO): SBD MOMSN=8430107
2018-08-20T16:58:53.695Z,1534784333.695 [DataOverHttps](INFO): Sending 734 bytes from file Logs/20180820T165543/Express0001.lzma
2018-08-20T16:58:54.492Z,1534784334.492 [DataOverHttps](INFO): Moved sent file to Logs/20180820T165543/Express0001.lzma.bak
2018-08-20T16:58:54.492Z,1534784334.492 [DataOverHttps](INFO): SBD MOMSN=8430111
2018-08-20T16:58:55.329Z,1534784335.329 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-08-20T16:58:55.329Z,1534784335.329 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-08-20T16:58:55.329Z,1534784335.329 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-08-20T16:58:55.332Z,1534784335.332 [Startup:StartupSatComms:B] Stopped
2018-08-20T16:58:55.332Z,1534784335.332 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-08-20T16:58:55.332Z,1534784335.332 [Startup:StartupSatComms] Stopped
2018-08-20T16:58:55.332Z,1534784335.332 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-08-20T16:58:55.338Z,1534784335.338 [Startup](INFO): Completed Startup
2018-08-20T16:58:55.338Z,1534784335.338 [MissionManager](INFO): Startup is completed.
2018-08-20T16:58:55.338Z,1534784335.338 [MissionManager](INFO): Uninitializing Mission Startup
2018-08-20T16:58:55.338Z,1534784335.338 [Startup] Stopped
2018-08-20T16:58:55.338Z,1534784335.338 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-08-20T16:58:55.338Z,1534784335.338 [Startup:A.GoToSurface] Stopped
2018-08-20T16:58:55.338Z,1534784335.338 [Startup:A.GoToSurface](DEBUG): Uninitialize G