2019-03-12T20:08:32.447Z,1552421312.447 [Supervisor](DEBUG): Initializing supervisor.
2019-03-12T20:08:32.451Z,1552421312.451 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-03-12T20:08:32.452Z,1552421312.452 [SyncHandler](INFO): Protected caller Thread ID is 4980
2019-03-12T20:08:32.452Z,1552421312.452 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-03-12T20:08:32.453Z,1552421312.453 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-03-12T20:08:32.453Z,1552421312.453 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4981
2019-03-12T20:08:32.458Z,1552421312.458 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-03-12T20:08:32.469Z,1552421312.469 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-03-12T20:08:32.470Z,1552421312.470 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-03-12T20:08:32.471Z,1552421312.471 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4982
2019-03-12T20:08:32.472Z,1552421312.472 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-03-12T20:08:32.472Z,1552421312.472 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-03-12T20:08:32.473Z,1552421312.473 [logger ThreadHandler](INFO): Protected caller Thread ID is 4983
2019-03-12T20:08:32.475Z,1552421312.475 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-03-12T20:08:32.475Z,1552421312.475 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-03-12T20:08:32.477Z,1552421312.477 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-03-12T20:08:32.962Z,1552421312.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-03-12T20:08:32.963Z,1552421312.963 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-03-12T20:08:33.447Z,1552421313.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-03-12T20:08:33.448Z,1552421313.448 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-03-12T20:08:33.646Z,1552421313.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-03-12T20:08:33.647Z,1552421313.647 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-03-12T20:08:33.793Z,1552421313.793 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-03-12T20:08:33.794Z,1552421313.794 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-03-12T20:08:34.940Z,1552421314.940 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-03-12T20:08:34.941Z,1552421314.941 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-03-12T20:08:35.187Z,1552421315.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-03-12T20:08:35.188Z,1552421315.188 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-03-12T20:08:35.333Z,1552421315.333 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-03-12T20:08:35.334Z,1552421315.334 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-03-12T20:08:35.464Z,1552421315.464 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-03-12T20:08:35.465Z,1552421315.465 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-03-12T20:08:35.883Z,1552421315.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-03-12T20:08:35.884Z,1552421315.884 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-03-12T20:08:36.275Z,1552421316.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-03-12T20:08:36.276Z,1552421316.276 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-03-12T20:08:36.478Z,1552421316.478 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-03-12T20:08:36.478Z,1552421316.478 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-03-12T20:08:36.705Z,1552421316.705 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-03-12T20:08:36.706Z,1552421316.706 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-03-12T20:08:36.788Z,1552421316.788 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-03-12T20:08:37.142Z,1552421317.142 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-03-12T20:08:37.142Z,1552421317.142 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-03-12T20:08:37.466Z,1552421317.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-03-12T20:08:37.468Z,1552421317.468 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2019-03-12T20:08:37.469Z,1552421317.469 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2019-03-12T20:08:37.555Z,1552421317.555 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2019-03-12T20:08:37.709Z,1552421317.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2019-03-12T20:08:37.809Z,1552421317.809 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2019-03-12T20:08:37.986Z,1552421317.986 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2019-03-12T20:08:38.069Z,1552421318.069 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2019-03-12T20:08:38.297Z,1552421318.297 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-03-12T20:08:38.298Z,1552421318.298 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2019-03-12T20:08:38.414Z,1552421318.414 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2019-03-12T20:08:38.513Z,1552421318.513 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2019-03-12T20:08:38.608Z,1552421318.608 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2019-03-12T20:08:38.709Z,1552421318.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2019-03-12T20:08:38.820Z,1552421318.820 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2019-03-12T20:08:38.821Z,1552421318.821 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-03-12T20:08:38.826Z,1552421318.826 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-03-12T20:08:38.882Z,1552421318.882 [DepthRateCalculator] Loaded
2019-03-12T20:08:38.882Z,1552421318.882 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-03-12T20:08:38.888Z,1552421318.888 [PitchRateCalculator] Loaded
2019-03-12T20:08:38.888Z,1552421318.888 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-03-12T20:08:38.904Z,1552421318.904 [SpeedCalculator] Loaded
2019-03-12T20:08:38.904Z,1552421318.904 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-03-12T20:08:38.925Z,1552421318.925 [TempGradientCalculator] Loaded
2019-03-12T20:08:38.925Z,1552421318.925 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-03-12T20:08:38.931Z,1552421318.931 [YawRateCalculator] Loaded
2019-03-12T20:08:38.931Z,1552421318.931 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-03-12T20:08:38.971Z,1552421318.971 [ElevatorOffsetCalculator] Loaded
2019-03-12T20:08:38.971Z,1552421318.971 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-03-12T20:08:38.971Z,1552421318.971 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-03-12T20:08:38.972Z,1552421318.972 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-03-12T20:08:39.241Z,1552421319.241 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-03-12T20:08:39.241Z,1552421319.241 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-03-12T20:08:39.641Z,1552421319.641 [DataOverHttps] Loaded
2019-03-12T20:08:39.641Z,1552421319.641 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-03-12T20:08:39.642Z,1552421319.642 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407CE4E0
2019-03-12T20:08:39.642Z,1552421319.642 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5062
2019-03-12T20:08:39.682Z,1552421319.682 [Depth_Keller] Loaded
2019-03-12T20:08:39.682Z,1552421319.682 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-03-12T20:08:39.687Z,1552421319.687 [DropWeight] Loaded
2019-03-12T20:08:39.687Z,1552421319.687 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-03-12T20:08:39.783Z,1552421319.783 [NAL9602] Loaded
2019-03-12T20:08:39.784Z,1552421319.784 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-03-12T20:08:39.799Z,1552421319.799 [Onboard] Loaded
2019-03-12T20:08:39.799Z,1552421319.799 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-03-12T20:08:39.806Z,1552421319.806 [Radio_Surface] Loaded
2019-03-12T20:08:39.806Z,1552421319.806 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-03-12T20:08:39.807Z,1552421319.807 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407FE4E0
2019-03-12T20:08:39.807Z,1552421319.807 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5063
2019-03-12T20:08:41.756Z,1552421321.756 [BPC1] Loaded
2019-03-12T20:08:41.756Z,1552421321.756 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-03-12T20:08:41.757Z,1552421321.757 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-03-12T20:08:41.757Z,1552421321.757 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-03-12T20:08:41.858Z,1552421321.858 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-03-12T20:08:41.858Z,1552421321.858 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-03-12T20:08:41.976Z,1552421321.976 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-03-12T20:08:41.976Z,1552421321.976 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-03-12T20:08:42.034Z,1552421322.034 [DeadReckonUsingSpeedCalculator] Loaded
2019-03-12T20:08:42.035Z,1552421322.035 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-03-12T20:08:42.055Z,1552421322.055 [NavChart] Loaded
2019-03-12T20:08:42.055Z,1552421322.055 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-03-12T20:08:42.059Z,1552421322.059 [UniversalFixResidualReporter] Loaded
2019-03-12T20:08:42.060Z,1552421322.060 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-03-12T20:08:42.060Z,1552421322.060 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-03-12T20:08:42.061Z,1552421322.061 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-03-12T20:08:42.378Z,1552421322.378 [CTD_NeilBrown] Loaded
2019-03-12T20:08:42.378Z,1552421322.378 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-03-12T20:08:42.379Z,1552421322.379 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409524E0
2019-03-12T20:08:42.380Z,1552421322.380 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 5064
2019-03-12T20:08:42.428Z,1552421322.428 [WetLabsBB2FL] Loaded
2019-03-12T20:08:42.428Z,1552421322.428 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-03-12T20:08:42.429Z,1552421322.429 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409824E0
2019-03-12T20:08:42.429Z,1552421322.429 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5065
2019-03-12T20:08:42.430Z,1552421322.430 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-03-12T20:08:42.431Z,1552421322.431 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-03-12T20:08:42.516Z,1552421322.516 [VerticalControl](DEBUG): Construct VerticalControl.
2019-03-12T20:08:42.614Z,1552421322.614 [VerticalControl] Loaded
2019-03-12T20:08:42.614Z,1552421322.614 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-03-12T20:08:42.615Z,1552421322.615 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-03-12T20:08:42.682Z,1552421322.682 [HorizontalControl] Loaded
2019-03-12T20:08:42.682Z,1552421322.682 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-03-12T20:08:42.683Z,1552421322.683 [SpeedControl](DEBUG): Construct SpeedControl.
2019-03-12T20:08:42.688Z,1552421322.688 [SpeedControl] Loaded
2019-03-12T20:08:42.688Z,1552421322.688 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-03-12T20:08:42.689Z,1552421322.689 [LoopControl](DEBUG): Construct LoopControl.
2019-03-12T20:08:42.689Z,1552421322.689 [LoopControl] Loaded
2019-03-12T20:08:42.690Z,1552421322.690 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-03-12T20:08:42.690Z,1552421322.690 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-03-12T20:08:42.691Z,1552421322.691 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-03-12T20:08:42.715Z,1552421322.715 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-03-12T20:08:42.715Z,1552421322.715 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-03-12T20:08:42.870Z,1552421322.870 [SBIT](DEBUG): Construct Startup Built In Test.
2019-03-12T20:08:42.881Z,1552421322.881 [SBIT] Loaded
2019-03-12T20:08:42.882Z,1552421322.882 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-03-12T20:08:42.882Z,1552421322.882 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-03-12T20:08:42.894Z,1552421322.894 [IBIT] Loaded
2019-03-12T20:08:42.894Z,1552421322.894 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-03-12T20:08:42.897Z,1552421322.897 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-03-12T20:08:43.033Z,1552421323.033 [CBIT] Loaded
2019-03-12T20:08:43.033Z,1552421323.033 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-03-12T20:08:43.034Z,1552421323.034 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-03-12T20:08:43.034Z,1552421323.034 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-03-12T20:08:43.157Z,1552421323.157 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-03-12T20:08:43.157Z,1552421323.157 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-03-12T20:08:43.198Z,1552421323.198 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-03-12T20:08:43.199Z,1552421323.199 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-03-12T20:08:43.311Z,1552421323.311 [BuoyancyServo] Loaded
2019-03-12T20:08:43.312Z,1552421323.312 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-03-12T20:08:43.323Z,1552421323.323 [ElevatorServo] Loaded
2019-03-12T20:08:43.323Z,1552421323.323 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-03-12T20:08:43.334Z,1552421323.334 [MassServo](DEBUG): LcmSlateWriter::add(): platform_mass_position
2019-03-12T20:08:43.335Z,1552421323.335 [MassServo](INFO): created writer for : platform_mass_position
2019-03-12T20:08:43.338Z,1552421323.338 [MassServo] Loaded
2019-03-12T20:08:43.338Z,1552421323.338 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-03-12T20:08:43.349Z,1552421323.349 [RudderServo] Loaded
2019-03-12T20:08:43.349Z,1552421323.349 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-03-12T20:08:43.360Z,1552421323.360 [ThrusterServo] Loaded
2019-03-12T20:08:43.360Z,1552421323.360 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-03-12T20:08:43.361Z,1552421323.361 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-03-12T20:08:43.364Z,1552421323.364 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-03-12T20:08:43.365Z,1552421323.365 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-03-12T20:08:43.372Z,1552421323.372 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-03-12T20:08:43.373Z,1552421323.373 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AA94E0
2019-03-12T20:08:43.373Z,1552421323.373 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5066
2019-03-12T20:08:43.378Z,1552421323.378 [Supervisor](INFO): Main Thread ID is 4626
2019-03-12T20:08:43.378Z,1552421323.378 [Supervisor](DEBUG): Running supervisor.
2019-03-12T20:08:43.379Z,1552421323.379 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5067
2019-03-12T20:08:43.389Z,1552421323.389 [controlThread ThreadHandler](INFO): Handler Thread ID is 5068
2019-03-12T20:08:43.390Z,1552421323.390 [controlThread](DEBUG): Initializing ControlThread
2019-03-12T20:08:43.391Z,1552421323.391 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-03-12T20:08:43.391Z,1552421323.391 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-03-12T20:08:43.391Z,1552421323.391 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-03-12T20:08:43.392Z,1552421323.392 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-03-12T20:08:43.392Z,1552421323.392 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-03-12T20:08:43.393Z,1552421323.393 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-03-12T20:08:43.398Z,1552421323.398 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-12T20:08:43.398Z,1552421323.398 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-03-12T20:08:43.398Z,1552421323.398 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-03-12T20:08:43.399Z,1552421323.399 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-03-12T20:08:43.400Z,1552421323.400 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-03-12T20:08:43.401Z,1552421323.401 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-03-12T20:08:43.401Z,1552421323.401 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-03-12T20:08:43.402Z,1552421323.402 [SBIT](INFO): Initialize SBIT Component.
2019-03-12T20:08:43.402Z,1552421323.402 [SBIT](IMPORTANT): git: 2019-03-04-44-ga2d3d21
2019-03-12T20:08:43.402Z,1552421323.402 [SBIT](INFO): git hash: a2d3d214b101d483b423158d4952d3c69d955466
2019-03-12T20:08:43.403Z,1552421323.403 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-03-12T20:08:43.403Z,1552421323.403 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2019-03-12T20:08:43.404Z,1552421323.404 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-03-12T20:08:43.405Z,1552421323.405 [IBIT](INFO): Initialize IBIT Component.
2019-03-12T20:08:43.405Z,1552421323.405 [CBIT](DEBUG): Initialize CBIT Component.
2019-03-12T20:08:43.406Z,1552421323.406 [logger ThreadHandler](INFO): Handler Thread ID is 5069
2019-03-12T20:08:43.419Z,1552421323.419 [CBIT](DEBUG): Initialized mux pins.
2019-03-12T20:08:43.419Z,1552421323.419 [CBIT](DEBUG): Initializing the watchdog timer.
2019-03-12T20:08:43.424Z,1552421323.424 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5070
2019-03-12T20:08:43.425Z,1552421323.425 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-03-12T20:08:43.435Z,1552421323.435 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5071
2019-03-12T20:08:43.443Z,1552421323.443 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-03-12T20:08:43.443Z,1552421323.443 [CBIT](DEBUG): Initializing heartbeat.
2019-03-12T20:08:43.444Z,1552421323.444 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 5072
2019-03-12T20:08:43.451Z,1552421323.451 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5073
2019-03-12T20:08:43.453Z,1552421323.453 [WetLabsBB2FL](INFO): Powering down
2019-03-12T20:08:43.471Z,1552421323.471 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5074
2019-03-12T20:08:43.479Z,1552421323.479 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-03-12T20:08:43.479Z,1552421323.479 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-03-12T20:08:43.479Z,1552421323.479 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-03-12T20:08:43.479Z,1552421323.479 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-03-12T20:08:43.480Z,1552421323.480 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-03-12T20:08:43.480Z,1552421323.480 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-03-12T20:08:43.480Z,1552421323.480 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-03-12T20:08:43.480Z,1552421323.480 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-03-12T20:08:43.480Z,1552421323.480 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-03-12T20:08:43.481Z,1552421323.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-03-12T20:08:43.481Z,1552421323.481 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-03-12T20:08:43.481Z,1552421323.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-03-12T20:08:43.481Z,1552421323.481 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-03-12T20:08:43.481Z,1552421323.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-03-12T20:08:43.482Z,1552421323.482 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-03-12T20:08:43.482Z,1552421323.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-03-12T20:08:43.515Z,1552421323.515 [CBIT](DEBUG): Deactivating GF circuits.
2019-03-12T20:08:43.515Z,1552421323.515 [CBIT](DEBUG): Deactivating emergency mode.
2019-03-12T20:08:43.553Z,1552421323.553 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-03-12T20:08:43.599Z,1552421323.599 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-03-12T20:08:43.610Z,1552421323.610 [MissionManager](DEBUG):
2019-03-12T20:08:43.611Z,1552421323.611 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-03-12T20:08:43.679Z,1552421323.679 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-03-12T20:08:43.696Z,1552421323.696 [Default:A.Wait](DEBUG): Construct Wait.
2019-03-12T20:08:43.697Z,1552421323.697 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-03-12T20:08:43.751Z,1552421323.751 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-03-12T20:08:43.753Z,1552421323.753 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-03-12T20:08:43.775Z,1552421323.775 [Default:E.Execute](DEBUG): Construct Execute.
2019-03-12T20:08:43.778Z,1552421323.778 [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
2019-03-12T20:08:43.782Z,1552421323.782 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,DropWeight,NAL9602,Onboard,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,
2019-03-12T20:08:43.839Z,1552421323.839 [Radio_Surface](INFO): Powering up
2019-03-12T20:08:43.957Z,1552421323.957 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-03-12T20:08:43.963Z,1552421323.963 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-03-12T20:08:43.964Z,1552421323.964 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-03-12T20:08:43.971Z,1552421323.971 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-03-12T20:08:43.972Z,1552421323.972 [MassServo](DEBUG): Initializing EZServoServo.
2019-03-12T20:08:43.979Z,1552421323.979 [MassServo](DEBUG): Initializing MassServo.
2019-03-12T20:08:43.980Z,1552421323.980 [RudderServo](DEBUG): Initializing EZServoServo.
2019-03-12T20:08:43.987Z,1552421323.987 [RudderServo](DEBUG): Initializing RudderServo.
2019-03-12T20:08:43.988Z,1552421323.988 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-03-12T20:08:44.001Z,1552421324.001 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-03-12T20:08:44.204Z,1552421324.204 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2019-03-12T20:08:44.204Z,1552421324.204 [DropWeight] Hardware Fault, FailCount= 1
2019-03-12T20:08:44.204Z,1552421324.204 [DropWeight](ERROR): Hardware Fault
2019-03-12T20:08:44.241Z,1552421324.241 [CommandLine](FAULT): Scheduling is paused
2019-03-12T20:08:44.241Z,1552421324.241 [CBIT](INFO): Critical error at 20190312T200844
2019-03-12T20:08:44.241Z,1552421324.241 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-03-12T20:08:44.252Z,1552421324.252 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-03-12T20:08:44.253Z,1552421324.253 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-03-12T20:08:44.931Z,1552421324.931 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-03-12T20:08:44.931Z,1552421324.931 [RudderServo](FAULT): Rudder failed to initialize
2019-03-12T20:08:44.931Z,1552421324.931 [RudderServo] Communications Fault, FailCount= 1
2019-03-12T20:08:44.931Z,1552421324.931 [RudderServo](ERROR): Communications Fault
2019-03-12T20:08:45.041Z,1552421325.041 [CBIT](INFO): Critical error at 20190312T200844
2019-03-12T20:08:45.044Z,1552421325.044 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-03-12T20:08:45.200Z,1552421325.200 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-03-12T20:08:45.200Z,1552421325.200 [RudderServo](INFO): Powering down
2019-03-12T20:08:45.887Z,1552421325.887 [RudderServo](DEBUG): Initializing EZServoServo.
2019-03-12T20:08:46.008Z,1552421326.008 [RudderServo](DEBUG): Initializing RudderServo.
2019-03-12T20:08:46.012Z,1552421326.012 [CBIT](INFO): Clearing failed state for component RudderServo
2019-03-12T20:08:46.012Z,1552421326.012 [RudderServo] No Fault, FailCount= 1
2019-03-12T20:09:10.109Z,1552421350.109 [NAL9602](INFO): Powering up NAL9602
2019-03-12T20:09:12.160Z,1552421352.160 [SBIT](IMPORTANT): Beginning Startup BIT
2019-03-12T20:09:12.165Z,1552421352.165 [CBIT](IMPORTANT): Beginning ground fault scan
2019-03-12T20:09:21.248Z,1552421361.248 [NAL9602](INFO): NAL9602 initialized
2019-03-12T20:09:22.071Z,1552421362.071 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:09:22.956Z,1552421362.956 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.008619
CHAN A1 (24V): 0.002003
CHAN A2 (12V): -0.005576
CHAN A3 (5V): -0.002548
CHAN B0 (3.3V): -0.001020
CHAN B1 (3.15aV): -0.001211
CHAN B2 (3.15bV): -0.001606
CHAN B3 (GND): -0.000459
OPEN: -0.001242
Full Scale Calc: 4.765 mA, -1.589 mA
2019-03-12T20:10:05.900Z,1552421405.900 [SBIT](IMPORTANT): SBIT PASSED
2019-03-12T20:10:05.940Z,1552421405.940 [CommandLine](IMPORTANT): got command configSet list
2019-03-12T20:10:05.941Z,1552421405.941 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-03-12T20:10:05.942Z,1552421405.942 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;
2019-03-12T20:10:05.942Z,1552421405.942 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;
2019-03-12T20:10:06.299Z,1552421406.299 [MissionManager](IMPORTANT): Started mission Startup
2019-03-12T20:10:06.300Z,1552421406.300 [Startup] Running Loop=1
2019-03-12T20:10:06.300Z,1552421406.300 [Startup](DEBUG): Aggregate::initialize Startup
2019-03-12T20:10:06.300Z,1552421406.300 [Startup:A.GoToSurface] Running Loop=1
2019-03-12T20:10:06.300Z,1552421406.300 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-12T20:10:06.301Z,1552421406.301 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-12T20:10:06.301Z,1552421406.301 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-12T20:10:06.301Z,1552421406.301 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-12T20:10:06.302Z,1552421406.302 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-12T20:10:06.302Z,1552421406.302 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-12T20:10:06.304Z,1552421406.304 [Startup:StartupSatComms] Running Loop=1
2019-03-12T20:10:06.304Z,1552421406.304 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-03-12T20:10:06.304Z,1552421406.304 [Startup:StartupSatComms:A] Running Loop=1
2019-03-12T20:10:06.708Z,1552421406.708 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-03-12T20:10:43.526Z,1552421443.526 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-12T20:10:43.527Z,1552421443.527 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-03-12T20:10:43.527Z,1552421443.527 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-12T20:10:43.528Z,1552421443.528 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-12T20:10:43.529Z,1552421443.529 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-03-12T20:10:43.529Z,1552421443.529 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-12T20:10:43.540Z,1552421443.540 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-12T20:10:43.540Z,1552421443.540 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-12T20:10:43.970Z,1552421443.970 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-12T20:10:43.970Z,1552421443.970 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-03-12T20:10:43.971Z,1552421443.971 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-12T20:10:43.971Z,1552421443.971 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-03-12T20:10:44.279Z,1552421444.279 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-12T20:11:06.477Z,1552421466.477 [Startup:StartupSatComms:A](INFO): Timed out from 2019-03-12T20:10:06.3Z
2019-03-12T20:11:06.477Z,1552421466.477 [Startup:StartupSatComms:A] Stopped
2019-03-12T20:11:06.477Z,1552421466.477 [Startup:StartupSatComms:B] Running Loop=1
2019-03-12T20:11:06.888Z,1552421466.888 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-03-12T20:11:10.213Z,1552421470.213 [DataOverHttps](IMPORTANT): SBD MTMSN=20190312T201110
2019-03-12T20:11:10.217Z,1552421470.217 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004774
2019-03-12T20:11:17.102Z,1552421477.102 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190312T180901/Courier0037.lzma
2019-03-12T20:11:17.105Z,1552421477.105 [DataOverHttps](INFO): Received command:configSet CTD_Seabird.loadAtStartup 0 bool persist
2019-03-12T20:11:17.243Z,1552421477.243 [CommandLine](IMPORTANT): got command configSet CTD_Seabird.loadAtStartup 0.000000 bool persist
2019-03-12T20:11:17.243Z,1552421477.243 [CommandLine](IMPORTANT): configSet CTD_Seabird.loadAtStartup requires a restart to take effect.
2019-03-12T20:11:17.908Z,1552421477.908 [DataOverHttps](INFO): Moved sent file to Logs/20190312T180901/Courier0037.lzma.bak
2019-03-12T20:11:17.909Z,1552421477.909 [DataOverHttps](INFO): SBD MOMSN=10126278
2019-03-12T20:11:28.886Z,1552421488.886 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20190312T200832/Courier0000.lzma
2019-03-12T20:11:29.692Z,1552421489.692 [DataOverHttps](INFO): Moved sent file to Logs/20190312T200832/Courier0000.lzma.bak
2019-03-12T20:11:29.692Z,1552421489.692 [DataOverHttps](INFO): SBD MOMSN=10126281
2019-03-12T20:11:41.058Z,1552421501.058 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190312T200832/Courier0004.lzma
2019-03-12T20:11:41.864Z,1552421501.864 [DataOverHttps](INFO): Moved sent file to Logs/20190312T200832/Courier0004.lzma.bak
2019-03-12T20:11:41.865Z,1552421501.865 [DataOverHttps](INFO): SBD MOMSN=10126286
2019-03-12T20:11:54.211Z,1552421514.211 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20190312T180901/Express0038.lzma
2019-03-12T20:11:54.985Z,1552421514.985 [DataOverHttps](INFO): Moved sent file to Logs/20190312T180901/Express0038.lzma.bak
2019-03-12T20:11:54.985Z,1552421514.985 [DataOverHttps](INFO): SBD MOMSN=10126288
2019-03-12T20:12:06.732Z,1552421526.732 [Startup:StartupSatComms:B](INFO): Timed out from 2019-03-12T20:11:06.5Z
2019-03-12T20:12:06.732Z,1552421526.732 [Startup:StartupSatComms:B] Stopped
2019-03-12T20:12:06.732Z,1552421526.732 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-03-12T20:12:06.732Z,1552421526.732 [Startup:StartupSatComms] Stopped
2019-03-12T20:12:06.732Z,1552421526.732 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-03-12T20:12:06.733Z,1552421526.733 [Startup](INFO): Completed Startup
2019-03-12T20:12:06.733Z,1552421526.733 [MissionManager](INFO): Startup is completed.
2019-03-12T20:12:06.733Z,1552421526.733 [MissionManager](INFO): Uninitializing Mission Startup
2019-03-12T20:12:06.733Z,1552421526.733 [Startup] Stopped
2019-03-12T20:12:06.733Z,1552421526.733 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-03-12T20:12:06.733Z,1552421526.733 [Startup:A.GoToSurface] Stopped
2019-03-12T20:12:06.734Z,1552421526.734 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-12T20:12:07.136Z,1552421527.136 [MissionManager](IMPORTANT): Started mission Default
2019-03-12T20:12:07.136Z,1552421527.136 [Default] Running Loop=1
2019-03-12T20:12:07.136Z,1552421527.136 [Default](DEBUG): Aggregate::initialize Default
2019-03-12T20:12:07.136Z,1552421527.136 [Default:B.GoToSurface] Running Loop=1
2019-03-12T20:12:07.136Z,1552421527.136 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-03-12T20:12:07.136Z,1552421527.136 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-03-12T20:12:07.137Z,1552421527.137 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-03-12T20:12:07.137Z,1552421527.137 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-03-12T20:12:07.137Z,1552421527.137 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-03-12T20:12:07.138Z,1552421527.138 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-03-12T20:12:07.138Z,1552421527.138 [Default:A.Wait] Running Loop=1
2019-03-12T20:12:07.138Z,1552421527.138 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-03-12T20:12:13.120Z,1552421533.120 [DataOverHttps](INFO): Sending 841 bytes from file Logs/20190312T200832/Express0001.lzma
2019-03-12T20:12:13.924Z,1552421533.924 [DataOverHttps](INFO): Moved sent file to Logs/20190312T200832/Express0001.lzma.bak
2019-03-12T20:12:13.924Z,1552421533.924 [DataOverHttps](INFO): SBD MOMSN=10126302
2019-03-12T20:12:20.464Z,1552421540.464 [Default:A.Wait](INFO): Done Waiting.
2019-03-12T20:12:20.465Z,1552421540.465 [Default:A.Wait] Stopped
2019-03-12T20:12:20.465Z,1552421540.465 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-03-12T20:12:20.868Z,1552421540.868 [Default:CheckIn] Running Loop=1
2019-03-12T20:12:20.868Z,1552421540.868 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-03-12T20:12:20.868Z,1552421540.868 [Default:CheckIn:Read_GPS] Running Loop=1
2019-03-12T20:12:21.271Z,1552421541.271 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-03-12T20:12:44.315Z,1552421564.315 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-12T20:12:44.316Z,1552421564.316 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-03-12T20:12:44.316Z,1552421564.316 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-12T20:12:44.317Z,1552421564.317 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-12T20:12:44.317Z,1552421564.317 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2019-03-12T20:12:44.317Z,1552421564.317 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-12T20:12:44.328Z,1552421564.328 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-12T20:12:44.328Z,1552421564.328 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-12T20:12:44.736Z,1552421564.736 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-12T20:12:44.736Z,1552421564.736 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-03-12T20:12:44.736Z,1552421564.736 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-12T20:12:44.736Z,1552421564.736 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2019-03-12T20:12:45.130Z,1552421565.130 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-12T20:13:59.808Z,1552421639.808 [DataOverHttps](IMPORTANT): SBD MTMSN=20190312T201400
2019-03-12T20:14:04.750Z,1552421644.750 [DataOverHttps](INFO): Received command:configSet DropWeight.loadAtStartup 0 bool persist
2019-03-12T20:14:04.886Z,1552421644.886 [CommandLine](IMPORTANT): got command configSet DropWeight.loadAtStartup 0.000000 bool persist
2019-03-12T20:14:04.886Z,1552421644.886 [CommandLine](IMPORTANT): configSet DropWeight.loadAtStartup requires a restart to take effect.
2019-03-12T20:14:25.272Z,1552421665.272 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-03-12T20:14:26.095Z,1552421666.095 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:30.135Z,1552421670.135 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:32.963Z,1552421672.963 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:36.187Z,1552421676.187 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:39.019Z,1552421679.019 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:42.255Z,1552421682.255 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:45.079Z,1552421685.079 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:45.514Z,1552421685.514 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-12T20:14:45.514Z,1552421685.514 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-03-12T20:14:45.514Z,1552421685.514 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-03-12T20:14:45.515Z,1552421685.515 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-03-12T20:14:45.516Z,1552421685.516 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2019-03-12T20:14:45.516Z,1552421685.516 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-03-12T20:14:45.526Z,1552421685.526 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-03-12T20:14:45.526Z,1552421685.526 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-03-12T20:14:45.941Z,1552421685.941 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-03-12T20:14:45.941Z,1552421685.941 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-03-12T20:14:45.941Z,1552421685.941 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-03-12T20:14:45.941Z,1552421685.941 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2019-03-12T20:14:46.302Z,1552421686.302 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-03-12T20:14:48.310Z,1552421688.310 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:51.139Z,1552421691.139 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:53.971Z,1552421693.971 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:57.203Z,1552421697.203 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:14:58.496Z,1552421698.496 [CommandLine](IMPORTANT): got command restart application
2019-03-12T20:14:59.499Z,1552421699.499 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:14:59.499Z,1552421699.499 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:14:59.583Z,1552421699.583 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-03-12T20:14:59.583Z,1552421699.583 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:14:59.584Z,1552421699.584 [CommandLine](INFO): Join timeout helper Thread ID is 5101
2019-03-12T20:14:59.584Z,1552421699.584 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-03-12T20:14:59.584Z,1552421699.584 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:14:59.585Z,1552421699.585 [NavChartDb](INFO): Join timeout helper Thread ID is 5102
2019-03-12T20:14:59.759Z,1552421699.759 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:14:59.759Z,1552421699.759 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:14:59.763Z,1552421699.763 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-03-12T20:14:59.763Z,1552421699.763 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:14:59.763Z,1552421699.763 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5103
2019-03-12T20:15:00.027Z,1552421700.027 [NAL9602](DEBUG): Fix Requested
2019-03-12T20:15:00.033Z,1552421700.033 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:15:00.033Z,1552421700.033 [WetLabsBB2FL](INFO): Powering down
2019-03-12T20:15:00.034Z,1552421700.034 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.044Z,1552421700.044 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-03-12T20:15:00.044Z,1552421700.044 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.044Z,1552421700.044 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 5104
2019-03-12T20:15:00.123Z,1552421700.123 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:15:00.123Z,1552421700.123 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.131Z,1552421700.131 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-03-12T20:15:00.131Z,1552421700.131 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.131Z,1552421700.131 [Radio_Surface](INFO): Join timeout helper Thread ID is 5105
2019-03-12T20:15:00.435Z,1552421700.435 [Radio_Surface](INFO): Powering down
2019-03-12T20:15:00.436Z,1552421700.436 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:15:00.436Z,1552421700.436 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.452Z,1552421700.452 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-03-12T20:15:00.452Z,1552421700.452 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.452Z,1552421700.452 [DataOverHttps](INFO): Join timeout helper Thread ID is 5106
2019-03-12T20:15:00.695Z,1552421700.695 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:15:00.695Z,1552421700.695 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.700Z,1552421700.700 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-03-12T20:15:00.700Z,1552421700.700 [logger ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.700Z,1552421700.700 [logger](INFO): Join timeout helper Thread ID is 5107
2019-03-12T20:15:00.795Z,1552421700.795 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:15:00.795Z,1552421700.795 [logger ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.800Z,1552421700.800 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-03-12T20:15:00.800Z,1552421700.800 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.800Z,1552421700.800 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-03-12T20:15:00.800Z,1552421700.800 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.800Z,1552421700.800 [controlThread](INFO): Join timeout helper Thread ID is 5108
2019-03-12T20:15:00.815Z,1552421700.815 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-03-12T20:15:00.815Z,1552421700.815 [controlThread](DEBUG): Uninitializing ControlThread
2019-03-12T20:15:00.816Z,1552421700.816 [NAL9602](INFO): Powering down
2019-03-12T20:15:00.818Z,1552421700.818 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-03-12T20:15:00.819Z,1552421700.819 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-03-12T20:15:00.820Z,1552421700.820 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-03-12T20:15:00.820Z,1552421700.820 [MissionManager](INFO): Uninitializing Mission Default
2019-03-12T20:15:00.820Z,1552421700.820 [Default] Stopped
2019-03-12T20:15:00.821Z,1552421700.821 [Default](DEBUG): Aggregate::uninitialize Default
2019-03-12T20:15:00.821Z,1552421700.821 [Default:B.GoToSurface] Stopped
2019-03-12T20:15:00.821Z,1552421700.821 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-03-12T20:15:00.821Z,1552421700.821 [Default:CheckIn] Stopped
2019-03-12T20:15:00.821Z,1552421700.821 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-03-12T20:15:00.821Z,1552421700.821 [Default:CheckIn:Read_GPS] Stopped
2019-03-12T20:15:00.823Z,1552421700.823 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-03-12T20:15:00.824Z,1552421700.824 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-03-12T20:15:00.824Z,1552421700.824 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-03-12T20:15:00.824Z,1552421700.824 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-03-12T20:15:00.824Z,1552421700.824 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-03-12T20:15:00.824Z,1552421700.824 [BuoyancyServo](INFO): Powering down
2019-03-12T20:15:00.839Z,1552421700.839 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-03-12T20:15:00.839Z,1552421700.839 [ElevatorServo](INFO): Powering down
2019-03-12T20:15:00.840Z,1552421700.840 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-03-12T20:15:00.840Z,1552421700.840 [MassServo](INFO): Powering down
2019-03-12T20:15:00.841Z,1552421700.841 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-03-12T20:15:00.841Z,1552421700.841 [RudderServo](INFO): Powering down
2019-03-12T20:15:00.842Z,1552421700.842 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-03-12T20:15:00.842Z,1552421700.842 [ThrusterServo](INFO): Powering down
2019-03-12T20:15:00.842Z,1552421700.842 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-03-12T20:15:00.843Z,1552421700.843 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-03-12T20:15:00.843Z,1552421700.843 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-03-12T20:15:00.843Z,1552421700.843 [CBIT](DEBUG): Powering off loads.
2019-03-12T20:15:00.855Z,1552421700.855 [CBIT](DEBUG): Disabling WDT.
2019-03-12T20:15:00.867Z,1552421700.867 [CBIT](DEBUG): Opening all GF detection circuits.
2019-03-12T20:15:00.868Z,1552421700.868 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.944Z,1552421700.944 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.950Z,1552421700.950 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.981Z,1552421700.981 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:00.983Z,1552421700.983 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:01.029Z,1552421701.029 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-03-12T20:15:01.083Z,1552421701.083 [logger ThreadHandler](INFO): Thread cancelled.