2019-05-30T18:12:38.924Z,1559239958.924 [Supervisor](DEBUG): Initializing supervisor.
2019-05-30T18:12:38.927Z,1559239958.927 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-30T18:12:38.928Z,1559239958.928 [SyncHandler](INFO): Protected caller Thread ID is 2170
2019-05-30T18:12:38.928Z,1559239958.928 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-30T18:12:38.929Z,1559239958.929 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-30T18:12:38.929Z,1559239958.929 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2171
2019-05-30T18:12:38.932Z,1559239958.932 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-30T18:12:39.156Z,1559239959.156 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-30T18:12:39.157Z,1559239959.157 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-30T18:12:39.158Z,1559239959.158 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2172
2019-05-30T18:12:39.158Z,1559239959.158 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-30T18:12:39.159Z,1559239959.159 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-30T18:12:39.160Z,1559239959.160 [logger ThreadHandler](INFO): Protected caller Thread ID is 2173
2019-05-30T18:12:39.162Z,1559239959.162 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-30T18:12:39.162Z,1559239959.162 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-30T18:12:39.164Z,1559239959.164 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-30T18:12:39.587Z,1559239959.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-30T18:12:39.588Z,1559239959.588 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-30T18:12:39.687Z,1559239959.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-30T18:12:39.687Z,1559239959.687 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-30T18:12:40.030Z,1559239960.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-30T18:12:40.031Z,1559239960.031 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-30T18:12:40.174Z,1559239960.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-30T18:12:40.175Z,1559239960.175 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-30T18:12:40.369Z,1559239960.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-30T18:12:40.369Z,1559239960.369 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-30T18:12:40.826Z,1559239960.826 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-30T18:12:40.826Z,1559239960.826 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-30T18:12:41.038Z,1559239961.038 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-30T18:12:41.038Z,1559239961.038 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-30T18:12:41.186Z,1559239961.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-30T18:12:41.187Z,1559239961.187 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-30T18:12:41.382Z,1559239961.382 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-30T18:12:41.382Z,1559239961.382 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-30T18:12:41.479Z,1559239961.479 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-30T18:12:41.480Z,1559239961.480 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-30T18:12:41.803Z,1559239961.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-30T18:12:41.803Z,1559239961.803 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-30T18:12:41.886Z,1559239961.886 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-30T18:12:41.993Z,1559239961.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-30T18:12:41.993Z,1559239961.993 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-30T18:12:42.597Z,1559239962.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-30T18:12:42.598Z,1559239962.598 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-30T18:12:42.989Z,1559239962.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-30T18:12:42.991Z,1559239962.991 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-05-30T18:12:42.992Z,1559239962.992 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-05-30T18:12:43.208Z,1559239963.208 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-05-30T18:12:43.311Z,1559239963.311 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-05-30T18:12:43.412Z,1559239963.412 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-05-30T18:12:43.642Z,1559239963.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-30T18:12:43.643Z,1559239963.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-05-30T18:12:43.765Z,1559239963.765 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-05-30T18:12:43.913Z,1559239963.913 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-05-30T18:12:44.063Z,1559239964.063 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-05-30T18:12:44.183Z,1559239964.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-05-30T18:12:44.448Z,1559239964.448 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-05-30T18:12:44.784Z,1559239964.784 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-05-30T18:12:44.917Z,1559239964.917 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/LOGIN/
2019-05-30T18:12:44.917Z,1559239964.917 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-30T18:12:44.932Z,1559239964.932 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-30T18:12:45.317Z,1559239965.317 [AHRS_M2] Loaded
2019-05-30T18:12:45.317Z,1559239965.317 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-05-30T18:12:45.331Z,1559239965.331 [Depth_Keller] Loaded
2019-05-30T18:12:45.331Z,1559239965.331 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-30T18:12:45.336Z,1559239965.336 [DropWeight] Loaded
2019-05-30T18:12:45.336Z,1559239965.336 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-05-30T18:12:45.394Z,1559239965.394 [DUSBL_Hydroid] Loaded
2019-05-30T18:12:45.394Z,1559239965.394 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-05-30T18:12:45.442Z,1559239965.442 [Micromodem] Loaded
2019-05-30T18:12:45.442Z,1559239965.442 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-05-30T18:12:45.541Z,1559239965.541 [NAL9602] Loaded
2019-05-30T18:12:45.541Z,1559239965.541 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-30T18:12:45.557Z,1559239965.557 [Onboard] Loaded
2019-05-30T18:12:45.557Z,1559239965.557 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-30T18:12:45.563Z,1559239965.563 [PowerOnly] Loaded
2019-05-30T18:12:45.564Z,1559239965.564 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-05-30T18:12:45.574Z,1559239965.574 [Radio_Surface] Loaded
2019-05-30T18:12:45.574Z,1559239965.574 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-30T18:12:45.575Z,1559239965.575 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407644E0
2019-05-30T18:12:45.576Z,1559239965.576 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2252
2019-05-30T18:12:45.621Z,1559239965.621 [RDI_Pathfinder] Loaded
2019-05-30T18:12:45.621Z,1559239965.621 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-05-30T18:12:47.133Z,1559239967.133 [BPC1] Loaded
2019-05-30T18:12:47.133Z,1559239967.133 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-30T18:12:47.134Z,1559239967.134 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-30T18:12:47.134Z,1559239967.134 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-30T18:12:47.147Z,1559239967.147 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-30T18:12:47.148Z,1559239967.148 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-30T18:12:47.255Z,1559239967.255 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-30T18:12:47.255Z,1559239967.255 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-30T18:12:47.276Z,1559239967.276 [NavChart] Loaded
2019-05-30T18:12:47.276Z,1559239967.276 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-30T18:12:47.280Z,1559239967.280 [UniversalFixResidualReporter] Loaded
2019-05-30T18:12:47.280Z,1559239967.280 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-30T18:12:47.281Z,1559239967.281 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-30T18:12:47.281Z,1559239967.281 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-30T18:12:47.390Z,1559239967.390 [BuoyancyServo] Loaded
2019-05-30T18:12:47.390Z,1559239967.390 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-30T18:12:47.405Z,1559239967.405 [ElevatorServo] Loaded
2019-05-30T18:12:47.406Z,1559239967.406 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-30T18:12:47.420Z,1559239967.420 [MassServo] Loaded
2019-05-30T18:12:47.421Z,1559239967.421 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-30T18:12:47.436Z,1559239967.436 [RudderServo] Loaded
2019-05-30T18:12:47.436Z,1559239967.436 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-30T18:12:47.451Z,1559239967.451 [ThrusterServo] Loaded
2019-05-30T18:12:47.451Z,1559239967.451 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-30T18:12:47.452Z,1559239967.452 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-30T18:12:47.452Z,1559239967.452 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-30T18:12:47.704Z,1559239967.704 [CTD_NeilBrown] Loaded
2019-05-30T18:12:47.704Z,1559239967.704 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-30T18:12:47.705Z,1559239967.705 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408A64E0
2019-05-30T18:12:47.705Z,1559239967.705 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2253
2019-05-30T18:12:47.750Z,1559239967.750 [WetLabsSeaOWL_UV_A] Loaded
2019-05-30T18:12:47.751Z,1559239967.751 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-05-30T18:12:47.752Z,1559239967.752 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 408D64E0
2019-05-30T18:12:47.752Z,1559239967.752 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2254
2019-05-30T18:12:47.753Z,1559239967.753 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-30T18:12:47.753Z,1559239967.753 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-30T18:12:48.056Z,1559239968.056 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-30T18:12:48.056Z,1559239968.056 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-30T18:12:48.097Z,1559239968.097 [DepthRateCalculator] Loaded
2019-05-30T18:12:48.097Z,1559239968.097 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-30T18:12:48.103Z,1559239968.103 [PitchRateCalculator] Loaded
2019-05-30T18:12:48.103Z,1559239968.103 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-30T18:12:48.116Z,1559239968.116 [SpeedCalculator] Loaded
2019-05-30T18:12:48.116Z,1559239968.116 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-30T18:12:48.137Z,1559239968.137 [TempGradientCalculator] Loaded
2019-05-30T18:12:48.137Z,1559239968.137 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-30T18:12:48.143Z,1559239968.143 [YawRateCalculator] Loaded
2019-05-30T18:12:48.143Z,1559239968.143 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-30T18:12:48.184Z,1559239968.184 [ElevatorOffsetCalculator] Loaded
2019-05-30T18:12:48.184Z,1559239968.184 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-30T18:12:48.184Z,1559239968.184 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-30T18:12:48.185Z,1559239968.185 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-30T18:12:48.324Z,1559239968.324 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-30T18:12:48.346Z,1559239968.346 [SBIT] Loaded
2019-05-30T18:12:48.346Z,1559239968.346 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-30T18:12:48.347Z,1559239968.347 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-30T18:12:48.358Z,1559239968.358 [IBIT] Loaded
2019-05-30T18:12:48.359Z,1559239968.359 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-30T18:12:48.362Z,1559239968.362 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-30T18:12:48.501Z,1559239968.501 [CBIT] Loaded
2019-05-30T18:12:48.501Z,1559239968.501 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-30T18:12:48.501Z,1559239968.501 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-30T18:12:48.502Z,1559239968.502 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-30T18:12:48.573Z,1559239968.573 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-30T18:12:48.573Z,1559239968.573 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-30T18:12:48.675Z,1559239968.675 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-30T18:12:48.676Z,1559239968.676 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-30T18:12:48.743Z,1559239968.743 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-30T18:12:48.826Z,1559239968.826 [VerticalControl] Loaded
2019-05-30T18:12:48.827Z,1559239968.827 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-30T18:12:48.828Z,1559239968.828 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-30T18:12:48.885Z,1559239968.885 [HorizontalControl] Loaded
2019-05-30T18:12:48.885Z,1559239968.885 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-30T18:12:48.886Z,1559239968.886 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-30T18:12:48.888Z,1559239968.888 [SpeedControl] Loaded
2019-05-30T18:12:48.888Z,1559239968.888 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-30T18:12:48.889Z,1559239968.889 [LoopControl](DEBUG): Construct LoopControl.
2019-05-30T18:12:48.889Z,1559239968.889 [LoopControl] Loaded
2019-05-30T18:12:48.890Z,1559239968.890 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-30T18:12:48.890Z,1559239968.890 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-30T18:12:48.891Z,1559239968.891 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-30T18:12:48.958Z,1559239968.958 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-30T18:12:48.961Z,1559239968.961 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-30T18:12:48.962Z,1559239968.962 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-30T18:12:48.969Z,1559239968.969 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-30T18:12:48.970Z,1559239968.970 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AAD4E0
2019-05-30T18:12:48.971Z,1559239968.971 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2255
2019-05-30T18:12:48.975Z,1559239968.975 [Supervisor](INFO): Main Thread ID is 2169
2019-05-30T18:12:48.975Z,1559239968.975 [Supervisor](DEBUG): Running supervisor.
2019-05-30T18:12:48.976Z,1559239968.976 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2256
2019-05-30T18:12:48.978Z,1559239968.978 [controlThread ThreadHandler](INFO): Handler Thread ID is 2257
2019-05-30T18:12:48.978Z,1559239968.978 [controlThread](DEBUG): Initializing ControlThread
2019-05-30T18:12:48.987Z,1559239968.987 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-30T18:12:48.987Z,1559239968.987 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-30T18:12:48.988Z,1559239968.988 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-30T18:12:48.989Z,1559239968.989 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-30T18:12:48.989Z,1559239968.989 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-30T18:12:48.989Z,1559239968.989 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-30T18:12:48.990Z,1559239968.990 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-30T18:12:48.990Z,1559239968.990 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-30T18:12:48.991Z,1559239968.991 [SBIT](INFO): Initialize SBIT Component.
2019-05-30T18:12:48.991Z,1559239968.991 [SBIT](IMPORTANT): git: 2019-05-01-19-g6ef4ecc
2019-05-30T18:12:48.991Z,1559239968.991 [SBIT](INFO): git hash: 6ef4ecc926d3cc84e5878e2d73d98fd38ff7dcf7
2019-05-30T18:12:48.992Z,1559239968.992 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-30T18:12:48.993Z,1559239968.993 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-30T18:12:48.994Z,1559239968.994 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2019-05-30T18:12:48.995Z,1559239968.995 [IBIT](INFO): Initialize IBIT Component.
2019-05-30T18:12:48.996Z,1559239968.996 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-30T18:12:48.996Z,1559239968.996 [logger ThreadHandler](INFO): Handler Thread ID is 2258
2019-05-30T18:12:49.007Z,1559239969.007 [CBIT](DEBUG): Initialized mux pins.
2019-05-30T18:12:49.007Z,1559239969.007 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-30T18:12:49.012Z,1559239969.012 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2259
2019-05-30T18:12:49.014Z,1559239969.014 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2260
2019-05-30T18:12:49.015Z,1559239969.015 [CTD_NeilBrown](INFO): Powering down
2019-05-30T18:12:49.036Z,1559239969.036 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2261
2019-05-30T18:12:49.037Z,1559239969.037 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T18:12:49.051Z,1559239969.051 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-30T18:12:49.051Z,1559239969.051 [CBIT](DEBUG): Initializing heartbeat.
2019-05-30T18:12:49.058Z,1559239969.058 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2262
2019-05-30T18:12:49.061Z,1559239969.061 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-30T18:12:49.061Z,1559239969.061 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-30T18:12:49.062Z,1559239969.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-30T18:12:49.062Z,1559239969.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-30T18:12:49.062Z,1559239969.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-30T18:12:49.062Z,1559239969.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-30T18:12:49.062Z,1559239969.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-30T18:12:49.063Z,1559239969.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-30T18:12:49.065Z,1559239969.065 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-30T18:12:49.065Z,1559239969.065 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-30T18:12:49.065Z,1559239969.065 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-30T18:12:49.066Z,1559239969.066 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-30T18:12:49.066Z,1559239969.066 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-30T18:12:49.066Z,1559239969.066 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-30T18:12:49.066Z,1559239969.066 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-30T18:12:49.066Z,1559239969.066 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-30T18:12:49.123Z,1559239969.123 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-30T18:12:49.123Z,1559239969.123 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-30T18:12:49.159Z,1559239969.159 [CBIT](DEBUG): Backplane powered.
2019-05-30T18:12:49.159Z,1559239969.159 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-30T18:12:49.161Z,1559239969.161 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-30T18:12:49.162Z,1559239969.162 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-30T18:12:49.162Z,1559239969.162 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-30T18:12:49.163Z,1559239969.163 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-30T18:12:49.173Z,1559239969.173 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T18:12:49.200Z,1559239969.200 [MissionManager](DEBUG):
2019-05-30T18:12:49.201Z,1559239969.201 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-30T18:12:49.271Z,1559239969.271 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-30T18:12:49.272Z,1559239969.272 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-30T18:12:49.274Z,1559239969.274 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-30T18:12:49.309Z,1559239969.309 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-30T18:12:49.311Z,1559239969.311 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-30T18:12:49.321Z,1559239969.321 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-30T18:12:49.340Z,1559239969.340 [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-05-30T18:12:49.345Z,1559239969.345 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-05-30T18:12:49.363Z,1559239969.363 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-05-30T18:12:49.396Z,1559239969.396 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-05-30T18:12:49.397Z,1559239969.397 [DUSBL_Hydroid](INFO): Powering up
2019-05-30T18:12:49.397Z,1559239969.397 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-05-30T18:12:49.415Z,1559239969.415 [Radio_Surface](INFO): Powering up
2019-05-30T18:12:49.471Z,1559239969.471 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-30T18:12:49.489Z,1559239969.489 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-30T18:12:49.495Z,1559239969.495 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-30T18:12:49.496Z,1559239969.496 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-30T18:12:49.503Z,1559239969.503 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-30T18:12:49.504Z,1559239969.504 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-30T18:12:49.511Z,1559239969.511 [MassServo](DEBUG): Initializing MassServo.
2019-05-30T18:12:49.512Z,1559239969.512 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-30T18:12:49.519Z,1559239969.519 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-30T18:12:49.520Z,1559239969.520 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-30T18:12:49.527Z,1559239969.527 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-30T18:12:49.867Z,1559239969.867 [Micromodem](INFO): Powering up
2019-05-30T18:12:49.867Z,1559239969.867 [Micromodem](DEBUG): Initializing Micromodem.
2019-05-30T18:12:54.637Z,1559239974.637 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2019-05-30T18:12:55.041Z,1559239975.041 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2019-05-30T18:12:55.042Z,1559239975.042 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31
2019-05-30T18:12:55.445Z,1559239975.445 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33
2019-05-30T18:12:55.445Z,1559239975.445 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2019-05-30T18:12:55.837Z,1559239975.837 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2019-05-30T18:12:55.838Z,1559239975.838 [Micromodem](INFO): Nmea out: $CCCFG,nav.nst,1*4D
2019-05-30T18:12:56.253Z,1559239976.253 [Micromodem](INFO): Nmea in: $CACFG,nav.nst,1*4F
2019-05-30T18:12:56.253Z,1559239976.253 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E
2019-05-30T18:12:56.657Z,1559239976.657 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C
2019-05-30T18:12:56.657Z,1559239976.657 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46
2019-05-30T18:12:57.061Z,1559239977.061 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44
2019-05-30T18:12:57.061Z,1559239977.061 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2019-05-30T18:12:57.453Z,1559239977.453 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2019-05-30T18:12:57.453Z,1559239977.453 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2019-05-30T18:12:57.861Z,1559239977.861 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2019-05-30T18:12:57.862Z,1559239977.862 [Micromodem](INFO): Nmea out: $CCCLK,2019,05,30,18,12,58*4F
2019-05-30T18:12:58.253Z,1559239978.253 [Micromodem](INFO): Nmea in: $CACLK,2019,5,30,18,12,58*7D
2019-05-30T18:12:59.058Z,1559239979.058 [Micromodem](INFO): Nmea in: $CATMS,0,2019-05-30T18:12:59Z*7C
2019-05-30T18:12:59.081Z,1559239979.081 [Micromodem](INFO): Nmea in: $CATMG,2019-05-30T18:12:59Z,USER_CMD,RTC*35
2019-05-30T18:13:02.710Z,1559239982.710 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-05-30T18:13:07.533Z,1559239987.533 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-05-30T18:13:15.625Z,1559239995.625 [NAL9602](INFO): Powering up NAL9602
2019-05-30T18:13:26.529Z,1559240006.529 [NAL9602](INFO): NAL9602 initialized
2019-05-30T18:13:27.339Z,1559240007.339 [NAL9602](DEBUG): Fix Requested
2019-05-30T18:13:28.585Z,1559240008.585 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-30T18:13:28.621Z,1559240008.621 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-30T18:13:39.625Z,1559240019.625 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.013293
CHAN A1 (24V): -0.025562
CHAN A2 (12V): -0.005852
CHAN A3 (5V): -0.002284
CHAN B0 (3.3V): 0.000532
CHAN B1 (3.15aV): 0.000080
CHAN B2 (3.15bV): 0.000096
CHAN B3 (GND): 0.001765
OPEN: 0.007112
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-30T18:13:49.415Z,1559240029.415 [NAL9602](INFO): SBD MO Status=2, MOMSN=5588, MT Status=2, MTMSN=0
2019-05-30T18:13:49.416Z,1559240029.416 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-05-30T18:14:21.958Z,1559240061.958 [SBIT](IMPORTANT): SBIT PASSED
2019-05-30T18:14:22.019Z,1559240062.019 [CommandLine](IMPORTANT): got command configSet list
2019-05-30T18:14:22.020Z,1559240062.020 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=3 hour;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): BPC1.loadAtStartup=1 bool;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=40 count;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.BottomVelocityFlag 0.000000 count;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;
2019-05-30T18:14:22.021Z,1559240062.021 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;
2019-05-30T18:14:22.022Z,1559240062.022 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;
2019-05-30T18:14:22.022Z,1559240062.022 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 5.000000 microgram_per_liter;
2019-05-30T18:14:22.022Z,1559240062.022 [CommandLine](IMPORTANT): Express none mass_concentration_of_oxygen_in_sea_water;
2019-05-30T18:14:22.022Z,1559240062.022 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;
2019-05-30T18:14:22.022Z,1559240062.022 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;
2019-05-30T18:14:22.022Z,1559240062.022 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;
2019-05-30T18:14:22.344Z,1559240062.344 [MissionManager](IMPORTANT): Started mission Startup
2019-05-30T18:14:22.344Z,1559240062.344 [Startup] Running Loop=1
2019-05-30T18:14:22.345Z,1559240062.345 [Startup](DEBUG): Aggregate::initialize Startup
2019-05-30T18:14:22.345Z,1559240062.345 [Startup:A.GoToSurface] Running Loop=1
2019-05-30T18:14:22.345Z,1559240062.345 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T18:14:22.345Z,1559240062.345 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T18:14:22.346Z,1559240062.346 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T18:14:22.346Z,1559240062.346 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T18:14:22.346Z,1559240062.346 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T18:14:22.347Z,1559240062.347 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T18:14:22.348Z,1559240062.348 [Startup:StartupSatComms] Running Loop=1
2019-05-30T18:14:22.349Z,1559240062.349 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-05-30T18:14:22.349Z,1559240062.349 [Startup:StartupSatComms:A] Running Loop=1
2019-05-30T18:14:22.770Z,1559240062.770 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-05-30T18:15:22.541Z,1559240122.541 [Startup:StartupSatComms:A](INFO): Timed out from 2019-05-30T18:14:22.3Z
2019-05-30T18:15:22.541Z,1559240122.541 [Startup:StartupSatComms:A] Stopped
2019-05-30T18:15:22.541Z,1559240122.541 [Startup:StartupSatComms:B] Running Loop=1
2019-05-30T18:15:22.948Z,1559240122.948 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T18:15:23.626Z,1559240123.626 [Micromodem](INFO): Outgoing frame #1: BB13F05C040001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567
2019-05-30T18:15:23.627Z,1559240123.627 [Micromodem](INFO): Outgoing frame #2: 266CC0E6F1A517638CB0C0B8BE35994FEABFBDB92FCD92215011E57437C4F5E5F0EC9E14B85A146956ECB75E9F5714D7DBF47C37AF9BB003AE5DC2F70FE304F6
2019-05-30T18:15:23.627Z,1559240123.627 [Micromodem](INFO): Outgoing frame #3: B3E74F2048B14D68F5DE6A13DF4FA06075CAA87D1CF047737B5CBD634C385F34DE5D20CA7A5F635220D90674665503574914BE7D204248BB6588F9B157F197A5
2019-05-30T18:15:23.628Z,1559240123.628 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53
2019-05-30T18:15:24.157Z,1559240124.157 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51
2019-05-30T18:15:24.561Z,1559240124.561 [Micromodem](INFO): Nmea in: $CADRQ,181523,1,9,0,64,1*42
2019-05-30T18:15:24.565Z,1559240124.565 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,BB13F05C040001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*0B
2019-05-30T18:15:24.961Z,1559240124.961 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-05-30T18:15:25.365Z,1559240125.365 [Micromodem](INFO): Nmea in: $CADRQ,181524,1,9,0,64,2*46
2019-05-30T18:15:25.366Z,1559240125.366 [Micromodem](INFO): Received CADRQ with unexpected frame#: 2
2019-05-30T18:15:25.366Z,1559240125.366 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,266CC0E6F1A517638CB0C0B8BE35994FEABFBDB92FCD92215011E57437C4F5E5F0EC9E14B85A146956ECB75E9F5714D7DBF47C37AF9BB003AE5DC2F70FE304F6*7D
2019-05-30T18:15:25.773Z,1559240125.773 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-05-30T18:15:26.173Z,1559240126.173 [Micromodem](INFO): Nmea in: $CADRQ,181525,1,9,0,64,3*46
2019-05-30T18:15:26.174Z,1559240126.174 [Micromodem](INFO): Received CADRQ with unexpected frame#: 3
2019-05-30T18:15:26.174Z,1559240126.174 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,B3E74F2048B14D68F5DE6A13DF4FA06075CAA87D1CF047737B5CBD634C385F34DE5D20CA7A5F635220D90674665503574914BE7D204248BB6588F9B157F197A5*7A
2019-05-30T18:15:26.577Z,1559240126.577 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-05-30T18:15:26.985Z,1559240126.985 [Micromodem](INFO): Nmea in: $CATXP,192*48
2019-05-30T18:15:30.634Z,1559240130.634 [Micromodem](INFO): Nmea in: $CATXF,192*5E
2019-05-30T18:15:31.022Z,1559240131.022 [Micromodem](INFO): Nmea in: $CAXST,6,20190530,181526.577628,3,0,200,4000,10000,1,1,9,1,3,3,3,192*4C
2019-05-30T18:15:33.850Z,1559240133.850 [Micromodem](INFO): Nmea in: $CAACK,9,1,1,1*43
2019-05-30T18:15:33.850Z,1559240133.850 [Micromodem](INFO): Received CAACK with unexpected frame#: 1
2019-05-30T18:15:34.257Z,1559240134.257 [Micromodem](INFO): Nmea in: $CAACK,9,1,2,1*40
2019-05-30T18:15:34.258Z,1559240134.258 [Micromodem](INFO): Received CAACK with no data to send
2019-05-30T18:15:34.661Z,1559240134.661 [Micromodem](INFO): Nmea in: $CAACK,9,1,3,1*41
2019-05-30T18:15:34.662Z,1559240134.662 [Micromodem](INFO): Received CAACK with no data to send
2019-05-30T18:15:35.075Z,1559240135.075 [Micromodem](INFO): Nmea in: $CACST,6,0,20190530181532.981232,06,15696,41,0338,0150,07,00,00,00,00,1,009,001,0,4,1,0,150,-21.5,5.00,16,-2.00,-01,-0.02,79,10000,4000*6E
2019-05-30T18:15:45.629Z,1559240145.629 [RDI_Pathfinder](ERROR): Failed to parse:
:BE, -19, -27, -10,A
2019-05-30T18:15:48.844Z,1559240148.844 [RDI_Pathfinder](ERROR): Failed to parse:
:SA, +0.00, +0.00, 0.00
2019-05-30T18:15:49.260Z,1559240149.260 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-05-30T18:15:49.260Z,1559240149.260 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-05-30T18:15:49.270Z,1559240149.270 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-05-30T18:15:49.802Z,1559240149.802 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-05-30T18:15:49.802Z,1559240149.802 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-05-30T18:16:22.794Z,1559240182.794 [Startup:StartupSatComms:B](INFO): Timed out from 2019-05-30T18:15:22.5Z
2019-05-30T18:16:22.794Z,1559240182.794 [Startup:StartupSatComms:B] Stopped
2019-05-30T18:16:22.794Z,1559240182.794 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-05-30T18:16:22.795Z,1559240182.795 [Startup:StartupSatComms] Stopped
2019-05-30T18:16:22.795Z,1559240182.795 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-05-30T18:16:22.800Z,1559240182.800 [Startup](INFO): Completed Startup
2019-05-30T18:16:22.800Z,1559240182.800 [MissionManager](INFO): Startup is completed.
2019-05-30T18:16:22.800Z,1559240182.800 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-30T18:16:22.800Z,1559240182.800 [Startup] Stopped
2019-05-30T18:16:22.800Z,1559240182.800 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-05-30T18:16:22.800Z,1559240182.800 [Startup:A.GoToSurface] Stopped
2019-05-30T18:16:22.800Z,1559240182.800 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T18:16:23.172Z,1559240183.172 [MissionManager](IMPORTANT): Started mission Default
2019-05-30T18:16:23.172Z,1559240183.172 [Default] Running Loop=1
2019-05-30T18:16:23.172Z,1559240183.172 [Default](DEBUG): Aggregate::initialize Default
2019-05-30T18:16:23.172Z,1559240183.172 [Default:B.GoToSurface] Running Loop=1
2019-05-30T18:16:23.172Z,1559240183.172 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-05-30T18:16:23.173Z,1559240183.173 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-05-30T18:16:23.173Z,1559240183.173 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-05-30T18:16:23.173Z,1559240183.173 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-05-30T18:16:23.174Z,1559240183.174 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-05-30T18:16:23.174Z,1559240183.174 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-05-30T18:16:23.174Z,1559240183.174 [Default:A.Wait] Running Loop=1
2019-05-30T18:16:23.174Z,1559240183.174 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-05-30T18:16:36.497Z,1559240196.497 [Default:A.Wait](INFO): Done Waiting.
2019-05-30T18:16:36.497Z,1559240196.497 [Default:A.Wait] Stopped
2019-05-30T18:16:36.497Z,1559240196.497 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-05-30T18:16:36.908Z,1559240196.908 [Default:CheckIn] Running Loop=1
2019-05-30T18:16:36.909Z,1559240196.909 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-05-30T18:16:36.909Z,1559240196.909 [Default:CheckIn:Read_GPS] Running Loop=1
2019-05-30T18:16:37.309Z,1559240197.309 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-05-30T18:17:27.002Z,1559240247.002 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2019-05-30T18:17:27.002Z,1559240247.002 [RDI_Pathfinder](ERROR): Failed to parse:
:RA, 0.00, 96.92, 94.42, 0.00
2019-05-30T18:18:29.994Z,1559240309.994 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-05-30T18:18:30.819Z,1559240310.819 [NAL9602](DEBUG): Fix Requested
2019-05-30T18:18:35.667Z,1559240315.667 [NAL9602](DEBUG): Fix Requested
2019-05-30T18:18:36.060Z,1559240316.060 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181829.00,A,3648.17236,N,12147.28452,W,0.719,134.86,300519,,,A*7E
2019-05-30T18:18:36.062Z,1559240316.062 [NAL9602](INFO): GPS fix at 20190530T181829: (36.802873, -121.788075)
2019-05-30T18:18:36.103Z,1559240316.103 [Default:CheckIn:Read_GPS] Stopped
2019-05-30T18:18:36.103Z,1559240316.103 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-05-30T18:18:36.518Z,1559240316.518 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-05-30T18:18:36.873Z,1559240316.873 [Micromodem](ERROR): Buffer fill timout failure.
2019-05-30T18:18:37.541Z,1559240317.541 [Micromodem](INFO): Outgoing frame #1: BB13F05C040001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567
2019-05-30T18:18:37.541Z,1559240317.541 [Micromodem](INFO): Outgoing frame #2: 266CC0E6F1A517638CB0C0B8BE35994FEABFBDB92FCD92215011E57437C4F5E5F0EC9E14B85A146956ECB75E9F5714D7DBF47C37AF9BB003AE5DC2F70FE304F6
2019-05-30T18:18:37.541Z,1559240317.541 [Micromodem](INFO): Outgoing frame #3: B3E74F2048B14D68F5DE6A13DF4FA06075CAA87D1CF047737B5CBD634C385F34DE5D20CA7A5F635220D90674665503574914BE7D204248BB6588F9B157F197A5
2019-05-30T18:18:37.542Z,1559240317.542 [Micromodem](INFO): Nmea out: $CCCYC,0,1,9,1,0,3*53
2019-05-30T18:18:37.687Z,1559240317.687 [Micromodem](INFO): Nmea in: $CACYC,0,1,9,1,0,3*51
2019-05-30T18:18:38.081Z,1559240318.081 [Micromodem](INFO): Nmea in: $CADRQ,181837,1,9,0,64,1*4A
2019-05-30T18:18:38.081Z,1559240318.081 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,BB13F05C040001005D00000400DB0100000000000000151D80030C5669BF3148E2FA22188B6A3173E6960F887FF8A99E669AC91D474B0DB47F940EC581E0D567*0B
2019-05-30T18:18:38.485Z,1559240318.485 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-05-30T18:18:38.889Z,1559240318.889 [Micromodem](INFO): Nmea in: $CADRQ,181838,1,9,0,64,2*46
2019-05-30T18:18:38.889Z,1559240318.889 [Micromodem](INFO): Received CADRQ with unexpected frame#: 2
2019-05-30T18:18:38.890Z,1559240318.890 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,266CC0E6F1A517638CB0C0B8BE35994FEABFBDB92FCD92215011E57437C4F5E5F0EC9E14B85A146956ECB75E9F5714D7DBF47C37AF9BB003AE5DC2F70FE304F6*7D
2019-05-30T18:18:39.297Z,1559240319.297 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-05-30T18:18:39.697Z,1559240319.697 [Micromodem](INFO): Nmea in: $CADRQ,181839,1,9,0,64,3*46
2019-05-30T18:18:39.697Z,1559240319.697 [Micromodem](INFO): Received CADRQ with unexpected frame#: 3
2019-05-30T18:18:39.698Z,1559240319.698 [Micromodem](INFO): Nmea out: $CCTXD,1,9,1,B3E74F2048B14D68F5DE6A13DF4FA06075CAA87D1CF047737B5CBD634C385F34DE5D20CA7A5F635220D90674665503574914BE7D204248BB6588F9B157F197A5*7A
2019-05-30T18:18:40.105Z,1559240320.105 [Micromodem](INFO): Nmea in: $CATXD,1,9,1,64*71
2019-05-30T18:18:40.505Z,1559240320.505 [Micromodem](INFO): Nmea in: $CATXP,192*48
2019-05-30T18:18:44.141Z,1559240324.141 [Micromodem](INFO): Nmea in: $CATXF,192*5E
2019-05-30T18:18:44.550Z,1559240324.550 [Micromodem](INFO): Nmea in: $CAXST,6,20190530,181840.100123,3,0,200,4000,10000,1,1,9,1,3,3,3,192*49
2019-05-30T18:18:47.379Z,1559240327.379 [Micromodem](INFO): Nmea in: $CAACK,9,1,1,1*43
2019-05-30T18:18:47.380Z,1559240327.380 [Micromodem](INFO): Received CAACK with unexpected frame#: 1
2019-05-30T18:18:47.785Z,1559240327.785 [Micromodem](INFO): Nmea in: $CAACK,9,1,2,1*40
2019-05-30T18:18:47.785Z,1559240327.785 [Micromodem](INFO): Received CAACK with no data to send
2019-05-30T18:18:48.181Z,1559240328.181 [Micromodem](INFO): Nmea in: $CAACK,9,1,3,1*41
2019-05-30T18:18:48.181Z,1559240328.181 [Micromodem](INFO): Received CAACK with no data to send
2019-05-30T18:18:48.625Z,1559240328.625 [Micromodem](INFO): Nmea in: $CACST,6,0,20190530181846.504738,06,16138,42,0348,0150,07,00,00,00,00,1,009,001,0,4,1,0,150,-24.5,5.00,16,-2.00,-01,-0.02,79,10000,4000*6F
2019-05-30T18:19:08.782Z,1559240348.782 [NAL9602](INFO): Not Powering down - fast GPS
2019-05-30T18:19:10.539Z,1559240350.539 [CommandLine](IMPORTANT): got command quit
2019-05-30T18:19:11.543Z,1559240351.543 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-30T18:19:11.543Z,1559240351.543 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T18:19:11.544Z,1559240351.544 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:11.683Z,1559240351.683 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-05-30T18:19:11.683Z,1559240351.683 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:11.684Z,1559240351.684 [CommandLine](INFO): Join timeout helper Thread ID is 2285
2019-05-30T18:19:11.684Z,1559240351.684 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-30T18:19:11.684Z,1559240351.684 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:11.685Z,1559240351.685 [NavChartDb](INFO): Join timeout helper Thread ID is 2286
2019-05-30T18:19:11.799Z,1559240351.799 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T18:19:11.799Z,1559240351.799 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:11.803Z,1559240351.803 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-05-30T18:19:11.803Z,1559240351.803 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:11.804Z,1559240351.804 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2287
2019-05-30T18:19:12.079Z,1559240352.079 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T18:19:12.079Z,1559240352.079 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-05-30T18:19:12.080Z,1559240352.080 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.087Z,1559240352.087 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-30T18:19:12.087Z,1559240352.087 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.088Z,1559240352.088 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2288
2019-05-30T18:19:12.199Z,1559240352.199 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T18:19:12.200Z,1559240352.200 [CTD_NeilBrown](INFO): Powering down
2019-05-30T18:19:12.211Z,1559240352.211 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.219Z,1559240352.219 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-30T18:19:12.219Z,1559240352.219 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.219Z,1559240352.219 [Radio_Surface](INFO): Join timeout helper Thread ID is 2289
2019-05-30T18:19:12.487Z,1559240352.487 [Radio_Surface](INFO): Powering down
2019-05-30T18:19:12.488Z,1559240352.488 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T18:19:12.488Z,1559240352.488 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.504Z,1559240352.504 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-30T18:19:12.504Z,1559240352.504 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.505Z,1559240352.505 [logger](INFO): Join timeout helper Thread ID is 2290
2019-05-30T18:19:12.511Z,1559240352.511 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T18:19:12.511Z,1559240352.511 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.513Z,1559240352.513 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-30T18:19:12.513Z,1559240352.513 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.513Z,1559240352.513 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-30T18:19:12.513Z,1559240352.513 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:12.513Z,1559240352.513 [controlThread](INFO): Join timeout helper Thread ID is 2291
2019-05-30T18:19:12.807Z,1559240352.807 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-30T18:19:12.807Z,1559240352.807 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-30T18:19:12.808Z,1559240352.808 [AHRS_M2](INFO): Powering down
2019-05-30T18:19:12.880Z,1559240352.880 [DUSBL_Hydroid](INFO): Powering down
2019-05-30T18:19:12.971Z,1559240352.971 [Micromodem](INFO): Powering down
2019-05-30T18:19:13.067Z,1559240353.067 [NAL9602](INFO): Powering down
2019-05-30T18:19:13.139Z,1559240353.139 [RDI_Pathfinder](INFO): Powering down
2019-05-30T18:19:13.141Z,1559240353.141 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-30T18:19:13.142Z,1559240353.142 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-30T18:19:13.142Z,1559240353.142 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-30T18:19:13.143Z,1559240353.143 [MissionManager](INFO): Uninitializing Mission Default
2019-05-30T18:19:13.143Z,1559240353.143 [Default] Stopped
2019-05-30T18:19:13.143Z,1559240353.143 [Default](DEBUG): Aggregate::uninitialize Default
2019-05-30T18:19:13.143Z,1559240353.143 [Default:B.GoToSurface] Stopped
2019-05-30T18:19:13.143Z,1559240353.143 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-05-30T18:19:13.143Z,1559240353.143 [Default:CheckIn] Stopped
2019-05-30T18:19:13.143Z,1559240353.143 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-05-30T18:19:13.143Z,1559240353.143 [Default:CheckIn:Read_Iridium] Stopped
2019-05-30T18:19:13.146Z,1559240353.146 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-30T18:19:13.146Z,1559240353.146 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-30T18:19:13.146Z,1559240353.146 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-30T18:19:13.146Z,1559240353.146 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-30T18:19:13.147Z,1559240353.147 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-30T18:19:13.147Z,1559240353.147 [BuoyancyServo](INFO): Powering down
2019-05-30T18:19:13.159Z,1559240353.159 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-30T18:19:13.159Z,1559240353.159 [ElevatorServo](INFO): Powering down
2019-05-30T18:19:13.160Z,1559240353.160 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-30T18:19:13.160Z,1559240353.160 [MassServo](INFO): Powering down
2019-05-30T18:19:13.161Z,1559240353.161 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-30T18:19:13.161Z,1559240353.161 [RudderServo](INFO): Powering down
2019-05-30T18:19:13.162Z,1559240353.162 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-30T18:19:13.162Z,1559240353.162 [ThrusterServo](INFO): Powering down
2019-05-30T18:19:13.163Z,1559240353.163 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-30T18:19:13.163Z,1559240353.163 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-30T18:19:13.163Z,1559240353.163 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-30T18:19:13.164Z,1559240353.164 [CBIT](DEBUG): Powering off loads.
2019-05-30T18:19:13.175Z,1559240353.175 [CBIT](DEBUG): Disabling WDT.
2019-05-30T18:19:13.187Z,1559240353.187 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-30T18:19:13.188Z,1559240353.188 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:13.228Z,1559240353.228 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:13.270Z,1559240353.270 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:13.272Z,1559240353.272 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:13.328Z,1559240353.328 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-30T18:19:13.397Z,1559240353.397 [logger ThreadHandler](INFO): Thread cancelled.