2018-10-30T22:30:25.549Z,1540938625.549 [Supervisor](DEBUG): Initializing supervisor.
2018-10-30T22:30:25.552Z,1540938625.552 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-10-30T22:30:25.553Z,1540938625.553 [SyncHandler](INFO): Protected caller Thread ID is 7004
2018-10-30T22:30:25.554Z,1540938625.554 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-10-30T22:30:25.555Z,1540938625.555 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-10-30T22:30:25.555Z,1540938625.555 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7005
2018-10-30T22:30:25.558Z,1540938625.558 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-10-30T22:30:25.571Z,1540938625.571 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-10-30T22:30:25.572Z,1540938625.572 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-10-30T22:30:25.572Z,1540938625.572 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7006
2018-10-30T22:30:25.573Z,1540938625.573 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-10-30T22:30:25.574Z,1540938625.574 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-10-30T22:30:25.574Z,1540938625.574 [logger ThreadHandler](INFO): Protected caller Thread ID is 7007
2018-10-30T22:30:25.576Z,1540938625.576 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-10-30T22:30:25.577Z,1540938625.577 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-10-30T22:30:25.578Z,1540938625.578 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-10-30T22:30:26.036Z,1540938626.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-10-30T22:30:26.036Z,1540938626.036 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-10-30T22:30:26.508Z,1540938626.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-10-30T22:30:26.509Z,1540938626.509 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-10-30T22:30:26.712Z,1540938626.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-10-30T22:30:26.713Z,1540938626.713 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-10-30T22:30:26.863Z,1540938626.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-10-30T22:30:26.864Z,1540938626.864 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-10-30T22:30:27.326Z,1540938627.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-10-30T22:30:27.327Z,1540938627.327 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-10-30T22:30:27.424Z,1540938627.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-10-30T22:30:27.424Z,1540938627.424 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-10-30T22:30:27.571Z,1540938627.571 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-10-30T22:30:27.571Z,1540938627.571 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-10-30T22:30:27.674Z,1540938627.674 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-10-30T22:30:27.674Z,1540938627.674 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-10-30T22:30:27.780Z,1540938627.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-10-30T22:30:27.781Z,1540938627.781 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-10-30T22:30:28.142Z,1540938628.142 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-10-30T22:30:28.142Z,1540938628.142 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-10-30T22:30:28.357Z,1540938628.357 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-10-30T22:30:28.358Z,1540938628.358 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-10-30T22:30:28.581Z,1540938628.581 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-10-30T22:30:28.581Z,1540938628.581 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-10-30T22:30:28.664Z,1540938628.664 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-10-30T22:30:29.034Z,1540938629.034 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-10-30T22:30:29.034Z,1540938629.034 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-10-30T22:30:29.371Z,1540938629.371 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-10-30T22:30:29.373Z,1540938629.373 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2018-10-30T22:30:29.374Z,1540938629.374 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2018-10-30T22:30:29.461Z,1540938629.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2018-10-30T22:30:29.629Z,1540938629.629 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2018-10-30T22:30:29.790Z,1540938629.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2018-10-30T22:30:30.037Z,1540938630.037 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2018-10-30T22:30:30.257Z,1540938630.257 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2018-10-30T22:30:30.589Z,1540938630.589 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-10-30T22:30:30.590Z,1540938630.590 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2018-10-30T22:30:30.709Z,1540938630.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2018-10-30T22:30:30.813Z,1540938630.813 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2018-10-30T22:30:30.910Z,1540938630.910 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2018-10-30T22:30:31.016Z,1540938631.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2018-10-30T22:30:31.133Z,1540938631.133 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2018-10-30T22:30:31.133Z,1540938631.133 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-10-30T22:30:31.139Z,1540938631.139 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-10-30T22:30:31.183Z,1540938631.183 [DepthRateCalculator] Loaded
2018-10-30T22:30:31.183Z,1540938631.183 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-10-30T22:30:31.189Z,1540938631.189 [PitchRateCalculator] Loaded
2018-10-30T22:30:31.189Z,1540938631.189 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-10-30T22:30:31.205Z,1540938631.205 [SpeedCalculator] Loaded
2018-10-30T22:30:31.206Z,1540938631.206 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-10-30T22:30:31.226Z,1540938631.226 [TempGradientCalculator] Loaded
2018-10-30T22:30:31.227Z,1540938631.227 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-10-30T22:30:31.233Z,1540938631.233 [YawRateCalculator] Loaded
2018-10-30T22:30:31.233Z,1540938631.233 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-10-30T22:30:31.273Z,1540938631.273 [ElevatorOffsetCalculator] Loaded
2018-10-30T22:30:31.274Z,1540938631.274 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-10-30T22:30:31.274Z,1540938631.274 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-10-30T22:30:31.275Z,1540938631.275 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-10-30T22:30:31.518Z,1540938631.518 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-10-30T22:30:31.518Z,1540938631.518 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-10-30T22:30:31.825Z,1540938631.825 [DataOverHttps] Loaded
2018-10-30T22:30:31.826Z,1540938631.826 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-10-30T22:30:31.852Z,1540938631.852 [Depth_Keller] Loaded
2018-10-30T22:30:31.852Z,1540938631.852 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-10-30T22:30:31.857Z,1540938631.857 [DropWeight] Loaded
2018-10-30T22:30:31.857Z,1540938631.857 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-10-30T22:30:31.955Z,1540938631.955 [NAL9602] Loaded
2018-10-30T22:30:31.956Z,1540938631.956 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-10-30T22:30:31.972Z,1540938631.972 [Onboard] Loaded
2018-10-30T22:30:31.972Z,1540938631.972 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-10-30T22:30:31.983Z,1540938631.983 [Radio_Surface] Loaded
2018-10-30T22:30:31.983Z,1540938631.983 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-10-30T22:30:31.984Z,1540938631.984 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407C34E0
2018-10-30T22:30:31.984Z,1540938631.984 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7086
2018-10-30T22:30:31.991Z,1540938631.991 [SCPI] Loaded
2018-10-30T22:30:31.991Z,1540938631.991 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-10-30T22:30:33.750Z,1540938633.750 [BPC1] Loaded
2018-10-30T22:30:33.751Z,1540938633.751 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-10-30T22:30:33.751Z,1540938633.751 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-10-30T22:30:33.752Z,1540938633.752 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-10-30T22:30:33.818Z,1540938633.818 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-10-30T22:30:33.818Z,1540938633.818 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-10-30T22:30:33.914Z,1540938633.914 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-10-30T22:30:33.915Z,1540938633.915 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-10-30T22:30:33.968Z,1540938633.968 [DeadReckonUsingSpeedCalculator] Loaded
2018-10-30T22:30:33.969Z,1540938633.969 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-10-30T22:30:33.985Z,1540938633.985 [NavChart] Loaded
2018-10-30T22:30:33.986Z,1540938633.986 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-10-30T22:30:33.990Z,1540938633.990 [UniversalFixResidualReporter] Loaded
2018-10-30T22:30:33.990Z,1540938633.990 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-10-30T22:30:33.990Z,1540938633.990 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-10-30T22:30:33.991Z,1540938633.991 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-10-30T22:30:34.220Z,1540938634.220 [CTD_NeilBrown] Loaded
2018-10-30T22:30:34.220Z,1540938634.220 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-10-30T22:30:34.221Z,1540938634.221 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408CE4E0
2018-10-30T22:30:34.222Z,1540938634.222 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7087
2018-10-30T22:30:34.272Z,1540938634.272 [WetLabsBB2FL] Loaded
2018-10-30T22:30:34.272Z,1540938634.272 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-10-30T22:30:34.273Z,1540938634.273 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408FE4E0
2018-10-30T22:30:34.274Z,1540938634.274 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7088
2018-10-30T22:30:34.274Z,1540938634.274 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-10-30T22:30:34.275Z,1540938634.275 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-10-30T22:30:34.342Z,1540938634.342 [VerticalControl](DEBUG): Construct VerticalControl.
2018-10-30T22:30:34.443Z,1540938634.443 [VerticalControl] Loaded
2018-10-30T22:30:34.443Z,1540938634.443 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-10-30T22:30:34.444Z,1540938634.444 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-10-30T22:30:34.513Z,1540938634.513 [HorizontalControl] Loaded
2018-10-30T22:30:34.514Z,1540938634.514 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-10-30T22:30:34.514Z,1540938634.514 [SpeedControl](DEBUG): Construct SpeedControl.
2018-10-30T22:30:34.520Z,1540938634.520 [SpeedControl] Loaded
2018-10-30T22:30:34.520Z,1540938634.520 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-10-30T22:30:34.521Z,1540938634.521 [LoopControl](DEBUG): Construct LoopControl.
2018-10-30T22:30:34.521Z,1540938634.521 [LoopControl] Loaded
2018-10-30T22:30:34.521Z,1540938634.521 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-10-30T22:30:34.522Z,1540938634.522 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-10-30T22:30:34.522Z,1540938634.522 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-10-30T22:30:34.535Z,1540938634.535 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-10-30T22:30:34.536Z,1540938634.536 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-10-30T22:30:34.666Z,1540938634.666 [SBIT](DEBUG): Construct Startup Built In Test.
2018-10-30T22:30:34.677Z,1540938634.677 [SBIT] Loaded
2018-10-30T22:30:34.677Z,1540938634.677 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-10-30T22:30:34.678Z,1540938634.678 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-10-30T22:30:34.690Z,1540938634.690 [IBIT] Loaded
2018-10-30T22:30:34.690Z,1540938634.690 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-10-30T22:30:34.693Z,1540938634.693 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-10-30T22:30:34.843Z,1540938634.843 [CBIT] Loaded
2018-10-30T22:30:34.843Z,1540938634.843 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-10-30T22:30:34.844Z,1540938634.844 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-10-30T22:30:34.845Z,1540938634.845 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-10-30T22:30:35.104Z,1540938635.104 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-10-30T22:30:35.104Z,1540938635.104 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-10-30T22:30:35.280Z,1540938635.280 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-10-30T22:30:35.280Z,1540938635.280 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-10-30T22:30:35.377Z,1540938635.378 [BuoyancyServo] Loaded
2018-10-30T22:30:35.378Z,1540938635.378 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-10-30T22:30:35.389Z,1540938635.389 [ElevatorServo] Loaded
2018-10-30T22:30:35.390Z,1540938635.390 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-10-30T22:30:35.401Z,1540938635.401 [MassServo] Loaded
2018-10-30T22:30:35.401Z,1540938635.401 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-10-30T22:30:35.412Z,1540938635.412 [RudderServo] Loaded
2018-10-30T22:30:35.413Z,1540938635.413 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-10-30T22:30:35.424Z,1540938635.424 [ThrusterServo] Loaded
2018-10-30T22:30:35.424Z,1540938635.424 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-10-30T22:30:35.424Z,1540938635.424 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-10-30T22:30:35.428Z,1540938635.428 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-10-30T22:30:35.429Z,1540938635.429 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-10-30T22:30:35.436Z,1540938635.436 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-10-30T22:30:35.437Z,1540938635.437 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0
2018-10-30T22:30:35.437Z,1540938635.437 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7089
2018-10-30T22:30:35.442Z,1540938635.442 [Supervisor](INFO): Main Thread ID is 5713
2018-10-30T22:30:35.442Z,1540938635.442 [Supervisor](DEBUG): Running supervisor.
2018-10-30T22:30:35.443Z,1540938635.443 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7090
2018-10-30T22:30:35.445Z,1540938635.445 [controlThread ThreadHandler](INFO): Handler Thread ID is 7091
2018-10-30T22:30:35.446Z,1540938635.446 [controlThread](DEBUG): Initializing ControlThread
2018-10-30T22:30:35.447Z,1540938635.447 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-30T22:30:35.447Z,1540938635.447 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-10-30T22:30:35.447Z,1540938635.447 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-10-30T22:30:35.448Z,1540938635.448 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-10-30T22:30:35.448Z,1540938635.448 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-10-30T22:30:35.449Z,1540938635.449 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-10-30T22:30:35.455Z,1540938635.455 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-10-30T22:30:35.456Z,1540938635.456 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-10-30T22:30:35.457Z,1540938635.457 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-10-30T22:30:35.457Z,1540938635.457 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-30T22:30:35.458Z,1540938635.458 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-30T22:30:35.458Z,1540938635.458 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-30T22:30:35.458Z,1540938635.458 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-10-30T22:30:35.459Z,1540938635.459 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-10-30T22:30:35.459Z,1540938635.459 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-10-30T22:30:35.461Z,1540938635.461 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-10-30T22:30:35.462Z,1540938635.462 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-10-30T22:30:35.462Z,1540938635.462 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-10-30T22:30:35.462Z,1540938635.462 [SBIT](INFO): Initialize SBIT Component.
2018-10-30T22:30:35.463Z,1540938635.463 [SBIT](IMPORTANT): git: 2018-10-09-45-g2ba51c3
2018-10-30T22:30:35.463Z,1540938635.463 [SBIT](INFO): git hash: 2ba51c3684b0a49cdfc0413537bdbfe1abb16683
2018-10-30T22:30:35.463Z,1540938635.463 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-10-30T22:30:35.463Z,1540938635.463 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-10-30T22:30:35.464Z,1540938635.464 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2018-10-30T22:30:35.465Z,1540938635.465 [IBIT](INFO): Initialize IBIT Component.
2018-10-30T22:30:35.466Z,1540938635.466 [CBIT](DEBUG): Initialize CBIT Component.
2018-10-30T22:30:35.466Z,1540938635.466 [CBIT](CRITICAL): Watchdog Timer failed to initialize.
2018-10-30T22:30:35.466Z,1540938635.466 [CBIT] Hardware Fault, FailCount= 1
2018-10-30T22:30:35.466Z,1540938635.466 [CBIT](ERROR): Hardware Fault
2018-10-30T22:30:35.467Z,1540938635.467 [logger ThreadHandler](INFO): Handler Thread ID is 7092
2018-10-30T22:30:35.485Z,1540938635.485 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7093
2018-10-30T22:30:35.491Z,1540938635.491 [Radio_Surface](INFO): Powering up
2018-10-30T22:30:35.497Z,1540938635.497 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7094
2018-10-30T22:30:35.509Z,1540938635.509 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7095
2018-10-30T22:30:35.510Z,1540938635.510 [WetLabsBB2FL](INFO): Powering down
2018-10-30T22:30:35.545Z,1540938635.545 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7096
2018-10-30T22:30:35.548Z,1540938635.548 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-10-30T22:30:35.549Z,1540938635.549 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-10-30T22:30:35.549Z,1540938635.549 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-10-30T22:30:35.549Z,1540938635.549 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-10-30T22:30:35.549Z,1540938635.549 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-10-30T22:30:35.549Z,1540938635.549 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-10-30T22:30:35.550Z,1540938635.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-10-30T22:30:35.550Z,1540938635.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-10-30T22:30:35.550Z,1540938635.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-10-30T22:30:35.550Z,1540938635.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-10-30T22:30:35.550Z,1540938635.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-10-30T22:30:35.550Z,1540938635.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-10-30T22:30:35.551Z,1540938635.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-10-30T22:30:35.551Z,1540938635.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-10-30T22:30:35.551Z,1540938635.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-10-30T22:30:35.551Z,1540938635.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-10-30T22:30:35.579Z,1540938635.579 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-10-30T22:30:35.590Z,1540938635.590 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-30T22:30:35.617Z,1540938635.617 [MissionManager](DEBUG):
2018-10-30T22:30:35.618Z,1540938635.618 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-10-30T22:30:35.692Z,1540938635.692 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-10-30T22:30:35.713Z,1540938635.713 [Default:A.Wait](DEBUG): Construct Wait.
2018-10-30T22:30:35.715Z,1540938635.715 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-30T22:30:35.738Z,1540938635.738 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-10-30T22:30:35.740Z,1540938635.740 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-10-30T22:30:35.766Z,1540938635.766 [Default:E.Execute](DEBUG): Construct Execute.
2018-10-30T22:30:35.785Z,1540938635.785 [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-10-30T22:30:35.790Z,1540938635.790 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-10-30T22:30:35.815Z,1540938635.815 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-10-30T22:30:35.840Z,1540938635.840 [Depth_Keller](ERROR): Pressure reading out of range: 1801.317627 decibar
2018-10-30T22:30:35.893Z,1540938635.893 [Onboard](INFO): Requesting onboard humidity...
2018-10-30T22:30:35.910Z,1540938635.910 [Onboard](ERROR): I2C read error. Can't read 1 bytes.
2018-10-30T22:30:35.910Z,1540938635.910 [Onboard](FAULT): Can't read temperature LSB.
2018-10-30T22:30:35.910Z,1540938635.910 [Onboard] Hardware Fault, FailCount= 1
2018-10-30T22:30:35.910Z,1540938635.910 [Onboard](ERROR): Hardware Fault
2018-10-30T22:30:35.911Z,1540938635.911 [Onboard](ERROR): I2C read error. Can't read 1 bytes.
2018-10-30T22:30:35.911Z,1540938635.911 [Onboard](FAULT): Can't read temperature MSB.
2018-10-30T22:30:35.912Z,1540938635.912 [Onboard](ERROR): I2C read error. Can't read 1 bytes.
2018-10-30T22:30:35.912Z,1540938635.912 [Onboard](FAULT): Can't read pressure LSB.
2018-10-30T22:30:35.912Z,1540938635.912 [Onboard](ERROR): I2C read error. Can't read 1 bytes.
2018-10-30T22:30:35.912Z,1540938635.912 [Onboard](FAULT): Can't read pressure MSB.
2018-10-30T22:30:35.983Z,1540938635.983 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-10-30T22:30:36.221Z,1540938636.221 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:36.229Z,1540938636.229 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-30T22:30:36.251Z,1540938636.251 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:36.257Z,1540938636.257 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-10-30T22:30:36.263Z,1540938636.263 [MassServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:36.269Z,1540938636.269 [MassServo](DEBUG): Initializing MassServo.
2018-10-30T22:30:36.290Z,1540938636.290 [RudderServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:36.298Z,1540938636.298 [RudderServo](DEBUG): Initializing RudderServo.
2018-10-30T22:30:36.319Z,1540938636.319 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:36.325Z,1540938636.325 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-10-30T22:30:36.378Z,1540938636.378 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-10-30T22:30:36.473Z,1540938636.473 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2018-10-30T22:30:36.474Z,1540938636.474 [DropWeight] Hardware Fault, FailCount= 1
2018-10-30T22:30:36.474Z,1540938636.474 [DropWeight](ERROR): Hardware Fault
2018-10-30T22:30:36.493Z,1540938636.493 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-10-30T22:30:37.133Z,1540938637.133 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-10-30T22:30:37.133Z,1540938637.133 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-10-30T22:30:37.133Z,1540938637.133 [BuoyancyServo] Communications Fault, FailCount= 1
2018-10-30T22:30:37.133Z,1540938637.133 [BuoyancyServo](ERROR): Communications Fault
2018-10-30T22:30:37.445Z,1540938637.445 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout
2018-10-30T22:30:37.445Z,1540938637.445 [ElevatorServo](FAULT): Elevator failed to initialize
2018-10-30T22:30:37.445Z,1540938637.445 [ElevatorServo] Communications Fault, FailCount= 1
2018-10-30T22:30:37.445Z,1540938637.445 [ElevatorServo](ERROR): Communications Fault
2018-10-30T22:30:37.761Z,1540938637.761 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2018-10-30T22:30:37.761Z,1540938637.761 [RudderServo](FAULT): Rudder failed to initialize
2018-10-30T22:30:37.761Z,1540938637.761 [RudderServo] Communications Fault, FailCount= 1
2018-10-30T22:30:37.761Z,1540938637.761 [RudderServo](ERROR): Communications Fault
2018-10-30T22:30:38.085Z,1540938638.085 [ThrusterServo](ERROR): Thruster halt for initialization uart error serial timeout
2018-10-30T22:30:38.409Z,1540938638.409 [ThrusterServo](ERROR): Thruster initialization uart error serial timeout
2018-10-30T22:30:38.409Z,1540938638.409 [ThrusterServo](FAULT): Thruster failed to initialize
2018-10-30T22:30:38.409Z,1540938638.409 [ThrusterServo] Communications Fault, FailCount= 1
2018-10-30T22:30:38.409Z,1540938638.409 [ThrusterServo](ERROR): Communications Fault
2018-10-30T22:30:38.458Z,1540938638.458 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-10-30T22:30:38.460Z,1540938638.460 [BuoyancyServo](INFO): Powering down
2018-10-30T22:30:38.521Z,1540938638.521 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-10-30T22:30:38.521Z,1540938638.521 [ElevatorServo](INFO): Powering down
2018-10-30T22:30:38.877Z,1540938638.877 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout
2018-10-30T22:30:38.877Z,1540938638.877 [MassServo] Communications Fault, FailCount= 1
2018-10-30T22:30:38.877Z,1540938638.877 [MassServo](ERROR): Communications Fault
2018-10-30T22:30:38.878Z,1540938638.878 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-10-30T22:30:38.878Z,1540938638.878 [RudderServo](INFO): Powering down
2018-10-30T22:30:38.896Z,1540938638.896 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-10-30T22:30:38.896Z,1540938638.896 [ThrusterServo](INFO): Powering down
2018-10-30T22:30:39.030Z,1540938639.030 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-10-30T22:30:39.030Z,1540938639.030 [MassServo](INFO): Powering down
2018-10-30T22:30:39.375Z,1540938639.375 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:39.494Z,1540938639.494 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-10-30T22:30:39.496Z,1540938639.496 [RudderServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:39.614Z,1540938639.614 [RudderServo](DEBUG): Initializing RudderServo.
2018-10-30T22:30:39.771Z,1540938639.771 [MassServo](DEBUG): Initializing EZServoServo.
2018-10-30T22:30:39.890Z,1540938639.890 [MassServo](DEBUG): Initializing MassServo.
2018-10-30T22:30:41.146Z,1540938641.146 [Radio_Surface](INFO): Powering down
2018-10-30T22:31:02.162Z,1540938662.162 [NAL9602](INFO): Powering up NAL9602
2018-10-30T22:31:04.175Z,1540938664.175 [SBIT](IMPORTANT): Beginning Startup BIT
2018-10-30T22:31:17.375Z,1540938677.375 [SBIT](ERROR): Could not read elevatorAngleReader_.
2018-10-30T22:31:17.375Z,1540938677.375 [SBIT](ERROR): Could not read rudderAngleReader_.
2018-10-30T22:31:17.375Z,1540938677.375 [SBIT](ERROR): Could not read massPosReader_.
2018-10-30T22:31:23.362Z,1540938683.362 [NAL9602](ERROR): NAL9602 initialization error.
2018-10-30T22:31:23.362Z,1540938683.362 [NAL9602] Communications Fault, FailCount= 1
2018-10-30T22:31:23.362Z,1540938683.362 [NAL9602](ERROR): Communications Fault
2018-10-30T22:31:23.762Z,1540938683.762 [NAL9602](INFO): Powering down
2018-10-30T22:31:43.821Z,1540938703.821 [SBIT](ERROR): Could not read elevatorAngleReader_.
2018-10-30T22:31:43.821Z,1540938703.821 [SBIT](ERROR): Could not read rudderAngleReader_.
2018-10-30T22:31:43.821Z,1540938703.821 [SBIT](ERROR): Could not read massPosReader_.
2018-10-30T22:31:43.821Z,1540938703.821 [SBIT](FAULT): Control surface position failure.
2018-10-30T22:31:57.392Z,1540938717.392 [SBIT](ERROR): Could not read elevatorAngleReader_.
2018-10-30T22:31:57.392Z,1540938717.392 [SBIT](ERROR): Could not read rudderAngleReader_.
2018-10-30T22:31:57.392Z,1540938717.392 [SBIT](ERROR): Could not read massPosReader_.
2018-10-30T22:31:57.393Z,1540938717.393 [SBIT](FAULT): Control surface position failure.
2018-10-30T22:31:57.783Z,1540938717.783 [SBIT](CRITICAL): SBIT FAILED
2018-10-30T22:31:57.803Z,1540938717.803 [CommandLine](IMPORTANT): got command configSet list
2018-10-30T22:31:57.804Z,1540938717.804 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-10-30T22:31:57.804Z,1540938717.804 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;
2018-10-30T22:31:57.805Z,1540938717.805 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;
2018-10-30T22:31:57.805Z,1540938717.805 [CommandLine](IMPORTANT): Depth_Keller.offset=-20.6875 decibar;
2018-10-30T22:31:57.805Z,1540938717.805 [CommandLine](IMPORTANT): Depth_Keller.scale=43.44 micropascal;
2018-10-30T22:31:57.805Z,1540938717.805 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=0 bool;
2018-10-30T22:31:58.180Z,1540938718.180 [MissionManager](IMPORTANT): Started mission Startup
2018-10-30T22:31:58.180Z,1540938718.180 [Startup] Running Loop=1
2018-10-30T22:31:58.180Z,1540938718.180 [Startup](DEBUG): Aggregate::initialize Startup
2018-10-30T22:31:58.180Z,1540938718.180 [Startup:A.GoToSurface] Running Loop=1
2018-10-30T22:31:58.180Z,1540938718.180 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-10-30T22:31:58.181Z,1540938718.181 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-10-30T22:31:58.181Z,1540938718.181 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-10-30T22:31:58.182Z,1540938718.182 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-10-30T22:31:58.182Z,1540938718.182 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-10-30T22:31:58.183Z,1540938718.183 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-10-30T22:31:58.188Z,1540938718.188 [Startup:StartupSatComms] Running Loop=1
2018-10-30T22:31:58.189Z,1540938718.189 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-10-30T22:31:58.189Z,1540938718.189 [Startup:StartupSatComms:A] Running Loop=1
2018-10-30T22:31:58.390Z,1540938718.390 [Radio_Surface](INFO): Powering up
2018-10-30T22:31:58.582Z,1540938718.582 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-10-30T22:32:35.834Z,1540938755.834 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-10-30T22:32:35.834Z,1540938755.834 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-10-30T22:32:35.835Z,1540938755.835 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-10-30T22:32:35.836Z,1540938755.836 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-10-30T22:32:35.836Z,1540938755.836 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-10-30T22:32:35.836Z,1540938755.836 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-30T22:32:58.573Z,1540938778.573 [Startup:StartupSatComms:A](INFO): Timed out from 2018-10-30T22:31:58.2Z
2018-10-30T22:32:58.573Z,1540938778.573 [Startup:StartupSatComms:A] Stopped
2018-10-30T22:32:58.573Z,1540938778.573 [Startup:StartupSatComms:B] Running Loop=1
2018-10-30T22:32:58.972Z,1540938778.972 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-10-30T22:33:58.576Z,1540938838.576 [Startup:StartupSatComms:B](INFO): Timed out from 2018-10-30T22:32:58.6Z
2018-10-30T22:33:58.576Z,1540938838.576 [Startup:StartupSatComms:B] Stopped
2018-10-30T22:33:58.576Z,1540938838.576 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-10-30T22:33:58.576Z,1540938838.576 [Startup:StartupSatComms] Stopped
2018-10-30T22:33:58.576Z,1540938838.576 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-10-30T22:33:58.577Z,1540938838.577 [Startup](INFO): Completed Startup
2018-10-30T22:33:58.578Z,1540938838.578 [MissionManager](INFO): Startup is completed.
2018-10-30T22:33:58.578Z,1540938838.578 [MissionManager](INFO): Uninitializing Mission Startup
2018-10-30T22:33:58.578Z,1540938838.578 [Startup] Stopped
2018-10-30T22:33:58.578Z,1540938838.578 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-10-30T22:33:58.578Z,1540938838.578 [Startup:A.GoToSurface] Stopped
2018-10-30T22:33:58.578Z,1540