2021-08-05T20:26:13.583Z,1628195173.583 [Supervisor](DEBUG): Initializing supervisor. 2021-08-05T20:26:13.587Z,1628195173.587 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2021-08-05T20:26:13.588Z,1628195173.588 [SyncHandler](INFO): Protected caller Thread ID is 827 2021-08-05T20:26:13.588Z,1628195173.588 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2021-08-05T20:26:13.589Z,1628195173.589 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2021-08-05T20:26:13.589Z,1628195173.589 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 828 2021-08-05T20:26:13.594Z,1628195173.594 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2021-08-05T20:26:13.614Z,1628195173.614 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2021-08-05T20:26:13.615Z,1628195173.615 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2021-08-05T20:26:13.615Z,1628195173.615 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 829 2021-08-05T20:26:13.617Z,1628195173.617 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2021-08-05T20:26:13.618Z,1628195173.618 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2021-08-05T20:26:13.619Z,1628195173.619 [logger ThreadHandler](INFO): Protected caller Thread ID is 830 2021-08-05T20:26:13.623Z,1628195173.623 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2021-08-05T20:26:13.623Z,1628195173.623 [Supervisor](INFO): Looking for Config files in directory: Config/ 2021-08-05T20:26:13.627Z,1628195173.627 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2021-08-05T20:26:13.959Z,1628195173.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2021-08-05T20:26:13.960Z,1628195173.960 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2021-08-05T20:26:14.620Z,1628195174.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2021-08-05T20:26:14.622Z,1628195174.622 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2021-08-05T20:26:14.733Z,1628195174.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2021-08-05T20:26:14.735Z,1628195174.735 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2021-08-05T20:26:15.266Z,1628195175.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2021-08-05T20:26:15.268Z,1628195175.268 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2021-08-05T20:26:15.364Z,1628195175.364 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2021-08-05T20:26:15.365Z,1628195175.365 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2021-08-05T20:26:15.447Z,1628195175.447 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2021-08-05T20:26:15.828Z,1628195175.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2021-08-05T20:26:15.830Z,1628195175.830 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2021-08-05T20:26:15.981Z,1628195175.981 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2021-08-05T20:26:15.983Z,1628195175.983 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2021-08-05T20:26:16.110Z,1628195176.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2021-08-05T20:26:16.112Z,1628195176.112 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2021-08-05T20:26:16.335Z,1628195176.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2021-08-05T20:26:16.336Z,1628195176.336 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2021-08-05T20:26:16.825Z,1628195176.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2021-08-05T20:26:16.827Z,1628195176.827 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2021-08-05T20:26:17.552Z,1628195177.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2021-08-05T20:26:17.553Z,1628195177.553 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2021-08-05T20:26:17.633Z,1628195177.633 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2021-08-05T20:26:17.836Z,1628195177.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2021-08-05T20:26:17.838Z,1628195177.838 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2021-08-05T20:26:18.051Z,1628195178.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2021-08-05T20:26:18.052Z,1628195178.052 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2021-08-05T20:26:18.307Z,1628195178.307 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2021-08-05T20:26:18.309Z,1628195178.309 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2021-08-05T20:26:18.314Z,1628195178.314 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2021-08-05T20:26:18.422Z,1628195178.422 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2021-08-05T20:26:18.570Z,1628195178.570 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2021-08-05T20:26:18.656Z,1628195178.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2021-08-05T20:26:18.739Z,1628195178.739 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2021-08-05T20:26:18.849Z,1628195178.849 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2021-08-05T20:26:19.034Z,1628195179.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2021-08-05T20:26:19.299Z,1628195179.299 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2021-08-05T20:26:19.299Z,1628195179.299 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2021-08-05T20:26:19.433Z,1628195179.433 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2021-08-05T20:26:19.526Z,1628195179.526 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2021-08-05T20:26:19.632Z,1628195179.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2021-08-05T20:26:19.728Z,1628195179.728 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2021-08-05T20:26:19.745Z,1628195179.745 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2021-08-05T20:26:19.869Z,1628195179.869 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2021-08-05T20:26:19.871Z,1628195179.871 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2021-08-05T20:26:19.887Z,1628195179.887 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2021-08-05T20:26:19.888Z,1628195179.888 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2021-08-05T20:26:19.951Z,1628195179.951 [DepthRateCalculator] Loaded 2021-08-05T20:26:19.951Z,1628195179.951 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2021-08-05T20:26:19.957Z,1628195179.957 [PitchRateCalculator] Loaded 2021-08-05T20:26:19.957Z,1628195179.957 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2021-08-05T20:26:19.968Z,1628195179.968 [SpeedCalculator] Loaded 2021-08-05T20:26:19.969Z,1628195179.969 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2021-08-05T20:26:19.982Z,1628195179.982 [TempGradientCalculator] Loaded 2021-08-05T20:26:19.983Z,1628195179.983 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2021-08-05T20:26:19.988Z,1628195179.988 [YawRateCalculator] Loaded 2021-08-05T20:26:19.988Z,1628195179.988 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2021-08-05T20:26:20.010Z,1628195180.010 [ElevatorOffsetCalculator] Loaded 2021-08-05T20:26:20.010Z,1628195180.010 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2021-08-05T20:26:20.011Z,1628195180.011 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2021-08-05T20:26:20.013Z,1628195180.013 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2021-08-05T20:26:20.084Z,1628195180.084 [VerticalControl](DEBUG): Construct VerticalControl. 2021-08-05T20:26:20.142Z,1628195180.142 [VerticalControl] Loaded 2021-08-05T20:26:20.143Z,1628195180.143 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2021-08-05T20:26:20.145Z,1628195180.145 [HorizontalControl](DEBUG): Construct HorizontalControl. 2021-08-05T20:26:20.184Z,1628195180.184 [HorizontalControl] Loaded 2021-08-05T20:26:20.185Z,1628195180.185 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2021-08-05T20:26:20.187Z,1628195180.187 [SpeedControl](DEBUG): Construct SpeedControl. 2021-08-05T20:26:20.190Z,1628195180.190 [SpeedControl] Loaded 2021-08-05T20:26:20.190Z,1628195180.190 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2021-08-05T20:26:20.193Z,1628195180.193 [LoopControl](DEBUG): Construct LoopControl. 2021-08-05T20:26:20.193Z,1628195180.193 [LoopControl] Loaded 2021-08-05T20:26:20.194Z,1628195180.194 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2021-08-05T20:26:20.194Z,1628195180.194 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2021-08-05T20:26:20.195Z,1628195180.195 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2021-08-05T20:26:20.296Z,1628195180.296 [DeadReckonUsingMultipleVelocitySources] Loaded 2021-08-05T20:26:20.296Z,1628195180.296 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2021-08-05T20:26:20.310Z,1628195180.310 [NavChart] Loaded 2021-08-05T20:26:20.310Z,1628195180.310 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2021-08-05T20:26:20.316Z,1628195180.316 [UniversalFixResidualReporter] Loaded 2021-08-05T20:26:20.316Z,1628195180.316 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2021-08-05T20:26:20.317Z,1628195180.317 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2021-08-05T20:26:20.319Z,1628195180.319 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2021-08-05T20:26:20.456Z,1628195180.456 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2021-08-05T20:26:20.456Z,1628195180.456 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2021-08-05T20:26:21.222Z,1628195181.222 [AHRS_M2] Loaded 2021-08-05T20:26:21.222Z,1628195181.222 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2021-08-05T20:26:21.466Z,1628195181.466 [BackseatComponent] Loaded 2021-08-05T20:26:21.467Z,1628195181.467 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2021-08-05T20:26:21.468Z,1628195181.468 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408714E0 2021-08-05T20:26:21.468Z,1628195181.468 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 913 2021-08-05T20:26:21.471Z,1628195181.471 [LcmUniversalReporter] Loaded 2021-08-05T20:26:21.471Z,1628195181.471 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2021-08-05T20:26:22.502Z,1628195182.502 [BPC1] Loaded 2021-08-05T20:26:22.502Z,1628195182.502 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2021-08-05T20:26:22.758Z,1628195182.758 [DataOverHttps] Loaded 2021-08-05T20:26:22.759Z,1628195182.759 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2021-08-05T20:26:22.760Z,1628195182.760 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408A14E0 2021-08-05T20:26:22.760Z,1628195182.760 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 914 2021-08-05T20:26:22.780Z,1628195182.780 [Depth_Keller] Loaded 2021-08-05T20:26:22.781Z,1628195182.781 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2021-08-05T20:26:22.785Z,1628195182.785 [DropWeight] Loaded 2021-08-05T20:26:22.785Z,1628195182.785 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2021-08-05T20:26:22.823Z,1628195182.823 [DVL_micro] Loaded 2021-08-05T20:26:22.823Z,1628195182.823 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2021-08-05T20:26:22.883Z,1628195182.883 [NAL9602] Loaded 2021-08-05T20:26:22.883Z,1628195182.883 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2021-08-05T20:26:22.913Z,1628195182.913 [Onboard] Loaded 2021-08-05T20:26:22.914Z,1628195182.914 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2021-08-05T20:26:22.915Z,1628195182.915 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408D14E0 2021-08-05T20:26:22.915Z,1628195182.915 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 915 2021-08-05T20:26:22.927Z,1628195182.927 [Power24vConverter] Loaded 2021-08-05T20:26:22.927Z,1628195182.927 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2021-08-05T20:26:22.940Z,1628195182.940 [Radio_Surface] Loaded 2021-08-05T20:26:22.941Z,1628195182.941 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2021-08-05T20:26:22.942Z,1628195182.942 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409014E0 2021-08-05T20:26:22.942Z,1628195182.942 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 916 2021-08-05T20:26:23.026Z,1628195183.026 [DAT] Loaded 2021-08-05T20:26:23.027Z,1628195183.027 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2021-08-05T20:26:23.027Z,1628195183.027 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2021-08-05T20:26:23.029Z,1628195183.029 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2021-08-05T20:26:23.189Z,1628195183.189 [BuoyancyServo] Loaded 2021-08-05T20:26:23.190Z,1628195183.190 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2021-08-05T20:26:23.210Z,1628195183.210 [ElevatorServo] Loaded 2021-08-05T20:26:23.210Z,1628195183.210 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2021-08-05T20:26:23.230Z,1628195183.230 [MassServo] Loaded 2021-08-05T20:26:23.230Z,1628195183.230 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2021-08-05T20:26:23.248Z,1628195183.248 [RudderServo] Loaded 2021-08-05T20:26:23.249Z,1628195183.249 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2021-08-05T20:26:23.267Z,1628195183.267 [ThrusterServo] Loaded 2021-08-05T20:26:23.267Z,1628195183.267 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2021-08-05T20:26:23.268Z,1628195183.268 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2021-08-05T20:26:23.268Z,1628195183.268 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2021-08-05T20:26:23.351Z,1628195183.351 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2021-08-05T20:26:23.353Z,1628195183.353 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2021-08-05T20:26:23.397Z,1628195183.397 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2021-08-05T20:26:23.399Z,1628195183.399 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2021-08-05T20:26:23.789Z,1628195183.789 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2021-08-05T20:26:23.789Z,1628195183.789 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2021-08-05T20:26:24.019Z,1628195184.019 [CTD_Seabird] Loaded 2021-08-05T20:26:24.020Z,1628195184.020 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2021-08-05T20:26:24.021Z,1628195184.021 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A964E0 2021-08-05T20:26:24.021Z,1628195184.021 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 917 2021-08-05T20:26:24.054Z,1628195184.054 [ESPComponent] Loaded 2021-08-05T20:26:24.055Z,1628195184.055 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2021-08-05T20:26:24.074Z,1628195184.074 [PAR_Licor] Loaded 2021-08-05T20:26:24.075Z,1628195184.075 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2021-08-05T20:26:24.107Z,1628195184.107 [WetLabsBB2FL] Loaded 2021-08-05T20:26:24.107Z,1628195184.107 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2021-08-05T20:26:24.108Z,1628195184.108 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC64E0 2021-08-05T20:26:24.109Z,1628195184.109 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 918 2021-08-05T20:26:24.109Z,1628195184.109 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2021-08-05T20:26:24.110Z,1628195184.110 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2021-08-05T20:26:24.292Z,1628195184.292 [SBIT](DEBUG): Construct Startup Built In Test. 2021-08-05T20:26:24.301Z,1628195184.301 [SBIT] Loaded 2021-08-05T20:26:24.302Z,1628195184.302 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2021-08-05T20:26:24.305Z,1628195184.305 [IBIT](DEBUG): Construct Initiated Built In Test. 2021-08-05T20:26:24.318Z,1628195184.318 [IBIT] Loaded 2021-08-05T20:26:24.318Z,1628195184.318 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2021-08-05T20:26:24.324Z,1628195184.324 [CBIT](DEBUG): Construct Continuous Built In Test. 2021-08-05T20:26:24.431Z,1628195184.431 [CBIT] Loaded 2021-08-05T20:26:24.431Z,1628195184.431 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2021-08-05T20:26:24.432Z,1628195184.432 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2021-08-05T20:26:24.438Z,1628195184.438 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2021-08-05T20:26:24.441Z,1628195184.441 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2021-08-05T20:26:24.452Z,1628195184.452 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2021-08-05T20:26:24.453Z,1628195184.453 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B324E0 2021-08-05T20:26:24.453Z,1628195184.453 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 919 2021-08-05T20:26:24.458Z,1628195184.458 [Supervisor](INFO): Main Thread ID is 823 2021-08-05T20:26:24.458Z,1628195184.458 [Supervisor](DEBUG): Running supervisor. 2021-08-05T20:26:24.459Z,1628195184.459 [CommandLine ThreadHandler](INFO): Handler Thread ID is 920 2021-08-05T20:26:24.461Z,1628195184.461 [controlThread ThreadHandler](INFO): Handler Thread ID is 921 2021-08-05T20:26:24.461Z,1628195184.461 [controlThread](DEBUG): Initializing ControlThread 2021-08-05T20:26:24.463Z,1628195184.463 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2021-08-05T20:26:24.463Z,1628195184.463 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2021-08-05T20:26:24.463Z,1628195184.463 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2021-08-05T20:26:24.464Z,1628195184.464 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2021-08-05T20:26:24.464Z,1628195184.464 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2021-08-05T20:26:24.465Z,1628195184.465 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2021-08-05T20:26:24.465Z,1628195184.465 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2021-08-05T20:26:24.467Z,1628195184.467 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2021-08-05T20:26:24.468Z,1628195184.468 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2021-08-05T20:26:24.468Z,1628195184.468 [LoopControl](DEBUG): Initialize LoopControlComponent. 2021-08-05T20:26:24.469Z,1628195184.469 [NavChart](DEBUG): Initialize NavChart Navigation. 2021-08-05T20:26:24.469Z,1628195184.469 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2021-08-05T20:26:24.479Z,1628195184.479 [SBIT](INFO): Initialize SBIT Component. 2021-08-05T20:26:24.479Z,1628195184.479 [SBIT](IMPORTANT): git: 2021-08-04 2021-08-05T20:26:24.479Z,1628195184.480 [SBIT](INFO): git hash: 34cc6a8bcb09b3a08deceec5468acc868a8ac258 2021-08-05T20:26:24.480Z,1628195184.480 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2021-08-05T20:26:24.481Z,1628195184.481 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2021-08-05T20:26:24.482Z,1628195184.482 [SBIT](INFO): Beginning SBIT in 24.000000 seconds. 2021-08-05T20:26:24.483Z,1628195184.483 [IBIT](INFO): Initialize IBIT Component. 2021-08-05T20:26:24.484Z,1628195184.484 [CBIT](DEBUG): Initialize CBIT Component. 2021-08-05T20:26:24.485Z,1628195184.485 [logger ThreadHandler](INFO): Handler Thread ID is 922 2021-08-05T20:26:24.498Z,1628195184.498 [CBIT](DEBUG): Initialized mux pins. 2021-08-05T20:26:24.499Z,1628195184.499 [CBIT](DEBUG): Initializing the watchdog timer. 2021-08-05T20:26:24.503Z,1628195184.503 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 923 2021-08-05T20:26:24.511Z,1628195184.511 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 924 2021-08-05T20:26:24.512Z,1628195184.512 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2021-08-05T20:26:24.519Z,1628195184.519 [Onboard ThreadHandler](INFO): Handler Thread ID is 925 2021-08-05T20:26:24.523Z,1628195184.523 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2021-08-05T20:26:24.524Z,1628195184.524 [CBIT](DEBUG): Initializing heartbeat. 2021-08-05T20:26:24.544Z,1628195184.544 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 926 2021-08-05T20:26:24.555Z,1628195184.555 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 927 2021-08-05T20:26:24.555Z,1628195184.555 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2021-08-05T20:26:24.560Z,1628195184.560 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 929 2021-08-05T20:26:24.563Z,1628195184.563 [WetLabsBB2FL](INFO): Powering up 2021-08-05T20:26:24.564Z,1628195184.564 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 931 2021-08-05T20:26:24.572Z,1628195184.572 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000 2021-08-05T20:26:24.572Z,1628195184.572 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000 2021-08-05T20:26:24.572Z,1628195184.572 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000 2021-08-05T20:26:24.572Z,1628195184.572 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000 2021-08-05T20:26:24.572Z,1628195184.572 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000 2021-08-05T20:26:24.572Z,1628195184.572 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000 2021-08-05T20:26:24.573Z,1628195184.573 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000 2021-08-05T20:26:24.573Z,1628195184.573 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000 2021-08-05T20:26:24.594Z,1628195184.594 [CBIT](DEBUG): Deactivating GF circuits. 2021-08-05T20:26:24.595Z,1628195184.595 [CBIT](DEBUG): Deactivating emergency mode. 2021-08-05T20:26:24.630Z,1628195184.630 [CBIT](DEBUG): Backplane powered. 2021-08-05T20:26:24.631Z,1628195184.631 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2021-08-05T20:26:24.660Z,1628195184.660 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2021-08-05T20:26:24.680Z,1628195184.680 [MissionManager](DEBUG): 2021-08-05T20:26:24.681Z,1628195184.681 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2021-08-05T20:26:24.763Z,1628195184.763 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2021-08-05T20:26:24.764Z,1628195184.764 [Default:A.Wait](DEBUG): Construct Wait. 2021-08-05T20:26:24.771Z,1628195184.771 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2021-08-05T20:26:24.803Z,1628195184.803 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2021-08-05T20:26:24.805Z,1628195184.805 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2021-08-05T20:26:24.827Z,1628195184.827 [Default:E.Execute](DEBUG): Construct Execute. 2021-08-05T20:26:24.847Z,1628195184.847 [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 2021-08-05T20:26:24.863Z,1628195184.863 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,DAT,ESPComponent,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,LcmUniversalReporter,Reporter,LogSplitter, 2021-08-05T20:26:24.879Z,1628195184.879 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2021-08-05T20:26:24.946Z,1628195184.946 [Radio_Surface](INFO): Powering up 2021-08-05T20:26:24.987Z,1628195184.987 [Depth_Keller](ERROR): Pressure reading out of range: 1829.595459 decibar 2021-08-05T20:26:24.996Z,1628195184.996 [Power24vConverter](INFO): Powering up. 2021-08-05T20:26:24.996Z,1628195184.996 [DAT](INFO): Powering up 2021-08-05T20:26:24.997Z,1628195184.997 [DAT](DEBUG): Initializing DAT. 2021-08-05T20:26:25.043Z,1628195185.043 [DepthRateCalculator](ERROR): Depth measurement is not active 2021-08-05T20:26:25.079Z,1628195185.079 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-08-05T20:26:25.098Z,1628195185.098 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-08-05T20:26:25.099Z,1628195185.099 [ElevatorServo](DEBUG): Initializing EZServoServo. 2021-08-05T20:26:25.111Z,1628195185.111 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2021-08-05T20:26:25.112Z,1628195185.112 [MassServo](DEBUG): Initializing EZServoServo. 2021-08-05T20:26:25.119Z,1628195185.119 [MassServo](DEBUG): Initializing MassServo. 2021-08-05T20:26:25.119Z,1628195185.119 [RudderServo](DEBUG): Initializing EZServoServo. 2021-08-05T20:26:25.127Z,1628195185.127 [RudderServo](DEBUG): Initializing RudderServo. 2021-08-05T20:26:25.128Z,1628195185.128 [ThrusterServo](DEBUG): Initializing EZServoServo. 2021-08-05T20:26:25.135Z,1628195185.135 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2021-08-05T20:26:26.010Z,1628195186.010 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2021-08-05T20:26:26.011Z,1628195186.011 [RudderServo](FAULT): Rudder failed to initialize 2021-08-05T20:26:26.011Z,1628195186.011 [RudderServo] Communications Fault, FailCount= 1 2021-08-05T20:26:26.011Z,1628195186.011 [RudderServo](ERROR): Communications Fault 2021-08-05T20:26:26.111Z,1628195186.111 [CBIT](ERROR): Communications Fault in component: RudderServo 2021-08-05T20:26:26.292Z,1628195186.292 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-08-05T20:26:26.292Z,1628195186.292 [RudderServo](INFO): Powering down 2021-08-05T20:26:26.947Z,1628195186.947 [RudderServo](DEBUG): Initializing EZServoServo. 2021-08-05T20:26:27.067Z,1628195187.067 [RudderServo](DEBUG): Initializing RudderServo. 2021-08-05T20:26:27.072Z,1628195187.072 [CBIT](INFO): Clearing failed state for component RudderServo 2021-08-05T20:26:27.072Z,1628195187.072 [RudderServo] No Fault, FailCount= 1 2021-08-05T20:26:27.175Z,1628195187.175 [WetLabsBB2FL](INFO): Powering down 2021-08-05T20:26:39.055Z,1628195199.055 [DAT](INFO): commRate: 800 2021-08-05T20:26:41.073Z,1628195201.073 [DAT](INFO): entering command mode 2021-08-05T20:26:41.477Z,1628195201.477 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:41.881Z,1628195201.881 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:42.299Z,1628195202.299 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:42.689Z,1628195202.689 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:43.093Z,1628195203.093 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:43.497Z,1628195203.497 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:43.901Z,1628195203.901 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:44.309Z,1628195204.309 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:44.709Z,1628195204.709 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:45.152Z,1628195205.152 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:45.517Z,1628195205.517 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:45.921Z,1628195205.921 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:46.325Z,1628195206.325 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:46.729Z,1628195206.729 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:47.133Z,1628195207.133 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:47.547Z,1628195207.547 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:47.946Z,1628195207.946 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:48.345Z,1628195208.345 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:48.749Z,1628195208.749 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:49.153Z,1628195209.153 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:49.185Z,1628195209.185 [SBIT](IMPORTANT): Beginning Startup BIT 2021-08-05T20:26:49.222Z,1628195209.222 [CBIT](IMPORTANT): Beginning ground fault scan 2021-08-05T20:26:49.561Z,1628195209.561 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:49.987Z,1628195209.987 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:50.365Z,1628195210.365 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:50.769Z,1628195210.769 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:51.173Z,1628195211.173 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:51.577Z,1628195211.577 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:51.981Z,1628195211.981 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:52.396Z,1628195212.396 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:52.790Z,1628195212.790 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:53.202Z,1628195213.202 [NAL9602](INFO): Powering up NAL9602 2021-08-05T20:26:53.204Z,1628195213.204 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:53.601Z,1628195213.601 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:54.005Z,1628195214.005 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:54.409Z,1628195214.409 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:54.846Z,1628195214.846 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:55.217Z,1628195215.217 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:55.621Z,1628195215.621 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:56.021Z,1628195216.021 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:56.431Z,1628195216.431 [DAT](DEBUG): checking for command mode acknowledgment 2021-08-05T20:26:56.431Z,1628195216.431 [DAT](FAULT): failed to enter command mode 2021-08-05T20:26:56.834Z,1628195216.834 [DAT](INFO): entering command mode 2021-08-05T20:26:57.234Z,1628195217.234 [DAT](INFO): setting verbose to 3 2021-08-05T20:26:57.653Z,1628195217.653 [DAT](INFO): set verbose to 3 2021-08-05T20:26:57.654Z,1628195217.654 [DAT](INFO): setting DatVerbose to 27440 2021-08-05T20:26:58.050Z,1628195218.050 [DAT](INFO): set DatVerbose to 27440 2021-08-05T20:26:58.051Z,1628195218.051 [DAT](INFO): setting transmit power to 8 2021-08-05T20:26:58.446Z,1628195218.446 [DAT](INFO): set transmit power to 8 2021-08-05T20:26:58.447Z,1628195218.447 [DAT](INFO): setting local address to 8 2021-08-05T20:26:58.855Z,1628195218.855 [DAT](INFO): set local address to 8 2021-08-05T20:27:00.155Z,1628195220.155 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.004580 CHAN A1 (24V): -0.002401 CHAN A2 (12V): -0.000149 CHAN A3 (5V): -0.000360 CHAN B0 (3.3V): 0.000483 CHAN B1 (3.15aV): 0.000227 CHAN B2 (3.15bV): 0.000843 CHAN B3 (GND): 0.001037 OPEN: -0.004170 Full Scale Calc: 4.765 mA, -1.589 mA 2021-08-05T20:27:04.105Z,1628195224.105 [NAL9602](INFO): NAL9602 initialized 2021-08-05T20:27:43.324Z,1628195263.324 [SBIT](IMPORTANT): SBIT PASSED 2021-08-05T20:27:43.325Z,1628195263.325 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2021-08-05T20:27:43.325Z,1628195263.325 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2021-08-05T20:27:43.326Z,1628195263.326 [SBIT](IMPORTANT): BackseatComponent.loadAtStartup=1 bool; 2021-08-05T20:27:43.326Z,1628195263.326 [SBIT](IMPORTANT): BackseatComponent.simulateHardware=1 bool; 2021-08-05T20:27:43.326Z,1628195263.326 [SBIT](IMPORTANT): CBIT.abortDepth=15 meter; 2021-08-05T20:27:43.326Z,1628195263.326 [SBIT](IMPORTANT): CBIT.stopDepth=10 meter; 2021-08-05T20:27:43.326Z,1628195263.326 [SBIT](IMPORTANT): CTD_Seabird.minSalinityBound=0.01 practical_salinity_unit; 2021-08-05T20:27:43.326Z,1628195263.326 [SBIT](IMPORTANT): ESPComponent.processCompleteTimeout=120 minute; 2021-08-05T20:27:43.327Z,1628195263.327 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.010000 practical_salinity_unit; 2021-08-05T20:27:43.327Z,1628195263.327 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water; 2021-08-05T20:27:43.327Z,1628195263.327 [SBIT](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 0.200000 microgram_per_liter; 2021-08-05T20:27:43.327Z,1628195263.327 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=214.815570 cubic_centimeter; 2021-08-05T20:27:43.327Z,1628195263.327 [SBIT](IMPORTANT): VerticalControl.massDefault=-1 millimeter; 2021-08-05T20:27:43.721Z,1628195263.721 [MissionManager](IMPORTANT): Started mission Startup 2021-08-05T20:27:43.722Z,1628195263.722 [Startup] Running Loop=1 2021-08-05T20:27:43.722Z,1628195263.722 [Startup](DEBUG): Aggregate::initialize Startup 2021-08-05T20:27:43.722Z,1628195263.722 [Startup:A.GoToSurface] Running Loop=1 2021-08-05T20:27:43.722Z,1628195263.722 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-08-05T20:27:43.723Z,1628195263.723 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-08-05T20:27:43.723Z,1628195263.723 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-08-05T20:27:43.724Z,1628195263.724 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-08-05T20:27:43.724Z,1628195263.724 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-08-05T20:27:43.724Z,1628195263.724 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-08-05T20:27:43.726Z,1628195263.726 [Startup:StartupSatComms] Running Loop=1 2021-08-05T20:27:43.726Z,1628195263.726 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2021-08-05T20:27:43.726Z,1628195263.726 [Startup:StartupSatComms:A] Running Loop=1 2021-08-05T20:27:44.117Z,1628195264.117 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2021-08-05T20:28:43.917Z,1628195323.917 [Startup:StartupSatComms:A](INFO): Timed out from 2021-08-05T20:27:43.7Z 2021-08-05T20:28:43.918Z,1628195323.918 [Startup:StartupSatComms:A] Stopped 2021-08-05T20:28:43.918Z,1628195323.918 [Startup:StartupSatComms:B] Running Loop=1 2021-08-05T20:28:44.337Z,1628195324.337 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-08-05T20:29:22.548Z,1628195362.548 [DataOverHttps](IMPORTANT): SBD MTMSN=20210805T202922 2021-08-05T20:29:22.553Z,1628195362.553 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004612 2021-08-05T20:29:24.716Z,1628195364.716 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2021-08-05T20:29:24.716Z,1628195364.716 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-08-05T20:29:24.751Z,1628195364.751 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-08-05T20:29:25.256Z,1628195365.256 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-08-05T20:29:25.256Z,1628195365.256 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2021-08-05T20:29:32.432Z,1628195372.432 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210805T045057/Courier0259.lzma 2021-08-05T20:29:32.434Z,1628195372.434 [DataOverHttps](INFO): Received command:strobe off 2021-08-05T20:29:32.483Z,1628195372.483 [CommandLine](IMPORTANT): got command strobe off 2021-08-05T20:29:32.483Z,1628195372.483 [CommandLine](IMPORTANT): Deactivating strobe 2021-08-05T20:29:33.789Z,1628195373.789 [DataOverHttps](INFO): Moved sent file to Logs/20210805T045057/Courier0259.lzma.bak 2021-08-05T20:29:33.789Z,1628195373.789 [DataOverHttps](INFO): SBD MOMSN=15839553 2021-08-05T20:29:44.147Z,1628195384.147 [Startup:StartupSatComms:B](INFO): Timed out from 2021-08-05T20:28:43.9Z 2021-08-05T20:29:44.148Z,1628195384.148 [Startup:StartupSatComms:B] Stopped 2021-08-05T20:29:44.148Z,1628195384.148 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2021-08-05T20:29:44.148Z,1628195384.148 [Startup:StartupSatComms] Stopped 2021-08-05T20:29:44.148Z,1628195384.148 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2021-08-05T20:29:44.149Z,1628195384.149 [Startup](INFO): Completed Startup 2021-08-05T20:29:44.149Z,1628195384.149 [MissionManager](INFO): Startup is completed. 2021-08-05T20:29:44.149Z,1628195384.149 [MissionManager](INFO): Uninitializing Mission Startup 2021-08-05T20:29:44.149Z,1628195384.149 [Startup] Stopped 2021-08-05T20:29:44.149Z,1628195384.149 [Startup](DEBUG): Aggregate::uninitialize Startup 2021-08-05T20:29:44.149Z,1628195384.149 [Startup:A.GoToSurface] Stopped 2021-08-05T20:29:44.149Z,1628195384.149 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-08-05T20:29:44.541Z,1628195384.541 [MissionManager](IMPORTANT): Started mission Default 2021-08-05T20:29:44.541Z,1628195384.541 [Default] Running Loop=1 2021-08-05T20:29:44.542Z,1628195384.542 [Default](DEBUG): Aggregate::initialize Default 2021-08-05T20:29:44.542Z,1628195384.542 [Default:B.GoToSurface] Running Loop=1 2021-08-05T20:29:44.542Z,1628195384.542 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-08-05T20:29:44.542Z,1628195384.542 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-08-05T20:29:44.543Z,1628195384.543 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-08-05T20:29:44.543Z,1628195384.543 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-08-05T20:29:44.543Z,1628195384.543 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-08-05T20:29:44.544Z,1628195384.544 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-08-05T20:29:44.544Z,1628195384.544 [Default:A.Wait] Running Loop=1 2021-08-05T20:29:44.544Z,1628195384.544 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-08-05T20:29:50.242Z,1628195390.242 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210805T202613/Courier0000.lzma 2021-08-05T20:29:51.244Z,1628195391.244 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0000.lzma.bak 2021-08-05T20:29:51.244Z,1628195391.244 [DataOverHttps](INFO): SBD MOMSN=15839561 2021-08-05T20:29:57.900Z,1628195397.900 [Default:A.Wait](INFO): Done Waiting. 2021-08-05T20:29:57.900Z,1628195397.900 [Default:A.Wait] Stopped 2021-08-05T20:29:57.900Z,1628195397.900 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T20:29:58.331Z,1628195398.331 [Default:CheckIn] Running Loop=1 2021-08-05T20:29:58.331Z,1628195398.331 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T20:29:58.331Z,1628195398.331 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T20:29:58.702Z,1628195398.702 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2021-08-05T20:32:07.168Z,1628195527.168 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2021-08-05T20:32:25.754Z,1628195545.754 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2021-08-05T20:32:25.754Z,1628195545.754 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2021-08-05T20:32:25.765Z,1628195545.765 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2021-08-05T20:32:26.186Z,1628195546.186 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2021-08-05T20:32:26.186Z,1628195546.186 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2021-08-05T20:32:31.387Z,1628195551.387 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:32:37.032Z,1628195557.032 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:32:51.981Z,1628195571.981 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:33:06.928Z,1628195586.928 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:33:22.054Z,1628195602.054 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:33:31.684Z,1628195611.684 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203330.00,A,4149.69523,N,08324.71071,W,0.039,0.00,050821,,,A*77 2021-08-05T20:33:31.696Z,1628195611.696 [NAL9602](INFO): GPS fix at 20210805T203330: (41.828254, -83.411845) 2021-08-05T20:33:31.736Z,1628195611.736 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T20:33:31.736Z,1628195611.736 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T20:33:32.075Z,1628195612.076 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2021-08-05T20:33:36.878Z,1628195616.878 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:33:41.354Z,1628195621.354 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210805T202613/Courier0004.lzma 2021-08-05T20:33:42.356Z,1628195622.356 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0004.lzma.bak 2021-08-05T20:33:42.357Z,1628195622.357 [DataOverHttps](INFO): SBD MOMSN=15839637 2021-08-05T20:33:51.867Z,1628195631.867 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:34:04.039Z,1628195644.039 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T20:34:05.507Z,1628195645.507 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20210805T202613/Courier0007.lzma 2021-08-05T20:34:06.510Z,1628195646.510 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0007.lzma.bak 2021-08-05T20:34:06.511Z,1628195646.511 [DataOverHttps](INFO): SBD MOMSN=15839642 2021-08-05T20:34:06.821Z,1628195646.821 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:34:21.365Z,1628195661.365 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:34:23.539Z,1628195663.539 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20210805T045057/Express0260.lzma 2021-08-05T20:34:24.541Z,1628195664.541 [DataOverHttps](INFO): Moved sent file to Logs/20210805T045057/Express0260.lzma.bak 2021-08-05T20:34:24.541Z,1628195664.541 [DataOverHttps](INFO): SBD MOMSN=15839646 2021-08-05T20:34:36.314Z,1628195676.314 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:34:41.484Z,1628195681.484 [DataOverHttps](INFO): Sending 1022 bytes from file Logs/20210805T202613/Express0001.lzma 2021-08-05T20:34:42.484Z,1628195682.484 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0001.lzma.bak 2021-08-05T20:34:42.484Z,1628195682.484 [DataOverHttps](INFO): SBD MOMSN=15839655 2021-08-05T20:34:50.862Z,1628195690.862 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T20:34:59.582Z,1628195699.582 [DataOverHttps](INFO): Sending 172 bytes from file Logs/20210805T202613/Express0005.lzma 2021-08-05T20:35:00.588Z,1628195700.588 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0005.lzma.bak 2021-08-05T20:35:00.588Z,1628195700.588 [DataOverHttps](INFO): SBD MOMSN=15839680 2021-08-05T20:35:06.626Z,1628195706.626 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-05T20:35:06.627Z,1628195706.627 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2021-08-05T20:35:06.630Z,1628195706.630 [BPC1](INFO): Received data from all battery sticks. 2021-08-05T20:35:17.631Z,1628195717.631 [DataOverHttps](INFO): Sending 313 bytes from file Logs/20210805T202613/Express0008.lzma 2021-08-05T20:35:18.632Z,1628195718.632 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0008.lzma.bak 2021-08-05T20:35:18.632Z,1628195718.632 [DataOverHttps](INFO): SBD MOMSN=15839691 2021-08-05T20:35:19.964Z,1628195719.964 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T20:35:19.964Z,1628195719.964 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T20:35:19.964Z,1628195719.964 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T20:36:17.381Z,1628195777.381 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T20:36:17.381Z,1628195777.381 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-08-05T20:39:19.934Z,1628195959.934 [CommandLine](IMPORTANT): got command show variable limitAft 2021-08-05T20:39:19.953Z,1628195959.953 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft (millimeter) 2021-08-05T20:39:29.640Z,1628195969.640 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft 2021-08-05T20:39:29.641Z,1628195969.641 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -27.000000 mm 2021-08-05T20:39:36.601Z,1628195976.601 [CommandLine](IMPORTANT): got command get platform_mass_position 2021-08-05T20:39:36.601Z,1628195976.601 [CommandLine](IMPORTANT): platform_mass_position -0.001000 m 2021-08-05T20:39:50.356Z,1628195990.356 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T20:39:50.356Z,1628195990.356 [DVL_micro](ERROR): Failed to parse: :BI,+00149,-00307,+00040, 2021-08-05T20:39:52.363Z,1628195992.363 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction -2.000000 centimeter 2021-08-05T20:39:52.379Z,1628195992.379 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2021-08-05T20:39:52.624Z,1628195992.624 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,DAT,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-08-05T20:39:58.721Z,1628195998.721 [CommandLine](IMPORTANT): got command show variable limitfwd 2021-08-05T20:39:58.754Z,1628195998.754 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter) 2021-08-05T20:40:11.450Z,1628196011.450 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd 2021-08-05T20:40:11.451Z,1628196011.451 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 34.000000 mm 2021-08-05T20:40:20.696Z,1628196020.696 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T20:40:20.696Z,1628196020.696 [Default:CheckIn:C.Wait] Stopped 2021-08-05T20:40:20.697Z,1628196020.697 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T20:40:20.697Z,1628196020.697 [Default:CheckIn:D] Running Loop=1 2021-08-05T20:40:21.103Z,1628196021.103 [Default:CheckIn:D] Stopped 2021-08-05T20:40:21.103Z,1628196021.103 [Default:CheckIn:E] Running Loop=1 2021-08-05T20:40:21.528Z,1628196021.528 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.609354 min 2021-08-05T20:40:21.528Z,1628196021.528 [Default:CheckIn:E] Stopped 2021-08-05T20:40:21.528Z,1628196021.528 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T20:40:21.528Z,1628196021.528 [Default:CheckIn] Stopped 2021-08-05T20:40:21.528Z,1628196021.528 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T20:40:21.529Z,1628196021.529 [Default:CheckIn](INFO): Running loop #2 2021-08-05T20:40:21.529Z,1628196021.529 [Default:CheckIn] Running Loop=2 2021-08-05T20:40:21.529Z,1628196021.529 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T20:40:21.529Z,1628196021.529 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T20:40:23.506Z,1628196023.506 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204023.00,A,4149.69561,N,08324.71267,W,0.117,4.18,050821,,,A*72 2021-08-05T20:40:23.508Z,1628196023.508 [NAL9602](INFO): GPS fix at 20210805T204023: (41.828260, -83.411878) 2021-08-05T20:40:23.520Z,1628196023.520 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T20:40:23.520Z,1628196023.520 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T20:40:31.670Z,1628196031.670 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210805T202613/Courier0010.lzma 2021-08-05T20:40:32.673Z,1628196032.673 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0010.lzma.bak 2021-08-05T20:40:32.673Z,1628196032.673 [DataOverHttps](INFO): SBD MOMSN=15839737 2021-08-05T20:40:49.671Z,1628196049.671 [DataOverHttps](INFO): Sending 377 bytes from file Logs/20210805T202613/Express0011.lzma 2021-08-05T20:40:50.672Z,1628196050.672 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0011.lzma.bak 2021-08-05T20:40:50.673Z,1628196050.673 [DataOverHttps](INFO): SBD MOMSN=15839743 2021-08-05T20:40:52.615Z,1628196052.615 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T20:40:52.616Z,1628196052.616 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T20:40:52.616Z,1628196052.616 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T20:40:54.214Z,1628196054.214 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2021-08-05T20:40:54.295Z,1628196054.295 [NAL9602](ERROR): received: +CSQ:1 OK 2021-08-05T20:41:12.015Z,1628196072.015 [NAL9602](INFO): SBD MO Status=0, MOMSN=3048, MT Status=0, MTMSN=0 2021-08-05T20:41:12.016Z,1628196072.016 [NAL9602](INFO): No messages in MT queue 2021-08-05T20:41:42.688Z,1628196102.688 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T20:43:02.323Z,1628196182.323 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T20:43:02.323Z,1628196182.323 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-08-05T20:44:13.115Z,1628196253.115 [DVL_micro](ERROR): Failed to parse: :R99,+9999.99,+99999.99 2021-08-05T20:45:53.331Z,1628196353.331 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T20:45:53.331Z,1628196353.331 [Default:CheckIn:C.Wait] Stopped 2021-08-05T20:45:53.332Z,1628196353.332 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T20:45:53.332Z,1628196353.332 [Default:CheckIn:D] Running Loop=1 2021-08-05T20:45:53.774Z,1628196353.774 [Default:CheckIn:D] Stopped 2021-08-05T20:45:53.774Z,1628196353.774 [Default:CheckIn:E] Running Loop=1 2021-08-05T20:45:54.182Z,1628196354.182 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.153743 min 2021-08-05T20:45:54.182Z,1628196354.182 [Default:CheckIn:E] Stopped 2021-08-05T20:45:54.182Z,1628196354.182 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T20:45:54.182Z,1628196354.182 [Default:CheckIn] Stopped 2021-08-05T20:45:54.186Z,1628196354.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T20:45:54.187Z,1628196354.187 [Default:CheckIn](INFO): Running loop #3 2021-08-05T20:45:54.187Z,1628196354.187 [Default:CheckIn] Running Loop=3 2021-08-05T20:45:54.187Z,1628196354.187 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T20:45:54.187Z,1628196354.187 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T20:45:56.140Z,1628196356.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204556.00,A,4149.69630,N,08324.70851,W,0.058,124.15,050821,,,D*7D 2021-08-05T20:45:56.142Z,1628196356.142 [NAL9602](INFO): GPS fix at 20210805T204556: (41.828272, -83.411809) 2021-08-05T20:45:56.162Z,1628196356.162 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T20:45:56.163Z,1628196356.163 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T20:46:05.654Z,1628196365.654 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210805T202613/Courier0013.lzma 2021-08-05T20:46:06.656Z,1628196366.656 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0013.lzma.bak 2021-08-05T20:46:06.656Z,1628196366.656 [DataOverHttps](INFO): SBD MOMSN=15839799 2021-08-05T20:46:20.477Z,1628196380.477 [NAL9602](INFO): SBD MO Status=0, MOMSN=3049, MT Status=0, MTMSN=0 2021-08-05T20:46:20.478Z,1628196380.478 [NAL9602](INFO): No messages in MT queue 2021-08-05T20:46:24.382Z,1628196384.382 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210805T202613/Express0014.lzma 2021-08-05T20:46:25.384Z,1628196385.384 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0014.lzma.bak 2021-08-05T20:46:25.384Z,1628196385.384 [DataOverHttps](INFO): SBD MOMSN=15839805 2021-08-05T20:46:27.015Z,1628196387.015 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T20:46:27.015Z,1628196387.015 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T20:46:27.015Z,1628196387.015 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T20:46:39.860Z,1628196399.860 [CommandLine](IMPORTANT): got command get platform_rudder_angle 2021-08-05T20:46:39.860Z,1628196399.860 [CommandLine](FAULT): Incomplete syntax. Try: help get 2021-08-05T20:46:42.756Z,1628196402.756 [CommandLine](IMPORTANT): got command get platform_rudder_angle degree 2021-08-05T20:46:42.756Z,1628196402.756 [CommandLine](IMPORTANT): platform_rudder_angle 0.017595 arcdeg 2021-08-05T20:46:51.186Z,1628196411.186 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T20:47:06.388Z,1628196426.388 [CommandLine](IMPORTANT): got command failComponent 2021-08-05T20:47:06.389Z,1628196426.389 [CommandLine](IMPORTANT): Failed components: 2021-08-05T20:47:06.389Z,1628196426.389 [CommandLine](IMPORTANT): No failed Components. 2021-08-05T20:47:15.959Z,1628196435.959 [CommandLine](IMPORTANT): got command failComponent hardware RudderServo 2021-08-05T20:47:15.960Z,1628196435.960 [RudderServo] Hardware Fault, FailCount= 1 2021-08-05T20:47:15.960Z,1628196435.960 [RudderServo](ERROR): Hardware Fault 2021-08-05T20:47:15.960Z,1628196435.960 [CommandLine](IMPORTANT): RudderServo failureMode is Hardware Fault 2021-08-05T20:47:16.259Z,1628196436.259 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2021-08-05T20:47:16.259Z,1628196436.259 [RudderServo](INFO): Powering down 2021-08-05T20:47:16.263Z,1628196436.263 [CBIT](ERROR): Hardware Fault in component: RudderServo 2021-08-05T20:47:17.061Z,1628196437.061 [CBIT](INFO): Clearing failed state for component RudderServo 2021-08-05T20:47:17.061Z,1628196437.061 [RudderServo] No Fault, FailCount= 1 2021-08-05T20:47:17.476Z,1628196437.476 [RudderServo](DEBUG): Initializing EZServoServo. 2021-08-05T20:47:17.477Z,1628196437.477 [RudderServo](DEBUG): Initializing RudderServo. 2021-08-05T20:47:34.255Z,1628196454.255 [CommandLine](IMPORTANT): got command get platform_rudder_angle degree 2021-08-05T20:47:34.256Z,1628196454.256 [CommandLine](IMPORTANT): platform_rudder_angle -0.017595 arcdeg 2021-08-05T20:49:30.814Z,1628196570.814 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T20:49:30.814Z,1628196570.814 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.9,0000.0,00 2021-08-05T20:51:27.717Z,1628196687.717 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T20:51:27.717Z,1628196687.717 [Default:CheckIn:C.Wait] Stopped 2021-08-05T20:51:27.717Z,1628196687.717 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T20:51:27.718Z,1628196687.718 [Default:CheckIn:D] Running Loop=1 2021-08-05T20:51:28.095Z,1628196688.095 [Default:CheckIn:D] Stopped 2021-08-05T20:51:28.095Z,1628196688.095 [Default:CheckIn:E] Running Loop=1 2021-08-05T20:51:28.489Z,1628196688.489 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.725883 min 2021-08-05T20:51:28.489Z,1628196688.489 [Default:CheckIn:E] Stopped 2021-08-05T20:51:28.490Z,1628196688.490 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T20:51:28.490Z,1628196688.490 [Default:CheckIn] Stopped 2021-08-05T20:51:28.490Z,1628196688.490 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T20:51:28.490Z,1628196688.490 [Default:CheckIn](INFO): Running loop #4 2021-08-05T20:51:28.510Z,1628196688.510 [Default:CheckIn] Running Loop=4 2021-08-05T20:51:28.511Z,1628196688.511 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T20:51:28.511Z,1628196688.511 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T20:51:30.474Z,1628196690.474 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205130.00,A,4149.69591,N,08324.70961,W,0.039,124.15,050821,,,D*75 2021-08-05T20:51:30.490Z,1628196690.490 [NAL9602](INFO): GPS fix at 20210805T205130: (41.828265, -83.411827) 2021-08-05T20:51:30.502Z,1628196690.502 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T20:51:30.502Z,1628196690.502 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T20:51:38.058Z,1628196698.058 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210805T202613/Courier0016.lzma 2021-08-05T20:51:39.060Z,1628196699.060 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0016.lzma.bak 2021-08-05T20:51:39.060Z,1628196699.060 [DataOverHttps](INFO): SBD MOMSN=15839849 2021-08-05T20:51:41.004Z,1628196701.004 [NAL9602](INFO): SBD MO Status=0, MOMSN=3050, MT Status=0, MTMSN=0 2021-08-05T20:51:41.004Z,1628196701.004 [NAL9602](INFO): No messages in MT queue 2021-08-05T20:52:06.618Z,1628196726.618 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20210805T202613/Express0017.lzma 2021-08-05T20:52:07.620Z,1628196727.620 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0017.lzma.bak 2021-08-05T20:52:07.620Z,1628196727.620 [DataOverHttps](INFO): SBD MOMSN=15839856 2021-08-05T20:52:08.995Z,1628196728.995 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T20:52:08.995Z,1628196728.995 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T20:52:08.996Z,1628196728.996 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T20:52:11.408Z,1628196731.408 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T20:56:21.254Z,1628196981.254 [DVL_micro](ERROR): only read 2 of 4 data items 2021-08-05T20:56:21.254Z,1628196981.254 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,++9999.99 2021-08-05T20:56:26.140Z,1628196986.140 [DVL_micro](ERROR): Failed to parse::WI,-00638,-03172,+01137,+0:BI,-00638,-03172,+01137,+00000,I 2021-08-05T20:57:09.747Z,1628197029.747 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T20:57:09.747Z,1628197029.747 [Default:CheckIn:C.Wait] Stopped 2021-08-05T20:57:09.747Z,1628197029.747 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T20:57:09.747Z,1628197029.747 [Default:CheckIn:D] Running Loop=1 2021-08-05T20:57:10.148Z,1628197030.148 [Default:CheckIn:D] Stopped 2021-08-05T20:57:10.148Z,1628197030.148 [Default:CheckIn:E] Running Loop=1 2021-08-05T20:57:10.555Z,1628197030.555 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.426770 min 2021-08-05T20:57:10.555Z,1628197030.555 [Default:CheckIn:E] Stopped 2021-08-05T20:57:10.556Z,1628197030.556 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T20:57:10.556Z,1628197030.556 [Default:CheckIn] Stopped 2021-08-05T20:57:10.556Z,1628197030.556 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T20:57:10.556Z,1628197030.556 [Default:CheckIn](INFO): Running loop #5 2021-08-05T20:57:10.556Z,1628197030.556 [Default:CheckIn] Running Loop=5 2021-08-05T20:57:10.556Z,1628197030.556 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T20:57:10.556Z,1628197030.556 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T20:57:12.567Z,1628197032.567 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205712.00,A,4149.69658,N,08324.70961,W,0.058,124.15,050821,,,D*72 2021-08-05T20:57:12.570Z,1628197032.570 [NAL9602](INFO): GPS fix at 20210805T205712: (41.828276, -83.411827) 2021-08-05T20:57:12.581Z,1628197032.581 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T20:57:12.582Z,1628197032.582 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T20:57:20.650Z,1628197040.650 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210805T202613/Courier0019.lzma 2021-08-05T20:57:21.652Z,1628197041.652 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0019.lzma.bak 2021-08-05T20:57:21.652Z,1628197041.652 [DataOverHttps](INFO): SBD MOMSN=15839914 2021-08-05T20:57:36.397Z,1628197056.397 [NAL9602](INFO): SBD MO Status=2, MOMSN=3051, MT Status=2, MTMSN=0 2021-08-05T20:57:36.398Z,1628197056.398 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-05T20:57:38.534Z,1628197058.534 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210805T202613/Express0020.lzma 2021-08-05T20:57:39.536Z,1628197059.536 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0020.lzma.bak 2021-08-05T20:57:39.536Z,1628197059.536 [DataOverHttps](INFO): SBD MOMSN=15839917 2021-08-05T20:57:41.298Z,1628197061.298 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T20:57:41.298Z,1628197061.298 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T20:57:41.298Z,1628197061.298 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T20:57:55.043Z,1628197075.043 [NAL9602](INFO): SBD MO Status=0, MOMSN=3051, MT Status=0, MTMSN=0 2021-08-05T20:57:55.043Z,1628197075.043 [NAL9602](INFO): No messages in MT queue 2021-08-05T20:58:25.777Z,1628197105.777 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:00:05.377Z,1628197205.377 [CommandLine](IMPORTANT): got command maintain clear 2021-08-05T21:00:05.446Z,1628197205.446 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,DAT,ESPComponent,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,LcmUniversalReporter,Reporter,LogSplitter, 2021-08-05T21:00:24.445Z,1628197224.445 [CommandLine](IMPORTANT): got command report mod platform_buoyancy_position 2021-08-05T21:00:24.709Z,1628197224.709 [Reporter](INFO): platform_buoyancy_position 947.324951 cc 2021-08-05T21:00:38.200Z,1628197238.200 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300.000000 cubic_centimeter 2021-08-05T21:00:38.204Z,1628197238.204 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2021-08-05T21:00:38.418Z,1628197238.418 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,DAT,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-08-05T21:00:40.894Z,1628197240.894 [Reporter](INFO): platform_buoyancy_position 960.486328 cc 2021-08-05T21:00:41.309Z,1628197241.309 [Reporter](INFO): platform_buoyancy_position 960.755005 cc 2021-08-05T21:00:41.689Z,1628197241.689 [Reporter](INFO): platform_buoyancy_position 960.217773 cc 2021-08-05T21:00:42.085Z,1628197242.085 [Reporter](INFO): platform_buoyancy_position 949.608032 cc 2021-08-05T21:00:42.481Z,1628197242.481 [Reporter](INFO): platform_buoyancy_position 947.324951 cc 2021-08-05T21:00:42.912Z,1628197242.912 [Reporter](INFO): platform_buoyancy_position 943.027344 cc 2021-08-05T21:00:43.361Z,1628197243.361 [Reporter](INFO): platform_buoyancy_position 938.864136 cc 2021-08-05T21:00:43.753Z,1628197243.753 [Reporter](INFO): platform_buoyancy_position 932.686279 cc 2021-08-05T21:00:44.093Z,1628197244.093 [Reporter](INFO): platform_buoyancy_position 930.000244 cc 2021-08-05T21:00:44.508Z,1628197244.508 [Reporter](INFO): platform_buoyancy_position 923.822510 cc 2021-08-05T21:00:44.905Z,1628197244.905 [Reporter](INFO): platform_buoyancy_position 919.390625 cc 2021-08-05T21:00:45.305Z,1628197245.305 [Reporter](INFO): platform_buoyancy_position 913.078491 cc 2021-08-05T21:00:45.705Z,1628197245.705 [Reporter](INFO): platform_buoyancy_position 908.646606 cc 2021-08-05T21:00:46.120Z,1628197246.120 [Reporter](INFO): platform_buoyancy_position 902.200195 cc 2021-08-05T21:00:46.529Z,1628197246.529 [Reporter](INFO): platform_buoyancy_position 897.768311 cc 2021-08-05T21:00:46.957Z,1628197246.957 [Reporter](INFO): platform_buoyancy_position 891.590454 cc 2021-08-05T21:00:47.325Z,1628197247.325 [Reporter](INFO): platform_buoyancy_position 887.158569 cc 2021-08-05T21:00:47.736Z,1628197247.736 [Reporter](INFO): platform_buoyancy_position 882.323730 cc 2021-08-05T21:00:48.137Z,1628197248.137 [Reporter](INFO): platform_buoyancy_position 876.414551 cc 2021-08-05T21:00:48.525Z,1628197248.525 [Reporter](INFO): platform_buoyancy_position 872.116943 cc 2021-08-05T21:00:48.893Z,1628197248.893 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T21:00:48.893Z,1628197248.893 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.5,089.0,000 2021-08-05T21:00:48.964Z,1628197248.964 [Reporter](INFO): platform_buoyancy_position 865.804932 cc 2021-08-05T21:00:49.360Z,1628197249.360 [Reporter](INFO): platform_buoyancy_position 861.372925 cc 2021-08-05T21:00:49.733Z,1628197249.733 [Reporter](INFO): platform_buoyancy_position 855.060913 cc 2021-08-05T21:00:50.156Z,1628197250.156 [Reporter](INFO): platform_buoyancy_position 850.629028 cc 2021-08-05T21:00:50.565Z,1628197250.565 [Reporter](INFO): platform_buoyancy_position 844.182617 cc 2021-08-05T21:00:50.971Z,1628197250.971 [Reporter](INFO): platform_buoyancy_position 839.885010 cc 2021-08-05T21:00:51.372Z,1628197251.372 [Reporter](INFO): platform_buoyancy_position 833.572876 cc 2021-08-05T21:00:51.768Z,1628197251.768 [Reporter](INFO): platform_buoyancy_position 829.140991 cc 2021-08-05T21:00:52.173Z,1628197252.173 [Reporter](INFO): platform_buoyancy_position 823.097473 cc 2021-08-05T21:00:52.577Z,1628197252.577 [Reporter](INFO): platform_buoyancy_position 818.531250 cc 2021-08-05T21:00:52.989Z,1628197252.989 [Reporter](INFO): platform_buoyancy_position 812.084900 cc 2021-08-05T21:00:53.401Z,1628197253.401 [Reporter](INFO): platform_buoyancy_position 807.787292 cc 2021-08-05T21:00:53.795Z,1628197253.795 [Reporter](INFO): platform_buoyancy_position 802.146667 cc 2021-08-05T21:00:54.180Z,1628197254.180 [Reporter](INFO): platform_buoyancy_position 796.908997 cc 2021-08-05T21:00:54.600Z,1628197254.600 [Reporter](INFO): platform_buoyancy_position 792.074158 cc 2021-08-05T21:00:55.017Z,1628197255.017 [Reporter](INFO): platform_buoyancy_position 786.164978 cc 2021-08-05T21:00:55.382Z,1628197255.382 [Reporter](INFO): platform_buoyancy_position 781.867371 cc 2021-08-05T21:00:55.797Z,1628197255.797 [Reporter](INFO): platform_buoyancy_position 775.420959 cc 2021-08-05T21:00:56.213Z,1628197256.213 [Reporter](INFO): platform_buoyancy_position 771.123352 cc 2021-08-05T21:00:56.661Z,1628197256.661 [Reporter](INFO): platform_buoyancy_position 764.676941 cc 2021-08-05T21:00:57.048Z,1628197257.048 [Reporter](INFO): platform_buoyancy_position 760.379395 cc 2021-08-05T21:00:57.413Z,1628197257.413 [Reporter](INFO): platform_buoyancy_position 755.678894 cc 2021-08-05T21:00:57.829Z,1628197257.829 [Reporter](INFO): platform_buoyancy_position 749.635376 cc 2021-08-05T21:00:58.241Z,1628197258.241 [Reporter](INFO): platform_buoyancy_position 743.994751 cc 2021-08-05T21:00:58.645Z,1628197258.645 [Reporter](INFO): platform_buoyancy_position 738.891357 cc 2021-08-05T21:00:59.059Z,1628197259.059 [Reporter](INFO): platform_buoyancy_position 732.579285 cc 2021-08-05T21:00:59.441Z,1628197259.441 [Reporter](INFO): platform_buoyancy_position 728.281677 cc 2021-08-05T21:00:59.861Z,1628197259.861 [Reporter](INFO): platform_buoyancy_position 723.178284 cc 2021-08-05T21:01:00.279Z,1628197260.279 [Reporter](INFO): platform_buoyancy_position 717.403381 cc 2021-08-05T21:01:00.678Z,1628197260.678 [Reporter](INFO): platform_buoyancy_position 711.091248 cc 2021-08-05T21:01:01.081Z,1628197261.081 [Reporter](INFO): platform_buoyancy_position 706.659363 cc 2021-08-05T21:01:01.474Z,1628197261.474 [Reporter](INFO): platform_buoyancy_position 702.093140 cc 2021-08-05T21:01:01.861Z,1628197261.861 [Reporter](INFO): platform_buoyancy_position 696.049683 cc 2021-08-05T21:01:02.277Z,1628197262.277 [Reporter](INFO): platform_buoyancy_position 691.617737 cc 2021-08-05T21:01:02.692Z,1628197262.692 [Reporter](INFO): platform_buoyancy_position 685.171387 cc 2021-08-05T21:01:03.097Z,1628197263.097 [Reporter](INFO): platform_buoyancy_position 678.859253 cc 2021-08-05T21:01:03.477Z,1628197263.477 [Reporter](INFO): platform_buoyancy_position 674.561646 cc 2021-08-05T21:01:03.881Z,1628197263.881 [Reporter](INFO): platform_buoyancy_position 669.995483 cc 2021-08-05T21:01:04.301Z,1628197264.301 [Reporter](INFO): platform_buoyancy_position 663.683350 cc 2021-08-05T21:01:04.725Z,1628197264.725 [Reporter](INFO): platform_buoyancy_position 659.385742 cc 2021-08-05T21:01:05.137Z,1628197265.137 [Reporter](INFO): platform_buoyancy_position 652.939392 cc 2021-08-05T21:01:05.505Z,1628197265.505 [Reporter](INFO): platform_buoyancy_position 648.641785 cc 2021-08-05T21:01:05.913Z,1628197265.913 [Reporter](INFO): platform_buoyancy_position 642.195374 cc 2021-08-05T21:01:06.333Z,1628197266.333 [Reporter](INFO): platform_buoyancy_position 637.897766 cc 2021-08-05T21:01:06.694Z,1628197266.694 [Reporter](INFO): platform_buoyancy_position 633.600159 cc 2021-08-05T21:01:07.120Z,1628197267.120 [Reporter](INFO): platform_buoyancy_position 627.153748 cc 2021-08-05T21:01:07.532Z,1628197267.532 [Reporter](INFO): platform_buoyancy_position 622.990479 cc 2021-08-05T21:01:07.941Z,1628197267.941 [Reporter](INFO): platform_buoyancy_position 616.544067 cc 2021-08-05T21:01:08.317Z,1628197268.317 [Reporter](INFO): platform_buoyancy_position 612.112183 cc 2021-08-05T21:01:08.749Z,1628197268.749 [Reporter](INFO): platform_buoyancy_position 605.800049 cc 2021-08-05T21:01:09.161Z,1628197269.161 [Reporter](INFO): platform_buoyancy_position 601.099548 cc 2021-08-05T21:01:09.557Z,1628197269.557 [Reporter](INFO): platform_buoyancy_position 595.056030 cc 2021-08-05T21:01:09.949Z,1628197269.949 [Reporter](INFO): platform_buoyancy_position 590.624146 cc 2021-08-05T21:01:10.385Z,1628197270.385 [Reporter](INFO): platform_buoyancy_position 584.312073 cc 2021-08-05T21:01:10.757Z,1628197270.757 [Reporter](INFO): platform_buoyancy_position 579.880127 cc 2021-08-05T21:01:11.168Z,1628197271.168 [Reporter](INFO): platform_buoyancy_position 573.568054 cc 2021-08-05T21:01:11.564Z,1628197271.564 [Reporter](INFO): platform_buoyancy_position 569.270447 cc 2021-08-05T21:01:11.979Z,1628197271.979 [Reporter](INFO): platform_buoyancy_position 562.958374 cc 2021-08-05T21:01:12.379Z,1628197272.379 [Reporter](INFO): platform_buoyancy_position 558.526428 cc 2021-08-05T21:01:12.783Z,1628197272.783 [Reporter](INFO): platform_buoyancy_position 554.228882 cc 2021-08-05T21:01:13.201Z,1628197273.201 [Reporter](INFO): platform_buoyancy_position 547.782471 cc 2021-08-05T21:01:13.597Z,1628197273.597 [Reporter](INFO): platform_buoyancy_position 542.410461 cc 2021-08-05T21:01:14.005Z,1628197274.005 [Reporter](INFO): platform_buoyancy_position 537.038452 cc 2021-08-05T21:01:14.397Z,1628197274.397 [Reporter](INFO): platform_buoyancy_position 532.740845 cc 2021-08-05T21:01:14.825Z,1628197274.825 [Reporter](INFO): platform_buoyancy_position 526.160156 cc 2021-08-05T21:01:15.296Z,1628197275.296 [Reporter](INFO): platform_buoyancy_position 519.713745 cc 2021-08-05T21:01:15.617Z,1628197275.617 [Reporter](INFO): platform_buoyancy_position 515.416138 cc 2021-08-05T21:01:16.033Z,1628197276.033 [Reporter](INFO): platform_buoyancy_position 511.118500 cc 2021-08-05T21:01:16.451Z,1628197276.451 [Reporter](INFO): platform_buoyancy_position 504.940735 cc 2021-08-05T21:01:16.881Z,1628197276.881 [Reporter](INFO): platform_buoyancy_position 498.360016 cc 2021-08-05T21:01:17.294Z,1628197277.294 [Reporter](INFO): platform_buoyancy_position 494.196777 cc 2021-08-05T21:01:17.677Z,1628197277.677 [Reporter](INFO): platform_buoyancy_position 489.764862 cc 2021-08-05T21:01:18.065Z,1628197278.065 [Reporter](INFO): platform_buoyancy_position 485.332947 cc 2021-08-05T21:01:18.473Z,1628197278.473 [Reporter](INFO): platform_buoyancy_position 478.886536 cc 2021-08-05T21:01:18.868Z,1628197278.868 [Reporter](INFO): platform_buoyancy_position 473.514526 cc 2021-08-05T21:01:19.257Z,1628197279.257 [Reporter](INFO): platform_buoyancy_position 468.142578 cc 2021-08-05T21:01:19.637Z,1628197279.637 [Reporter](INFO): platform_buoyancy_position 463.844971 cc 2021-08-05T21:01:20.045Z,1628197280.045 [Reporter](INFO): platform_buoyancy_position 457.398560 cc 2021-08-05T21:01:20.464Z,1628197280.464 [Reporter](INFO): platform_buoyancy_position 453.100952 cc 2021-08-05T21:01:20.869Z,1628197280.869 [Reporter](INFO): platform_buoyancy_position 446.788818 cc 2021-08-05T21:01:21.241Z,1628197281.241 [Reporter](INFO): platform_buoyancy_position 442.356934 cc 2021-08-05T21:01:21.661Z,1628197281.661 [Reporter](INFO): platform_buoyancy_position 436.179138 cc 2021-08-05T21:01:22.084Z,1628197282.084 [Reporter](INFO): platform_buoyancy_position 431.612976 cc 2021-08-05T21:01:22.457Z,1628197282.457 [Reporter](INFO): platform_buoyancy_position 425.300842 cc 2021-08-05T21:01:22.923Z,1628197282.923 [Reporter](INFO): platform_buoyancy_position 420.734619 cc 2021-08-05T21:01:23.285Z,1628197283.285 [Reporter](INFO): platform_buoyancy_position 416.034119 cc 2021-08-05T21:01:23.693Z,1628197283.693 [Reporter](INFO): platform_buoyancy_position 410.259216 cc 2021-08-05T21:01:24.077Z,1628197284.077 [Reporter](INFO): platform_buoyancy_position 403.812866 cc 2021-08-05T21:01:24.481Z,1628197284.481 [Reporter](INFO): platform_buoyancy_position 399.380920 cc 2021-08-05T21:01:24.897Z,1628197284.897 [Reporter](INFO): platform_buoyancy_position 393.068848 cc 2021-08-05T21:01:25.298Z,1628197285.298 [Reporter](INFO): platform_buoyancy_position 388.636963 cc 2021-08-05T21:01:25.701Z,1628197285.701 [Reporter](INFO): platform_buoyancy_position 384.205017 cc 2021-08-05T21:01:26.122Z,1628197286.122 [Reporter](INFO): platform_buoyancy_position 378.027222 cc 2021-08-05T21:01:26.523Z,1628197286.523 [Reporter](INFO): platform_buoyancy_position 373.595337 cc 2021-08-05T21:01:26.905Z,1628197286.905 [Reporter](INFO): platform_buoyancy_position 367.283264 cc 2021-08-05T21:01:27.325Z,1628197287.325 [Reporter](INFO): platform_buoyancy_position 362.851318 cc 2021-08-05T21:01:27.730Z,1628197287.730 [Reporter](INFO): platform_buoyancy_position 356.673523 cc 2021-08-05T21:01:28.113Z,1628197288.113 [Reporter](INFO): platform_buoyancy_position 352.241638 cc 2021-08-05T21:01:28.529Z,1628197288.529 [Reporter](INFO): platform_buoyancy_position 347.809753 cc 2021-08-05T21:01:28.949Z,1628197288.949 [Reporter](INFO): platform_buoyancy_position 341.497620 cc 2021-08-05T21:01:29.369Z,1628197289.369 [Reporter](INFO): platform_buoyancy_position 335.051270 cc 2021-08-05T21:01:29.733Z,1628197289.733 [Reporter](INFO): platform_buoyancy_position 330.619324 cc 2021-08-05T21:01:30.145Z,1628197290.145 [Reporter](INFO): platform_buoyancy_position 326.321716 cc 2021-08-05T21:01:30.564Z,1628197290.564 [Reporter](INFO): platform_buoyancy_position 320.009644 cc 2021-08-05T21:01:30.973Z,1628197290.973 [Reporter](INFO): platform_buoyancy_position 315.309143 cc 2021-08-05T21:01:31.404Z,1628197291.404 [Reporter](INFO): platform_buoyancy_position 309.399933 cc 2021-08-05T21:02:37.561Z,1628197357.561 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.000000 centimeter 2021-08-05T21:02:37.562Z,1628197357.562 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2021-08-05T21:02:37.685Z,1628197357.685 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,DAT,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2021-08-05T21:02:42.109Z,1628197362.109 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:02:42.109Z,1628197362.109 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:02:42.109Z,1628197362.109 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:02:42.109Z,1628197362.109 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:02:42.530Z,1628197362.530 [Default:CheckIn:D] Stopped 2021-08-05T21:02:42.530Z,1628197362.530 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:02:42.919Z,1628197362.919 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.966471 min 2021-08-05T21:02:42.919Z,1628197362.919 [Default:CheckIn:E] Stopped 2021-08-05T21:02:42.919Z,1628197362.919 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:02:42.919Z,1628197362.919 [Default:CheckIn] Stopped 2021-08-05T21:02:42.919Z,1628197362.919 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:02:42.919Z,1628197362.919 [Default:CheckIn](INFO): Running loop #6 2021-08-05T21:02:42.920Z,1628197362.920 [Default:CheckIn] Running Loop=6 2021-08-05T21:02:42.920Z,1628197362.920 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:02:42.920Z,1628197362.920 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:02:44.918Z,1628197364.918 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210244.00,A,4149.69429,N,08324.71359,W,0.156,230.29,050821,,,D*72 2021-08-05T21:02:44.924Z,1628197364.924 [NAL9602](INFO): GPS fix at 20210805T210244: (41.828238, -83.411893) 2021-08-05T21:02:44.973Z,1628197364.973 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:02:44.973Z,1628197364.973 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:02:51.336Z,1628197371.336 [CommandLine](IMPORTANT): got command get platform_mass_position centimeter 2021-08-05T21:02:51.337Z,1628197371.337 [CommandLine](IMPORTANT): platform_mass_position 0.786970 cm 2021-08-05T21:02:54.110Z,1628197374.110 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210805T202613/Courier0022.lzma 2021-08-05T21:02:55.112Z,1628197375.112 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0022.lzma.bak 2021-08-05T21:02:55.112Z,1628197375.112 [DataOverHttps](INFO): SBD MOMSN=15839964 2021-08-05T21:02:56.375Z,1628197376.375 [CommandLine](IMPORTANT): got command get platform_mass_position centimeter 2021-08-05T21:02:56.376Z,1628197376.376 [CommandLine](IMPORTANT): platform_mass_position 1.000430 cm 2021-08-05T21:03:05.930Z,1628197385.930 [NAL9602](INFO): SBD MO Status=2, MOMSN=3052, MT Status=2, MTMSN=0 2021-08-05T21:03:05.931Z,1628197385.931 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-05T21:03:09.119Z,1628197389.119 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd 2021-08-05T21:03:09.119Z,1628197389.119 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 34.000000 mm 2021-08-05T21:03:13.122Z,1628197393.122 [DataOverHttps](INFO): Sending 270 bytes from file Logs/20210805T202613/Express0023.lzma 2021-08-05T21:03:14.124Z,1628197394.124 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0023.lzma.bak 2021-08-05T21:03:14.124Z,1628197394.124 [DataOverHttps](INFO): SBD MOMSN=15839967 2021-08-05T21:03:15.653Z,1628197395.653 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:03:15.653Z,1628197395.653 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:03:15.653Z,1628197395.653 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:03:24.535Z,1628197404.535 [NAL9602](INFO): SBD MO Status=0, MOMSN=3052, MT Status=0, MTMSN=0 2021-08-05T21:03:24.535Z,1628197404.535 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:03:25.614Z,1628197405.614 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.500000 centimeter 2021-08-05T21:03:55.264Z,1628197435.264 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:04:15.881Z,1628197455.881 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 250.000000 cubic_centimeter 2021-08-05T21:04:18.057Z,1628197458.057 [Reporter](INFO): platform_buoyancy_position 298.387329 cc 2021-08-05T21:04:18.813Z,1628197458.813 [Reporter](INFO): platform_buoyancy_position 296.238525 cc 2021-08-05T21:04:19.213Z,1628197459.213 [Reporter](INFO): platform_buoyancy_position 289.792145 cc 2021-08-05T21:04:19.666Z,1628197459.666 [BuoyancyServo](ERROR): getPosition uart error serial timeout 2021-08-05T21:04:19.667Z,1628197459.667 [BuoyancyServo](FAULT): Buoyancy getPosition uart error.serial timeout 2021-08-05T21:04:19.667Z,1628197459.667 [BuoyancyServo] Communications Fault, FailCount= 1 2021-08-05T21:04:19.667Z,1628197459.667 [BuoyancyServo](ERROR): Communications Fault 2021-08-05T21:04:19.672Z,1628197459.672 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2021-08-05T21:04:21.663Z,1628197461.663 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2021-08-05T21:04:21.664Z,1628197461.664 [BuoyancyServo](INFO): Powering down 2021-08-05T21:04:22.425Z,1628197462.425 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2021-08-05T21:04:22.426Z,1628197462.425 [BuoyancyServo] No Fault, FailCount= 1 2021-08-05T21:04:22.836Z,1628197462.836 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2021-08-05T21:04:22.837Z,1628197462.837 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2021-08-05T21:04:26.525Z,1628197466.525 [Reporter](INFO): platform_buoyancy_position 274.750549 cc 2021-08-05T21:04:26.898Z,1628197466.898 [Reporter](INFO): platform_buoyancy_position 274.616241 cc 2021-08-05T21:04:27.313Z,1628197467.313 [Reporter](INFO): platform_buoyancy_position 274.750549 cc 2021-08-05T21:04:27.697Z,1628197467.697 [Reporter](INFO): platform_buoyancy_position 268.304138 cc 2021-08-05T21:04:28.105Z,1628197468.105 [Reporter](INFO): platform_buoyancy_position 264.006531 cc 2021-08-05T21:04:28.565Z,1628197468.565 [Reporter](INFO): platform_buoyancy_position 259.574646 cc 2021-08-05T21:05:31.880Z,1628197531.880 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T21:05:31.880Z,1628197531.880 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.,1489.0,0+00000,+0000,+0000,+00000,+00000,+00000,+00000,I 2021-08-05T21:06:27.730Z,1628197587.730 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:06:27.731Z,1628197587.731 [DVL_micro](ERROR): Failed to parse: :RD,+99002.78,+0000.58,+0003.75 2021-08-05T21:08:08.388Z,1628197688.388 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.000000 centimeter 2021-08-05T21:08:16.475Z,1628197696.475 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:08:16.476Z,1628197696.476 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:08:16.476Z,1628197696.476 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:08:16.476Z,1628197696.476 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:08:16.840Z,1628197696.840 [Default:CheckIn:D] Stopped 2021-08-05T21:08:16.840Z,1628197696.840 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:08:17.284Z,1628197697.284 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.538310 min 2021-08-05T21:08:17.284Z,1628197697.284 [Default:CheckIn:E] Stopped 2021-08-05T21:08:17.284Z,1628197697.284 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:08:17.285Z,1628197697.285 [Default:CheckIn] Stopped 2021-08-05T21:08:17.285Z,1628197697.285 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:08:17.285Z,1628197697.285 [Default:CheckIn](INFO): Running loop #7 2021-08-05T21:08:17.285Z,1628197697.285 [Default:CheckIn] Running Loop=7 2021-08-05T21:08:17.285Z,1628197697.285 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:08:17.285Z,1628197697.285 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:08:19.262Z,1628197699.262 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210819.00,A,4149.69535,N,08324.71349,W,0.019,230.29,050821,,,D*77 2021-08-05T21:08:19.265Z,1628197699.265 [NAL9602](INFO): GPS fix at 20210805T210819: (41.828256, -83.411891) 2021-08-05T21:08:19.285Z,1628197699.285 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:08:19.285Z,1628197699.285 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:08:20.603Z,1628197700.603 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 150.000000 cubic_centimeter 2021-08-05T21:08:23.088Z,1628197703.088 [Reporter](INFO): platform_buoyancy_position 252.725357 cc 2021-08-05T21:08:23.402Z,1628197703.402 [Reporter](INFO): platform_buoyancy_position 253.262558 cc 2021-08-05T21:08:23.819Z,1628197703.819 [Reporter](INFO): platform_buoyancy_position 251.248047 cc 2021-08-05T21:08:24.222Z,1628197704.222 [Reporter](INFO): platform_buoyancy_position 244.801636 cc 2021-08-05T21:08:24.634Z,1628197704.634 [Reporter](INFO): platform_buoyancy_position 240.504028 cc 2021-08-05T21:08:25.109Z,1628197705.109 [Reporter](INFO): platform_buoyancy_position 236.206421 cc 2021-08-05T21:08:25.537Z,1628197705.537 [Reporter](INFO): platform_buoyancy_position 229.625732 cc 2021-08-05T21:08:25.925Z,1628197705.925 [Reporter](INFO): platform_buoyancy_position 225.328125 cc 2021-08-05T21:08:26.304Z,1628197706.304 [Reporter](INFO): platform_buoyancy_position 221.030518 cc 2021-08-05T21:08:26.713Z,1628197706.713 [Reporter](INFO): platform_buoyancy_position 214.584137 cc 2021-08-05T21:08:27.173Z,1628197707.173 [Reporter](INFO): platform_buoyancy_position 208.272034 cc 2021-08-05T21:08:27.489Z,1628197707.489 [Reporter](INFO): platform_buoyancy_position 203.974426 cc 2021-08-05T21:08:27.894Z,1628197707.894 [Reporter](INFO): platform_buoyancy_position 199.676819 cc 2021-08-05T21:08:28.296Z,1628197708.296 [Reporter](INFO): platform_buoyancy_position 193.230438 cc 2021-08-05T21:08:28.729Z,1628197708.729 [Reporter](INFO): platform_buoyancy_position 188.529938 cc 2021-08-05T21:08:29.173Z,1628197709.173 [Reporter](INFO): platform_buoyancy_position 182.352142 cc 2021-08-05T21:08:29.552Z,1628197709.552 [Reporter](INFO): platform_buoyancy_position 178.054535 cc 2021-08-05T21:08:29.957Z,1628197709.957 [Reporter](INFO): platform_buoyancy_position 171.876740 cc 2021-08-05T21:08:30.364Z,1628197710.364 [Reporter](INFO): platform_buoyancy_position 167.444824 cc 2021-08-05T21:08:30.711Z,1628197710.711 [Reporter](INFO): platform_buoyancy_position 163.012939 cc 2021-08-05T21:08:31.071Z,1628197711.071 [NAL9602](INFO): SBD MO Status=0, MOMSN=3053, MT Status=0, MTMSN=0 2021-08-05T21:08:31.071Z,1628197711.071 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:08:31.241Z,1628197711.241 [Reporter](INFO): platform_buoyancy_position 156.700836 cc 2021-08-05T21:08:31.466Z,1628197711.466 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210805T202613/Courier0025.lzma 2021-08-05T21:08:32.468Z,1628197712.468 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0025.lzma.bak 2021-08-05T21:08:32.468Z,1628197712.468 [DataOverHttps](INFO): SBD MOMSN=15840031 2021-08-05T21:08:37.146Z,1628197717.146 [DVL_micro](ERROR): DVL uart error: serial timeout 2021-08-05T21:08:37.147Z,1628197717.147 [DVL_micro] Communications Fault, FailCount= 1 2021-08-05T21:08:37.147Z,1628197717.147 [DVL_micro](ERROR): Communications Fault 2021-08-05T21:08:37.149Z,1628197717.149 [DVL_micro](ERROR): Failed to parse: 2021-08-05T21:08:37.238Z,1628197717.238 [CBIT](ERROR): Communications Fault in component: DVL_micro 2021-08-05T21:08:37.552Z,1628197717.552 [DVL_micro](INFO): Powering down 2021-08-05T21:08:38.407Z,1628197718.407 [CBIT](INFO): Clearing failed state for component DVL_micro 2021-08-05T21:08:38.407Z,1628197718.407 [DVL_micro] No Fault, FailCount= 1 2021-08-05T21:08:49.423Z,1628197729.423 [DataOverHttps](INFO): Sending 387 bytes from file Logs/20210805T202613/Express0026.lzma 2021-08-05T21:08:50.424Z,1628197730.424 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0026.lzma.bak 2021-08-05T21:08:50.425Z,1628197730.425 [DataOverHttps](INFO): SBD MOMSN=15840034 2021-08-05T21:08:52.053Z,1628197732.053 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:08:52.054Z,1628197732.054 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:08:52.054Z,1628197732.054 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:09:01.720Z,1628197741.720 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:09:37.083Z,1628197777.083 [CommandLine](IMPORTANT): got command get depth 2021-08-05T21:09:37.083Z,1628197777.083 [CommandLine](IMPORTANT): depth -0.108117 m 2021-08-05T21:09:45.807Z,1628197785.807 [CommandLine](IMPORTANT): got command show variable depth_keller.offset 2021-08-05T21:09:45.846Z,1628197785.846 [CommandLine](IMPORTANT): Depth_Keller.offset (decibar) 2021-08-05T21:09:50.024Z,1628197790.024 [CommandLine](IMPORTANT): got command get Depth_Keller.offset 2021-08-05T21:09:50.025Z,1628197790.025 [CommandLine](IMPORTANT): Depth_Keller.offset 3.396000 db 2021-08-05T21:09:52.225Z,1628197792.225 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+26.2,0000.,000 2021-08-05T21:10:23.159Z,1628197823.159 [CommandLine](IMPORTANT): got command configSet Depth_Keller.offset 3.290000 decibar persist 2021-08-05T21:10:25.439Z,1628197825.439 [CommandLine](IMPORTANT): got command get depth 2021-08-05T21:10:25.439Z,1628197825.439 [CommandLine](IMPORTANT): depth -0.183480 m 2021-08-05T21:10:38.567Z,1628197838.567 [CommandLine](IMPORTANT): got command configSet Depth_Keller.offset 3.490000 decibar persist 2021-08-05T21:10:40.400Z,1628197840.400 [CommandLine](IMPORTANT): got command get depth 2021-08-05T21:10:40.401Z,1628197840.401 [CommandLine](IMPORTANT): depth -0.029973 m 2021-08-05T21:10:59.599Z,1628197859.599 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 300.000000 cubic_centimeter 2021-08-05T21:11:01.847Z,1628197861.847 [Reporter](INFO): platform_buoyancy_position 152.268921 cc 2021-08-05T21:11:02.605Z,1628197862.605 [Reporter](INFO): platform_buoyancy_position 152.403229 cc 2021-08-05T21:11:03.024Z,1628197863.024 [Reporter](INFO): platform_buoyancy_position 154.552032 cc 2021-08-05T21:11:03.429Z,1628197863.429 [Reporter](INFO): platform_buoyancy_position 160.998413 cc 2021-08-05T21:11:03.841Z,1628197863.841 [Reporter](INFO): platform_buoyancy_position 167.310516 cc 2021-08-05T21:11:04.221Z,1628197864.221 [Reporter](INFO): platform_buoyancy_position 171.608124 cc 2021-08-05T21:11:04.624Z,1628197864.624 [Reporter](INFO): platform_buoyancy_position 178.188843 cc 2021-08-05T21:11:05.045Z,1628197865.045 [Reporter](INFO): platform_buoyancy_position 182.486420 cc 2021-08-05T21:11:05.489Z,1628197865.489 [Reporter](INFO): platform_buoyancy_position 188.932831 cc 2021-08-05T21:11:05.881Z,1628197865.881 [Reporter](INFO): platform_buoyancy_position 195.110626 cc 2021-08-05T21:11:06.245Z,1628197866.245 [Reporter](INFO): platform_buoyancy_position 199.542542 cc 2021-08-05T21:11:06.672Z,1628197866.672 [Reporter](INFO): platform_buoyancy_position 203.974426 cc 2021-08-05T21:11:07.041Z,1628197867.041 [Reporter](INFO): platform_buoyancy_position 208.272034 cc 2021-08-05T21:11:07.457Z,1628197867.457 [Reporter](INFO): platform_buoyancy_position 214.718445 cc 2021-08-05T21:11:07.883Z,1628197867.883 [Reporter](INFO): platform_buoyancy_position 219.821838 cc 2021-08-05T21:11:08.265Z,1628197868.265 [Reporter](INFO): platform_buoyancy_position 225.328125 cc 2021-08-05T21:11:08.657Z,1628197868.657 [Reporter](INFO): platform_buoyancy_position 230.968719 cc 2021-08-05T21:11:09.117Z,1628197869.117 [Reporter](INFO): platform_buoyancy_position 236.340729 cc 2021-08-05T21:11:09.485Z,1628197869.485 [Reporter](INFO): platform_buoyancy_position 240.504028 cc 2021-08-05T21:11:09.904Z,1628197869.904 [Reporter](INFO): platform_buoyancy_position 246.950424 cc 2021-08-05T21:11:10.273Z,1628197870.273 [Reporter](INFO): platform_buoyancy_position 251.248047 cc 2021-08-05T21:11:10.689Z,1628197870.689 [Reporter](INFO): platform_buoyancy_position 257.425842 cc 2021-08-05T21:11:11.101Z,1628197871.101 [Reporter](INFO): platform_buoyancy_position 262.126343 cc 2021-08-05T21:11:11.493Z,1628197871.493 [Reporter](INFO): platform_buoyancy_position 268.304138 cc 2021-08-05T21:11:11.897Z,1628197871.897 [Reporter](INFO): platform_buoyancy_position 272.870331 cc 2021-08-05T21:11:12.331Z,1628197872.331 [Reporter](INFO): platform_buoyancy_position 279.182434 cc 2021-08-05T21:11:12.697Z,1628197872.697 [Reporter](INFO): platform_buoyancy_position 283.480042 cc 2021-08-05T21:11:13.113Z,1628197873.113 [Reporter](INFO): platform_buoyancy_position 289.120636 cc 2021-08-05T21:11:13.545Z,1628197873.545 [Reporter](INFO): platform_buoyancy_position 294.089722 cc 2021-08-05T21:12:56.439Z,1628197976.439 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.500000 centimeter 2021-08-05T21:12:59.347Z,1628197979.347 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T21:12:59.347Z,1628197979.347 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.,1489.0,000 2021-08-05T21:13:18.519Z,1628197998.519 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 200.000000 cubic_centimeter 2021-08-05T21:13:20.461Z,1628198000.461 [Reporter](INFO): platform_buoyancy_position 298.387329 cc 2021-08-05T21:13:20.846Z,1628198000.846 [Reporter](INFO): platform_buoyancy_position 300.536133 cc 2021-08-05T21:13:21.241Z,1628198001.241 [Reporter](INFO): platform_buoyancy_position 298.387329 cc 2021-08-05T21:13:21.641Z,1628198001.641 [Reporter](INFO): platform_buoyancy_position 291.940948 cc 2021-08-05T21:13:22.025Z,1628198002.025 [Reporter](INFO): platform_buoyancy_position 287.643341 cc 2021-08-05T21:13:22.445Z,1628198002.445 [Reporter](INFO): platform_buoyancy_position 283.345734 cc 2021-08-05T21:13:22.829Z,1628198002.829 [Reporter](INFO): platform_buoyancy_position 278.376648 cc 2021-08-05T21:13:23.309Z,1628198003.309 [Reporter](INFO): platform_buoyancy_position 270.587250 cc 2021-08-05T21:13:23.673Z,1628198003.673 [Reporter](INFO): platform_buoyancy_position 266.155334 cc 2021-08-05T21:13:24.087Z,1628198004.087 [Reporter](INFO): platform_buoyancy_position 261.992035 cc 2021-08-05T21:13:24.509Z,1628198004.509 [Reporter](INFO): platform_buoyancy_position 255.545624 cc 2021-08-05T21:13:24.873Z,1628198004.873 [Reporter](INFO): platform_buoyancy_position 251.382324 cc 2021-08-05T21:13:25.289Z,1628198005.289 [Reporter](INFO): platform_buoyancy_position 245.473145 cc 2021-08-05T21:13:25.680Z,1628198005.680 [Reporter](INFO): platform_buoyancy_position 240.504028 cc 2021-08-05T21:13:26.113Z,1628198006.113 [Reporter](INFO): platform_buoyancy_position 236.206421 cc 2021-08-05T21:13:26.504Z,1628198006.504 [Reporter](INFO): platform_buoyancy_position 229.760040 cc 2021-08-05T21:13:26.889Z,1628198006.889 [Reporter](INFO): platform_buoyancy_position 225.328125 cc 2021-08-05T21:13:27.313Z,1628198007.313 [Reporter](INFO): platform_buoyancy_position 219.150330 cc 2021-08-05T21:13:27.725Z,1628198007.725 [Reporter](INFO): platform_buoyancy_position 214.584137 cc 2021-08-05T21:13:28.130Z,1628198008.130 [Reporter](INFO): platform_buoyancy_position 210.420837 cc 2021-08-05T21:13:28.533Z,1628198008.533 [Reporter](INFO): platform_buoyancy_position 205.988922 cc 2021-08-05T21:13:29.818Z,1628198009.818 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 1.750000 centimeter 2021-08-05T21:13:52.726Z,1628198032.726 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:13:52.726Z,1628198032.726 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:13:52.726Z,1628198032.726 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:13:52.726Z,1628198032.726 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:13:53.160Z,1628198033.160 [Default:CheckIn:D] Stopped 2021-08-05T21:13:53.160Z,1628198033.160 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:13:53.526Z,1628198033.526 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.143644 min 2021-08-05T21:13:53.526Z,1628198033.526 [Default:CheckIn:E] Stopped 2021-08-05T21:13:53.526Z,1628198033.526 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:13:53.526Z,1628198033.526 [Default:CheckIn] Stopped 2021-08-05T21:13:53.527Z,1628198033.527 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:13:53.527Z,1628198033.527 [Default:CheckIn](INFO): Running loop #8 2021-08-05T21:13:53.527Z,1628198033.527 [Default:CheckIn] Running Loop=8 2021-08-05T21:13:53.527Z,1628198033.527 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:13:53.527Z,1628198033.527 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:13:55.512Z,1628198035.512 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211355.00,A,4149.69443,N,08324.71401,W,0.097,201.30,050821,,,D*72 2021-08-05T21:13:55.514Z,1628198035.514 [NAL9602](INFO): GPS fix at 20210805T211355: (41.828240, -83.411900) 2021-08-05T21:13:55.535Z,1628198035.535 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:13:55.535Z,1628198035.535 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:14:04.046Z,1628198044.046 [NAL9602](INFO): SBD MO Status=0, MOMSN=3054, MT Status=0, MTMSN=0 2021-08-05T21:14:04.046Z,1628198044.046 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:14:07.398Z,1628198047.398 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210805T202613/Courier0028.lzma 2021-08-05T21:14:08.400Z,1628198048.400 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0028.lzma.bak 2021-08-05T21:14:08.400Z,1628198048.400 [DataOverHttps](INFO): SBD MOMSN=15840084 2021-08-05T21:14:30.419Z,1628198070.419 [DataOverHttps](INFO): Sending 429 bytes from file Logs/20210805T202613/Express0029.lzma 2021-08-05T21:14:31.420Z,1628198071.420 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0029.lzma.bak 2021-08-05T21:14:31.421Z,1628198071.421 [DataOverHttps](INFO): SBD MOMSN=15840087 2021-08-05T21:14:33.389Z,1628198073.389 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 2.000000 centimeter 2021-08-05T21:14:33.648Z,1628198073.648 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:14:33.648Z,1628198073.648 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:14:33.648Z,1628198073.648 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:14:34.852Z,1628198074.852 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:15:22.447Z,1628198122.447 [CommandLine](IMPORTANT): got command maintain clear 2021-08-05T21:15:22.640Z,1628198122.640 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,DAT,ESPComponent,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,LcmUniversalReporter,Reporter,LogSplitter, 2021-08-05T21:15:25.085Z,1628198125.085 [Reporter](INFO): platform_buoyancy_position 202.497131 cc 2021-08-05T21:15:25.420Z,1628198125.420 [Reporter](INFO): platform_buoyancy_position 203.974426 cc 2021-08-05T21:15:26.236Z,1628198126.236 [Reporter](INFO): platform_buoyancy_position 204.645935 cc 2021-08-05T21:15:26.685Z,1628198126.685 [Reporter](INFO): platform_buoyancy_position 210.420837 cc 2021-08-05T21:15:27.064Z,1628198127.064 [Reporter](INFO): platform_buoyancy_position 216.732941 cc 2021-08-05T21:15:27.468Z,1628198127.468 [Reporter](INFO): platform_buoyancy_position 221.299133 cc 2021-08-05T21:15:27.838Z,1628198127.838 [Reporter](INFO): platform_buoyancy_position 227.476929 cc 2021-08-05T21:15:28.248Z,1628198128.248 [Reporter](INFO): platform_buoyancy_position 231.908844 cc 2021-08-05T21:15:28.668Z,1628198128.668 [Reporter](INFO): platform_buoyancy_position 238.220947 cc 2021-08-05T21:15:29.064Z,1628198129.064 [Reporter](INFO): platform_buoyancy_position 244.533035 cc 2021-08-05T21:15:29.461Z,1628198129.461 [Reporter](INFO): platform_buoyancy_position 249.099243 cc 2021-08-05T21:15:29.878Z,1628198129.878 [Reporter](INFO): platform_buoyancy_position 253.531128 cc 2021-08-05T21:15:30.281Z,1628198130.281 [Reporter](INFO): platform_buoyancy_position 259.708923 cc 2021-08-05T21:15:30.708Z,1628198130.708 [Reporter](INFO): platform_buoyancy_position 265.886749 cc 2021-08-05T21:15:31.085Z,1628198131.085 [Reporter](INFO): platform_buoyancy_position 270.452942 cc 2021-08-05T21:15:31.480Z,1628198131.480 [Reporter](INFO): platform_buoyancy_position 275.019135 cc 2021-08-05T21:15:31.874Z,1628198131.874 [Reporter](INFO): platform_buoyancy_position 281.196930 cc 2021-08-05T21:15:32.300Z,1628198132.300 [Reporter](INFO): platform_buoyancy_position 285.628845 cc 2021-08-05T21:15:32.709Z,1628198132.709 [Reporter](INFO): platform_buoyancy_position 291.940948 cc 2021-08-05T21:15:33.104Z,1628198133.104 [Reporter](INFO): platform_buoyancy_position 296.238525 cc 2021-08-05T21:15:33.489Z,1628198133.489 [Reporter](INFO): platform_buoyancy_position 301.610535 cc 2021-08-05T21:15:33.914Z,1628198133.914 [Reporter](INFO): platform_buoyancy_position 307.116852 cc 2021-08-05T21:15:34.309Z,1628198134.309 [Reporter](INFO): platform_buoyancy_position 312.488831 cc 2021-08-05T21:15:34.728Z,1628198134.728 [Reporter](INFO): platform_buoyancy_position 317.726562 cc 2021-08-05T21:15:35.096Z,1628198135.096 [Reporter](INFO): platform_buoyancy_position 322.158447 cc 2021-08-05T21:15:35.517Z,1628198135.517 [Reporter](INFO): platform_buoyancy_position 328.470520 cc 2021-08-05T21:15:35.921Z,1628198135.921 [Reporter](INFO): platform_buoyancy_position 332.902466 cc 2021-08-05T21:15:36.340Z,1628198136.340 [Reporter](INFO): platform_buoyancy_position 339.214539 cc 2021-08-05T21:15:36.744Z,1628198136.744 [Reporter](INFO): platform_buoyancy_position 343.646423 cc 2021-08-05T21:15:37.165Z,1628198137.165 [Reporter](INFO): platform_buoyancy_position 348.615540 cc 2021-08-05T21:15:37.548Z,1628198137.548 [Reporter](INFO): platform_buoyancy_position 353.047424 cc 2021-08-05T21:15:37.944Z,1628198137.944 [Reporter](INFO): platform_buoyancy_position 358.822327 cc 2021-08-05T21:15:38.335Z,1628198138.335 [Reporter](INFO): platform_buoyancy_position 365.000122 cc 2021-08-05T21:15:38.752Z,1628198138.752 [Reporter](INFO): platform_buoyancy_position 369.700623 cc 2021-08-05T21:15:39.156Z,1628198139.156 [Reporter](INFO): platform_buoyancy_position 375.744141 cc 2021-08-05T21:15:39.548Z,1628198139.548 [Reporter](INFO): platform_buoyancy_position 380.310364 cc 2021-08-05T21:15:39.952Z,1628198139.952 [Reporter](INFO): platform_buoyancy_position 386.622437 cc 2021-08-05T21:15:40.397Z,1628198140.397 [Reporter](INFO): platform_buoyancy_position 391.860168 cc 2021-08-05T21:15:40.785Z,1628198140.785 [Reporter](INFO): platform_buoyancy_position 397.232117 cc 2021-08-05T21:15:41.156Z,1628198141.156 [Reporter](INFO): platform_buoyancy_position 401.664062 cc 2021-08-05T21:15:41.565Z,1628198141.565 [Reporter](INFO): platform_buoyancy_position 407.976135 cc 2021-08-05T21:15:41.972Z,1628198141.972 [Reporter](INFO): platform_buoyancy_position 412.408020 cc 2021-08-05T21:15:42.411Z,1628198142.411 [Reporter](INFO): platform_buoyancy_position 418.854431 cc 2021-08-05T21:15:42.788Z,1628198142.788 [Reporter](INFO): platform_buoyancy_position 423.152039 cc 2021-08-05T21:15:43.184Z,1628198143.184 [Reporter](INFO): platform_buoyancy_position 429.464172 cc 2021-08-05T21:15:43.605Z,1628198143.605 [Reporter](INFO): platform_buoyancy_position 434.164673 cc 2021-08-05T21:15:44.008Z,1628198144.008 [Reporter](INFO): platform_buoyancy_position 438.865173 cc 2021-08-05T21:15:44.421Z,1628198144.421 [Reporter](INFO): platform_buoyancy_position 444.640076 cc 2021-08-05T21:15:44.800Z,1628198144.800 [Reporter](INFO): platform_buoyancy_position 449.877747 cc 2021-08-05T21:15:45.212Z,1628198145.212 [Reporter](INFO): platform_buoyancy_position 455.249756 cc 2021-08-05T21:15:45.609Z,1628198145.609 [Reporter](INFO): platform_buoyancy_position 460.621765 cc 2021-08-05T21:15:46.008Z,1628198146.008 [Reporter](INFO): platform_buoyancy_position 465.993774 cc 2021-08-05T21:15:46.461Z,1628198146.461 [Reporter](INFO): platform_buoyancy_position 472.440125 cc 2021-08-05T21:15:46.832Z,1628198146.832 [Reporter](INFO): platform_buoyancy_position 476.872070 cc 2021-08-05T21:15:47.272Z,1628198147.272 [Reporter](INFO): platform_buoyancy_position 483.049866 cc 2021-08-05T21:15:47.632Z,1628198147.632 [Reporter](INFO): platform_buoyancy_position 487.481750 cc 2021-08-05T21:15:48.037Z,1628198148.037 [Reporter](INFO): platform_buoyancy_position 491.913635 cc 2021-08-05T21:15:48.465Z,1628198148.465 [Reporter](INFO): platform_buoyancy_position 498.225800 cc 2021-08-05T21:15:48.839Z,1628198148.839 [Reporter](INFO): platform_buoyancy_position 502.523376 cc 2021-08-05T21:15:49.241Z,1628198149.241 [Reporter](INFO): platform_buoyancy_position 508.969696 cc 2021-08-05T21:15:49.645Z,1628198149.645 [Reporter](INFO): platform_buoyancy_position 513.267334 cc 2021-08-05T21:15:50.064Z,1628198150.064 [Reporter](INFO): platform_buoyancy_position 519.713745 cc 2021-08-05T21:15:50.492Z,1628198150.492 [Reporter](INFO): platform_buoyancy_position 524.145630 cc 2021-08-05T21:15:50.883Z,1628198150.883 [Reporter](INFO): platform_buoyancy_position 530.323425 cc 2021-08-05T21:15:51.301Z,1628198151.301 [Reporter](INFO): platform_buoyancy_position 534.889648 cc 2021-08-05T21:15:51.696Z,1628198151.696 [Reporter](INFO): platform_buoyancy_position 541.201782 cc 2021-08-05T21:15:52.153Z,1628198152.153 [Reporter](INFO): platform_buoyancy_position 545.767944 cc 2021-08-05T21:15:52.676Z,1628198152.676 [Reporter](INFO): platform_buoyancy_position 552.080078 cc 2021-08-05T21:15:52.865Z,1628198152.865 [Reporter](INFO): platform_buoyancy_position 556.243347 cc 2021-08-05T21:15:53.293Z,1628198153.293 [Reporter](INFO): platform_buoyancy_position 562.689758 cc 2021-08-05T21:15:53.677Z,1628198153.677 [Reporter](INFO): platform_buoyancy_position 566.987366 cc 2021-08-05T21:15:54.085Z,1628198154.085 [Reporter](INFO): platform_buoyancy_position 571.822144 cc 2021-08-05T21:15:54.574Z,1628198154.574 [Reporter](INFO): platform_buoyancy_position 577.865662 cc 2021-08-05T21:15:54.957Z,1628198154.957 [Reporter](INFO): platform_buoyancy_position 584.177734 cc 2021-08-05T21:15:55.340Z,1628198155.340 [Reporter](INFO): platform_buoyancy_position 588.475342 cc 2021-08-05T21:15:55.773Z,1628198155.773 [Reporter](INFO): platform_buoyancy_position 593.981628 cc 2021-08-05T21:15:56.227Z,1628198156.227 [Reporter](INFO): platform_buoyancy_position 599.487976 cc 2021-08-05T21:15:56.661Z,1628198156.661 [Reporter](INFO): platform_buoyancy_position 605.665771 cc 2021-08-05T21:15:57.042Z,1628198157.042 [Reporter](INFO): platform_buoyancy_position 611.172058 cc 2021-08-05T21:15:57.405Z,1628198157.405 [Reporter](INFO): platform_buoyancy_position 616.409790 cc 2021-08-05T21:15:57.832Z,1628198157.832 [Reporter](INFO): platform_buoyancy_position 620.975952 cc 2021-08-05T21:15:58.244Z,1628198158.244 [Reporter](INFO): platform_buoyancy_position 625.139282 cc 2021-08-05T21:15:58.657Z,1628198158.657 [Reporter](INFO): platform_buoyancy_position 631.451355 cc 2021-08-05T21:15:59.037Z,1628198159.037 [Reporter](INFO): platform_buoyancy_position 635.883240 cc 2021-08-05T21:15:59.441Z,1628198159.441 [Reporter](INFO): platform_buoyancy_position 642.195374 cc 2021-08-05T21:15:59.872Z,1628198159.872 [Reporter](INFO): platform_buoyancy_position 648.641785 cc 2021-08-05T21:16:00.261Z,1628198160.261 [Reporter](INFO): platform_buoyancy_position 653.073669 cc 2021-08-05T21:16:00.697Z,1628198160.697 [Reporter](INFO): platform_buoyancy_position 659.385742 cc 2021-08-05T21:16:01.083Z,1628198161.083 [Reporter](INFO): platform_buoyancy_position 663.817688 cc 2021-08-05T21:16:01.539Z,1628198161.539 [Reporter](INFO): platform_buoyancy_position 670.129761 cc 2021-08-05T21:16:01.917Z,1628198161.917 [Reporter](INFO): platform_buoyancy_position 674.427368 cc 2021-08-05T21:16:02.236Z,1628198162.236 [DVL_micro](ERROR): Failed to parse:00000000000,35.0,00.0,1489.0,000 2021-08-05T21:16:02.395Z,1628198162.395 [Reporter](INFO): platform_buoyancy_position 681.008057 cc 2021-08-05T21:16:02.703Z,1628198162.703 [Reporter](INFO): platform_buoyancy_position 685.171387 cc 2021-08-05T21:16:03.061Z,1628198163.061 [Reporter](INFO): platform_buoyancy_position 689.603271 cc 2021-08-05T21:16:03.465Z,1628198163.465 [Reporter](INFO): platform_buoyancy_position 695.915344 cc 2021-08-05T21:16:03.857Z,1628198163.857 [Reporter](INFO): platform_buoyancy_position 700.347290 cc 2021-08-05T21:16:04.313Z,1628198164.313 [Reporter](INFO): platform_buoyancy_position 706.793640 cc 2021-08-05T21:16:04.693Z,1628198164.693 [Reporter](INFO): platform_buoyancy_position 711.091248 cc 2021-08-05T21:16:05.087Z,1628198165.087 [Reporter](INFO): platform_buoyancy_position 715.523193 cc 2021-08-05T21:16:05.495Z,1628198165.495 [Reporter](INFO): platform_buoyancy_position 721.700989 cc 2021-08-05T21:16:05.931Z,1628198165.931 [Reporter](INFO): platform_buoyancy_position 728.147339 cc 2021-08-05T21:16:06.335Z,1628198166.335 [Reporter](INFO): platform_buoyancy_position 732.579285 cc 2021-08-05T21:16:06.691Z,1628198166.691 [Reporter](INFO): platform_buoyancy_position 736.876892 cc 2021-08-05T21:16:07.069Z,1628198167.069 [Reporter](INFO): platform_buoyancy_position 743.188965 cc 2021-08-05T21:16:07.493Z,1628198167.493 [Reporter](INFO): platform_buoyancy_position 747.620850 cc 2021-08-05T21:16:07.903Z,1628198167.903 [Reporter](INFO): platform_buoyancy_position 753.932983 cc 2021-08-05T21:16:08.313Z,1628198168.313 [Reporter](INFO): platform_buoyancy_position 758.230591 cc 2021-08-05T21:16:08.692Z,1628198168.692 [Reporter](INFO): platform_buoyancy_position 763.065369 cc 2021-08-05T21:16:09.117Z,1628198169.117 [Reporter](INFO): platform_buoyancy_position 769.108887 cc 2021-08-05T21:16:09.529Z,1628198169.529 [Reporter](INFO): platform_buoyancy_position 773.406494 cc 2021-08-05T21:16:09.905Z,1628198169.905 [Reporter](INFO): platform_buoyancy_position 779.718567 cc 2021-08-05T21:16:10.329Z,1628198170.329 [Reporter](INFO): platform_buoyancy_position 784.150452 cc 2021-08-05T21:16:10.729Z,1628198170.729 [Reporter](INFO): platform_buoyancy_position 790.462585 cc 2021-08-05T21:16:11.113Z,1628198171.113 [Reporter](INFO): platform_buoyancy_position 794.894470 cc 2021-08-05T21:16:11.529Z,1628198171.529 [Reporter](INFO): platform_buoyancy_position 801.072266 cc 2021-08-05T21:16:11.941Z,1628198171.941 [Reporter](INFO): platform_buoyancy_position 805.504150 cc 2021-08-05T21:16:12.289Z,1628198172.289 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:16:12.290Z,1628198172.290 [DVL_micro](ERROR): Failed to parse: :RD,+0000.30,+0003.27,+00004.93 2021-08-05T21:16:12.361Z,1628198172.361 [Reporter](INFO): platform_buoyancy_position 811.950562 cc 2021-08-05T21:16:12.757Z,1628198172.757 [Reporter](INFO): platform_buoyancy_position 816.382446 cc 2021-08-05T21:16:13.153Z,1628198173.153 [Reporter](INFO): platform_buoyancy_position 822.560303 cc 2021-08-05T21:16:13.537Z,1628198173.537 [Reporter](INFO): platform_buoyancy_position 826.992188 cc 2021-08-05T21:16:13.941Z,1628198173.941 [Reporter](INFO): platform_buoyancy_position 831.961304 cc 2021-08-05T21:16:14.357Z,1628198174.357 [Reporter](INFO): platform_buoyancy_position 837.870483 cc 2021-08-05T21:16:14.769Z,1628198174.769 [Reporter](INFO): platform_buoyancy_position 842.570923 cc 2021-08-05T21:16:15.177Z,1628198175.177 [Reporter](INFO): platform_buoyancy_position 848.480225 cc 2021-08-05T21:16:15.553Z,1628198175.553 [Reporter](INFO): platform_buoyancy_position 852.912109 cc 2021-08-05T21:16:16.068Z,1628198176.068 [Reporter](INFO): platform_buoyancy_position 860.030029 cc 2021-08-05T21:16:16.440Z,1628198176.440 [Reporter](INFO): platform_buoyancy_position 865.670532 cc 2021-08-05T21:16:16.809Z,1628198176.809 [Reporter](INFO): platform_buoyancy_position 869.968140 cc 2021-08-05T21:16:17.240Z,1628198177.240 [Reporter](INFO): platform_buoyancy_position 874.534424 cc 2021-08-05T21:16:17.601Z,1628198177.601 [Reporter](INFO): platform_buoyancy_position 880.712158 cc 2021-08-05T21:16:18.013Z,1628198178.013 [Reporter](INFO): platform_buoyancy_position 885.144043 cc 2021-08-05T21:16:18.437Z,1628198178.437 [Reporter](INFO): platform_buoyancy_position 891.590454 cc 2021-08-05T21:16:18.817Z,1628198178.817 [Reporter](INFO): platform_buoyancy_position 895.753784 cc 2021-08-05T21:16:19.229Z,1628198179.229 [Reporter](INFO): platform_buoyancy_position 902.200195 cc 2021-08-05T21:16:19.610Z,1628198179.610 [Reporter](INFO): platform_buoyancy_position 906.632080 cc 2021-08-05T21:16:20.085Z,1628198180.085 [Reporter](INFO): platform_buoyancy_position 913.078491 cc 2021-08-05T21:16:20.481Z,1628198180.481 [Reporter](INFO): platform_buoyancy_position 918.181885 cc 2021-08-05T21:16:20.836Z,1628198180.836 [Reporter](INFO): platform_buoyancy_position 923.688232 cc 2021-08-05T21:16:21.249Z,1628198181.249 [Reporter](INFO): platform_buoyancy_position 928.120117 cc 2021-08-05T21:16:21.641Z,1628198181.641 [Reporter](INFO): platform_buoyancy_position 932.283325 cc 2021-08-05T21:16:22.048Z,1628198182.048 [Reporter](INFO): platform_buoyancy_position 938.729736 cc 2021-08-05T21:16:22.497Z,1628198182.497 [Reporter](INFO): platform_buoyancy_position 943.161743 cc 2021-08-05T21:16:22.877Z,1628198182.877 [Reporter](INFO): platform_buoyancy_position 947.459229 cc 2021-08-05T21:19:34.449Z,1628198374.449 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:19:34.449Z,1628198374.449 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:19:34.449Z,1628198374.449 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:19:34.449Z,1628198374.449 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:19:34.851Z,1628198374.851 [Default:CheckIn:D] Stopped 2021-08-05T21:19:34.851Z,1628198374.851 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:19:35.264Z,1628198375.264 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.838497 min 2021-08-05T21:19:35.264Z,1628198375.264 [Default:CheckIn:E] Stopped 2021-08-05T21:19:35.264Z,1628198375.264 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:19:35.264Z,1628198375.264 [Default:CheckIn] Stopped 2021-08-05T21:19:35.264Z,1628198375.264 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:19:35.265Z,1628198375.265 [Default:CheckIn](INFO): Running loop #9 2021-08-05T21:19:35.265Z,1628198375.265 [Default:CheckIn] Running Loop=9 2021-08-05T21:19:35.265Z,1628198375.265 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:19:35.265Z,1628198375.265 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:19:37.256Z,1628198377.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211937.00,A,4149.69503,N,08324.70933,W,0.117,154.36,050821,,,D*78 2021-08-05T21:19:37.258Z,1628198377.258 [NAL9602](INFO): GPS fix at 20210805T211937: (41.828251, -83.411822) 2021-08-05T21:19:37.270Z,1628198377.270 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:19:37.270Z,1628198377.270 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:19:45.354Z,1628198385.354 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210805T202613/Courier0031.lzma 2021-08-05T21:19:46.356Z,1628198386.356 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0031.lzma.bak 2021-08-05T21:19:46.356Z,1628198386.356 [DataOverHttps](INFO): SBD MOMSN=15840145 2021-08-05T21:19:50.617Z,1628198390.617 [NAL9602](INFO): SBD MO Status=0, MOMSN=3055, MT Status=0, MTMSN=0 2021-08-05T21:19:50.618Z,1628198390.618 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:20:08.394Z,1628198408.394 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20210805T202613/Express0032.lzma 2021-08-05T21:20:09.396Z,1628198409.396 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0032.lzma.bak 2021-08-05T21:20:09.396Z,1628198409.396 [DataOverHttps](INFO): SBD MOMSN=15840151 2021-08-05T21:20:10.892Z,1628198410.892 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:20:10.892Z,1628198410.892 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:20:10.892Z,1628198410.892 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:20:21.388Z,1628198421.388 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:21:22.812Z,1628198482.812 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T21:21:22.812Z,1628198482.812 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.2,000.0,000 2021-08-05T21:24:11.385Z,1628198651.385 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:24:11.385Z,1628198651.385 [DVL_micro](ERROR): Failed to parse: :BI,+0104,+00763,+00000,I 2021-08-05T21:25:11.668Z,1628198711.668 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:25:11.668Z,1628198711.668 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:25:11.668Z,1628198711.668 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:25:11.669Z,1628198711.669 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:25:12.091Z,1628198712.091 [Default:CheckIn:D] Stopped 2021-08-05T21:25:12.091Z,1628198712.091 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:25:12.472Z,1628198712.472 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.459155 min 2021-08-05T21:25:12.472Z,1628198712.472 [Default:CheckIn:E] Stopped 2021-08-05T21:25:12.472Z,1628198712.472 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:25:12.472Z,1628198712.472 [Default:CheckIn] Stopped 2021-08-05T21:25:12.472Z,1628198712.472 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:25:12.473Z,1628198712.473 [Default:CheckIn](INFO): Running loop #10 2021-08-05T21:25:12.473Z,1628198712.473 [Default:CheckIn] Running Loop=10 2021-08-05T21:25:12.473Z,1628198712.473 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:25:12.473Z,1628198712.473 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:25:14.495Z,1628198714.495 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212514.00,A,4149.69243,N,08324.68447,W,0.292,24.54,050821,,,D*4E 2021-08-05T21:25:14.498Z,1628198714.498 [NAL9602](INFO): GPS fix at 20210805T212514: (41.828207, -83.411408) 2021-08-05T21:25:14.510Z,1628198714.510 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:25:14.510Z,1628198714.510 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:25:22.674Z,1628198722.674 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210805T202613/Courier0034.lzma 2021-08-05T21:25:23.676Z,1628198723.676 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0034.lzma.bak 2021-08-05T21:25:23.676Z,1628198723.676 [DataOverHttps](INFO): SBD MOMSN=15840191 2021-08-05T21:25:35.486Z,1628198735.486 [NAL9602](INFO): SBD MO Status=0, MOMSN=3056, MT Status=0, MTMSN=0 2021-08-05T21:25:35.486Z,1628198735.486 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:25:40.791Z,1628198740.791 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20210805T202613/Express0035.lzma 2021-08-05T21:25:41.784Z,1628198741.784 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0035.lzma.bak 2021-08-05T21:25:41.785Z,1628198741.785 [DataOverHttps](INFO): SBD MOMSN=15840197 2021-08-05T21:25:43.172Z,1628198743.172 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:25:43.172Z,1628198743.172 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:25:43.172Z,1628198743.172 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:26:06.196Z,1628198766.196 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:26:28.089Z,1628198788.089 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2021-08-05T21:26:28.089Z,1628198788.089 [DropWeight] Hardware Fault, FailCount= 1 2021-08-05T21:26:28.089Z,1628198788.089 [DropWeight](ERROR): Hardware Fault 2021-08-05T21:26:28.184Z,1628198788.184 [CommandLine](FAULT): Scheduling is paused 2021-08-05T21:26:28.184Z,1628198788.184 [CBIT](INFO): Critical error at 20210805T212628 2021-08-05T21:26:28.184Z,1628198788.184 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2021-08-05T21:26:28.204Z,1628198788.204 [CBIT](ERROR): Hardware Fault in component: DropWeight 2021-08-05T21:26:28.204Z,1628198788.204 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2021-08-05T21:26:28.520Z,1628198788.520 [CBIT](INFO): Critical error at 20210805T212628 2021-08-05T21:26:57.992Z,1628198817.992 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:26:57.992Z,1628198817.992 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+99999.99 2021-08-05T21:30:43.624Z,1628199043.624 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:30:43.624Z,1628199043.624 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:30:43.624Z,1628199043.624 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:30:43.624Z,1628199043.624 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:30:44.031Z,1628199044.031 [Default:CheckIn:D] Stopped 2021-08-05T21:30:44.031Z,1628199044.031 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:30:44.467Z,1628199044.467 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.991492 min 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn:E] Stopped 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn] Stopped 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn](INFO): Running loop #11 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn] Running Loop=11 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:30:44.468Z,1628199044.468 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:30:46.448Z,1628199046.448 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213046.00,A,4149.69322,N,08324.68582,W,0.039,24.54,050821,,,A*45 2021-08-05T21:30:46.451Z,1628199046.451 [NAL9602](INFO): GPS fix at 20210805T213046: (41.828220, -83.411430) 2021-08-05T21:30:46.462Z,1628199046.462 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:30:46.463Z,1628199046.463 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:30:54.135Z,1628199054.135 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20210805T202613/Courier0037.lzma 2021-08-05T21:30:55.136Z,1628199055.136 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0037.lzma.bak 2021-08-05T21:30:55.137Z,1628199055.137 [DataOverHttps](INFO): SBD MOMSN=15840235 2021-08-05T21:31:12.050Z,1628199072.050 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20210805T202613/Express0038.lzma 2021-08-05T21:31:13.052Z,1628199073.052 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0038.lzma.bak 2021-08-05T21:31:13.053Z,1628199073.053 [DataOverHttps](INFO): SBD MOMSN=15840240 2021-08-05T21:31:14.783Z,1628199074.783 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:31:14.783Z,1628199074.783 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:31:14.783Z,1628199074.783 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:31:21.589Z,1628199081.589 [NAL9602](INFO): SBD MO Status=2, MOMSN=3057, MT Status=2, MTMSN=0 2021-08-05T21:31:21.589Z,1628199081.589 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-05T21:31:58.433Z,1628199118.433 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:31:58.433Z,1628199118.433 [DVL_micro](ERROR): Failed to parse: :BI,+01031,-0496,+00000,I 2021-08-05T21:32:02.867Z,1628199122.867 [NAL9602](INFO): SBD MO Status=0, MOMSN=3057, MT Status=0, MTMSN=0 2021-08-05T21:32:02.867Z,1628199122.867 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:32:33.618Z,1628199153.618 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:33:16.819Z,1628199196.819 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:33:16.819Z,1628199196.819 [DVL_micro](ERROR): Failed to parse: :BI,+01043,+0180,+00000,I 2021-08-05T21:35:48.337Z,1628199348.337 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T21:35:48.337Z,1628199348.337 [DVL_micro](ERROR): Failed to parse: :TS0000000,35,0000.,000 2021-08-05T21:36:15.483Z,1628199375.483 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:36:15.483Z,1628199375.483 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:36:15.483Z,1628199375.483 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:36:15.483Z,1628199375.483 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:36:15.887Z,1628199375.887 [Default:CheckIn:D] Stopped 2021-08-05T21:36:15.887Z,1628199375.887 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:36:16.351Z,1628199376.351 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.522424 min 2021-08-05T21:36:16.352Z,1628199376.352 [Default:CheckIn:E] Stopped 2021-08-05T21:36:16.352Z,1628199376.352 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:36:16.352Z,1628199376.352 [Default:CheckIn] Stopped 2021-08-05T21:36:16.352Z,1628199376.352 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:36:16.352Z,1628199376.352 [Default:CheckIn](INFO): Running loop #12 2021-08-05T21:36:16.352Z,1628199376.352 [Default:CheckIn] Running Loop=12 2021-08-05T21:36:16.352Z,1628199376.352 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:36:16.353Z,1628199376.353 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:36:18.338Z,1628199378.338 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213618.00,A,4149.69648,N,08324.68596,W,0.078,185.70,050821,,,A*7D 2021-08-05T21:36:18.340Z,1628199378.340 [NAL9602](INFO): GPS fix at 20210805T213618: (41.828275, -83.411433) 2021-08-05T21:36:18.389Z,1628199378.389 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:36:18.389Z,1628199378.389 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:36:30.474Z,1628199390.474 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210805T202613/Courier0040.lzma 2021-08-05T21:36:31.476Z,1628199391.476 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0040.lzma.bak 2021-08-05T21:36:31.476Z,1628199391.476 [DataOverHttps](INFO): SBD MOMSN=15840283 2021-08-05T21:36:34.182Z,1628199394.182 [NAL9602](INFO): SBD MO Status=0, MOMSN=3058, MT Status=0, MTMSN=0 2021-08-05T21:36:34.190Z,1628199394.190 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:36:48.418Z,1628199408.418 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210805T202613/Express0041.lzma 2021-08-05T21:36:49.420Z,1628199409.420 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0041.lzma.bak 2021-08-05T21:36:49.420Z,1628199409.420 [DataOverHttps](INFO): SBD MOMSN=15840289 2021-08-05T21:36:50.768Z,1628199410.768 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:36:50.768Z,1628199410.768 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:36:50.768Z,1628199410.768 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:37:04.872Z,1628199424.872 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:39:13.395Z,1628199553.395 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:39:13.395Z,1628199553.395 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2021-08-05T21:39:18.624Z,1628199558.624 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:39:18.624Z,1628199558.624 [DVL_micro](ERROR): Failed to parse: :BI,-00337,-00156,+0002,I 2021-08-05T21:41:28.403Z,1628199688.403 [CBIT](INFO): Clearing failed state for component DropWeight 2021-08-05T21:41:28.403Z,1628199688.403 [DropWeight] No Fault, FailCount= 1 2021-08-05T21:41:51.458Z,1628199711.458 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:41:51.458Z,1628199711.458 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:41:51.459Z,1628199711.459 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:41:51.459Z,1628199711.459 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:41:51.874Z,1628199711.874 [Default:CheckIn:D] Stopped 2021-08-05T21:41:51.874Z,1628199711.874 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:41:52.256Z,1628199712.256 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.122201 min 2021-08-05T21:41:52.256Z,1628199712.256 [Default:CheckIn:E] Stopped 2021-08-05T21:41:52.256Z,1628199712.256 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:41:52.256Z,1628199712.256 [Default:CheckIn] Stopped 2021-08-05T21:41:52.257Z,1628199712.257 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:41:52.257Z,1628199712.257 [Default:CheckIn](INFO): Running loop #13 2021-08-05T21:41:52.257Z,1628199712.257 [Default:CheckIn] Running Loop=13 2021-08-05T21:41:52.257Z,1628199712.257 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:41:52.257Z,1628199712.257 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:41:54.223Z,1628199714.223 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214154.00,A,4149.69333,N,08324.68639,W,0.058,185.70,050821,,,D*7D 2021-08-05T21:41:54.225Z,1628199714.225 [NAL9602](INFO): GPS fix at 20210805T214154: (41.828222, -83.411440) 2021-08-05T21:41:54.269Z,1628199714.269 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:41:54.269Z,1628199714.269 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:42:05.050Z,1628199725.050 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210805T202613/Courier0043.lzma 2021-08-05T21:42:06.053Z,1628199726.053 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0043.lzma.bak 2021-08-05T21:42:06.053Z,1628199726.053 [DataOverHttps](INFO): SBD MOMSN=15840340 2021-08-05T21:42:08.322Z,1628199728.322 [NAL9602](INFO): SBD MO Status=0, MOMSN=3059, MT Status=0, MTMSN=0 2021-08-05T21:42:08.323Z,1628199728.323 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:42:27.011Z,1628199747.011 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210805T202613/Express0044.lzma 2021-08-05T21:42:28.013Z,1628199748.013 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0044.lzma.bak 2021-08-05T21:42:28.013Z,1628199748.013 [DataOverHttps](INFO): SBD MOMSN=15840347 2021-08-05T21:42:29.822Z,1628199749.822 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:42:29.822Z,1628199749.822 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:42:29.823Z,1628199749.823 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:42:39.092Z,1628199759.092 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:42:41.913Z,1628199761.913 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T21:42:47.570Z,1628199767.570 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2021-08-05T21:42:47.577Z,1628199767.577 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2021-08-05T21:42:47.578Z,1628199767.578 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2021-08-05T21:42:47.581Z,1628199767.581 [BPC1](INFO): Received data from all battery sticks. 2021-08-05T21:45:53.905Z,1628199953.905 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T21:45:53.905Z,1628199953.905 [DVL_micro](ERROR): Failed to parse: :TS,00000000000,+25.0,0000.0,1489.0,000 2021-08-05T21:47:28.064Z,1628200048.064 [DVL_micro](ERROR): Failed to parse: 0000000000,35.0,+24.9,0000.0,1489.0,000 2021-08-05T21:47:30.543Z,1628200050.543 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:47:30.543Z,1628200050.543 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:47:30.543Z,1628200050.543 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:47:30.543Z,1628200050.543 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:47:30.926Z,1628200050.926 [Default:CheckIn:D] Stopped 2021-08-05T21:47:30.927Z,1628200050.927 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:47:31.312Z,1628200051.312 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.772746 min 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn:E] Stopped 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn] Stopped 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn](INFO): Running loop #14 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn] Running Loop=14 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:47:31.313Z,1628200051.313 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:47:33.324Z,1628200053.324 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214733.00,A,4149.69298,N,08324.68713,W,0.039,185.70,050821,,,D*74 2021-08-05T21:47:33.327Z,1628200053.327 [NAL9602](INFO): GPS fix at 20210805T214733: (41.828216, -83.411452) 2021-08-05T21:47:33.338Z,1628200053.338 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:47:33.338Z,1628200053.338 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:47:41.350Z,1628200061.350 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20210805T202613/Courier0046.lzma 2021-08-05T21:47:42.352Z,1628200062.352 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0046.lzma.bak 2021-08-05T21:47:42.352Z,1628200062.352 [DataOverHttps](INFO): SBD MOMSN=15840385 2021-08-05T21:47:47.050Z,1628200067.050 [NAL9602](INFO): SBD MO Status=0, MOMSN=3060, MT Status=0, MTMSN=0 2021-08-05T21:47:47.050Z,1628200067.050 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:47:50.690Z,1628200070.690 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:47:50.690Z,1628200070.690 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+99999.99,+9999.99 2021-08-05T21:48:02.450Z,1628200082.450 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20210805T202613/Express0047.lzma 2021-08-05T21:48:03.453Z,1628200083.453 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0047.lzma.bak 2021-08-05T21:48:03.453Z,1628200083.453 [DataOverHttps](INFO): SBD MOMSN=15840391 2021-08-05T21:48:04.895Z,1628200084.895 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:48:04.896Z,1628200084.896 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:48:04.896Z,1628200084.896 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:48:17.844Z,1628200097.844 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:48:59.055Z,1628200139.055 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:48:59.055Z,1628200139.055 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,+9999.99,+ 2021-08-05T21:51:56.937Z,1628200316.937 [DVL_micro](ERROR): Failed to parse: :SA,-02.87,-00.05,351.2 2021-08-05T21:53:05.632Z,1628200385.632 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:53:05.632Z,1628200385.632 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:53:05.633Z,1628200385.633 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:53:05.633Z,1628200385.633 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:53:06.048Z,1628200386.048 [Default:CheckIn:D] Stopped 2021-08-05T21:53:06.048Z,1628200386.048 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:53:06.470Z,1628200386.470 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.358439 min 2021-08-05T21:53:06.470Z,1628200386.470 [Default:CheckIn:E] Stopped 2021-08-05T21:53:06.470Z,1628200386.470 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:53:06.474Z,1628200386.474 [Default:CheckIn] Stopped 2021-08-05T21:53:06.474Z,1628200386.474 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:53:06.475Z,1628200386.475 [Default:CheckIn](INFO): Running loop #15 2021-08-05T21:53:06.475Z,1628200386.475 [Default:CheckIn] Running Loop=15 2021-08-05T21:53:06.475Z,1628200386.475 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:53:06.475Z,1628200386.475 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:53:08.450Z,1628200388.450 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215308.00,A,4149.69258,N,08324.68721,W,0.019,185.70,050821,,,D*76 2021-08-05T21:53:08.453Z,1628200388.453 [NAL9602](INFO): GPS fix at 20210805T215308: (41.828210, -83.411453) 2021-08-05T21:53:08.464Z,1628200388.464 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:53:08.464Z,1628200388.464 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:53:16.530Z,1628200396.530 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210805T202613/Courier0049.lzma 2021-08-05T21:53:17.532Z,1628200397.532 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0049.lzma.bak 2021-08-05T21:53:17.533Z,1628200397.533 [DataOverHttps](INFO): SBD MOMSN=15840429 2021-08-05T21:53:21.382Z,1628200401.382 [NAL9602](INFO): SBD MO Status=0, MOMSN=3061, MT Status=0, MTMSN=0 2021-08-05T21:53:21.382Z,1628200401.382 [NAL9602](INFO): No messages in MT queue 2021-08-05T21:53:34.531Z,1628200414.531 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20210805T202613/Express0050.lzma 2021-08-05T21:53:35.532Z,1628200415.532 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0050.lzma.bak 2021-08-05T21:53:35.532Z,1628200415.532 [DataOverHttps](INFO): SBD MOMSN=15840435 2021-08-05T21:53:37.154Z,1628200417.154 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:53:37.154Z,1628200417.154 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:53:37.154Z,1628200417.154 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:53:52.108Z,1628200432.108 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T21:54:57.219Z,1628200497.219 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+25.1,0000.0,1489.0,000 2021-08-05T21:57:49.748Z,1628200669.748 [DVL_micro](ERROR): only read 3 of 4 data items 2021-08-05T21:57:49.749Z,1628200669.749 [DVL_micro](ERROR): Failed to parse: :BI,-00020,-0018,+00000,I 2021-08-05T21:58:37.891Z,1628200717.891 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2021-08-05T21:58:37.891Z,1628200717.891 [Default:CheckIn:C.Wait] Stopped 2021-08-05T21:58:37.891Z,1628200717.891 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2021-08-05T21:58:37.891Z,1628200717.891 [Default:CheckIn:D] Running Loop=1 2021-08-05T21:58:38.299Z,1628200718.299 [Default:CheckIn:D] Stopped 2021-08-05T21:58:38.299Z,1628200718.299 [Default:CheckIn:E] Running Loop=1 2021-08-05T21:58:38.733Z,1628200718.733 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.895955 min 2021-08-05T21:58:38.733Z,1628200718.733 [Default:CheckIn:E] Stopped 2021-08-05T21:58:38.733Z,1628200718.733 [Default:CheckIn](INFO): Completed Default:CheckIn 2021-08-05T21:58:38.733Z,1628200718.733 [Default:CheckIn] Stopped 2021-08-05T21:58:38.734Z,1628200718.734 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-08-05T21:58:38.734Z,1628200718.734 [Default:CheckIn](INFO): Running loop #16 2021-08-05T21:58:38.734Z,1628200718.734 [Default:CheckIn] Running Loop=16 2021-08-05T21:58:38.734Z,1628200718.734 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-08-05T21:58:38.734Z,1628200718.734 [Default:CheckIn:Read_GPS] Running Loop=1 2021-08-05T21:58:40.703Z,1628200720.703 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215840.00,A,4149.69698,N,08324.71182,W,0.330,263.93,050821,,,D*70 2021-08-05T21:58:40.705Z,1628200720.705 [NAL9602](INFO): GPS fix at 20210805T215840: (41.828283, -83.411864) 2021-08-05T21:58:40.716Z,1628200720.716 [Default:CheckIn:Read_GPS] Stopped 2021-08-05T21:58:40.717Z,1628200720.717 [Default:CheckIn:Read_Iridium] Running Loop=1 2021-08-05T21:58:50.958Z,1628200730.958 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20210805T202613/Courier0052.lzma 2021-08-05T21:58:51.960Z,1628200731.960 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Courier0052.lzma.bak 2021-08-05T21:58:51.960Z,1628200731.960 [DataOverHttps](INFO): SBD MOMSN=15840472 2021-08-05T21:59:09.010Z,1628200749.010 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20210805T202613/Express0053.lzma 2021-08-05T21:59:10.012Z,1628200750.012 [DataOverHttps](INFO): Moved sent file to Logs/20210805T202613/Express0053.lzma.bak 2021-08-05T21:59:10.012Z,1628200750.012 [DataOverHttps](INFO): SBD MOMSN=15840478 2021-08-05T21:59:11.410Z,1628200751.410 [NAL9602](INFO): SBD MO Status=2, MOMSN=3062, MT Status=2, MTMSN=0 2021-08-05T21:59:11.410Z,1628200751.410 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-05T21:59:11.428Z,1628200751.428 [Default:CheckIn:Read_Iridium] Stopped 2021-08-05T21:59:11.428Z,1628200751.428 [Default:CheckIn:C.Wait] Running Loop=1 2021-08-05T21:59:11.428Z,1628200751.428 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2021-08-05T21:59:14.667Z,1628200754.667 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T21:59:14.667Z,1628200754.667 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+25.9,000.0,000 2021-08-05T21:59:34.864Z,1628200774.864 [NAL9602](INFO): SBD MO Status=2, MOMSN=3062, MT Status=2, MTMSN=0 2021-08-05T21:59:34.865Z,1628200774.865 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2021-08-05T21:59:44.134Z,1628200784.134 [NAL9602](INFO): SBD MO Status=0, MOMSN=3062, MT Status=0, MTMSN=0 2021-08-05T21:59:44.134Z,1628200784.134 [NAL9602](INFO): No messages in MT queue 2021-08-05T22:00:08.450Z,1628200808.450 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2021-08-05T22:00:08.451Z,1628200808.451 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+26.0,0000.0,00 2021-08-05T22:00:14.900Z,1628200814.900 [NAL9602](INFO): Not Powering down - fast GPS 2021-08-05T22:00:34.672Z,1628200834.672 [DataOverHttps](IMPORTANT): SBD MTMSN=20210805T220034 2021-08-05T22:00:42.746Z,1628200842.746 [DataOverHttps](INFO): Received command:restart logs