2020-01-17T17:18:14.673Z,1579281494.673 [Supervisor](DEBUG): Initializing supervisor. 2020-01-17T17:18:14.677Z,1579281494.677 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-01-17T17:18:14.677Z,1579281494.677 [SyncHandler](INFO): Protected caller Thread ID is 4362 2020-01-17T17:18:14.678Z,1579281494.678 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-01-17T17:18:14.679Z,1579281494.679 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-01-17T17:18:14.679Z,1579281494.679 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4363 2020-01-17T17:18:14.683Z,1579281494.683 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-01-17T17:18:14.695Z,1579281494.695 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-01-17T17:18:14.696Z,1579281494.696 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-01-17T17:18:14.696Z,1579281494.696 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4364 2020-01-17T17:18:14.697Z,1579281494.697 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-01-17T17:18:14.698Z,1579281494.698 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-01-17T17:18:14.698Z,1579281494.698 [logger ThreadHandler](INFO): Protected caller Thread ID is 4365 2020-01-17T17:18:14.700Z,1579281494.700 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-01-17T17:18:14.701Z,1579281494.701 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-01-17T17:18:14.702Z,1579281494.702 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-01-17T17:18:15.129Z,1579281495.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-01-17T17:18:15.130Z,1579281495.130 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-01-17T17:18:15.227Z,1579281495.227 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-01-17T17:18:15.228Z,1579281495.228 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-01-17T17:18:15.546Z,1579281495.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-01-17T17:18:15.546Z,1579281495.546 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-01-17T17:18:15.736Z,1579281495.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-01-17T17:18:15.737Z,1579281495.737 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-01-17T17:18:15.925Z,1579281495.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-01-17T17:18:15.926Z,1579281495.926 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-01-17T17:18:16.362Z,1579281496.362 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-01-17T17:18:16.363Z,1579281496.363 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-01-17T17:18:16.569Z,1579281496.569 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-01-17T17:18:16.570Z,1579281496.570 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-01-17T17:18:16.712Z,1579281496.712 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-01-17T17:18:16.712Z,1579281496.712 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-01-17T17:18:16.900Z,1579281496.900 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-01-17T17:18:16.901Z,1579281496.901 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-01-17T17:18:16.997Z,1579281496.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-01-17T17:18:16.998Z,1579281496.998 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-01-17T17:18:17.291Z,1579281497.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-01-17T17:18:17.292Z,1579281497.292 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-01-17T17:18:17.373Z,1579281497.373 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-01-17T17:18:17.475Z,1579281497.475 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-01-17T17:18:17.475Z,1579281497.475 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-01-17T17:18:18.099Z,1579281498.099 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-01-17T17:18:18.099Z,1579281498.099 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-01-17T17:18:18.500Z,1579281498.500 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-01-17T17:18:18.502Z,1579281498.502 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2020-01-17T17:18:18.503Z,1579281498.503 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2020-01-17T17:18:18.712Z,1579281498.712 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2020-01-17T17:18:18.812Z,1579281498.812 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2020-01-17T17:18:18.912Z,1579281498.912 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2020-01-17T17:18:19.137Z,1579281499.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-01-17T17:18:19.137Z,1579281499.137 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2020-01-17T17:18:19.222Z,1579281499.222 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2020-01-17T17:18:19.316Z,1579281499.316 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2020-01-17T17:18:19.415Z,1579281499.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2020-01-17T17:18:19.498Z,1579281499.498 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2020-01-17T17:18:19.606Z,1579281499.606 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/workSite.cfg 2020-01-17T17:18:19.698Z,1579281499.698 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2020-01-17T17:18:19.880Z,1579281499.880 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2020-01-17T17:18:20.010Z,1579281500.010 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/ 2020-01-17T17:18:20.010Z,1579281500.010 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-01-17T17:18:20.017Z,1579281500.017 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-01-17T17:18:20.324Z,1579281500.324 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-01-17T17:18:20.329Z,1579281500.329 [AHRS_M2](INFO): created writer for : platform_orientation 2020-01-17T17:18:20.332Z,1579281500.332 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-01-17T17:18:20.336Z,1579281500.336 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-01-17T17:18:20.337Z,1579281500.337 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-01-17T17:18:20.342Z,1579281500.342 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-01-17T17:18:20.342Z,1579281500.342 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-01-17T17:18:20.347Z,1579281500.347 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-01-17T17:18:20.414Z,1579281500.414 [AHRS_M2] Loaded 2020-01-17T17:18:20.414Z,1579281500.414 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-01-17T17:18:20.492Z,1579281500.492 [DataOverHttps] Loaded 2020-01-17T17:18:20.492Z,1579281500.492 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-01-17T17:18:20.493Z,1579281500.493 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407684E0 2020-01-17T17:18:20.494Z,1579281500.494 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4447 2020-01-17T17:18:20.516Z,1579281500.516 [DDM] Loaded 2020-01-17T17:18:20.516Z,1579281500.516 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread. 2020-01-17T17:18:20.528Z,1579281500.528 [Depth_Keller] Loaded 2020-01-17T17:18:20.529Z,1579281500.529 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-01-17T17:18:20.533Z,1579281500.533 [DropWeight] Loaded 2020-01-17T17:18:20.533Z,1579281500.533 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-01-17T17:18:20.591Z,1579281500.591 [DUSBL_Hydroid] Loaded 2020-01-17T17:18:20.591Z,1579281500.591 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread. 2020-01-17T17:18:20.635Z,1579281500.635 [Micromodem] Loaded 2020-01-17T17:18:20.635Z,1579281500.635 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread. 2020-01-17T17:18:20.726Z,1579281500.726 [NAL9602] Loaded 2020-01-17T17:18:20.726Z,1579281500.726 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-01-17T17:18:20.760Z,1579281500.760 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now 2020-01-17T17:18:20.761Z,1579281500.761 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now 2020-01-17T17:18:20.761Z,1579281500.761 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now 2020-01-17T17:18:20.762Z,1579281500.762 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full 2020-01-17T17:18:20.762Z,1579281500.762 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now 2020-01-17T17:18:20.763Z,1579281500.763 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now 2020-01-17T17:18:20.763Z,1579281500.763 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now 2020-01-17T17:18:20.764Z,1579281500.764 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full 2020-01-17T17:18:20.764Z,1579281500.764 [Onboard] Loaded 2020-01-17T17:18:20.764Z,1579281500.764 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2020-01-17T17:18:20.770Z,1579281500.770 [PowerOnly] Loaded 2020-01-17T17:18:20.770Z,1579281500.770 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2020-01-17T17:18:20.776Z,1579281500.776 [Radio_Surface] Loaded 2020-01-17T17:18:20.776Z,1579281500.776 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-01-17T17:18:20.777Z,1579281500.777 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407984E0 2020-01-17T17:18:20.778Z,1579281500.778 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4448 2020-01-17T17:18:20.818Z,1579281500.818 [RDI_Pathfinder] Loaded 2020-01-17T17:18:20.818Z,1579281500.818 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2020-01-17T17:18:22.631Z,1579281502.631 [BPC1] Loaded 2020-01-17T17:18:22.631Z,1579281502.631 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-01-17T17:18:22.631Z,1579281502.631 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-01-17T17:18:22.632Z,1579281502.632 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-01-17T17:18:22.645Z,1579281502.645 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-01-17T17:18:22.646Z,1579281502.646 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-01-17T17:18:22.745Z,1579281502.745 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-01-17T17:18:22.745Z,1579281502.745 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-01-17T17:18:22.764Z,1579281502.764 [NavChart] Loaded 2020-01-17T17:18:22.765Z,1579281502.765 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-01-17T17:18:22.768Z,1579281502.768 [UniversalFixResidualReporter] Loaded 2020-01-17T17:18:22.769Z,1579281502.769 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-01-17T17:18:22.769Z,1579281502.769 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-01-17T17:18:22.770Z,1579281502.770 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-01-17T17:18:22.874Z,1579281502.874 [BuoyancyServo] Loaded 2020-01-17T17:18:22.874Z,1579281502.874 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-01-17T17:18:22.889Z,1579281502.889 [ElevatorServo] Loaded 2020-01-17T17:18:22.889Z,1579281502.889 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-01-17T17:18:22.903Z,1579281502.903 [MassServo] Loaded 2020-01-17T17:18:22.903Z,1579281502.903 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-01-17T17:18:22.917Z,1579281502.917 [RudderServo] Loaded 2020-01-17T17:18:22.918Z,1579281502.918 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-01-17T17:18:22.931Z,1579281502.931 [ThrusterServo] Loaded 2020-01-17T17:18:22.931Z,1579281502.931 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-01-17T17:18:22.932Z,1579281502.932 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-01-17T17:18:22.933Z,1579281502.933 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-01-17T17:18:23.184Z,1579281503.184 [CTD_NeilBrown] Loaded 2020-01-17T17:18:23.184Z,1579281503.184 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2020-01-17T17:18:23.185Z,1579281503.185 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408EC4E0 2020-01-17T17:18:23.185Z,1579281503.185 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4449 2020-01-17T17:18:23.199Z,1579281503.199 [PAR_Licor] Loaded 2020-01-17T17:18:23.199Z,1579281503.199 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2020-01-17T17:18:23.240Z,1579281503.240 [WetLabsSeaOWL_UV_A] Loaded 2020-01-17T17:18:23.240Z,1579281503.240 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2020-01-17T17:18:23.241Z,1579281503.241 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4091C4E0 2020-01-17T17:18:23.242Z,1579281503.242 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 4450 2020-01-17T17:18:23.242Z,1579281503.242 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-01-17T17:18:23.243Z,1579281503.243 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-01-17T17:18:23.560Z,1579281503.560 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-01-17T17:18:23.561Z,1579281503.561 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-01-17T17:18:23.600Z,1579281503.600 [DepthRateCalculator] Loaded 2020-01-17T17:18:23.601Z,1579281503.601 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-01-17T17:18:23.606Z,1579281503.606 [PitchRateCalculator] Loaded 2020-01-17T17:18:23.606Z,1579281503.606 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-01-17T17:18:23.618Z,1579281503.618 [SpeedCalculator] Loaded 2020-01-17T17:18:23.618Z,1579281503.618 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-01-17T17:18:23.638Z,1579281503.638 [TempGradientCalculator] Loaded 2020-01-17T17:18:23.638Z,1579281503.638 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-01-17T17:18:23.643Z,1579281503.643 [YawRateCalculator] Loaded 2020-01-17T17:18:23.643Z,1579281503.643 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-01-17T17:18:23.682Z,1579281503.682 [ElevatorOffsetCalculator] Loaded 2020-01-17T17:18:23.682Z,1579281503.682 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-01-17T17:18:23.683Z,1579281503.683 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-01-17T17:18:23.683Z,1579281503.683 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-01-17T17:18:23.811Z,1579281503.811 [SBIT](DEBUG): Construct Startup Built In Test. 2020-01-17T17:18:23.831Z,1579281503.831 [SBIT] Loaded 2020-01-17T17:18:23.831Z,1579281503.831 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-01-17T17:18:23.832Z,1579281503.832 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-01-17T17:18:23.844Z,1579281503.844 [IBIT] Loaded 2020-01-17T17:18:23.844Z,1579281503.844 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-01-17T17:18:23.847Z,1579281503.847 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-01-17T17:18:23.978Z,1579281503.978 [CBIT] Loaded 2020-01-17T17:18:23.978Z,1579281503.978 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-01-17T17:18:23.978Z,1579281503.978 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-01-17T17:18:23.979Z,1579281503.979 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-01-17T17:18:24.061Z,1579281504.061 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-01-17T17:18:24.062Z,1579281504.062 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-01-17T17:18:24.156Z,1579281504.156 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-01-17T17:18:24.156Z,1579281504.156 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-01-17T17:18:24.203Z,1579281504.203 [VerticalControl](DEBUG): Construct VerticalControl. 2020-01-17T17:18:24.282Z,1579281504.282 [VerticalControl] Loaded 2020-01-17T17:18:24.283Z,1579281504.283 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-01-17T17:18:24.283Z,1579281504.283 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-01-17T17:18:24.348Z,1579281504.348 [HorizontalControl] Loaded 2020-01-17T17:18:24.348Z,1579281504.348 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-01-17T17:18:24.349Z,1579281504.349 [SpeedControl](DEBUG): Construct SpeedControl. 2020-01-17T17:18:24.350Z,1579281504.350 [SpeedControl] Loaded 2020-01-17T17:18:24.351Z,1579281504.351 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-01-17T17:18:24.351Z,1579281504.351 [LoopControl](DEBUG): Construct LoopControl. 2020-01-17T17:18:24.352Z,1579281504.352 [LoopControl] Loaded 2020-01-17T17:18:24.352Z,1579281504.352 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-01-17T17:18:24.352Z,1579281504.352 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-01-17T17:18:24.353Z,1579281504.353 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-01-17T17:18:24.384Z,1579281504.384 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-01-17T17:18:24.388Z,1579281504.388 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-01-17T17:18:24.389Z,1579281504.389 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-01-17T17:18:24.395Z,1579281504.395 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-01-17T17:18:24.396Z,1579281504.396 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0 2020-01-17T17:18:24.397Z,1579281504.397 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4451 2020-01-17T17:18:24.402Z,1579281504.402 [Supervisor](INFO): Main Thread ID is 4177 2020-01-17T17:18:24.402Z,1579281504.402 [Supervisor](DEBUG): Running supervisor. 2020-01-17T17:18:24.402Z,1579281504.402 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4452 2020-01-17T17:18:24.405Z,1579281504.405 [controlThread ThreadHandler](INFO): Handler Thread ID is 4453 2020-01-17T17:18:24.405Z,1579281504.405 [controlThread](DEBUG): Initializing ControlThread 2020-01-17T17:18:24.412Z,1579281504.412 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-01-17T17:18:24.412Z,1579281504.412 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-01-17T17:18:24.417Z,1579281504.417 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-01-17T17:18:24.417Z,1579281504.417 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-01-17T17:18:24.418Z,1579281504.418 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-01-17T17:18:24.418Z,1579281504.418 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-01-17T17:18:24.418Z,1579281504.418 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-01-17T17:18:24.419Z,1579281504.419 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-01-17T17:18:24.419Z,1579281504.419 [SBIT](INFO): Initialize SBIT Component. 2020-01-17T17:18:24.420Z,1579281504.420 [SBIT](IMPORTANT): git: 2019-12-03-58-g2404391 2020-01-17T17:18:24.420Z,1579281504.420 [SBIT](INFO): git hash: 2404391fd42d3cfd696f295822da4e43305eac06 2020-01-17T17:18:24.420Z,1579281504.420 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-01-17T17:18:24.421Z,1579281504.421 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #2 PREEMPT Wed May 15 08:34:03 PDT 2019 2020-01-17T17:18:24.422Z,1579281504.422 [SBIT](INFO): Beginning SBIT in 39.000000 seconds. 2020-01-17T17:18:24.423Z,1579281504.423 [IBIT](INFO): Initialize IBIT Component. 2020-01-17T17:18:24.424Z,1579281504.424 [CBIT](DEBUG): Initialize CBIT Component. 2020-01-17T17:18:24.425Z,1579281504.425 [logger ThreadHandler](INFO): Handler Thread ID is 4454 2020-01-17T17:18:24.437Z,1579281504.437 [CBIT](DEBUG): Initialized mux pins. 2020-01-17T17:18:24.437Z,1579281504.437 [CBIT](DEBUG): Initializing the watchdog timer. 2020-01-17T17:18:24.445Z,1579281504.445 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4455 2020-01-17T17:18:24.446Z,1579281504.446 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-01-17T17:18:24.457Z,1579281504.457 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4456 2020-01-17T17:18:24.461Z,1579281504.461 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-01-17T17:18:24.461Z,1579281504.461 [CBIT](DEBUG): Initializing heartbeat. 2020-01-17T17:18:24.469Z,1579281504.469 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4457 2020-01-17T17:18:24.470Z,1579281504.470 [CTD_NeilBrown](INFO): Powering down 2020-01-17T17:18:24.489Z,1579281504.489 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 4458 2020-01-17T17:18:24.490Z,1579281504.490 [WetLabsSeaOWL_UV_A](INFO): Powering down 2020-01-17T17:18:24.521Z,1579281504.521 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4459 2020-01-17T17:18:24.524Z,1579281504.524 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-01-17T17:18:24.524Z,1579281504.524 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-01-17T17:18:24.525Z,1579281504.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-01-17T17:18:24.525Z,1579281504.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-01-17T17:18:24.525Z,1579281504.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-01-17T17:18:24.525Z,1579281504.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-01-17T17:18:24.525Z,1579281504.525 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-01-17T17:18:24.525Z,1579281504.525 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-01-17T17:18:24.526Z,1579281504.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-01-17T17:18:24.526Z,1579281504.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-01-17T17:18:24.526Z,1579281504.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-01-17T17:18:24.526Z,1579281504.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-01-17T17:18:24.526Z,1579281504.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-01-17T17:18:24.526Z,1579281504.526 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-01-17T17:18:24.527Z,1579281504.527 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-01-17T17:18:24.527Z,1579281504.527 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-01-17T17:18:24.533Z,1579281504.533 [CBIT](DEBUG): Deactivating GF circuits. 2020-01-17T17:18:24.533Z,1579281504.533 [CBIT](DEBUG): Deactivating emergency mode. 2020-01-17T17:18:24.569Z,1579281504.569 [CBIT](DEBUG): Backplane powered. 2020-01-17T17:18:24.569Z,1579281504.569 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-01-17T17:18:24.571Z,1579281504.571 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-01-17T17:18:24.572Z,1579281504.572 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-01-17T17:18:24.572Z,1579281504.572 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-01-17T17:18:24.573Z,1579281504.573 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-01-17T17:18:24.609Z,1579281504.609 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-01-17T17:18:24.635Z,1579281504.635 [MissionManager](DEBUG): 2020-01-17T17:18:24.636Z,1579281504.636 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-01-17T17:18:24.700Z,1579281504.700 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-01-17T17:18:24.713Z,1579281504.713 [Default:A.Wait](DEBUG): Construct Wait. 2020-01-17T17:18:24.715Z,1579281504.715 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-01-17T17:18:24.755Z,1579281504.755 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-01-17T17:18:24.773Z,1579281504.773 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-01-17T17:18:24.779Z,1579281504.779 [Default:E.Execute](DEBUG): Construct Execute. 2020-01-17T17:18:24.791Z,1579281504.791 [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 2020-01-17T17:18:24.796Z,1579281504.796 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2020-01-17T17:18:24.837Z,1579281504.837 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-01-17T17:18:24.861Z,1579281504.861 [Radio_Surface](INFO): Powering up 2020-01-17T17:18:24.879Z,1579281504.879 [DDM](INFO): Powering up 2020-01-17T17:18:24.879Z,1579281504.879 [DDM](DEBUG): Initializing DDM. 2020-01-17T17:18:24.906Z,1579281504.906 [Depth_Keller](ERROR): Pressure reading out of range: 957.962097 decibar 2020-01-17T17:18:24.907Z,1579281504.907 [DUSBL_Hydroid](INFO): Powering up 2020-01-17T17:18:24.907Z,1579281504.907 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid. 2020-01-17T17:18:24.989Z,1579281504.989 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-01-17T17:18:25.006Z,1579281505.006 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-01-17T17:18:25.013Z,1579281505.013 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-01-17T17:18:25.014Z,1579281505.014 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-01-17T17:18:25.021Z,1579281505.021 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-01-17T17:18:25.022Z,1579281505.022 [MassServo](DEBUG): Initializing EZServoServo. 2020-01-17T17:18:25.029Z,1579281505.029 [MassServo](DEBUG): Initializing MassServo. 2020-01-17T17:18:25.030Z,1579281505.030 [RudderServo](DEBUG): Initializing EZServoServo. 2020-01-17T17:18:25.041Z,1579281505.041 [RudderServo](DEBUG): Initializing RudderServo. 2020-01-17T17:18:25.042Z,1579281505.042 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-01-17T17:18:25.049Z,1579281505.049 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-01-17T17:18:25.224Z,1579281505.224 [Micromodem](INFO): Powering up 2020-01-17T17:18:25.225Z,1579281505.225 [Micromodem](DEBUG): Initializing Micromodem. 2020-01-17T17:18:25.985Z,1579281505.985 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-01-17T17:18:25.985Z,1579281505.985 [RudderServo](FAULT): Rudder failed to initialize 2020-01-17T17:18:25.985Z,1579281505.985 [RudderServo] Communications Fault, FailCount= 1 2020-01-17T17:18:25.985Z,1579281505.985 [RudderServo](ERROR): Communications Fault 2020-01-17T17:18:26.096Z,1579281506.096 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-01-17T17:18:26.314Z,1579281506.314 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-01-17T17:18:26.314Z,1579281506.314 [RudderServo](INFO): Powering down 2020-01-17T17:18:26.959Z,1579281506.959 [RudderServo](DEBUG): Initializing EZServoServo. 2020-01-17T17:18:27.078Z,1579281507.078 [RudderServo](DEBUG): Initializing RudderServo. 2020-01-17T17:18:27.082Z,1579281507.082 [CBIT](INFO): Clearing failed state for component RudderServo 2020-01-17T17:18:27.082Z,1579281507.082 [RudderServo] No Fault, FailCount= 1 2020-01-17T17:18:30.184Z,1579281510.184 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33 2020-01-17T17:18:30.588Z,1579281510.588 [Micromodem](INFO): Nmea in: $CARE,17831IIT,2.0.32731*4E 2020-01-17T17:18:30.588Z,1579281510.588 [Micromodem](ERROR): Response from modem failed NMEA checksum: $CARE,17831IIT,2.0.32731*4E expected 4B 2020-01-17T17:18:30.588Z,1579281510.588 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33 2020-01-17T17:18:32.240Z,1579281512.240 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T17:18:31.190675Z,RTC,RTC*56 2020-01-17T17:18:32.240Z,1579281512.240 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2020-01-17T17:18:31.190675Z,RTC,RTC*56 2020-01-17T17:18:32.647Z,1579281512.647 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31 2020-01-17T17:18:32.647Z,1579281512.647 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31 2020-01-17T17:18:33.048Z,1579281513.048 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31 2020-01-17T17:18:33.048Z,1579281513.048 [Micromodem](ERROR): CFG response from modem unexpected: $CACFG,ALL,0*31 2020-01-17T17:18:33.476Z,1579281513.476 [Micromodem](INFO): Nmea in: $CACFG,SRC,1*33 2020-01-17T17:18:33.476Z,1579281513.476 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64 2020-01-17T17:18:33.831Z,1579281513.831 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66 2020-01-17T17:18:33.832Z,1579281513.832 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F 2020-01-17T17:18:34.251Z,1579281514.251 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D 2020-01-17T17:18:34.251Z,1579281514.251 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E 2020-01-17T17:18:34.635Z,1579281514.635 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C 2020-01-17T17:18:34.635Z,1579281514.635 [Micromodem](INFO): Nmea out: $CCCFG,FC0,10000*46 2020-01-17T17:18:35.038Z,1579281515.038 [Micromodem](INFO): Nmea in: $CACFG,FC0,10000*44 2020-01-17T17:18:35.039Z,1579281515.039 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63 2020-01-17T17:18:35.444Z,1579281515.444 [DDM](INFO): Dynamic Docking Module:!C REMUS Capture Rev 1.1 2020-01-17T17:18:35.559Z,1579281515.559 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61 2020-01-17T17:18:35.559Z,1579281515.559 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A 2020-01-17T17:18:35.843Z,1579281515.843 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38 2020-01-17T17:18:35.844Z,1579281515.844 [Micromodem](INFO): Nmea out: $CCCLK,2020,01,17,17,18,36*49 2020-01-17T17:18:36.271Z,1579281516.271 [Micromodem](INFO): Nmea in: $CACLK,2020,1,17,17,18,36*7B 2020-01-17T17:18:36.273Z,1579281516.273 [Micromodem](INFO): Nmea in: $CATMS,0,2020-01-17T17:18:37Z*7A 2020-01-17T17:18:36.274Z,1579281516.274 [Micromodem](INFO): Nmea in: $CATMG,2020-01-17T17:18:37.028229Z,USER_CMD,RTC*1E 2020-01-17T17:18:38.301Z,1579281518.301 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2020-01-17T17:18:42.718Z,1579281522.718 [DUSBL_Hydroid](INFO): DUSBL Version:O 2020-01-17T17:18:50.787Z,1579281530.787 [NAL9602](INFO): Powering up NAL9602 2020-01-17T17:19:01.695Z,1579281541.695 [NAL9602](INFO): NAL9602 initialized 2020-01-17T17:19:04.217Z,1579281544.217 [SBIT](IMPORTANT): Beginning Startup BIT 2020-01-17T17:19:04.226Z,1579281544.226 [CBIT](IMPORTANT): Beginning ground fault scan 2020-01-17T17:19:14.949Z,1579281554.949 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.012366 CHAN A1 (24V): -0.030245 CHAN A2 (12V): -0.007064 CHAN A3 (5V): -0.002024 CHAN B0 (3.3V): 0.000055 CHAN B1 (3.15aV): 0.000045 CHAN B2 (3.15bV): 0.000149 CHAN B3 (GND): 0.002474 OPEN: 0.005083 Full Scale Calc: 4.765 mA, -1.589 mA 2020-01-17T17:19:29.127Z,1579281569.127 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-01-17T17:19:29.127Z,1579281569.127 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,- 2020-01-17T17:19:57.948Z,1579281597.948 [SBIT](IMPORTANT): SBIT PASSED 2020-01-17T17:19:57.948Z,1579281597.948 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-01-17T17:19:57.949Z,1579281597.949 [SBIT](IMPORTANT): DDM.verbosity=3 count; 2020-01-17T17:19:57.949Z,1579281597.949 [SBIT](IMPORTANT): DUSBL_Hydroid.detectionThreshold=30 count; 2020-01-17T17:19:57.949Z,1579281597.949 [SBIT](IMPORTANT): Micromodem.sendExpress=1 bool; 2020-01-17T17:19:57.949Z,1579281597.949 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=105 cubic_centimeter; 2020-01-17T17:19:57.949Z,1579281597.949 [SBIT](IMPORTANT): VerticalControl.massDefault=-5 millimeter; 2020-01-17T17:19:58.403Z,1579281598.403 [MissionManager](IMPORTANT): Started mission Startup 2020-01-17T17:19:58.403Z,1579281598.403 [Startup] Running Loop=1 2020-01-17T17:19:58.403Z,1579281598.403 [Startup](DEBUG): Aggregate::initialize Startup 2020-01-17T17:19:58.404Z,1579281598.404 [Startup:A.GoToSurface] Running Loop=1 2020-01-17T17:19:58.404Z,1579281598.404 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-01-17T17:19:58.404Z,1579281598.404 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-01-17T17:19:58.405Z,1579281598.405 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-01-17T17:19:58.405Z,1579281598.405 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-01-17T17:19:58.406Z,1579281598.406 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-01-17T17:19:58.406Z,1579281598.406 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-01-17T17:19:58.407Z,1579281598.407 [Startup:StartupSatComms] Running Loop=1 2020-01-17T17:19:58.407Z,1579281598.407 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-01-17T17:19:58.407Z,1579281598.407 [Startup:StartupSatComms:A] Running Loop=1 2020-01-17T17:19:58.812Z,1579281598.812 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-01-17T17:20:53.695Z,1579281653.695 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004880 2020-01-17T17:20:58.521Z,1579281658.521 [Startup:StartupSatComms:A](INFO): Timed out from 2020-01-17T17:19:58.4Z 2020-01-17T17:20:58.521Z,1579281658.521 [Startup:StartupSatComms:A] Stopped 2020-01-17T17:20:58.521Z,1579281658.521 [Startup:StartupSatComms:B] Running Loop=1 2020-01-17T17:20:58.923Z,1579281658.923 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-01-17T17:21:08.553Z,1579281668.553 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20200117T171814/Courier0000.lzma 2020-01-17T17:21:10.558Z,1579281670.558 [DataOverHttps](INFO): Moved sent file to Logs/20200117T171814/Courier0000.lzma.bak 2020-01-17T17:21:10.559Z,1579281670.559 [DataOverHttps](INFO): SBD MOMSN=12196637 2020-01-17T17:21:24.778Z,1579281684.778 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-01-17T17:21:24.778Z,1579281684.778 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:21:24.787Z,1579281684.787 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:21:25.218Z,1579281685.218 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:21:25.218Z,1579281685.218 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-01-17T17:21:32.140Z,1579281692.140 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20200117T165701/Express0008.lzma 2020-01-17T17:21:34.149Z,1579281694.149 [DataOverHttps](INFO): Moved sent file to Logs/20200117T165701/Express0008.lzma.bak 2020-01-17T17:21:34.149Z,1579281694.149 [DataOverHttps](INFO): SBD MOMSN=12196640 2020-01-17T17:21:55.349Z,1579281715.349 [DataOverHttps](INFO): Sending 720 bytes from file Logs/20200117T171814/Express0001.lzma 2020-01-17T17:21:57.354Z,1579281717.354 [DataOverHttps](INFO): Moved sent file to Logs/20200117T171814/Express0001.lzma.bak 2020-01-17T17:21:57.354Z,1579281717.354 [DataOverHttps](INFO): SBD MOMSN=12196643 2020-01-17T17:21:58.731Z,1579281718.731 [Startup:StartupSatComms:B](INFO): Timed out from 2020-01-17T17:20:58.5Z 2020-01-17T17:21:58.731Z,1579281718.731 [Startup:StartupSatComms:B] Stopped 2020-01-17T17:21:58.731Z,1579281718.731 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-01-17T17:21:58.731Z,1579281718.731 [Startup:StartupSatComms] Stopped 2020-01-17T17:21:58.731Z,1579281718.731 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-01-17T17:21:58.732Z,1579281718.732 [Startup](INFO): Completed Startup 2020-01-17T17:21:58.732Z,1579281718.732 [MissionManager](INFO): Startup is completed. 2020-01-17T17:21:58.732Z,1579281718.732 [MissionManager](INFO): Uninitializing Mission Startup 2020-01-17T17:21:58.732Z,1579281718.732 [Startup] Stopped 2020-01-17T17:21:58.733Z,1579281718.733 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-01-17T17:21:58.733Z,1579281718.733 [Startup:A.GoToSurface] Stopped 2020-01-17T17:21:58.733Z,1579281718.733 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-01-17T17:21:59.157Z,1579281719.157 [MissionManager](IMPORTANT): Started mission Default 2020-01-17T17:21:59.158Z,1579281719.158 [Default] Running Loop=1 2020-01-17T17:21:59.158Z,1579281719.158 [Default](DEBUG): Aggregate::initialize Default 2020-01-17T17:21:59.158Z,1579281719.158 [Default:B.GoToSurface] Running Loop=1 2020-01-17T17:21:59.158Z,1579281719.158 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-01-17T17:21:59.158Z,1579281719.158 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-01-17T17:21:59.158Z,1579281719.158 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-01-17T17:21:59.159Z,1579281719.159 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-01-17T17:21:59.159Z,1579281719.159 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-01-17T17:21:59.159Z,1579281719.159 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-01-17T17:21:59.159Z,1579281719.159 [Default:A.Wait] Running Loop=1 2020-01-17T17:21:59.160Z,1579281719.160 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-01-17T17:22:12.449Z,1579281732.449 [Default:A.Wait](INFO): Done Waiting. 2020-01-17T17:22:12.449Z,1579281732.449 [Default:A.Wait] Stopped 2020-01-17T17:22:12.449Z,1579281732.449 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-01-17T17:22:12.914Z,1579281732.914 [Default:CheckIn] Running Loop=1 2020-01-17T17:22:12.914Z,1579281732.914 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-17T17:22:12.914Z,1579281732.914 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-17T17:22:13.382Z,1579281733.382 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-01-17T17:22:44.471Z,1579281764.471 [CommandLine](IMPORTANT): got command run ./Missions/Docked.xml 2020-01-17T17:22:44.471Z,1579281764.471 [MissionManager](INFO): Loading Mission: ./Missions/Docked.xml 2020-01-17T17:22:44.537Z,1579281764.537 [MissionManager](INFO): DefineArg Docked.MaxDockRange = 8.000000 m 2020-01-17T17:22:44.540Z,1579281764.540 [MissionManager](INFO): DefineArg Docked.DetachedTimeout = 20.000000 s 2020-01-17T17:22:44.544Z,1579281764.544 [MissionManager](INFO): DefineArg Docked.DockedTimeout = 30.000000 s 2020-01-17T17:22:44.547Z,1579281764.547 [MissionManager](INFO): DefineArg Docked.TransponderCode = 2.000000 count 2020-01-17T17:22:44.551Z,1579281764.551 [MissionManager](INFO): DefineArg Docked.TrackingUpdatePeriod = 60.000000 s 2020-01-17T17:22:44.554Z,1579281764.554 [MissionManager](INFO): DefineArg Docked.NumberOfPings = 1.000000 count 2020-01-17T17:22:44.558Z,1579281764.558 [MissionManager](INFO): DefineArg Docked.DepthDeadband = 1.500000 m 2020-01-17T17:22:44.561Z,1579281764.561 [MissionManager](INFO): DefineArg Docked.PitchLimit = 20.000000 arcdeg 2020-01-17T17:22:44.565Z,1579281764.565 [MissionManager](INFO): DefineArg Docked.MinDepth = 1.000000 m 2020-01-17T17:22:44.569Z,1579281764.569 [MissionManager](INFO): DefineArg Docked.MaxDepth = 215.000000 m 2020-01-17T17:22:44.570Z,1579281764.570 [Docked:A.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2020-01-17T17:22:44.785Z,1579281764.785 [Docked:E.Docked](DEBUG): Construct. 2020-01-17T17:22:44.799Z,1579281764.799 [Docked:G.Wait](DEBUG): Construct Wait. 2020-01-17T17:22:44.825Z,1579281764.825 [MissionManager](DEBUG): Maximum range allowed from the dock. 8 Time duration limit for determining if the vehicle is detached from the dock. 20 Time duration limit for determining if the vehicle is ON the dock. 30 Transponder Address. 2 How long to wait between acoustic queries. 60 Number of pings requested each time. 1 How much vertical drift from the specified depth is allowed while docked. 1.5 Max vehicle pitch (+/-) while on dock. 20 Minimum depth while docked. Maximum depth while docked. Docked satisfied! 5 2020-01-17T17:22:44.827Z,1579281764.827 [CommandLine](IMPORTANT): Running ./Missions/Docked.xml 2020-01-17T17:22:45.199Z,1579281765.199 [Default] Stopped 2020-01-17T17:22:45.199Z,1579281765.199 [Default](DEBUG): Aggregate::uninitialize Default 2020-01-17T17:22:45.199Z,1579281765.199 [Default:B.GoToSurface] Stopped 2020-01-17T17:22:45.199Z,1579281765.199 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-01-17T17:22:45.199Z,1579281765.199 [Default:CheckIn] Stopped 2020-01-17T17:22:45.199Z,1579281765.199 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-17T17:22:45.199Z,1579281765.199 [Default:CheckIn:Read_GPS] Stopped 2020-01-17T17:22:45.199Z,1579281765.199 [MissionManager](IMPORTANT): Started mission Docked 2020-01-17T17:22:45.199Z,1579281765.199 [Docked] Running Loop=1 2020-01-17T17:22:45.200Z,1579281765.200 [Docked](DEBUG): Aggregate::initialize Docked 2020-01-17T17:22:45.200Z,1579281765.200 [Docked:A.DepthEnvelope] Running Loop=1 2020-01-17T17:22:45.200Z,1579281765.200 [Docked:A.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2020-01-17T17:22:45.200Z,1579281765.200 [Docked:B.] Running Loop=1 2020-01-17T17:22:45.200Z,1579281765.200 [Docked:B.](INFO): Initializing TrackAcousticContact. 2020-01-17T17:22:45.200Z,1579281765.200 [Docked:C] Running Loop=1 2020-01-17T17:22:45.200Z,1579281765.200 [Docked:D] Running Loop=1 2020-01-17T17:22:45.200Z,1579281765.200 [Docked:E.Docked] Running Loop=1 2020-01-17T17:22:45.217Z,1579281765.217 [Docked:E.Docked](DEBUG): Initialize. 2020-01-17T17:22:45.218Z,1579281765.218 [Docked:E.Docked](INFO): Depth unspecified. Maintaining workSite beacon depth of 6.000000 m. 2020-01-17T17:22:45.219Z,1579281765.219 [Docked:D] Running Loop=1 2020-01-17T17:22:45.220Z,1579281765.220 [Docked:C] Running Loop=1 2020-01-17T17:22:45.225Z,1579281765.225 [Docked:B.] Running Loop=1 2020-01-17T17:22:45.226Z,1579281765.226 [Docked:A.DepthEnvelope] Running Loop=1 2020-01-17T17:23:08.723Z,1579281788.723 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 6.000000 meter 2020-01-17T17:23:08.725Z,1579281788.725 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2020-01-17T17:23:08.755Z,1579281788.755 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2020-01-17T17:23:41.918Z,1579281821.918 [CommandLine](IMPORTANT): got command set TrackAcousticContact.range_to_contact 4.000000 meter 2020-01-17T17:23:42.303Z,1579281822.303 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:42.699Z,1579281822.699 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:43.126Z,1579281823.126 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:43.498Z,1579281823.498 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:43.890Z,1579281823.890 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:44.313Z,1579281824.313 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:44.693Z,1579281824.693 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:45.104Z,1579281825.104 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:45.518Z,1579281825.518 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:45.519Z,1579281825.519 [Docked:B.](INFO): *** querying acoustic contact *** 2020-01-17T17:23:45.927Z,1579281825.927 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:46.287Z,1579281826.287 [Micromodem](INFO): Nmea out: $CCPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*77 2020-01-17T17:23:46.392Z,1579281826.392 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:46.867Z,1579281826.867 [Micromodem](INFO): Nmea in: $SNPGT,1,10000,40,0,1000,24000,28,4A1C0370,6C8F7D30,2107E320,37BCD1E0,4000,4000,0*6A 2020-01-17T17:23:46.967Z,1579281826.967 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:47.324Z,1579281827.324 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:47.675Z,1579281827.675 [Micromodem](INFO): Nmea in: $SNTTA,,,,,172347.39*50 2020-01-17T17:23:47.875Z,1579281827.875 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:48.201Z,1579281828.201 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:48.543Z,1579281828.543 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:48.951Z,1579281828.951 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:49.340Z,1579281829.340 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:49.695Z,1579281829.695 [DUSBL_Hydroid](ERROR): No response from remote modem. 2020-01-17T17:23:49.747Z,1579281829.747 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:50.175Z,1579281830.175 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:50.550Z,1579281830.550 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:50.958Z,1579281830.958 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:51.355Z,1579281831.355 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:51.750Z,1579281831.750 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:52.199Z,1579281832.199 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:52.574Z,1579281832.574 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:52.983Z,1579281832.983 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:53.404Z,1579281833.404 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:53.771Z,1579281833.771 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:54.213Z,1579281834.213 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:54.579Z,1579281834.579 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:54.999Z,1579281834.999 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:55.413Z,1579281835.413 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:55.796Z,1579281835.796 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:56.202Z,1579281836.202 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:56.630Z,1579281836.630 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:57.011Z,1579281837.011 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:57.455Z,1579281837.455 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:57.831Z,1579281837.831 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:58.239Z,1579281838.239 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:58.635Z,1579281838.635 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:59.031Z,1579281839.031 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:59.449Z,1579281839.449 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:23:59.827Z,1579281839.827 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:00.246Z,1579281840.246 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:00.641Z,1579281840.641 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:01.129Z,1579281841.129 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:01.547Z,1579281841.547 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:01.894Z,1579281841.894 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:02.314Z,1579281842.314 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:02.687Z,1579281842.687 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:03.095Z,1579281843.095 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:03.506Z,1579281843.506 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:03.507Z,1579281843.507 [Docked:E.Docked](INFO): Detected possible state switch to DETACHED. 2020-01-17T17:24:03.894Z,1579281843.894 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:04.282Z,1579281844.282 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:04.675Z,1579281844.675 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:05.060Z,1579281845.060 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-01-17T17:24:05.087Z,1579281845.087 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:05.498Z,1579281845.498 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:05.907Z,1579281845.907 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:06.290Z,1579281846.290 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:06.707Z,1579281846.707 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:07.104Z,1579281847.104 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:07.536Z,1579281847.536 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:07.928Z,1579281847.928 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:08.353Z,1579281848.353 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:08.722Z,1579281848.722 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:09.140Z,1579281849.140 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:09.523Z,1579281849.523 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:09.931Z,1579281849.931 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:10.355Z,1579281850.355 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:10.755Z,1579281850.755 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:11.179Z,1579281851.179 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:11.546Z,1579281851.546 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:11.959Z,1579281851.959 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:12.363Z,1579281852.363 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:12.772Z,1579281852.772 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:13.193Z,1579281853.193 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:13.579Z,1579281853.579 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:13.983Z,1579281853.983 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:14.399Z,1579281854.399 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:14.838Z,1579281854.838 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:15.300Z,1579281855.300 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:15.619Z,1579281855.619 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:16.019Z,1579281856.019 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:16.434Z,1579281856.434 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:16.814Z,1579281856.814 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:17.219Z,1579281857.219 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:17.620Z,1579281857.620 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:18.009Z,1579281858.009 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:18.427Z,1579281858.427 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:18.816Z,1579281858.816 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:19.247Z,1579281859.247 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:19.631Z,1579281859.631 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:20.132Z,1579281860.132 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:20.506Z,1579281860.506 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:20.923Z,1579281860.923 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:21.328Z,1579281861.328 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:21.732Z,1579281861.732 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:22.147Z,1579281862.147 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:22.539Z,1579281862.539 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:22.965Z,1579281862.965 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:23.367Z,1579281863.367 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:23.746Z,1579281863.746 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:23.746Z,1579281863.746 [Docked:E.Docked](IMPORTANT): VEHICLE DETACHED FROM DOCK. 2020-01-17T17:24:23.748Z,1579281863.748 [Docked:F] Running Loop=1 2020-01-17T17:24:24.184Z,1579281864.184 [Docked:F](INFO): Docked satisfied! 2020-01-17T17:24:24.184Z,1579281864.184 [Docked:F] Stopped 2020-01-17T17:24:24.184Z,1579281864.184 [Docked:G.Wait] Running Loop=1 2020-01-17T17:24:24.184Z,1579281864.184 [Docked:G.Wait](DEBUG): Initialize Wait Component. 2020-01-17T17:24:24.189Z,1579281864.189 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:24.585Z,1579281864.585 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:24.968Z,1579281864.968 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:25.403Z,1579281865.403 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:25.799Z,1579281865.799 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-01-17T17:24:25.799Z,1579281865.799 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:24:25.805Z,1579281865.805 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:26.269Z,1579281866.269 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:24:26.362Z,1579281866.362 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:26.436Z,1579281866.436 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:24:26.436Z,1579281866.436 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-01-17T17:24:26.754Z,1579281866.754 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:27.142Z,1579281867.142 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:27.588Z,1579281867.588 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:27.958Z,1579281867.958 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:28.253Z,1579281868.253 [CommandLine](IMPORTANT): got command stop 2020-01-17T17:24:28.254Z,1579281868.254 [CommandLine](IMPORTANT): Scheduling is paused 2020-01-17T17:24:28.254Z,1579281868.254 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop 2020-01-17T17:24:28.450Z,1579281868.450 [Docked:E.Docked](INFO): got range 4.000000 2020-01-17T17:24:28.451Z,1579281868.451 [MissionManager](INFO): MissionManager is completed. 2020-01-17T17:24:28.451Z,1579281868.451 [MissionManager](INFO): Uninitializing Mission Docked 2020-01-17T17:24:28.451Z,1579281868.451 [Docked] Stopped 2020-01-17T17:24:28.452Z,1579281868.452 [Docked](DEBUG): Aggregate::uninitialize Docked 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:A.DepthEnvelope] Stopped 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:A.DepthEnvelope](DEBUG): Uninitialize. 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:B.] Stopped 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:C] Stopped 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:D] Stopped 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:E.Docked] Stopped 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:G.Wait] Stopped 2020-01-17T17:24:28.452Z,1579281868.452 [Docked:G.Wait](DEBUG): Uninitialize Wait Component. 2020-01-17T17:24:28.813Z,1579281868.813 [MissionManager](IMPORTANT): Started mission Default 2020-01-17T17:24:28.813Z,1579281868.813 [Default] Running Loop=1 2020-01-17T17:24:28.813Z,1579281868.813 [Default](DEBUG): Aggregate::initialize Default 2020-01-17T17:24:28.813Z,1579281868.813 [Default:B.GoToSurface] Running Loop=1 2020-01-17T17:24:28.813Z,1579281868.813 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-01-17T17:24:28.814Z,1579281868.814 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-01-17T17:24:28.814Z,1579281868.814 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-01-17T17:24:28.814Z,1579281868.814 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-01-17T17:24:28.814Z,1579281868.814 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-01-17T17:24:28.815Z,1579281868.815 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-01-17T17:24:28.815Z,1579281868.815 [Default:A.Wait] Running Loop=1 2020-01-17T17:24:28.815Z,1579281868.815 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-01-17T17:24:29.223Z,1579281869.223 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position -22.00 mm (1 active estimators). 2020-01-17T17:24:40.456Z,1579281880.456 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, 0.00 2020-01-17T17:24:42.204Z,1579281882.204 [Default:A.Wait](INFO): Done Waiting. 2020-01-17T17:24:42.204Z,1579281882.204 [Default:A.Wait] Stopped 2020-01-17T17:24:42.204Z,1579281882.204 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-01-17T17:25:22.103Z,1579281922.103 [CommandLine](IMPORTANT): got command load ./Missions/Docked.xml 2020-01-17T17:25:22.103Z,1579281922.103 [MissionManager](INFO): Loading Mission: ./Missions/Docked.xml 2020-01-17T17:25:22.134Z,1579281922.134 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-01-17T17:25:22.134Z,1579281922.134 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3768,V 2020-01-17T17:25:22.204Z,1579281922.204 [MissionManager](INFO): DefineArg Docked.MaxDockRange = 8.000000 m 2020-01-17T17:25:22.206Z,1579281922.206 [MissionManager](INFO): DefineArg Docked.DetachedTimeout = 20.000000 s 2020-01-17T17:25:22.210Z,1579281922.210 [MissionManager](INFO): DefineArg Docked.DockedTimeout = 30.000000 s 2020-01-17T17:25:22.231Z,1579281922.231 [MissionManager](INFO): DefineArg Docked.TransponderCode = 2.000000 count 2020-01-17T17:25:22.241Z,1579281922.241 [MissionManager](INFO): DefineArg Docked.TrackingUpdatePeriod = 60.000000 s 2020-01-17T17:25:22.243Z,1579281922.243 [MissionManager](INFO): DefineArg Docked.NumberOfPings = 1.000000 count 2020-01-17T17:25:22.259Z,1579281922.259 [MissionManager](INFO): DefineArg Docked.DepthDeadband = 1.500000 m 2020-01-17T17:25:22.273Z,1579281922.273 [MissionManager](INFO): DefineArg Docked.PitchLimit = 20.000000 arcdeg 2020-01-17T17:25:22.276Z,1579281922.276 [MissionManager](INFO): DefineArg Docked.MinDepth = 1.000000 m 2020-01-17T17:25:22.278Z,1579281922.278 [MissionManager](INFO): DefineArg Docked.MaxDepth = 215.000000 m 2020-01-17T17:25:22.279Z,1579281922.279 [Docked:A.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2020-01-17T17:25:22.327Z,1579281922.327 [Docked:E.Docked](DEBUG): Construct. 2020-01-17T17:25:22.342Z,1579281922.342 [Docked:G.Wait](DEBUG): Construct Wait. 2020-01-17T17:25:22.352Z,1579281922.352 [MissionManager](DEBUG): Maximum range allowed from the dock. 8 Time duration limit for determining if the vehicle is detached from the dock. 20 Time duration limit for determining if the vehicle is ON the dock. 30 Transponder Address. 2 How long to wait between acoustic queries. 60 Number of pings requested each time. 1 How much vertical drift from the specified depth is allowed while docked. 1.5 Max vehicle pitch (+/-) while on dock. 20 Minimum depth while docked. Maximum depth while docked. Docked satisfied! 5 2020-01-17T17:25:22.352Z,1579281922.352 [CommandLine](IMPORTANT): Loaded ./Missions/Docked.xml 2020-01-17T17:25:29.114Z,1579281929.114 [Default:B.GoToSurface](ERROR): Pitch down timeout. Pitch: -1.16 2020-01-17T17:25:46.459Z,1579281946.459 [RDI_Pathfinder](ERROR): Failed to parse:76,-32768,V 2020-01-17T17:25:48.113Z,1579281948.113 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-01-17T17:25:48.124Z,1579281948.124 [BPC1](INFO): Received data from all battery sticks. 2020-01-17T17:26:30.476Z,1579281990.476 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2020-01-17T17:26:53.498Z,1579282013.498 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-17T17:26:53.498Z,1579282013.498 [RDI_Pathfinder](ERROR): Failed to parse: :TS,20011710385439,35.0, -0.1, 0.0,10 2020-01-17T17:26:56.730Z,1579282016.730 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00, +0.00, 0.00,496.99 2020-01-17T17:27:10.475Z,1579282030.475 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-17T17:27:10.476Z,1579282030.476 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00, I,-32768,-32768,-32768,-32768,V 2020-01-17T17:27:12.503Z,1579282032.503 [CommandLine](IMPORTANT): got command maintain clear 2020-01-17T17:27:12.574Z,1579282032.574 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,DDM,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2020-01-17T17:27:12.911Z,1579282032.911 [Default:CheckIn] Running Loop=1 2020-01-17T17:27:12.911Z,1579282032.911 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-17T17:27:12.911Z,1579282032.911 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-17T17:27:27.134Z,1579282047.134 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-01-17T17:27:27.134Z,1579282047.134 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:27:27.210Z,1579282047.210 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:27:27.614Z,1579282047.614 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:27:27.614Z,1579282047.614 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-01-17T17:29:04.455Z,1579282144.455 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-17T17:29:04.455Z,1579282144.455 [NAL9602] Data Fault, FailCount= 1 2020-01-17T17:29:04.455Z,1579282144.455 [NAL9602](ERROR): Data Fault 2020-01-17T17:29:04.537Z,1579282144.537 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-17T17:29:04.861Z,1579282144.861 [NAL9602](INFO): Powering down 2020-01-17T17:29:05.705Z,1579282145.705 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-17T17:29:05.705Z,1579282145.705 [NAL9602] No Fault, FailCount= 1 2020-01-17T17:29:35.163Z,1579282175.163 [NAL9602](INFO): Powering up NAL9602 2020-01-17T17:29:46.067Z,1579282186.067 [NAL9602](INFO): NAL9602 initialized 2020-01-17T17:30:28.158Z,1579282228.158 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-01-17T17:30:28.158Z,1579282228.158 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:30:28.168Z,1579282228.168 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:30:28.538Z,1579282228.538 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:30:28.538Z,1579282228.538 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-01-17T17:32:13.180Z,1579282333.180 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-17T17:27:12.9Z 2020-01-17T17:32:13.180Z,1579282333.180 [Default:CheckIn:Read_GPS] Stopped 2020-01-17T17:32:13.180Z,1579282333.180 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-17T17:32:13.575Z,1579282333.575 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-01-17T17:32:24.963Z,1579282344.963 [DataOverHttps](INFO): Sending 1007 bytes from file Logs/20200117T171814/Courier0004.lzma 2020-01-17T17:32:26.967Z,1579282346.967 [DataOverHttps](INFO): Moved sent file to Logs/20200117T171814/Courier0004.lzma.bak 2020-01-17T17:32:26.967Z,1579282346.967 [DataOverHttps](INFO): SBD MOMSN=12196660 2020-01-17T17:32:34.257Z,1579282354.257 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2020-01-17T17:32:34.257Z,1579282354.257 [RDI_Pathfinder] Communications Fault, FailCount= 1 2020-01-17T17:32:34.257Z,1579282354.257 [RDI_Pathfinder](ERROR): Communications Fault 2020-01-17T17:32:34.257Z,1579282354.257 [RDI_Pathfinder](ERROR): Failed to parse: 2020-01-17T17:32:34.333Z,1579282354.333 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2020-01-17T17:32:34.637Z,1579282354.637 [RDI_Pathfinder](INFO): Powering down 2020-01-17T17:32:35.403Z,1579282355.403 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2020-01-17T17:32:35.403Z,1579282355.403 [RDI_Pathfinder] No Fault, FailCount= 1 2020-01-17T17:32:47.089Z,1579282367.089 [DataOverHttps](INFO): Sending 477 bytes from file Logs/20200117T171814/Express0005.lzma 2020-01-17T17:32:48.709Z,1579282368.709 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2020-01-17T17:32:49.094Z,1579282369.094 [DataOverHttps](INFO): Moved sent file to Logs/20200117T171814/Express0005.lzma.bak 2020-01-17T17:32:49.094Z,1579282369.094 [DataOverHttps](INFO): SBD MOMSN=12196662 2020-01-17T17:32:50.327Z,1579282370.327 [Default:CheckIn:Read_Iridium] Stopped 2020-01-17T17:32:50.327Z,1579282370.327 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-17T17:32:50.327Z,1579282370.327 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-17T17:33:16.174Z,1579282396.174 [RDI_Pathfinder](ERROR): only read 0 of 4 data items 2020-01-17T17:33:16.174Z,1579282396.174 [RDI_Pathfinder](ERROR): Failed to parse: :BS-32768,-32768,V 2020-01-17T17:33:24.693Z,1579282404.693 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2020-01-17T17:33:24.694Z,1579282404.694 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, 0 +0.00, +0.00, 0.00, 36.00 2020-01-17T17:33:29.125Z,1579282409.125 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-01-17T17:33:29.125Z,1579282409.125 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:33:29.169Z,1579282409.169 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:33:29.534Z,1579282409.534 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:33:29.534Z,1579282409.534 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-01-17T17:34:39.000Z,1579282479.000 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-17T17:34:39.000Z,1579282479.000 [RDI_Pathfinder](ERROR): Failed to parse: :TS,200117104639 -0.1, 0.0,1448.9, 0 2020-01-17T17:35:00.007Z,1579282500.007 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-17T17:35:00.008Z,1579282500.008 [RDI_Pathfinder](ERROR): Failed to parse: :TS,20011710470091,35.0, -0.1, 0.0,1448.RA, 0.00, 0.00, 0.00, 0.00, 0.00 2020-01-17T17:35:56.167Z,1579282556.167 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-17T17:35:56.167Z,1579282556.167 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-17T17:36:20.001Z,1579282580.001 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-17T17:36:20.001Z,1579282580.001 [RDI_Pathfinder](ERROR): Failed to parse: :TS,20011710482091,35.0, -0.1, 0.0 0 2020-01-17T17:36:30.117Z,1579282590.117 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-01-17T17:36:30.117Z,1579282590.117 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:36:30.135Z,1579282590.135 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:36:30.534Z,1579282590.534 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:36:30.534Z,1579282590.534 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-01-17T17:36:36.981Z,1579282596.981 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2020-01-17T17:36:40.996Z,1579282600.996 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-01-17T17:36:40.996Z,1579282600.996 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,32768,V 2020-01-17T17:37:50.907Z,1579282670.907 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-01-17T17:37:50.907Z,1579282670.907 [Default:CheckIn:C.Wait] Stopped 2020-01-17T17:37:50.907Z,1579282670.907 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-17T17:37:50.907Z,1579282670.907 [Default:CheckIn:D] Running Loop=1 2020-01-17T17:37:51.307Z,1579282671.307 [Default:CheckIn:D] Stopped 2020-01-17T17:37:51.307Z,1579282671.307 [Default:CheckIn:E] Running Loop=1 2020-01-17T17:37:51.712Z,1579282671.712 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.374895 min 2020-01-17T17:37:51.712Z,1579282671.712 [Default:CheckIn:E] Stopped 2020-01-17T17:37:51.712Z,1579282671.712 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-01-17T17:37:51.712Z,1579282671.712 [Default:CheckIn] Stopped 2020-01-17T17:37:51.712Z,1579282671.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-17T17:37:51.712Z,1579282671.712 [Default:CheckIn](INFO): Running loop #2 2020-01-17T17:37:51.712Z,1579282671.712 [Default:CheckIn] Running Loop=2 2020-01-17T17:37:51.713Z,1579282671.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-01-17T17:37:51.713Z,1579282671.713 [Default:CheckIn:Read_GPS] Running Loop=1 2020-01-17T17:38:40.620Z,1579282720.620 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-01-17T17:38:40.620Z,1579282720.620 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-3768,V 2020-01-17T17:39:31.110Z,1579282771.110 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-01-17T17:39:31.110Z,1579282771.110 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:39:31.120Z,1579282771.120 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:39:31.527Z,1579282771.527 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:39:31.527Z,1579282771.527 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2020-01-17T17:39:40.000Z,1579282780.000 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-17T17:39:40.001Z,1579282780.001 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-17T17:39:43.651Z,1579282783.651 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude 2020-01-17T17:39:43.651Z,1579282783.651 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.0 +0.00, 0.00,414.99 2020-01-17T17:39:47.224Z,1579282787.224 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-01-17T17:39:47.224Z,1579282787.224 [NAL9602] Data Fault, FailCount= 2 2020-01-17T17:39:47.224Z,1579282787.224 [NAL9602](ERROR): Data Fault 2020-01-17T17:39:47.305Z,1579282787.305 [CBIT](ERROR): Data Fault in component: NAL9602 2020-01-17T17:39:47.627Z,1579282787.627 [NAL9602](INFO): Powering down 2020-01-17T17:39:48.033Z,1579282788.033 [NAL9602](FAULT): LCB fault: Invalid Command. 2020-01-17T17:39:48.033Z,1579282788.033 [NAL9602] Hardware Fault, FailCount= 2 2020-01-17T17:39:48.033Z,1579282788.033 [NAL9602](ERROR): Hardware Fault 2020-01-17T17:39:48.478Z,1579282788.478 [CBIT](INFO): Clearing failed state for component NAL9602 2020-01-17T17:39:48.478Z,1579282788.478 [NAL9602] No Fault, FailCount= 2 2020-01-17T17:40:00.982Z,1579282800.982 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-17T17:40:00.982Z,1579282800.982 [RDI_Pathfinder](ERROR): Failed to parse: :TS,20011710520191,35.0, -0.1, .9, 0 2020-01-17T17:40:17.943Z,1579282817.943 [NAL9602](INFO): Powering up NAL9602 2020-01-17T17:40:21.999Z,1579282821.999 [RDI_Pathfinder](ERROR): only read 2 of 4 data items 2020-01-17T17:40:21.000Z,1579282822.000 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-3276,-32768,V 2020-01-17T17:40:28.839Z,1579282828.839 [NAL9602](INFO): NAL9602 initialized 2020-01-17T17:41:44.007Z,1579282904.007 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-17T17:41:44.008Z,1579282904.008 [RDI_Pathfinder](ERROR): Failed to parse: :TS,20011710534491,35.0, -0.1, 0., 0 2020-01-17T17:42:18.362Z,1579282938.362 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2020-01-17T17:42:32.098Z,1579282952.098 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2020-01-17T17:42:32.098Z,1579282952.098 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:42:32.108Z,1579282952.108 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:42:32.515Z,1579282952.515 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:42:32.515Z,1579282952.515 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2020-01-17T17:42:51.906Z,1579282971.906 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-01-17T17:37:51.7Z 2020-01-17T17:42:51.906Z,1579282971.906 [Default:CheckIn:Read_GPS] Stopped 2020-01-17T17:42:51.906Z,1579282971.906 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-01-17T17:43:01.716Z,1579282981.716 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20200117T171814/Express0008.lzma 2020-01-17T17:43:01.974Z,1579282981.974 [RDI_Pathfinder](ERROR): only read 3 of 4 data items 2020-01-17T17:43:01.974Z,1579282981.974 [RDI_Pathfinder](ERROR): Failed to parse: :RA, 0.00, 0.00, 0.00, 0.00 2020-01-17T17:43:03.722Z,1579282983.722 [DataOverHttps](INFO): Moved sent file to Logs/20200117T171814/Express0008.lzma.bak 2020-01-17T17:43:03.722Z,1579282983.722 [DataOverHttps](INFO): SBD MOMSN=12196679 2020-01-17T17:43:05.223Z,1579282985.223 [Default:CheckIn:Read_Iridium] Stopped 2020-01-17T17:43:05.223Z,1579282985.223 [Default:CheckIn:C.Wait] Running Loop=1 2020-01-17T17:43:05.224Z,1579282985.224 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-01-17T17:43:16.151Z,1579282996.151 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2020-01-17T17:43:16.151Z,1579282996.151 [RDI_Pathfinder](ERROR): Failed to parse: :TS,20011710551691,35.0, -0.1, .9, 0 2020-01-17T17:45:02.813Z,1579283102.813 [CommandLine](IMPORTANT): got command get depth 2020-01-17T17:45:02.814Z,1579283102.814 [CommandLine](IMPORTANT): depth 0.268752 m 2020-01-17T17:45:33.145Z,1579283133.145 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2020-01-17T17:45:33.145Z,1579283133.145 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-01-17T17:45:33.163Z,1579283133.163 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-01-17T17:45:33.534Z,1579283133.534 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-01-17T17:45:33.534Z,1579283133.534 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2020-01-17T17:45:52.608Z,1579283152.608 [CommandLine](IMPORTANT): got command restart application 2020-01-17T17:45:53.614Z,1579283153.614 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2020-01-17T17:45:53.615Z,1579283153.615 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:53.616Z,1579283153.616 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:53.809Z,1579283153.809 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-01-17T17:45:53.809Z,1579283153.809 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:53.810Z,1579283153.810 [CommandLine](INFO): Join timeout helper Thread ID is 4541 2020-01-17T17:45:53.810Z,1579283153.810 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-01-17T17:45:53.810Z,1579283153.810 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:53.811Z,1579283153.811 [NavChartDb](INFO): Join timeout helper Thread ID is 4542 2020-01-17T17:45:53.885Z,1579283153.885 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:53.885Z,1579283153.885 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:53.889Z,1579283153.889 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2020-01-17T17:45:53.889Z,1579283153.889 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:53.889Z,1579283153.889 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 4543 2020-01-17T17:45:54.225Z,1579283154.225 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:54.225Z,1579283154.225 [WetLabsSeaOWL_UV_A](INFO): Powering down 2020-01-17T17:45:54.226Z,1579283154.226 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:54.237Z,1579283154.237 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2020-01-17T17:45:54.237Z,1579283154.237 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:54.237Z,1579283154.237 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4544 2020-01-17T17:45:54.413Z,1579283154.413 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:54.414Z,1579283154.414 [CTD_NeilBrown](INFO): Powering down 2020-01-17T17:45:54.429Z,1579283154.429 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:54.437Z,1579283154.437 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-01-17T17:45:54.437Z,1579283154.437 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:54.437Z,1579283154.437 [Radio_Surface](INFO): Join timeout helper Thread ID is 4545 2020-01-17T17:45:54.609Z,1579283154.609 [Radio_Surface](INFO): Powering down 2020-01-17T17:45:54.610Z,1579283154.610 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:54.610Z,1579283154.610 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:54.618Z,1579283154.618 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-01-17T17:45:54.619Z,1579283154.619 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:54.620Z,1579283154.620 [DataOverHttps](INFO): Join timeout helper Thread ID is 4546 2020-01-17T17:45:55.317Z,1579283155.317 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:55.317Z,1579283155.317 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.318Z,1579283155.318 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-01-17T17:45:55.319Z,1579283155.319 [logger ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.319Z,1579283155.319 [logger](INFO): Join timeout helper Thread ID is 4547 2020-01-17T17:45:55.336Z,1579283155.336 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:55.336Z,1579283155.336 [logger ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.350Z,1579283155.350 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-01-17T17:45:55.350Z,1579283155.350 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.350Z,1579283155.350 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-01-17T17:45:55.350Z,1579283155.350 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.350Z,1579283155.350 [controlThread](INFO): Join timeout helper Thread ID is 4548 2020-01-17T17:45:55.354Z,1579283155.354 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-01-17T17:45:55.355Z,1579283155.355 [controlThread](DEBUG): Uninitializing ControlThread 2020-01-17T17:45:55.355Z,1579283155.355 [AHRS_M2](INFO): Powering down 2020-01-17T17:45:55.425Z,1579283155.425 [DDM](INFO): Powering down 2020-01-17T17:45:55.518Z,1579283155.518 [DUSBL_Hydroid](INFO): Powering down 2020-01-17T17:45:55.589Z,1579283155.589 [Micromodem](INFO): Powering down 2020-01-17T17:45:55.685Z,1579283155.685 [NAL9602](INFO): Powering down 2020-01-17T17:45:55.757Z,1579283155.757 [RDI_Pathfinder](INFO): Powering down 2020-01-17T17:45:55.758Z,1579283155.758 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-01-17T17:45:55.759Z,1579283155.759 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-01-17T17:45:55.760Z,1579283155.760 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-01-17T17:45:55.760Z,1579283155.760 [MissionManager](INFO): Uninitializing Mission Default 2020-01-17T17:45:55.760Z,1579283155.760 [Default] Stopped 2020-01-17T17:45:55.760Z,1579283155.760 [Default](DEBUG): Aggregate::uninitialize Default 2020-01-17T17:45:55.760Z,1579283155.760 [Default:B.GoToSurface] Stopped 2020-01-17T17:45:55.760Z,1579283155.760 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-01-17T17:45:55.761Z,1579283155.761 [Default:CheckIn] Stopped 2020-01-17T17:45:55.761Z,1579283155.761 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-01-17T17:45:55.761Z,1579283155.761 [Default:CheckIn:C.Wait] Stopped 2020-01-17T17:45:55.761Z,1579283155.761 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-01-17T17:45:55.763Z,1579283155.763 [MissionManager](INFO): Uninitializing Mission Docked 2020-01-17T17:45:55.768Z,1579283155.768 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-01-17T17:45:55.768Z,1579283155.768 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-01-17T17:45:55.769Z,1579283155.769 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-01-17T17:45:55.769Z,1579283155.769 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-01-17T17:45:55.769Z,1579283155.769 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-01-17T17:45:55.769Z,1579283155.769 [BuoyancyServo](INFO): Powering down 2020-01-17T17:45:55.781Z,1579283155.781 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-01-17T17:45:55.781Z,1579283155.781 [ElevatorServo](INFO): Powering down 2020-01-17T17:45:55.782Z,1579283155.782 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-01-17T17:45:55.782Z,1579283155.782 [MassServo](INFO): Powering down 2020-01-17T17:45:55.783Z,1579283155.783 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-01-17T17:45:55.783Z,1579283155.783 [RudderServo](INFO): Powering down 2020-01-17T17:45:55.783Z,1579283155.783 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-01-17T17:45:55.784Z,1579283155.784 [ThrusterServo](INFO): Powering down 2020-01-17T17:45:55.784Z,1579283155.784 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-01-17T17:45:55.785Z,1579283155.785 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-01-17T17:45:55.785Z,1579283155.785 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-01-17T17:45:55.785Z,1579283155.785 [CBIT](DEBUG): Powering off loads. 2020-01-17T17:45:55.797Z,1579283155.797 [CBIT](DEBUG): Disabling WDT. 2020-01-17T17:45:55.809Z,1579283155.809 [CBIT](DEBUG): Opening all GF detection circuits. 2020-01-17T17:45:55.810Z,1579283155.810 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.851Z,1579283155.851 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.862Z,1579283155.862 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.903Z,1579283155.903 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.906Z,1579283155.906 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:55.966Z,1579283155.966 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-01-17T17:45:56.026Z,1579283156.026 [logger ThreadHandler](INFO): Thread cancelled.