2018-11-05T23:42:44.964Z,1541461364.964 [Supervisor](DEBUG): Initializing supervisor.
2018-11-05T23:42:44.966Z,1541461364.966 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-05T23:42:44.967Z,1541461364.967 [SyncHandler](INFO): Protected caller Thread ID is 797
2018-11-05T23:42:44.967Z,1541461364.967 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-05T23:42:44.968Z,1541461364.968 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-05T23:42:44.969Z,1541461364.969 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 798
2018-11-05T23:42:44.971Z,1541461364.971 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-05T23:42:44.983Z,1541461364.983 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-05T23:42:44.984Z,1541461364.984 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-05T23:42:44.985Z,1541461364.985 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 799
2018-11-05T23:42:44.986Z,1541461364.986 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-05T23:42:44.987Z,1541461364.987 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-05T23:42:44.987Z,1541461364.987 [logger ThreadHandler](INFO): Protected caller Thread ID is 800
2018-11-05T23:42:44.989Z,1541461364.989 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-05T23:42:44.989Z,1541461364.989 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-05T23:42:44.993Z,1541461364.993 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-05T23:42:45.340Z,1541461365.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-05T23:42:45.340Z,1541461365.340 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-05T23:42:45.552Z,1541461365.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-05T23:42:45.553Z,1541461365.553 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-05T23:42:45.865Z,1541461365.865 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-05T23:42:45.866Z,1541461365.866 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-05T23:42:46.016Z,1541461366.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-05T23:42:46.017Z,1541461366.017 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-05T23:42:46.118Z,1541461366.118 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-05T23:42:46.120Z,1541461366.120 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-05T23:42:46.598Z,1541461366.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-05T23:42:46.599Z,1541461366.599 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-05T23:42:47.168Z,1541461367.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-05T23:42:47.170Z,1541461367.170 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-05T23:42:47.658Z,1541461367.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-05T23:42:47.660Z,1541461367.660 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-05T23:42:47.767Z,1541461367.767 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-05T23:42:47.769Z,1541461367.769 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-05T23:42:47.868Z,1541461367.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-05T23:42:47.868Z,1541461367.868 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-05T23:42:48.092Z,1541461368.092 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-05T23:42:48.092Z,1541461368.092 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-05T23:42:48.304Z,1541461368.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-05T23:42:48.305Z,1541461368.305 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-05T23:42:48.672Z,1541461368.672 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-05T23:42:48.673Z,1541461368.673 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-05T23:42:49.347Z,1541461369.347 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-05T23:42:49.349Z,1541461369.349 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-05T23:42:49.433Z,1541461369.433 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-11-05T23:42:49.435Z,1541461369.435 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-11-05T23:42:49.543Z,1541461369.543 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-11-05T23:42:49.666Z,1541461369.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-11-05T23:42:49.763Z,1541461369.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-11-05T23:42:49.850Z,1541461369.850 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-11-05T23:42:50.021Z,1541461370.021 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-11-05T23:42:50.210Z,1541461370.210 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-11-05T23:42:50.287Z,1541461370.287 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-11-05T23:42:50.520Z,1541461370.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-05T23:42:50.521Z,1541461370.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-11-05T23:42:50.606Z,1541461370.606 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-11-05T23:42:50.701Z,1541461370.701 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-11-05T23:42:50.805Z,1541461370.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-11-05T23:42:50.938Z,1541461370.938 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-11-05T23:42:50.938Z,1541461370.938 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-05T23:42:50.952Z,1541461370.952 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-05T23:42:51.235Z,1541461371.235 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-05T23:42:51.236Z,1541461371.236 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-05T23:42:51.292Z,1541461371.292 [DepthRateCalculator] Loaded
2018-11-05T23:42:51.293Z,1541461371.293 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-05T23:42:51.299Z,1541461371.299 [PitchRateCalculator] Loaded
2018-11-05T23:42:51.299Z,1541461371.299 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-05T23:42:51.315Z,1541461371.315 [SpeedCalculator] Loaded
2018-11-05T23:42:51.316Z,1541461371.316 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-05T23:42:51.337Z,1541461371.337 [TempGradientCalculator] Loaded
2018-11-05T23:42:51.337Z,1541461371.337 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-05T23:42:51.343Z,1541461371.343 [YawRateCalculator] Loaded
2018-11-05T23:42:51.343Z,1541461371.343 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-05T23:42:51.383Z,1541461371.383 [ElevatorOffsetCalculator] Loaded
2018-11-05T23:42:51.383Z,1541461371.383 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-05T23:42:51.384Z,1541461371.384 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-05T23:42:51.384Z,1541461371.384 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-05T23:42:51.487Z,1541461371.487 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-05T23:42:51.489Z,1541461371.489 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-05T23:42:51.622Z,1541461371.622 [BuoyancyServo] Loaded
2018-11-05T23:42:51.623Z,1541461371.623 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-05T23:42:51.637Z,1541461371.637 [ElevatorServo] Loaded
2018-11-05T23:42:51.638Z,1541461371.638 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-05T23:42:51.652Z,1541461371.652 [MassServo] Loaded
2018-11-05T23:42:51.653Z,1541461371.653 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-05T23:42:51.668Z,1541461371.668 [RudderServo] Loaded
2018-11-05T23:42:51.668Z,1541461371.668 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-05T23:42:51.683Z,1541461371.683 [ThrusterServo] Loaded
2018-11-05T23:42:51.683Z,1541461371.683 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-05T23:42:51.683Z,1541461371.683 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-05T23:42:51.684Z,1541461371.684 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-05T23:42:51.708Z,1541461371.708 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-05T23:42:51.709Z,1541461371.709 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-05T23:42:51.835Z,1541461371.835 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-05T23:42:51.836Z,1541461371.836 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-05T23:42:52.409Z,1541461372.409 [DataOverHttps] Loaded
2018-11-05T23:42:52.409Z,1541461372.409 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-05T23:42:52.423Z,1541461372.423 [Depth_Keller] Loaded
2018-11-05T23:42:52.423Z,1541461372.423 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-05T23:42:52.428Z,1541461372.428 [DropWeight] Loaded
2018-11-05T23:42:52.428Z,1541461372.428 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-05T23:42:52.526Z,1541461372.526 [NAL9602] Loaded
2018-11-05T23:42:52.526Z,1541461372.526 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-05T23:42:52.542Z,1541461372.542 [Onboard] Loaded
2018-11-05T23:42:52.542Z,1541461372.542 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-05T23:42:52.553Z,1541461372.553 [Radio_Surface] Loaded
2018-11-05T23:42:52.553Z,1541461372.553 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-05T23:42:52.554Z,1541461372.554 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-11-05T23:42:52.555Z,1541461372.555 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 883
2018-11-05T23:42:52.707Z,1541461372.707 [PNI_TCM] Loaded
2018-11-05T23:42:52.707Z,1541461372.707 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-05T23:42:52.767Z,1541461372.767 [Rowe_600LCM] Loaded
2018-11-05T23:42:52.768Z,1541461372.768 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-05T23:42:52.769Z,1541461372.769 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-11-05T23:42:52.769Z,1541461372.769 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 884
2018-11-05T23:42:52.770Z,1541461372.770 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-05T23:42:52.770Z,1541461372.770 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-05T23:42:52.923Z,1541461372.923 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-05T23:42:52.945Z,1541461372.945 [SBIT] Loaded
2018-11-05T23:42:52.945Z,1541461372.945 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-05T23:42:52.946Z,1541461372.946 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-05T23:42:52.959Z,1541461372.959 [IBIT] Loaded
2018-11-05T23:42:52.959Z,1541461372.959 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-05T23:42:52.962Z,1541461372.962 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-05T23:42:53.111Z,1541461373.111 [CBIT] Loaded
2018-11-05T23:42:53.111Z,1541461373.111 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-05T23:42:53.111Z,1541461373.111 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-05T23:42:53.112Z,1541461373.112 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-05T23:42:53.318Z,1541461373.318 [Aanderaa_O2] Loaded
2018-11-05T23:42:53.318Z,1541461373.318 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-05T23:42:53.400Z,1541461373.400 [CTD_NeilBrown] Loaded
2018-11-05T23:42:53.400Z,1541461373.400 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-11-05T23:42:53.401Z,1541461373.401 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4098B4E0
2018-11-05T23:42:53.402Z,1541461373.402 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 885
2018-11-05T23:42:53.416Z,1541461373.416 [PAR_Licor] Loaded
2018-11-05T23:42:53.416Z,1541461373.416 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-05T23:42:53.465Z,1541461373.465 [WetLabsBB2FL] Loaded
2018-11-05T23:42:53.465Z,1541461373.465 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-05T23:42:53.466Z,1541461373.466 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409BB4E0
2018-11-05T23:42:53.467Z,1541461373.467 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 886
2018-11-05T23:42:53.467Z,1541461373.467 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-05T23:42:53.468Z,1541461373.468 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-05T23:42:53.556Z,1541461373.556 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-05T23:42:53.639Z,1541461373.639 [VerticalControl] Loaded
2018-11-05T23:42:53.640Z,1541461373.640 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-05T23:42:53.640Z,1541461373.640 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-05T23:42:53.697Z,1541461373.697 [HorizontalControl] Loaded
2018-11-05T23:42:53.697Z,1541461373.697 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-05T23:42:53.698Z,1541461373.698 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-05T23:42:53.700Z,1541461373.700 [SpeedControl] Loaded
2018-11-05T23:42:53.700Z,1541461373.700 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-05T23:42:53.701Z,1541461373.701 [LoopControl](DEBUG): Construct LoopControl.
2018-11-05T23:42:53.701Z,1541461373.701 [LoopControl] Loaded
2018-11-05T23:42:53.702Z,1541461373.702 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-05T23:42:53.702Z,1541461373.702 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-05T23:42:53.704Z,1541461373.704 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-05T23:42:53.846Z,1541461373.846 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-05T23:42:53.847Z,1541461373.847 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-05T23:42:54.699Z,1541461374.699 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-05T23:42:54.699Z,1541461374.699 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-05T23:42:54.715Z,1541461374.715 [NavChart] Loaded
2018-11-05T23:42:54.716Z,1541461374.716 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-05T23:42:54.720Z,1541461374.720 [UniversalFixResidualReporter] Loaded
2018-11-05T23:42:54.720Z,1541461374.720 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-05T23:42:54.721Z,1541461374.721 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-05T23:42:54.739Z,1541461374.739 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-05T23:42:54.740Z,1541461374.740 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-05T23:42:54.748Z,1541461374.748 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-05T23:42:54.749Z,1541461374.749 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0
2018-11-05T23:42:54.750Z,1541461374.750 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 887
2018-11-05T23:42:54.754Z,1541461374.754 [Supervisor](INFO): Main Thread ID is 796
2018-11-05T23:42:54.754Z,1541461374.754 [Supervisor](DEBUG): Running supervisor.
2018-11-05T23:42:54.755Z,1541461374.755 [CommandLine ThreadHandler](INFO): Handler Thread ID is 888
2018-11-05T23:42:54.757Z,1541461374.757 [controlThread ThreadHandler](INFO): Handler Thread ID is 889
2018-11-05T23:42:54.758Z,1541461374.758 [controlThread](DEBUG): Initializing ControlThread
2018-11-05T23:42:54.759Z,1541461374.759 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-05T23:42:54.759Z,1541461374.759 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-05T23:42:54.759Z,1541461374.759 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-05T23:42:54.760Z,1541461374.760 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-05T23:42:54.760Z,1541461374.760 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-05T23:42:54.761Z,1541461374.761 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-05T23:42:54.767Z,1541461374.767 [SBIT](INFO): Initialize SBIT Component.
2018-11-05T23:42:54.768Z,1541461374.768 [SBIT](IMPORTANT): git: 2018-11-05
2018-11-05T23:42:54.768Z,1541461374.768 [SBIT](INFO): git hash: 17f8e4440ddc7f0910aa911cb821ed1a114d9cee
2018-11-05T23:42:54.768Z,1541461374.768 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-05T23:42:54.768Z,1541461374.768 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-05T23:42:54.770Z,1541461374.770 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-11-05T23:42:54.770Z,1541461374.770 [IBIT](INFO): Initialize IBIT Component.
2018-11-05T23:42:54.771Z,1541461374.771 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-05T23:42:54.771Z,1541461374.771 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-11-05T23:42:54.772Z,1541461374.772 [logger ThreadHandler](INFO): Handler Thread ID is 890
2018-11-05T23:42:54.793Z,1541461374.793 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 891
2018-11-05T23:42:54.799Z,1541461374.799 [Radio_Surface](INFO): Powering up
2018-11-05T23:42:54.805Z,1541461374.805 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 892
2018-11-05T23:42:54.806Z,1541461374.806 [Rowe_600LCM](INFO): Initializing
2018-11-05T23:42:54.807Z,1541461374.807 [Rowe_600LCM](INFO): Checking LCM
2018-11-05T23:42:54.908Z,1541461374.908 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 893
2018-11-05T23:42:54.909Z,1541461374.909 [CTD_NeilBrown](INFO): Powering down
2018-11-05T23:42:54.930Z,1541461374.930 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-05T23:42:54.932Z,1541461374.932 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-05T23:42:54.935Z,1541461374.935 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-05T23:42:54.937Z,1541461374.937 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-05T23:42:54.937Z,1541461374.937 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-05T23:42:54.938Z,1541461374.938 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-05T23:42:55.002Z,1541461375.002 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-05T23:42:55.003Z,1541461375.003 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-05T23:42:55.003Z,1541461375.003 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-05T23:42:55.004Z,1541461375.004 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-05T23:42:55.016Z,1541461375.016 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 894
2018-11-05T23:42:55.018Z,1541461375.018 [WetLabsBB2FL](INFO): Powering down
2018-11-05T23:42:55.037Z,1541461375.037 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 895
2018-11-05T23:42:55.181Z,1541461375.181 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-05T23:42:55.184Z,1541461375.184 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-05T23:42:55.184Z,1541461375.184 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-05T23:42:55.184Z,1541461375.184 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-05T23:42:55.184Z,1541461375.184 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-05T23:42:55.184Z,1541461375.184 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-05T23:42:55.184Z,1541461375.184 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-05T23:42:55.185Z,1541461375.185 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-05T23:42:55.185Z,1541461375.185 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-05T23:42:55.185Z,1541461375.185 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-05T23:42:55.185Z,1541461375.185 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-05T23:42:55.185Z,1541461375.185 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-05T23:42:55.186Z,1541461375.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-05T23:42:55.186Z,1541461375.186 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-05T23:42:55.186Z,1541461375.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-05T23:42:55.186Z,1541461375.186 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-05T23:42:55.186Z,1541461375.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-05T23:42:55.192Z,1541461375.192 [Rowe_600LCM](INFO): LCM OK
2018-11-05T23:42:55.192Z,1541461375.192 [Rowe_600LCM](INFO): Powering up
2018-11-05T23:42:55.211Z,1541461375.211 [MissionManager](DEBUG):
2018-11-05T23:42:55.211Z,1541461375.211 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-05T23:42:55.275Z,1541461375.275 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-05T23:42:55.276Z,1541461375.276 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-05T23:42:55.278Z,1541461375.278 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-05T23:42:55.326Z,1541461375.326 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-05T23:42:55.328Z,1541461375.328 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-05T23:42:55.355Z,1541461375.355 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-05T23:42:55.359Z,1541461375.359 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2018-11-05T23:42:55.373Z,1541461375.373 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-11-05T23:42:55.398Z,1541461375.398 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-05T23:42:55.447Z,1541461375.447 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-11-05T23:42:55.722Z,1541461375.722 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-11-05T23:42:56.010Z,1541461376.010 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:42:56.013Z,1541461376.013 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-05T23:42:56.035Z,1541461376.035 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:42:56.041Z,1541461376.041 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-05T23:42:56.047Z,1541461376.047 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:42:56.053Z,1541461376.053 [MassServo](DEBUG): Initializing MassServo.
2018-11-05T23:42:56.059Z,1541461376.059 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:42:56.066Z,1541461376.066 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-05T23:42:56.087Z,1541461376.087 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:42:56.093Z,1541461376.093 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-05T23:42:56.327Z,1541461376.327 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-11-05T23:42:56.327Z,1541461376.327 [DropWeight] Hardware Fault, FailCount= 1
2018-11-05T23:42:56.327Z,1541461376.327 [DropWeight](ERROR): Hardware Fault
2018-11-05T23:42:56.414Z,1541461376.414 [CommandLine](FAULT): Scheduling is paused
2018-11-05T23:42:56.414Z,1541461376.414 [CBIT](INFO): Critical error at 20181105T234256
2018-11-05T23:42:56.415Z,1541461376.415 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-11-05T23:42:56.417Z,1541461376.417 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-05T23:42:56.418Z,1541461376.418 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-05T23:42:56.937Z,1541461376.937 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-11-05T23:42:56.937Z,1541461376.937 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-11-05T23:42:56.937Z,1541461376.937 [BuoyancyServo] Communications Fault, FailCount= 1
2018-11-05T23:42:56.937Z,1541461376.937 [BuoyancyServo](ERROR): Communications Fault
2018-11-05T23:42:57.143Z,1541461377.143 [CBIT](INFO): Critical error at 20181105T234256
2018-11-05T23:42:57.145Z,1541461377.145 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-11-05T23:42:58.905Z,1541461378.905 [Aanderaa_O2](INFO): Powering down
2018-11-05T23:42:59.194Z,1541461379.194 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-05T23:42:59.363Z,1541461379.363 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-11-05T23:42:59.363Z,1541461379.363 [BuoyancyServo] No Fault, FailCount= 1
2018-11-05T23:42:59.374Z,1541461379.374 [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-11-05T23:42:59.523Z,1541461379.523 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-05T23:42:59.524Z,1541461379.524 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-05T23:42:59.524Z,1541461379.524 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-05T23:42:59.703Z,1541461379.703 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-05T23:42:59.704Z,1541461379.704 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-05T23:43:02.138Z,1541461382.138 [CommandLine](IMPORTANT): got command quit
2018-11-05T23:43:03.144Z,1541461383.144 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:03.144Z,1541461383.144 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.281Z,1541461383.281 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-11-05T23:43:03.282Z,1541461383.282 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.282Z,1541461383.282 [CommandLine](INFO): Join timeout helper Thread ID is 908
2018-11-05T23:43:03.298Z,1541461383.298 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-05T23:43:03.298Z,1541461383.298 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.299Z,1541461383.299 [NavChartDb](INFO): Join timeout helper Thread ID is 909
2018-11-05T23:43:03.393Z,1541461383.393 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:03.394Z,1541461383.394 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.397Z,1541461383.397 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-05T23:43:03.397Z,1541461383.397 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.397Z,1541461383.397 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 910
2018-11-05T23:43:03.629Z,1541461383.629 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:03.629Z,1541461383.629 [WetLabsBB2FL](INFO): Powering down
2018-11-05T23:43:03.630Z,1541461383.630 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.633Z,1541461383.633 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-11-05T23:43:03.633Z,1541461383.633 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.634Z,1541461383.634 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 911
2018-11-05T23:43:03.721Z,1541461383.721 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:03.721Z,1541461383.721 [CTD_NeilBrown](INFO): Powering down
2018-11-05T23:43:03.733Z,1541461383.733 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.737Z,1541461383.737 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-05T23:43:03.737Z,1541461383.737 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:03.737Z,1541461383.737 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 912
2018-11-05T23:43:03.921Z,1541461383.921 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:03.921Z,1541461383.921 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-05T23:43:04.281Z,1541461384.281 [Rowe_600LCM](INFO): Powering down
2018-11-05T23:43:04.282Z,1541461384.282 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:04.298Z,1541461384.298 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-05T23:43:04.298Z,1541461384.298 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:04.299Z,1541461384.299 [Radio_Surface](INFO): Join timeout helper Thread ID is 914
2018-11-05T23:43:04.309Z,1541461384.309 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:04.310Z,1541461384.310 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:04.326Z,1541461384.326 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-05T23:43:04.326Z,1541461384.326 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:04.326Z,1541461384.326 [logger](INFO): Join timeout helper Thread ID is 915
2018-11-05T23:43:04.346Z,1541461384.346 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:04.346Z,1541461384.346 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:04.360Z,1541461384.360 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-05T23:43:04.360Z,1541461384.360 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:04.361Z,1541461384.361 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-05T23:43:04.361Z,1541461384.361 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:04.361Z,1541461384.361 [controlThread](INFO): Join timeout helper Thread ID is 916
2018-11-05T23:43:04.445Z,1541461384.445 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-05T23:43:04.445Z,1541461384.445 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-05T23:43:04.446Z,1541461384.446 [NAL9602](INFO): Powering down
2018-11-05T23:43:04.467Z,1541461384.467 [PNI_TCM](INFO): Powering down
2018-11-05T23:43:04.553Z,1541461384.553 [Aanderaa_O2](INFO): Powering down
2018-11-05T23:43:04.555Z,1541461384.555 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-05T23:43:04.556Z,1541461384.556 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-05T23:43:04.556Z,1541461384.556 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-05T23:43:04.557Z,1541461384.557 [MissionManager](INFO): Uninitializing Mission Default
2018-11-05T23:43:04.559Z,1541461384.559 [MissionManager](INFO): Uninitializing Mission Startup
2018-11-05T23:43:04.561Z,1541461384.561 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-05T23:43:04.561Z,1541461384.561 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-05T23:43:04.562Z,1541461384.562 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-05T23:43:04.562Z,1541461384.562 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-05T23:43:04.562Z,1541461384.562 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-05T23:43:04.562Z,1541461384.562 [BuoyancyServo](INFO): Powering down
2018-11-05T23:43:04.713Z,1541461384.713 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-05T23:43:04.713Z,1541461384.713 [ElevatorServo](INFO): Powering down
2018-11-05T23:43:04.733Z,1541461384.733 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-05T23:43:04.734Z,1541461384.734 [MassServo](INFO): Powering down
2018-11-05T23:43:04.753Z,1541461384.753 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-05T23:43:04.753Z,1541461384.753 [RudderServo](INFO): Powering down
2018-11-05T23:43:04.754Z,1541461384.754 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-05T23:43:04.755Z,1541461384.755 [ThrusterServo](INFO): Powering down
2018-11-05T23:43:04.756Z,1541461384.756 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-05T23:43:04.756Z,1541461384.756 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-05T23:43:04.756Z,1541461384.756 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-05T23:43:04.757Z,1541461384.757 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:05.050Z,1541461385.050 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:05.057Z,1541461385.057 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:05.096Z,1541461385.096 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:05.101Z,1541461385.101 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:05.130Z,1541461385.130 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-05T23:43:05.191Z,1541461385.191 [logger ThreadHandler](INFO): Thread cancelled.