2018-09-19T21:21:40.044Z,1537392100.044 [Supervisor](DEBUG): Initializing supervisor.
2018-09-19T21:21:40.047Z,1537392100.047 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-09-19T21:21:40.048Z,1537392100.048 [SyncHandler](INFO): Protected caller Thread ID is 2319
2018-09-19T21:21:40.049Z,1537392100.049 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-09-19T21:21:40.050Z,1537392100.050 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-09-19T21:21:40.050Z,1537392100.050 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2320
2018-09-19T21:21:40.054Z,1537392100.054 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-09-19T21:21:40.066Z,1537392100.066 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-09-19T21:21:40.067Z,1537392100.067 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-09-19T21:21:40.068Z,1537392100.068 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2321
2018-09-19T21:21:40.068Z,1537392100.068 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-09-19T21:21:40.069Z,1537392100.069 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-09-19T21:21:40.070Z,1537392100.070 [logger ThreadHandler](INFO): Protected caller Thread ID is 2322
2018-09-19T21:21:40.072Z,1537392100.072 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-09-19T21:21:40.072Z,1537392100.072 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-09-19T21:21:40.074Z,1537392100.074 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-09-19T21:21:40.316Z,1537392100.316 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-09-19T21:21:40.316Z,1537392100.316 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-09-19T21:21:40.461Z,1537392100.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-09-19T21:21:40.462Z,1537392100.462 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-09-19T21:21:40.811Z,1537392100.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-09-19T21:21:40.812Z,1537392100.812 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-09-19T21:21:40.952Z,1537392100.952 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-09-19T21:21:40.953Z,1537392100.953 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-09-19T21:21:41.035Z,1537392101.035 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-09-19T21:21:41.239Z,1537392101.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-09-19T21:21:41.240Z,1537392101.240 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-09-19T21:21:41.340Z,1537392101.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-09-19T21:21:41.341Z,1537392101.341 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-09-19T21:21:41.684Z,1537392101.684 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-09-19T21:21:41.684Z,1537392101.684 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-09-19T21:21:42.144Z,1537392102.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-09-19T21:21:42.145Z,1537392102.145 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-09-19T21:21:42.461Z,1537392102.461 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-09-19T21:21:42.461Z,1537392102.461 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-09-19T21:21:42.982Z,1537392102.982 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-09-19T21:21:42.983Z,1537392102.983 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-09-19T21:21:43.193Z,1537392103.193 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-09-19T21:21:43.194Z,1537392103.194 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-09-19T21:21:43.294Z,1537392103.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-09-19T21:21:43.295Z,1537392103.295 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-09-19T21:21:43.791Z,1537392103.791 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-09-19T21:21:43.791Z,1537392103.791 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-09-19T21:21:43.929Z,1537392103.929 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-09-19T21:21:43.931Z,1537392103.931 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2018-09-19T21:21:43.932Z,1537392103.932 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2018-09-19T21:21:44.763Z,1537392104.763 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-09-19T21:21:44.764Z,1537392104.764 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2018-09-19T21:21:47.873Z,1537392107.873 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2018-09-19T21:21:47.968Z,1537392107.968 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2018-09-19T21:21:48.073Z,1537392108.073 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2018-09-19T21:21:48.161Z,1537392108.161 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2018-09-19T21:21:48.297Z,1537392108.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2018-09-19T21:21:48.468Z,1537392108.468 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2018-09-19T21:21:48.580Z,1537392108.580 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2018-09-19T21:21:48.667Z,1537392108.667 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2018-09-19T21:21:48.752Z,1537392108.752 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2018-09-19T21:21:48.996Z,1537392108.996 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/
2018-09-19T21:21:48.996Z,1537392108.996 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-09-19T21:21:50.431Z,1537392110.431 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-09-19T21:21:50.667Z,1537392110.667 [SBIT](DEBUG): Construct Startup Built In Test.
2018-09-19T21:21:50.698Z,1537392110.698 [SBIT] Loaded
2018-09-19T21:21:50.698Z,1537392110.698 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-09-19T21:21:50.699Z,1537392110.699 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-09-19T21:21:50.726Z,1537392110.726 [IBIT] Loaded
2018-09-19T21:21:50.726Z,1537392110.726 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-09-19T21:21:50.730Z,1537392110.730 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-09-19T21:21:50.885Z,1537392110.885 [CBIT] Loaded
2018-09-19T21:21:50.885Z,1537392110.885 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-09-19T21:21:50.886Z,1537392110.886 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-09-19T21:21:50.886Z,1537392110.886 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-09-19T21:21:50.956Z,1537392110.956 [VerticalControl](DEBUG): Construct VerticalControl.
2018-09-19T21:21:51.057Z,1537392111.057 [VerticalControl] Loaded
2018-09-19T21:21:51.057Z,1537392111.057 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-09-19T21:21:51.058Z,1537392111.058 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-09-19T21:21:51.119Z,1537392111.119 [HorizontalControl] Loaded
2018-09-19T21:21:51.119Z,1537392111.119 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-09-19T21:21:51.119Z,1537392111.119 [SpeedControl](DEBUG): Construct SpeedControl.
2018-09-19T21:21:51.125Z,1537392111.125 [SpeedControl] Loaded
2018-09-19T21:21:51.125Z,1537392111.125 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-09-19T21:21:51.126Z,1537392111.126 [LoopControl](DEBUG): Construct LoopControl.
2018-09-19T21:21:51.127Z,1537392111.127 [LoopControl] Loaded
2018-09-19T21:21:51.127Z,1537392111.127 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-09-19T21:21:51.127Z,1537392111.127 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-09-19T21:21:51.128Z,1537392111.128 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-09-19T21:21:51.184Z,1537392111.184 [DepthRateCalculator] Loaded
2018-09-19T21:21:51.184Z,1537392111.184 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-09-19T21:21:51.190Z,1537392111.190 [PitchRateCalculator] Loaded
2018-09-19T21:21:51.190Z,1537392111.190 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-09-19T21:21:51.206Z,1537392111.206 [SpeedCalculator] Loaded
2018-09-19T21:21:51.206Z,1537392111.206 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-09-19T21:21:51.227Z,1537392111.227 [TempGradientCalculator] Loaded
2018-09-19T21:21:51.227Z,1537392111.227 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-09-19T21:21:51.243Z,1537392111.243 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-09-19T21:21:51.243Z,1537392111.243 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-09-19T21:21:51.248Z,1537392111.248 [YawRateCalculator] Loaded
2018-09-19T21:21:51.249Z,1537392111.249 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-09-19T21:21:51.278Z,1537392111.278 [ElevatorOffsetCalculator] Loaded
2018-09-19T21:21:51.278Z,1537392111.278 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-09-19T21:21:51.279Z,1537392111.279 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-09-19T21:21:51.279Z,1537392111.279 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-09-19T21:21:51.383Z,1537392111.383 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-09-19T21:21:51.384Z,1537392111.384 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-09-19T21:21:51.669Z,1537392111.669 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-09-19T21:21:51.669Z,1537392111.669 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-09-19T21:21:51.783Z,1537392111.783 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-09-19T21:21:51.783Z,1537392111.783 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-09-19T21:21:51.837Z,1537392111.837 [DeadReckonUsingSpeedCalculator] Loaded
2018-09-19T21:21:51.838Z,1537392111.838 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-09-19T21:21:51.854Z,1537392111.854 [NavChart] Loaded
2018-09-19T21:21:51.855Z,1537392111.855 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-09-19T21:21:51.859Z,1537392111.859 [UniversalFixResidualReporter] Loaded
2018-09-19T21:21:51.859Z,1537392111.859 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-09-19T21:21:51.860Z,1537392111.860 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-09-19T21:21:51.860Z,1537392111.860 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-09-19T21:21:51.874Z,1537392111.874 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-09-19T21:21:51.874Z,1537392111.874 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-09-19T21:21:52.029Z,1537392112.029 [Aanderaa_O2] Loaded
2018-09-19T21:21:52.030Z,1537392112.030 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-09-19T21:21:52.075Z,1537392112.075 [WetLabsSeaOWL_UV_A] Loaded
2018-09-19T21:21:52.076Z,1537392112.076 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-09-19T21:21:52.077Z,1537392112.077 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406D54E0
2018-09-19T21:21:52.077Z,1537392112.077 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2401
2018-09-19T21:21:52.078Z,1537392112.078 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-09-19T21:21:52.078Z,1537392112.078 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-09-19T21:21:52.386Z,1537392112.386 [AHRS_M2] Loaded
2018-09-19T21:21:52.386Z,1537392112.386 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2018-09-19T21:21:52.456Z,1537392112.456 [DataOverHttps] Loaded
2018-09-19T21:21:52.456Z,1537392112.456 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-09-19T21:21:52.470Z,1537392112.470 [Depth_Keller] Loaded
2018-09-19T21:21:52.470Z,1537392112.470 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-09-19T21:21:52.475Z,1537392112.475 [DropWeight] Loaded
2018-09-19T21:21:52.476Z,1537392112.476 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-09-19T21:21:52.566Z,1537392112.566 [NAL9602] Loaded
2018-09-19T21:21:52.566Z,1537392112.566 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-09-19T21:21:52.571Z,1537392112.571 [Onboard] Loaded
2018-09-19T21:21:52.572Z,1537392112.572 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-09-19T21:21:52.579Z,1537392112.579 [Radio_Surface] Loaded
2018-09-19T21:21:52.579Z,1537392112.579 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-09-19T21:21:52.580Z,1537392112.580 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409364E0
2018-09-19T21:21:52.580Z,1537392112.580 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2402
2018-09-19T21:21:52.609Z,1537392112.609 [RDI_Pathfinder] Loaded
2018-09-19T21:21:52.610Z,1537392112.610 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2018-09-19T21:21:52.632Z,1537392112.632 [RDI_PathfinderUp] Loaded
2018-09-19T21:21:52.632Z,1537392112.632 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2018-09-19T21:21:52.639Z,1537392112.639 [SCPI] Loaded
2018-09-19T21:21:52.639Z,1537392112.639 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2018-09-19T21:21:54.454Z,1537392114.454 [BPC1] Loaded
2018-09-19T21:21:54.454Z,1537392114.454 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-09-19T21:21:54.455Z,1537392114.455 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-09-19T21:21:54.455Z,1537392114.455 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-09-19T21:21:54.616Z,1537392114.616 [BuoyancyServo] Loaded
2018-09-19T21:21:54.616Z,1537392114.616 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-09-19T21:21:54.628Z,1537392114.628 [ElevatorServo] Loaded
2018-09-19T21:21:54.628Z,1537392114.628 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-09-19T21:21:54.639Z,1537392114.639 [MassServo] Loaded
2018-09-19T21:21:54.639Z,1537392114.639 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-09-19T21:21:54.651Z,1537392114.651 [RudderServo] Loaded
2018-09-19T21:21:54.652Z,1537392114.652 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-09-19T21:21:54.662Z,1537392114.662 [ThrusterServo] Loaded
2018-09-19T21:21:54.663Z,1537392114.663 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-09-19T21:21:54.663Z,1537392114.663 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-09-19T21:21:54.664Z,1537392114.664 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-09-19T21:21:54.791Z,1537392114.791 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-09-19T21:21:54.792Z,1537392114.792 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-09-19T21:21:54.829Z,1537392114.829 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-09-19T21:21:54.832Z,1537392114.832 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-09-19T21:21:54.833Z,1537392114.833 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-09-19T21:21:54.840Z,1537392114.840 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-09-19T21:21:54.841Z,1537392114.841 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409DF4E0
2018-09-19T21:21:54.841Z,1537392114.841 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2403
2018-09-19T21:21:54.846Z,1537392114.846 [Supervisor](INFO): Main Thread ID is 800
2018-09-19T21:21:54.846Z,1537392114.846 [Supervisor](DEBUG): Running supervisor.
2018-09-19T21:21:54.847Z,1537392114.847 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2404
2018-09-19T21:21:54.849Z,1537392114.849 [controlThread ThreadHandler](INFO): Handler Thread ID is 2405
2018-09-19T21:21:54.850Z,1537392114.850 [controlThread](DEBUG): Initializing ControlThread
2018-09-19T21:21:54.851Z,1537392114.851 [SBIT](INFO): Initialize SBIT Component.
2018-09-19T21:21:54.851Z,1537392114.851 [SBIT](IMPORTANT): git: 2018-09-04-21-gd54d9fc
2018-09-19T21:21:54.851Z,1537392114.851 [SBIT](INFO): git hash: d54d9fc12f891c3a6b7eed365ed7708e78930892
2018-09-19T21:21:54.852Z,1537392114.852 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-09-19T21:21:54.853Z,1537392114.853 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-09-19T21:21:54.855Z,1537392114.855 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-09-19T21:21:54.855Z,1537392114.855 [IBIT](INFO): Initialize IBIT Component.
2018-09-19T21:21:54.856Z,1537392114.856 [CBIT](DEBUG): Initialize CBIT Component.
2018-09-19T21:21:54.856Z,1537392114.856 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-09-19T21:21:54.857Z,1537392114.857 [logger ThreadHandler](INFO): Handler Thread ID is 2406
2018-09-19T21:21:54.883Z,1537392114.883 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2407
2018-09-19T21:21:54.891Z,1537392114.891 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-19T21:21:54.911Z,1537392114.911 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2408
2018-09-19T21:21:54.928Z,1537392114.928 [Radio_Surface](INFO): Powering up
2018-09-19T21:21:54.929Z,1537392114.929 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2409
2018-09-19T21:21:54.937Z,1537392114.937 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-09-19T21:21:54.937Z,1537392114.937 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-09-19T21:21:54.937Z,1537392114.937 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-09-19T21:21:54.937Z,1537392114.937 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-09-19T21:21:54.937Z,1537392114.937 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-09-19T21:21:54.938Z,1537392114.938 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-09-19T21:21:54.938Z,1537392114.938 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-09-19T21:21:54.938Z,1537392114.938 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-09-19T21:21:54.939Z,1537392114.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-09-19T21:21:54.939Z,1537392114.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-09-19T21:21:54.939Z,1537392114.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-09-19T21:21:54.939Z,1537392114.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-09-19T21:21:54.939Z,1537392114.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-09-19T21:21:54.939Z,1537392114.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-09-19T21:21:54.940Z,1537392114.940 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-09-19T21:21:54.940Z,1537392114.940 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-09-19T21:21:54.962Z,1537392114.962 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-09-19T21:21:54.964Z,1537392114.964 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-09-19T21:21:54.965Z,1537392114.965 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-09-19T21:21:54.965Z,1537392114.965 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-09-19T21:21:54.966Z,1537392114.966 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-19T21:21:54.966Z,1537392114.966 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-09-19T21:21:54.966Z,1537392114.966 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-09-19T21:21:54.967Z,1537392114.967 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-09-19T21:21:54.967Z,1537392114.967 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-09-19T21:21:54.968Z,1537392114.968 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-09-19T21:21:54.968Z,1537392114.968 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-09-19T21:21:54.969Z,1537392114.969 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-19T21:21:54.970Z,1537392114.970 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:21:54.970Z,1537392114.970 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:21:54.971Z,1537392114.971 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:21:54.971Z,1537392114.971 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:21:54.972Z,1537392114.972 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:21:54.972Z,1537392114.972 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-09-19T21:21:54.972Z,1537392114.972 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-09-19T21:21:54.979Z,1537392114.979 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-09-19T21:21:55.007Z,1537392115.007 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-19T21:21:55.043Z,1537392115.043 [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>


2018-09-19T21:21:55.044Z,1537392115.044 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-09-19T21:21:55.125Z,1537392115.125 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-09-19T21:21:55.126Z,1537392115.126 [Default:A.Wait](DEBUG): Construct Wait.
2018-09-19T21:21:55.128Z,1537392115.128 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-09-19T21:21:55.159Z,1537392115.159 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-09-19T21:21:55.162Z,1537392115.162 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-09-19T21:21:55.194Z,1537392115.194 [Default:E.Execute](DEBUG): Construct Execute.
2018-09-19T21:21:55.198Z,1537392115.198 [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>


2018-09-19T21:21:55.203Z,1537392115.203 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,RDI_PathfinderUp,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-09-19T21:21:55.258Z,1537392115.258 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2018-09-19T21:21:55.326Z,1537392115.326 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-09-19T21:21:55.367Z,1537392115.367 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2018-09-19T21:21:55.561Z,1537392115.561 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-19T21:21:55.658Z,1537392115.658 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:55.694Z,1537392115.694 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:55.796Z,1537392115.796 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:21:55.803Z,1537392115.803 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-19T21:21:55.825Z,1537392115.825 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:21:55.831Z,1537392115.831 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-09-19T21:21:55.837Z,1537392115.837 [MassServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:21:55.843Z,1537392115.843 [MassServo](DEBUG): Initializing MassServo.
2018-09-19T21:21:55.849Z,1537392115.849 [RudderServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:21:55.855Z,1537392115.855 [RudderServo](DEBUG): Initializing RudderServo.
2018-09-19T21:21:55.861Z,1537392115.861 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:21:55.867Z,1537392115.867 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-09-19T21:21:56.039Z,1537392116.039 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-09-19T21:21:56.039Z,1537392116.039 [DropWeight] Hardware Fault, FailCount= 1
2018-09-19T21:21:56.039Z,1537392116.039 [DropWeight](ERROR): Hardware Fault
2018-09-19T21:21:56.127Z,1537392116.127 [RDI_PathfinderUp](INFO): Powering down
2018-09-19T21:21:56.173Z,1537392116.173 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-19T21:21:56.184Z,1537392116.184 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:56.185Z,1537392116.185 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:56.211Z,1537392116.211 [CommandLine](FAULT): Scheduling is paused
2018-09-19T21:21:56.211Z,1537392116.211 [CBIT](INFO): Critical error at 20180919T212156
2018-09-19T21:21:56.212Z,1537392116.212 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-09-19T21:21:56.214Z,1537392116.214 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-09-19T21:21:56.215Z,1537392116.215 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-09-19T21:21:56.375Z,1537392116.375 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-09-19T21:21:56.378Z,1537392116.378 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:56.379Z,1537392116.379 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:56.710Z,1537392116.710 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-09-19T21:21:56.711Z,1537392116.711 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-09-19T21:21:56.711Z,1537392116.711 [BuoyancyServo] Communications Fault, FailCount= 1
2018-09-19T21:21:56.711Z,1537392116.711 [BuoyancyServo](ERROR): Communications Fault
2018-09-19T21:21:56.933Z,1537392116.933 [CBIT](INFO): Critical error at 20180919T212156
2018-09-19T21:21:56.935Z,1537392116.935 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-09-19T21:21:56.998Z,1537392116.998 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:57.006Z,1537392117.006 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:57.020Z,1537392117.020 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-19T21:21:57.021Z,1537392117.021 [BuoyancyServo](INFO): Powering down
2018-09-19T21:21:57.371Z,1537392117.371 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:57.372Z,1537392117.372 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:57.778Z,1537392117.778 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:57.779Z,1537392117.779 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:58.174Z,1537392118.174 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:58.175Z,1537392118.175 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:58.662Z,1537392118.662 [Aanderaa_O2](INFO): Powering down
2018-09-19T21:21:58.790Z,1537392118.790 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:58.798Z,1537392118.798 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:59.007Z,1537392119.007 [AHRS_M2](ERROR): Read RFS packet UART error: serial timeout
2018-09-19T21:21:59.047Z,1537392119.047 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:59.048Z,1537392119.048 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-09-19T21:21:59.099Z,1537392119.099 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-09-19T21:21:59.099Z,1537392119.099 [BuoyancyServo] No Fault, FailCount= 1
2018-09-19T21:21:59.404Z,1537392119.404 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-09-19T21:21:59.523Z,1537392119.523 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-09-19T21:22:08.978Z,1537392128.978 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2018-09-19T21:22:19.385Z,1537392139.385 [SBIT](IMPORTANT): Beginning Startup BIT
2018-09-19T21:22:19.406Z,1537392139.406 [CBIT](IMPORTANT): Beginning ground fault scan
2018-09-19T21:22:22.656Z,1537392142.656 [NAL9602](INFO): Powering up NAL9602
2018-09-19T21:22:30.352Z,1537392150.352 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.018681
CHAN A1 (24V): -0.022145
CHAN A2 (12V): -0.007098
CHAN A3 (5V): -0.001787
CHAN B0 (3.3V): 0.000282
CHAN B1 (3.15aV): -0.000363
CHAN B2 (3.15bV): 0.000095
CHAN B3 (GND): 0.002419
OPEN: 0.005115
Full Scale Calc: 4.765 mA, -1.589 mA
2018-09-19T21:22:33.852Z,1537392153.852 [NAL9602](INFO): NAL9602 initialized
2018-09-19T21:23:02.696Z,1537392182.696 [BPC1](ERROR): BPC1A: No match for stick with serial number:0165 in the onboard configuration file.
2018-09-19T21:23:02.697Z,1537392182.697 [BPC1](ERROR): BPC1B: No match for stick with serial number:0140 in the onboard configuration file.
2018-09-19T21:23:02.697Z,1537392182.697 [BPC1](FAULT): Failed to parse data from all battery packs.
2018-09-19T21:23:02.698Z,1537392182.698 [BPC1] Data Fault, FailCount= 1
2018-09-19T21:23:02.698Z,1537392182.698 [BPC1](ERROR): Data Fault
2018-09-19T21:23:02.813Z,1537392182.813 [CBIT](ERROR): Data Fault in component: BPC1
2018-09-19T21:23:13.501Z,1537392193.501 [SBIT](IMPORTANT): SBIT PASSED
2018-09-19T21:23:13.550Z,1537392193.550 [CommandLine](IMPORTANT): got command configSet list
2018-09-19T21:23:13.551Z,1537392193.551 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-09-19T21:23:13.552Z,1537392193.552 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=160 cubic_centimeter;

2018-09-19T21:23:13.552Z,1537392193.552 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 millimeter;

2018-09-19T21:23:13.880Z,1537392193.880 [MissionManager](IMPORTANT): Started mission Startup
2018-09-19T21:23:13.881Z,1537392193.881 [Startup] Running Loop=1
2018-09-19T21:23:13.881Z,1537392193.881 [Startup](DEBUG): Aggregate::initialize Startup
2018-09-19T21:23:13.881Z,1537392193.881 [Startup:A.GoToSurface] Running Loop=1
2018-09-19T21:23:13.881Z,1537392193.881 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-09-19T21:23:13.882Z,1537392193.882 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-09-19T21:23:13.906Z,1537392193.906 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-09-19T21:23:13.907Z,1537392193.907 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-09-19T21:23:13.907Z,1537392193.907 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-09-19T21:23:13.908Z,1537392193.908 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-09-19T21:23:13.914Z,1537392193.914 [Startup:StartupSatComms] Running Loop=1
2018-09-19T21:23:13.914Z,1537392193.914 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-09-19T21:23:13.914Z,1537392193.914 [Startup:StartupSatComms:A] Running Loop=1
2018-09-19T21:23:14.277Z,1537392194.277 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-09-19T21:24:14.263Z,1537392254.263 [Startup:StartupSatComms:A](INFO): Timed out from 2018-09-19T21:23:13.9Z
2018-09-19T21:24:14.264Z,1537392254.264 [Startup:StartupSatComms:A] Stopped
2018-09-19T21:24:14.264Z,1537392254.264 [Startup:StartupSatComms:B] Running Loop=1
2018-09-19T21:24:14.678Z,1537392254.678 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-09-19T21:24:55.083Z,1537392295.083 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:24:55.083Z,1537392295.083 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-09-19T21:24:55.083Z,1537392295.083 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-09-19T21:24:55.085Z,1537392295.085 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-09-19T21:24:55.085Z,1537392295.085 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-09-19T21:24:55.086Z,1537392295.086 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-09-19T21:24:55.131Z,1537392295.131 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-09-19T21:24:55.131Z,1537392295.131 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-09-19T21:24:55.483Z,1537392295.483 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-09-19T21:24:55.483Z,1537392295.483 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-09-19T21:24:55.484Z,1537392295.484 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-09-19T21:24:55.484Z,1537392295.484 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-09-19T21:24:55.891Z,1537392295.891 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-09-19T21:24:55.892Z,1537392295.892 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:24:55.892Z,1537392295.892 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:24:55.892Z,1537392295.892 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-09-19T21:24:55.893Z,1537392295.893 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-09-19T21:24:55.893Z,1537392295.893 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-09-19T21:25:01.161Z,1537392301.161 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004377
2018-09-19T21:25:01.618Z,1537392301.618 [CommandLine](IMPORTANT): got command restart application
2018-09-19T21:25:02.625Z,1537392302.625 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:25:02.626Z,1537392302.626 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:02.694Z,1537392302.694 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-09-19T21:25:02.694Z,1537392302.694 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:02.695Z,1537392302.695 [CommandLine](INFO): Join timeout helper Thread ID is 2434
2018-09-19T21:25:02.706Z,1537392302.706 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-09-19T21:25:02.706Z,1537392302.706 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:02.707Z,1537392302.707 [NavChartDb](INFO): Join timeout helper Thread ID is 2435
2018-09-19T21:25:03.059Z,1537392303.059 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:25:03.059Z,1537392303.059 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.078Z,1537392303.078 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-09-19T21:25:03.078Z,1537392303.078 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.079Z,1537392303.079 [Radio_Surface](INFO): Join timeout helper Thread ID is 2436
2018-09-19T21:25:03.295Z,1537392303.295 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:25:03.295Z,1537392303.295 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.306Z,1537392303.306 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-09-19T21:25:03.306Z,1537392303.306 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.307Z,1537392303.307 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2437
2018-09-19T21:25:03.667Z,1537392303.667 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:25:03.667Z,1537392303.667 [WetLabsSeaOWL_UV_A](INFO): Powering down
2018-09-19T21:25:03.667Z,1537392303.667 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.678Z,1537392303.678 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-09-19T21:25:03.679Z,1537392303.679 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.679Z,1537392303.679 [logger](INFO): Join timeout helper Thread ID is 2438
2018-09-19T21:25:03.679Z,1537392303.679 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:25:03.680Z,1537392303.680 [logger ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.681Z,1537392303.681 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-09-19T21:25:03.681Z,1537392303.681 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.681Z,1537392303.681 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-09-19T21:25:03.681Z,1537392303.681 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:03.682Z,1537392303.682 [controlThread](INFO): Join timeout helper Thread ID is 2439
2018-09-19T21:25:05.188Z,1537392305.188 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-09-19T21:25:05.188Z,1537392305.188 [controlThread](DEBUG): Uninitializing ControlThread
2018-09-19T21:25:05.188Z,1537392305.188 [Aanderaa_O2](INFO): Powering down
2018-09-19T21:25:05.189Z,1537392305.189 [AHRS_M2](INFO): Powering down
2018-09-19T21:25:05.262Z,1537392305.262 [NAL9602](INFO): Powering down
2018-09-19T21:25:05.334Z,1537392305.334 [RDI_Pathfinder](INFO): Powering down
2018-09-19T21:25:05.335Z,1537392305.335 [RDI_PathfinderUp](INFO): Powering down
2018-09-19T21:25:05.337Z,1537392305.337 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-09-19T21:25:05.338Z,1537392305.338 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-09-19T21:25:05.339Z,1537392305.339 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-09-19T21:25:05.339Z,1537392305.339 [MissionManager](INFO): Uninitializing Mission Default
2018-09-19T21:25:05.342Z,1537392305.342 [MissionManager](INFO): Uninitializing Mission Startup
2018-09-19T21:25:05.342Z,1537392305.342 [Startup] Stopped
2018-09-19T21:25:05.342Z,1537392305.342 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-09-19T21:25:05.342Z,1537392305.342 [Startup:A.GoToSurface] Stopped
2018-09-19T21:25:05.342Z,1537392305.342 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-09-19T21:25:05.342Z,1537392305.342 [Startup:StartupSatComms] Stopped
2018-09-19T21:25:05.343Z,1537392305.343 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-09-19T21:25:05.343Z,1537392305.343 [Startup:StartupSatComms:B] Stopped
2018-09-19T21:25:05.345Z,1537392305.345 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-09-19T21:25:05.345Z,1537392305.345 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-09-19T21:25:05.345Z,1537392305.345 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-09-19T21:25:05.345Z,1537392305.345 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-09-19T21:25:05.346Z,1537392305.346 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-09-19T21:25:05.346Z,1537392305.346 [BuoyancyServo](INFO): Powering down
2018-09-19T21:25:05.358Z,1537392305.358 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-09-19T21:25:05.359Z,1537392305.359 [ElevatorServo](INFO): Powering down
2018-09-19T21:25:05.360Z,1537392305.360 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-09-19T21:25:05.360Z,1537392305.360 [MassServo](INFO): Powering down
2018-09-19T21:25:05.361Z,1537392305.361 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-09-19T21:25:05.361Z,1537392305.361 [RudderServo](INFO): Powering down
2018-09-19T21:25:05.362Z,1537392305.362 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-09-19T21:25:05.362Z,1537392305.362 [ThrusterServo](INFO): Powering down
2018-09-19T21:25:05.363Z,1537392305.363 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-09-19T21:25:05.363Z,1537392305.363 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-09-19T21:25:05.363Z,1537392305.363 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-09-19T21:25:05.364Z,1537392305.364 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:05.419Z,1537392305.419 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:05.481Z,1537392305.481 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:05.567Z,1537392305.567 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-09-19T21:25:05.658Z,1537392305.658 [logger ThreadHandler](INFO): Thread cancelled.