2021-07-20T19:30:53.603Z,1626809453.603 [Supervisor](DEBUG): Initializing supervisor.
2021-07-20T19:30:53.608Z,1626809453.608 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-07-20T19:30:53.609Z,1626809453.609 [SyncHandler](INFO): Protected caller Thread ID is 1274
2021-07-20T19:30:53.609Z,1626809453.609 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-07-20T19:30:53.610Z,1626809453.610 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-07-20T19:30:53.611Z,1626809453.611 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1275
2021-07-20T19:30:53.615Z,1626809453.615 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-07-20T19:30:53.636Z,1626809453.636 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-07-20T19:30:53.637Z,1626809453.637 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-07-20T19:30:53.637Z,1626809453.637 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1276
2021-07-20T19:30:53.639Z,1626809453.639 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-07-20T19:30:53.640Z,1626809453.640 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-07-20T19:30:53.641Z,1626809453.641 [logger ThreadHandler](INFO): Protected caller Thread ID is 1277
2021-07-20T19:30:53.644Z,1626809453.644 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-07-20T19:30:53.645Z,1626809453.645 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-07-20T19:30:53.646Z,1626809453.646 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-07-20T19:30:53.885Z,1626809453.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-07-20T19:30:53.885Z,1626809453.885 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-07-20T19:30:53.966Z,1626809453.966 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-07-20T19:30:54.487Z,1626809454.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-07-20T19:30:54.488Z,1626809454.488 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-07-20T19:30:54.839Z,1626809454.839 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-07-20T19:30:54.840Z,1626809454.840 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-07-20T19:30:54.937Z,1626809454.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-07-20T19:30:54.937Z,1626809454.937 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-07-20T19:30:55.410Z,1626809455.410 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-07-20T19:30:55.411Z,1626809455.411 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-07-20T19:30:55.618Z,1626809455.618 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-07-20T19:30:55.619Z,1626809455.619 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-07-20T19:30:56.104Z,1626809456.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-07-20T19:30:56.105Z,1626809456.105 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-07-20T19:30:56.233Z,1626809456.233 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-07-20T19:30:56.234Z,1626809456.234 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-07-20T19:30:56.313Z,1626809456.313 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-07-20T19:30:57.015Z,1626809457.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-07-20T19:30:57.015Z,1626809457.015 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-07-20T19:30:57.396Z,1626809457.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-07-20T19:30:57.397Z,1626809457.397 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-07-20T19:30:57.601Z,1626809457.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-07-20T19:30:57.602Z,1626809457.602 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-07-20T19:30:57.715Z,1626809457.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-07-20T19:30:57.716Z,1626809457.716 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-07-20T19:30:57.872Z,1626809457.872 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-07-20T19:30:57.873Z,1626809457.873 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-07-20T19:30:58.117Z,1626809458.117 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-07-20T19:30:58.119Z,1626809458.119 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-07-20T19:30:58.119Z,1626809458.119 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-07-20T19:30:58.211Z,1626809458.211 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-07-20T19:30:58.297Z,1626809458.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-07-20T19:30:58.401Z,1626809458.401 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-07-20T19:30:58.484Z,1626809458.484 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-07-20T19:30:58.582Z,1626809458.582 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-07-20T19:30:58.686Z,1626809458.686 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-07-20T19:30:58.887Z,1626809458.887 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-07-20T19:30:58.963Z,1626809458.963 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-07-20T19:30:59.118Z,1626809459.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-07-20T19:30:59.261Z,1626809459.261 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-07-20T19:30:59.382Z,1626809459.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-07-20T19:30:59.649Z,1626809459.649 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-07-20T19:30:59.650Z,1626809459.650 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-07-20T19:30:59.661Z,1626809459.661 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-07-20T19:30:59.719Z,1626809459.719 [VerticalControl](DEBUG): Construct VerticalControl.
2021-07-20T19:30:59.783Z,1626809459.783 [VerticalControl] Loaded
2021-07-20T19:30:59.783Z,1626809459.783 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-07-20T19:30:59.786Z,1626809459.786 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-07-20T19:30:59.826Z,1626809459.826 [HorizontalControl] Loaded
2021-07-20T19:30:59.827Z,1626809459.827 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-07-20T19:30:59.829Z,1626809459.829 [SpeedControl](DEBUG): Construct SpeedControl.
2021-07-20T19:30:59.832Z,1626809459.832 [SpeedControl] Loaded
2021-07-20T19:30:59.833Z,1626809459.833 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-07-20T19:30:59.835Z,1626809459.835 [LoopControl](DEBUG): Construct LoopControl.
2021-07-20T19:30:59.836Z,1626809459.836 [LoopControl] Loaded
2021-07-20T19:30:59.836Z,1626809459.836 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-07-20T19:30:59.836Z,1626809459.836 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-07-20T19:30:59.837Z,1626809459.837 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-07-20T19:30:59.848Z,1626809459.848 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-07-20T19:30:59.849Z,1626809459.849 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-07-20T19:30:59.959Z,1626809459.959 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-07-20T19:30:59.960Z,1626809459.960 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-07-20T19:31:00.116Z,1626809460.116 [BuoyancyServo] Loaded
2021-07-20T19:31:00.116Z,1626809460.116 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-07-20T19:31:00.136Z,1626809460.136 [ElevatorServo] Loaded
2021-07-20T19:31:00.136Z,1626809460.136 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-07-20T19:31:00.154Z,1626809460.154 [MassServo] Loaded
2021-07-20T19:31:00.155Z,1626809460.155 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-07-20T19:31:00.173Z,1626809460.173 [RudderServo] Loaded
2021-07-20T19:31:00.174Z,1626809460.174 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-07-20T19:31:00.191Z,1626809460.191 [ThrusterServo] Loaded
2021-07-20T19:31:00.191Z,1626809460.191 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-07-20T19:31:00.192Z,1626809460.192 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-07-20T19:31:00.193Z,1626809460.193 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-07-20T19:31:00.526Z,1626809460.526 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-07-20T19:31:00.526Z,1626809460.526 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-07-20T19:31:00.540Z,1626809460.540 [NavChart] Loaded
2021-07-20T19:31:00.540Z,1626809460.540 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-07-20T19:31:00.546Z,1626809460.546 [UniversalFixResidualReporter] Loaded
2021-07-20T19:31:00.546Z,1626809460.546 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-07-20T19:31:00.546Z,1626809460.546 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-07-20T19:31:00.547Z,1626809460.547 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-07-20T19:31:00.829Z,1626809460.829 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-07-20T19:31:00.829Z,1626809460.829 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-07-20T19:31:01.313Z,1626809461.313 [AHRS_M2] Loaded
2021-07-20T19:31:01.313Z,1626809461.313 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-07-20T19:31:02.121Z,1626809462.121 [BPC1] Loaded
2021-07-20T19:31:02.122Z,1626809462.122 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-07-20T19:31:02.196Z,1626809462.196 [DataOverHttps] Loaded
2021-07-20T19:31:02.196Z,1626809462.196 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-07-20T19:31:02.197Z,1626809462.197 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408854E0
2021-07-20T19:31:02.198Z,1626809462.198 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1362
2021-07-20T19:31:02.218Z,1626809462.218 [Depth_Keller] Loaded
2021-07-20T19:31:02.218Z,1626809462.218 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-07-20T19:31:02.223Z,1626809462.223 [DropWeight] Loaded
2021-07-20T19:31:02.223Z,1626809462.223 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-07-20T19:31:02.282Z,1626809462.282 [NAL9602] Loaded
2021-07-20T19:31:02.283Z,1626809462.283 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-07-20T19:31:02.312Z,1626809462.312 [Onboard] Loaded
2021-07-20T19:31:02.312Z,1626809462.312 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-07-20T19:31:02.313Z,1626809462.313 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408B54E0
2021-07-20T19:31:02.314Z,1626809462.314 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1363
2021-07-20T19:31:02.326Z,1626809462.326 [Power24vConverter] Loaded
2021-07-20T19:31:02.327Z,1626809462.327 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-07-20T19:31:02.340Z,1626809462.340 [Radio_Surface] Loaded
2021-07-20T19:31:02.340Z,1626809462.340 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-07-20T19:31:02.341Z,1626809462.341 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408E54E0
2021-07-20T19:31:02.341Z,1626809462.341 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1364
2021-07-20T19:31:02.342Z,1626809462.342 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-07-20T19:31:02.343Z,1626809462.343 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-07-20T19:31:02.388Z,1626809462.388 [DepthRateCalculator] Loaded
2021-07-20T19:31:02.388Z,1626809462.388 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-07-20T19:31:02.393Z,1626809462.393 [PitchRateCalculator] Loaded
2021-07-20T19:31:02.394Z,1626809462.394 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-07-20T19:31:02.403Z,1626809462.403 [SpeedCalculator] Loaded
2021-07-20T19:31:02.403Z,1626809462.403 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-07-20T19:31:02.417Z,1626809462.417 [TempGradientCalculator] Loaded
2021-07-20T19:31:02.418Z,1626809462.418 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-07-20T19:31:02.422Z,1626809462.422 [YawRateCalculator] Loaded
2021-07-20T19:31:02.422Z,1626809462.422 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-07-20T19:31:02.440Z,1626809462.440 [ElevatorOffsetCalculator] Loaded
2021-07-20T19:31:02.441Z,1626809462.441 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-07-20T19:31:02.441Z,1626809462.441 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-07-20T19:31:02.442Z,1626809462.442 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-07-20T19:31:02.588Z,1626809462.588 [CANONSampler] Loaded
2021-07-20T19:31:02.588Z,1626809462.588 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2021-07-20T19:31:02.648Z,1626809462.648 [CTD_Seabird] Loaded
2021-07-20T19:31:02.648Z,1626809462.648 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-07-20T19:31:02.649Z,1626809462.649 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4099A4E0
2021-07-20T19:31:02.649Z,1626809462.649 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1365
2021-07-20T19:31:02.670Z,1626809462.670 [PAR_Licor] Loaded
2021-07-20T19:31:02.670Z,1626809462.670 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-07-20T19:31:02.703Z,1626809462.703 [WetLabsBB2FL] Loaded
2021-07-20T19:31:02.703Z,1626809462.703 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-07-20T19:31:02.704Z,1626809462.704 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409CA4E0
2021-07-20T19:31:02.705Z,1626809462.705 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1366
2021-07-20T19:31:02.706Z,1626809462.706 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-07-20T19:31:02.706Z,1626809462.706 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-07-20T19:31:02.736Z,1626809462.736 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-07-20T19:31:02.737Z,1626809462.737 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-07-20T19:31:03.094Z,1626809463.094 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-07-20T19:31:03.095Z,1626809463.095 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-07-20T19:31:03.276Z,1626809463.276 [SBIT](DEBUG): Construct Startup Built In Test.
2021-07-20T19:31:03.286Z,1626809463.286 [SBIT] Loaded
2021-07-20T19:31:03.286Z,1626809463.286 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-07-20T19:31:03.289Z,1626809463.289 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-07-20T19:31:03.302Z,1626809463.302 [IBIT] Loaded
2021-07-20T19:31:03.302Z,1626809463.302 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-07-20T19:31:03.308Z,1626809463.308 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-07-20T19:31:03.411Z,1626809463.411 [CBIT] Loaded
2021-07-20T19:31:03.412Z,1626809463.412 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-07-20T19:31:03.412Z,1626809463.412 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-07-20T19:31:03.413Z,1626809463.413 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-07-20T19:31:03.516Z,1626809463.516 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-07-20T19:31:03.522Z,1626809463.522 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-07-20T19:31:03.525Z,1626809463.525 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-07-20T19:31:03.537Z,1626809463.537 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-07-20T19:31:03.538Z,1626809463.538 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFE4E0
2021-07-20T19:31:03.539Z,1626809463.539 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1367
2021-07-20T19:31:03.543Z,1626809463.543 [Supervisor](INFO): Main Thread ID is 829
2021-07-20T19:31:03.544Z,1626809463.544 [Supervisor](DEBUG): Running supervisor.
2021-07-20T19:31:03.544Z,1626809463.544 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1368
2021-07-20T19:31:03.547Z,1626809463.547 [controlThread ThreadHandler](INFO): Handler Thread ID is 1369
2021-07-20T19:31:03.547Z,1626809463.547 [controlThread](DEBUG): Initializing ControlThread
2021-07-20T19:31:03.548Z,1626809463.548 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-07-20T19:31:03.550Z,1626809463.550 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-07-20T19:31:03.551Z,1626809463.551 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-07-20T19:31:03.551Z,1626809463.551 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-07-20T19:31:03.553Z,1626809463.553 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-07-20T19:31:03.554Z,1626809463.554 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-07-20T19:31:03.558Z,1626809463.558 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-07-20T19:31:03.558Z,1626809463.558 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-07-20T19:31:03.558Z,1626809463.558 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-07-20T19:31:03.559Z,1626809463.559 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-07-20T19:31:03.559Z,1626809463.559 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-07-20T19:31:03.560Z,1626809463.560 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-07-20T19:31:03.564Z,1626809463.564 [SBIT](INFO): Initialize SBIT Component.
2021-07-20T19:31:03.565Z,1626809463.565 [SBIT](IMPORTANT): git: 2021-06-24-6-gba3a55f22
2021-07-20T19:31:03.565Z,1626809463.565 [SBIT](INFO): git hash: ba3a55f2224e7c70e8e462f655364809e4684817
2021-07-20T19:31:03.565Z,1626809463.565 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-07-20T19:31:03.566Z,1626809463.566 [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-20T19:31:03.568Z,1626809463.568 [SBIT](INFO): Beginning SBIT in 88.000000 seconds.
2021-07-20T19:31:03.569Z,1626809463.569 [IBIT](INFO): Initialize IBIT Component.
2021-07-20T19:31:03.569Z,1626809463.569 [CBIT](DEBUG): Initialize CBIT Component.
2021-07-20T19:31:03.570Z,1626809463.570 [logger ThreadHandler](INFO): Handler Thread ID is 1370
2021-07-20T19:31:03.584Z,1626809463.584 [CBIT](DEBUG): Initialized mux pins.
2021-07-20T19:31:03.584Z,1626809463.584 [CBIT](DEBUG): Initializing the watchdog timer.
2021-07-20T19:31:03.588Z,1626809463.588 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1371
2021-07-20T19:31:03.590Z,1626809463.590 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-07-20T19:31:03.597Z,1626809463.597 [Onboard ThreadHandler](INFO): Handler Thread ID is 1372
2021-07-20T19:31:03.609Z,1626809463.609 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-07-20T19:31:03.609Z,1626809463.609 [CBIT](DEBUG): Initializing heartbeat.
2021-07-20T19:31:03.617Z,1626809463.617 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1373
2021-07-20T19:31:03.629Z,1626809463.629 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1374
2021-07-20T19:31:03.630Z,1626809463.630 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-07-20T19:31:03.636Z,1626809463.636 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1376
2021-07-20T19:31:03.641Z,1626809463.641 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1378
2021-07-20T19:31:03.645Z,1626809463.645 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-07-20T19:31:03.645Z,1626809463.645 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-07-20T19:31:03.645Z,1626809463.645 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-07-20T19:31:03.645Z,1626809463.645 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-07-20T19:31:03.645Z,1626809463.645 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-07-20T19:31:03.646Z,1626809463.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-07-20T19:31:03.646Z,1626809463.646 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-07-20T19:31:03.646Z,1626809463.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-07-20T19:31:03.646Z,1626809463.646 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-07-20T19:31:03.646Z,1626809463.646 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-07-20T19:31:03.647Z,1626809463.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-07-20T19:31:03.647Z,1626809463.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-07-20T19:31:03.647Z,1626809463.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-07-20T19:31:03.647Z,1626809463.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-07-20T19:31:03.647Z,1626809463.647 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-07-20T19:31:03.647Z,1626809463.647 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-07-20T19:31:03.661Z,1626809463.661 [WetLabsBB2FL](INFO): Powering up
2021-07-20T19:31:03.680Z,1626809463.680 [CBIT](DEBUG): Deactivating GF circuits.
2021-07-20T19:31:03.680Z,1626809463.680 [CBIT](DEBUG): Deactivating emergency mode.
2021-07-20T19:31:03.716Z,1626809463.716 [CBIT](DEBUG): Backplane powered.
2021-07-20T19:31:03.717Z,1626809463.717 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-07-20T19:31:03.731Z,1626809463.731 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-07-20T19:31:03.755Z,1626809463.755 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2021-07-20T19:31:03.756Z,1626809463.756 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-07-20T19:31:03.836Z,1626809463.836 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-07-20T19:31:03.853Z,1626809463.853 [Default:A.Wait](DEBUG): Construct Wait.
2021-07-20T19:31:03.855Z,1626809463.855 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-07-20T19:31:03.875Z,1626809463.875 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-07-20T19:31:03.899Z,1626809463.899 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-07-20T19:31:03.921Z,1626809463.921 [Default:E.Execute](DEBUG): Construct Execute.
2021-07-20T19:31:03.925Z,1626809463.925 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2021-07-20T19:31:03.945Z,1626809463.945 [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-20T19:31:03.951Z,1626809463.951 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-07-20T19:31:04.032Z,1626809464.032 [Radio_Surface](INFO): Powering up
2021-07-20T19:31:04.035Z,1626809464.035 [Power24vConverter](INFO): Powering up.
2021-07-20T19:31:04.036Z,1626809464.036 [CANONSampler](INFO): Powering down
2021-07-20T19:31:04.093Z,1626809464.093 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-07-20T19:31:04.100Z,1626809464.100 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-07-20T19:31:04.101Z,1626809464.101 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-07-20T19:31:04.108Z,1626809464.108 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-07-20T19:31:04.109Z,1626809464.109 [MassServo](DEBUG): Initializing EZServoServo.
2021-07-20T19:31:04.116Z,1626809464.116 [MassServo](DEBUG): Initializing MassServo.
2021-07-20T19:31:04.117Z,1626809464.117 [RudderServo](DEBUG): Initializing EZServoServo.
2021-07-20T19:31:04.124Z,1626809464.124 [RudderServo](DEBUG): Initializing RudderServo.
2021-07-20T19:31:04.125Z,1626809464.125 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-07-20T19:31:04.132Z,1626809464.132 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-07-20T19:31:05.092Z,1626809465.092 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-07-20T19:31:05.092Z,1626809465.092 [RudderServo](FAULT): Rudder failed to initialize
2021-07-20T19:31:05.092Z,1626809465.092 [RudderServo] Communications Fault, FailCount= 1
2021-07-20T19:31:05.092Z,1626809465.092 [RudderServo](ERROR): Communications Fault
2021-07-20T19:31:05.195Z,1626809465.195 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-07-20T19:31:05.361Z,1626809465.361 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-07-20T19:31:05.361Z,1626809465.361 [RudderServo](INFO): Powering down
2021-07-20T19:31:05.748Z,1626809465.748 [WetLabsBB2FL](INFO): Powering down
2021-07-20T19:31:06.033Z,1626809466.033 [RudderServo](DEBUG): Initializing EZServoServo.
2021-07-20T19:31:06.153Z,1626809466.153 [RudderServo](DEBUG): Initializing RudderServo.
2021-07-20T19:31:06.158Z,1626809466.158 [CBIT](INFO): Clearing failed state for component RudderServo
2021-07-20T19:31:06.158Z,1626809466.158 [RudderServo] No Fault, FailCount= 1
2021-07-20T19:31:32.286Z,1626809492.286 [NAL9602](INFO): Powering up NAL9602
2021-07-20T19:31:43.186Z,1626809503.186 [NAL9602](INFO): NAL9602 initialized
2021-07-20T19:32:32.091Z,1626809552.091 [SBIT](IMPORTANT): Beginning Startup BIT
2021-07-20T19:32:32.095Z,1626809552.095 [CBIT](IMPORTANT): Beginning ground fault scan
2021-07-20T19:32:43.011Z,1626809563.011 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.677548
CHAN A1 (24V): -0.180437
CHAN A2 (12V): -0.002182
CHAN A3 (5V): 4.753929
CHAN B0 (3.3V): 0.001538
CHAN B1 (3.15aV): -0.000060
CHAN B2 (3.15bV): -0.000616
CHAN B3 (GND): -0.000018
OPEN: -0.000592
Full Scale Calc: 4.765 mA, -1.589 mA
2021-07-20T19:33:26.287Z,1626809606.287 [SBIT](IMPORTANT): SBIT PASSED
2021-07-20T19:33:26.287Z,1626809606.287 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-07-20T19:33:26.289Z,1626809606.289 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2021-07-20T19:33:26.289Z,1626809606.289 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=406.019663 cubic_centimeter;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): VerticalControl.kiDepthRateBuoy=15 reciprocal_second;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): VerticalControl.kpDepthBuoy=60 ratio;

2021-07-20T19:33:26.290Z,1626809606.290 [SBIT](IMPORTANT): VerticalControl.kpDepthRateBuoy=-25 ratio;

2021-07-20T19:33:26.291Z,1626809606.291 [SBIT](IMPORTANT): VerticalControl.massDefault=-17.052770 millimeter;

2021-07-20T19:33:26.631Z,1626809606.631 [MissionManager](IMPORTANT): Started mission Startup
2021-07-20T19:33:26.631Z,1626809606.631 [Startup] Running Loop=1
2021-07-20T19:33:26.631Z,1626809606.631 [Startup](DEBUG): Aggregate::initialize Startup
2021-07-20T19:33:26.632Z,1626809606.632 [Startup:A.GoToSurface] Running Loop=1
2021-07-20T19:33:26.632Z,1626809606.632 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-20T19:33:26.633Z,1626809606.633 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-20T19:33:26.633Z,1626809606.633 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-20T19:33:26.633Z,1626809606.633 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-20T19:33:26.634Z,1626809606.634 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-20T19:33:26.634Z,1626809606.634 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-20T19:33:26.644Z,1626809606.644 [Startup:StartupSatComms] Running Loop=1
2021-07-20T19:33:26.644Z,1626809606.644 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-07-20T19:33:26.644Z,1626809606.644 [Startup:StartupSatComms:A] Running Loop=1
2021-07-20T19:33:27.042Z,1626809607.042 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-07-20T19:34:03.856Z,1626809643.856 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-07-20T19:34:03.857Z,1626809643.857 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:34:03.867Z,1626809643.867 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:34:04.247Z,1626809644.247 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:34:04.247Z,1626809644.247 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-07-20T19:34:26.822Z,1626809666.822 [Startup:StartupSatComms:A](INFO): Timed out from 2021-07-20T19:33:26.6Z
2021-07-20T19:34:26.822Z,1626809666.822 [Startup:StartupSatComms:A] Stopped
2021-07-20T19:34:26.822Z,1626809666.822 [Startup:StartupSatComms:B] Running Loop=1
2021-07-20T19:34:27.234Z,1626809667.234 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-07-20T19:34:48.926Z,1626809688.926 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004558
2021-07-20T19:34:57.184Z,1626809697.184 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20210720T190158/Courier0024.lzma
2021-07-20T19:34:59.394Z,1626809699.394 [DataOverHttps](INFO): Moved sent file to Logs/20210720T190158/Courier0024.lzma.bak
2021-07-20T19:34:59.394Z,1626809699.394 [DataOverHttps](INFO): SBD MOMSN=15749693
2021-07-20T19:35:15.024Z,1626809715.024 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20210720T193053/Courier0000.lzma
2021-07-20T19:35:16.026Z,1626809716.026 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Courier0000.lzma.bak
2021-07-20T19:35:16.026Z,1626809716.026 [DataOverHttps](INFO): SBD MOMSN=15749696
2021-07-20T19:35:27.041Z,1626809727.041 [Startup:StartupSatComms:B](INFO): Timed out from 2021-07-20T19:34:26.8Z
2021-07-20T19:35:27.041Z,1626809727.041 [Startup:StartupSatComms:B] Stopped
2021-07-20T19:35:27.041Z,1626809727.041 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-07-20T19:35:27.041Z,1626809727.041 [Startup:StartupSatComms] Stopped
2021-07-20T19:35:27.042Z,1626809727.042 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-07-20T19:35:27.042Z,1626809727.042 [Startup](INFO): Completed Startup
2021-07-20T19:35:27.043Z,1626809727.043 [MissionManager](INFO): Startup is completed.
2021-07-20T19:35:27.043Z,1626809727.043 [MissionManager](INFO): Uninitializing Mission Startup
2021-07-20T19:35:27.043Z,1626809727.043 [Startup] Stopped
2021-07-20T19:35:27.043Z,1626809727.043 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-07-20T19:35:27.043Z,1626809727.043 [Startup:A.GoToSurface] Stopped
2021-07-20T19:35:27.043Z,1626809727.043 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-20T19:35:27.463Z,1626809727.463 [MissionManager](IMPORTANT): Started mission Default
2021-07-20T19:35:27.463Z,1626809727.463 [Default] Running Loop=1
2021-07-20T19:35:27.463Z,1626809727.463 [Default](DEBUG): Aggregate::initialize Default
2021-07-20T19:35:27.463Z,1626809727.463 [Default:B.GoToSurface] Running Loop=1
2021-07-20T19:35:27.463Z,1626809727.463 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-20T19:35:27.464Z,1626809727.464 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-20T19:35:27.464Z,1626809727.464 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-20T19:35:27.465Z,1626809727.465 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-20T19:35:27.465Z,1626809727.465 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-20T19:35:27.465Z,1626809727.465 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-20T19:35:27.466Z,1626809727.466 [Default:A.Wait] Running Loop=1
2021-07-20T19:35:27.466Z,1626809727.466 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-07-20T19:35:36.816Z,1626809736.816 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20210720T190158/Express0022.lzma
2021-07-20T19:35:37.818Z,1626809737.818 [DataOverHttps](INFO): Moved sent file to Logs/20210720T190158/Express0022.lzma.bak
2021-07-20T19:35:37.818Z,1626809737.818 [DataOverHttps](INFO): SBD MOMSN=15749699
2021-07-20T19:35:40.819Z,1626809740.819 [Default:A.Wait](INFO): Done Waiting.
2021-07-20T19:35:40.819Z,1626809740.819 [Default:A.Wait] Stopped
2021-07-20T19:35:40.829Z,1626809740.829 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T19:35:41.209Z,1626809741.209 [Default:CheckIn] Running Loop=1
2021-07-20T19:35:41.209Z,1626809741.209 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-20T19:35:41.209Z,1626809741.209 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-20T19:35:41.612Z,1626809741.612 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-07-20T19:36:28.994Z,1626809788.994 [CommandLine](IMPORTANT): got command configSet list
2021-07-20T19:36:28.995Z,1626809788.995 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-07-20T19:36:28.998Z,1626809788.998 [CommandLine](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2021-07-20T19:36:28.998Z,1626809788.998 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2021-07-20T19:36:28.998Z,1626809788.998 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-07-20T19:36:28.998Z,1626809788.998 [CommandLine](IMPORTANT): DAT.verbosity=3 count;

2021-07-20T19:36:28.998Z,1626809788.998 [CommandLine](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;

2021-07-20T19:36:28.998Z,1626809788.998 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=406.019663 cubic_centimeter;

2021-07-20T19:36:28.999Z,1626809788.999 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;

2021-07-20T19:36:28.999Z,1626809788.999 [CommandLine](IMPORTANT): VerticalControl.kiDepthRateBuoy=15 reciprocal_second;

2021-07-20T19:36:28.999Z,1626809788.999 [CommandLine](IMPORTANT): VerticalControl.kpDepthBuoy=60 ratio;

2021-07-20T19:36:28.999Z,1626809788.999 [CommandLine](IMPORTANT): VerticalControl.kpDepthRateBuoy=-25 ratio;

2021-07-20T19:36:28.999Z,1626809788.999 [CommandLine](IMPORTANT): VerticalControl.massDefault=-17.052770 millimeter;

2021-07-20T19:36:38.295Z,1626809798.295 [DataOverHttps](IMPORTANT): SBD MTMSN=20210720T193627
2021-07-20T19:36:46.930Z,1626809806.930 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-07-20T19:36:48.393Z,1626809808.393 [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" 1hd4o 1 2
2021-07-20T19:36:48.429Z,1626809808.429 [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" 1hd4o 1 2.000000
2021-07-20T19:36:48.430Z,1626809808.430 [CommandLine](IMPORTANT): Scheduling command #1 of 2 with id=1hd4o
2021-07-20T19:36:48.431Z,1626809808.431 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 2 with id='1hd4o'): "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-20T19:36:49.394Z,1626809809.394 [DataOverHttps](IMPORTANT): SBD MTMSN=20210720T193638
2021-07-20T19:36:56.612Z,1626809816.612 [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" 1hd4o 2 2
2021-07-20T19:36:56.649Z,1626809816.649 [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" 1hd4o 2 2.000000
2021-07-20T19:36:56.650Z,1626809816.650 [CommandLine](IMPORTANT): Scheduling command #2 of 2 with id=1hd4o
2021-07-20T19:36:56.651Z,1626809816.651 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 2 with id='1hd4o'): "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-20T19:36:56.900Z,1626809816.900 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/tank_ballast_and_trim.xml
2021-07-20T19:36:56.901Z,1626809816.901 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/tank_ballast_and_trim.xml
2021-07-20T19:36:56.989Z,1626809816.989 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2021-07-20T19:36:56.993Z,1626809816.993 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2021-07-20T19:36:56.996Z,1626809816.996 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2021-07-20T19:36:56.999Z,1626809816.999 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2021-07-20T19:36:57.006Z,1626809817.006 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2021-07-20T19:36:57.009Z,1626809817.009 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2021-07-20T19:36:57.013Z,1626809817.013 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2021-07-20T19:36:57.016Z,1626809817.016 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2021-07-20T19:36:57.019Z,1626809817.019 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2021-07-20T19:36:57.046Z,1626809817.046 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2021-07-20T19:36:57.050Z,1626809817.050 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2021-07-20T19:36:57.069Z,1626809817.069 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2021-07-20T19:36:57.076Z,1626809817.076 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900000 %
2021-07-20T19:36:57.079Z,1626809817.079 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2021-07-20T19:36:57.084Z,1626809817.084 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2021-07-20T19:36:57.541Z,1626809817.541 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2021-07-20T19:36:57.544Z,1626809817.544 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2021-07-20T19:36:57.546Z,1626809817.546 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2021-07-20T19:36:57.549Z,1626809817.549 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2021-07-20T19:36:57.552Z,1626809817.552 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2021-07-20T19:36:57.555Z,1626809817.555 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2021-07-20T19:36:57.558Z,1626809817.558 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2021-07-20T19:36:57.561Z,1626809817.561 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2021-07-20T19:36:57.564Z,1626809817.564 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2021-07-20T19:36:57.567Z,1626809817.567 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2021-07-20T19:36:57.569Z,1626809817.569 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2021-07-20T19:36:57.572Z,1626809817.572 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2021-07-20T19:36:57.575Z,1626809817.575 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2021-07-20T19:36:57.578Z,1626809817.578 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2021-07-20T19:36:57.605Z,1626809817.605 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0.000000 bool
2021-07-20T19:36:57.609Z,1626809817.609 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0.000000 bool
2021-07-20T19:36:57.624Z,1626809817.624 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1.000000 bool
2021-07-20T19:36:57.628Z,1626809817.628 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1.000000 bool
2021-07-20T19:36:57.696Z,1626809817.696 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0.000000 bool
2021-07-20T19:36:57.699Z,1626809817.699 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0.000000 bool
2021-07-20T19:36:57.703Z,1626809817.703 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2021-07-20T19:36:57.718Z,1626809817.718 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2021-07-20T19:36:57.737Z,1626809817.737 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2021-07-20T19:36:57.756Z,1626809817.756 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2021-07-20T19:36:57.760Z,1626809817.760 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2021-07-20T19:36:57.771Z,1626809817.771 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2021-07-20T19:36:57.774Z,1626809817.774 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2021-07-20T19:36:57.794Z,1626809817.794 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2021-07-20T19:36:57.798Z,1626809817.798 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2021-07-20T19:36:57.817Z,1626809817.817 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2021-07-20T19:36:57.833Z,1626809817.833 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2021-07-20T19:36:57.848Z,1626809817.848 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2021-07-20T19:36:57.851Z,1626809817.851 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2021-07-20T19:36:57.867Z,1626809817.867 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2021-07-20T19:36:57.874Z,1626809817.874 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2021-07-20T19:36:57.908Z,1626809817.908 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2021-07-20T19:36:57.911Z,1626809817.911 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2021-07-20T19:36:57.925Z,1626809817.925 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2021-07-20T19:36:57.936Z,1626809817.936 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2021-07-20T19:36:57.944Z,1626809817.944 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2021-07-20T19:36:57.947Z,1626809817.947 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2021-07-20T19:36:57.963Z,1626809817.963 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2021-07-20T19:36:57.968Z,1626809817.968 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2021-07-20T19:36:57.994Z,1626809817.994 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2021-07-20T19:36:57.998Z,1626809817.998 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2021-07-20T19:36:58.023Z,1626809818.023 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2021-07-20T19:36:58.027Z,1626809818.027 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2021-07-20T19:36:58.030Z,1626809818.030 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2021-07-20T19:36:58.051Z,1626809818.051 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2021-07-20T19:36:58.101Z,1626809818.101 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2021-07-20T19:36:58.112Z,1626809818.112 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2021-07-20T19:36:58.115Z,1626809818.115 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2021-07-20T19:36:58.127Z,1626809818.127 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2021-07-20T19:36:58.147Z,1626809818.147 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2021-07-20T19:36:58.160Z,1626809818.160 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2021-07-20T19:36:58.163Z,1626809818.163 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2021-07-20T19:36:58.179Z,1626809818.179 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2021-07-20T19:36:58.186Z,1626809818.186 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2021-07-20T19:36:58.191Z,1626809818.191 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2021-07-20T19:36:58.202Z,1626809818.202 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2021-07-20T19:36:58.211Z,1626809818.211 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2021-07-20T19:36:58.227Z,1626809818.227 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2021-07-20T19:36:58.238Z,1626809818.238 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2021-07-20T19:36:58.260Z,1626809818.260 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2021-07-20T19:36:58.329Z,1626809818.329 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-20T19:36:58.362Z,1626809818.362 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2021-07-20T19:36:58.397Z,1626809818.397 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-20T19:36:58.436Z,1626809818.436 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-20T19:36:58.487Z,1626809818.487 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2021-07-20T19:36:58.528Z,1626809818.528 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-20T19:36:58.574Z,1626809818.574 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2021-07-20T19:36:58.620Z,1626809818.620 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2021-07-20T19:36:58.659Z,1626809818.659 [MissionManager](INFO): Inserting Stack: Missions/Insert/BallastAndTrim.xml
2021-07-20T19:36:58.835Z,1626809818.835 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2021-07-20T19:36:58.873Z,1626809818.873 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2021-07-20T19:36:58.876Z,1626809818.876 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.008333 m/s
2021-07-20T19:36:58.879Z,1626809818.879 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2021-07-20T19:36:58.915Z,1626809818.915 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2021-07-20T19:36:58.954Z,1626809818.954 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2021-07-20T19:36:58.958Z,1626809818.958 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2021-07-20T19:36:58.993Z,1626809818.993 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2021-07-20T19:36:59.013Z,1626809819.013 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2021-07-20T19:36:59.016Z,1626809819.016 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2021-07-20T19:36:59.020Z,1626809819.020 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2021-07-20T19:36:59.028Z,1626809819.028 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900000 %
2021-07-20T19:36:59.035Z,1626809819.035 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2021-07-20T19:36:59.047Z,1626809819.047 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertKiDepthBuoy = 0.300000 1/s
2021-07-20T19:36:59.055Z,1626809819.055 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2021-07-20T19:36:59.099Z,1626809819.099 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2021-07-20T19:36:59.107Z,1626809819.107 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2021-07-20T19:36:59.127Z,1626809819.127 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2021-07-20T19:36:59.149Z,1626809819.149 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2021-07-20T19:36:59.161Z,1626809819.161 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2021-07-20T19:36:59.177Z,1626809819.177 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2021-07-20T19:36:59.195Z,1626809819.195 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2021-07-20T19:36:59.199Z,1626809819.199 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2021-07-20T19:36:59.202Z,1626809819.202 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2021-07-20T19:36:59.230Z,1626809819.230 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2021-07-20T19:36:59.249Z,1626809819.249 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2021-07-20T19:36:59.317Z,1626809819.317 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2021-07-20T19:36:59.319Z,1626809819.319 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2021-07-20T19:36:59.329Z,1626809819.329 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2021-07-20T19:36:59.340Z,1626809819.340 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2021-07-20T19:36:59.357Z,1626809819.357 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2021-07-20T19:36:59.359Z,1626809819.359 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2021-07-20T19:36:59.365Z,1626809819.365 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2021-07-20T19:36:59.367Z,1626809819.367 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2021-07-20T19:36:59.419Z,1626809819.419 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2021-07-20T19:36:59.423Z,1626809819.423 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2021-07-20T19:36:59.480Z,1626809819.480 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="ballast_and_trim">

    <DefineArg Name="MissionTimeout"><Description>
        Maximum duration of mission
    </Description><Units:minute/><Value>120</Value></DefineArg>

    <DefineArg Name="SkipComms"><Description>
        Skip communications at start of mission.
    </Description><False/></DefineArg>

    <DefineArg Name="Depth1"><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="Depth2"><Units:meter/><Value>NaN</Value></DefineArg>

    <DefineArg Name="DepthDeadband"><Description>
        How much vertical drift from the specified depth is allowed durnig the
        mission.
    </Description><Units:meter/><Value>0.1</Value></DefineArg>

    <DefineArg Name="SurfaceThreshold"><Description>
        Surface threshold depth.
    </Description><Units:meter/><Value>2.5</Value></DefineArg>

    <DefineArg Name="MaxWaitOnSurface"><Description>
        Maximum wait time for the vehicle to go under the surface (i.e., reach
        the surface threshold depth).
    </Description><Units:minute/><Value>20</Value></DefineArg>

    <DefineArg Name="SettleTime"><Description>
        How long to wait after reaching target depth before starting ballast and
        trim.
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="EstimationTimeout"><Description>
        Timeout for ballast and trim estimation.
    </Description><Units:minute/><Value>45</Value></DefineArg>

    <DefineArg Name="MinEstimationTime"><Description>
        Minimum time to run ballast and trim estimation before determining
        convergence (must be shorter than timeout).
    </Description><Units:minute/><Value>10</Value></DefineArg>

    <DefineArg Name="MassEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:millimeter/><Value>0.25</Value></DefineArg>

    <DefineArg Name="BuoyEstimationErrorBound"><Description>
        Desired range of the estimated sample mean from the true mean statistic
        (smaller values take longer to converge).
    </Description><Units:cubic_centimeter/><Value>15</Value></DefineArg>

    <DefineArg Name="EstimationConfidence"><Description>
        Confidence level that the estimator has reached the desired error range
        (larger values take longer to converge).
    </Description><Units:percent/><Value>99.9</Value></DefineArg>

    <DefineArg Name="WaitToFloat"><Units:minute/><Value>5</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Insert Filename="Insert/Science.xml"/>

    <Aggregate Id="RunBallastAndTrim">

        <Sequence/>

        <Insert Filename="Insert/BallastAndTrim.xml">
            <RedefineArg Name="InsertDepthDeadband"><Arg Name="DepthDeadband"/></RedefineArg>
            <RedefineArg Name="InsertApproachDepthTimeout"><Arg Name="MaxWaitOnSurface"/></RedefineArg>
            <RedefineArg Name="InsertSettleTime"><Arg Name="SettleTime"/></RedefineArg>
            <RedefineArg Name="EstTimeout"><Arg Name="EstimationTimeout"/></RedefineArg>
            <RedefineArg Name="MinEstTime"><Arg Name="MinEstimationTime"/></RedefineArg>
            <RedefineArg Name="MassEstErrorBound"><Arg Name="MassEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="BuoyEstErrorBound"><Arg Name="BuoyEstimationErrorBound"/></RedefineArg>
            <RedefineArg Name="EstConfidence"><Arg Name="EstimationConfidence"/></RedefineArg>
        </Insert>

        <Aggregate Id="Depth1">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth1"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

        <Aggregate Id="Depth2">

            <Sequence/>

            <Break>
                <IsNaN><Arg Name="Depth2"/>
                </IsNaN>
            </Break>

            <Assign><Sequence/><Arg Name="BallastAndTrim:InsertDepth"/><Arg Name="Depth1"/></Assign>

            <Call RefId="BallastAndTrim"/>

        </Aggregate>

    </Aggregate>

    <Aggregate Id="Float_Up">

        <Description>
            Float to surface instead of driving.
        </Description>

        <Sequence/>

        <Break>
            <Universal:depth/>
            <Lt><Control:VerticalControl.surfaceThreshold/></Lt>
        </Break>

        <Guidance:Buoyancy>
            <Parallel/>
            <Setting><Guidance:Buoyancy.position/><Control:VerticalControl.buoyancyDefault/></Setting>
        </Guidance:Buoyancy>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Arg Name="WaitToFloat"/></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2021-07-20T19:36:59.481Z,1626809819.481 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/tank_ballast_and_trim.xml
2021-07-20T19:37:04.994Z,1626809824.994 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-07-20T19:37:04.994Z,1626809824.994 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:37:05.005Z,1626809825.005 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:37:05.407Z,1626809825.407 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:37:05.407Z,1626809825.407 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-07-20T19:37:09.423Z,1626809829.423 [CommandLine](IMPORTANT): got command set ballast_and_trim.MissionTimeout 30.000000 minute
2021-07-20T19:37:09.433Z,1626809829.433 [CommandLine](IMPORTANT): got command set ballast_and_trim.Depth1 2.000000 meter
2021-07-20T19:37:09.435Z,1626809829.435 [CommandLine](IMPORTANT): got command set ballast_and_trim.SurfaceThreshold 1.000000 meter
2021-07-20T19:37:09.437Z,1626809829.437 [CommandLine](IMPORTANT): got command set ballast_and_trim.EstimationTimeout 15.000000 minute
2021-07-20T19:37:17.729Z,1626809837.729 [CommandLine](IMPORTANT): got command set ballast_and_trim.MassEstimationErrorBound 1.000000 millimeter
2021-07-20T19:37:17.730Z,1626809837.730 [CommandLine](IMPORTANT): got command set ballast_and_trim.BuoyEstimationErrorBound 25.000000 cubic_centimeter
2021-07-20T19:37:17.731Z,1626809837.731 [CommandLine](IMPORTANT): got command set ballast_and_trim.EstimationConfidence 98.000000 percent
2021-07-20T19:37:17.731Z,1626809837.731 [CommandLine](IMPORTANT): got command run
2021-07-20T19:37:17.735Z,1626809837.735 [CommandLine](IMPORTANT): Running 
2021-07-20T19:37:17.890Z,1626809837.890 [Default] Stopped
2021-07-20T19:37:17.891Z,1626809837.891 [Default](DEBUG): Aggregate::uninitialize Default
2021-07-20T19:37:17.891Z,1626809837.891 [Default:B.GoToSurface] Stopped
2021-07-20T19:37:17.891Z,1626809837.891 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-20T19:37:17.891Z,1626809837.891 [Default:CheckIn] Stopped
2021-07-20T19:37:17.891Z,1626809837.891 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-20T19:37:17.891Z,1626809837.891 [Default:CheckIn:Read_GPS] Stopped
2021-07-20T19:37:17.891Z,1626809837.891 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim] Running Loop=1
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim:Science] Running Loop=1
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim:Science:A] Running Loop=1
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim:Science:B] Running Loop=1
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim:Science:C] Running Loop=1
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim:Science:D] Running Loop=1
2021-07-20T19:37:17.892Z,1626809837.892 [ballast_and_trim:Science:E] Running Loop=1
2021-07-20T19:37:17.893Z,1626809837.893 [ballast_and_trim:Science:F] Running Loop=1
2021-07-20T19:37:17.893Z,1626809837.893 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2021-07-20T19:37:17.893Z,1626809837.893 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2021-07-20T19:37:17.893Z,1626809837.893 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2021-07-20T19:37:17.893Z,1626809837.893 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2021-07-20T19:37:17.893Z,1626809837.893 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-20T19:37:17.895Z,1626809837.895 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2021-07-20T19:37:17.895Z,1626809837.895 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2021-07-20T19:37:17.895Z,1626809837.895 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2021-07-20T19:37:17.896Z,1626809837.896 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2021-07-20T19:37:17.931Z,1626809837.931 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2021-07-20T19:37:17.931Z,1626809837.931 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2021-07-20T19:37:17.931Z,1626809837.931 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2021-07-20T19:37:17.931Z,1626809837.931 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-20T19:37:17.933Z,1626809837.933 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2021-07-20T19:37:17.934Z,1626809837.934 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2021-07-20T19:37:17.934Z,1626809837.934 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2021-07-20T19:37:17.934Z,1626809837.934 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-20T19:37:17.936Z,1626809837.936 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2021-07-20T19:37:17.936Z,1626809837.936 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2021-07-20T19:37:17.936Z,1626809837.936 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2021-07-20T19:37:17.936Z,1626809837.936 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2021-07-20T19:37:17.937Z,1626809837.937 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2021-07-20T19:37:17.937Z,1626809837.937 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2021-07-20T19:37:17.937Z,1626809837.937 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2021-07-20T19:37:17.937Z,1626809837.937 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-20T19:37:17.939Z,1626809837.939 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2021-07-20T19:37:17.939Z,1626809837.939 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2021-07-20T19:37:17.939Z,1626809837.939 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2021-07-20T19:37:17.940Z,1626809837.940 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2021-07-20T19:37:17.957Z,1626809837.957 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2021-07-20T19:37:17.958Z,1626809837.958 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2021-07-20T19:37:17.958Z,1626809837.958 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2021-07-20T19:37:17.958Z,1626809837.958 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2021-07-20T19:37:17.958Z,1626809837.958 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2021-07-20T19:37:17.959Z,1626809837.959 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2021-07-20T19:37:17.959Z,1626809837.959 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2021-07-20T19:37:17.959Z,1626809837.959 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2021-07-20T19:37:17.959Z,1626809837.959 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2021-07-20T19:37:17.959Z,1626809837.959 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2021-07-20T19:37:17.960Z,1626809837.960 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2021-07-20T19:37:17.960Z,1626809837.960 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2021-07-20T19:37:17.960Z,1626809837.960 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2021-07-20T19:37:17.961Z,1626809837.961 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2021-07-20T19:37:17.961Z,1626809837.961 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2021-07-20T19:37:17.961Z,1626809837.961 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2021-07-20T19:37:17.961Z,1626809837.961 [ballast_and_trim:Science] Running Loop=1
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-20T19:37:17.963Z,1626809837.963 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2021-07-20T19:37:17.964Z,1626809837.964 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2021-07-20T19:37:17.964Z,1626809837.964 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2021-07-20T19:37:17.976Z,1626809837.976 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-20T19:37:17.976Z,1626809837.976 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2021-07-20T19:37:17.976Z,1626809837.976 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2021-07-20T19:37:17.976Z,1626809837.976 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2021-07-20T19:37:17.976Z,1626809837.976 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2021-07-20T19:37:17.976Z,1626809837.976 [ballast_and_trim:Science:PeakDetectOil] Stopped
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2021-07-20T19:37:17.977Z,1626809837.977 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:PeakDetectChl] Stopped
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:Read_Oil] Stopped
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:F] Stopped
2021-07-20T19:37:17.978Z,1626809837.978 [ballast_and_trim:Science:E] Running Loop=1
2021-07-20T19:37:17.979Z,1626809837.979 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2021-07-20T19:37:17.979Z,1626809837.979 [ballast_and_trim:Science:D] Stopped
2021-07-20T19:37:17.980Z,1626809837.980 [ballast_and_trim:Science:C] Running Loop=1
2021-07-20T19:37:17.980Z,1626809837.980 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2021-07-20T19:37:17.981Z,1626809837.981 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2021-07-20T19:37:17.981Z,1626809837.981 [ballast_and_trim:Science:B] Running Loop=1
2021-07-20T19:37:17.982Z,1626809837.982 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2021-07-20T19:37:17.983Z,1626809837.983 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2021-07-20T19:37:17.983Z,1626809837.983 [ballast_and_trim:Science:A] Stopped
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2021-07-20T19:37:18.287Z,1626809838.287 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G] Running Loop=1
2021-07-20T19:37:18.290Z,1626809838.290 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G](INFO): Going to target depth. Speed set to 0.000000 m/s 
2021-07-20T19:37:18.290Z,1626809838.290 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:G] Stopped
2021-07-20T19:37:18.290Z,1626809838.290 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2021-07-20T19:37:18.290Z,1626809838.290 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2021-07-20T19:37:18.290Z,1626809838.290 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2021-07-20T19:37:18.290Z,1626809838.290 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2021-07-20T19:37:18.291Z,1626809838.291 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2021-07-20T19:37:18.291Z,1626809838.291 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2021-07-20T19:37:18.291Z,1626809838.291 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2021-07-20T19:37:18.291Z,1626809838.291 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2021-07-20T19:37:18.291Z,1626809838.291 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2021-07-20T19:37:18.291Z,1626809838.291 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2021-07-20T19:37:18.291Z,1626809838.291 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2021-07-20T19:37:18.292Z,1626809838.292 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2021-07-20T19:37:18.292Z,1626809838.292 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2021-07-20T19:37:18.292Z,1626809838.292 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2021-07-20T19:37:18.292Z,1626809838.292 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2021-07-20T19:37:18.292Z,1626809838.292 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2021-07-20T19:37:18.293Z,1626809838.293 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2021-07-20T19:37:18.293Z,1626809838.293 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2021-07-20T19:37:18.293Z,1626809838.293 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2021-07-20T19:37:18.293Z,1626809838.293 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2021-07-20T19:37:18.329Z,1626809838.329 [WetLabsBB2FL](INFO): Powering up
2021-07-20T19:37:18.700Z,1626809838.700 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2021-07-20T19:37:18.701Z,1626809838.701 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2021-07-20T19:37:18.702Z,1626809838.702 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2021-07-20T19:37:18.702Z,1626809838.702 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2021-07-20T19:37:18.702Z,1626809838.702 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2021-07-20T19:37:18.702Z,1626809838.702 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2021-07-20T19:37:18.702Z,1626809838.702 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2021-07-20T19:37:19.091Z,1626809839.091 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2021-07-20T19:37:19.092Z,1626809839.092 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 2.000000 m 
2021-07-20T19:37:19.092Z,1626809839.092 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2021-07-20T19:37:19.092Z,1626809839.092 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2021-07-20T19:37:19.092Z,1626809839.092 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2021-07-20T19:37:21.241Z,1626809841.241 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2021-07-20T19:38:14.993Z,1626809894.993 [CommandLine](IMPORTANT): got command show variable depthMode
2021-07-20T19:38:15.047Z,1626809895.047 [CommandLine](IMPORTANT): VerticalControl.useElevIntInDepthMode (bool)
2021-07-20T19:38:18.474Z,1626809898.474 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-07-20T19:38:18.478Z,1626809898.478 [BPC1](INFO): Received data from all battery sticks.
2021-07-20T19:38:25.367Z,1626809905.367 [CommandLine](IMPORTANT): got command show variable mode
2021-07-20T19:38:25.375Z,1626809905.375 [CommandLine](IMPORTANT): NAL9602.strobeMode (count)
2021-07-20T19:38:25.378Z,1626809905.378 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.loadAtStartup (bool)
2021-07-20T19:38:25.378Z,1626809905.378 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.accuracyPremultiplier (none)
2021-07-20T19:38:25.378Z,1626809905.378 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.allowableFailures (count)
2021-07-20T19:38:25.379Z,1626809905.379 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.orientationStaleAfter (minute)
2021-07-20T19:38:25.379Z,1626809905.379 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.velocityStaleAfter (second)
2021-07-20T19:38:25.380Z,1626809905.380 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.verbosity (count)
2021-07-20T19:38:25.444Z,1626809905.444 [CommandLine](IMPORTANT): Config/Simulator.oceanModelData (none)
2021-07-20T19:38:25.469Z,1626809905.469 [CommandLine](IMPORTANT): VerticalControl.useElevIntInDepthMode (bool)
2021-07-20T19:38:25.520Z,1626809905.520 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadControl (none)
2021-07-20T19:38:25.521Z,1626809905.521 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.uart (none)
2021-07-20T19:38:25.521Z,1626809905.521 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.baud (bit_per_second)
2021-07-20T19:38:25.522Z,1626809905.522 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadControl2 (none)
2021-07-20T19:38:25.550Z,1626809905.550 [CommandLine](IMPORTANT): Micromodem.loadControl (none)
2021-07-20T19:38:25.550Z,1626809905.550 [CommandLine](IMPORTANT): Micromodem.loadControl2 (none)
2021-07-20T19:38:25.551Z,1626809905.551 [CommandLine](IMPORTANT): Micromodem.uart (none)
2021-07-20T19:38:25.552Z,1626809905.552 [CommandLine](IMPORTANT): Micromodem.baud (bit_per_second)
2021-07-20T19:38:25.588Z,1626809905.588 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup (bool)
2021-07-20T19:38:25.589Z,1626809905.589 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.simulateHardware (bool)
2021-07-20T19:38:25.589Z,1626809905.589 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.txPower (enum)
2021-07-20T19:38:25.590Z,1626809905.590 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.localAddress (count)
2021-07-20T19:38:25.590Z,1626809905.590 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.sbdAddress (enum)
2021-07-20T19:38:25.591Z,1626809905.591 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.transponderAddress (enum)
2021-07-20T19:38:25.591Z,1626809905.591 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.sendExpress (bool)
2021-07-20T19:38:25.600Z,1626809905.600 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.surfaceThreshold (meter)
2021-07-20T19:38:25.601Z,1626809905.601 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.verbosity (count)
2021-07-20T19:38:25.603Z,1626809905.603 [CommandLine](IMPORTANT): BR_Ping1D.autoMode (bool)
2021-07-20T19:38:25.625Z,1626809905.625 [CommandLine](IMPORTANT): GobyModem.loadAtStartup (bool)
2021-07-20T19:38:25.625Z,1626809905.625 [CommandLine](IMPORTANT): GobyModem.simulateHardware (bool)
2021-07-20T19:38:25.626Z,1626809905.626 [CommandLine](IMPORTANT): GobyModem.modemType (none)
2021-07-20T19:38:25.626Z,1626809905.626 [CommandLine](IMPORTANT): GobyModem.networkIds (none)
2021-07-20T19:38:25.627Z,1626809905.627 [CommandLine](IMPORTANT): GobyModem.maxDistance (kilometer)
2021-07-20T19:38:25.628Z,1626809905.628 [CommandLine](IMPORTANT): GobyModem.transBaud (bit_per_second)
2021-07-20T19:38:25.644Z,1626809905.644 [CommandLine](IMPORTANT): Micromodem.loadAtStartup (bool)
2021-07-20T19:38:25.645Z,1626809905.645 [CommandLine](IMPORTANT): Micromodem.simulateHardware (bool)
2021-07-20T19:38:25.645Z,1626809905.645 [CommandLine](IMPORTANT): Micromodem.localAddress (enum)
2021-07-20T19:38:25.646Z,1626809905.646 [CommandLine](IMPORTANT): Micromodem.destinationAddress (enum)
2021-07-20T19:38:25.646Z,1626809905.646 [CommandLine](IMPORTANT): Micromodem.dataRate (enum)
2021-07-20T19:38:25.646Z,1626809905.646 [CommandLine](IMPORTANT): Micromodem.sendExpress (bool)
2021-07-20T19:38:25.647Z,1626809905.647 [CommandLine](IMPORTANT): Micromodem.surfaceThreshold (meter)
2021-07-20T19:38:25.647Z,1626809905.647 [CommandLine](IMPORTANT): Micromodem.pwrampTXLevel (enum)
2021-07-20T19:38:25.656Z,1626809905.656 [CommandLine](IMPORTANT): Micromodem.centerFrequency (hertz)
2021-07-20T19:38:25.656Z,1626809905.656 [CommandLine](IMPORTANT): Micromodem.bandwidth (hertz)
2021-07-20T19:38:25.657Z,1626809905.657 [CommandLine](IMPORTANT): Micromodem.dusblPingCode (none)
2021-07-20T19:38:25.657Z,1626809905.657 [CommandLine](IMPORTANT): Micromodem.rangeTxSeqCode (none)
2021-07-20T19:38:25.658Z,1626809905.658 [CommandLine](IMPORTANT): Micromodem.rangeTAT (millisecond)
2021-07-20T19:38:25.658Z,1626809905.658 [CommandLine](IMPORTANT): Micromodem.trans1Channel (enum)
2021-07-20T19:38:25.658Z,1626809905.658 [CommandLine](IMPORTANT): Micromodem.trans2Channel (enum)
2021-07-20T19:38:25.659Z,1626809905.659 [CommandLine](IMPORTANT): Micromodem.trans3Channel (enum)
2021-07-20T19:38:25.659Z,1626809905.659 [CommandLine](IMPORTANT): Micromodem.trans4Channel (enum)
2021-07-20T19:38:25.671Z,1626809905.671 [CommandLine](IMPORTANT): Aanderaa_O2.model (none)
2021-07-20T19:38:25.722Z,1626809905.722 [CommandLine](IMPORTANT): VerticalControl.verticalMode (enum)
2021-07-20T19:38:25.723Z,1626809905.723 [CommandLine](IMPORTANT): HorizontalControl.horizontalMode (enum)
2021-07-20T19:38:34.895Z,1626809914.895 [CommandLine](IMPORTANT): got command get VerticalControl.verticalMode
2021-07-20T19:38:34.895Z,1626809914.895 [CommandLine](IMPORTANT): VerticalControl.verticalMode 2 enum
2021-07-20T19:39:22.608Z,1626809962.608 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T19:39:53.514Z,1626809993.514 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2021-07-20T19:39:53.515Z,1626809993.515 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2021-07-20T19:39:53.515Z,1626809993.515 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2021-07-20T19:39:53.518Z,1626809993.518 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2021-07-20T19:39:53.518Z,1626809993.518 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2021-07-20T19:39:53.518Z,1626809993.518 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2021-07-20T19:39:53.518Z,1626809993.518 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2021-07-20T19:39:53.518Z,1626809993.518 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2021-07-20T19:39:53.518Z,1626809993.518 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2021-07-20T19:39:53.519Z,1626809993.519 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2021-07-20T19:39:53.519Z,1626809993.519 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2021-07-20T19:39:53.519Z,1626809993.519 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2021-07-20T19:39:53.519Z,1626809993.519 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2021-07-20T19:39:53.519Z,1626809993.519 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2021-07-20T19:39:53.521Z,1626809993.521 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2021-07-20T19:39:53.521Z,1626809993.521 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2021-07-20T19:39:53.522Z,1626809993.522 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2021-07-20T19:39:53.732Z,1626809993.732 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T19:39:53.935Z,1626809993.935 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 2.028650 m 
2021-07-20T19:39:53.936Z,1626809993.936 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2021-07-20T19:39:53.948Z,1626809993.948 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2021-07-20T19:39:53.948Z,1626809993.948 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2021-07-20T19:39:53.948Z,1626809993.948 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2021-07-20T19:39:53.949Z,1626809993.949 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2021-07-20T19:40:06.037Z,1626810006.037 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-07-20T19:40:06.037Z,1626810006.037 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:40:06.107Z,1626810006.107 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:40:06.465Z,1626810006.465 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:40:06.465Z,1626810006.465 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-07-20T19:40:24.856Z,1626810024.856 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T19:40:26.340Z,1626810026.340 [Radio_Surface](INFO): Powering down
2021-07-20T19:40:55.984Z,1626810055.984 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T19:40:56.988Z,1626810056.988 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2021-07-20T19:41:04.992Z,1626810064.992 [Power24vConverter](INFO): Powering down.
2021-07-20T19:41:36.176Z,1626810096.176 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.766968
2021-07-20T19:41:44.982Z,1626810104.982 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-07-20T19:41:44.982Z,1626810104.982 [NAL9602] Data Fault, FailCount= 1
2021-07-20T19:41:44.982Z,1626810104.982 [NAL9602](ERROR): Data Fault
2021-07-20T19:41:45.008Z,1626810105.008 [CBIT](ERROR): Data Fault in component: NAL9602
2021-07-20T19:41:45.381Z,1626810105.381 [NAL9602](INFO): Powering down
2021-07-20T19:41:46.213Z,1626810106.213 [CBIT](INFO): Clearing failed state for component NAL9602
2021-07-20T19:41:46.214Z,1626810106.214 [NAL9602] No Fault, FailCount= 1
2021-07-20T19:42:15.678Z,1626810135.678 [NAL9602](INFO): Powering up NAL9602
2021-07-20T19:42:26.598Z,1626810146.598 [NAL9602](INFO): NAL9602 initialized
2021-07-20T19:43:07.018Z,1626810187.018 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-07-20T19:43:07.018Z,1626810187.018 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:43:07.065Z,1626810187.065 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:43:07.532Z,1626810187.532 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:43:07.532Z,1626810187.532 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-07-20T19:46:08.014Z,1626810368.014 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-07-20T19:46:08.014Z,1626810368.014 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:46:08.029Z,1626810368.029 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:46:08.447Z,1626810368.447 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:46:08.447Z,1626810368.447 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-07-20T19:49:09.016Z,1626810549.016 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-07-20T19:49:09.016Z,1626810549.016 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:49:09.085Z,1626810549.085 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:49:09.469Z,1626810549.469 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:49:09.469Z,1626810549.469 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-07-20T19:49:54.665Z,1626810594.665 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2021-07-20T19:49:54.665Z,1626810594.665 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2021-07-20T19:49:54.665Z,1626810594.665 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T19:49:54.670Z,1626810594.670 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2021-07-20T19:49:55.065Z,1626810595.065 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 1.574576 m 
2021-07-20T19:49:55.065Z,1626810595.065 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2021-07-20T19:49:55.065Z,1626810595.065 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2021-07-20T19:49:55.065Z,1626810595.065 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2021-07-20T19:52:10.017Z,1626810730.017 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-07-20T19:52:10.017Z,1626810730.017 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:52:10.033Z,1626810730.033 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:52:10.449Z,1626810730.449 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:52:10.449Z,1626810730.449 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-07-20T19:52:28.154Z,1626810748.154 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-07-20T19:52:28.154Z,1626810748.154 [NAL9602] Data Fault, FailCount= 2
2021-07-20T19:52:28.154Z,1626810748.154 [NAL9602](ERROR): Data Fault
2021-07-20T19:52:28.218Z,1626810748.218 [CBIT](ERROR): Data Fault in component: NAL9602
2021-07-20T19:52:28.558Z,1626810748.558 [NAL9602](INFO): Powering down
2021-07-20T19:52:29.419Z,1626810749.419 [CBIT](INFO): Clearing failed state for component NAL9602
2021-07-20T19:52:29.419Z,1626810749.419 [NAL9602] No Fault, FailCount= 2
2021-07-20T19:52:58.870Z,1626810778.870 [NAL9602](INFO): Powering up NAL9602
2021-07-20T19:53:09.780Z,1626810789.780 [NAL9602](INFO): NAL9602 initialized
2021-07-20T19:55:11.005Z,1626810911.005 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-07-20T19:55:11.005Z,1626810911.005 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:55:11.021Z,1626810911.021 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:55:11.433Z,1626810911.433 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:55:11.433Z,1626810911.433 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-07-20T19:58:12.010Z,1626811092.010 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-07-20T19:58:12.010Z,1626811092.010 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T19:58:12.026Z,1626811092.026 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T19:58:12.434Z,1626811092.434 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T19:58:12.434Z,1626811092.434 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-07-20T19:59:55.826Z,1626811195.826 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 10.01 minutes.
2021-07-20T19:59:55.827Z,1626811195.827 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 437.278425 +/- 3.131588 cc (conf. level 98.00%, sigma: 17.077918 cc).
2021-07-20T19:59:55.840Z,1626811195.840 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: -17.509891 +/- 0.134793 mm (conf. level 98.00%, sigma: 0.735084 mm).
2021-07-20T19:59:55.841Z,1626811195.841 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 437.278425 cc buoyancy neutral and -17.509891 mm mass default
2021-07-20T19:59:55.849Z,1626811195.849 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-07-20T19:59:55.850Z,1626811195.850 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2021-07-20T19:59:55.850Z,1626811195.850 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2021-07-20T19:59:55.850Z,1626811195.850 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-07-20T19:59:55.850Z,1626811195.850 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): DAT.verbosity=3 count;

2021-07-20T19:59:55.850Z,1626811195.850 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;

2021-07-20T19:59:55.850Z,1626811195.850 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=437.278425 cubic_centimeter;

2021-07-20T19:59:55.850Z,1626811195.850 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;

2021-07-20T19:59:55.851Z,1626811195.851 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.kiDepthRateBuoy=15 reciprocal_second;

2021-07-20T19:59:55.851Z,1626811195.851 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.kpDepthBuoy=60 ratio;

2021-07-20T19:59:55.851Z,1626811195.851 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.kpDepthRateBuoy=-25 ratio;

2021-07-20T19:59:55.851Z,1626811195.851 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=-17.509891 millimeter;

2021-07-20T19:59:55.851Z,1626811195.851 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2021-07-20T19:59:55.851Z,1626811195.851 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2021-07-20T19:59:55.857Z,1626811195.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2021-07-20T19:59:55.857Z,1626811195.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2021-07-20T19:59:55.857Z,1626811195.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2021-07-20T19:59:55.857Z,1626811195.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2021-07-20T19:59:55.857Z,1626811195.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2021-07-20T19:59:55.857Z,1626811195.857 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2021-07-20T19:59:55.859Z,1626811195.859 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2021-07-20T19:59:56.233Z,1626811196.233 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2021-07-20T19:59:56.233Z,1626811196.233 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2021-07-20T19:59:56.234Z,1626811196.234 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2021-07-20T19:59:56.234Z,1626811196.234 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2021-07-20T19:59:56.234Z,1626811196.234 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2021-07-20T19:59:56.234Z,1626811196.234 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2021-07-20T19:59:56.234Z,1626811196.234 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2021-07-20T19:59:56.234Z,1626811196.234 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2021-07-20T19:59:56.234Z,1626811196.234 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2021-07-20T19:59:56.619Z,1626811196.619 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2021-07-20T19:59:56.619Z,1626811196.619 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2021-07-20T19:59:56.620Z,1626811196.620 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2021-07-20T19:59:56.620Z,1626811196.620 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2021-07-20T19:59:56.620Z,1626811196.620 [ballast_and_trim:RunBallastAndTrim] Stopped
2021-07-20T19:59:56.620Z,1626811196.620 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2021-07-20T19:59:56.620Z,1626811196.620 [ballast_and_trim:Float_Up] Running Loop=1
2021-07-20T19:59:56.620Z,1626811196.620 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2021-07-20T19:59:56.621Z,1626811196.621 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2021-07-20T19:59:56.621Z,1626811196.621 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2021-07-20T19:59:56.621Z,1626811196.621 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2021-07-20T19:59:56.621Z,1626811196.621 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2021-07-20T19:59:57.020Z,1626811197.020 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2021-07-20T20:00:50.757Z,1626811250.757 [ballast_and_trim:Float_Up] Stopped
2021-07-20T20:00:50.757Z,1626811250.757 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2021-07-20T20:00:50.757Z,1626811250.757 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2021-07-20T20:00:50.757Z,1626811250.757 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2021-07-20T20:00:50.757Z,1626811250.757 [ballast_and_trim:Float_Up:B.Wait] Stopped
2021-07-20T20:00:50.758Z,1626811250.758 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T20:00:50.759Z,1626811250.759 [ballast_and_trim](INFO): Completed ballast_and_trim
2021-07-20T20:00:50.759Z,1626811250.759 [MissionManager](INFO): ballast_and_trim is completed.
2021-07-20T20:00:50.760Z,1626811250.760 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2021-07-20T20:00:50.760Z,1626811250.760 [ballast_and_trim] Stopped
2021-07-20T20:00:50.760Z,1626811250.760 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2021-07-20T20:00:50.760Z,1626811250.760 [ballast_and_trim:Science] Stopped
2021-07-20T20:00:50.760Z,1626811250.760 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2021-07-20T20:00:50.760Z,1626811250.760 [ballast_and_trim:Science:B] Stopped
2021-07-20T20:00:50.760Z,1626811250.760 [ballast_and_trim:Science:C] Stopped
2021-07-20T20:00:50.760Z,1626811250.760 [ballast_and_trim:Science:E] Stopped
2021-07-20T20:00:50.761Z,1626811250.761 [ballast_and_trim:Science:OceanCurrent] Stopped
2021-07-20T20:00:50.761Z,1626811250.761 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2021-07-20T20:00:50.761Z,1626811250.761 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2021-07-20T20:00:51.185Z,1626811251.185 [MissionManager](IMPORTANT): Started mission Default
2021-07-20T20:00:51.185Z,1626811251.185 [Default] Running Loop=1
2021-07-20T20:00:51.185Z,1626811251.185 [Default](DEBUG): Aggregate::initialize Default
2021-07-20T20:00:51.185Z,1626811251.185 [Default:B.GoToSurface] Running Loop=1
2021-07-20T20:00:51.185Z,1626811251.185 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-07-20T20:00:51.186Z,1626811251.186 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-07-20T20:00:51.186Z,1626811251.186 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-07-20T20:00:51.187Z,1626811251.187 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-07-20T20:00:51.187Z,1626811251.187 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-07-20T20:00:51.187Z,1626811251.187 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-07-20T20:00:51.188Z,1626811251.188 [Default:A.Wait] Running Loop=1
2021-07-20T20:00:51.188Z,1626811251.188 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-07-20T20:00:51.332Z,1626811251.332 [Radio_Surface](INFO): Powering up
2021-07-20T20:00:51.352Z,1626811251.352 [WetLabsBB2FL](INFO): Powering down
2021-07-20T20:00:57.088Z,1626811257.088 [DataOverHttps](INFO): Radio surface powered ON.
2021-07-20T20:01:04.512Z,1626811264.512 [Default:A.Wait](INFO): Done Waiting.
2021-07-20T20:01:04.512Z,1626811264.512 [Default:A.Wait] Stopped
2021-07-20T20:01:04.512Z,1626811264.512 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T20:01:04.909Z,1626811264.909 [Default:CheckIn] Running Loop=1
2021-07-20T20:01:04.909Z,1626811264.909 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-20T20:01:04.909Z,1626811264.909 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-20T20:01:12.994Z,1626811272.994 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-07-20T20:01:12.994Z,1626811272.994 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T20:01:13.040Z,1626811273.040 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T20:01:13.439Z,1626811273.439 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T20:01:13.439Z,1626811273.439 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-07-20T20:01:27.208Z,1626811287.208 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T20:01:58.332Z,1626811318.332 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T20:02:29.456Z,1626811349.456 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T20:03:00.580Z,1626811380.580 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T20:03:10.930Z,1626811390.930 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-07-20T20:03:10.930Z,1626811390.930 [NAL9602] Data Fault, FailCount= 3
2021-07-20T20:03:10.930Z,1626811390.930 [NAL9602](ERROR): Data Fault
2021-07-20T20:03:10.973Z,1626811390.973 [CBIT](ERROR): Data Fault in component: NAL9602
2021-07-20T20:03:11.331Z,1626811391.331 [NAL9602](INFO): Powering down
2021-07-20T20:03:12.158Z,1626811392.158 [CBIT](INFO): Clearing failed state for component NAL9602
2021-07-20T20:03:12.158Z,1626811392.158 [NAL9602] No Fault, FailCount= 3
2021-07-20T20:03:31.705Z,1626811411.705 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T20:03:41.638Z,1626811421.638 [NAL9602](INFO): Powering up NAL9602
2021-07-20T20:03:52.549Z,1626811432.549 [NAL9602](INFO): NAL9602 initialized
2021-07-20T20:04:02.836Z,1626811442.836 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2021-07-20T20:04:13.978Z,1626811453.978 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-07-20T20:04:13.978Z,1626811453.978 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T20:04:14.009Z,1626811454.009 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T20:04:14.400Z,1626811454.400 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T20:04:14.400Z,1626811454.400 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-07-20T20:04:34.037Z,1626811474.037 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003785
2021-07-20T20:06:05.195Z,1626811565.195 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-07-20T20:01:04.9Z
2021-07-20T20:06:05.196Z,1626811565.196 [Default:CheckIn:Read_GPS] Stopped
2021-07-20T20:06:05.212Z,1626811565.212 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-20T20:06:05.597Z,1626811565.597 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-07-20T20:06:13.668Z,1626811573.668 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20210720T193053/Courier0004.lzma
2021-07-20T20:06:14.670Z,1626811574.670 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Courier0004.lzma.bak
2021-07-20T20:06:14.670Z,1626811574.670 [DataOverHttps](INFO): SBD MOMSN=15749787
2021-07-20T20:06:34.304Z,1626811594.304 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20210720T190158/Express0025.lzma
2021-07-20T20:06:35.306Z,1626811595.306 [DataOverHttps](INFO): Moved sent file to Logs/20210720T190158/Express0025.lzma.bak
2021-07-20T20:06:35.306Z,1626811595.306 [DataOverHttps](INFO): SBD MOMSN=15749789
2021-07-20T20:06:56.371Z,1626811616.371 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20210720T190158/Express0028.lzma
2021-07-20T20:06:57.374Z,1626811617.374 [DataOverHttps](INFO): Moved sent file to Logs/20210720T190158/Express0028.lzma.bak
2021-07-20T20:06:57.374Z,1626811617.374 [DataOverHttps](INFO): SBD MOMSN=15749794
2021-07-20T20:07:14.557Z,1626811634.557 [DataOverHttps](INFO): Sending 987 bytes from file Logs/20210720T193053/Express0001.lzma
2021-07-20T20:07:14.851Z,1626811634.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-07-20T20:07:14.851Z,1626811634.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-07-20T20:07:14.862Z,1626811634.862 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-07-20T20:07:15.240Z,1626811635.240 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-07-20T20:07:15.240Z,1626811635.240 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-07-20T20:07:15.558Z,1626811635.558 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Express0001.lzma.bak
2021-07-20T20:07:15.558Z,1626811635.558 [DataOverHttps](INFO): SBD MOMSN=15749796
2021-07-20T20:07:32.763Z,1626811652.763 [DataOverHttps](INFO): Sending 2432 bytes from file Logs/20210720T193053/Express0005.lzma
2021-07-20T20:07:33.762Z,1626811653.762 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Express0005.lzma.bak
2021-07-20T20:07:33.762Z,1626811653.762 [DataOverHttps](INFO): SBD MOMSN=15749819
2021-07-20T20:07:51.071Z,1626811671.071 [DataOverHttps](INFO): Sending 49 bytes from file Logs/20210720T193053/Express0008.lzma
2021-07-20T20:07:52.074Z,1626811672.074 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Express0008.lzma.bak
2021-07-20T20:07:52.074Z,1626811672.074 [DataOverHttps](INFO): SBD MOMSN=15749935
2021-07-20T20:07:55.235Z,1626811675.235 [Default:CheckIn:Read_Iridium] Stopped
2021-07-20T20:07:55.235Z,1626811675.235 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-20T20:07:55.235Z,1626811675.235 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-20T20:10:02.536Z,1626811802.536 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200951.00,A,3648.16526,N,12147.28750,W,0.117,130.42,200721,,,A*70
2021-07-20T20:10:02.539Z,1626811802.539 [NAL9602](INFO): GPS fix at 20210720T200951: (36.802754, -121.788125)
2021-07-20T20:10:34.857Z,1626811834.857 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-20T20:12:55.927Z,1626811975.927 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-20T20:12:55.927Z,1626811975.927 [Default:CheckIn:C.Wait] Stopped
2021-07-20T20:12:55.927Z,1626811975.927 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T20:12:55.928Z,1626811975.928 [Default:CheckIn:D] Running Loop=1
2021-07-20T20:12:56.316Z,1626811976.316 [Default:CheckIn:D] Stopped
2021-07-20T20:12:56.316Z,1626811976.316 [Default:CheckIn:E] Running Loop=1
2021-07-20T20:12:56.716Z,1626811976.716 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.085503 min 
2021-07-20T20:12:56.716Z,1626811976.716 [Default:CheckIn:E] Stopped
2021-07-20T20:12:56.716Z,1626811976.716 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-20T20:12:56.717Z,1626811976.717 [Default:CheckIn] Stopped
2021-07-20T20:12:56.717Z,1626811976.717 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-20T20:12:56.717Z,1626811976.717 [Default:CheckIn](INFO): Running loop #2
2021-07-20T20:12:56.717Z,1626811976.717 [Default:CheckIn] Running Loop=2
2021-07-20T20:12:56.717Z,1626811976.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-20T20:12:56.717Z,1626811976.717 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-20T20:12:58.729Z,1626811978.729 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201247.00,A,3648.16291,N,12147.28733,W,0.641,130.42,200721,,,A*77
2021-07-20T20:12:58.731Z,1626811978.731 [NAL9602](INFO): GPS fix at 20210720T201247: (36.802715, -121.788122)
2021-07-20T20:12:58.743Z,1626811978.743 [Default:CheckIn:Read_GPS] Stopped
2021-07-20T20:12:58.743Z,1626811978.743 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-20T20:13:07.264Z,1626811987.264 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20210720T193053/Courier0010.lzma
2021-07-20T20:13:09.633Z,1626811989.633 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Courier0010.lzma.bak
2021-07-20T20:13:09.633Z,1626811989.633 [DataOverHttps](INFO): SBD MOMSN=15749937
2021-07-20T20:13:26.512Z,1626812006.512 [DataOverHttps](INFO): Sending 295 bytes from file Logs/20210720T193053/Express0011.lzma
2021-07-20T20:13:27.514Z,1626812007.514 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Express0011.lzma.bak
2021-07-20T20:13:27.514Z,1626812007.514 [DataOverHttps](INFO): SBD MOMSN=15749940
2021-07-20T20:13:30.277Z,1626812010.277 [Default:CheckIn:Read_Iridium] Stopped
2021-07-20T20:13:30.277Z,1626812010.277 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-20T20:13:30.277Z,1626812010.277 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-20T20:14:42.963Z,1626812082.963 [NAL9602](INFO): SBD MO Status=2, MOMSN=28492, MT Status=2, MTMSN=0
2021-07-20T20:14:42.963Z,1626812082.963 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-20T20:15:01.951Z,1626812101.951 [NAL9602](INFO): SBD MO Status=2, MOMSN=28492, MT Status=2, MTMSN=0
2021-07-20T20:15:01.951Z,1626812101.951 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-20T20:16:09.015Z,1626812169.015 [NAL9602](INFO): SBD MO Status=2, MOMSN=28492, MT Status=2, MTMSN=0
2021-07-20T20:16:09.015Z,1626812169.015 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-20T20:16:21.131Z,1626812181.131 [NAL9602](INFO): SBD MO Status=2, MOMSN=28492, MT Status=2, MTMSN=0
2021-07-20T20:16:21.131Z,1626812181.131 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-20T20:16:39.315Z,1626812199.315 [NAL9602](INFO): SBD MO Status=0, MOMSN=28492, MT Status=0, MTMSN=0
2021-07-20T20:16:39.315Z,1626812199.315 [NAL9602](INFO): No messages in MT queue
2021-07-20T20:17:10.029Z,1626812230.029 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-20T20:18:30.839Z,1626812310.839 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-20T20:18:30.839Z,1626812310.839 [Default:CheckIn:C.Wait] Stopped
2021-07-20T20:18:30.839Z,1626812310.839 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T20:18:30.839Z,1626812310.839 [Default:CheckIn:D] Running Loop=1
2021-07-20T20:18:31.258Z,1626812311.258 [Default:CheckIn:D] Stopped
2021-07-20T20:18:31.258Z,1626812311.258 [Default:CheckIn:E] Running Loop=1
2021-07-20T20:18:31.660Z,1626812311.660 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.667877 min 
2021-07-20T20:18:31.660Z,1626812311.660 [Default:CheckIn:E] Stopped
2021-07-20T20:18:31.660Z,1626812311.660 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-20T20:18:31.660Z,1626812311.660 [Default:CheckIn] Stopped
2021-07-20T20:18:31.660Z,1626812311.660 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-20T20:18:31.661Z,1626812311.661 [Default:CheckIn](INFO): Running loop #3
2021-07-20T20:18:31.661Z,1626812311.661 [Default:CheckIn] Running Loop=3
2021-07-20T20:18:31.661Z,1626812311.661 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-20T20:18:31.661Z,1626812311.661 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-20T20:18:33.656Z,1626812313.656 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201823.00,A,3648.16201,N,12147.28484,W,0.467,0.00,200721,,,A*7B
2021-07-20T20:18:33.658Z,1626812313.658 [NAL9602](INFO): GPS fix at 20210720T201823: (36.802700, -121.788081)
2021-07-20T20:18:33.674Z,1626812313.674 [Default:CheckIn:Read_GPS] Stopped
2021-07-20T20:18:33.674Z,1626812313.674 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-20T20:18:46.424Z,1626812326.424 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210720T193053/Courier0013.lzma
2021-07-20T20:18:47.426Z,1626812327.426 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Courier0013.lzma.bak
2021-07-20T20:18:47.426Z,1626812327.426 [DataOverHttps](INFO): SBD MOMSN=15749944
2021-07-20T20:19:05.220Z,1626812345.220 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20210720T193053/Express0014.lzma
2021-07-20T20:19:06.222Z,1626812346.222 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Express0014.lzma.bak
2021-07-20T20:19:06.222Z,1626812346.222 [DataOverHttps](INFO): SBD MOMSN=15749948
2021-07-20T20:19:09.297Z,1626812349.297 [Default:CheckIn:Read_Iridium] Stopped
2021-07-20T20:19:09.297Z,1626812349.297 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-20T20:19:09.297Z,1626812349.297 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-20T20:19:09.703Z,1626812349.703 [NAL9602](INFO): SBD MO Status=2, MOMSN=28493, MT Status=2, MTMSN=0
2021-07-20T20:19:09.703Z,1626812349.703 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-20T20:22:18.763Z,1626812538.763 [NAL9602](INFO): SBD MO Status=0, MOMSN=28493, MT Status=0, MTMSN=0
2021-07-20T20:22:18.763Z,1626812538.763 [NAL9602](INFO): No messages in MT queue
2021-07-20T20:22:49.504Z,1626812569.504 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-20T20:24:09.911Z,1626812649.911 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-20T20:24:09.912Z,1626812649.912 [Default:CheckIn:C.Wait] Stopped
2021-07-20T20:24:09.912Z,1626812649.912 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T20:24:09.912Z,1626812649.912 [Default:CheckIn:D] Running Loop=1
2021-07-20T20:24:10.308Z,1626812650.308 [Default:CheckIn:D] Stopped
2021-07-20T20:24:10.308Z,1626812650.308 [Default:CheckIn:E] Running Loop=1
2021-07-20T20:24:10.712Z,1626812650.712 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.318703 min 
2021-07-20T20:24:10.712Z,1626812650.712 [Default:CheckIn:E] Stopped
2021-07-20T20:24:10.712Z,1626812650.712 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-20T20:24:10.712Z,1626812650.712 [Default:CheckIn] Stopped
2021-07-20T20:24:10.712Z,1626812650.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-20T20:24:10.713Z,1626812650.713 [Default:CheckIn](INFO): Running loop #4
2021-07-20T20:24:10.713Z,1626812650.713 [Default:CheckIn] Running Loop=4
2021-07-20T20:24:10.713Z,1626812650.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-20T20:24:10.713Z,1626812650.713 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-20T20:24:12.731Z,1626812652.731 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202402.00,A,3648.16240,N,12147.27903,W,0.292,339.40,200721,,,A*7E
2021-07-20T20:24:12.734Z,1626812652.734 [NAL9602](INFO): GPS fix at 20210720T202402: (36.802707, -121.787984)
2021-07-20T20:24:12.745Z,1626812652.745 [Default:CheckIn:Read_GPS] Stopped
2021-07-20T20:24:12.745Z,1626812652.745 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-20T20:24:20.475Z,1626812660.475 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20210720T193053/Courier0016.lzma
2021-07-20T20:24:21.478Z,1626812661.478 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Courier0016.lzma.bak
2021-07-20T20:24:21.478Z,1626812661.478 [DataOverHttps](INFO): SBD MOMSN=15749951
2021-07-20T20:24:33.383Z,1626812673.383 [NAL9602](INFO): SBD MO Status=2, MOMSN=28494, MT Status=2, MTMSN=0
2021-07-20T20:24:33.383Z,1626812673.383 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-20T20:24:45.485Z,1626812685.485 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20210720T193053/Express0017.lzma
2021-07-20T20:24:46.486Z,1626812686.486 [DataOverHttps](INFO): Moved sent file to Logs/20210720T193053/Express0017.lzma.bak
2021-07-20T20:24:46.486Z,1626812686.486 [DataOverHttps](INFO): SBD MOMSN=15749956
2021-07-20T20:24:51.343Z,1626812691.343 [Default:CheckIn:Read_Iridium] Stopped
2021-07-20T20:24:51.343Z,1626812691.343 [Default:CheckIn:C.Wait] Running Loop=1
2021-07-20T20:24:51.344Z,1626812691.344 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-07-20T20:25:10.658Z,1626812710.658 [NAL9602](INFO): SBD MO Status=2, MOMSN=28494, MT Status=2, MTMSN=0
2021-07-20T20:25:10.658Z,1626812710.658 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2021-07-20T20:25:26.011Z,1626812726.011 [NAL9602](INFO): SBD MO Status=0, MOMSN=28494, MT Status=0, MTMSN=0
2021-07-20T20:25:26.011Z,1626812726.011 [NAL9602](INFO): No messages in MT queue
2021-07-20T20:25:56.096Z,1626812756.096 [CommandLine](IMPORTANT): got command show variable kdDepthBuoy
2021-07-20T20:25:56.123Z,1626812756.123 [CommandLine](IMPORTANT): VerticalControl.kdDepthBuoy (second)
2021-07-20T20:25:56.773Z,1626812756.773 [NAL9602](INFO): Not Powering down - fast GPS
2021-07-20T20:26:02.697Z,1626812762.697 [CommandLine](IMPORTANT): got command get VerticalControl.kdDepthBuoy
2021-07-20T20:26:02.698Z,1626812762.698 [CommandLine](IMPORTANT): VerticalControl.kdDepthBuoy 0.000000 s
2021-07-20T20:28:12.402Z,1626812892.402 [DataOverHttps](IMPORTANT): SBD MTMSN=20210720T202801
2021-07-20T20:28:19.812Z,1626812899.812 [DataOverHttps](INFO): Received command:configSet VerticalControl.kdDepthBuoy 10000 s persist
2021-07-20T20:28:20.106Z,1626812900.106 [CommandLine](IMPORTANT): got command configSet VerticalControl.kdDepthBuoy 10000.000000 second persist
2021-07-20T20:28:24.934Z,1626812904.934 [CommandLine](IMPORTANT): got command configSet list
2021-07-20T20:28:24.934Z,1626812904.934 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-07-20T20:28:24.935Z,1626812904.935 [CommandLine](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2021-07-20T20:28:24.935Z,1626812904.935 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2021-07-20T20:28:24.935Z,1626812904.935 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2021-07-20T20:28:24.935Z,1626812904.935 [CommandLine](IMPORTANT): DAT.verbosity=3 count;

2021-07-20T20:28:24.936Z,1626812904.936 [CommandLine](IMPORTANT): Express linearApproximation platform_pitch_angle 5.000000 degree;

2021-07-20T20:28:24.936Z,1626812904.936 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=437.278425 cubic_centimeter;

2021-07-20T20:28:24.936Z,1626812904.936 [CommandLine](IMPORTANT): VerticalControl.kdDepthBuoy=10000 second;

2021-07-20T20:28:24.936Z,1626812904.936 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second;

2021-07-20T20:28:24.936Z,1626812904.936 [CommandLine](IMPORTANT): VerticalControl.kiDepthRateBuoy=15 reciprocal_second;

2021-07-20T20:28:24.936Z,1626812904.936 [CommandLine](IMPORTANT): VerticalControl.kpDepthBuoy=60 ratio;

2021-07-20T20:28:24.937Z,1626812904.937 [CommandLine](IMPORTANT): VerticalControl.kpDepthRateBuoy=-25 ratio;

2021-07-20T20:28:24.937Z,1626812904.937 [CommandLine](IMPORTANT): VerticalControl.massDefault=-17.509891 millimeter;

2021-07-20T20:29:25.541Z,1626812965.541 [DataOverHttps](IMPORTANT): SBD MTMSN=20210720T202915
2021-07-20T20:29:36.536Z,1626812976.536 [DataOverHttps](INFO): Received command:restart app
2021-07-20T20:29:36.578Z,1626812976.578 [CommandLine](IMPORTANT): got command restart 
2021-07-20T20:29:36.578Z,1626812976.578 [CommandLine](FAULT): Incomplete syntax. Try: help restart
2021-07-20T20:29:52.031Z,1626812992.031 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-07-20T20:29:52.031Z,1626812992.031 [Default:CheckIn:C.Wait] Stopped
2021-07-20T20:29:52.031Z,1626812992.031 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-07-20T20:29:52.036Z,1626812992.036 [Default:CheckIn:D] Running Loop=1
2021-07-20T20:29:52.429Z,1626812992.429 [Default:CheckIn:D] Stopped
2021-07-20T20:29:52.429Z,1626812992.429 [Default:CheckIn:E] Running Loop=1
2021-07-20T20:29:52.831Z,1626812992.831 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.020736 min 
2021-07-20T20:29:52.831Z,1626812992.831 [Default:CheckIn:E] Stopped
2021-07-20T20:29:52.831Z,1626812992.831 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-07-20T20:29:52.832Z,1626812992.832 [Default:CheckIn] Stopped
2021-07-20T20:29:52.832Z,1626812992.832 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-20T20:29:52.832Z,1626812992.832 [Default:CheckIn](INFO): Running loop #5
2021-07-20T20:29:52.832Z,1626812992.832 [Default:CheckIn] Running Loop=5
2021-07-20T20:29:52.832Z,1626812992.832 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-07-20T20:29:52.832Z,1626812992.832 [Default:CheckIn:Read_GPS] Running Loop=1
2021-07-20T20:29:54.845Z,1626812994.845 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202944.00,A,3648.16988,N,12147.28422,W,0.428,339.40,200721,,,A*78
2021-07-20T20:29:54.847Z,1626812994.847 [NAL9602](INFO): GPS fix at 20210720T202944: (36.802831, -121.788070)
2021-07-20T20:29:54.858Z,1626812994.858 [Default:CheckIn:Read_GPS] Stopped
2021-07-20T20:29:54.858Z,1626812994.858 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-07-20T20:29:57.435Z,1626812997.435 [CommandLine](IMPORTANT): got command restart application
2021-07-20T20:29:58.440Z,1626812998.440 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2021-07-20T20:29:58.440Z,1626812998.440 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:29:58.441Z,1626812998.441 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:58.540Z,1626812998.540 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-07-20T20:29:58.540Z,1626812998.540 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:58.541Z,1626812998.541 [CommandLine](INFO): Join timeout helper Thread ID is 1718
2021-07-20T20:29:58.548Z,1626812998.548 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-07-20T20:29:58.548Z,1626812998.548 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:58.549Z,1626812998.549 [NavChartDb](INFO): Join timeout helper Thread ID is 1719
2021-07-20T20:29:58.744Z,1626812998.744 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:29:58.745Z,1626812998.745 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:58.756Z,1626812998.756 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-07-20T20:29:58.756Z,1626812998.756 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:58.756Z,1626812998.756 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1720
2021-07-20T20:29:59.240Z,1626812999.240 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:29:59.240Z,1626812999.240 [WetLabsBB2FL](INFO): Powering down
2021-07-20T20:29:59.241Z,1626812999.241 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:59.260Z,1626812999.260 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-07-20T20:29:59.260Z,1626812999.260 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:59.260Z,1626812999.260 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1721
2021-07-20T20:29:59.744Z,1626812999.744 [CTD_Seabird](INFO): Powering down
2021-07-20T20:29:59.756Z,1626812999.756 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:29:59.756Z,1626812999.756 [CTD_Seabird](INFO): Powering down
2021-07-20T20:29:59.768Z,1626812999.768 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:59.784Z,1626812999.784 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-07-20T20:29:59.784Z,1626812999.784 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:59.785Z,1626812999.785 [Radio_Surface](INFO): Join timeout helper Thread ID is 1722
2021-07-20T20:29:59.824Z,1626812999.824 [Radio_Surface](INFO): Powering down
2021-07-20T20:29:59.825Z,1626812999.825 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:29:59.825Z,1626812999.825 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:59.841Z,1626812999.841 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-07-20T20:29:59.841Z,1626812999.841 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:29:59.841Z,1626812999.841 [Onboard](INFO): Join timeout helper Thread ID is 1723
2021-07-20T20:30:01.672Z,1626813001.672 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:30:01.672Z,1626813001.672 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:01.689Z,1626813001.689 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2021-07-20T20:30:01.689Z,1626813001.689 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:01.689Z,1626813001.689 [DataOverHttps](INFO): Join timeout helper Thread ID is 1724
2021-07-20T20:30:02.532Z,1626813002.532 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:30:02.535Z,1626813002.535 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.541Z,1626813002.541 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-07-20T20:30:02.541Z,1626813002.541 [logger ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.541Z,1626813002.541 [logger](INFO): Join timeout helper Thread ID is 1725
2021-07-20T20:30:02.544Z,1626813002.544 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:30:02.544Z,1626813002.544 [logger ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.558Z,1626813002.558 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-07-20T20:30:02.558Z,1626813002.558 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.558Z,1626813002.558 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-07-20T20:30:02.558Z,1626813002.558 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.558Z,1626813002.558 [controlThread](INFO): Join timeout helper Thread ID is 1726
2021-07-20T20:30:02.560Z,1626813002.560 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-07-20T20:30:02.560Z,1626813002.560 [controlThread](DEBUG): Uninitializing ControlThread
2021-07-20T20:30:02.560Z,1626813002.560 [AHRS_M2](INFO): Powering down
2021-07-20T20:30:02.633Z,1626813002.633 [NAL9602](INFO): Powering down
2021-07-20T20:30:02.635Z,1626813002.635 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-07-20T20:30:02.637Z,1626813002.637 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-07-20T20:30:02.637Z,1626813002.637 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-07-20T20:30:02.638Z,1626813002.638 [MissionManager](INFO): Uninitializing Mission Default
2021-07-20T20:30:02.638Z,1626813002.638 [Default] Stopped
2021-07-20T20:30:02.638Z,1626813002.638 [Default](DEBUG): Aggregate::uninitialize Default
2021-07-20T20:30:02.638Z,1626813002.638 [Default:B.GoToSurface] Stopped
2021-07-20T20:30:02.638Z,1626813002.638 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-07-20T20:30:02.638Z,1626813002.638 [Default:CheckIn] Stopped
2021-07-20T20:30:02.638Z,1626813002.638 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-07-20T20:30:02.638Z,1626813002.638 [Default:CheckIn:Read_Iridium] Stopped
2021-07-20T20:30:02.642Z,1626813002.642 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-07-20T20:30:02.642Z,1626813002.642 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-07-20T20:30:02.642Z,1626813002.642 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-07-20T20:30:02.643Z,1626813002.643 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-07-20T20:30:02.643Z,1626813002.643 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-07-20T20:30:02.643Z,1626813002.643 [BuoyancyServo](INFO): Powering down
2021-07-20T20:30:02.656Z,1626813002.656 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-07-20T20:30:02.656Z,1626813002.656 [ElevatorServo](INFO): Powering down
2021-07-20T20:30:02.657Z,1626813002.657 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-07-20T20:30:02.657Z,1626813002.657 [MassServo](INFO): Powering down
2021-07-20T20:30:02.658Z,1626813002.658 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-07-20T20:30:02.658Z,1626813002.658 [RudderServo](INFO): Powering down
2021-07-20T20:30:02.659Z,1626813002.659 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2021-07-20T20:30:02.659Z,1626813002.659 [ThrusterServo](INFO): Powering down
2021-07-20T20:30:02.660Z,1626813002.660 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-07-20T20:30:02.661Z,1626813002.661 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-07-20T20:30:02.661Z,1626813002.661 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-07-20T20:30:02.661Z,1626813002.661 [CBIT](DEBUG): Powering off loads.
2021-07-20T20:30:02.672Z,1626813002.672 [CBIT](DEBUG): Disabling WDT.
2021-07-20T20:30:02.684Z,1626813002.684 [CBIT](DEBUG): Opening all GF detection circuits.
2021-07-20T20:30:02.685Z,1626813002.685 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.736Z,1626813002.736 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.739Z,1626813002.739 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.745Z,1626813002.745 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.817Z,1626813002.817 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.821Z,1626813002.821 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.860Z,1626813002.860 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-07-20T20:30:02.939Z,1626813002.939 [logger ThreadHandler](INFO): Thread cancelled.