2021-07-19T21:58:48.870Z,1626731928.870 [Supervisor](DEBUG): Initializing supervisor.
2021-07-19T21:58:48.874Z,1626731928.874 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-07-19T21:58:48.875Z,1626731928.875 [SyncHandler](INFO): Protected caller Thread ID is 3070
2021-07-19T21:58:48.875Z,1626731928.875 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-07-19T21:58:48.876Z,1626731928.876 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-07-19T21:58:48.877Z,1626731928.877 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3071
2021-07-19T21:58:48.881Z,1626731928.881 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-07-19T21:58:48.901Z,1626731928.901 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-07-19T21:58:48.902Z,1626731928.902 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-07-19T21:58:48.902Z,1626731928.902 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3072
2021-07-19T21:58:48.905Z,1626731928.905 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-07-19T21:58:48.906Z,1626731928.906 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-07-19T21:58:48.906Z,1626731928.906 [logger ThreadHandler](INFO): Protected caller Thread ID is 3073
2021-07-19T21:58:48.910Z,1626731928.910 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-07-19T21:58:48.910Z,1626731928.910 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-07-19T21:58:48.912Z,1626731928.912 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-07-19T21:58:49.140Z,1626731929.140 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-07-19T21:58:49.141Z,1626731929.141 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-07-19T21:58:49.222Z,1626731929.222 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-07-19T21:58:49.723Z,1626731929.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-07-19T21:58:49.724Z,1626731929.724 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-07-19T21:58:50.058Z,1626731930.058 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-07-19T21:58:50.058Z,1626731930.058 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-07-19T21:58:50.156Z,1626731930.156 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-07-19T21:58:50.157Z,1626731930.157 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-07-19T21:58:50.530Z,1626731930.530 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-07-19T21:58:50.530Z,1626731930.530 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-07-19T21:58:50.731Z,1626731930.731 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-07-19T21:58:50.732Z,1626731930.732 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-07-19T21:58:51.198Z,1626731931.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-07-19T21:58:51.199Z,1626731931.199 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-07-19T21:58:51.326Z,1626731931.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-07-19T21:58:51.327Z,1626731931.327 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-07-19T21:58:51.407Z,1626731931.407 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-07-19T21:58:52.076Z,1626731932.076 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-07-19T21:58:52.077Z,1626731932.077 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-07-19T21:58:52.444Z,1626731932.444 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-07-19T21:58:52.445Z,1626731932.445 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-07-19T21:58:52.645Z,1626731932.645 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-07-19T21:58:52.645Z,1626731932.645 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-07-19T21:58:52.757Z,1626731932.757 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-07-19T21:58:52.758Z,1626731932.758 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-07-19T21:58:52.970Z,1626731932.970 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-07-19T21:58:52.971Z,1626731932.971 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-07-19T21:58:53.472Z,1626731933.472 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-07-19T21:58:53.474Z,1626731933.474 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-07-19T21:58:53.474Z,1626731933.474 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-07-19T21:58:53.760Z,1626731933.760 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-07-19T21:58:53.913Z,1626731933.913 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-07-19T21:58:54.107Z,1626731934.107 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-07-19T21:58:54.322Z,1626731934.322 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-07-19T21:58:54.539Z,1626731934.539 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-07-19T21:58:54.722Z,1626731934.722 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-07-19T21:58:55.191Z,1626731935.191 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-07-19T21:58:55.323Z,1626731935.323 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-07-19T21:58:55.477Z,1626731935.477 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-07-19T21:58:55.619Z,1626731935.619 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-07-19T21:58:55.739Z,1626731935.739 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-07-19T21:58:56.005Z,1626731936.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-07-19T21:58:56.005Z,1626731936.005 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-07-19T21:58:56.015Z,1626731936.015 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-07-19T21:58:56.071Z,1626731936.071 [VerticalControl](DEBUG): Construct VerticalControl.
2021-07-19T21:58:56.132Z,1626731936.132 [VerticalControl] Loaded
2021-07-19T21:58:56.132Z,1626731936.132 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-07-19T21:58:56.135Z,1626731936.135 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-07-19T21:58:56.174Z,1626731936.174 [HorizontalControl] Loaded
2021-07-19T21:58:56.174Z,1626731936.174 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-07-19T21:58:56.176Z,1626731936.176 [SpeedControl](DEBUG): Construct SpeedControl.
2021-07-19T21:58:56.180Z,1626731936.180 [SpeedControl] Loaded
2021-07-19T21:58:56.180Z,1626731936.180 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-07-19T21:58:56.182Z,1626731936.182 [LoopControl](DEBUG): Construct LoopControl.
2021-07-19T21:58:56.183Z,1626731936.183 [LoopControl] Loaded
2021-07-19T21:58:56.183Z,1626731936.183 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-07-19T21:58:56.184Z,1626731936.184 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-07-19T21:58:56.184Z,1626731936.184 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-07-19T21:58:56.195Z,1626731936.195 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-07-19T21:58:56.196Z,1626731936.196 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-07-19T21:58:56.303Z,1626731936.303 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-07-19T21:58:56.303Z,1626731936.303 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-07-19T21:58:56.452Z,1626731936.452 [BuoyancyServo] Loaded
2021-07-19T21:58:56.453Z,1626731936.453 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-07-19T21:58:56.472Z,1626731936.472 [ElevatorServo] Loaded
2021-07-19T21:58:56.472Z,1626731936.472 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-07-19T21:58:56.490Z,1626731936.490 [MassServo] Loaded
2021-07-19T21:58:56.491Z,1626731936.491 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-07-19T21:58:56.509Z,1626731936.509 [RudderServo] Loaded
2021-07-19T21:58:56.509Z,1626731936.509 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-07-19T21:58:56.526Z,1626731936.526 [ThrusterServo] Loaded
2021-07-19T21:58:56.527Z,1626731936.527 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-07-19T21:58:56.527Z,1626731936.527 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-07-19T21:58:56.527Z,1626731936.527 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-07-19T21:58:56.609Z,1626731936.609 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-07-19T21:58:56.609Z,1626731936.609 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-07-19T21:58:56.622Z,1626731936.622 [NavChart] Loaded
2021-07-19T21:58:56.622Z,1626731936.622 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-07-19T21:58:56.628Z,1626731936.628 [UniversalFixResidualReporter] Loaded
2021-07-19T21:58:56.628Z,1626731936.628 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-07-19T21:58:56.629Z,1626731936.629 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-07-19T21:58:56.629Z,1626731936.629 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-07-19T21:58:56.689Z,1626731936.689 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-07-19T21:58:56.689Z,1626731936.689 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-07-19T21:58:57.064Z,1626731937.064 [AHRS_M2] Loaded
2021-07-19T21:58:57.064Z,1626731937.064 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-07-19T21:58:57.864Z,1626731937.864 [BPC1] Loaded
2021-07-19T21:58:57.865Z,1626731937.865 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-07-19T21:58:57.939Z,1626731937.939 [DataOverHttps] Loaded
2021-07-19T21:58:57.940Z,1626731937.940 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-07-19T21:58:57.941Z,1626731937.941 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408854E0
2021-07-19T21:58:57.941Z,1626731937.941 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3158
2021-07-19T21:58:57.961Z,1626731937.961 [Depth_Keller] Loaded
2021-07-19T21:58:57.961Z,1626731937.961 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-07-19T21:58:57.966Z,1626731937.966 [DropWeight] Loaded
2021-07-19T21:58:57.966Z,1626731937.966 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-07-19T21:58:58.025Z,1626731938.025 [NAL9602] Loaded
2021-07-19T21:58:58.025Z,1626731938.025 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-07-19T21:58:58.054Z,1626731938.054 [Onboard] Loaded
2021-07-19T21:58:58.054Z,1626731938.054 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-07-19T21:58:58.055Z,1626731938.055 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408B54E0
2021-07-19T21:58:58.056Z,1626731938.056 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3159
2021-07-19T21:58:58.068Z,1626731938.068 [Power24vConverter] Loaded
2021-07-19T21:58:58.068Z,1626731938.068 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-07-19T21:58:58.081Z,1626731938.081 [Radio_Surface] Loaded
2021-07-19T21:58:58.082Z,1626731938.082 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-07-19T21:58:58.083Z,1626731938.083 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408E54E0
2021-07-19T21:58:58.083Z,1626731938.083 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3160
2021-07-19T21:58:58.084Z,1626731938.084 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-07-19T21:58:58.084Z,1626731938.084 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-07-19T21:58:58.128Z,1626731938.128 [DepthRateCalculator] Loaded
2021-07-19T21:58:58.128Z,1626731938.128 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-07-19T21:58:58.133Z,1626731938.133 [PitchRateCalculator] Loaded
2021-07-19T21:58:58.133Z,1626731938.133 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-07-19T21:58:58.142Z,1626731938.142 [SpeedCalculator] Loaded
2021-07-19T21:58:58.143Z,1626731938.143 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-07-19T21:58:58.156Z,1626731938.156 [TempGradientCalculator] Loaded
2021-07-19T21:58:58.157Z,1626731938.157 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-07-19T21:58:58.161Z,1626731938.161 [YawRateCalculator] Loaded
2021-07-19T21:58:58.161Z,1626731938.161 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-07-19T21:58:58.179Z,1626731938.179 [ElevatorOffsetCalculator] Loaded
2021-07-19T21:58:58.179Z,1626731938.179 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-07-19T21:58:58.179Z,1626731938.179 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-07-19T21:58:58.180Z,1626731938.180 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-07-19T21:58:58.320Z,1626731938.320 [CANONSampler] Loaded
2021-07-19T21:58:58.321Z,1626731938.321 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2021-07-19T21:58:58.379Z,1626731938.379 [CTD_Seabird] Loaded
2021-07-19T21:58:58.379Z,1626731938.379 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-07-19T21:58:58.380Z,1626731938.380 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4099A4E0
2021-07-19T21:58:58.381Z,1626731938.381 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3161
2021-07-19T21:58:58.400Z,1626731938.400 [PAR_Licor] Loaded
2021-07-19T21:58:58.401Z,1626731938.401 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-07-19T21:58:58.433Z,1626731938.433 [WetLabsBB2FL] Loaded
2021-07-19T21:58:58.433Z,1626731938.433 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-07-19T21:58:58.434Z,1626731938.434 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409CA4E0
2021-07-19T21:58:58.435Z,1626731938.435 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3162
2021-07-19T21:58:58.435Z,1626731938.435 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-07-19T21:58:58.436Z,1626731938.436 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-07-19T21:58:58.464Z,1626731938.464 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-07-19T21:58:58.465Z,1626731938.465 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-07-19T21:58:59.231Z,1626731939.231 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-07-19T21:58:59.231Z,1626731939.231 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-07-19T21:58:59.386Z,1626731939.386 [SBIT](DEBUG): Construct Startup Built In Test.
2021-07-19T21:58:59.395Z,1626731939.395 [SBIT] Loaded
2021-07-19T21:58:59.395Z,1626731939.395 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-07-19T21:58:59.398Z,1626731939.398 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-07-19T21:58:59.411Z,1626731939.411 [IBIT] Loaded
2021-07-19T21:58:59.411Z,1626731939.411 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-07-19T21:58:59.417Z,1626731939.417 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-07-19T21:58:59.517Z,1626731939.517 [CBIT] Loaded
2021-07-19T21:58:59.518Z,1626731939.518 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-07-19T21:58:59.518Z,1626731939.518 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-07-19T21:58:59.518Z,1626731939.518 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-07-19T21:58:59.618Z,1626731939.618 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-07-19T21:58:59.623Z,1626731939.623 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-07-19T21:58:59.626Z,1626731939.626 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-07-19T21:58:59.638Z,1626731939.638 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-07-19T21:58:59.639Z,1626731939.639 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFD4E0
2021-07-19T21:58:59.639Z,1626731939.639 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3163
2021-07-19T21:58:59.644Z,1626731939.644 [Supervisor](INFO): Main Thread ID is 2217
2021-07-19T21:58:59.644Z,1626731939.644 [Supervisor](DEBUG): Running supervisor.
2021-07-19T21:58:59.645Z,1626731939.645 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3164
2021-07-19T21:58:59.647Z,1626731939.647 [controlThread ThreadHandler](INFO): Handler Thread ID is 3165
2021-07-19T21:58:59.648Z,1626731939.648 [controlThread](DEBUG): Initializing ControlThread
2021-07-19T21:58:59.648Z,1626731939.648 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-07-19T21:58:59.650Z,1626731939.650 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-07-19T21:58:59.651Z,1626731939.651 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-07-19T21:58:59.652Z,1626731939.652 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-07-19T21:58:59.654Z,1626731939.654 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-07-19T21:58:59.654Z,1626731939.654 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-07-19T21:58:59.659Z,1626731939.659 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-07-19T21:58:59.659Z,1626731939.659 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-07-19T21:58:59.659Z,1626731939.659 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-07-19T21:58:59.660Z,1626731939.660 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-07-19T21:58:59.660Z,1626731939.660 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-07-19T21:58:59.661Z,1626731939.661 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-07-19T21:58:59.665Z,1626731939.665 [SBIT](INFO): Initialize SBIT Component.
2021-07-19T21:58:59.666Z,1626731939.666 [SBIT](IMPORTANT): git: 2021-06-25
2021-07-19T21:58:59.666Z,1626731939.666 [SBIT](INFO): git hash: ce6655dd71cbacf6863957f250954322ec92cc29
2021-07-19T21:58:59.666Z,1626731939.666 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-07-19T21:58:59.667Z,1626731939.667 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-07-19T21:58:59.669Z,1626731939.669 [SBIT](INFO): Beginning SBIT in 89.000000 seconds.
2021-07-19T21:58:59.669Z,1626731939.669 [IBIT](INFO): Initialize IBIT Component.
2021-07-19T21:58:59.670Z,1626731939.670 [CBIT](DEBUG): Initialize CBIT Component.
2021-07-19T21:58:59.671Z,1626731939.671 [logger ThreadHandler](INFO): Handler Thread ID is 3166
2021-07-19T21:58:59.685Z,1626731939.685 [CBIT](DEBUG): Initialized mux pins.
2021-07-19T21:58:59.685Z,1626731939.685 [CBIT](DEBUG): Initializing the watchdog timer.
2021-07-19T21:58:59.689Z,1626731939.689 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3167
2021-07-19T21:58:59.691Z,1626731939.691 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-07-19T21:58:59.698Z,1626731939.698 [Onboard ThreadHandler](INFO): Handler Thread ID is 3168
2021-07-19T21:58:59.710Z,1626731939.710 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-07-19T21:58:59.710Z,1626731939.710 [CBIT](DEBUG): Initializing heartbeat.
2021-07-19T21:58:59.718Z,1626731939.718 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3169
2021-07-19T21:58:59.733Z,1626731939.733 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3170
2021-07-19T21:58:59.734Z,1626731939.734 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-07-19T21:58:59.738Z,1626731939.738 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3172
2021-07-19T21:58:59.741Z,1626731939.741 [WetLabsBB2FL](INFO): Powering up
2021-07-19T21:58:59.743Z,1626731939.743 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3174
2021-07-19T21:58:59.746Z,1626731939.746 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-07-19T21:58:59.747Z,1626731939.747 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-07-19T21:58:59.747Z,1626731939.747 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-07-19T21:58:59.747Z,1626731939.747 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-07-19T21:58:59.747Z,1626731939.747 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-07-19T21:58:59.747Z,1626731939.747 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-07-19T21:58:59.748Z,1626731939.748 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-07-19T21:58:59.748Z,1626731939.748 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-07-19T21:58:59.748Z,1626731939.748 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-07-19T21:58:59.748Z,1626731939.748 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-07-19T21:58:59.748Z,1626731939.748 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-07-19T21:58:59.748Z,1626731939.748 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-07-19T21:58:59.749Z,1626731939.749 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-07-19T21:58:59.749Z,1626731939.749 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-07-19T21:58:59.750Z,1626731939.750 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-07-19T21:58:59.750Z,1626731939.750 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-07-19T21:58:59.781Z,1626731939.781 [CBIT](DEBUG): Deactivating GF circuits.
2021-07-19T21:58:59.781Z,1626731939.781 [CBIT](DEBUG): Deactivating emergency mode.
2021-07-19T21:58:59.817Z,1626731939.817 [CBIT](DEBUG): Backplane powered.
2021-07-19T21:58:59.818Z,1626731939.818 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-07-19T21:58:59.831Z,1626731939.831 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-07-19T21:58:59.855Z,1626731939.855 [MissionManager](DEBUG):
2021-07-19T21:58:59.856Z,1626731939.856 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-07-19T21:58:59.935Z,1626731939.935 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-07-19T21:58:59.937Z,1626731939.937 [Default:A.Wait](DEBUG): Construct Wait.
2021-07-19T21:58:59.955Z,1626731939.955 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-07-19T21:58:59.987Z,1626731939.987 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-07-19T21:58:59.990Z,1626731939.990 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-07-19T21:59:00.012Z,1626731940.012 [Default:E.Execute](DEBUG): Construct Execute.
2021-07-19T21:59:00.015Z,1626731940.015 [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-07-19T21:59:00.033Z,1626731940.033 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-07-19T21:59:00.040Z,1626731940.040 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-07-19T21:59:00.104Z,1626731940.104 [Power24vConverter](INFO): Powering up.
2021-07-19T21:59:00.104Z,1626731940.104 [CANONSampler](INFO): Powering down
2021-07-19T21:59:00.125Z,1626731940.125 [Radio_Surface](INFO): Powering up
2021-07-19T21:59:00.148Z,1626731940.148 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-07-19T21:59:00.153Z,1626731940.153 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-07-19T21:59:00.154Z,1626731940.154 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-07-19T21:59:00.161Z,1626731940.161 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-07-19T21:59:00.162Z,1626731940.162 [MassServo](DEBUG): Initializing EZServoServo.
2021-07-19T21:59:00.169Z,1626731940.169 [MassServo](DEBUG): Initializing MassServo.
2021-07-19T21:59:00.170Z,1626731940.170 [RudderServo](DEBUG): Initializing EZServoServo.
2021-07-19T21:59:00.177Z,1626731940.177 [RudderServo](DEBUG): Initializing RudderServo.
2021-07-19T21:59:00.178Z,1626731940.178 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-07-19T21:59:00.185Z,1626731940.185 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-07-19T21:59:01.849Z,1626731941.849 [WetLabsBB2FL](INFO): Powering down
2021-07-19T21:59:06.766Z,1626731946.766 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-07-19T21:59:28.327Z,1626731968.327 [NAL9602](INFO): Powering up NAL9602
2021-07-19T21:59:39.235Z,1626731979.235 [NAL9602](INFO): NAL9602 initialized
2021-07-19T22:00:29.348Z,1626732029.348 [SBIT](IMPORTANT): Beginning Startup BIT
2021-07-19T22:00:29.352Z,1626732029.352 [CBIT](IMPORTANT): Beginning ground fault scan
2021-07-19T22:00:40.264Z,1626732040.264 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.677548
CHAN A1 (24V): -0.180567
CHAN A2 (12V): -0.002054
CHAN A3 (5V): -0.001469
CHAN B0 (3.3V): 0.000358
CHAN B1 (3.15aV): 4.767929
CHAN B2 (3.15bV): 0.000019
CHAN B3 (GND): -0.000127
OPEN: -0.000223
Full Scale Calc: 4.765 mA, -1.589 mA
2021-07-19T22:01:23.522Z,1626732083.522 [SBIT](IMPORTANT): SBIT PASSED
2021-07-19T22:01:23.523Z,1626732083.523 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-07-19T22:01:23.524Z,1626732083.524 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;
2021-07-19T22:01:23.524Z,1626732083.524 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;
2021-07-19T22:01:23.524Z,1626732083.524 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2021-07-19T22:01:23.524Z,1626732083.524 [SBIT](IMPORTANT): DAT.verbosity=3 count;
2021-07-19T22:01:23.524Z,1626732083.524 [SBIT](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;
2021-07-19T22:01:23.524Z,1626732083.524 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=401.334477 cubic_centimeter;
2021-07-19T22:01:23.524Z,1626732083.524 [SBIT](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;
2021-07-19T22:01:23.525Z,1626732083.525 [SBIT](IMPORTANT): VerticalControl.kpDepthBuoy=60 ratio;
2021-07-19T22:01:23.525Z,1626732083.525 [SBIT](IMPORTANT): VerticalControl.massDefault=-17.489190 millimeter;
2021-07-19T22:01:23.894Z,1626732083.894 [MissionManager](IMPORTANT): Started mission Startup
2021-07-19T22:01:23.894Z,1626732083.894 [Startup] Running Loop=1
2021-07-19T22:01:23.894Z,1626732083.894 [Startup](DEBUG): Aggregate::initialize Startup
2021-07-19T22:01:23.894Z,1626732083.894 [Startup:A.GoToSurface] Running Loop=1
2021-07-19T22:01:23.894Z,1626732083.894 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-19T22:01:23.895Z,1626732083.895 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-19T22:01:23.895Z,1626732083.895 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-19T22:01:23.896Z,1626732083.896 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-19T22:01:23.896Z,1626732083.896 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-19T22:01:23.896Z,1626732083.896 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-19T22:01:23.898Z,1626732083.898 [Startup:StartupSatComms] Running Loop=1
2021-07-19T22:01:23.898Z,1626732083.898 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-07-19T22:01:23.899Z,1626732083.899 [Startup:StartupSatComms:A] Running Loop=1
2021-07-19T22:01:24.312Z,1626732084.312 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-07-19T22:01:59.852Z,1626732119.852 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-07-19T22:01:59.852Z,1626732119.852 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-19T22:01:59.900Z,1626732119.900 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-19T22:02:00.269Z,1626732120.269 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-19T22:02:00.269Z,1626732120.269 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-07-19T22:02:24.091Z,1626732144.091 [Startup:StartupSatComms:A](INFO): Timed out from 2021-07-19T22:01:23.9Z
2021-07-19T22:02:24.091Z,1626732144.091 [Startup:StartupSatComms:A] Stopped
2021-07-19T22:02:24.091Z,1626732144.091 [Startup:StartupSatComms:B] Running Loop=1
2021-07-19T22:02:24.483Z,1626732144.483 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-07-19T22:02:44.807Z,1626732164.807 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004657
2021-07-19T22:02:52.161Z,1626732172.161 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210719T213749/Courier0018.lzma
2021-07-19T22:02:53.163Z,1626732173.163 [DataOverHttps](INFO): Moved sent file to Logs/20210719T213749/Courier0018.lzma.bak
2021-07-19T22:02:53.163Z,1626732173.163 [DataOverHttps](INFO): SBD MOMSN=15749267
2021-07-19T22:03:08.601Z,1626732188.601 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210719T215848/Courier0000.lzma
2021-07-19T22:03:09.603Z,1626732189.603 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Courier0000.lzma.bak
2021-07-19T22:03:09.603Z,1626732189.603 [DataOverHttps](INFO): SBD MOMSN=15749269
2021-07-19T22:03:24.326Z,1626732204.326 [Startup:StartupSatComms:B](INFO): Timed out from 2021-07-19T22:02:24.1Z
2021-07-19T22:03:24.326Z,1626732204.326 [Startup:StartupSatComms:B] Stopped
2021-07-19T22:03:24.326Z,1626732204.326 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-07-19T22:03:24.326Z,1626732204.326 [Startup:StartupSatComms] Stopped
2021-07-19T22:03:24.326Z,1626732204.326 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-07-19T22:03:24.327Z,1626732204.327 [Startup](INFO): Completed Startup
2021-07-19T22:03:24.327Z,1626732204.327 [MissionManager](INFO): Startup is completed.
2021-07-19T22:03:24.327Z,1626732204.327 [MissionManager](INFO): Uninitializing Mission Startup
2021-07-19T22:03:24.328Z,1626732204.328 [Startup] Stopped
2021-07-19T22:03:24.328Z,1626732204.328 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-07-19T22:03:24.328Z,1626732204.328 [Startup:A.GoToSurface] Stopped
2021-07-19T22:03:24.328Z,1626732204.328 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-19T22:03:24.707Z,1626732204.707 [MissionManager](IMPORTANT): Started mission Default
2021-07-19T22:03:24.707Z,1626732204.707 [Default] Running Loop=1
2021-07-19T22:03:24.707Z,1626732204.707 [Default](DEBUG): Aggregate::initialize Default
2021-07-19T22:03:24.707Z,1626732204.707 [Default:B.GoToSurface] Running Loop=1
2021-07-19T22:03:24.708Z,1626732204.708 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-19T22:03:24.708Z,1626732204.708 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-19T22:03:24.708Z,1626732204.708 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-19T22:03:24.708Z,1626732204.708 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-19T22:03:24.713Z,1626732204.713 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-19T22:03:24.713Z,1626732204.713 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-19T22:03:24.714Z,1626732204.714 [Default:A.Wait] Running Loop=1
2021-07-19T22:03:24.714Z,1626732204.714 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-07-19T22:03:27.068Z,1626732207.068 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210719T213749/Express0016.lzma
2021-07-19T22:03:29.190Z,1626732209.190 [DataOverHttps](INFO): Moved sent file to Logs/20210719T213749/Express0016.lzma.bak
2021-07-19T22:03:29.191Z,1626732209.191 [DataOverHttps](INFO): SBD MOMSN=15749272
2021-07-19T22:03:38.012Z,1626732218.012 [Default:A.Wait](INFO): Done Waiting.
2021-07-19T22:03:38.012Z,1626732218.012 [Default:A.Wait] Stopped
2021-07-19T22:03:38.012Z,1626732218.012 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-07-19T22:03:38.415Z,1626732218.415 [Default:CheckIn] Running Loop=1
2021-07-19T22:03:38.415Z,1626732218.415 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-19T22:03:38.415Z,1626732218.415 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-19T22:03:38.824Z,1626732218.824 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-07-19T22:04:42.650Z,1626732282.650 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-07-19T22:04:43.861Z,1626732283.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220442.00,A,3648.16005,N,12147.28025,W,0.467,326.88,190721,,,A*77
2021-07-19T22:04:43.864Z,1626732283.864 [NAL9602](INFO): GPS fix at 20210719T220442: (36.802667, -121.788004)
2021-07-19T22:04:43.876Z,1626732283.876 [Default:CheckIn:Read_GPS] Stopped
2021-07-19T22:04:43.876Z,1626732283.876 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-19T22:04:44.298Z,1626732284.298 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-07-19T22:04:54.021Z,1626732294.021 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20210719T215848/Courier0004.lzma
2021-07-19T22:04:55.024Z,1626732295.024 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Courier0004.lzma.bak
2021-07-19T22:04:55.024Z,1626732295.024 [DataOverHttps](INFO): SBD MOMSN=15749274
2021-07-19T22:05:14.492Z,1626732314.492 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20210719T213749/Express0019.lzma
2021-07-19T22:05:15.491Z,1626732315.491 [DataOverHttps](INFO): Moved sent file to Logs/20210719T213749/Express0019.lzma.bak
2021-07-19T22:05:15.491Z,1626732315.491 [DataOverHttps](INFO): SBD MOMSN=15749277
2021-07-19T22:05:16.197Z,1626732316.197 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-19T22:05:33.581Z,1626732333.581 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210719T213749/Express0022.lzma
2021-07-19T22:05:34.583Z,1626732334.583 [DataOverHttps](INFO): Moved sent file to Logs/20210719T213749/Express0022.lzma.bak
2021-07-19T22:05:34.583Z,1626732334.583 [DataOverHttps](INFO): SBD MOMSN=15749283
2021-07-19T22:05:52.534Z,1626732352.534 [DataOverHttps](INFO): Sending 894 bytes from file Logs/20210719T215848/Express0001.lzma
2021-07-19T22:05:53.535Z,1626732353.535 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Express0001.lzma.bak
2021-07-19T22:05:53.535Z,1626732353.535 [DataOverHttps](INFO): SBD MOMSN=15749285
2021-07-19T22:06:11.737Z,1626732371.737 [DataOverHttps](INFO): Sending 332 bytes from file Logs/20210719T215848/Express0005.lzma
2021-07-19T22:06:12.739Z,1626732372.739 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Express0005.lzma.bak
2021-07-19T22:06:12.739Z,1626732372.739 [DataOverHttps](INFO): SBD MOMSN=15749305
2021-07-19T22:06:15.630Z,1626732375.630 [Default:CheckIn:Read_Iridium] Stopped
2021-07-19T22:06:15.630Z,1626732375.630 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-19T22:06:15.630Z,1626732375.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-19T22:06:29.413Z,1626732389.413 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-07-19T22:06:29.416Z,1626732389.416 [BPC1](INFO): Received data from all battery sticks.
2021-07-19T22:09:00.981Z,1626732540.981 [Power24vConverter](INFO): Powering down.
2021-07-19T22:11:16.408Z,1626732676.408 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-19T22:11:16.408Z,1626732676.408 [Default:CheckIn:C.Wait] Stopped
2021-07-19T22:11:16.408Z,1626732676.408 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-19T22:11:16.409Z,1626732676.409 [Default:CheckIn:D] Running Loop=1
2021-07-19T22:11:16.827Z,1626732676.827 [Default:CheckIn:D] Stopped
2021-07-19T22:11:16.827Z,1626732676.827 [Default:CheckIn:E] Running Loop=1
2021-07-19T22:11:17.232Z,1626732677.232 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.868658 min
2021-07-19T22:11:17.233Z,1626732677.233 [Default:CheckIn:E] Stopped
2021-07-19T22:11:17.233Z,1626732677.233 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-19T22:11:17.233Z,1626732677.233 [Default:CheckIn] Stopped
2021-07-19T22:11:17.233Z,1626732677.233 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-19T22:11:17.233Z,1626732677.233 [Default:CheckIn](INFO): Running loop #2
2021-07-19T22:11:17.234Z,1626732677.234 [Default:CheckIn] Running Loop=2
2021-07-19T22:11:17.234Z,1626732677.234 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-19T22:11:17.234Z,1626732677.234 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-19T22:11:19.224Z,1626732679.224 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221118.00,A,3648.14936,N,12147.27650,W,1.263,155.46,190721,,,A*7B
2021-07-19T22:11:19.227Z,1626732679.227 [NAL9602](INFO): GPS fix at 20210719T221118: (36.802489, -121.787942)
2021-07-19T22:11:19.276Z,1626732679.276 [Default:CheckIn:Read_GPS] Stopped
2021-07-19T22:11:19.276Z,1626732679.276 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-19T22:11:26.865Z,1626732686.865 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20210719T215848/Courier0007.lzma
2021-07-19T22:11:27.867Z,1626732687.867 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Courier0007.lzma.bak
2021-07-19T22:11:27.867Z,1626732687.867 [DataOverHttps](INFO): SBD MOMSN=15749309
2021-07-19T22:11:45.477Z,1626732705.477 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20210719T215848/Express0008.lzma
2021-07-19T22:11:46.479Z,1626732706.479 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Express0008.lzma.bak
2021-07-19T22:11:46.479Z,1626732706.479 [DataOverHttps](INFO): SBD MOMSN=15749312
2021-07-19T22:11:49.581Z,1626732709.581 [Default:CheckIn:Read_Iridium] Stopped
2021-07-19T22:11:49.581Z,1626732709.581 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-19T22:11:49.581Z,1626732709.581 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-19T22:13:08.704Z,1626732788.704 [DataOverHttps](IMPORTANT): SBD MTMSN=20210719T221307
2021-07-19T22:13:16.025Z,1626732796.025 [DataOverHttps](INFO): Received command:sched asap "load Maintenance/tank_ballast_and_trim.xml;set ballast_and_trim.MissionTimeout 30 min;set ballast_and_trim.Depth1 2 m;set ballast_and_trim.SurfaceThreshold 1 m;set ballast_and_trim.EstimationTimeout 15 min" 1fppf 1 2
2021-07-19T22:13:16.055Z,1626732796.055 [CommandLine](IMPORTANT): got command schedule asap "load Maintenance/tank_ballast_and_trim.xml;set ballast_and_trim.MissionTimeout 30 min;set ballast_and_trim.Depth1 2 m;set ballast_and_trim.SurfaceThreshold 1 m;set ballast_and_trim.EstimationTimeout 15 min" 1fppf 1 2.000000
2021-07-19T22:13:16.055Z,1626732796.055 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=1fppf
2021-07-19T22:13:16.056Z,1626732796.056 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='1fppf'): "load Maintenance/tank_ballast_and_trim.xml;set ballast_and_trim.MissionTimeout 30 min;set ballast_and_trim.Depth1 2 m;set ballast_and_trim.SurfaceThreshold 1 m;set ballast_and_trim.EstimationTimeout 15 min" ASAP
2021-07-19T22:13:17.027Z,1626732797.027 [DataOverHttps](IMPORTANT): SBD MTMSN=20210719T221316
2021-07-19T22:13:24.709Z,1626732804.709 [DataOverHttps](INFO): Received command:sched asap "set ballast_and_trim.MassEstimationErrorBound 1 mm;set ballast_and_trim.BuoyEstimationErrorBound 25 cc;set ballast_and_trim.EstimationConfidence 98.0 %;run" 1fppf 2 2
2021-07-19T22:13:24.778Z,1626732804.778 [CommandLine](IMPORTANT): got command schedule asap "set ballast_and_trim.MassEstimationErrorBound 1 mm;set ballast_and_trim.BuoyEstimationErrorBound 25 cc;set ballast_and_trim.EstimationConfidence 98.0 %;run" 1fppf 2 2.000000
2021-07-19T22:13:24.778Z,1626732804.778 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=1fppf
2021-07-19T22:13:24.779Z,1626732804.779 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='1fppf'): "set ballast_and_trim.MassEstimationErrorBound 1 mm;set ballast_and_trim.BuoyEstimationErrorBound 25 cc;set ballast_and_trim.EstimationConfidence 98.0 %;run" ASAP
2021-07-19T22:13:24.995Z,1626732804.995 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/tank_ballast_and_trim.xml
2021-07-19T22:13:24.995Z,1626732804.995 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_ballast_and_trim.xml
2021-07-19T22:13:25.041Z,1626732805.041 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2021-07-19T22:13:25.043Z,1626732805.043 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2021-07-19T22:13:25.095Z,1626732805.095 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2021-07-19T22:13:25.099Z,1626732805.099 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2021-07-19T22:13:25.121Z,1626732805.121 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2021-07-19T22:13:25.124Z,1626732805.124 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2021-07-19T22:13:25.127Z,1626732805.127 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2021-07-19T22:13:25.143Z,1626732805.143 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2021-07-19T22:13:25.146Z,1626732805.146 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2021-07-19T22:13:25.149Z,1626732805.149 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2021-07-19T22:13:25.152Z,1626732805.152 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2021-07-19T22:13:25.194Z,1626732805.194 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2021-07-19T22:13:25.197Z,1626732805.197 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900000 %
2021-07-19T22:13:25.200Z,1626732805.200 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2021-07-19T22:13:25.201Z,1626732805.201 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2021-07-19T22:13:25.650Z,1626732805.650 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2021-07-19T22:13:25.653Z,1626732805.653 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2021-07-19T22:13:25.656Z,1626732805.656 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2021-07-19T22:13:25.658Z,1626732805.658 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2021-07-19T22:13:25.661Z,1626732805.661 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2021-07-19T22:13:25.664Z,1626732805.664 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2021-07-19T22:13:25.667Z,1626732805.667 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2021-07-19T22:13:25.670Z,1626732805.670 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2021-07-19T22:13:25.673Z,1626732805.673 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2021-07-19T22:13:25.676Z,1626732805.676 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2021-07-19T22:13:25.761Z,1626732805.761 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2021-07-19T22:13:25.764Z,1626732805.764 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2021-07-19T22:13:25.771Z,1626732805.771 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2021-07-19T22:13:25.798Z,1626732805.798 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2021-07-19T22:13:25.807Z,1626732805.807 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0.000000 bool
2021-07-19T22:13:25.811Z,1626732805.811 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0.000000 bool
2021-07-19T22:13:25.831Z,1626732805.831 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1.000000 bool
2021-07-19T22:13:25.835Z,1626732805.835 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1.000000 bool
2021-07-19T22:13:25.847Z,1626732805.847 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2021-07-19T22:13:25.850Z,1626732805.850 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0.000000 bool
2021-07-19T22:13:25.866Z,1626732805.866 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2021-07-19T22:13:25.873Z,1626732805.873 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2021-07-19T22:13:25.876Z,1626732805.876 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2021-07-19T22:13:25.884Z,1626732805.884 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2021-07-19T22:13:25.888Z,1626732805.888 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2021-07-19T22:13:25.908Z,1626732805.908 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2021-07-19T22:13:25.923Z,1626732805.923 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2021-07-19T22:13:25.926Z,1626732805.926 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2021-07-19T22:13:25.942Z,1626732805.942 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2021-07-19T22:13:25.945Z,1626732805.945 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2021-07-19T22:13:25.948Z,1626732805.948 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2021-07-19T22:13:25.951Z,1626732805.951 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2021-07-19T22:13:25.978Z,1626732805.978 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2021-07-19T22:13:25.981Z,1626732805.981 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2021-07-19T22:13:25.984Z,1626732805.984 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2021-07-19T22:13:25.999Z,1626732805.999 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2021-07-19T22:13:26.003Z,1626732806.003 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2021-07-19T22:13:26.006Z,1626732806.006 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2021-07-19T22:13:26.029Z,1626732806.029 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2021-07-19T22:13:26.032Z,1626732806.032 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2021-07-19T22:13:26.038Z,1626732806.038 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2021-07-19T22:13:26.054Z,1626732806.054 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2021-07-19T22:13:26.057Z,1626732806.057 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2021-07-19T22:13:26.061Z,1626732806.061 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2021-07-19T22:13:26.064Z,1626732806.064 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2021-07-19T22:13:26.083Z,1626732806.083 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2021-07-19T22:13:26.086Z,1626732806.086 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2021-07-19T22:13:26.134Z,1626732806.134 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2021-07-19T22:13:26.138Z,1626732806.138 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2021-07-19T22:13:26.171Z,1626732806.171 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2021-07-19T22:13:26.174Z,1626732806.174 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2021-07-19T22:13:26.197Z,1626732806.197 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2021-07-19T22:13:26.201Z,1626732806.201 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2021-07-19T22:13:26.204Z,1626732806.204 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2021-07-19T22:13:26.207Z,1626732806.207 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2021-07-19T22:13:26.221Z,1626732806.221 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2021-07-19T22:13:26.225Z,1626732806.225 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2021-07-19T22:13:26.228Z,1626732806.228 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2021-07-19T22:13:26.253Z,1626732806.253 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2021-07-19T22:13:26.256Z,1626732806.256 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2021-07-19T22:13:26.259Z,1626732806.259 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2021-07-19T22:13:26.266Z,1626732806.266 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2021-07-19T22:13:26.269Z,1626732806.269 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2021-07-19T22:13:26.273Z,1626732806.273 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2021-07-19T22:13:26.394Z,1626732806.394 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-19T22:13:26.434Z,1626732806.434 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2021-07-19T22:13:26.478Z,1626732806.478 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-19T22:13:26.500Z,1626732806.500 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-19T22:13:26.590Z,1626732806.590 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2021-07-19T22:13:26.626Z,1626732806.626 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-19T22:13:26.670Z,1626732806.670 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-19T22:13:26.704Z,1626732806.704 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2021-07-19T22:13:26.751Z,1626732806.751 [MissionManager](INFO): Inserting Stack: Missions/Insert/BallastAndTrim.xml
2021-07-19T22:13:27.046Z,1626732807.046 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2021-07-19T22:13:27.058Z,1626732807.058 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2021-07-19T22:13:27.065Z,1626732807.065 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2021-07-19T22:13:27.071Z,1626732807.071 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2021-07-19T22:13:27.075Z,1626732807.075 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2021-07-19T22:13:27.078Z,1626732807.078 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2021-07-19T22:13:27.090Z,1626732807.090 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2021-07-19T22:13:27.116Z,1626732807.116 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2021-07-19T22:13:27.120Z,1626732807.120 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2021-07-19T22:13:27.123Z,1626732807.123 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2021-07-19T22:13:27.138Z,1626732807.138 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2021-07-19T22:13:27.142Z,1626732807.142 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900000 %
2021-07-19T22:13:27.145Z,1626732807.145 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2021-07-19T22:13:27.148Z,1626732807.148 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertKiDepthBuoy = 0.300000 1/s
2021-07-19T22:13:27.174Z,1626732807.174 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2021-07-19T22:13:27.242Z,1626732807.242 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2021-07-19T22:13:27.250Z,1626732807.250 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2021-07-19T22:13:27.270Z,1626732807.270 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2021-07-19T22:13:27.298Z,1626732807.298 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2021-07-19T22:13:27.302Z,1626732807.302 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2021-07-19T22:13:27.311Z,1626732807.311 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2021-07-19T22:13:27.382Z,1626732807.382 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2021-07-19T22:13:27.386Z,1626732807.386 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2021-07-19T22:13:27.409Z,1626732807.409 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2021-07-19T22:13:27.425Z,1626732807.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2021-07-19T22:13:27.432Z,1626732807.432 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2021-07-19T22:13:27.498Z,1626732807.498 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2021-07-19T22:13:27.500Z,1626732807.500 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2021-07-19T22:13:27.502Z,1626732807.502 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2021-07-19T22:13:27.503Z,1626732807.503 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2021-07-19T22:13:27.523Z,1626732807.523 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2021-07-19T22:13:27.525Z,1626732807.525 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2021-07-19T22:13:27.527Z,1626732807.527 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2021-07-19T22:13:27.529Z,1626732807.529 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2021-07-19T22:13:27.553Z,1626732807.553 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2021-07-19T22:13:27.596Z,1626732807.596 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2021-07-19T22:13:27.640Z,1626732807.640 [MissionManager](DEBUG):
Maximum duration of mission
120
Skip communications at start of mission.
7
NaN
How much vertical drift from the specified depth is allowed durnig the
mission.
0.1
Surface threshold depth.
2.5
Maximum wait time for the vehicle to go under the surface (i.e., reach
the surface threshold depth).
20
How long to wait after reaching target depth before starting ballast and
trim.
10
Timeout for ballast and trim estimation.
45
Minimum time to run ballast and trim estimation before determining
convergence (must be shorter than timeout).
10
Desired range of the estimated sample mean from the true mean statistic
(smaller values take longer to converge).
0.25
Desired range of the estimated sample mean from the true mean statistic
(smaller values take longer to converge).
15
Confidence level that the estimator has reached the desired error range
(larger values take longer to converge).
99.9
5
Float to surface instead of driving.
2021-07-19T22:13:27.641Z,1626732807.641 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/tank_ballast_and_trim.xml
2021-07-19T22:13:38.006Z,1626732818.006 [CommandLine](IMPORTANT): got command set ballast_and_trim.MissionTimeout 30.000000 minute
2021-07-19T22:13:38.007Z,1626732818.007 [CommandLine](IMPORTANT): got command set ballast_and_trim.Depth1 2.000000 meter
2021-07-19T22:13:38.007Z,1626732818.007 [CommandLine](IMPORTANT): got command set ballast_and_trim.SurfaceThreshold 1.000000 meter
2021-07-19T22:13:38.008Z,1626732818.008 [CommandLine](IMPORTANT): got command set ballast_and_trim.EstimationTimeout 15.000000 minute
2021-07-19T22:13:46.500Z,1626732826.500 [CommandLine](IMPORTANT): got command set ballast_and_trim.MassEstimationErrorBound 1.000000 millimeter
2021-07-19T22:13:46.501Z,1626732826.501 [CommandLine](IMPORTANT): got command set ballast_and_trim.BuoyEstimationErrorBound 25.000000 cubic_centimeter
2021-07-19T22:13:46.502Z,1626732826.502 [CommandLine](IMPORTANT): got command set ballast_and_trim.EstimationConfidence 98.000000 percent
2021-07-19T22:13:46.502Z,1626732826.502 [CommandLine](IMPORTANT): got command run
2021-07-19T22:13:46.506Z,1626732826.506 [CommandLine](IMPORTANT): Running
2021-07-19T22:13:46.744Z,1626732826.744 [Default] Stopped
2021-07-19T22:13:46.745Z,1626732826.745 [Default](DEBUG): Aggregate::uninitialize Default
2021-07-19T22:13:46.745Z,1626732826.745 [Default:B.GoToSurface] Stopped
2021-07-19T22:13:46.745Z,1626732826.745 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-19T22:13:46.745Z,1626732826.745 [Default:CheckIn] Stopped
2021-07-19T22:13:46.745Z,1626732826.745 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-19T22:13:46.745Z,1626732826.745 [Default:CheckIn:C.Wait] Stopped
2021-07-19T22:13:46.745Z,1626732826.745 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-19T22:13:46.745Z,1626732826.745 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim] Running Loop=1
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim:Science] Running Loop=1
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim:Science:A] Running Loop=1
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim:Science:B] Running Loop=1
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim:Science:C] Running Loop=1
2021-07-19T22:13:46.746Z,1626732826.746 [ballast_and_trim:Science:D] Running Loop=1
2021-07-19T22:13:46.747Z,1626732826.747 [ballast_and_trim:Science:E] Running Loop=1
2021-07-19T22:13:46.747Z,1626732826.747 [ballast_and_trim:Science:F] Running Loop=1
2021-07-19T22:13:46.747Z,1626732826.747 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2021-07-19T22:13:46.747Z,1626732826.747 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2021-07-19T22:13:46.747Z,1626732826.747 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2021-07-19T22:13:46.747Z,1626732826.747 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2021-07-19T22:13:46.747Z,1626732826.747 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-19T22:13:46.761Z,1626732826.761 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2021-07-19T22:13:46.762Z,1626732826.762 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2021-07-19T22:13:46.762Z,1626732826.762 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2021-07-19T22:13:46.762Z,1626732826.762 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2021-07-19T22:13:46.762Z,1626732826.762 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2021-07-19T22:13:46.762Z,1626732826.762 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2021-07-19T22:13:46.763Z,1626732826.763 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2021-07-19T22:13:46.763Z,1626732826.763 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-19T22:13:46.765Z,1626732826.765 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2021-07-19T22:13:46.765Z,1626732826.765 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2021-07-19T22:13:46.765Z,1626732826.765 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2021-07-19T22:13:46.765Z,1626732826.765 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-19T22:13:46.767Z,1626732826.767 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2021-07-19T22:13:46.767Z,1626732826.767 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2021-07-19T22:13:46.767Z,1626732826.767 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2021-07-19T22:13:46.768Z,1626732826.768 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2021-07-19T22:13:46.768Z,1626732826.768 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2021-07-19T22:13:46.768Z,1626732826.768 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2021-07-19T22:13:46.768Z,1626732826.768 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2021-07-19T22:13:46.768Z,1626732826.768 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-19T22:13:46.770Z,1626732826.770 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2021-07-19T22:13:46.771Z,1626732826.771 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2021-07-19T22:13:46.771Z,1626732826.771 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2021-07-19T22:13:46.771Z,1626732826.771 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-19T22:13:46.773Z,1626732826.773 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2021-07-19T22:13:46.785Z,1626732826.785 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2021-07-19T22:13:46.785Z,1626732826.785 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2021-07-19T22:13:46.785Z,1626732826.785 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2021-07-19T22:13:46.786Z,1626732826.786 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2021-07-19T22:13:46.786Z,1626732826.786 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2021-07-19T22:13:46.786Z,1626732826.786 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2021-07-19T22:13:46.786Z,1626732826.786 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2021-07-19T22:13:46.786Z,1626732826.786 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2021-07-19T22:13:46.786Z,1626732826.786 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2021-07-19T22:13:46.787Z,1626732826.787 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2021-07-19T22:13:46.787Z,1626732826.787 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2021-07-19T22:13:46.787Z,1626732826.787 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2021-07-19T22:13:46.788Z,1626732826.788 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2021-07-19T22:13:46.788Z,1626732826.788 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2021-07-19T22:13:46.788Z,1626732826.788 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2021-07-19T22:13:46.788Z,1626732826.788 [ballast_and_trim:Science] Running Loop=1
2021-07-19T22:13:46.789Z,1626732826.789 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2021-07-19T22:13:46.790Z,1626732826.790 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:PeakDetectOil] Stopped
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2021-07-19T22:13:46.791Z,1626732826.791 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:PeakDetectChl] Stopped
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2021-07-19T22:13:46.792Z,1626732826.792 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2021-07-19T22:13:46.793Z,1626732826.793 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-19T22:13:46.793Z,1626732826.793 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2021-07-19T22:13:46.793Z,1626732826.793 [ballast_and_trim:Science:Read_Oil] Stopped
2021-07-19T22:13:46.793Z,1626732826.793 [ballast_and_trim:Science:F] Stopped
2021-07-19T22:13:46.793Z,1626732826.793 [ballast_and_trim:Science:E] Running Loop=1
2021-07-19T22:13:46.794Z,1626732826.794 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2021-07-19T22:13:46.794Z,1626732826.794 [ballast_and_trim:Science:D] Stopped
2021-07-19T22:13:46.794Z,1626732826.794 [ballast_and_trim:Science:C] Running Loop=1
2021-07-19T22:13:46.795Z,1626732826.795 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2021-07-19T22:13:46.796Z,1626732826.796 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2021-07-19T22:13:46.796Z,1626732826.796 [ballast_and_trim:Science:B] Running Loop=1
2021-07-19T22:13:46.796Z,1626732826.796 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2021-07-19T22:13:46.809Z,1626732826.809 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2021-07-19T22:13:46.809Z,1626732826.809 [ballast_and_trim:Science:A] Stopped
2021-07-19T22:13:46.989Z,1626732826.989 [WetLabsBB2FL](INFO): Powering up
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2021-07-19T22:13:47.151Z,1626732827.151 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G] Running Loop=1
2021-07-19T22:13:47.154Z,1626732827.154 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G](INFO): Going to target depth. Speed set to 0.000000 m/s
2021-07-19T22:13:47.154Z,1626732827.154 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G] Stopped
2021-07-19T22:13:47.154Z,1626732827.154 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2021-07-19T22:13:47.154Z,1626732827.154 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2021-07-19T22:13:47.155Z,1626732827.155 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2021-07-19T22:13:47.156Z,1626732827.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2021-07-19T22:13:47.156Z,1626732827.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2021-07-19T22:13:47.156Z,1626732827.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2021-07-19T22:13:47.156Z,1626732827.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2021-07-19T22:13:47.156Z,1626732827.156 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2021-07-19T22:13:47.157Z,1626732827.157 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2021-07-19T22:13:47.157Z,1626732827.157 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2021-07-19T22:13:47.158Z,1626732827.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2021-07-19T22:13:47.158Z,1626732827.158 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2021-07-19T22:13:47.554Z,1626732827.554 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2021-07-19T22:13:47.554Z,1626732827.554 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2021-07-19T22:13:47.555Z,1626732827.555 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2021-07-19T22:13:47.556Z,1626732827.556 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2021-07-19T22:13:47.556Z,1626732827.556 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2021-07-19T22:13:47.556Z,1626732827.556 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2021-07-19T22:13:47.556Z,1626732827.556 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2021-07-19T22:13:47.556Z,1626732827.556 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2021-07-19T22:13:47.980Z,1626732827.980 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2021-07-19T22:13:47.980Z,1626732827.980 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 2.000000 m
2021-07-19T22:13:47.981Z,1626732827.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2021-07-19T22:13:47.981Z,1626732827.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2021-07-19T22:13:47.981Z,1626732827.981 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2021-07-19T22:13:50.531Z,1626732830.531 [CTD_Seabird](ERROR): Failed to parse device response:
2021-07-19T22:15:50.077Z,1626732950.077 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:16:07.034Z,1626732967.034 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2021-07-19T22:16:07.034Z,1626732967.034 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2021-07-19T22:16:07.035Z,1626732967.035 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2021-07-19T22:16:07.035Z,1626732967.035 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2021-07-19T22:16:07.035Z,1626732967.035 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2021-07-19T22:16:07.035Z,1626732967.035 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2021-07-19T22:16:07.036Z,1626732967.036 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2021-07-19T22:16:07.036Z,1626732967.036 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2021-07-19T22:16:07.036Z,1626732967.036 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2021-07-19T22:16:07.036Z,1626732967.036 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2021-07-19T22:16:07.036Z,1626732967.036 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2021-07-19T22:16:07.037Z,1626732967.037 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2021-07-19T22:16:07.037Z,1626732967.037 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2021-07-19T22:16:07.037Z,1626732967.037 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2021-07-19T22:16:07.037Z,1626732967.037 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2021-07-19T22:16:07.037Z,1626732967.037 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2021-07-19T22:16:07.038Z,1626732967.038 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2021-07-19T22:16:07.428Z,1626732967.428 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 2.035582 m
2021-07-19T22:16:07.428Z,1626732967.428 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2021-07-19T22:16:07.428Z,1626732967.428 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2021-07-19T22:16:07.428Z,1626732967.428 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2021-07-19T22:16:07.428Z,1626732967.428 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2021-07-19T22:16:07.445Z,1626732967.445 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2021-07-19T22:16:21.205Z,1626732981.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:16:21.561Z,1626732981.561 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-07-19T22:16:41.921Z,1626733001.921 [Radio_Surface](INFO): Powering down
2021-07-19T22:16:52.262Z,1626733012.262 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-19T22:16:52.335Z,1626733012.335 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:16:53.337Z,1626733013.337 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-07-19T22:17:58.598Z,1626733078.598 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.735199
2021-07-19T22:26:08.216Z,1626733568.216 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2021-07-19T22:26:08.217Z,1626733568.217 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2021-07-19T22:26:08.217Z,1626733568.217 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2021-07-19T22:26:08.217Z,1626733568.217 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2021-07-19T22:26:08.603Z,1626733568.603 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 2.433329 m
2021-07-19T22:26:08.604Z,1626733568.604 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2021-07-19T22:26:08.604Z,1626733568.604 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2021-07-19T22:26:08.604Z,1626733568.604 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2021-07-19T22:36:09.399Z,1626734169.399 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 10.01 minutes.
2021-07-19T22:36:09.400Z,1626734169.400 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 406.019663 +/- 3.058899 cc (conf. level 98.00%, sigma: 16.681511 cc).
2021-07-19T22:36:09.406Z,1626734169.406 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: -17.052770 +/- 0.132380 mm (conf. level 98.00%, sigma: 0.721927 mm).
2021-07-19T22:36:09.406Z,1626734169.406 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 406.019663 cc buoyancy neutral and -17.052770 mm mass default
2021-07-19T22:36:09.415Z,1626734169.415 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-07-19T22:36:09.415Z,1626734169.415 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): AMEcho.loadAtStartup=0 bool;
2021-07-19T22:36:09.416Z,1626734169.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CANONSampler.loadAtStartup=1 bool;
2021-07-19T22:36:09.416Z,1626734169.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.loadAtStartup=0 bool;
2021-07-19T22:36:09.416Z,1626734169.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.verbosity=3 count;
2021-07-19T22:36:09.416Z,1626734169.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;
2021-07-19T22:36:09.416Z,1626734169.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=406.019663 cubic_centimeter;
2021-07-19T22:36:09.416Z,1626734169.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;
2021-07-19T22:36:09.416Z,1626734169.416 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.kpDepthBuoy=60 ratio;
2021-07-19T22:36:09.417Z,1626734169.417 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=-17.052770 millimeter;
2021-07-19T22:36:09.421Z,1626734169.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2021-07-19T22:36:09.421Z,1626734169.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2021-07-19T22:36:09.422Z,1626734169.422 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2021-07-19T22:36:09.422Z,1626734169.422 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2021-07-19T22:36:09.423Z,1626734169.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2021-07-19T22:36:09.423Z,1626734169.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2021-07-19T22:36:09.423Z,1626734169.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2021-07-19T22:36:09.423Z,1626734169.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2021-07-19T22:36:09.424Z,1626734169.424 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2021-07-19T22:36:09.424Z,1626734169.424 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2021-07-19T22:36:09.425Z,1626734169.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2021-07-19T22:36:09.429Z,1626734169.429 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2021-07-19T22:36:09.429Z,1626734169.429 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2021-07-19T22:36:09.429Z,1626734169.429 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2021-07-19T22:36:09.429Z,1626734169.429 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2021-07-19T22:36:09.429Z,1626734169.429 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2021-07-19T22:36:09.429Z,1626734169.429 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2021-07-19T22:36:09.802Z,1626734169.802 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2021-07-19T22:36:09.803Z,1626734169.803 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2021-07-19T22:36:10.208Z,1626734170.208 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2021-07-19T22:36:10.208Z,1626734170.208 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2021-07-19T22:36:10.208Z,1626734170.208 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2021-07-19T22:36:10.208Z,1626734170.208 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2021-07-19T22:36:10.208Z,1626734170.208 [ballast_and_trim:RunBallastAndTrim] Stopped
2021-07-19T22:36:10.208Z,1626734170.208 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2021-07-19T22:36:10.209Z,1626734170.209 [ballast_and_trim:Float_Up] Running Loop=1
2021-07-19T22:36:10.209Z,1626734170.209 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2021-07-19T22:36:10.209Z,1626734170.209 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2021-07-19T22:36:10.209Z,1626734170.209 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2021-07-19T22:36:10.209Z,1626734170.209 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2021-07-19T22:36:10.209Z,1626734170.209 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2021-07-19T22:36:10.641Z,1626734170.641 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2021-07-19T22:37:09.993Z,1626734229.993 [ballast_and_trim:Float_Up] Stopped
2021-07-19T22:37:09.993Z,1626734229.993 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2021-07-19T22:37:09.993Z,1626734229.993 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2021-07-19T22:37:09.993Z,1626734229.993 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2021-07-19T22:37:09.993Z,1626734229.993 [ballast_and_trim:Float_Up:B.Wait] Stopped
2021-07-19T22:37:09.994Z,1626734229.994 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2021-07-19T22:37:09.995Z,1626734229.995 [ballast_and_trim](INFO): Completed ballast_and_trim
2021-07-19T22:37:09.995Z,1626734229.995 [MissionManager](INFO): ballast_and_trim is completed.
2021-07-19T22:37:09.996Z,1626734229.996 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim] Stopped
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim:Science] Stopped
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim:Science:B] Stopped
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim:Science:C] Stopped
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim:Science:E] Stopped
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim:Science:OceanCurrent] Stopped
2021-07-19T22:37:09.996Z,1626734229.996 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2021-07-19T22:37:09.997Z,1626734229.997 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2021-07-19T22:37:10.153Z,1626734230.153 [WetLabsBB2FL](INFO): Powering down
2021-07-19T22:37:10.398Z,1626734230.398 [MissionManager](IMPORTANT): Started mission Default
2021-07-19T22:37:10.398Z,1626734230.398 [Default] Running Loop=1
2021-07-19T22:37:10.398Z,1626734230.398 [Default](DEBUG): Aggregate::initialize Default
2021-07-19T22:37:10.398Z,1626734230.398 [Default:B.GoToSurface] Running Loop=1
2021-07-19T22:37:10.399Z,1626734230.399 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-19T22:37:10.399Z,1626734230.399 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-19T22:37:10.399Z,1626734230.399 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-19T22:37:10.400Z,1626734230.400 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-19T22:37:10.400Z,1626734230.400 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-19T22:37:10.400Z,1626734230.400 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-19T22:37:10.401Z,1626734230.401 [Default:A.Wait] Running Loop=1
2021-07-19T22:37:10.401Z,1626734230.401 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-07-19T22:37:10.549Z,1626734230.549 [Radio_Surface](INFO): Powering up
2021-07-19T22:37:16.457Z,1626734236.457 [DataOverHttps](INFO): Radio surface powered ON.
2021-07-19T22:37:23.744Z,1626734243.744 [Default:A.Wait](INFO): Done Waiting.
2021-07-19T22:37:23.744Z,1626734243.744 [Default:A.Wait] Stopped
2021-07-19T22:37:23.744Z,1626734243.744 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-07-19T22:37:24.133Z,1626734244.133 [Default:CheckIn] Running Loop=1
2021-07-19T22:37:24.133Z,1626734244.133 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-19T22:37:24.133Z,1626734244.133 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-19T22:37:46.577Z,1626734266.577 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:37:56.843Z,1626734276.843 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2021-07-19T22:37:56.917Z,1626734276.917 [NAL9602](ERROR): received:
+CSQ:0
OK
2021-07-19T22:38:17.701Z,1626734297.701 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:38:24.320Z,1626734304.320 [NAL9602](INFO): SBD MO Status=2, MOMSN=28486, MT Status=2, MTMSN=0
2021-07-19T22:38:24.320Z,1626734304.320 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-19T22:38:48.826Z,1626734328.826 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:39:19.949Z,1626734359.949 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:39:51.089Z,1626734391.089 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:40:22.213Z,1626734422.213 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:40:53.346Z,1626734453.346 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-19T22:41:04.789Z,1626734464.789 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003647
2021-07-19T22:42:24.331Z,1626734544.331 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-19T22:37:24.1Z
2021-07-19T22:42:24.331Z,1626734544.331 [Default:CheckIn:Read_GPS] Stopped
2021-07-19T22:42:24.332Z,1626734544.332 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-19T22:42:28.207Z,1626734548.207 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-07-19T22:42:36.653Z,1626734556.653 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210719T215848/Courier0010.lzma
2021-07-19T22:42:37.655Z,1626734557.655 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Courier0010.lzma.bak
2021-07-19T22:42:37.656Z,1626734557.656 [DataOverHttps](IMPORTANT): SBD MOMSN=15749319, MTMSN=20210719T224236
2021-07-19T22:42:46.885Z,1626734566.885 [DataOverHttps](INFO): Received command:failc
2021-07-19T22:42:46.892Z,1626734566.892 [CommandLine](IMPORTANT): got command failComponent
2021-07-19T22:42:46.893Z,1626734566.893 [CommandLine](IMPORTANT): Failed components:
2021-07-19T22:42:46.893Z,1626734566.893 [CommandLine](IMPORTANT): No failed Components.
2021-07-19T22:42:56.403Z,1626734576.403 [DataOverHttps](INFO): Sending 1524 bytes from file Logs/20210719T215848/Express0011.lzma
2021-07-19T22:42:57.403Z,1626734577.403 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Express0011.lzma.bak
2021-07-19T22:42:57.403Z,1626734577.403 [DataOverHttps](INFO): SBD MOMSN=15749322
2021-07-19T22:42:58.922Z,1626734578.922 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-19T22:43:14.269Z,1626734594.269 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210719T215848/Courier0015.lzma
2021-07-19T22:43:15.271Z,1626734595.271 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Courier0015.lzma.bak
2021-07-19T22:43:15.271Z,1626734595.271 [DataOverHttps](INFO): SBD MOMSN=15749360
2021-07-19T22:43:34.192Z,1626734614.192 [DataOverHttps](INFO): Sending 251 bytes from file Logs/20210719T215848/Express0017.lzma
2021-07-19T22:43:35.199Z,1626734615.199 [DataOverHttps](INFO): Moved sent file to Logs/20210719T215848/Express0017.lzma.bak
2021-07-19T22:43:35.199Z,1626734615.199 [DataOverHttps](INFO): SBD MOMSN=15749362
2021-07-19T22:43:38.113Z,1626734618.113 [Default:CheckIn:Read_Iridium] Stopped
2021-07-19T22:43:38.113Z,1626734618.113 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-19T22:43:38.113Z,1626734618.113 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-19T22:45:26.270Z,1626734726.270 [DataOverHttps](IMPORTANT): SBD MTMSN=20210719T224525
2021-07-19T22:45:33.809Z,1626734733.809 [DataOverHttps](INFO): Received command:restart logs
2021-07-19T22:45:33.859Z,1626734733.859 [CommandLine](IMPORTANT): got command restart logs