2019-05-19T07:15:46.280Z,1558250146.280 [Supervisor](DEBUG): Initializing supervisor.
2019-05-19T07:15:46.283Z,1558250146.283 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-19T07:15:46.284Z,1558250146.284 [SyncHandler](INFO): Protected caller Thread ID is 2831
2019-05-19T07:15:46.285Z,1558250146.285 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-19T07:15:46.286Z,1558250146.286 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-19T07:15:46.286Z,1558250146.286 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2832
2019-05-19T07:15:46.289Z,1558250146.289 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-19T07:15:46.301Z,1558250146.301 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-19T07:15:46.302Z,1558250146.302 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-19T07:15:46.302Z,1558250146.302 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2833
2019-05-19T07:15:46.303Z,1558250146.303 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-19T07:15:46.304Z,1558250146.304 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-19T07:15:46.304Z,1558250146.304 [logger ThreadHandler](INFO): Protected caller Thread ID is 2834
2019-05-19T07:15:46.306Z,1558250146.306 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-19T07:15:46.307Z,1558250146.307 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-19T07:15:46.308Z,1558250146.308 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-19T07:15:46.506Z,1558250146.506 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-19T07:15:46.506Z,1558250146.506 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-19T07:15:46.587Z,1558250146.587 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-19T07:15:47.009Z,1558250147.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-19T07:15:47.010Z,1558250147.010 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-19T07:15:47.330Z,1558250147.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-19T07:15:47.331Z,1558250147.331 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-19T07:15:47.427Z,1558250147.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-19T07:15:47.428Z,1558250147.428 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-19T07:15:47.720Z,1558250147.720 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-19T07:15:47.720Z,1558250147.720 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-19T07:15:47.913Z,1558250147.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-19T07:15:47.913Z,1558250147.913 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-19T07:15:48.356Z,1558250148.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-19T07:15:48.357Z,1558250148.357 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-19T07:15:48.462Z,1558250148.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-19T07:15:48.462Z,1558250148.462 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-19T07:15:48.563Z,1558250148.563 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-19T07:15:48.563Z,1558250148.563 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-19T07:15:49.127Z,1558250149.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-19T07:15:49.127Z,1558250149.127 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-19T07:15:49.509Z,1558250149.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-19T07:15:49.509Z,1558250149.509 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-19T07:15:49.699Z,1558250149.699 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-19T07:15:49.699Z,1558250149.699 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-19T07:15:49.846Z,1558250149.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-19T07:15:49.846Z,1558250149.846 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-19T07:15:49.994Z,1558250149.994 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-19T07:15:49.996Z,1558250149.996 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-05-19T07:15:49.997Z,1558250149.997 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-05-19T07:15:50.088Z,1558250150.088 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-05-19T07:15:50.174Z,1558250150.174 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-05-19T07:15:50.275Z,1558250150.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-05-19T07:15:50.359Z,1558250150.359 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-05-19T07:15:50.455Z,1558250150.455 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-05-19T07:15:50.555Z,1558250150.555 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-05-19T07:15:50.864Z,1558250150.864 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-05-19T07:15:50.942Z,1558250150.942 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-05-19T07:15:51.341Z,1558250151.341 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-05-19T07:15:51.570Z,1558250151.570 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-05-19T07:15:51.818Z,1558250151.818 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-05-19T07:15:52.045Z,1558250152.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-19T07:15:52.047Z,1558250152.047 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2019-05-19T07:15:52.047Z,1558250152.047 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-19T07:15:52.062Z,1558250152.062 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-19T07:15:52.123Z,1558250152.123 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-19T07:15:52.235Z,1558250152.235 [VerticalControl] Loaded
2019-05-19T07:15:52.236Z,1558250152.236 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-19T07:15:52.236Z,1558250152.236 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-19T07:15:52.305Z,1558250152.305 [HorizontalControl] Loaded
2019-05-19T07:15:52.305Z,1558250152.305 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-19T07:15:52.306Z,1558250152.306 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-19T07:15:52.311Z,1558250152.311 [SpeedControl] Loaded
2019-05-19T07:15:52.311Z,1558250152.311 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-19T07:15:52.312Z,1558250152.312 [LoopControl](DEBUG): Construct LoopControl.
2019-05-19T07:15:52.313Z,1558250152.313 [LoopControl] Loaded
2019-05-19T07:15:52.313Z,1558250152.313 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-19T07:15:52.313Z,1558250152.313 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-19T07:15:52.314Z,1558250152.314 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-19T07:15:52.327Z,1558250152.327 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-19T07:15:52.327Z,1558250152.327 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-19T07:15:52.419Z,1558250152.419 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-19T07:15:52.419Z,1558250152.419 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-19T07:15:52.539Z,1558250152.539 [BuoyancyServo] Loaded
2019-05-19T07:15:52.539Z,1558250152.539 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-19T07:15:52.550Z,1558250152.550 [ElevatorServo] Loaded
2019-05-19T07:15:52.550Z,1558250152.550 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-19T07:15:52.561Z,1558250152.561 [MassServo] Loaded
2019-05-19T07:15:52.561Z,1558250152.561 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-19T07:15:52.573Z,1558250152.573 [RudderServo] Loaded
2019-05-19T07:15:52.573Z,1558250152.573 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-19T07:15:52.584Z,1558250152.584 [ThrusterServo] Loaded
2019-05-19T07:15:52.584Z,1558250152.584 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-19T07:15:52.585Z,1558250152.585 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-19T07:15:52.585Z,1558250152.585 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-19T07:15:52.691Z,1558250152.691 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-19T07:15:52.691Z,1558250152.691 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-19T07:15:52.711Z,1558250152.711 [NavChart] Loaded
2019-05-19T07:15:52.712Z,1558250152.712 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-19T07:15:52.715Z,1558250152.715 [UniversalFixResidualReporter] Loaded
2019-05-19T07:15:52.716Z,1558250152.716 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-19T07:15:52.716Z,1558250152.716 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-19T07:15:52.717Z,1558250152.717 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-19T07:15:52.782Z,1558250152.782 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-19T07:15:52.783Z,1558250152.783 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-19T07:15:53.093Z,1558250153.093 [DataOverHttps] Loaded
2019-05-19T07:15:53.093Z,1558250153.093 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-19T07:15:53.094Z,1558250153.094 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087B4E0
2019-05-19T07:15:53.094Z,1558250153.094 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2916
2019-05-19T07:15:53.108Z,1558250153.108 [Depth_Keller] Loaded
2019-05-19T07:15:53.108Z,1558250153.108 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-19T07:15:53.203Z,1558250153.203 [NAL9602] Loaded
2019-05-19T07:15:53.203Z,1558250153.203 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-19T07:15:53.220Z,1558250153.220 [Onboard] Loaded
2019-05-19T07:15:53.220Z,1558250153.220 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-19T07:15:53.223Z,1558250153.223 [Radio_Surface] Loaded
2019-05-19T07:15:53.223Z,1558250153.223 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-19T07:15:53.225Z,1558250153.225 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AB4E0
2019-05-19T07:15:53.225Z,1558250153.225 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2917
2019-05-19T07:15:53.353Z,1558250153.353 [DAT] Loaded
2019-05-19T07:15:53.353Z,1558250153.353 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-05-19T07:15:53.354Z,1558250153.354 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-19T07:15:53.355Z,1558250153.355 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-19T07:15:53.393Z,1558250153.393 [DepthRateCalculator] Loaded
2019-05-19T07:15:53.394Z,1558250153.394 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-19T07:15:53.399Z,1558250153.399 [PitchRateCalculator] Loaded
2019-05-19T07:15:53.399Z,1558250153.399 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-19T07:15:53.411Z,1558250153.411 [SpeedCalculator] Loaded
2019-05-19T07:15:53.411Z,1558250153.411 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-19T07:15:53.432Z,1558250153.432 [TempGradientCalculator] Loaded
2019-05-19T07:15:53.432Z,1558250153.432 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-19T07:15:53.437Z,1558250153.437 [YawRateCalculator] Loaded
2019-05-19T07:15:53.438Z,1558250153.438 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-19T07:15:53.468Z,1558250153.468 [ElevatorOffsetCalculator] Loaded
2019-05-19T07:15:53.468Z,1558250153.468 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-19T07:15:53.468Z,1558250153.468 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-19T07:15:53.469Z,1558250153.469 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-19T07:15:53.710Z,1558250153.710 [CTD_NeilBrown] Loaded
2019-05-19T07:15:53.710Z,1558250153.710 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-19T07:15:53.711Z,1558250153.711 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409AD4E0
2019-05-19T07:15:53.711Z,1558250153.711 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2918
2019-05-19T07:15:53.741Z,1558250153.741 [ESPComponent] Loaded
2019-05-19T07:15:53.741Z,1558250153.741 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-05-19T07:15:53.755Z,1558250153.755 [PAR_Licor] Loaded
2019-05-19T07:15:53.755Z,1558250153.755 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-19T07:15:53.803Z,1558250153.803 [WetLabsBB2FL] Loaded
2019-05-19T07:15:53.804Z,1558250153.804 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-19T07:15:53.805Z,1558250153.805 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409DD4E0
2019-05-19T07:15:53.805Z,1558250153.805 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2919
2019-05-19T07:15:53.806Z,1558250153.806 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-19T07:15:53.806Z,1558250153.806 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-19T07:15:53.831Z,1558250153.831 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-19T07:15:53.832Z,1558250153.832 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-19T07:15:54.100Z,1558250154.100 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-19T07:15:54.101Z,1558250154.101 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-19T07:15:54.222Z,1558250154.222 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-19T07:15:54.233Z,1558250154.233 [SBIT] Loaded
2019-05-19T07:15:54.234Z,1558250154.234 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-19T07:15:54.235Z,1558250154.235 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-19T07:15:54.247Z,1558250154.247 [IBIT] Loaded
2019-05-19T07:15:54.247Z,1558250154.247 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-19T07:15:54.250Z,1558250154.250 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-19T07:15:54.638Z,1558250154.638 [CBIT] Loaded
2019-05-19T07:15:54.638Z,1558250154.638 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-19T07:15:54.638Z,1558250154.638 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-19T07:15:54.642Z,1558250154.642 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-19T07:15:54.643Z,1558250154.643 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-19T07:15:54.650Z,1558250154.650 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-19T07:15:54.651Z,1558250154.651 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADB4E0
2019-05-19T07:15:54.651Z,1558250154.651 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2920
2019-05-19T07:15:54.656Z,1558250154.656 [Supervisor](INFO): Main Thread ID is 2699
2019-05-19T07:15:54.656Z,1558250154.656 [Supervisor](DEBUG): Running supervisor.
2019-05-19T07:15:54.657Z,1558250154.657 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2921
2019-05-19T07:15:54.659Z,1558250154.659 [controlThread ThreadHandler](INFO): Handler Thread ID is 2922
2019-05-19T07:15:54.659Z,1558250154.659 [controlThread](DEBUG): Initializing ControlThread
2019-05-19T07:15:54.660Z,1558250154.660 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-19T07:15:54.662Z,1558250154.662 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-19T07:15:54.663Z,1558250154.663 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-19T07:15:54.663Z,1558250154.663 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-19T07:15:54.665Z,1558250154.665 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-19T07:15:54.665Z,1558250154.665 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-19T07:15:54.670Z,1558250154.670 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-19T07:15:54.670Z,1558250154.670 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-19T07:15:54.670Z,1558250154.670 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-19T07:15:54.671Z,1558250154.671 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-19T07:15:54.671Z,1558250154.671 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-19T07:15:54.671Z,1558250154.671 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-19T07:15:54.677Z,1558250154.677 [SBIT](INFO): Initialize SBIT Component.
2019-05-19T07:15:54.678Z,1558250154.678 [SBIT](IMPORTANT): git: 2019-05-01-10-gcab12ce
2019-05-19T07:15:54.678Z,1558250154.678 [SBIT](INFO): git hash: cab12ce958be6da2bb158d8a74bde728d70637cd
2019-05-19T07:15:54.678Z,1558250154.678 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-19T07:15:54.679Z,1558250154.679 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-05-19T07:15:54.680Z,1558250154.680 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2019-05-19T07:15:54.681Z,1558250154.681 [IBIT](INFO): Initialize IBIT Component.
2019-05-19T07:15:54.682Z,1558250154.682 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-19T07:15:54.683Z,1558250154.683 [logger ThreadHandler](INFO): Handler Thread ID is 2923
2019-05-19T07:15:54.693Z,1558250154.693 [CBIT](DEBUG): Initialized mux pins.
2019-05-19T07:15:54.693Z,1558250154.693 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-19T07:15:54.701Z,1558250154.701 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2924
2019-05-19T07:15:54.702Z,1558250154.702 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-19T07:15:54.713Z,1558250154.713 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2925
2019-05-19T07:15:54.717Z,1558250154.717 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-19T07:15:54.717Z,1558250154.717 [CBIT](DEBUG): Initializing heartbeat.
2019-05-19T07:15:54.725Z,1558250154.725 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2926
2019-05-19T07:15:54.726Z,1558250154.726 [CTD_NeilBrown](INFO): Powering down
2019-05-19T07:15:54.753Z,1558250154.753 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2927
2019-05-19T07:15:54.755Z,1558250154.755 [WetLabsBB2FL](INFO): Powering down
2019-05-19T07:15:54.781Z,1558250154.781 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2928
2019-05-19T07:15:54.784Z,1558250154.784 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-19T07:15:54.784Z,1558250154.784 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-19T07:15:54.785Z,1558250154.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-19T07:15:54.785Z,1558250154.785 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-19T07:15:54.785Z,1558250154.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-19T07:15:54.785Z,1558250154.785 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-19T07:15:54.785Z,1558250154.785 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-19T07:15:54.786Z,1558250154.786 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-19T07:15:54.786Z,1558250154.786 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-19T07:15:54.786Z,1558250154.786 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-19T07:15:54.786Z,1558250154.786 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-19T07:15:54.786Z,1558250154.786 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-19T07:15:54.786Z,1558250154.786 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-19T07:15:54.787Z,1558250154.787 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-19T07:15:54.787Z,1558250154.787 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-19T07:15:54.787Z,1558250154.787 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-19T07:15:54.789Z,1558250154.789 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-19T07:15:54.789Z,1558250154.789 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-19T07:15:54.825Z,1558250154.825 [CBIT](DEBUG): Backplane powered.
2019-05-19T07:15:54.826Z,1558250154.826 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-19T07:15:54.835Z,1558250154.835 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-19T07:15:54.846Z,1558250154.846 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2019-05-19T07:15:54.847Z,1558250154.847 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-19T07:15:54.909Z,1558250154.909 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-19T07:15:54.910Z,1558250154.910 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-19T07:15:54.912Z,1558250154.912 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-19T07:15:54.955Z,1558250154.955 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-19T07:15:54.974Z,1558250154.974 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-19T07:15:54.979Z,1558250154.979 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-19T07:15:55.001Z,1558250155.001 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2019-05-19T07:15:55.014Z,1558250155.014 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,NAL9602,Onboard,DAT,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-19T07:15:55.051Z,1558250155.051 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-05-19T07:15:55.081Z,1558250155.081 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-05-19T07:15:55.081Z,1558250155.081 [DAT](INFO): Powering up
2019-05-19T07:15:55.081Z,1558250155.081 [DAT](DEBUG): Initializing DAT.
2019-05-19T07:15:55.101Z,1558250155.101 [ESPComponent](INFO): powering down ESP
2019-05-19T07:15:55.117Z,1558250155.117 [Radio_Surface](INFO): Powering up
2019-05-19T07:15:55.173Z,1558250155.173 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-05-19T07:15:55.512Z,1558250155.512 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-19T07:15:55.539Z,1558250155.539 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-19T07:15:55.545Z,1558250155.545 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-19T07:15:55.546Z,1558250155.546 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-19T07:15:55.553Z,1558250155.553 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-19T07:15:55.554Z,1558250155.554 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-19T07:15:55.561Z,1558250155.561 [MassServo](DEBUG): Initializing MassServo.
2019-05-19T07:15:55.562Z,1558250155.562 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-19T07:15:55.569Z,1558250155.569 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-19T07:15:55.570Z,1558250155.570 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-19T07:15:55.577Z,1558250155.577 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-19T07:16:08.132Z,1558250168.132 [DAT](INFO): setting local address to 2
2019-05-19T07:16:08.535Z,1558250168.535 [DAT](INFO): set local address to 2
2019-05-19T07:16:16.541Z,1558250176.541 [CommandLine](IMPORTANT): got command restart system
2019-05-19T07:16:19.693Z,1558250179.693 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-19T07:16:19.693Z,1558250179.693 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:19.694Z,1558250179.694 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:19.701Z,1558250179.701 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-19T07:16:19.701Z,1558250179.701 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:19.702Z,1558250179.702 [CommandLine](INFO): Join timeout helper Thread ID is 2939
2019-05-19T07:16:19.713Z,1558250179.713 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-19T07:16:19.713Z,1558250179.713 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:19.713Z,1558250179.713 [NavChartDb](INFO): Join timeout helper Thread ID is 2940
2019-05-19T07:16:20.491Z,1558250180.491 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:20.491Z,1558250180.491 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:20.501Z,1558250180.501 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-19T07:16:20.501Z,1558250180.501 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:20.501Z,1558250180.501 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2941
2019-05-19T07:16:20.962Z,1558250180.962 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:20.962Z,1558250180.962 [WetLabsBB2FL](INFO): Powering down
2019-05-19T07:16:20.963Z,1558250180.963 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:20.965Z,1558250180.965 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-19T07:16:20.965Z,1558250180.965 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:20.965Z,1558250180.965 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2942
2019-05-19T07:16:21.057Z,1558250181.057 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:21.057Z,1558250181.057 [CTD_NeilBrown](INFO): Powering down
2019-05-19T07:16:21.069Z,1558250181.069 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.077Z,1558250181.077 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-19T07:16:21.077Z,1558250181.077 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.077Z,1558250181.077 [Radio_Surface](INFO): Join timeout helper Thread ID is 2943
2019-05-19T07:16:21.377Z,1558250181.377 [Radio_Surface](INFO): Powering down
2019-05-19T07:16:21.378Z,1558250181.378 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:21.378Z,1558250181.378 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.386Z,1558250181.386 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-19T07:16:21.386Z,1558250181.386 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.386Z,1558250181.386 [DataOverHttps](INFO): Join timeout helper Thread ID is 2944
2019-05-19T07:16:21.769Z,1558250181.769 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:21.769Z,1558250181.769 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.773Z,1558250181.773 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-19T07:16:21.774Z,1558250181.774 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.774Z,1558250181.774 [logger](INFO): Join timeout helper Thread ID is 2945
2019-05-19T07:16:21.797Z,1558250181.797 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:21.797Z,1558250181.797 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.813Z,1558250181.813 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-19T07:16:21.813Z,1558250181.813 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.814Z,1558250181.814 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-19T07:16:21.814Z,1558250181.814 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:21.814Z,1558250181.814 [controlThread](INFO): Join timeout helper Thread ID is 2946
2019-05-19T07:16:21.845Z,1558250181.845 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-19T07:16:21.845Z,1558250181.845 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-19T07:16:21.845Z,1558250181.845 [NAL9602](INFO): Powering down
2019-05-19T07:16:21.865Z,1558250181.865 [DAT](INFO): Powering down
2019-05-19T07:16:21.987Z,1558250181.987 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-19T07:16:21.988Z,1558250181.988 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-19T07:16:21.988Z,1558250181.988 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-19T07:16:21.989Z,1558250181.989 [MissionManager](INFO): Uninitializing Mission Default
2019-05-19T07:16:21.991Z,1558250181.991 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-19T07:16:21.993Z,1558250181.993 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-19T07:16:21.993Z,1558250181.993 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-19T07:16:21.994Z,1558250181.994 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-19T07:16:21.994Z,1558250181.994 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-19T07:16:21.994Z,1558250181.994 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-19T07:16:21.994Z,1558250181.994 [BuoyancyServo](INFO): Powering down
2019-05-19T07:16:22.009Z,1558250182.009 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-19T07:16:22.009Z,1558250182.009 [ElevatorServo](INFO): Powering down
2019-05-19T07:16:22.028Z,1558250182.028 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-19T07:16:22.028Z,1558250182.028 [MassServo](INFO): Powering down
2019-05-19T07:16:22.029Z,1558250182.029 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-19T07:16:22.029Z,1558250182.029 [RudderServo](INFO): Powering down
2019-05-19T07:16:22.030Z,1558250182.030 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-19T07:16:22.030Z,1558250182.030 [ThrusterServo](INFO): Powering down
2019-05-19T07:16:22.031Z,1558250182.031 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-19T07:16:22.031Z,1558250182.031 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-19T07:16:22.031Z,1558250182.031 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-19T07:16:22.031Z,1558250182.031 [CBIT](DEBUG): Powering off loads.
2019-05-19T07:16:22.045Z,1558250182.045 [CBIT](DEBUG): Disabling WDT.
2019-05-19T07:16:22.057Z,1558250182.057 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-19T07:16:22.057Z,1558250182.057 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:22.348Z,1558250182.348 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:22.354Z,1558250182.354 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:22.381Z,1558250182.381 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:22.385Z,1558250182.385 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:22.422Z,1558250182.422 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-19T07:16:22.481Z,1558250182.481 [logger ThreadHandler](INFO): Thread cancelled.