2022-07-11T17:36:32.257Z,1657560992.257 [Supervisor](DEBUG): Initializing supervisor.
2022-07-11T17:36:32.261Z,1657560992.261 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-07-11T17:36:32.262Z,1657560992.262 [SyncHandler](INFO): Protected caller Thread ID is 5859
2022-07-11T17:36:32.262Z,1657560992.262 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-07-11T17:36:32.263Z,1657560992.263 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-07-11T17:36:32.264Z,1657560992.264 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5860
2022-07-11T17:36:32.268Z,1657560992.268 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-07-11T17:36:32.286Z,1657560992.286 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-07-11T17:36:32.287Z,1657560992.287 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-07-11T17:36:32.287Z,1657560992.287 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5861
2022-07-11T17:36:32.291Z,1657560992.291 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-07-11T17:36:32.292Z,1657560992.292 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-07-11T17:36:32.293Z,1657560992.293 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5862
2022-07-11T17:36:32.295Z,1657560992.295 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-07-11T17:36:32.296Z,1657560992.296 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-07-11T17:36:32.296Z,1657560992.296 [logger ThreadHandler](INFO): Protected caller Thread ID is 5863
2022-07-11T17:36:32.300Z,1657560992.300 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-07-11T17:36:32.300Z,1657560992.300 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-07-11T17:36:32.304Z,1657560992.304 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-07-11T17:36:32.698Z,1657560992.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-07-11T17:36:32.699Z,1657560992.699 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-07-11T17:36:33.377Z,1657560993.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-07-11T17:36:33.377Z,1657560993.377 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-07-11T17:36:33.490Z,1657560993.490 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-07-11T17:36:33.492Z,1657560993.492 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-07-11T17:36:34.068Z,1657560994.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-07-11T17:36:34.069Z,1657560994.069 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-07-11T17:36:34.170Z,1657560994.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-07-11T17:36:34.172Z,1657560994.172 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-07-11T17:36:34.258Z,1657560994.258 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-07-11T17:36:34.652Z,1657560994.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-07-11T17:36:34.652Z,1657560994.652 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-07-11T17:36:34.882Z,1657560994.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-07-11T17:36:34.884Z,1657560994.884 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-07-11T17:36:35.015Z,1657560995.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-07-11T17:36:35.016Z,1657560995.016 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-07-11T17:36:35.251Z,1657560995.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-07-11T17:36:35.253Z,1657560995.253 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-07-11T17:36:35.749Z,1657560995.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-07-11T17:36:35.751Z,1657560995.751 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-07-11T17:36:36.131Z,1657560996.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-07-11T17:36:36.133Z,1657560996.133 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-07-11T17:36:36.218Z,1657560996.218 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-07-11T17:36:36.419Z,1657560996.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-07-11T17:36:36.419Z,1657560996.419 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-07-11T17:36:36.648Z,1657560996.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-07-11T17:36:36.649Z,1657560996.649 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-07-11T17:36:36.954Z,1657560996.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-07-11T17:36:36.956Z,1657560996.956 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2022-07-11T17:36:36.960Z,1657560996.960 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2022-07-11T17:36:37.076Z,1657560997.076 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2022-07-11T17:36:37.419Z,1657560997.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2022-07-11T17:36:37.702Z,1657560997.702 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2022-07-11T17:36:37.789Z,1657560997.789 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2022-07-11T17:36:37.964Z,1657560997.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2022-07-11T17:36:38.148Z,1657560998.148 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2022-07-11T17:36:38.422Z,1657560998.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-07-11T17:36:38.423Z,1657560998.423 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2022-07-11T17:36:38.560Z,1657560998.560 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2022-07-11T17:36:38.658Z,1657560998.658 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2022-07-11T17:36:38.767Z,1657560998.767 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2022-07-11T17:36:38.870Z,1657560998.870 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-07-11T17:36:38.897Z,1657560998.897 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-07-11T17:36:39.018Z,1657560999.018 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-07-11T17:36:39.020Z,1657560999.020 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-07-11T17:36:39.036Z,1657560999.036 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-07-11T17:36:39.037Z,1657560999.037 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-07-11T17:36:39.109Z,1657560999.109 [DepthRateCalculator] Loaded
2022-07-11T17:36:39.109Z,1657560999.109 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-07-11T17:36:39.115Z,1657560999.115 [PitchRateCalculator] Loaded
2022-07-11T17:36:39.115Z,1657560999.115 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-07-11T17:36:39.126Z,1657560999.126 [SpeedCalculator] Loaded
2022-07-11T17:36:39.126Z,1657560999.126 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-07-11T17:36:39.131Z,1657560999.131 [YawRateCalculator] Loaded
2022-07-11T17:36:39.131Z,1657560999.131 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-07-11T17:36:39.152Z,1657560999.152 [ElevatorOffsetCalculator] Loaded
2022-07-11T17:36:39.152Z,1657560999.152 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-07-11T17:36:39.169Z,1657560999.169 [ShortestDistanceToPolygonSidesCalculator] Loaded
2022-07-11T17:36:39.169Z,1657560999.169 [ComponentRegistry](DEBUG): SyncComponent "ShortestDistanceToPolygonSidesCalculator" handled in the control thread.
2022-07-11T17:36:39.170Z,1657560999.170 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-07-11T17:36:39.170Z,1657560999.170 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-07-11T17:36:39.239Z,1657560999.239 [VerticalControl](DEBUG): Construct VerticalControl.
2022-07-11T17:36:39.295Z,1657560999.295 [VerticalControl] Loaded
2022-07-11T17:36:39.296Z,1657560999.296 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-07-11T17:36:39.298Z,1657560999.298 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-07-11T17:36:39.337Z,1657560999.337 [HorizontalControl] Loaded
2022-07-11T17:36:39.337Z,1657560999.337 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-07-11T17:36:39.339Z,1657560999.339 [SpeedControl](DEBUG): Construct SpeedControl.
2022-07-11T17:36:39.342Z,1657560999.342 [SpeedControl] Loaded
2022-07-11T17:36:39.343Z,1657560999.343 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-07-11T17:36:39.345Z,1657560999.345 [LoopControl](DEBUG): Construct LoopControl.
2022-07-11T17:36:39.346Z,1657560999.346 [LoopControl] Loaded
2022-07-11T17:36:39.346Z,1657560999.346 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-07-11T17:36:39.346Z,1657560999.346 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-07-11T17:36:39.347Z,1657560999.347 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-07-11T17:36:39.484Z,1657560999.484 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-07-11T17:36:39.484Z,1657560999.484 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-07-11T17:36:39.498Z,1657560999.498 [NavChart] Loaded
2022-07-11T17:36:39.498Z,1657560999.498 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-07-11T17:36:39.504Z,1657560999.504 [UniversalFixResidualReporter] Loaded
2022-07-11T17:36:39.504Z,1657560999.504 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-07-11T17:36:39.505Z,1657560999.505 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-07-11T17:36:39.507Z,1657560999.507 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-07-11T17:36:39.649Z,1657560999.649 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-07-11T17:36:39.650Z,1657560999.650 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-07-11T17:36:40.423Z,1657561000.423 [AHRS_M2] Loaded
2022-07-11T17:36:40.423Z,1657561000.423 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-07-11T17:36:40.675Z,1657561000.675 [BackseatComponent] Loaded
2022-07-11T17:36:40.675Z,1657561000.675 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-07-11T17:36:40.676Z,1657561000.676 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408DD4E0
2022-07-11T17:36:40.676Z,1657561000.676 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 5945
2022-07-11T17:36:40.679Z,1657561000.679 [LcmUniversalReporter] Loaded
2022-07-11T17:36:40.679Z,1657561000.679 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-07-11T17:36:40.965Z,1657561000.965 [DataOverHttps] Loaded
2022-07-11T17:36:40.965Z,1657561000.965 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-07-11T17:36:40.966Z,1657561000.966 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2022-07-11T17:36:40.966Z,1657561000.966 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5946
2022-07-11T17:36:40.987Z,1657561000.987 [Depth_Keller] Loaded
2022-07-11T17:36:40.988Z,1657561000.988 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-07-11T17:36:40.992Z,1657561000.992 [DropWeight] Loaded
2022-07-11T17:36:40.993Z,1657561000.993 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-07-11T17:36:41.055Z,1657561001.055 [NAL9602] Loaded
2022-07-11T17:36:41.055Z,1657561001.055 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-07-11T17:36:41.085Z,1657561001.085 [Onboard] Loaded
2022-07-11T17:36:41.086Z,1657561001.086 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-07-11T17:36:41.087Z,1657561001.087 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2022-07-11T17:36:41.087Z,1657561001.087 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5947
2022-07-11T17:36:41.099Z,1657561001.099 [Power24vConverter] Loaded
2022-07-11T17:36:41.099Z,1657561001.099 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-07-11T17:36:41.112Z,1657561001.112 [Radio_Surface] Loaded
2022-07-11T17:36:41.113Z,1657561001.113 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-07-11T17:36:41.114Z,1657561001.114 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2022-07-11T17:36:41.114Z,1657561001.114 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5948
2022-07-11T17:36:41.115Z,1657561001.115 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-07-11T17:36:41.116Z,1657561001.116 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-07-11T17:36:41.269Z,1657561001.269 [BuoyancyServo] Loaded
2022-07-11T17:36:41.269Z,1657561001.269 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-07-11T17:36:41.290Z,1657561001.290 [ElevatorServo] Loaded
2022-07-11T17:36:41.290Z,1657561001.290 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-07-11T17:36:41.310Z,1657561001.310 [MassServo] Loaded
2022-07-11T17:36:41.310Z,1657561001.310 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-07-11T17:36:41.329Z,1657561001.329 [RudderServo] Loaded
2022-07-11T17:36:41.329Z,1657561001.329 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-07-11T17:36:41.344Z,1657561001.344 [ThrusterHE] Loaded
2022-07-11T17:36:41.344Z,1657561001.344 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-07-11T17:36:41.344Z,1657561001.344 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-07-11T17:36:41.345Z,1657561001.345 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-07-11T17:36:41.430Z,1657561001.430 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-07-11T17:36:41.430Z,1657561001.430 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-07-11T17:36:41.473Z,1657561001.473 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-07-11T17:36:41.474Z,1657561001.474 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-07-11T17:36:41.841Z,1657561001.841 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-07-11T17:36:41.842Z,1657561001.842 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-07-11T17:36:42.062Z,1657561002.062 [CTD_Seabird] Loaded
2022-07-11T17:36:42.062Z,1657561002.062 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-07-11T17:36:42.063Z,1657561002.063 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B024E0
2022-07-11T17:36:42.064Z,1657561002.064 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5949
2022-07-11T17:36:42.097Z,1657561002.097 [ESPComponent] Loaded
2022-07-11T17:36:42.097Z,1657561002.097 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2022-07-11T17:36:42.117Z,1657561002.117 [PAR_Licor] Loaded
2022-07-11T17:36:42.117Z,1657561002.117 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-07-11T17:36:42.149Z,1657561002.149 [WetLabsBB2FL] Loaded
2022-07-11T17:36:42.149Z,1657561002.149 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-07-11T17:36:42.150Z,1657561002.150 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B324E0
2022-07-11T17:36:42.151Z,1657561002.151 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5950
2022-07-11T17:36:42.151Z,1657561002.151 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-07-11T17:36:42.152Z,1657561002.152 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-07-11T17:36:42.324Z,1657561002.324 [SBIT](DEBUG): Construct Startup Built In Test.
2022-07-11T17:36:42.333Z,1657561002.333 [SBIT] Loaded
2022-07-11T17:36:42.333Z,1657561002.333 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-07-11T17:36:42.336Z,1657561002.336 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-07-11T17:36:42.349Z,1657561002.349 [IBIT] Loaded
2022-07-11T17:36:42.350Z,1657561002.350 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-07-11T17:36:42.356Z,1657561002.356 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-07-11T17:36:42.588Z,1657561002.588 [CBIT] Loaded
2022-07-11T17:36:42.588Z,1657561002.588 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-07-11T17:36:42.588Z,1657561002.588 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-07-11T17:36:42.618Z,1657561002.618 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-07-11T17:36:42.621Z,1657561002.621 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-07-11T17:36:42.656Z,1657561002.656 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-07-11T17:36:42.657Z,1657561002.657 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA04E0
2022-07-11T17:36:42.658Z,1657561002.658 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5951
2022-07-11T17:36:42.662Z,1657561002.662 [Supervisor](INFO): Main Thread ID is 5858
2022-07-11T17:36:42.662Z,1657561002.662 [Supervisor](DEBUG): Running supervisor.
2022-07-11T17:36:42.663Z,1657561002.663 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5952
2022-07-11T17:36:42.664Z,1657561002.664 [CommandExec](INFO): Initializing the command executive.
2022-07-11T17:36:42.721Z,1657561002.721 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5953
2022-07-11T17:36:42.724Z,1657561002.724 [controlThread ThreadHandler](INFO): Handler Thread ID is 5954
2022-07-11T17:36:42.725Z,1657561002.725 [logger ThreadHandler](INFO): Handler Thread ID is 5955
2022-07-11T17:36:42.726Z,1657561002.726 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 5956
2022-07-11T17:36:42.726Z,1657561002.726 [controlThread](DEBUG): Initializing ControlThread
2022-07-11T17:36:42.727Z,1657561002.727 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-07-11T17:36:42.728Z,1657561002.728 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-07-11T17:36:42.728Z,1657561002.728 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-07-11T17:36:42.728Z,1657561002.728 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-07-11T17:36:42.729Z,1657561002.729 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-07-11T17:36:42.729Z,1657561002.729 [ShortestDistanceToPolygonSidesCalculator](DEBUG): Initializing.
2022-07-11T17:36:42.730Z,1657561002.730 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-07-11T17:36:42.731Z,1657561002.731 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-07-11T17:36:42.732Z,1657561002.732 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-07-11T17:36:42.732Z,1657561002.732 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-07-11T17:36:42.733Z,1657561002.733 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-07-11T17:36:42.734Z,1657561002.734 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-07-11T17:36:42.742Z,1657561002.742 [SBIT](INFO): Initialize SBIT Component.
2022-07-11T17:36:42.742Z,1657561002.742 [SBIT](IMPORTANT): git: 2022-07-07
2022-07-11T17:36:42.742Z,1657561002.742 [SBIT](INFO): git hash: 48b7c4fbe3545a8904a3b2b7df7cd86ca01e1427
2022-07-11T17:36:42.743Z,1657561002.743 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-07-11T17:36:42.744Z,1657561002.744 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-07-11T17:36:42.745Z,1657561002.745 [SBIT](INFO): Beginning SBIT in 48.000000 seconds.
2022-07-11T17:36:42.745Z,1657561002.745 [IBIT](INFO): Initialize IBIT Component.
2022-07-11T17:36:42.746Z,1657561002.746 [CBIT](DEBUG): Initialize CBIT Component.
2022-07-11T17:36:42.757Z,1657561002.757 [CBIT](DEBUG): Initialized mux pins.
2022-07-11T17:36:42.757Z,1657561002.757 [CBIT](DEBUG): Initializing the watchdog timer.
2022-07-11T17:36:42.762Z,1657561002.762 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5957
2022-07-11T17:36:42.763Z,1657561002.763 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-07-11T17:36:42.766Z,1657561002.766 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5959
2022-07-11T17:36:42.767Z,1657561002.767 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5960
2022-07-11T17:36:42.769Z,1657561002.769 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-07-11T17:36:42.772Z,1657561002.772 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5962
2022-07-11T17:36:42.774Z,1657561002.774 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5963
2022-07-11T17:36:42.781Z,1657561002.781 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-07-11T17:36:42.782Z,1657561002.782 [CBIT](DEBUG): Initializing heartbeat.
2022-07-11T17:36:42.782Z,1657561002.782 [Onboard ThreadHandler](INFO): Handler Thread ID is 5958
2022-07-11T17:36:42.796Z,1657561002.796 [WetLabsBB2FL](INFO): Powering up
2022-07-11T17:36:42.853Z,1657561002.853 [CBIT](DEBUG): Deactivating GF circuits.
2022-07-11T17:36:42.853Z,1657561002.853 [CBIT](DEBUG): Deactivating emergency mode.
2022-07-11T17:36:42.889Z,1657561002.889 [CBIT](DEBUG): Backplane powered.
2022-07-11T17:36:42.890Z,1657561002.890 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-07-11T17:36:42.955Z,1657561002.955 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-07-11T17:36:42.959Z,1657561002.959 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-07-11T17:36:42.959Z,1657561002.959 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-07-11T17:36:42.960Z,1657561002.960 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-07-11T17:36:42.960Z,1657561002.960 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-07-11T17:36:42.960Z,1657561002.960 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-07-11T17:36:42.960Z,1657561002.960 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-07-11T17:36:42.960Z,1657561002.960 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-07-11T17:36:42.960Z,1657561002.960 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-07-11T17:36:42.961Z,1657561002.961 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2022-07-11T17:36:42.961Z,1657561002.961 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000
2022-07-11T17:36:43.007Z,1657561003.007 [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>


2022-07-11T17:36:43.008Z,1657561003.008 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-07-11T17:36:43.169Z,1657561003.169 [Radio_Surface](INFO): Powering up
2022-07-11T17:36:43.274Z,1657561003.274 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-07-11T17:36:43.276Z,1657561003.276 [Default:A.Wait](DEBUG): Construct Wait.
2022-07-11T17:36:43.278Z,1657561003.278 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-07-11T17:36:43.322Z,1657561003.322 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-07-11T17:36:43.325Z,1657561003.325 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-07-11T17:36:43.347Z,1657561003.347 [Default:E.Execute](DEBUG): Construct Execute.
2022-07-11T17:36:43.350Z,1657561003.350 [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>


2022-07-11T17:36:43.359Z,1657561003.359 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,ShortestDistanceToPolygonSidesCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-07-11T17:36:43.377Z,1657561003.377 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-07-11T17:36:43.528Z,1657561003.528 [Power24vConverter](INFO): Powering up.
2022-07-11T17:36:43.615Z,1657561003.615 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-07-11T17:36:43.622Z,1657561003.622 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-07-11T17:36:43.623Z,1657561003.623 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-07-11T17:36:43.630Z,1657561003.630 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-07-11T17:36:43.631Z,1657561003.631 [MassServo](DEBUG): Initializing EZServoServo.
2022-07-11T17:36:43.638Z,1657561003.638 [MassServo](DEBUG): Initializing MassServo.
2022-07-11T17:36:43.638Z,1657561003.638 [RudderServo](DEBUG): Initializing EZServoServo.
2022-07-11T17:36:43.646Z,1657561003.646 [RudderServo](DEBUG): Initializing RudderServo.
2022-07-11T17:36:43.646Z,1657561003.646 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-07-11T17:36:43.654Z,1657561003.654 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-07-11T17:36:44.513Z,1657561004.513 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-07-11T17:36:44.514Z,1657561004.514 [RudderServo](FAULT): Rudder failed to initialize
2022-07-11T17:36:44.514Z,1657561004.514 [RudderServo] Communications Fault, FailCount= 1
2022-07-11T17:36:44.514Z,1657561004.514 [RudderServo](ERROR): Communications Fault
2022-07-11T17:36:44.518Z,1657561004.518 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-07-11T17:36:44.754Z,1657561004.754 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-07-11T17:36:44.755Z,1657561004.755 [RudderServo](INFO): Powering down
2022-07-11T17:36:45.389Z,1657561005.389 [WetLabsBB2FL](INFO): Powering down
2022-07-11T17:36:45.435Z,1657561005.435 [RudderServo](DEBUG): Initializing EZServoServo.
2022-07-11T17:36:45.554Z,1657561005.554 [RudderServo](DEBUG): Initializing RudderServo.
2022-07-11T17:36:45.558Z,1657561005.558 [CBIT](INFO): Clearing failed state for component RudderServo
2022-07-11T17:36:45.559Z,1657561005.559 [RudderServo] No Fault, FailCount= 1
2022-07-11T17:36:49.158Z,1657561009.158 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-07-11T17:36:49.798Z,1657561009.798 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2022-07-11T17:36:56.635Z,1657561016.635 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004187
2022-07-11T17:36:58.109Z,1657561018.109 [MassServo](ERROR): getPosition uart error serial timeout
2022-07-11T17:36:58.110Z,1657561018.110 [MassServo](FAULT): Invalid EZ Servo response:""
2022-07-11T17:36:58.110Z,1657561018.110 [MassServo] Communications Fault, FailCount= 1
2022-07-11T17:36:58.110Z,1657561018.110 [MassServo](ERROR): Communications Fault
2022-07-11T17:36:58.114Z,1657561018.114 [CBIT](ERROR): Communications Fault in component: MassServo
2022-07-11T17:36:58.389Z,1657561018.389 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-07-11T17:36:58.389Z,1657561018.389 [MassServo](INFO): Powering down
2022-07-11T17:36:59.153Z,1657561019.153 [MassServo](DEBUG): Initializing EZServoServo.
2022-07-11T17:36:59.278Z,1657561019.278 [MassServo](DEBUG): Initializing MassServo.
2022-07-11T17:36:59.283Z,1657561019.283 [CBIT](INFO): Clearing failed state for component MassServo
2022-07-11T17:36:59.283Z,1657561019.283 [MassServo] No Fault, FailCount= 1
2022-07-11T17:37:11.247Z,1657561031.247 [NAL9602](INFO): Powering up NAL9602
2022-07-11T17:37:22.159Z,1657561042.159 [NAL9602](INFO): NAL9602 initialized
2022-07-11T17:37:31.468Z,1657561051.468 [SBIT](IMPORTANT): Beginning Startup BIT
2022-07-11T17:37:31.472Z,1657561051.472 [CBIT](IMPORTANT): Beginning ground fault scan
2022-07-11T17:37:42.567Z,1657561062.567 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.003172
CHAN A1 (24V): 0.001419
CHAN A2 (12V): 0.000875
CHAN A3 (5V): 0.000263
CHAN B0 (3.3V): 0.000777
CHAN B1 (3.15aV): 0.000992
CHAN B2 (3.15bV): 0.000060
CHAN B3 (GND): 0.000572
OPEN: 0.004947
Full Scale: +/- 1 mA
2022-07-11T17:38:12.547Z,1657561092.547 [CommandExec](IMPORTANT): got command show stack
2022-07-11T17:38:12.547Z,1657561092.547 [CommandExec](IMPORTANT): Behavior Stack:

2022-07-11T17:38:12.547Z,1657561092.547 [MissionManager](IMPORTANT): Mission loaded, but not running.
2022-07-11T17:38:25.624Z,1657561105.624 [SBIT](IMPORTANT): SBIT PASSED
2022-07-11T17:38:25.624Z,1657561105.624 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-07-11T17:38:25.625Z,1657561105.625 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2022-07-11T17:38:25.625Z,1657561105.625 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2022-07-11T17:38:25.625Z,1657561105.625 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Depth_Keller.offset=3.6 decibar;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Express mostRecent CBIT.ampHoursUsed;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 1.000000 kelvin;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Express linearApproximation NAL9602.sigQuality 1.000000 count;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 0.200000 microgram_per_liter;

2022-07-11T17:38:25.626Z,1657561105.626 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex1=34.55 degree;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex2=34.4 degree;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex3=34.13 degree;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex4=34.42 degree;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex5=nan degree;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.loadAtStartup=1 bool;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex1=-120.67 degree;

2022-07-11T17:38:25.627Z,1657561105.627 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex2=-119.28 degree;

2022-07-11T17:38:25.628Z,1657561105.628 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex3=-119.28 degree;

2022-07-11T17:38:25.628Z,1657561105.628 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex4=-120.67 degree;

2022-07-11T17:38:25.628Z,1657561105.628 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex5=nan degree;

2022-07-11T17:38:25.628Z,1657561105.628 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=633 cubic_centimeter;

2022-07-11T17:38:25.628Z,1657561105.628 [SBIT](IMPORTANT): VerticalControl.massDefault=-7 millimeter;

2022-07-11T17:38:25.628Z,1657561105.628 [SBIT](IMPORTANT): VerticalControl.massPositionLimitAft=-28 millimeter;

2022-07-11T17:38:25.628Z,1657561105.628 [SBIT](IMPORTANT): VerticalControl.massPositionLimitFwd=32 millimeter;

2022-07-11T17:38:26.107Z,1657561106.107 [MissionManager](IMPORTANT): Started mission Startup
2022-07-11T17:38:26.107Z,1657561106.107 [Startup] Running Loop=1
2022-07-11T17:38:26.107Z,1657561106.107 [Startup](DEBUG): Aggregate::initialize Startup
2022-07-11T17:38:26.107Z,1657561106.107 [Startup:A.GoToSurface] Running Loop=1
2022-07-11T17:38:26.107Z,1657561106.107 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-07-11T17:38:26.108Z,1657561106.108 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-07-11T17:38:26.108Z,1657561106.108 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-07-11T17:38:26.108Z,1657561106.108 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-07-11T17:38:26.109Z,1657561106.109 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-07-11T17:38:26.109Z,1657561106.109 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-07-11T17:38:26.124Z,1657561106.124 [Startup:StartupSatComms] Running Loop=1
2022-07-11T17:38:26.124Z,1657561106.124 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-07-11T17:38:26.124Z,1657561106.124 [Startup:StartupSatComms:A] Running Loop=1
2022-07-11T17:38:26.445Z,1657561106.445 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-07-11T17:39:26.223Z,1657561166.223 [Startup:StartupSatComms:A](INFO): Timed out from 2022-07-11T17:38:26.1Z
2022-07-11T17:39:26.223Z,1657561166.223 [Startup:StartupSatComms:A] Stopped
2022-07-11T17:39:26.224Z,1657561166.224 [Startup:StartupSatComms:B] Running Loop=1
2022-07-11T17:39:26.628Z,1657561166.628 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-07-11T17:39:36.451Z,1657561176.451 [DataOverHttps](INFO): Sending 113 bytes from file Logs/20000205T081742/Courier0019.lzma
2022-07-11T17:39:37.452Z,1657561177.452 [DataOverHttps](INFO): Moved sent file to Logs/20000205T081742/Courier0019.lzma.bak
2022-07-11T17:39:37.452Z,1657561177.452 [DataOverHttps](INFO): SBD MOMSN=16961160
2022-07-11T17:39:42.787Z,1657561182.787 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2022-07-11T17:39:42.787Z,1657561182.787 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2022-07-11T17:39:42.804Z,1657561182.804 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2022-07-11T17:39:43.197Z,1657561183.197 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2022-07-11T17:39:43.197Z,1657561183.197 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2022-07-11T17:39:55.865Z,1657561195.865 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20220711T173632/Courier0000.lzma
2022-07-11T17:39:56.867Z,1657561196.867 [DataOverHttps](INFO): Moved sent file to Logs/20220711T173632/Courier0000.lzma.bak
2022-07-11T17:39:56.867Z,1657561196.867 [DataOverHttps](INFO): SBD MOMSN=16961164
2022-07-11T17:40:26.238Z,1657561226.238 [Startup:StartupSatComms:B](INFO): Timed out from 2022-07-11T17:39:26.2Z
2022-07-11T17:40:26.238Z,1657561226.238 [Startup:StartupSatComms:B] Stopped
2022-07-11T17:40:26.238Z,1657561226.238 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-07-11T17:40:26.238Z,1657561226.238 [Startup:StartupSatComms] Stopped
2022-07-11T17:40:26.238Z,1657561226.238 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-07-11T17:40:26.239Z,1657561226.239 [Startup](INFO): Completed Startup
2022-07-11T17:40:26.239Z,1657561226.239 [MissionManager](INFO): Startup is completed.
2022-07-11T17:40:26.239Z,1657561226.239 [MissionManager](INFO): Uninitializing Mission Startup
2022-07-11T17:40:26.245Z,1657561226.245 [Startup] Stopped
2022-07-11T17:40:26.246Z,1657561226.246 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-07-11T17:40:26.246Z,1657561226.246 [Startup:A.GoToSurface] Stopped
2022-07-11T17:40:26.246Z,1657561226.246 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-07-11T17:40:26.632Z,1657561226.632 [MissionManager](IMPORTANT): Started mission Default
2022-07-11T17:40:26.632Z,1657561226.632 [Default] Running Loop=1
2022-07-11T17:40:26.633Z,1657561226.633 [Default](DEBUG): Aggregate::initialize Default
2022-07-11T17:40:26.633Z,1657561226.633 [Default:B.GoToSurface] Running Loop=1
2022-07-11T17:40:26.633Z,1657561226.633 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-07-11T17:40:26.633Z,1657561226.633 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-07-11T17:40:26.678Z,1657561226.678 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-07-11T17:40:26.678Z,1657561226.678 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-07-11T17:40:26.678Z,1657561226.678 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-07-11T17:40:26.678Z,1657561226.678 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-07-11T17:40:26.679Z,1657561226.679 [Default:A.Wait] Running Loop=1
2022-07-11T17:40:26.679Z,1657561226.679 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-07-11T17:40:32.330Z,1657561232.330 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T222752/Express0001.lzma
2022-07-11T17:40:33.331Z,1657561233.331 [DataOverHttps](INFO): Moved sent file to Logs/19241125T222752/Express0001.lzma.bak
2022-07-11T17:40:33.331Z,1657561233.331 [DataOverHttps](INFO): SBD MOMSN=16961167
2022-07-11T17:40:39.988Z,1657561239.988 [Default:A.Wait](INFO): Done Waiting.
2022-07-11T17:40:39.988Z,1657561239.988 [Default:A.Wait] Stopped
2022-07-11T17:40:39.988Z,1657561239.988 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-07-11T17:40:40.411Z,1657561240.411 [Default:CheckIn] Running Loop=1
2022-07-11T17:40:40.412Z,1657561240.412 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-07-11T17:40:40.412Z,1657561240.412 [Default:CheckIn:Read_GPS] Running Loop=1
2022-07-11T17:40:40.812Z,1657561240.812 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-07-11T17:42:25.047Z,1657561345.047 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-07-11T17:42:29.905Z,1657561349.905 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174226.00,A,3648.16106,N,12147.28603,W,0.078,227.18,110722,,,A*79
2022-07-11T17:42:29.924Z,1657561349.924 [NAL9602](INFO): GPS fix at 20220711T174226: (36.802684, -121.788100)
2022-07-11T17:42:29.964Z,1657561349.964 [Default:CheckIn:Read_GPS] Stopped
2022-07-11T17:42:29.964Z,1657561349.964 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-07-11T17:42:30.379Z,1657561350.379 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-07-11T17:42:36.902Z,1657561356.902 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20220711T173632/Courier0004.lzma
2022-07-11T17:42:37.907Z,1657561357.907 [DataOverHttps](INFO): Moved sent file to Logs/20220711T173632/Courier0004.lzma.bak
2022-07-11T17:42:37.907Z,1657561357.907 [DataOverHttps](INFO): SBD MOMSN=16961169
2022-07-11T17:43:02.278Z,1657561382.278 [NAL9602](INFO): Not Powering down - fast GPS
2022-07-11T17:43:14.361Z,1657561394.361 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T223009/Express0001.lzma
2022-07-11T17:43:15.363Z,1657561395.363 [DataOverHttps](INFO): Moved sent file to Logs/19241125T223009/Express0001.lzma.bak
2022-07-11T17:43:15.364Z,1657561395.364 [DataOverHttps](INFO): SBD MOMSN=16961172
2022-07-11T17:43:42.017Z,1657561422.017 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T223505/Express0001.lzma
2022-07-11T17:43:43.019Z,1657561423.019 [DataOverHttps](INFO): Moved sent file to Logs/19241125T223505/Express0001.lzma.bak
2022-07-11T17:43:43.019Z,1657561423.019 [DataOverHttps](INFO): SBD MOMSN=16961174
2022-07-11T17:44:06.657Z,1657561446.657 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T223854/Express0001.lzma
2022-07-11T17:44:07.659Z,1657561447.659 [DataOverHttps](INFO): Moved sent file to Logs/19241125T223854/Express0001.lzma.bak
2022-07-11T17:44:07.659Z,1657561447.659 [DataOverHttps](INFO): SBD MOMSN=16961176
2022-07-11T17:44:46.889Z,1657561486.889 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T224110/Express0001.lzma
2022-07-11T17:44:47.891Z,1657561487.891 [DataOverHttps](INFO): Moved sent file to Logs/19241125T224110/Express0001.lzma.bak
2022-07-11T17:44:47.892Z,1657561487.892 [DataOverHttps](INFO): SBD MOMSN=16961178
2022-07-11T17:45:10.229Z,1657561510.229 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T224501/Express0001.lzma
2022-07-11T17:45:11.231Z,1657561511.231 [DataOverHttps](INFO): Moved sent file to Logs/19241125T224501/Express0001.lzma.bak
2022-07-11T17:45:11.231Z,1657561511.231 [DataOverHttps](INFO): SBD MOMSN=16961180
2022-07-11T17:45:51.093Z,1657561551.093 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T224825/Express0001.lzma
2022-07-11T17:45:52.095Z,1657561552.095 [DataOverHttps](INFO): Moved sent file to Logs/19241125T224825/Express0001.lzma.bak
2022-07-11T17:45:52.095Z,1657561552.095 [DataOverHttps](INFO): SBD MOMSN=16961182
2022-07-11T17:46:06.778Z,1657561566.778 [CommandExec](IMPORTANT): got command failComponent
2022-07-11T17:46:06.778Z,1657561566.778 [CommandExec](IMPORTANT): Failed components:
2022-07-11T17:46:06.779Z,1657561566.779 [CommandExec](IMPORTANT): No failed Components.
2022-07-11T17:46:13.315Z,1657561573.315 [CommandExec](IMPORTANT): got command show stack
2022-07-11T17:46:13.315Z,1657561573.315 [CommandExec](IMPORTANT): Behavior Stack:

2022-07-11T17:46:13.315Z,1657561573.315 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2022-07-11T17:46:13.315Z,1657561573.315 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_Iridium
2022-07-11T17:46:23.349Z,1657561583.349 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T225215/Express0001.lzma
2022-07-11T17:46:24.355Z,1657561584.355 [DataOverHttps](INFO): Moved sent file to Logs/19241125T225215/Express0001.lzma.bak
2022-07-11T17:46:24.355Z,1657561584.355 [DataOverHttps](INFO): SBD MOMSN=16961184
2022-07-11T17:46:44.451Z,1657561604.451 [Power24vConverter](INFO): Powering down.
2022-07-11T17:46:57.793Z,1657561617.793 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T225537/Express0001.lzma
2022-07-11T17:46:58.795Z,1657561618.795 [DataOverHttps](INFO): Moved sent file to Logs/19241125T225537/Express0001.lzma.bak
2022-07-11T17:46:58.795Z,1657561618.795 [DataOverHttps](INFO): SBD MOMSN=16961186
2022-07-11T17:47:25.141Z,1657561645.141 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T225924/Express0001.lzma
2022-07-11T17:47:26.143Z,1657561646.143 [DataOverHttps](INFO): Moved sent file to Logs/19241125T225924/Express0001.lzma.bak
2022-07-11T17:47:26.143Z,1657561646.143 [DataOverHttps](INFO): SBD MOMSN=16961188
2022-07-11T17:47:45.737Z,1657561665.737 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T230251/Express0001.lzma
2022-07-11T17:47:46.739Z,1657561666.739 [DataOverHttps](INFO): Moved sent file to Logs/19241125T230251/Express0001.lzma.bak
2022-07-11T17:47:46.739Z,1657561666.739 [DataOverHttps](INFO): SBD MOMSN=16961190
2022-07-11T17:48:16.293Z,1657561696.293 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T230642/Express0001.lzma
2022-07-11T17:48:17.295Z,1657561697.295 [DataOverHttps](INFO): Moved sent file to Logs/19241125T230642/Express0001.lzma.bak
2022-07-11T17:48:17.296Z,1657561697.296 [DataOverHttps](INFO): SBD MOMSN=16961192
2022-07-11T17:48:42.897Z,1657561722.897 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T231006/Express0001.lzma
2022-07-11T17:48:43.899Z,1657561723.899 [DataOverHttps](INFO): Moved sent file to Logs/19241125T231006/Express0001.lzma.bak
2022-07-11T17:48:43.899Z,1657561723.899 [DataOverHttps](INFO): SBD MOMSN=16961194
2022-07-11T17:49:10.695Z,1657561750.695 [DataOverHttps](IMPORTANT): SBD MTMSN=20220711T174909
2022-07-11T17:49:18.137Z,1657561758.137 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T231353/Express0001.lzma
2022-07-11T17:49:18.139Z,1657561758.139 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.xml
2022-07-11T17:49:18.267Z,1657561758.267 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-07-11T17:49:18.268Z,1657561758.268 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-07-11T17:49:18.356Z,1657561758.356 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2022-07-11T17:49:18.358Z,1657561758.358 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2022-07-11T17:49:18.361Z,1657561758.361 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2022-07-11T17:49:18.364Z,1657561758.364 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2022-07-11T17:49:18.367Z,1657561758.367 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2022-07-11T17:49:18.370Z,1657561758.370 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2022-07-11T17:49:18.373Z,1657561758.373 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2022-07-11T17:49:18.376Z,1657561758.376 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2022-07-11T17:49:18.378Z,1657561758.378 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2022-07-11T17:49:18.381Z,1657561758.381 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2022-07-11T17:49:18.384Z,1657561758.384 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2022-07-11T17:49:18.388Z,1657561758.388 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2022-07-11T17:49:18.423Z,1657561758.423 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2022-07-11T17:49:18.426Z,1657561758.426 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2022-07-11T17:49:18.427Z,1657561758.427 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.xml
2022-07-11T17:49:18.933Z,1657561758.933 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2022-07-11T17:49:18.936Z,1657561758.936 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2022-07-11T17:49:18.939Z,1657561758.939 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2022-07-11T17:49:18.942Z,1657561758.942 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2022-07-11T17:49:18.944Z,1657561758.944 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2022-07-11T17:49:18.947Z,1657561758.947 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2022-07-11T17:49:18.950Z,1657561758.950 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2022-07-11T17:49:18.953Z,1657561758.953 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2022-07-11T17:49:18.956Z,1657561758.956 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2022-07-11T17:49:18.959Z,1657561758.959 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2022-07-11T17:49:18.962Z,1657561758.962 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2022-07-11T17:49:18.964Z,1657561758.964 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2022-07-11T17:49:18.967Z,1657561758.967 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2022-07-11T17:49:18.970Z,1657561758.970 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2022-07-11T17:49:18.972Z,1657561758.972 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2022-07-11T17:49:19.064Z,1657561759.064 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2022-07-11T17:49:19.072Z,1657561759.072 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2022-07-11T17:49:19.088Z,1657561759.088 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2022-07-11T17:49:19.106Z,1657561759.106 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2022-07-11T17:49:19.110Z,1657561759.110 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2022-07-11T17:49:19.126Z,1657561759.126 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 0 bool
2022-07-11T17:49:19.129Z,1657561759.129 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2022-07-11T17:49:19.136Z,1657561759.136 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2022-07-11T17:49:19.175Z,1657561759.175 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2022-07-11T17:49:19.182Z,1657561759.182 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2022-07-11T17:49:19.185Z,1657561759.185 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2022-07-11T17:49:19.212Z,1657561759.212 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = 0.000000 ug/l
2022-07-11T17:49:19.224Z,1657561759.224 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = 0.000000 m
2022-07-11T17:49:19.227Z,1657561759.227 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = 0.000000 degC
2022-07-11T17:49:19.261Z,1657561759.261 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2022-07-11T17:49:19.264Z,1657561759.264 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2022-07-11T17:49:19.292Z,1657561759.292 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = 0.000000 umol/l
2022-07-11T17:49:19.295Z,1657561759.295 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = 0.000000 m
2022-07-11T17:49:19.334Z,1657561759.334 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2022-07-11T17:49:19.337Z,1657561759.337 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2022-07-11T17:49:19.340Z,1657561759.340 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = 0.000000 kg/m3
2022-07-11T17:49:19.351Z,1657561759.351 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = 0.000000 m
2022-07-11T17:49:19.354Z,1657561759.354 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2022-07-11T17:49:19.381Z,1657561759.381 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2022-07-11T17:49:19.389Z,1657561759.389 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = 0.000000 ppb
2022-07-11T17:49:19.392Z,1657561759.392 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = 0.000000 m
2022-07-11T17:49:19.427Z,1657561759.427 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2022-07-11T17:49:19.430Z,1657561759.430 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2022-07-11T17:49:19.433Z,1657561759.433 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2022-07-11T17:49:19.468Z,1657561759.468 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2022-07-11T17:49:19.471Z,1657561759.471 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = 0.000000 psu
2022-07-11T17:49:19.511Z,1657561759.511 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = 0.000000 m
2022-07-11T17:49:19.522Z,1657561759.522 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = 0.000000 degC
2022-07-11T17:49:19.525Z,1657561759.525 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2022-07-11T17:49:19.528Z,1657561759.528 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2022-07-11T17:49:19.563Z,1657561759.563 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = 0.000000 ug/l
2022-07-11T17:49:19.566Z,1657561759.566 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = 0.000000 m
2022-07-11T17:49:19.585Z,1657561759.585 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2022-07-11T17:49:19.588Z,1657561759.588 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2022-07-11T17:49:19.591Z,1657561759.591 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2022-07-11T17:49:19.607Z,1657561759.607 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = 0.000000 psu
2022-07-11T17:49:19.610Z,1657561759.610 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = 0.000000 m
2022-07-11T17:49:19.613Z,1657561759.613 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2022-07-11T17:49:19.641Z,1657561759.641 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2022-07-11T17:49:19.645Z,1657561759.645 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2022-07-11T17:49:19.648Z,1657561759.648 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = 0.000000 psu
2022-07-11T17:49:19.670Z,1657561759.670 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = 0.000000 m
2022-07-11T17:49:19.674Z,1657561759.674 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2022-07-11T17:49:19.677Z,1657561759.677 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2022-07-11T17:49:19.704Z,1657561759.704 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2022-07-11T17:49:19.778Z,1657561759.778 [DataOverHttps](INFO): Moved sent file to Logs/19241125T231353/Express0001.lzma.bak
2022-07-11T17:49:19.778Z,1657561759.778 [DataOverHttps](INFO): SBD MOMSN=16961197
2022-07-11T17:49:19.796Z,1657561759.796 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-07-11T17:49:19.889Z,1657561759.889 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-07-11T17:49:19.913Z,1657561759.913 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-07-11T17:49:19.965Z,1657561759.965 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-07-11T17:49:20.019Z,1657561760.019 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-07-11T17:49:20.055Z,1657561760.055 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-07-11T17:49:20.094Z,1657561760.094 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2022-07-11T17:49:20.127Z,1657561760.127 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2022-07-11T17:49:20.240Z,1657561760.240 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.xml
2022-07-11T17:49:20.600Z,1657561760.600 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2022-07-11T17:49:20.603Z,1657561760.603 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2022-07-11T17:49:20.638Z,1657561760.638 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2022-07-11T17:49:20.642Z,1657561760.642 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2022-07-11T17:49:20.644Z,1657561760.644 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2022-07-11T17:49:20.680Z,1657561760.680 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2022-07-11T17:49:20.683Z,1657561760.683 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2022-07-11T17:49:20.714Z,1657561760.714 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2022-07-11T17:49:20.717Z,1657561760.717 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2022-07-11T17:49:20.720Z,1657561760.720 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2022-07-11T17:49:20.737Z,1657561760.737 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2022-07-11T17:49:20.764Z,1657561760.764 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2022-07-11T17:49:20.776Z,1657561760.776 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2022-07-11T17:49:20.784Z,1657561760.784 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2022-07-11T17:49:20.845Z,1657561760.845 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2022-07-11T17:49:20.864Z,1657561760.864 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2022-07-11T17:49:20.892Z,1657561760.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2022-07-11T17:49:20.938Z,1657561760.938 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2022-07-11T17:49:20.942Z,1657561760.942 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2022-07-11T17:49:20.970Z,1657561760.970 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2022-07-11T17:49:20.994Z,1657561760.994 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2022-07-11T17:49:20.998Z,1657561760.998 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2022-07-11T17:49:21.001Z,1657561761.001 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2022-07-11T17:49:21.049Z,1657561761.049 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2022-07-11T17:49:21.091Z,1657561761.091 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2022-07-11T17:49:21.164Z,1657561761.164 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2022-07-11T17:49:21.187Z,1657561761.187 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2022-07-11T17:49:21.189Z,1657561761.189 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2022-07-11T17:49:21.203Z,1657561761.203 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2022-07-11T17:49:21.205Z,1657561761.205 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2022-07-11T17:49:21.206Z,1657561761.206 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2022-07-11T17:49:21.208Z,1657561761.208 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2022-07-11T17:49:21.218Z,1657561761.218 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2022-07-11T17:49:21.267Z,1657561761.267 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2022-07-11T17:49:21.291Z,1657561761.291 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2022-07-11T17:49:21.402Z,1657561761.402 [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>


2022-07-11T17:49:21.406Z,1657561761.406 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.xml
2022-07-11T17:49:21.479Z,1657561761.479 [Default] Stopped
2022-07-11T17:49:21.479Z,1657561761.479 [Default](DEBUG): Aggregate::uninitialize Default
2022-07-11T17:49:21.479Z,1657561761.479 [Default:B.GoToSurface] Stopped
2022-07-11T17:49:21.479Z,1657561761.479 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-07-11T17:49:21.479Z,1657561761.479 [Default:CheckIn] Stopped
2022-07-11T17:49:21.479Z,1657561761.479 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-07-11T17:49:21.479Z,1657561761.479 [Default:CheckIn:Read_Iridium] Stopped
2022-07-11T17:49:21.479Z,1657561761.479 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:A] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:B] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:C] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:D] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:E] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:F] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2022-07-11T17:49:21.480Z,1657561761.480 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2022-07-11T17:49:21.481Z,1657561761.481 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2022-07-11T17:49:21.481Z,1657561761.481 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-07-11T17:49:21.491Z,1657561761.491 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2022-07-11T17:49:21.491Z,1657561761.491 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2022-07-11T17:49:21.491Z,1657561761.491 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-07-11T17:49:21.491Z,1657561761.491 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-07-11T17:49:21.492Z,1657561761.492 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2022-07-11T17:49:21.492Z,1657561761.492 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2022-07-11T17:49:21.492Z,1657561761.492 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2022-07-11T17:49:21.492Z,1657561761.492 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-07-11T17:49:21.510Z,1657561761.510 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2022-07-11T17:49:21.510Z,1657561761.510 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2022-07-11T17:49:21.510Z,1657561761.510 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2022-07-11T17:49:21.511Z,1657561761.511 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-07-11T17:49:21.512Z,1657561761.512 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2022-07-11T17:49:21.513Z,1657561761.513 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2022-07-11T17:49:21.513Z,1657561761.513 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-07-11T17:49:21.513Z,1657561761.513 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-07-11T17:49:21.521Z,1657561761.521 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2022-07-11T17:49:21.521Z,1657561761.521 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2022-07-11T17:49:21.522Z,1657561761.522 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2022-07-11T17:49:21.522Z,1657561761.522 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-07-11T17:49:21.524Z,1657561761.524 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2022-07-11T17:49:21.524Z,1657561761.524 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2022-07-11T17:49:21.524Z,1657561761.524 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2022-07-11T17:49:21.524Z,1657561761.524 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2022-07-11T17:49:21.542Z,1657561761.542 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2022-07-11T17:49:21.542Z,1657561761.542 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2022-07-11T17:49:21.542Z,1657561761.542 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2022-07-11T17:49:21.542Z,1657561761.542 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2022-07-11T17:49:21.543Z,1657561761.543 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-07-11T17:49:21.544Z,1657561761.544 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2022-07-11T17:49:21.545Z,1657561761.545 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2022-07-11T17:49:21.545Z,1657561761.545 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2022-07-11T17:49:21.545Z,1657561761.545 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-07-11T17:49:21.545Z,1657561761.545 [ballast_and_trim:Science] Running Loop=1
2022-07-11T17:49:21.554Z,1657561761.554 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2022-07-11T17:49:21.555Z,1657561761.555 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectOil] Stopped
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2022-07-11T17:49:21.556Z,1657561761.556 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-07-11T17:49:21.557Z,1657561761.557 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2022-07-11T17:49:21.557Z,1657561761.557 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2022-07-11T17:49:21.557Z,1657561761.557 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2022-07-11T17:49:21.557Z,1657561761.557 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2022-07-11T17:49:21.557Z,1657561761.557 [ballast_and_trim:Science:PeakDetectChl] Stopped
2022-07-11T17:49:21.557Z,1657561761.557 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2022-07-11T17:49:21.557Z,1657561761.557 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2022-07-11T17:49:21.573Z,1657561761.573 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2022-07-11T17:49:21.573Z,1657561761.573 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2022-07-11T17:49:21.574Z,1657561761.574 [ballast_and_trim:Science:Read_Oil] Stopped
2022-07-11T17:49:21.574Z,1657561761.574 [ballast_and_trim:Science:F] Stopped
2022-07-11T17:49:21.574Z,1657561761.574 [ballast_and_trim:Science:E] Running Loop=1
2022-07-11T17:49:21.575Z,1657561761.575 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2022-07-11T17:49:21.575Z,1657561761.575 [ballast_and_trim:Science:D] Stopped
2022-07-11T17:49:21.575Z,1657561761.575 [ballast_and_trim:Science:C] Running Loop=1
2022-07-11T17:49:21.575Z,1657561761.575 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2022-07-11T17:49:21.576Z,1657561761.576 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2022-07-11T17:49:21.576Z,1657561761.576 [ballast_and_trim:Science:B] Running Loop=1
2022-07-11T17:49:21.577Z,1657561761.577 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2022-07-11T17:49:21.582Z,1657561761.582 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2022-07-11T17:49:21.582Z,1657561761.582 [ballast_and_trim:Science:A] Stopped
2022-07-11T17:49:21.755Z,1657561761.755 [WetLabsBB2FL](INFO): Powering up
2022-07-11T17:49:21.889Z,1657561761.889 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2022-07-11T17:49:21.890Z,1657561761.890 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-07-11T17:49:21.890Z,1657561761.890 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-07-11T17:49:21.890Z,1657561761.890 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-07-11T17:49:21.890Z,1657561761.890 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-07-11T17:49:21.890Z,1657561761.890 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-07-11T17:49:21.890Z,1657561761.890 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-07-11T17:49:21.890Z,1657561761.890 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2022-07-11T17:49:21.892Z,1657561761.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2022-07-11T17:49:21.892Z,1657561761.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2022-07-11T17:49:21.892Z,1657561761.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2022-07-11T17:49:21.892Z,1657561761.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-07-11T17:49:21.892Z,1657561761.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-07-11T17:49:21.892Z,1657561761.892 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2022-07-11T17:49:21.893Z,1657561761.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-07-11T17:49:21.893Z,1657561761.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2022-07-11T17:49:21.893Z,1657561761.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2022-07-11T17:49:21.893Z,1657561761.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2022-07-11T17:49:21.893Z,1657561761.893 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2022-07-11T17:49:21.901Z,1657561761.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2022-07-11T17:49:21.901Z,1657561761.901 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2022-07-11T17:49:21.902Z,1657561761.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2022-07-11T17:49:21.902Z,1657561761.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-07-11T17:49:21.902Z,1657561761.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2022-07-11T17:49:21.902Z,1657561761.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2022-07-11T17:49:21.902Z,1657561761.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2022-07-11T17:49:21.902Z,1657561761.902 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2022-07-11T17:49:21.903Z,1657561761.903 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2022-07-11T17:49:21.903Z,1657561761.903 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2022-07-11T17:49:22.279Z,1657561762.279 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2022-07-11T17:49:22.279Z,1657561762.279 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2022-07-11T17:49:22.279Z,1657561762.279 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2022-07-11T17:49:22.279Z,1657561762.279 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2022-07-11T17:49:22.279Z,1657561762.279 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2022-07-11T17:49:22.280Z,1657561762.280 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2022-07-11T17:49:22.280Z,1657561762.280 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2022-07-11T17:49:22.280Z,1657561762.280 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2022-07-11T17:49:22.280Z,1657561762.280 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2022-07-11T17:49:22.280Z,1657561762.280 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2022-07-11T17:49:22.280Z,1657561762.280 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2022-07-11T17:49:22.683Z,1657561762.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2022-07-11T17:49:22.683Z,1657561762.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2022-07-11T17:49:22.683Z,1657561762.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2022-07-11T17:49:22.683Z,1657561762.683 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-07-11T17:49:22.684Z,1657561762.684 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2022-07-11T17:49:22.684Z,1657561762.684 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2022-07-11T17:49:22.684Z,1657561762.684 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2022-07-11T17:49:22.684Z,1657561762.684 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-07-11T17:49:22.684Z,1657561762.684 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-07-11T17:49:22.684Z,1657561762.684 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2022-07-11T17:49:22.684Z,1657561762.684 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2022-07-11T17:49:23.070Z,1657561763.070 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2022-07-11T17:49:23.071Z,1657561763.071 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2022-07-11T17:49:23.071Z,1657561763.071 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2022-07-11T17:49:23.071Z,1657561763.071 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2022-07-11T17:49:23.071Z,1657561763.071 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2022-07-11T17:49:25.259Z,1657561765.259 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2022-07-11T17:50:13.017Z,1657561813.017 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20220711T173632/Courier0007.lzma
2022-07-11T17:50:14.019Z,1657561814.019 [DataOverHttps](INFO): Moved sent file to Logs/20220711T173632/Courier0007.lzma.bak
2022-07-11T17:50:14.019Z,1657561814.019 [DataOverHttps](INFO): SBD MOMSN=16961200
2022-07-11T17:51:08.282Z,1657561868.282 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-07-11T17:51:14.306Z,1657561874.306 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.287460
2022-07-11T17:51:41.998Z,1657561901.998 [Radio_Surface](INFO): Powering down
2022-07-11T17:51:42.422Z,1657561902.422 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2022-07-11T18:06:45.212Z,1657562805.212 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2022-07-11T18:06:45.212Z,1657562805.212 [DropWeight] Hardware Fault, FailCount= 1
2022-07-11T18:06:45.213Z,1657562805.213 [DropWeight](ERROR): Hardware Fault
2022-07-11T18:06:45.278Z,1657562805.278 [CommandExec](FAULT): Scheduling is paused
2022-07-11T18:06:45.278Z,1657562805.278 [CBIT](INFO): Critical error at 20220711T180645
2022-07-11T18:06:45.278Z,1657562805.278 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2022-07-11T18:06:45.281Z,1657562805.281 [CBIT](ERROR): Hardware Fault in component: DropWeight
2022-07-11T18:06:45.285Z,1657562805.285 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2022-07-11T18:06:45.639Z,1657562805.639 [MissionManager](INFO): MissionManager is completed.
2022-07-11T18:06:45.639Z,1657562805.639 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2022-07-11T18:06:45.639Z,1657562805.639 [ballast_and_trim] Stopped
2022-07-11T18:06:45.639Z,1657562805.639 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2022-07-11T18:06:45.639Z,1657562805.639 [ballast_and_trim:Science] Stopped
2022-07-11T18:06:45.639Z,1657562805.639 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:Science:B] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:Science:C] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:Science:E] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:Science:OceanCurrent] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2022-07-11T18:06:45.640Z,1657562805.640 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2022-07-11T18:06:45.641Z,1657562805.641 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2022-07-11T18:06:45.642Z,1657562805.642 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2022-07-11T18:06:45.832Z,1657562805.832 [CBIT](INFO): Critical error at 20220711T180645
2022-07-11T18:06:46.039Z,1657562806.039 [MissionManager](IMPORTANT): Started mission Default
2022-07-11T18:06:46.039Z,1657562806.039 [Default] Running Loop=1
2022-07-11T18:06:46.039Z,1657562806.039 [Default](DEBUG): Aggregate::initialize Default
2022-07-11T18:06:46.039Z,1657562806.039 [Default:B.GoToSurface] Running Loop=1
2022-07-11T18:06:46.039Z,1657562806.039 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-07-11T18:06:46.040Z,1657562806.040 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-07-11T18:06:46.040Z,1657562806.040 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-07-11T18:06:46.040Z,1657562806.040 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-07-11T18:06:46.040Z,1657562806.040 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-07-11T18:06:46.041Z,1657562806.041 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-07-11T18:06:46.041Z,1657562806.041 [Default:A.Wait] Running Loop=1
2022-07-11T18:06:46.041Z,1657562806.041 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-07-11T18:06:46.190Z,1657562806.190 [WetLabsBB2FL](INFO): Powering down
2022-07-11T18:06:46.450Z,1657562806.450 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position -28.00 mm (1 active estimators).
2022-07-11T18:06:46.617Z,1657562806.617 [Radio_Surface](INFO): Powering up
2022-07-11T18:06:52.226Z,1657562812.226 [DataOverHttps](INFO): Radio surface powered ON.
2022-07-11T18:06:59.391Z,1657562819.391 [Default:A.Wait](INFO): Done Waiting.
2022-07-11T18:06:59.391Z,1657562819.391 [Default:A.Wait] Stopped
2022-07-11T18:06:59.391Z,1657562819.391 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-07-11T18:07:22.346Z,1657562842.346 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-07-11T18:07:42.599Z,1657562862.599 [Default:CheckIn] Running Loop=1
2022-07-11T18:07:42.599Z,1657562862.599 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-07-11T18:07:42.599Z,1657562862.599 [Default:CheckIn:Read_GPS] Running Loop=1
2022-07-11T18:07:57.510Z,1657562877.510 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-07-11T18:08:15.307Z,1657562895.307 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2022-07-11T18:08:15.381Z,1657562895.381 [NAL9602](ERROR): received: 
+CSQ:0

OK
2022-07-11T18:08:32.662Z,1657562912.662 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-07-11T18:09:07.818Z,1657562947.818 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-07-11T18:09:42.966Z,1657562982.966 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2022-07-11T18:09:55.342Z,1657562995.342 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003004
2022-07-11T18:12:42.851Z,1657563162.851 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-07-11T18:07:42.6Z
2022-07-11T18:12:42.851Z,1657563162.851 [Default:CheckIn:Read_GPS] Stopped
2022-07-11T18:12:42.852Z,1657563162.852 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-07-11T18:12:47.286Z,1657563167.286 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2022-07-11T18:13:11.780Z,1657563191.780 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20220711T173632/Courier0010.lzma
2022-07-11T18:13:12.779Z,1657563192.779 [DataOverHttps](INFO): Moved sent file to Logs/20220711T173632/Courier0010.lzma.bak
2022-07-11T18:13:12.779Z,1657563192.779 [DataOverHttps](INFO): SBD MOMSN=16961206
2022-07-11T18:13:17.990Z,1657563197.990 [NAL9602](INFO): Not Powering down - fast GPS
2022-07-11T18:13:32.309Z,1657563212.309 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T231720/Express0001.lzma
2022-07-11T18:13:33.311Z,1657563213.311 [DataOverHttps](INFO): Moved sent file to Logs/19241125T231720/Express0001.lzma.bak
2022-07-11T18:13:33.311Z,1657563213.311 [DataOverHttps](INFO): SBD MOMSN=16961210
2022-07-11T18:14:00.025Z,1657563240.025 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T232110/Express0001.lzma
2022-07-11T18:14:01.027Z,1657563241.027 [DataOverHttps](INFO): Moved sent file to Logs/19241125T232110/Express0001.lzma.bak
2022-07-11T18:14:01.027Z,1657563241.027 [DataOverHttps](INFO): SBD MOMSN=16961212
2022-07-11T18:14:42.017Z,1657563282.017 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T232433/Express0001.lzma
2022-07-11T18:14:43.019Z,1657563283.019 [DataOverHttps](INFO): Moved sent file to Logs/19241125T232433/Express0001.lzma.bak
2022-07-11T18:14:43.019Z,1657563283.019 [DataOverHttps](INFO): SBD MOMSN=16961214
2022-07-11T18:15:05.341Z,1657563305.341 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T232821/Express0001.lzma
2022-07-11T18:15:06.343Z,1657563306.343 [DataOverHttps](INFO): Moved sent file to Logs/19241125T232821/Express0001.lzma.bak
2022-07-11T18:15:06.343Z,1657563306.343 [DataOverHttps](INFO): SBD MOMSN=16961216
2022-07-11T18:15:34.041Z,1657563334.041 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T233148/Express0001.lzma
2022-07-11T18:15:35.043Z,1657563335.043 [DataOverHttps](INFO): Moved sent file to Logs/19241125T233148/Express0001.lzma.bak
2022-07-11T18:15:35.043Z,1657563335.043 [DataOverHttps](INFO): SBD MOMSN=16961218
2022-07-11T18:15:55.984Z,1657563355.984 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T233536/Express0001.lzma
2022-07-11T18:15:56.984Z,1657563356.984 [DataOverHttps](INFO): Moved sent file to Logs/19241125T233536/Express0001.lzma.bak
2022-07-11T18:15:56.984Z,1657563356.984 [DataOverHttps](INFO): SBD MOMSN=16961220
2022-07-11T18:16:32.809Z,1657563392.809 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T233903/Express0001.lzma
2022-07-11T18:16:33.811Z,1657563393.811 [DataOverHttps](INFO): Moved sent file to Logs/19241125T233903/Express0001.lzma.bak
2022-07-11T18:16:33.811Z,1657563393.811 [DataOverHttps](INFO): SBD MOMSN=16961222
2022-07-11T18:16:54.793Z,1657563414.793 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T234251/Express0001.lzma
2022-07-11T18:16:55.795Z,1657563415.795 [DataOverHttps](INFO): Moved sent file to Logs/19241125T234251/Express0001.lzma.bak
2022-07-11T18:16:55.795Z,1657563415.795 [DataOverHttps](INFO): SBD MOMSN=16961224
2022-07-11T18:17:21.081Z,1657563441.081 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T234618/Express0001.lzma
2022-07-11T18:17:22.083Z,1657563442.083 [DataOverHttps](INFO): Moved sent file to Logs/19241125T234618/Express0001.lzma.bak
2022-07-11T18:17:22.083Z,1657563442.083 [DataOverHttps](INFO): SBD MOMSN=16961226
2022-07-11T18:17:41.961Z,1657563461.961 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T235004/Express0001.lzma
2022-07-11T18:17:42.963Z,1657563462.963 [DataOverHttps](INFO): Moved sent file to Logs/19241125T235004/Express0001.lzma.bak
2022-07-11T18:17:42.963Z,1657563462.963 [DataOverHttps](INFO): SBD MOMSN=16961228
2022-07-11T18:18:11.965Z,1657563491.965 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T235330/Express0001.lzma
2022-07-11T18:18:12.967Z,1657563492.967 [DataOverHttps](INFO): Moved sent file to Logs/19241125T235330/Express0001.lzma.bak
2022-07-11T18:18:12.967Z,1657563492.967 [DataOverHttps](INFO): SBD MOMSN=16961230
2022-07-11T18:18:40.181Z,1657563520.181 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241125T235859/Express0001.lzma
2022-07-11T18:18:41.535Z,1657563521.535 [DataOverHttps](INFO): Moved sent file to Logs/19241125T235859/Express0001.lzma.bak
2022-07-11T18:18:41.535Z,1657563521.535 [DataOverHttps](INFO): SBD MOMSN=16961233
2022-07-11T18:19:13.433Z,1657563553.433 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T000045/Express0001.lzma
2022-07-11T18:19:14.435Z,1657563554.435 [DataOverHttps](INFO): Moved sent file to Logs/19241126T000045/Express0001.lzma.bak
2022-07-11T18:19:14.435Z,1657563554.435 [DataOverHttps](INFO): SBD MOMSN=16961235
2022-07-11T18:19:42.069Z,1657563582.069 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T000435/Express0001.lzma
2022-07-11T18:19:43.071Z,1657563583.071 [DataOverHttps](INFO): Moved sent file to Logs/19241126T000435/Express0001.lzma.bak
2022-07-11T18:19:43.071Z,1657563583.071 [DataOverHttps](INFO): SBD MOMSN=16961238
2022-07-11T18:20:05.169Z,1657563605.169 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T000645/Express0001.lzma
2022-07-11T18:20:06.172Z,1657563606.172 [DataOverHttps](INFO): Moved sent file to Logs/19241126T000645/Express0001.lzma.bak
2022-07-11T18:20:06.172Z,1657563606.172 [DataOverHttps](INFO): SBD MOMSN=16961240
2022-07-11T18:20:48.205Z,1657563648.205 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T001036/Express0001.lzma
2022-07-11T18:20:49.207Z,1657563649.207 [DataOverHttps](INFO): Moved sent file to Logs/19241126T001036/Express0001.lzma.bak
2022-07-11T18:20:49.207Z,1657563649.207 [DataOverHttps](INFO): SBD MOMSN=16961242
2022-07-11T18:21:14.477Z,1657563674.477 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T001401/Express0001.lzma
2022-07-11T18:21:15.479Z,1657563675.479 [DataOverHttps](INFO): Moved sent file to Logs/19241126T001401/Express0001.lzma.bak
2022-07-11T18:21:15.479Z,1657563675.479 [DataOverHttps](INFO): SBD MOMSN=16961244
2022-07-11T18:21:37.433Z,1657563697.433 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T001750/Express0001.lzma
2022-07-11T18:21:38.435Z,1657563698.435 [DataOverHttps](INFO): Moved sent file to Logs/19241126T001750/Express0001.lzma.bak
2022-07-11T18:21:38.435Z,1657563698.435 [DataOverHttps](INFO): SBD MOMSN=16961246
2022-07-11T18:21:45.253Z,1657563705.253 [CBIT](INFO): Clearing failed state for component DropWeight
2022-07-11T18:21:45.253Z,1657563705.253 [DropWeight] No Fault, FailCount= 1
2022-07-11T18:22:07.977Z,1657563727.977 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T002117/Express0001.lzma
2022-07-11T18:22:08.979Z,1657563728.979 [DataOverHttps](INFO): Moved sent file to Logs/19241126T002117/Express0001.lzma.bak
2022-07-11T18:22:08.979Z,1657563728.979 [DataOverHttps](INFO): SBD MOMSN=16961248
2022-07-11T18:22:35.873Z,1657563755.873 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T002507/Express0001.lzma
2022-07-11T18:22:36.877Z,1657563756.877 [DataOverHttps](INFO): Moved sent file to Logs/19241126T002507/Express0001.lzma.bak
2022-07-11T18:22:36.878Z,1657563756.878 [DataOverHttps](INFO): SBD MOMSN=16961250
2022-07-11T18:23:11.397Z,1657563791.397 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T002833/Express0001.lzma
2022-07-11T18:23:12.399Z,1657563792.399 [DataOverHttps](INFO): Moved sent file to Logs/19241126T002833/Express0001.lzma.bak
2022-07-11T18:23:12.399Z,1657563792.399 [DataOverHttps](INFO): SBD MOMSN=16961252
2022-07-11T18:23:33.125Z,1657563813.125 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T003220/Express0001.lzma
2022-07-11T18:23:34.128Z,1657563814.128 [DataOverHttps](INFO): Moved sent file to Logs/19241126T003220/Express0001.lzma.bak
2022-07-11T18:23:34.128Z,1657563814.128 [DataOverHttps](INFO): SBD MOMSN=16961254
2022-07-11T18:24:08.041Z,1657563848.041 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T003548/Express0001.lzma
2022-07-11T18:24:09.043Z,1657563849.043 [DataOverHttps](INFO): Moved sent file to Logs/19241126T003548/Express0001.lzma.bak
2022-07-11T18:24:09.043Z,1657563849.043 [DataOverHttps](INFO): SBD MOMSN=16961256
2022-07-11T18:24:52.521Z,1657563892.521 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T003938/Express0001.lzma
2022-07-11T18:24:53.523Z,1657563893.523 [DataOverHttps](INFO): Moved sent file to Logs/19241126T003938/Express0001.lzma.bak
2022-07-11T18:24:53.523Z,1657563893.523 [DataOverHttps](INFO): SBD MOMSN=16961258
2022-07-11T18:25:14.393Z,1657563914.393 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T004304/Express0001.lzma
2022-07-11T18:25:15.396Z,1657563915.396 [DataOverHttps](INFO): Moved sent file to Logs/19241126T004304/Express0001.lzma.bak
2022-07-11T18:25:15.396Z,1657563915.396 [DataOverHttps](INFO): SBD MOMSN=16961260
2022-07-11T18:25:35.893Z,1657563935.893 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T004653/Express0001.lzma
2022-07-11T18:25:36.895Z,1657563936.895 [DataOverHttps](INFO): Moved sent file to Logs/19241126T004653/Express0001.lzma.bak
2022-07-11T18:25:36.895Z,1657563936.895 [DataOverHttps](INFO): SBD MOMSN=16961262
2022-07-11T18:26:13.705Z,1657563973.705 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T004903/Express0001.lzma
2022-07-11T18:26:14.707Z,1657563974.707 [DataOverHttps](INFO): Moved sent file to Logs/19241126T004903/Express0001.lzma.bak
2022-07-11T18:26:14.707Z,1657563974.707 [DataOverHttps](INFO): SBD MOMSN=16961264
2022-07-11T18:26:57.137Z,1657564017.137 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T005249/Express0001.lzma
2022-07-11T18:26:58.139Z,1657564018.139 [DataOverHttps](INFO): Moved sent file to Logs/19241126T005249/Express0001.lzma.bak
2022-07-11T18:26:58.139Z,1657564018.139 [DataOverHttps](INFO): SBD MOMSN=16961266
2022-07-11T18:27:24.221Z,1657564044.221 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T005618/Express0001.lzma
2022-07-11T18:27:25.223Z,1657564045.223 [DataOverHttps](INFO): Moved sent file to Logs/19241126T005618/Express0001.lzma.bak
2022-07-11T18:27:25.224Z,1657564045.224 [DataOverHttps](INFO): SBD MOMSN=16961268
2022-07-11T18:27:46.665Z,1657564066.665 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T010005/Express0001.lzma
2022-07-11T18:27:47.685Z,1657564067.685 [DataOverHttps](INFO): Moved sent file to Logs/19241126T010005/Express0001.lzma.bak
2022-07-11T18:27:47.685Z,1657564067.685 [DataOverHttps](INFO): SBD MOMSN=16961271
2022-07-11T18:28:22.241Z,1657564102.241 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T010330/Express0001.lzma
2022-07-11T18:28:23.243Z,1657564103.243 [DataOverHttps](INFO): Moved sent file to Logs/19241126T010330/Express0001.lzma.bak
2022-07-11T18:28:23.243Z,1657564103.243 [DataOverHttps](INFO): SBD MOMSN=16961273
2022-07-11T18:28:46.913Z,1657564126.913 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T010718/Express0001.lzma
2022-07-11T18:28:47.915Z,1657564127.915 [DataOverHttps](INFO): Moved sent file to Logs/19241126T010718/Express0001.lzma.bak
2022-07-11T18:28:47.915Z,1657564127.915 [DataOverHttps](INFO): SBD MOMSN=16961276
2022-07-11T18:29:13.609Z,1657564153.609 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T011043/Express0001.lzma
2022-07-11T18:29:14.612Z,1657564154.612 [DataOverHttps](INFO): Moved sent file to Logs/19241126T011043/Express0001.lzma.bak
2022-07-11T18:29:14.612Z,1657564154.612 [DataOverHttps](INFO): SBD MOMSN=16961278
2022-07-11T18:29:35.577Z,1657564175.577 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T011432/Express0001.lzma
2022-07-11T18:29:36.580Z,1657564176.580 [DataOverHttps](INFO): Moved sent file to Logs/19241126T011432/Express0001.lzma.bak
2022-07-11T18:29:36.580Z,1657564176.580 [DataOverHttps](INFO): SBD MOMSN=16961280
2022-07-11T18:30:06.077Z,1657564206.077 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T011758/Express0001.lzma
2022-07-11T18:30:07.079Z,1657564207.079 [DataOverHttps](INFO): Moved sent file to Logs/19241126T011758/Express0001.lzma.bak
2022-07-11T18:30:07.079Z,1657564207.079 [DataOverHttps](INFO): SBD MOMSN=16961282
2022-07-11T18:30:34.273Z,1657564234.273 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T012149/Express0001.lzma
2022-07-11T18:30:35.271Z,1657564235.271 [DataOverHttps](INFO): Moved sent file to Logs/19241126T012149/Express0001.lzma.bak
2022-07-11T18:30:35.271Z,1657564235.271 [DataOverHttps](INFO): SBD MOMSN=16961284
2022-07-11T18:31:08.329Z,1657564268.329 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T012515/Express0001.lzma
2022-07-11T18:31:09.331Z,1657564269.331 [DataOverHttps](INFO): Moved sent file to Logs/19241126T012515/Express0001.lzma.bak
2022-07-11T18:31:09.331Z,1657564269.331 [DataOverHttps](INFO): SBD MOMSN=16961286
2022-07-11T18:31:31.585Z,1657564291.585 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T012904/Express0001.lzma
2022-07-11T18:31:32.587Z,1657564292.587 [DataOverHttps](INFO): Moved sent file to Logs/19241126T012904/Express0001.lzma.bak
2022-07-11T18:31:32.587Z,1657564292.587 [DataOverHttps](INFO): SBD MOMSN=16961288
2022-07-11T18:31:57.453Z,1657564317.453 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T013112/Express0001.lzma
2022-07-11T18:31:58.455Z,1657564318.455 [DataOverHttps](INFO): Moved sent file to Logs/19241126T013112/Express0001.lzma.bak
2022-07-11T18:31:58.455Z,1657564318.455 [DataOverHttps](INFO): SBD MOMSN=16961290
2022-07-11T18:32:33.829Z,1657564353.829 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T013458/Express0001.lzma
2022-07-11T18:32:34.831Z,1657564354.831 [DataOverHttps](INFO): Moved sent file to Logs/19241126T013458/Express0001.lzma.bak
2022-07-11T18:32:34.831Z,1657564354.831 [DataOverHttps](INFO): SBD MOMSN=16961292
2022-07-11T18:32:50.766Z,1657564370.766 [CommandExec](IMPORTANT): got command failComponent
2022-07-11T18:32:50.766Z,1657564370.766 [CommandExec](IMPORTANT): Failed components:
2022-07-11T18:32:50.766Z,1657564370.766 [CommandExec](IMPORTANT): No failed Components.
2022-07-11T18:32:56.053Z,1657564376.053 [DataOverHttps](INFO): Sending 18 bytes from file Logs/19241126T013824/Express0001.lzma
2022-07-11T18:32:57.055Z,1657564377.055 [DataOverHttps](INFO): Moved sent file to Logs/19241126T013824/Express0001.lzma.bak
2022-07-11T18:32:57.055Z,1657564377.055 [DataOverHttps](INFO): SBD MOMSN=16961294
2022-07-11T18:33:07.231Z,1657564387.231 [CommandExec](IMPORTANT): got command restart system
2022-07-11T18:33:09.742Z,1657564389.742 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:09.742Z,1657564389.742 [CommandExec](INFO): Uninitializing the command executive.
2022-07-11T18:33:09.742Z,1657564389.742 [CommandExec](INFO): Uninitializing the command scheduler.
2022-07-11T18:33:09.742Z,1657564389.742 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:09.793Z,1657564389.793 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-07-11T18:33:09.794Z,1657564389.794 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-07-11T18:33:09.794Z,1657564389.794 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:09.795Z,1657564389.795 [NavChartDb](INFO): Join timeout helper Thread ID is 6436
2022-07-11T18:33:09.969Z,1657564389.969 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:09.970Z,1657564389.970 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:09.981Z,1657564389.981 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2022-07-11T18:33:09.982Z,1657564389.982 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:09.982Z,1657564389.982 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6437
2022-07-11T18:33:10.294Z,1657564390.294 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:10.294Z,1657564390.294 [WetLabsBB2FL](INFO): Powering down
2022-07-11T18:33:10.295Z,1657564390.295 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:10.305Z,1657564390.305 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-07-11T18:33:10.306Z,1657564390.306 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:10.306Z,1657564390.306 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6438
2022-07-11T18:33:11.193Z,1657564391.193 [CTD_Seabird](INFO): Powering down
2022-07-11T18:33:11.207Z,1657564391.207 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:11.208Z,1657564391.208 [CTD_Seabird](INFO): Powering down
2022-07-11T18:33:11.222Z,1657564391.222 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:11.234Z,1657564391.234 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-07-11T18:33:11.234Z,1657564391.234 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:11.234Z,1657564391.234 [Radio_Surface](INFO): Join timeout helper Thread ID is 6439
2022-07-11T18:33:11.250Z,1657564391.250 [Radio_Surface](INFO): Powering down
2022-07-11T18:33:11.251Z,1657564391.251 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:11.251Z,1657564391.251 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:11.254Z,1657564391.254 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-07-11T18:33:11.254Z,1657564391.254 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:11.255Z,1657564391.255 [Onboard](INFO): Join timeout helper Thread ID is 6440
2022-07-11T18:33:15.810Z,1657564395.810 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:15.810Z,1657564395.810 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:15.818Z,1657564395.818 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-07-11T18:33:15.818Z,1657564395.818 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:15.819Z,1657564395.819 [DataOverHttps](INFO): Join timeout helper Thread ID is 6441
2022-07-11T18:33:16.282Z,1657564396.282 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:16.285Z,1657564396.285 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.298Z,1657564396.298 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-07-11T18:33:16.298Z,1657564396.298 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.299Z,1657564396.299 [BackseatComponent](INFO): Join timeout helper Thread ID is 6442
2022-07-11T18:33:16.362Z,1657564396.362 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:16.362Z,1657564396.362 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.378Z,1657564396.378 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-07-11T18:33:16.378Z,1657564396.378 [logger ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.379Z,1657564396.379 [logger](INFO): Join timeout helper Thread ID is 6443
2022-07-11T18:33:16.422Z,1657564396.422 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:16.423Z,1657564396.423 [logger ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.426Z,1657564396.426 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-07-11T18:33:16.426Z,1657564396.426 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.427Z,1657564396.427 [CommandLine](INFO): Join timeout helper Thread ID is 6444
2022-07-11T18:33:16.497Z,1657564396.497 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:16.498Z,1657564396.498 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.506Z,1657564396.506 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-07-11T18:33:16.506Z,1657564396.506 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.507Z,1657564396.507 [CommandExec](INFO): Join timeout helper Thread ID is 6445
2022-07-11T18:33:16.508Z,1657564396.508 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-07-11T18:33:16.508Z,1657564396.508 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.508Z,1657564396.508 [controlThread](INFO): Join timeout helper Thread ID is 6446
2022-07-11T18:33:16.569Z,1657564396.569 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-07-11T18:33:16.570Z,1657564396.570 [controlThread](DEBUG): Uninitializing ControlThread
2022-07-11T18:33:16.570Z,1657564396.570 [AHRS_M2](INFO): Powering down
2022-07-11T18:33:16.571Z,1657564396.571 [NAL9602](INFO): Powering down
2022-07-11T18:33:16.574Z,1657564396.574 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-07-11T18:33:16.574Z,1657564396.574 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-07-11T18:33:16.575Z,1657564396.575 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-07-11T18:33:16.575Z,1657564396.575 [MissionManager](INFO): Uninitializing Mission Default
2022-07-11T18:33:16.575Z,1657564396.575 [Default] Stopped
2022-07-11T18:33:16.576Z,1657564396.576 [Default](DEBUG): Aggregate::uninitialize Default
2022-07-11T18:33:16.576Z,1657564396.576 [Default:B.GoToSurface] Stopped
2022-07-11T18:33:16.576Z,1657564396.576 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-07-11T18:33:16.576Z,1657564396.576 [Default:CheckIn] Stopped
2022-07-11T18:33:16.576Z,1657564396.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-07-11T18:33:16.576Z,1657564396.576 [Default:CheckIn:Read_Iridium] Stopped
2022-07-11T18:33:16.579Z,1657564396.579 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-07-11T18:33:16.579Z,1657564396.579 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-07-11T18:33:16.579Z,1657564396.579 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-07-11T18:33:16.580Z,1657564396.580 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-07-11T18:33:16.580Z,1657564396.580 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-07-11T18:33:16.580Z,1657564396.580 [BuoyancyServo](INFO): Powering down
2022-07-11T18:33:16.593Z,1657564396.593 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-07-11T18:33:16.594Z,1657564396.594 [ElevatorServo](INFO): Powering down
2022-07-11T18:33:16.594Z,1657564396.594 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-07-11T18:33:16.595Z,1657564396.595 [MassServo](INFO): Powering down
2022-07-11T18:33:16.595Z,1657564396.595 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-07-11T18:33:16.595Z,1657564396.595 [RudderServo](INFO): Powering down
2022-07-11T18:33:16.596Z,1657564396.596 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-07-11T18:33:16.596Z,1657564396.596 [ThrusterHE](INFO): Powering down
2022-07-11T18:33:16.597Z,1657564396.597 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-07-11T18:33:16.598Z,1657564396.598 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-07-11T18:33:16.598Z,1657564396.598 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-07-11T18:33:16.598Z,1657564396.598 [CBIT](DEBUG): Powering off loads.
2022-07-11T18:33:16.609Z,1657564396.609 [CBIT](DEBUG): Disabling WDT.
2022-07-11T18:33:16.621Z,1657564396.621 [CBIT](DEBUG): Opening all GF detection circuits.
2022-07-11T18:33:16.622Z,1657564396.622 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.727Z,1657564396.727 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.731Z,1657564396.731 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.799Z,1657564396.799 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.819Z,1657564396.819 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:16.995Z,1657564396.995 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:17.000Z,1657564397.000 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:17.064Z,1657564397.064 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-07-11T18:33:17.253Z,1657564397.253 [logger ThreadHandler](INFO): Thread cancelled.