2025-07-25T16:03:34.110Z,1753459414.110 [Supervisor](DEBUG): Initializing supervisor.
2025-07-25T16:03:34.115Z,1753459414.115 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-07-25T16:03:34.115Z,1753459414.115 [SyncHandler](INFO): Protected caller Thread ID is 4186
2025-07-25T16:03:34.116Z,1753459414.116 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-07-25T16:03:34.117Z,1753459414.117 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-07-25T16:03:34.117Z,1753459414.117 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4187
2025-07-25T16:03:34.121Z,1753459414.121 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-07-25T16:03:34.141Z,1753459414.141 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-07-25T16:03:34.142Z,1753459414.142 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-07-25T16:03:34.142Z,1753459414.142 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4188
2025-07-25T16:03:34.149Z,1753459414.149 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-07-25T16:03:34.150Z,1753459414.150 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-07-25T16:03:34.151Z,1753459414.151 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4189
2025-07-25T16:03:34.153Z,1753459414.153 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-07-25T16:03:34.154Z,1753459414.154 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-07-25T16:03:34.155Z,1753459414.155 [logger ThreadHandler](INFO): Protected caller Thread ID is 4190
2025-07-25T16:03:34.159Z,1753459414.159 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-07-25T16:03:34.160Z,1753459414.160 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-07-25T16:03:34.192Z,1753459414.192 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-07-25T16:03:34.621Z,1753459414.621 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-07-25T16:03:34.623Z,1753459414.623 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-07-25T16:03:34.723Z,1753459414.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-07-25T16:03:34.724Z,1753459414.724 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-07-25T16:03:34.841Z,1753459414.841 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-07-25T16:03:34.843Z,1753459414.843 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-07-25T16:03:34.982Z,1753459414.982 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-07-25T16:03:34.983Z,1753459414.983 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-07-25T16:03:35.341Z,1753459415.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-07-25T16:03:35.343Z,1753459415.343 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-07-25T16:03:35.448Z,1753459415.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-07-25T16:03:35.449Z,1753459415.449 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-07-25T16:03:35.854Z,1753459415.854 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-07-25T16:03:35.855Z,1753459415.855 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-07-25T16:03:36.091Z,1753459416.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-07-25T16:03:36.093Z,1753459416.093 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-07-25T16:03:36.181Z,1753459416.181 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-07-25T16:03:36.433Z,1753459416.433 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-07-25T16:03:36.435Z,1753459416.435 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-07-25T16:03:36.665Z,1753459416.665 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-07-25T16:03:36.667Z,1753459416.667 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-07-25T16:03:37.210Z,1753459417.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-07-25T16:03:37.211Z,1753459417.211 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-07-25T16:03:37.404Z,1753459417.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-07-25T16:03:37.405Z,1753459417.405 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-07-25T16:03:37.698Z,1753459417.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-07-25T16:03:37.698Z,1753459417.698 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-07-25T16:03:38.544Z,1753459418.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-07-25T16:03:38.545Z,1753459418.545 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-07-25T16:03:39.131Z,1753459419.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-07-25T16:03:39.134Z,1753459419.134 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/
2025-07-25T16:03:39.201Z,1753459419.201 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg
2025-07-25T16:03:39.321Z,1753459419.321 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg
2025-07-25T16:03:39.462Z,1753459419.462 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg
2025-07-25T16:03:39.554Z,1753459419.554 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg
2025-07-25T16:03:39.671Z,1753459419.671 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg
2025-07-25T16:03:39.772Z,1753459419.772 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg
2025-07-25T16:03:40.046Z,1753459420.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-07-25T16:03:40.048Z,1753459420.048 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg
2025-07-25T16:03:40.167Z,1753459420.167 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg
2025-07-25T16:03:40.274Z,1753459420.274 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg
2025-07-25T16:03:40.420Z,1753459420.420 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg
2025-07-25T16:03:40.515Z,1753459420.515 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-07-25T16:03:40.527Z,1753459420.527 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-07-25T16:03:40.690Z,1753459420.690 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-07-25T16:03:40.691Z,1753459420.691 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-07-25T16:03:40.756Z,1753459420.756 [VerticalControl](DEBUG): Construct VerticalControl.
2025-07-25T16:03:40.819Z,1753459420.819 [VerticalControl] Loaded
2025-07-25T16:03:40.819Z,1753459420.819 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-07-25T16:03:40.822Z,1753459420.822 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-07-25T16:03:40.870Z,1753459420.870 [HorizontalControl] Loaded
2025-07-25T16:03:40.870Z,1753459420.870 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-07-25T16:03:40.873Z,1753459420.873 [SpeedControl](DEBUG): Construct SpeedControl.
2025-07-25T16:03:40.876Z,1753459420.876 [SpeedControl] Loaded
2025-07-25T16:03:40.876Z,1753459420.876 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-07-25T16:03:40.879Z,1753459420.879 [LoopControl](DEBUG): Construct LoopControl.
2025-07-25T16:03:40.879Z,1753459420.879 [LoopControl] Loaded
2025-07-25T16:03:40.879Z,1753459420.879 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-07-25T16:03:40.880Z,1753459420.880 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-07-25T16:03:40.880Z,1753459420.880 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-07-25T16:03:40.962Z,1753459420.962 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-07-25T16:03:40.962Z,1753459420.962 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-07-25T16:03:41.615Z,1753459421.615 [AHRS_M2] Loaded
2025-07-25T16:03:41.615Z,1753459421.615 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-07-25T16:03:41.655Z,1753459421.655 [BackseatComponent] Loaded
2025-07-25T16:03:41.655Z,1753459421.655 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-07-25T16:03:41.656Z,1753459421.656 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BA4E0
2025-07-25T16:03:41.656Z,1753459421.656 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4269
2025-07-25T16:03:41.659Z,1753459421.659 [LcmUniversalReporter] Loaded
2025-07-25T16:03:41.660Z,1753459421.660 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-07-25T16:03:42.497Z,1753459422.497 [BPC1] Loaded
2025-07-25T16:03:42.497Z,1753459422.497 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-07-25T16:03:42.596Z,1753459422.596 [DAT] Loaded
2025-07-25T16:03:42.596Z,1753459422.596 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-07-25T16:03:42.597Z,1753459422.597 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408EA4E0
2025-07-25T16:03:42.597Z,1753459422.597 [DAT ThreadHandler](INFO): Protected caller Thread ID is 4270
2025-07-25T16:03:42.677Z,1753459422.677 [DataOverHttps] Loaded
2025-07-25T16:03:42.677Z,1753459422.677 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-07-25T16:03:42.678Z,1753459422.678 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091A4E0
2025-07-25T16:03:42.678Z,1753459422.678 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4271
2025-07-25T16:03:42.702Z,1753459422.702 [Depth_Keller] Loaded
2025-07-25T16:03:42.702Z,1753459422.702 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-07-25T16:03:42.707Z,1753459422.707 [DropWeight] Loaded
2025-07-25T16:03:42.708Z,1753459422.708 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-07-25T16:03:42.773Z,1753459422.773 [NAL9602] Loaded
2025-07-25T16:03:42.773Z,1753459422.773 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-07-25T16:03:42.804Z,1753459422.804 [Onboard] Loaded
2025-07-25T16:03:42.804Z,1753459422.804 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-07-25T16:03:42.805Z,1753459422.805 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094A4E0
2025-07-25T16:03:42.806Z,1753459422.806 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4272
2025-07-25T16:03:42.820Z,1753459422.820 [Power24vConverter] Loaded
2025-07-25T16:03:42.820Z,1753459422.820 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-07-25T16:03:42.836Z,1753459422.836 [Radio_Surface] Loaded
2025-07-25T16:03:42.837Z,1753459422.837 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-07-25T16:03:42.838Z,1753459422.838 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097A4E0
2025-07-25T16:03:42.838Z,1753459422.838 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4273
2025-07-25T16:03:42.854Z,1753459422.854 [Sonardyne_Nano] Loaded
2025-07-25T16:03:42.854Z,1753459422.854 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-07-25T16:03:42.855Z,1753459422.855 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-07-25T16:03:42.855Z,1753459422.855 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-07-25T16:03:42.869Z,1753459422.869 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-07-25T16:03:42.869Z,1753459422.869 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-07-25T16:03:42.912Z,1753459422.912 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-07-25T16:03:42.912Z,1753459422.912 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-07-25T16:03:43.103Z,1753459423.103 [SBIT](DEBUG): Construct Startup Built In Test.
2025-07-25T16:03:43.112Z,1753459423.112 [SBIT] Loaded
2025-07-25T16:03:43.112Z,1753459423.112 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-07-25T16:03:43.115Z,1753459423.115 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-07-25T16:03:43.128Z,1753459423.128 [IBIT] Loaded
2025-07-25T16:03:43.128Z,1753459423.128 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-07-25T16:03:43.134Z,1753459423.134 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-07-25T16:03:43.215Z,1753459423.215 [CBIT] Loaded
2025-07-25T16:03:43.215Z,1753459423.215 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-07-25T16:03:43.249Z,1753459423.249 [GFScanner] Loaded
2025-07-25T16:03:43.249Z,1753459423.249 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-07-25T16:03:43.249Z,1753459423.249 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-07-25T16:03:43.250Z,1753459423.250 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-07-25T16:03:43.650Z,1753459423.650 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-07-25T16:03:43.651Z,1753459423.651 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-07-25T16:03:43.718Z,1753459423.718 [DepthRateCalculator] Loaded
2025-07-25T16:03:43.719Z,1753459423.719 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-07-25T16:03:43.724Z,1753459423.724 [PitchRateCalculator] Loaded
2025-07-25T16:03:43.724Z,1753459423.724 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-07-25T16:03:43.734Z,1753459423.734 [SpeedCalculator] Loaded
2025-07-25T16:03:43.735Z,1753459423.735 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-07-25T16:03:43.739Z,1753459423.739 [YawRateCalculator] Loaded
2025-07-25T16:03:43.739Z,1753459423.739 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-07-25T16:03:43.759Z,1753459423.759 [ElevatorOffsetCalculator] Loaded
2025-07-25T16:03:43.759Z,1753459423.759 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-07-25T16:03:43.760Z,1753459423.760 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-07-25T16:03:43.760Z,1753459423.760 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-07-25T16:03:43.969Z,1753459423.969 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-07-25T16:03:43.969Z,1753459423.969 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-07-25T16:03:44.103Z,1753459424.103 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-07-25T16:03:44.103Z,1753459424.103 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-07-25T16:03:44.118Z,1753459424.118 [NavChart] Loaded
2025-07-25T16:03:44.118Z,1753459424.118 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-07-25T16:03:44.124Z,1753459424.124 [UniversalFixResidualReporter] Loaded
2025-07-25T16:03:44.124Z,1753459424.124 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-07-25T16:03:44.125Z,1753459424.125 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-07-25T16:03:44.125Z,1753459424.125 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-07-25T16:03:44.310Z,1753459424.309 [BuoyancyServo] Loaded
2025-07-25T16:03:44.310Z,1753459424.310 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-07-25T16:03:44.334Z,1753459424.334 [ElevatorServo] Loaded
2025-07-25T16:03:44.334Z,1753459424.334 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-07-25T16:03:44.356Z,1753459424.356 [MassServo] Loaded
2025-07-25T16:03:44.356Z,1753459424.356 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-07-25T16:03:44.377Z,1753459424.377 [RudderServo] Loaded
2025-07-25T16:03:44.378Z,1753459424.378 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-07-25T16:03:44.395Z,1753459424.395 [ThrusterHE] Loaded
2025-07-25T16:03:44.395Z,1753459424.395 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-07-25T16:03:44.396Z,1753459424.396 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-07-25T16:03:44.396Z,1753459424.396 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-07-25T16:03:44.611Z,1753459424.611 [CTD_Seabird] Loaded
2025-07-25T16:03:44.612Z,1753459424.612 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-07-25T16:03:44.613Z,1753459424.613 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C094E0
2025-07-25T16:03:44.613Z,1753459424.613 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4274
2025-07-25T16:03:44.650Z,1753459424.650 [ESPComponent] Loaded
2025-07-25T16:03:44.651Z,1753459424.651 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-07-25T16:03:44.673Z,1753459424.673 [PAR_Licor] Loaded
2025-07-25T16:03:44.674Z,1753459424.674 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-07-25T16:03:44.719Z,1753459424.719 [WetLabsBB2FL] Loaded
2025-07-25T16:03:44.720Z,1753459424.720 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-07-25T16:03:44.721Z,1753459424.721 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C394E0
2025-07-25T16:03:44.721Z,1753459424.721 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4275
2025-07-25T16:03:44.722Z,1753459424.722 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-07-25T16:03:44.728Z,1753459424.728 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-07-25T16:03:44.731Z,1753459424.731 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-07-25T16:03:44.743Z,1753459424.743 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-07-25T16:03:44.744Z,1753459424.744 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C694E0
2025-07-25T16:03:44.744Z,1753459424.744 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4276
2025-07-25T16:03:44.749Z,1753459424.749 [Supervisor](INFO): Main Thread ID is 827
2025-07-25T16:03:44.749Z,1753459424.749 [Supervisor](DEBUG): Running supervisor.
2025-07-25T16:03:44.749Z,1753459424.749 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4277
2025-07-25T16:03:44.750Z,1753459424.750 [CommandExec](INFO): Initializing the command executive.
2025-07-25T16:03:44.751Z,1753459424.751 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4278
2025-07-25T16:03:44.754Z,1753459424.754 [controlThread ThreadHandler](INFO): Handler Thread ID is 4279
2025-07-25T16:03:44.754Z,1753459424.754 [controlThread](DEBUG): Initializing ControlThread
2025-07-25T16:03:44.755Z,1753459424.755 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-07-25T16:03:44.756Z,1753459424.756 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-07-25T16:03:44.757Z,1753459424.757 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-07-25T16:03:44.758Z,1753459424.758 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-07-25T16:03:44.761Z,1753459424.761 [SBIT](INFO): Initialize SBIT Component.
2025-07-25T16:03:44.761Z,1753459424.761 [SBIT](IMPORTANT): git: 2025-07-17-7-g184199333
2025-07-25T16:03:44.761Z,1753459424.761 [SBIT](INFO): git hash: 1841993335de4f098fcec04cd714926e036c3b35
2025-07-25T16:03:44.762Z,1753459424.762 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-07-25T16:03:44.763Z,1753459424.763 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #1 PREEMPT Tue Nov 28 15:04:22 PST 2023
2025-07-25T16:03:44.764Z,1753459424.764 [SBIT](INFO): Beginning SBIT in 117.000000 seconds.
2025-07-25T16:03:44.764Z,1753459424.764 [IBIT](INFO): Initialize IBIT Component.
2025-07-25T16:03:44.765Z,1753459424.765 [CBIT](DEBUG): Initialize CBIT Component.
2025-07-25T16:03:44.766Z,1753459424.766 [logger ThreadHandler](INFO): Handler Thread ID is 4280
2025-07-25T16:03:44.777Z,1753459424.777 [CBIT](DEBUG): Initialized mux pins.
2025-07-25T16:03:44.777Z,1753459424.777 [CBIT](DEBUG): Initializing the watchdog timer.
2025-07-25T16:03:44.786Z,1753459424.786 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4281
2025-07-25T16:03:44.801Z,1753459424.801 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-07-25T16:03:44.801Z,1753459424.801 [CBIT](DEBUG): Initializing heartbeat.
2025-07-25T16:03:44.802Z,1753459424.802 [DAT ThreadHandler](INFO): Handler Thread ID is 4282
2025-07-25T16:03:44.803Z,1753459424.803 [DAT](INFO): Powering up
2025-07-25T16:03:44.803Z,1753459424.803 [DAT](DEBUG): Initializing DAT.
2025-07-25T16:03:44.806Z,1753459424.806 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4284
2025-07-25T16:03:44.808Z,1753459424.808 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-07-25T16:03:44.829Z,1753459424.829 [Onboard ThreadHandler](INFO): Handler Thread ID is 4285
2025-07-25T16:03:44.847Z,1753459424.847 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4286
2025-07-25T16:03:44.865Z,1753459424.865 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4287
2025-07-25T16:03:44.866Z,1753459424.866 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-07-25T16:03:44.870Z,1753459424.870 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4289
2025-07-25T16:03:44.873Z,1753459424.873 [CBIT](DEBUG): Deactivating emergency mode.
2025-07-25T16:03:44.874Z,1753459424.874 [WetLabsBB2FL](INFO): Powering up
2025-07-25T16:03:44.875Z,1753459424.875 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4291
2025-07-25T16:03:44.881Z,1753459424.881 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-07-25T16:03:44.882Z,1753459424.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-07-25T16:03:44.882Z,1753459424.882 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-07-25T16:03:44.882Z,1753459424.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-07-25T16:03:44.882Z,1753459424.882 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-07-25T16:03:44.882Z,1753459424.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-07-25T16:03:44.882Z,1753459424.882 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-07-25T16:03:44.883Z,1753459424.883 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-07-25T16:03:44.913Z,1753459424.913 [CBIT](DEBUG): Backplane powered.
2025-07-25T16:03:44.913Z,1753459424.913 [GFScanner](DEBUG): Initializing GFScanner
2025-07-25T16:03:44.913Z,1753459424.913 [GFScanner](DEBUG): Deactivating GF circuits.
2025-07-25T16:03:44.918Z,1753459424.918 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-07-25T16:03:44.918Z,1753459424.918 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-07-25T16:03:44.918Z,1753459424.918 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-07-25T16:03:44.919Z,1753459424.919 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-07-25T16:03:44.919Z,1753459424.919 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-07-25T16:03:44.920Z,1753459424.920 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-07-25T16:03:44.921Z,1753459424.921 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-07-25T16:03:44.926Z,1753459424.926 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-07-25T16:03:44.926Z,1753459424.926 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-07-25T16:03:44.927Z,1753459424.927 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-07-25T16:03:44.930Z,1753459424.930 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-07-25T16:03:45.008Z,1753459425.008 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-07-25T16:03:45.012Z,1753459425.012 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-07-25T16:03:45.052Z,1753459425.052 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-07-25T16:03:45.058Z,1753459425.058 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-07-25T16:03:45.059Z,1753459425.059 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-07-25T16:03:45.062Z,1753459425.062 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-07-25T16:03:45.253Z,1753459425.253 [Radio_Surface](INFO): Powering up
2025-07-25T16:03:45.368Z,1753459425.368 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-07-25T16:03:45.390Z,1753459425.390 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-07-25T16:03:45.391Z,1753459425.391 [Default:A.Wait](DEBUG): Construct Wait.
2025-07-25T16:03:45.410Z,1753459425.410 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-07-25T16:03:45.438Z,1753459425.438 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-07-25T16:03:45.441Z,1753459425.441 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-07-25T16:03:45.467Z,1753459425.467 [Default:E.Execute](DEBUG): Construct Execute.
2025-07-25T16:03:45.486Z,1753459425.486 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-07-25T16:03:45.491Z,1753459425.491 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-07-25T16:03:45.518Z,1753459425.518 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-07-25T16:03:45.573Z,1753459425.573 [Depth_Keller](INFO): Initializing.
2025-07-25T16:03:45.575Z,1753459425.575 [Power24vConverter](INFO): Powering up.
2025-07-25T16:03:45.575Z,1753459425.575 [Sonardyne_Nano](INFO): Initializing.
2025-07-25T16:03:45.621Z,1753459425.621 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-07-25T16:03:45.648Z,1753459425.648 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-07-25T16:03:45.653Z,1753459425.653 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-07-25T16:03:45.654Z,1753459425.654 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-07-25T16:03:45.661Z,1753459425.661 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-07-25T16:03:45.662Z,1753459425.662 [MassServo](DEBUG): Initializing EZServoServo.
2025-07-25T16:03:45.669Z,1753459425.669 [MassServo](DEBUG): Initializing MassServo.
2025-07-25T16:03:45.670Z,1753459425.670 [RudderServo](DEBUG): Initializing EZServoServo.
2025-07-25T16:03:45.677Z,1753459425.677 [RudderServo](DEBUG): Initializing RudderServo.
2025-07-25T16:03:45.678Z,1753459425.678 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-07-25T16:03:45.686Z,1753459425.686 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-07-25T16:03:46.981Z,1753459426.981 [WetLabsBB2FL](INFO): Powering down
2025-07-25T16:03:47.519Z,1753459427.519 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-07-25T16:03:48.805Z,1753459428.805 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311
2025-07-25T16:03:51.406Z,1753459431.406 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-07-25T16:03:57.150Z,1753459437.150 [DAT](INFO): DAT read:
2025-07-25T16:03:57.151Z,1753459437.151 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-07-25T16:03:58.914Z,1753459438.914 [DAT](INFO): DAT read: MF Frequency Band
2025-07-25T16:03:58.915Z,1753459438.915 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-07-25T16:03:58.916Z,1753459438.916 [DAT](INFO): DAT read: Jul 25 2025 16:03:57
2025-07-25T16:03:59.922Z,1753459439.922 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-07-25T16:03:59.923Z,1753459439.923 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-07-25T16:03:59.924Z,1753459439.924 [DAT](INFO): commRate: 800
2025-07-25T16:04:01.989Z,1753459441.989 [DAT](INFO): entering command mode
2025-07-25T16:04:02.190Z,1753459442.190 [DAT](INFO): DAT read:
2025-07-25T16:04:02.190Z,1753459442.190 [DAT](INFO): DAT read: user:1>
2025-07-25T16:04:02.191Z,1753459442.191 [DAT](INFO): setting verbose to 3
2025-07-25T16:04:02.442Z,1753459442.442 [DAT](INFO): DAT read: user:1>
2025-07-25T16:04:02.443Z,1753459442.443 [DAT](INFO): DAT read: Verbose | 3
2025-07-25T16:04:02.443Z,1753459442.443 [DAT](INFO): set verbose to 3
2025-07-25T16:04:02.443Z,1753459442.443 [DAT](INFO): setting DatVerbose to 27440
2025-07-25T16:04:02.694Z,1753459442.694 [DAT](INFO): DAT read: user:2>
2025-07-25T16:04:02.695Z,1753459442.695 [DAT](INFO): DAT read: DatVerbose | 27440
2025-07-25T16:04:02.695Z,1753459442.695 [DAT](INFO): set DatVerbose to 27440
2025-07-25T16:04:02.695Z,1753459442.695 [DAT](INFO): setting transmit power to 8
2025-07-25T16:04:02.946Z,1753459442.946 [DAT](INFO): DAT read: user:3>
2025-07-25T16:04:02.947Z,1753459442.947 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-07-25T16:04:02.947Z,1753459442.947 [DAT](INFO): set transmit power to 8
2025-07-25T16:04:02.947Z,1753459442.947 [DAT](INFO): setting local address to 1
2025-07-25T16:04:03.198Z,1753459443.198 [DAT](INFO): DAT read: user:4>
2025-07-25T16:04:03.199Z,1753459443.199 [DAT](INFO): DAT read: LocalAddr | 1
2025-07-25T16:04:03.199Z,1753459443.199 [DAT](INFO): set local address to 1
2025-07-25T16:04:03.200Z,1753459443.200 [DAT](INFO): Setting time to: 16:4:3 And date to:7/25/2025
2025-07-25T16:04:03.450Z,1753459443.450 [DAT](INFO): DAT read: user:5>
2025-07-25T16:04:03.451Z,1753459443.451 [DAT](INFO): DAT read: Fri Jul 25, 2025 16:04:03
2025-07-25T16:04:03.451Z,1753459443.451 [DAT](INFO): Local DAT time set to Fri Jul 25, 2025 16:04:03
2025-07-25T16:04:12.983Z,1753459452.983 [NAL9602](INFO): Powering up NAL9602
2025-07-25T16:04:23.887Z,1753459463.887 [NAL9602](INFO): NAL9602 initialized
2025-07-25T16:04:48.536Z,1753459488.536 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-07-25T16:04:55.808Z,1753459495.808 [NAL9602](INFO): SBD MO Status=0, MOMSN=26281, MT Status=0, MTMSN=0
2025-07-25T16:04:55.808Z,1753459495.808 [NAL9602](INFO): No messages in MT queue
2025-07-25T16:04:57.021Z,1753459497.021 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160500.00,A,3647.44082,N,12150.57123,W,1.497,135.50,250725,,,A*79
2025-07-25T16:04:57.024Z,1753459497.024 [NAL9602](INFO): GPS fix at 20250725T160500: (36.790680, -121.842854)
2025-07-25T16:05:29.366Z,1753459529.366 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T16:05:42.289Z,1753459542.289 [SBIT](IMPORTANT): Beginning Startup BIT
2025-07-25T16:05:42.294Z,1753459542.294 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-07-25T16:05:46.817Z,1753459546.817 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.005254
CHAN A1 (24V): 0.011168
CHAN A2 (12V): 0.005092
CHAN A3 (5V): -0.000380
CHAN B0 (3.3V): 0.000955
CHAN B1 (3.15aV): 0.000352
CHAN B2 (3.15bV): -0.000011
CHAN B3 (GND): -0.002237
OPEN: 0.006521
Full Scale: +/- 1 mA
2025-07-25T16:06:11.816Z,1753459571.816 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-07-25T16:06:17.843Z,1753459577.843 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-07-25T16:06:36.034Z,1753459596.034 [SBIT](IMPORTANT): SBIT PASSED
2025-07-25T16:06:36.035Z,1753459596.035 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-07-25T16:06:36.035Z,1753459596.035 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=15 count;
2025-07-25T16:06:36.035Z,1753459596.035 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): Express mostRecent _.planktivore_HM_AvgRois;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): Express mostRecent _.planktivore_LM_AvgRois;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=-0.5 ampere_hour;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=10 volt;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=203.823169 cubic_centimeter;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): VerticalControl.massDefault=24.289926 millimeter;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool;
2025-07-25T16:06:36.036Z,1753459596.036 [SBIT](IMPORTANT): Waypoint.wptRecalcBearing=1 bool;
2025-07-25T16:06:36.440Z,1753459596.440 [MissionManager](IMPORTANT): Started mission Startup
2025-07-25T16:06:36.441Z,1753459596.441 [Startup] Running Loop=1
2025-07-25T16:06:36.441Z,1753459596.441 [Startup](DEBUG): Aggregate::initialize Startup
2025-07-25T16:06:36.441Z,1753459596.441 [Startup:A.GoToSurface] Running Loop=1
2025-07-25T16:06:36.441Z,1753459596.441 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T16:06:36.442Z,1753459596.442 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-07-25T16:06:36.442Z,1753459596.442 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-07-25T16:06:36.442Z,1753459596.442 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-07-25T16:06:36.443Z,1753459596.443 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-07-25T16:06:36.443Z,1753459596.443 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T16:06:36.443Z,1753459596.443 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T16:06:36.445Z,1753459596.445 [Startup:StartupSatComms] Running Loop=1
2025-07-25T16:06:36.445Z,1753459596.445 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-07-25T16:06:36.446Z,1753459596.446 [Startup:StartupSatComms:A] Running Loop=1
2025-07-25T16:06:36.854Z,1753459596.854 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-07-25T16:06:38.444Z,1753459598.444 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-07-25T16:06:38.476Z,1753459598.476 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160641.00,A,3647.42488,N,12150.56560,W,0.330,156.47,250725,,,D*78
2025-07-25T16:06:38.486Z,1753459598.486 [NAL9602](INFO): GPS fix at 20250725T160641: (36.790415, -121.842760)
2025-07-25T16:06:38.526Z,1753459598.526 [Startup:StartupSatComms:A] Stopped
2025-07-25T16:06:38.526Z,1753459598.526 [Startup:StartupSatComms:B] Running Loop=1
2025-07-25T16:06:38.895Z,1753459598.895 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-07-25T16:07:11.284Z,1753459631.284 [NAL9602](INFO): SBD MO Status=2, MOMSN=26282, MT Status=2, MTMSN=0
2025-07-25T16:07:11.284Z,1753459631.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T16:07:25.405Z,1753459645.405 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:07:38.780Z,1753459658.780 [Startup:StartupSatComms:B](INFO): Timed out from 2025-07-25T16:06:38.5Z
2025-07-25T16:07:38.780Z,1753459658.780 [Startup:StartupSatComms:B] Stopped
2025-07-25T16:07:38.780Z,1753459658.780 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-07-25T16:07:38.780Z,1753459658.780 [Startup:StartupSatComms] Stopped
2025-07-25T16:07:38.780Z,1753459658.780 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-07-25T16:07:38.782Z,1753459658.782 [Startup](INFO): Completed Startup
2025-07-25T16:07:38.782Z,1753459658.782 [MissionManager](INFO): Startup is completed.
2025-07-25T16:07:38.782Z,1753459658.782 [MissionManager](INFO): Uninitializing Mission Startup
2025-07-25T16:07:38.782Z,1753459658.782 [Startup] Stopped
2025-07-25T16:07:38.782Z,1753459658.782 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-07-25T16:07:38.782Z,1753459658.782 [Startup:A.GoToSurface] Stopped
2025-07-25T16:07:38.782Z,1753459658.782 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T16:07:39.192Z,1753459659.192 [MissionManager](IMPORTANT): Started mission Default
2025-07-25T16:07:39.192Z,1753459659.192 [Default] Running Loop=1
2025-07-25T16:07:39.192Z,1753459659.192 [Default](DEBUG): Aggregate::initialize Default
2025-07-25T16:07:39.192Z,1753459659.192 [Default:B.GoToSurface] Running Loop=1
2025-07-25T16:07:39.192Z,1753459659.192 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T16:07:39.193Z,1753459659.193 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-07-25T16:07:39.193Z,1753459659.193 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-07-25T16:07:39.193Z,1753459659.193 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-07-25T16:07:39.194Z,1753459659.194 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-07-25T16:07:39.194Z,1753459659.194 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T16:07:39.194Z,1753459659.194 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T16:07:39.195Z,1753459659.195 [Default:A.Wait] Running Loop=1
2025-07-25T16:07:39.195Z,1753459659.195 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-07-25T16:07:40.394Z,1753459660.394 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:07:52.515Z,1753459672.515 [Default:A.Wait](INFO): Done Waiting.
2025-07-25T16:07:52.515Z,1753459672.515 [Default:A.Wait] Stopped
2025-07-25T16:07:52.515Z,1753459672.515 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-07-25T16:07:52.926Z,1753459672.926 [Default:CheckIn] Running Loop=1
2025-07-25T16:07:52.926Z,1753459672.926 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-07-25T16:07:52.926Z,1753459672.926 [Default:CheckIn:Read_GPS] Running Loop=1
2025-07-25T16:07:53.325Z,1753459673.325 [NAL9602](INFO): SBD MO Status=1, MOMSN=26282, MT Status=0, MTMSN=0
2025-07-25T16:07:53.375Z,1753459673.375 [NAL9602](INFO): Sent 39 bytes from file Logs/20250721T205855/Courier0328.lzma
2025-07-25T16:07:53.375Z,1753459673.375 [NAL9602](INFO): Packets left to send: 0
2025-07-25T16:07:53.411Z,1753459673.411 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-07-25T16:07:54.528Z,1753459674.528 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160757.00,A,3647.41339,N,12150.56167,W,0.564,174.91,250725,,,D*7F
2025-07-25T16:07:54.530Z,1753459674.530 [NAL9602](INFO): GPS fix at 20250725T160757: (36.790223, -121.842694)
2025-07-25T16:07:54.541Z,1753459674.541 [Default:CheckIn:Read_GPS] Stopped
2025-07-25T16:07:54.541Z,1753459674.541 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-07-25T16:07:54.952Z,1753459674.952 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-07-25T16:07:55.733Z,1753459675.733 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:08:11.371Z,1753459691.371 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005035
2025-07-25T16:08:11.543Z,1753459691.543 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:08:15.991Z,1753459695.991 [NAL9602](INFO): SBD MO Status=1, MOMSN=26283, MT Status=0, MTMSN=0
2025-07-25T16:08:16.045Z,1753459696.045 [NAL9602](INFO): Sent 268 bytes from file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:08:16.045Z,1753459696.045 [NAL9602](INFO): Packets left to send: 0
2025-07-25T16:08:16.093Z,1753459696.093 [Default:CheckIn:Read_Iridium] Stopped
2025-07-25T16:08:16.097Z,1753459696.097 [Default:CheckIn:C.Wait] Running Loop=1
2025-07-25T16:08:16.097Z,1753459696.097 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-07-25T16:08:18.947Z,1753459698.947 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:08:18.947Z,1753459698.947 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:08:26.489Z,1753459706.489 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:08:37.515Z,1753459717.515 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:08:37.515Z,1753459717.515 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:08:41.842Z,1753459721.842 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:08:46.692Z,1753459726.692 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T16:08:57.194Z,1753459737.194 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:09:08.167Z,1753459748.167 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:09:08.167Z,1753459748.167 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:09:12.142Z,1753459752.142 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:09:27.091Z,1753459767.091 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:09:38.872Z,1753459778.872 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:09:38.873Z,1753459778.873 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:09:41.633Z,1753459781.633 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2025-07-25T16:10:09.431Z,1753459809.431 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:10:09.431Z,1753459809.431 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:10:40.196Z,1753459840.196 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:10:40.196Z,1753459840.196 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:11:11.859Z,1753459871.859 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:11:11.859Z,1753459871.859 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:11:43.339Z,1753459903.339 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:11:43.339Z,1753459903.339 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:12:09.126Z,1753459929.126 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T16:12:09.133Z,1753459929.133 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T16:12:09.134Z,1753459929.134 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-07-25T16:12:09.134Z,1753459929.134 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T16:12:09.135Z,1753459929.135 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T16:12:09.136Z,1753459929.136 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2025-07-25T16:12:09.136Z,1753459929.136 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 4.
2025-07-25T16:12:09.139Z,1753459929.139 [BPC1](INFO): Received data from all battery sticks.
2025-07-25T16:12:14.107Z,1753459934.107 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:12:14.108Z,1753459934.108 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:12:46.031Z,1753459966.031 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:12:46.031Z,1753459966.031 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:13:13.571Z,1753459993.571 [DataOverHttps](IMPORTANT): Could not stat file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:13:13.571Z,1753459993.571 [DataOverHttps](FAULT): Could not open file Logs/20250725T160334/Courier0000.lzma
2025-07-25T16:13:16.665Z,1753459996.665 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-07-25T16:13:16.666Z,1753459996.666 [Default:CheckIn:C.Wait] Stopped
2025-07-25T16:13:16.666Z,1753459996.666 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-07-25T16:13:16.666Z,1753459996.666 [Default:CheckIn:D] Running Loop=1
2025-07-25T16:13:17.076Z,1753459997.076 [Default:CheckIn:D] Stopped
2025-07-25T16:13:17.076Z,1753459997.076 [Default:CheckIn:E] Running Loop=1
2025-07-25T16:13:17.472Z,1753459997.472 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.631404 min
2025-07-25T16:13:17.472Z,1753459997.472 [Default:CheckIn:E] Stopped
2025-07-25T16:13:17.473Z,1753459997.473 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-07-25T16:13:17.473Z,1753459997.473 [Default:CheckIn] Stopped
2025-07-25T16:13:17.473Z,1753459997.473 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-07-25T16:13:17.473Z,1753459997.473 [Default:CheckIn](INFO): Running loop #2
2025-07-25T16:13:17.473Z,1753459997.473 [Default:CheckIn] Running Loop=2
2025-07-25T16:13:17.473Z,1753459997.473 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-07-25T16:13:17.473Z,1753459997.473 [Default:CheckIn:Read_GPS] Running Loop=1
2025-07-25T16:13:19.484Z,1753459999.484 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161323.00,A,3647.36176,N,12150.54971,W,0.778,181.28,250725,,,D*7A
2025-07-25T16:13:19.487Z,1753459999.487 [NAL9602](INFO): GPS fix at 20250725T161323: (36.789363, -121.842495)
2025-07-25T16:13:19.498Z,1753459999.498 [Default:CheckIn:Read_GPS] Stopped
2025-07-25T16:13:19.498Z,1753459999.498 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-07-25T16:13:29.187Z,1753460009.187 [NAL9602](INFO): SBD MO Status=0, MOMSN=26284, MT Status=0, MTMSN=0
2025-07-25T16:13:29.188Z,1753460009.188 [NAL9602](INFO): No messages in MT queue
2025-07-25T16:13:31.081Z,1753460011.081 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250725T160334/Courier0004.lzma
2025-07-25T16:13:42.132Z,1753460022.132 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Courier0004.lzma.bak
2025-07-25T16:13:42.132Z,1753460022.132 [DataOverHttps](IMPORTANT): SBD MOMSN=25610530, MTMSN=20250725T161346
2025-07-25T16:13:49.659Z,1753460029.659 [DataOverHttps](INFO): Received command: load Transport/keepstation.tl;set keepstation.NeedCommsTime 30 min;set keepstation.Latitude 36.806966 degree;set keepstation.Longitude -121.824326 degree;set keepstation:BackseatDriver.EnableBackseat 1 bool;run
2025-07-25T16:13:49.800Z,1753460029.800 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl
2025-07-25T16:13:49.800Z,1753460029.800 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl
2025-07-25T16:13:49.800Z,1753460029.800 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl
2025-07-25T16:13:49.804Z,1753460029.804 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl
2025-07-25T16:13:51.167Z,1753460031.167 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/keepstation.tl translated into:
4
45
NaN
NaN
30
15
4
0.75
200
10
10
45
2
0
0
1
2
3
NaN
0
Sinking to
Timed out while trying to reach target sink depth at current depth of
2025-07-25T16:13:51.201Z,1753460031.201 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h
2025-07-25T16:13:51.204Z,1753460031.204 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min
2025-07-25T16:13:51.231Z,1753460031.231 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg
2025-07-25T16:13:51.238Z,1753460031.238 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg
2025-07-25T16:13:51.241Z,1753460031.241 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m
2025-07-25T16:13:51.256Z,1753460031.256 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m
2025-07-25T16:13:51.264Z,1753460031.264 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m
2025-07-25T16:13:51.279Z,1753460031.279 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s
2025-07-25T16:13:51.287Z,1753460031.287 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m
2025-07-25T16:13:51.302Z,1753460031.302 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool
2025-07-25T16:13:51.304Z,1753460031.304 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m
2025-07-25T16:13:51.312Z,1753460031.312 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min
2025-07-25T16:13:51.316Z,1753460031.316 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m
2025-07-25T16:13:51.331Z,1753460031.331 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km
2025-07-25T16:13:51.339Z,1753460031.339 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count
2025-07-25T16:13:51.357Z,1753460031.357 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count
2025-07-25T16:13:51.360Z,1753460031.360 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count
2025-07-25T16:13:51.368Z,1753460031.368 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count
2025-07-25T16:13:51.414Z,1753460031.414 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count
2025-07-25T16:13:51.425Z,1753460031.425 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool
2025-07-25T16:13:51.426Z,1753460031.426 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl
2025-07-25T16:13:51.426Z,1753460031.426 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl
2025-07-25T16:13:51.427Z,1753460031.427 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl
2025-07-25T16:13:51.742Z,1753460031.742 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into:
1
10
20
NaN
1
1000
7
30
0
last time_fix was:
first GPS update timeout
Comms timed out after
minutes
second GPS update timeout
2025-07-25T16:13:51.751Z,1753460031.751 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h
2025-07-25T16:13:51.755Z,1753460031.755 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min
2025-07-25T16:13:51.758Z,1753460031.758 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg
2025-07-25T16:13:51.760Z,1753460031.760 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s
2025-07-25T16:13:51.764Z,1753460031.764 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s
2025-07-25T16:13:51.767Z,1753460031.767 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s
2025-07-25T16:13:51.770Z,1753460031.770 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min
2025-07-25T16:13:51.773Z,1753460031.773 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min
2025-07-25T16:13:51.779Z,1753460031.779 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-07-25T16:13:51.878Z,1753460031.878 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl
2025-07-25T16:13:51.878Z,1753460031.878 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl
2025-07-25T16:13:51.879Z,1753460031.879 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl
2025-07-25T16:13:52.028Z,1753460032.028 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into:
5
1.5
200
2000
2025-07-25T16:13:52.036Z,1753460032.036 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m
2025-07-25T16:13:52.044Z,1753460032.044 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 1.500000 m
2025-07-25T16:13:52.047Z,1753460032.047 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m
2025-07-25T16:13:52.058Z,1753460032.058 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m
2025-07-25T16:13:52.059Z,1753460032.059 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2025-07-25T16:13:52.076Z,1753460032.076 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2025-07-25T16:13:52.097Z,1753460032.097 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2025-07-25T16:13:52.116Z,1753460032.116 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-07-25T16:13:52.116Z,1753460032.116 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-07-25T16:13:52.121Z,1753460032.121 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-07-25T16:13:52.164Z,1753460032.164 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-07-25T16:13:52.172Z,1753460032.172 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool
2025-07-25T16:13:52.180Z,1753460032.180 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-07-25T16:13:52.187Z,1753460032.187 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2025-07-25T16:13:52.187Z,1753460032.187 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2025-07-25T16:13:52.189Z,1753460032.189 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2025-07-25T16:13:52.459Z,1753460032.459 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
99999
2025-07-25T16:13:52.468Z,1753460032.468 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool
2025-07-25T16:13:52.481Z,1753460032.481 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool
2025-07-25T16:13:52.484Z,1753460032.484 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool
2025-07-25T16:13:52.498Z,1753460032.498 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool
2025-07-25T16:13:52.506Z,1753460032.506 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool
2025-07-25T16:13:52.521Z,1753460032.521 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait.
2025-07-25T16:13:52.523Z,1753460032.523 [keepstation:H.Pitch](DEBUG): Construct.
2025-07-25T16:13:52.571Z,1753460032.571 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2025-07-25T16:13:52.576Z,1753460032.576 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct.
2025-07-25T16:13:52.588Z,1753460032.588 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct.
2025-07-25T16:13:52.669Z,1753460032.669 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy.
2025-07-25T16:13:52.677Z,1753460032.677 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct.
2025-07-25T16:13:52.684Z,1753460032.684 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct.
2025-07-25T16:13:52.703Z,1753460032.703 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct.
2025-07-25T16:13:52.721Z,1753460032.721 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation.
2025-07-25T16:13:52.739Z,1753460032.739 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2025-07-25T16:13:52.769Z,1753460032.769 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait.
2025-07-25T16:13:52.842Z,1753460032.842 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission keepstation {
"""
Vehicle transits to desired waypoint (or stays put if none is commanded)
and stays within the specified radius.
"""
arguments {
MissionTimeout = 4 hour
"""
Maximum duration of mission
"""
NeedCommsTime = 45 minute
"""
How often to surface for communications
"""
Latitude = NaN degree
"""
Latitude of waypoint to hold. If NaN, hold the latitude at start of
mission.
"""
Longitude = NaN degree
"""
Longitude of waypoint to hold. If NaN, hold the longitude at start of
mission.
"""
Depth = 30 meter
"""
Depth held during drift mode
"""
ApproachDepth = 15 meter
"""
Depth for initial approach to station.
"""
DepthDeadband = 4 meter
"""
How much vertical drift from the specified depth is allowed in drift
mode
"""
Speed = 0.75 meter_per_second
"""
Vehicle transit speed.
"""
Radius = 200 meter
"""
Radius of circle around waypoint to hold.
"""
SinkOffSurface = false
"""
If true, use buoyancy only to decend to SinkDepth before driving to first target depth
"""
SinkDepth = 10 meter
"""
Initial depth to decend using only buoyancy before driving
"""
SinkDepthTimeout = 10 minute
"""
Max wait time for the vehicle to reach the target depth
"""
MaxDepth = 45 meter
"""
Maximum allowable depth during the mission.
"""
MinOffshore = 2 kilometer
"""
Minimum distance from the shoreline to maintain
"""
}
output {
DiveMode = 0 count
"""
Mission variable (don't change). The mission sets this variable to
switch between dive modes. Initialized to DoingComms.
"""
DoingComms = 0 count
"""
Mission variable (don't change). The mission will run in this mode
when doing surface comms.
"""
SurfaceSink = 1 count
"""
Mission variable (don't change). The mission will run in this mode
when sinking from the surface using only buoyancy.
"""
TransitToStation = 2 count
"""
Mission variable (don't change). The mission will run in this mode
when performing the transit to station
"""
StationKeep = 3 count
"""
Mission variable (don't change). The mission will run in this mode
when keeping station
"""
OnStation = false
"""
Mission variable (don't change). Determines last mode (Transit or StationKeep)
to resume after needcomms
"""
}
timeout duration=MissionTimeout
insert id="NeedComms" Insert/NeedComms.tl
assign in sequence NeedComms:DiveInterval = NeedCommsTime
insert Insert/StandardEnvelopes.tl
assign in sequence StandardEnvelopes:MaxDepth = MaxDepth
assign in sequence StandardEnvelopes:MinOffshore = MinOffshore
insert Insert/BackseatDriver.tl
insert Insert/PowerOnly.tl
behavior Guidance:Pitch {
run in parallel
set massPosition = Control:VerticalControl.massDefault
}
aggregate SurfaceComms {
run when (
called
or ( elapsed ( Universal:time_fix ) > NeedCommsTime )
)
assign in sequence DiveMode = DoingComms
call priorityHere=false refId="NeedComms"
aggregate setTransit {
run in sequence
break if (
SinkOffSurface
or OnStation
)
assign in sequence DiveMode = TransitToStation
}
aggregate setStation {
run in sequence
break if (
SinkOffSurface
or not OnStation
)
assign in sequence DiveMode = StationKeep
}
aggregate setSink {
run in sequence
break if ( not SinkOffSurface )
assign in sequence DiveMode = SurfaceSink
}
}
call id="StartingMission" priorityHere=false refId="SurfaceComms"
aggregate DiveCmd {
run when ( called )
aggregate SurfaceSink {
run while ( DiveMode == SurfaceSink )
aggregate sink {
run in sequence
behavior Guidance:Buoyancy id="BuoyancyHold" {
run in parallel
set position = NaN cc
}
behavior Guidance:SetSpeed {
run in parallel
set speed = 0 m/s
}
syslog info "Sinking to " + SinkDepth~meter
behavior Guidance:Pitch {
run in sequence
timeout duration=SinkDepthTimeout {
syslog important "Timed out while trying to reach target sink depth at current depth of "
+ Universal:depth~meter
}
set depth = SinkDepth
}
# Once we've sunk, either resume transit or station keeping depths and speeds
aggregate sinkToTransit {
run in sequence
break if ( OnStation )
assign in sequence DiveMode = TransitToStation
}
aggregate sinkToStation {
run in sequence
break if ( not OnStation )
assign in sequence DiveMode = StationKeep
}
}
}
aggregate TransitToStation {
run while ( DiveMode == TransitToStation )
aggregate dive {
run in sequence
behavior Guidance:Buoyancy {
run in parallel
set position = Control:VerticalControl.buoyancyNeutral
}
behavior Guidance:Pitch {
run in parallel
set depth = ApproachDepth
}
behavior Guidance:SetSpeed {
run in parallel
set speed = Speed
}
}
}
aggregate StationKeep {
run while ( DiveMode == StationKeep )
assign in parallel Control:VerticalControl.depthDeadband = DepthDeadband
behavior Guidance:Pitch {
run in parallel
set depth = Depth
}
behavior Guidance:KeepStation {
run in parallel
set latitude = Latitude
set longitude = Longitude
set radius = Radius
set speed = Speed
}
}
}
aggregate TransitToStation {
"""
Need a separate aggregate for transit if we want to specify a
different depth for the approach.
"""
run in sequence
aggregate Dive {
run while ( not ( DiveMode == DoingComms ) )
call priorityHere=false refId="DiveCmd"
}
behavior Guidance:Waypoint id="Wpt1" {
run in sequence
set latitude = Latitude
set longitude = Longitude
}
assign in sequence DiveMode = StationKeep
assign in sequence OnStation = true
}
call id="OnStation" priorityHere=false refId="NeedComms"
aggregate KeepStation {
run in sequence
aggregate Dive {
run while ( not ( DiveMode == DoingComms ) )
call priorityHere=false refId="DiveCmd"
}
behavior Guidance:Wait {
"""
Due to the way the KeepStation behavior is currently
implemented, we must run it in parallel and use a Wait to keep
from completing the mission before the timeout expires. However,
this new version of the mission uses a top-level timeout so that
the entire mission will not run for longer then MissionTimeout.
"""
run in sequence
set duration = MissionTimeout
}
}
}
2025-07-25T16:13:52.843Z,1753460032.843 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation
2025-07-25T16:13:59.894Z,1753460039.894 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T16:14:10.190Z,1753460050.190 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 30 minute
2025-07-25T16:14:10.191Z,1753460050.191 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.806966 degree
2025-07-25T16:14:10.192Z,1753460050.192 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.824326 degree
2025-07-25T16:14:10.192Z,1753460050.192 [CommandExec](IMPORTANT): got command set keepstation:BackseatDriver.EnableBackseat 1 bool
2025-07-25T16:14:10.197Z,1753460050.197 [CommandExec](IMPORTANT): got command run
2025-07-25T16:14:10.200Z,1753460050.200 [CommandExec](IMPORTANT): Running
2025-07-25T16:14:10.439Z,1753460050.439 [Default] Stopped
2025-07-25T16:14:10.439Z,1753460050.439 [Default](DEBUG): Aggregate::uninitialize Default
2025-07-25T16:14:10.439Z,1753460050.439 [Default:B.GoToSurface] Stopped
2025-07-25T16:14:10.439Z,1753460050.439 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T16:14:10.439Z,1753460050.439 [Default:CheckIn] Stopped
2025-07-25T16:14:10.439Z,1753460050.439 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-07-25T16:14:10.440Z,1753460050.440 [Default:CheckIn:Read_Iridium] Stopped
2025-07-25T16:14:10.440Z,1753460050.440 [MissionManager](IMPORTANT): Started mission keepstation
2025-07-25T16:14:10.440Z,1753460050.440 [keepstation] Running Loop=1
2025-07-25T16:14:10.440Z,1753460050.440 [keepstation](DEBUG): Aggregate::initialize keepstation
2025-07-25T16:14:10.440Z,1753460050.440 [keepstation:StandardEnvelopes] Running Loop=1
2025-07-25T16:14:10.440Z,1753460050.440 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes
2025-07-25T16:14:10.440Z,1753460050.440 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-07-25T16:14:10.440Z,1753460050.440 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2025-07-25T16:14:10.445Z,1753460050.445 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-07-25T16:14:10.445Z,1753460050.445 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2025-07-25T16:14:10.445Z,1753460050.445 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-07-25T16:14:10.445Z,1753460050.445 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2025-07-25T16:14:10.445Z,1753460050.445 [keepstation:BackseatDriver] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly:A] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly:B] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly:C] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly:D] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly:E.Wait] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:H.Pitch] Running Loop=1
2025-07-25T16:14:10.446Z,1753460050.446 [keepstation:H.Pitch](DEBUG): Initialize.
2025-07-25T16:14:10.447Z,1753460050.447 [keepstation:B] Running Loop=1
2025-07-25T16:14:10.447Z,1753460050.447 [keepstation:H.Pitch] Running Loop=1
2025-07-25T16:14:10.448Z,1753460050.448 [keepstation:PowerOnly] Running Loop=1
2025-07-25T16:14:10.448Z,1753460050.448 [keepstation:PowerOnly:D] Stopped
2025-07-25T16:14:10.448Z,1753460050.448 [keepstation:PowerOnly:C] Stopped
2025-07-25T16:14:10.448Z,1753460050.448 [keepstation:PowerOnly:B] Stopped
2025-07-25T16:14:10.448Z,1753460050.448 [keepstation:PowerOnly:A] Stopped
2025-07-25T16:14:10.448Z,1753460050.448 [keepstation:BackseatDriver] Running Loop=1
2025-07-25T16:14:10.453Z,1753460050.453 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-07-25T16:14:10.518Z,1753460050.518 [keepstation:StandardEnvelopes] Running Loop=1
2025-07-25T16:14:10.518Z,1753460050.518 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-07-25T16:14:10.519Z,1753460050.519 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-07-25T16:14:10.520Z,1753460050.520 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-07-25T16:14:10.520Z,1753460050.520 [keepstation:B] Stopped
2025-07-25T16:14:10.521Z,1753460050.521 [keepstation:D] Running Loop=1
2025-07-25T16:14:10.817Z,1753460050.817 [keepstation:D] Stopped
2025-07-25T16:14:10.817Z,1753460050.817 [keepstation:E] Running Loop=1
2025-07-25T16:14:10.833Z,1753460050.833 [BackseatComponent](INFO): Powering up
2025-07-25T16:14:10.834Z,1753460050.834 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-07-25T16:14:11.225Z,1753460051.225 [keepstation:E] Stopped
2025-07-25T16:14:11.225Z,1753460051.225 [keepstation:StartingMission] Running Loop=1
2025-07-25T16:14:11.226Z,1753460051.226 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission
2025-07-25T16:14:11.614Z,1753460051.614 [keepstation:SurfaceComms] Running Loop=1
2025-07-25T16:14:11.614Z,1753460051.614 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-07-25T16:14:11.614Z,1753460051.614 [keepstation:SurfaceComms:A] Running Loop=1
2025-07-25T16:14:11.614Z,1753460051.614 [keepstation:SurfaceComms:A] Stopped
2025-07-25T16:14:11.615Z,1753460051.615 [keepstation:SurfaceComms:B] Running Loop=1
2025-07-25T16:14:11.615Z,1753460051.615 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-07-25T16:14:11.642Z,1753460051.642 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20250725T160334/Courier0007.lzma
2025-07-25T16:14:12.022Z,1753460052.022 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2025-07-25T16:14:12.022Z,1753460052.022 [keepstation:NeedComms] Running Loop=1
2025-07-25T16:14:12.022Z,1753460052.022 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T16:14:12.022Z,1753460052.022 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T16:14:12.022Z,1753460052.022 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T16:14:12.022Z,1753460052.022 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T16:14:12.023Z,1753460052.023 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T16:14:12.023Z,1753460052.023 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T16:14:12.024Z,1753460052.024 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T16:14:12.024Z,1753460052.024 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T16:14:12.024Z,1753460052.024 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T16:14:12.024Z,1753460052.024 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T16:14:12.026Z,1753460052.026 [keepstation:NeedComms:A](INFO): last time_fix was: 1753460003.000000 second since 1970/01/01T00:00:00Z
2025-07-25T16:14:12.026Z,1753460052.026 [keepstation:NeedComms:A] Stopped
2025-07-25T16:14:12.435Z,1753460052.435 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T16:14:12.831Z,1753460052.831 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-07-25T16:14:14.432Z,1753460054.432 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161418.00,A,3647.35312,N,12150.54690,W,0.486,167.37,250725,,,D*72
2025-07-25T16:14:14.435Z,1753460054.435 [NAL9602](INFO): GPS fix at 20250725T161418: (36.789219, -121.842448)
2025-07-25T16:14:14.470Z,1753460054.470 [keepstation:NeedComms:C] Stopped
2025-07-25T16:14:14.470Z,1753460054.470 [keepstation:NeedComms:D] Running Loop=1
2025-07-25T16:14:14.878Z,1753460054.878 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-07-25T16:14:22.683Z,1753460062.683 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Courier0007.lzma.bak
2025-07-25T16:14:22.683Z,1753460062.683 [DataOverHttps](INFO): SBD MOMSN=25610540
2025-07-25T16:14:30.184Z,1753460070.184 [NAL9602](INFO): SBD MO Status=0, MOMSN=26285, MT Status=0, MTMSN=0
2025-07-25T16:14:30.184Z,1753460070.184 [NAL9602](INFO): No messages in MT queue
2025-07-25T16:14:51.761Z,1753460091.761 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250725T160334/Courier0010.lzma
2025-07-25T16:15:00.935Z,1753460100.935 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T16:15:02.803Z,1753460102.803 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Courier0010.lzma.bak
2025-07-25T16:15:02.803Z,1753460102.803 [DataOverHttps](INFO): SBD MOMSN=25610600
2025-07-25T16:15:28.825Z,1753460128.825 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250725T160334/Courier0013.lzma
2025-07-25T16:15:39.867Z,1753460139.867 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Courier0013.lzma.bak
2025-07-25T16:15:39.867Z,1753460139.867 [DataOverHttps](INFO): SBD MOMSN=25610603
2025-07-25T16:16:03.889Z,1753460163.889 [DataOverHttps](INFO): Sending 276 bytes from file Logs/20250721T205855/Express0329.lzma
2025-07-25T16:16:14.931Z,1753460174.931 [DataOverHttps](INFO): Moved sent file to Logs/20250721T205855/Express0329.lzma.bak
2025-07-25T16:16:14.931Z,1753460174.931 [DataOverHttps](INFO): SBD MOMSN=25610606
2025-07-25T16:16:16.513Z,1753460176.513 [BackseatComponent](IMPORTANT): ptvr: Running Planktivore backseat app. Logging to: 20250725T161542, NVMEDATA = 615993156 B
2025-07-25T16:16:19.219Z,1753460179.219 [BackseatComponent](INFO): Created data reader for Depth_Keller.enableBroadcast with code: 1724
2025-07-25T16:16:19.220Z,1753460179.220 [BackseatComponent](INFO): Requesting data from Depth_Keller.enableBroadcast (1724). Requested size is: 1
2025-07-25T16:16:19.221Z,1753460179.221 [BackseatComponent](INFO): Created universal data reader for depth with code: 6
2025-07-25T16:16:19.222Z,1753460179.222 [BackseatComponent](INFO): Requesting data from depth (6). Requested size is: 2
2025-07-25T16:16:19.311Z,1753460179.311 [Depth_Keller](ERROR): Failed to copy Depth_Keller.enableBroadcast's data value to LCM message.
2025-07-25T16:16:19.311Z,1753460179.311 [Depth_Keller](INFO): Activating messaging.
2025-07-25T16:16:41.140Z,1753460201.140 [DataOverHttps](INFO): Sending 1158 bytes from file Logs/20250725T160334/Express0001.lzma
2025-07-25T16:16:51.666Z,1753460211.666 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.planktivore_HM_AvgRois with code: 2007
2025-07-25T16:16:51.668Z,1753460211.668 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.planktivore_LM_AvgRois with code: 2008
2025-07-25T16:16:51.671Z,1753460211.671 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.planktivore_caseHumidity with code: 2009
2025-07-25T16:16:51.674Z,1753460211.674 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.planktivore_casePress with code: 2010
2025-07-25T16:16:51.676Z,1753460211.676 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.planktivore_caseTemp with code: 2011
2025-07-25T16:16:52.183Z,1753460212.183 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Express0001.lzma.bak
2025-07-25T16:16:52.183Z,1753460212.183 [DataOverHttps](INFO): SBD MOMSN=25610615
2025-07-25T16:17:12.669Z,1753460232.669 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.planktivore_diatoms with code: 2012
2025-07-25T16:17:12.671Z,1753460232.671 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.planktivore_dinoflagellates with code: 2013
2025-07-25T16:17:18.537Z,1753460238.537 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20250725T160334/Express0005.lzma
2025-07-25T16:17:29.579Z,1753460249.579 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Express0005.lzma.bak
2025-07-25T16:17:29.579Z,1753460249.579 [DataOverHttps](IMPORTANT): SBD MOMSN=25610640, MTMSN=20250725T161733
2025-07-25T16:17:37.045Z,1753460257.045 [DataOverHttps](INFO): Received command: set keepstation.Speed 1 m/s
2025-07-25T16:17:39.624Z,1753460259.624 [CommandExec](IMPORTANT): got command set keepstation.Speed 1 meter_per_second
2025-07-25T16:17:55.574Z,1753460275.574 [DataOverHttps](INFO): Sending 350 bytes from file Logs/20250725T160334/Express0008.lzma
2025-07-25T16:18:06.615Z,1753460286.615 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Express0008.lzma.bak
2025-07-25T16:18:06.615Z,1753460286.615 [DataOverHttps](INFO): SBD MOMSN=25610644
2025-07-25T16:18:32.700Z,1753460312.700 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250725T160334/Courier0016.lzma
2025-07-25T16:18:43.751Z,1753460323.751 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Courier0016.lzma.bak
2025-07-25T16:18:43.751Z,1753460323.751 [DataOverHttps](INFO): SBD MOMSN=25610669
2025-07-25T16:19:13.253Z,1753460353.253 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20250725T160334/Express0011.lzma
2025-07-25T16:19:24.295Z,1753460364.295 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Express0011.lzma.bak
2025-07-25T16:19:24.295Z,1753460364.295 [DataOverHttps](INFO): SBD MOMSN=25610677
2025-07-25T16:19:50.314Z,1753460390.314 [DataOverHttps](INFO): Sending 305 bytes from file Logs/20250725T160334/Express0014.lzma
2025-07-25T16:20:01.347Z,1753460401.347 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Express0014.lzma.bak
2025-07-25T16:20:01.347Z,1753460401.347 [DataOverHttps](INFO): SBD MOMSN=25610681
2025-07-25T16:20:27.606Z,1753460427.606 [DataOverHttps](INFO): Sending 374 bytes from file Logs/20250725T160334/Express0017.lzma
2025-07-25T16:20:38.647Z,1753460438.647 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Express0017.lzma.bak
2025-07-25T16:20:38.647Z,1753460438.647 [DataOverHttps](INFO): SBD MOMSN=25610691
2025-07-25T16:20:39.990Z,1753460439.990 [keepstation:NeedComms:D] Stopped
2025-07-25T16:20:39.991Z,1753460439.991 [keepstation:NeedComms:E] Running Loop=1
2025-07-25T16:20:40.387Z,1753460440.387 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-07-25T16:20:41.990Z,1753460441.990 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162046.00,A,3647.29598,N,12150.53721,W,0.700,177.13,250725,,,D*71
2025-07-25T16:20:41.992Z,1753460441.992 [NAL9602](INFO): GPS fix at 20250725T162046: (36.788266, -121.842287)
2025-07-25T16:20:42.075Z,1753460442.075 [keepstation:NeedComms:E] Stopped
2025-07-25T16:20:42.076Z,1753460442.076 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-07-25T16:20:42.076Z,1753460442.076 [keepstation:NeedComms] Stopped
2025-07-25T16:20:42.076Z,1753460442.076 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T16:20:42.076Z,1753460442.076 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T16:20:42.076Z,1753460442.076 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T16:20:42.459Z,1753460442.459 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B
2025-07-25T16:20:42.459Z,1753460442.459 [keepstation:SurfaceComms:B] Stopped
2025-07-25T16:20:42.459Z,1753460442.459 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-07-25T16:20:42.459Z,1753460442.459 [keepstation:SurfaceComms:setTransit] Running Loop=1
2025-07-25T16:20:42.460Z,1753460442.460 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit
2025-07-25T16:20:42.460Z,1753460442.460 [keepstation:SurfaceComms:setTransit:A] Running Loop=1
2025-07-25T16:20:42.872Z,1753460442.872 [keepstation:SurfaceComms:setTransit:A] Stopped
2025-07-25T16:20:42.872Z,1753460442.872 [keepstation:SurfaceComms:setTransit](INFO): Completed keepstation:SurfaceComms:setTransit
2025-07-25T16:20:42.872Z,1753460442.872 [keepstation:SurfaceComms:setTransit] Stopped
2025-07-25T16:20:42.872Z,1753460442.872 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit
2025-07-25T16:20:42.872Z,1753460442.872 [keepstation:SurfaceComms:setStation] Running Loop=1
2025-07-25T16:20:42.872Z,1753460442.872 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation
2025-07-25T16:20:42.872Z,1753460442.872 [keepstation:SurfaceComms:setStation:A] Running Loop=1
2025-07-25T16:20:43.259Z,1753460443.259 [keepstation:SurfaceComms:setStation] Stopped
2025-07-25T16:20:43.259Z,1753460443.259 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation
2025-07-25T16:20:43.259Z,1753460443.259 [keepstation:SurfaceComms:setStation:A] Stopped
2025-07-25T16:20:43.259Z,1753460443.259 [keepstation:SurfaceComms:setSink] Running Loop=1
2025-07-25T16:20:43.259Z,1753460443.259 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink
2025-07-25T16:20:43.259Z,1753460443.259 [keepstation:SurfaceComms:setSink:A] Running Loop=1
2025-07-25T16:20:43.710Z,1753460443.710 [keepstation:SurfaceComms:setSink] Stopped
2025-07-25T16:20:43.711Z,1753460443.711 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink
2025-07-25T16:20:43.711Z,1753460443.711 [keepstation:SurfaceComms:setSink:A] Stopped
2025-07-25T16:20:43.711Z,1753460443.711 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms
2025-07-25T16:20:43.711Z,1753460443.711 [keepstation:SurfaceComms] Stopped
2025-07-25T16:20:43.711Z,1753460443.711 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-07-25T16:20:44.095Z,1753460444.095 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:StartingMission] Stopped
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:TransitToStation] Running Loop=1
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:TransitToStation:Dive] Running Loop=1
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:TransitToStation:Dive:A] Running Loop=1
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A
2025-07-25T16:20:44.096Z,1753460444.096 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1
2025-07-25T16:20:44.097Z,1753460444.097 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2025-07-25T16:20:44.102Z,1753460444.102 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.806965,-121.824326
2025-07-25T16:20:44.480Z,1753460444.480 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326
2025-07-25T16:20:44.485Z,1753460444.485 [keepstation:TransitToStation:Dive] Running Loop=1
2025-07-25T16:20:44.485Z,1753460444.485 [keepstation:DiveCmd] Running Loop=1
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd](DEBUG): Aggregate::initialize keepstation:DiveCmd
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink] Running Loop=1
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1
2025-07-25T16:20:44.486Z,1753460444.486 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize.
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation] Running Loop=1
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize.
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1
2025-07-25T16:20:44.487Z,1753460444.487 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize.
2025-07-25T16:20:44.488Z,1753460444.488 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-07-25T16:20:44.488Z,1753460444.488 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep
2025-07-25T16:20:44.488Z,1753460444.488 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-07-25T16:20:44.488Z,1753460444.488 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-07-25T16:20:44.488Z,1753460444.488 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize.
2025-07-25T16:20:44.488Z,1753460444.488 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-07-25T16:20:44.488Z,1753460444.488 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-07-25T16:20:44.529Z,1753460444.529 [keepstation:DiveCmd:StationKeep] Stopped
2025-07-25T16:20:44.529Z,1753460444.529 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep
2025-07-25T16:20:44.529Z,1753460444.529 [keepstation:DiveCmd:StationKeep:A] Stopped
2025-07-25T16:20:44.530Z,1753460444.530 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped
2025-07-25T16:20:44.530Z,1753460444.530 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped
2025-07-25T16:20:44.530Z,1753460444.530 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-07-25T16:20:44.530Z,1753460444.530 [keepstation:DiveCmd:TransitToStation] Running Loop=1
2025-07-25T16:20:44.530Z,1753460444.530 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1
2025-07-25T16:20:44.530Z,1753460444.530 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink] Stopped
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink:sink] Stopped
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize.
2025-07-25T16:20:44.531Z,1753460444.531 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped
2025-07-25T16:20:44.556Z,1753460444.556 [HorizontalControl](DEBUG): kpHeading = 0.400000
2025-07-25T16:20:44.557Z,1753460444.557 [HorizontalControl](DEBUG): kiHeading = 0.001000
2025-07-25T16:20:44.577Z,1753460444.577 [HorizontalControl](DEBUG): kdHeading = 0.050000
2025-07-25T16:20:57.413Z,1753460457.413 [NAL9602](INFO): SBD MO Status=0, MOMSN=26286, MT Status=0, MTMSN=0
2025-07-25T16:20:57.413Z,1753460457.413 [NAL9602](INFO): No messages in MT queue
2025-07-25T16:21:28.155Z,1753460488.155 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T16:22:11.925Z,1753460531.925 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:22:43.050Z,1753460563.050 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:23:01.143Z,1753460581.143 [Radio_Surface](INFO): Powering down
2025-07-25T16:23:14.173Z,1753460594.173 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:23:15.178Z,1753460595.178 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-07-25T16:24:02.366Z,1753460642.366 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.979385
2025-07-25T16:50:42.396Z,1753462242.396 [keepstation:SurfaceComms] Running Loop=1
2025-07-25T16:50:42.396Z,1753462242.396 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-07-25T16:50:42.396Z,1753462242.396 [keepstation:SurfaceComms:A] Running Loop=1
2025-07-25T16:50:42.397Z,1753462242.397 [keepstation:SurfaceComms:A] Stopped
2025-07-25T16:50:42.397Z,1753462242.397 [keepstation:SurfaceComms:B] Running Loop=1
2025-07-25T16:50:42.397Z,1753462242.397 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-07-25T16:50:42.402Z,1753462242.402 [keepstation:NeedComms] Running Loop=1
2025-07-25T16:50:42.402Z,1753462242.402 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T16:50:42.402Z,1753462242.402 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T16:50:42.402Z,1753462242.402 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T16:50:42.402Z,1753462242.402 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T16:50:42.403Z,1753462242.403 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T16:50:42.403Z,1753462242.403 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T16:50:42.403Z,1753462242.403 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T16:50:42.404Z,1753462242.404 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T16:50:42.404Z,1753462242.404 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T16:50:42.404Z,1753462242.404 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T16:50:42.406Z,1753462242.406 [keepstation:NeedComms:A](INFO): last time_fix was: 1753460446.000000 second since 1970/01/01T00:00:00Z
2025-07-25T16:50:42.406Z,1753462242.406 [keepstation:NeedComms:A] Stopped
2025-07-25T16:50:42.787Z,1753462242.787 [keepstation:TransitToStation:Dive] Stopped
2025-07-25T16:50:42.787Z,1753462242.787 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive
2025-07-25T16:50:42.787Z,1753462242.787 [keepstation:TransitToStation:Dive:A] Stopped
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation] Stopped
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation:dive] Stopped
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped
2025-07-25T16:50:42.788Z,1753462242.788 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped
2025-07-25T16:50:42.789Z,1753462242.789 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize.
2025-07-25T16:51:41.551Z,1753462301.551 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T16:51:42.029Z,1753462302.029 [Radio_Surface](INFO): Powering up
2025-07-25T16:51:48.213Z,1753462308.213 [DataOverHttps](INFO): Radio surface powered ON.
2025-07-25T16:52:04.989Z,1753462324.989 [NAL9602](INFO): SBD MO Status=0, MOMSN=26287, MT Status=0, MTMSN=0
2025-07-25T16:52:04.989Z,1753462324.989 [NAL9602](INFO): No messages in MT queue
2025-07-25T16:52:06.194Z,1753462326.194 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165210.00,A,3647.81896,N,12149.98187,W,0.486,110.97,250725,,,D*73
2025-07-25T16:52:06.196Z,1753462326.196 [NAL9602](INFO): GPS fix at 20250725T165210: (36.796983, -121.833031)
2025-07-25T16:52:06.229Z,1753462326.229 [UniversalFixResidualReporter](INFO): Fix residual: 29.8 %DT, over the last 1824.9 m. Residual distance 543.6 m at bearing 31.2 degrees. Fix at (36.7970, -121.8330) with 1272.3 m made good.
2025-07-25T16:52:06.231Z,1753462326.231 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326
2025-07-25T16:52:06.234Z,1753462326.234 [keepstation:NeedComms:C] Stopped
2025-07-25T16:52:06.234Z,1753462326.234 [keepstation:NeedComms:D] Running Loop=1
2025-07-25T16:52:18.369Z,1753462338.369 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:52:21.658Z,1753462341.658 [NAL9602](INFO): SBD MO Status=1, MOMSN=26288, MT Status=0, MTMSN=0
2025-07-25T16:52:21.709Z,1753462341.709 [NAL9602](INFO): Sent 207 bytes from file Logs/20250725T160334/Courier0019.lzma
2025-07-25T16:52:21.710Z,1753462341.710 [NAL9602](INFO): Packets left to send: 0
2025-07-25T16:52:31.481Z,1753462351.481 [NAL9602](INFO): SBD MO Status=1, MOMSN=26289, MT Status=0, MTMSN=0
2025-07-25T16:52:31.529Z,1753462351.529 [NAL9602](INFO): Sent 332 bytes from file Logs/20250725T160334/Express0020.lzma
2025-07-25T16:52:31.529Z,1753462351.529 [NAL9602](INFO): Packets left to send: 1
2025-07-25T16:52:39.251Z,1753462359.251 [NAL9602](INFO): SBD MO Status=1, MOMSN=26290, MT Status=0, MTMSN=0
2025-07-25T16:52:39.305Z,1753462359.305 [NAL9602](INFO): Sent 186 bytes from file Logs/20250725T160334/Express0020.lzma
2025-07-25T16:52:39.305Z,1753462359.305 [NAL9602](INFO): Packets left to send: 0
2025-07-25T16:52:47.354Z,1753462367.354 [NAL9602](INFO): SBD MO Status=0, MOMSN=26291, MT Status=0, MTMSN=0
2025-07-25T16:52:47.434Z,1753462367.434 [keepstation:NeedComms:D] Stopped
2025-07-25T16:52:47.434Z,1753462367.434 [keepstation:NeedComms:E] Running Loop=1
2025-07-25T16:52:49.497Z,1753462369.497 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:52:49.763Z,1753462369.763 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165254.00,A,3647.81561,N,12149.98096,W,0.194,232.72,250725,,,D*79
2025-07-25T16:52:49.765Z,1753462369.765 [NAL9602](INFO): GPS fix at 20250725T165254: (36.796927, -121.833016)
2025-07-25T16:52:49.777Z,1753462369.777 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326
2025-07-25T16:52:49.783Z,1753462369.783 [keepstation:NeedComms:E] Stopped
2025-07-25T16:52:49.784Z,1753462369.784 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-07-25T16:52:49.784Z,1753462369.784 [keepstation:NeedComms] Stopped
2025-07-25T16:52:49.784Z,1753462369.784 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T16:52:49.784Z,1753462369.784 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T16:52:49.785Z,1753462369.785 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T16:52:50.192Z,1753462370.192 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B
2025-07-25T16:52:50.192Z,1753462370.192 [keepstation:SurfaceComms:B] Stopped
2025-07-25T16:52:50.192Z,1753462370.192 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-07-25T16:52:50.193Z,1753462370.193 [keepstation:SurfaceComms:setTransit] Running Loop=1
2025-07-25T16:52:50.193Z,1753462370.193 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit
2025-07-25T16:52:50.193Z,1753462370.193 [keepstation:SurfaceComms:setTransit:A] Running Loop=1
2025-07-25T16:52:50.576Z,1753462370.576 [keepstation:SurfaceComms:setTransit:A] Stopped
2025-07-25T16:52:50.576Z,1753462370.576 [keepstation:SurfaceComms:setTransit](INFO): Completed keepstation:SurfaceComms:setTransit
2025-07-25T16:52:50.577Z,1753462370.577 [keepstation:SurfaceComms:setTransit] Stopped
2025-07-25T16:52:50.577Z,1753462370.577 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit
2025-07-25T16:52:50.577Z,1753462370.577 [keepstation:SurfaceComms:setStation] Running Loop=1
2025-07-25T16:52:50.577Z,1753462370.577 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation
2025-07-25T16:52:50.577Z,1753462370.577 [keepstation:SurfaceComms:setStation:A] Running Loop=1
2025-07-25T16:52:50.985Z,1753462370.985 [keepstation:TransitToStation:Dive] Running Loop=1
2025-07-25T16:52:50.985Z,1753462370.985 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive
2025-07-25T16:52:50.986Z,1753462370.986 [keepstation:TransitToStation:Dive:A] Running Loop=1
2025-07-25T16:52:50.986Z,1753462370.986 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A
2025-07-25T16:52:50.986Z,1753462370.986 [keepstation:DiveCmd:TransitToStation] Running Loop=1
2025-07-25T16:52:50.986Z,1753462370.986 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation
2025-07-25T16:52:50.986Z,1753462370.986 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1
2025-07-25T16:52:50.987Z,1753462370.987 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive
2025-07-25T16:52:50.987Z,1753462370.987 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1
2025-07-25T16:52:50.987Z,1753462370.987 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-07-25T16:52:50.987Z,1753462370.987 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1
2025-07-25T16:52:50.987Z,1753462370.987 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize.
2025-07-25T16:52:50.987Z,1753462370.987 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1
2025-07-25T16:52:50.987Z,1753462370.987 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize.
2025-07-25T16:52:50.988Z,1753462370.988 [keepstation:SurfaceComms:setStation] Stopped
2025-07-25T16:52:50.988Z,1753462370.988 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation
2025-07-25T16:52:50.988Z,1753462370.988 [keepstation:SurfaceComms:setStation:A] Stopped
2025-07-25T16:52:50.988Z,1753462370.988 [keepstation:SurfaceComms:setSink] Running Loop=1
2025-07-25T16:52:50.989Z,1753462370.989 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink
2025-07-25T16:52:50.989Z,1753462370.989 [keepstation:SurfaceComms:setSink:A] Running Loop=1
2025-07-25T16:52:51.398Z,1753462371.398 [keepstation:SurfaceComms:setSink] Stopped
2025-07-25T16:52:51.398Z,1753462371.398 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink
2025-07-25T16:52:51.398Z,1753462371.398 [keepstation:SurfaceComms:setSink:A] Stopped
2025-07-25T16:52:51.398Z,1753462371.398 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms
2025-07-25T16:52:51.398Z,1753462371.398 [keepstation:SurfaceComms] Stopped
2025-07-25T16:52:51.399Z,1753462371.399 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-07-25T16:53:19.788Z,1753462399.788 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 20.00 deg, mass-position 24.29 mm (1 active estimators).
2025-07-25T16:53:20.621Z,1753462400.621 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:53:22.319Z,1753462402.319 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T16:53:51.745Z,1753462431.745 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:54:20.017Z,1753462460.017 [Radio_Surface](INFO): Powering down
2025-07-25T16:54:22.874Z,1753462462.874 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T16:54:23.877Z,1753462463.877 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-07-25T17:13:16.758Z,1753463596.758 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:13:31.749Z,1753463611.749 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:13:47.102Z,1753463627.102 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:14:02.863Z,1753463642.863 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:14:17.808Z,1753463657.808 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:14:33.156Z,1753463673.156 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:14:48.105Z,1753463688.105 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:15:03.052Z,1753463703.052 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:15:17.640Z,1753463717.640 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2025-07-25T17:16:00.884Z,1753463760.884 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-07-25T17:16:05.691Z,1753463765.691 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Reached waypoint: 36.806965,-121.824326
2025-07-25T17:16:05.691Z,1753463765.691 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped
2025-07-25T17:16:05.691Z,1753463765.691 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2025-07-25T17:16:05.691Z,1753463765.691 [keepstation:TransitToStation:C] Running Loop=1
2025-07-25T17:16:06.098Z,1753463766.098 [keepstation:TransitToStation:C] Stopped
2025-07-25T17:16:06.098Z,1753463766.098 [keepstation:TransitToStation:D] Running Loop=1
2025-07-25T17:16:06.099Z,1753463766.099 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-07-25T17:16:06.099Z,1753463766.099 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep
2025-07-25T17:16:06.099Z,1753463766.099 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-07-25T17:16:06.099Z,1753463766.099 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-07-25T17:16:06.099Z,1753463766.099 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize.
2025-07-25T17:16:06.099Z,1753463766.099 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-07-25T17:16:06.099Z,1753463766.099 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-07-25T17:16:06.100Z,1753463766.100 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-07-25T17:16:06.100Z,1753463766.100 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-07-25T17:16:06.100Z,1753463766.100 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-07-25T17:16:06.101Z,1753463766.101 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-07-25T17:16:06.101Z,1753463766.101 [keepstation:DiveCmd:TransitToStation] Stopped
2025-07-25T17:16:06.101Z,1753463766.101 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation
2025-07-25T17:16:06.101Z,1753463766.101 [keepstation:DiveCmd:TransitToStation:dive] Stopped
2025-07-25T17:16:06.101Z,1753463766.101 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive
2025-07-25T17:16:06.101Z,1753463766.101 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped
2025-07-25T17:16:06.102Z,1753463766.102 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-07-25T17:16:06.102Z,1753463766.102 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped
2025-07-25T17:16:06.102Z,1753463766.102 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped
2025-07-25T17:16:06.102Z,1753463766.102 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize.
2025-07-25T17:16:06.515Z,1753463766.515 [keepstation:TransitToStation:D] Stopped
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:TransitToStation](INFO): Completed keepstation:TransitToStation
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:TransitToStation] Stopped
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:TransitToStation:Dive] Stopped
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:TransitToStation:Dive:A] Stopped
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:OnStation] Running Loop=1
2025-07-25T17:16:06.516Z,1753463766.516 [keepstation:OnStation](DEBUG): Aggregate::initialize keepstation:OnStation
2025-07-25T17:16:06.934Z,1753463766.934 [keepstation:NeedComms] Running Loop=1
2025-07-25T17:16:06.934Z,1753463766.934 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T17:16:06.934Z,1753463766.934 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T17:16:06.934Z,1753463766.934 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T17:16:06.934Z,1753463766.934 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T17:16:06.935Z,1753463766.935 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T17:16:06.935Z,1753463766.935 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T17:16:06.936Z,1753463766.936 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T17:16:06.936Z,1753463766.936 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T17:16:06.936Z,1753463766.936 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T17:16:06.936Z,1753463766.936 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T17:16:06.946Z,1753463766.946 [keepstation:NeedComms:A](INFO): last time_fix was: 1753462374.000000 second since 1970/01/01T00:00:00Z
2025-07-25T17:16:06.946Z,1753463766.946 [keepstation:NeedComms:A] Stopped
2025-07-25T17:17:07.659Z,1753463827.659 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T17:17:08.042Z,1753463828.042 [Radio_Surface](INFO): Powering up
2025-07-25T17:17:13.561Z,1753463833.561 [DataOverHttps](INFO): Radio surface powered ON.
2025-07-25T17:17:33.834Z,1753463853.834 [NAL9602](INFO): SBD MO Status=2, MOMSN=26292, MT Status=2, MTMSN=0
2025-07-25T17:17:33.834Z,1753463853.834 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:17:43.697Z,1753463863.697 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:17:44.392Z,1753463864.392 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:17:57.677Z,1753463877.677 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:18:11.401Z,1753463891.401 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:18:14.853Z,1753463894.853 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:18:23.138Z,1753463903.138 [NAL9602](INFO): SBD MO Status=2, MOMSN=26292, MT Status=2, MTMSN=0
2025-07-25T17:18:23.138Z,1753463903.138 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:18:25.145Z,1753463905.145 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:18:38.473Z,1753463918.473 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:18:43.727Z,1753463923.727 [NAL9602](INFO): SBD MO Status=0, MOMSN=26292, MT Status=0, MTMSN=0
2025-07-25T17:18:43.727Z,1753463923.727 [NAL9602](INFO): No messages in MT queue
2025-07-25T17:18:44.938Z,1753463924.938 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171849.00,A,3648.25305,N,12149.55813,W,0.525,156.80,250725,,,D*79
2025-07-25T17:18:44.940Z,1753463924.940 [NAL9602](INFO): GPS fix at 20250725T171849: (36.804218, -121.825969)
2025-07-25T17:18:44.977Z,1753463924.977 [UniversalFixResidualReporter](INFO): Fix residual: 27.3 %DT, over the last 1421.8 m. Residual distance 388.4 m at bearing 27.7 degrees. Fix at (36.8042, -121.8260) with 1025.1 m made good.
2025-07-25T17:18:44.979Z,1753463924.979 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Rest->Waypoint
2025-07-25T17:18:44.990Z,1753463924.990 [keepstation:NeedComms:C] Stopped
2025-07-25T17:18:44.990Z,1753463924.990 [keepstation:NeedComms:D] Running Loop=1
2025-07-25T17:18:45.989Z,1753463925.989 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:18:51.890Z,1753463931.890 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:19:05.220Z,1753463945.220 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:19:08.869Z,1753463948.869 [NAL9602](INFO): SBD MO Status=2, MOMSN=26293, MT Status=2, MTMSN=0
2025-07-25T17:19:08.869Z,1753463948.869 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:19:17.113Z,1753463957.113 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:19:19.852Z,1753463959.852 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:19:33.590Z,1753463973.590 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:19:34.825Z,1753463974.825 [NAL9602](INFO): SBD MO Status=2, MOMSN=26293, MT Status=2, MTMSN=0
2025-07-25T17:19:34.825Z,1753463974.825 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:19:47.819Z,1753463987.819 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:19:48.237Z,1753463988.237 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:19:52.266Z,1753463992.266 [NAL9602](INFO): SBD MO Status=2, MOMSN=26293, MT Status=2, MTMSN=0
2025-07-25T17:19:52.267Z,1753463992.267 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:19:55.902Z,1753463995.902 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2025-07-25T17:20:02.010Z,1753464002.010 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:20:05.247Z,1753464005.247 [NAL9602](INFO): SBD MO Status=1, MOMSN=26293, MT Status=0, MTMSN=0
2025-07-25T17:20:05.301Z,1753464005.301 [NAL9602](INFO): Sent 83 bytes from file Logs/20250725T160334/Courier0022.lzma
2025-07-25T17:20:05.301Z,1753464005.301 [NAL9602](INFO): Packets left to send: 0
2025-07-25T17:20:19.363Z,1753464019.363 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:20:48.947Z,1753464048.947 [NAL9602](INFO): SBD MO Status=2, MOMSN=26294, MT Status=2, MTMSN=0
2025-07-25T17:20:48.947Z,1753464048.947 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:20:50.485Z,1753464050.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:21:09.222Z,1753464069.222 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003017
2025-07-25T17:21:16.890Z,1753464076.890 [DataOverHttps](INFO): Sending 424 bytes from file Logs/20250725T160334/Express0023.lzma
2025-07-25T17:21:17.750Z,1753464077.750 [NAL9602](INFO): SBD MO Status=2, MOMSN=26294, MT Status=2, MTMSN=0
2025-07-25T17:21:17.750Z,1753464077.750 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:21:27.931Z,1753464087.931 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Express0023.lzma.bak
2025-07-25T17:21:27.931Z,1753464087.931 [DataOverHttps](INFO): SBD MOMSN=25611109
2025-07-25T17:21:29.074Z,1753464089.074 [keepstation:NeedComms:D] Stopped
2025-07-25T17:21:29.074Z,1753464089.074 [keepstation:NeedComms:E] Running Loop=1
2025-07-25T17:21:31.085Z,1753464091.085 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172135.00,A,3648.23887,N,12149.56164,W,0.330,190.12,250725,,,D*76
2025-07-25T17:21:31.087Z,1753464091.087 [NAL9602](INFO): GPS fix at 20250725T172135: (36.803981, -121.826027)
2025-07-25T17:21:31.152Z,1753464091.152 [keepstation:NeedComms:E] Stopped
2025-07-25T17:21:31.153Z,1753464091.153 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-07-25T17:21:31.161Z,1753464091.161 [keepstation:NeedComms] Stopped
2025-07-25T17:21:31.161Z,1753464091.161 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T17:21:31.161Z,1753464091.161 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T17:21:31.161Z,1753464091.161 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T17:21:31.527Z,1753464091.527 [keepstation:OnStation](INFO): Completed keepstation:OnStation
2025-07-25T17:21:31.527Z,1753464091.527 [keepstation:OnStation] Stopped
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:OnStation](DEBUG): Aggregate::uninitialize keepstation:OnStation
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation] Running Loop=1
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation](DEBUG): Aggregate::initialize keepstation:KeepStation
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation:Dive] Running Loop=1
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation:Dive:A] Running Loop=1
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation:B.Wait] Running Loop=1
2025-07-25T17:21:31.528Z,1753464091.528 [keepstation:KeepStation:B.Wait](DEBUG): Initialize Wait Component.
2025-07-25T17:21:31.915Z,1753464091.915 [keepstation:KeepStation:Dive] Running Loop=1
2025-07-25T17:22:03.252Z,1753464123.252 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T17:22:26.508Z,1753464146.508 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:22:30.145Z,1753464150.145 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:22:32.570Z,1753464152.570 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:22:47.538Z,1753464167.538 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:23:01.270Z,1753464181.270 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:23:01.637Z,1753464181.637 [Radio_Surface](INFO): Powering down
2025-07-25T17:23:02.083Z,1753464182.083 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:23:02.273Z,1753464182.273 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-07-25T17:23:17.838Z,1753464197.838 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:23:34.021Z,1753464214.021 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:23:49.370Z,1753464229.370 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:24:05.168Z,1753464245.168 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:24:20.113Z,1753464260.113 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:24:35.073Z,1753464275.073 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:24:47.701Z,1753464287.701 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.727112
2025-07-25T17:25:40.109Z,1753464340.109 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2025-07-25T17:27:04.976Z,1753464424.976 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:27:11.453Z,1753464431.453 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:27:25.178Z,1753464445.178 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:27:39.349Z,1753464459.349 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:27:53.889Z,1753464473.889 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:28:08.029Z,1753464488.029 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:28:21.416Z,1753464501.416 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:28:34.744Z,1753464514.744 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:28:48.483Z,1753464528.483 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:29:01.813Z,1753464541.813 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:29:15.147Z,1753464555.147 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:30:37.176Z,1753464637.176 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Waypoint->Rest
2025-07-25T17:31:50.285Z,1753464710.285 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:32:05.235Z,1753464725.235 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:32:20.181Z,1753464740.181 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:32:35.534Z,1753464755.534 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:32:50.885Z,1753464770.885 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:33:05.845Z,1753464785.845 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:33:21.185Z,1753464801.185 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:33:36.136Z,1753464816.136 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:33:51.495Z,1753464831.495 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:34:06.035Z,1753464846.035 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2025-07-25T17:36:28.640Z,1753464988.640 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2025-07-25T17:36:35.105Z,1753464995.105 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:36:48.438Z,1753465008.438 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:37:01.785Z,1753465021.785 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:37:15.102Z,1753465035.102 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:37:28.838Z,1753465048.838 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:37:42.572Z,1753465062.572 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:37:56.311Z,1753465076.311 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:38:09.641Z,1753465089.641 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:38:23.378Z,1753465103.378 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:38:37.519Z,1753465117.519 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:41:13.467Z,1753465273.467 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:41:28.419Z,1753465288.419 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:41:43.357Z,1753465303.357 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:41:58.305Z,1753465318.305 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:42:14.060Z,1753465334.060 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:42:29.010Z,1753465349.010 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:42:44.360Z,1753465364.360 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:42:59.713Z,1753465379.713 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T17:43:10.219Z,1753465390.219 [BPC1](ERROR): Battery stick #16 (s/n: 00F8) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T17:43:10.220Z,1753465390.220 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T17:43:10.221Z,1753465390.221 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-07-25T17:43:10.222Z,1753465390.222 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T17:43:10.222Z,1753465390.222 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T17:43:10.223Z,1753465390.223 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2025-07-25T17:43:10.224Z,1753465390.224 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 4.
2025-07-25T17:43:10.226Z,1753465390.226 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2025-07-25T17:51:31.211Z,1753465891.211 [keepstation:SurfaceComms] Running Loop=1
2025-07-25T17:51:31.211Z,1753465891.211 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-07-25T17:51:31.212Z,1753465891.212 [keepstation:SurfaceComms:A] Running Loop=1
2025-07-25T17:51:31.212Z,1753465891.212 [keepstation:SurfaceComms:A] Stopped
2025-07-25T17:51:31.212Z,1753465891.212 [keepstation:SurfaceComms:B] Running Loop=1
2025-07-25T17:51:31.212Z,1753465891.212 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-07-25T17:51:31.217Z,1753465891.217 [keepstation:NeedComms] Running Loop=1
2025-07-25T17:51:31.217Z,1753465891.217 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T17:51:31.217Z,1753465891.217 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T17:51:31.217Z,1753465891.217 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T17:51:31.218Z,1753465891.218 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T17:51:31.218Z,1753465891.218 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T17:51:31.218Z,1753465891.218 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T17:51:31.219Z,1753465891.219 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T17:51:31.219Z,1753465891.219 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T17:51:31.219Z,1753465891.219 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T17:51:31.220Z,1753465891.220 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T17:51:31.221Z,1753465891.221 [keepstation:NeedComms:A](INFO): last time_fix was: 1753464095.000000 second since 1970/01/01T00:00:00Z
2025-07-25T17:51:31.221Z,1753465891.221 [keepstation:NeedComms:A] Stopped
2025-07-25T17:51:31.598Z,1753465891.598 [keepstation:KeepStation:Dive] Stopped
2025-07-25T17:51:31.598Z,1753465891.598 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:KeepStation:Dive:A] Stopped
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:DiveCmd:StationKeep] Stopped
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:DiveCmd:StationKeep:A] Stopped
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped
2025-07-25T17:51:31.599Z,1753465891.599 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-07-25T17:53:34.610Z,1753466014.610 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T17:53:35.037Z,1753466015.037 [Radio_Surface](INFO): Powering up
2025-07-25T17:53:40.769Z,1753466020.769 [DataOverHttps](INFO): Radio surface powered ON.
2025-07-25T17:54:10.913Z,1753466050.913 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:54:42.053Z,1753466082.053 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:55:13.177Z,1753466113.177 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:55:44.309Z,1753466144.309 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:56:15.433Z,1753466175.433 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:56:19.061Z,1753466179.061 [NAL9602](INFO): SBD MO Status=2, MOMSN=26294, MT Status=2, MTMSN=0
2025-07-25T17:56:19.061Z,1753466179.061 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:56:30.773Z,1753466190.773 [NAL9602](INFO): SBD MO Status=1, MOMSN=26294, MT Status=0, MTMSN=0
2025-07-25T17:56:30.773Z,1753466190.773 [NAL9602](INFO): No messages in MT queue
2025-07-25T17:56:31.988Z,1753466191.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175636.00,A,3648.37892,N,12149.34230,W,0.194,196.53,250725,,,D*7D
2025-07-25T17:56:31.991Z,1753466191.991 [NAL9602](INFO): GPS fix at 20250725T175636: (36.806315, -121.822372)
2025-07-25T17:56:32.003Z,1753466192.003 [UniversalFixResidualReporter](INFO): Fix residual: 40.2 %DT, over the last 638.3 m. Residual distance 256.9 m at bearing -3.2 degrees. Fix at (36.8063, -121.8224) with 416.3 m made good.
2025-07-25T17:56:32.010Z,1753466192.010 [keepstation:NeedComms:C] Stopped
2025-07-25T17:56:32.010Z,1753466192.010 [keepstation:NeedComms:D] Running Loop=1
2025-07-25T17:56:46.569Z,1753466206.569 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T17:56:49.838Z,1753466209.838 [NAL9602](INFO): SBD MO Status=1, MOMSN=26295, MT Status=0, MTMSN=0
2025-07-25T17:56:49.885Z,1753466209.885 [NAL9602](INFO): Sent 94 bytes from file Logs/20250725T160334/Courier0025.lzma
2025-07-25T17:56:49.886Z,1753466209.886 [NAL9602](INFO): Packets left to send: 0
2025-07-25T17:57:03.230Z,1753466223.230 [NAL9602](INFO): SBD MO Status=1, MOMSN=26296, MT Status=0, MTMSN=0
2025-07-25T17:57:03.285Z,1753466223.285 [NAL9602](INFO): Sent 332 bytes from file Logs/20250725T160334/Express0026.lzma
2025-07-25T17:57:03.285Z,1753466223.285 [NAL9602](INFO): Packets left to send: 1
2025-07-25T17:57:12.605Z,1753466232.605 [NAL9602](INFO): SBD MO Status=1, MOMSN=26297, MT Status=0, MTMSN=0
2025-07-25T17:57:12.661Z,1753466232.661 [NAL9602](INFO): Sent 88 bytes from file Logs/20250725T160334/Express0026.lzma
2025-07-25T17:57:12.661Z,1753466232.661 [NAL9602](INFO): Packets left to send: 0
2025-07-25T17:57:18.326Z,1753466238.326 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2025-07-25T17:57:33.205Z,1753466253.205 [NAL9602](INFO): SBD MO Status=2, MOMSN=26298, MT Status=2, MTMSN=0
2025-07-25T17:57:33.205Z,1753466253.205 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T17:57:36.893Z,1753466256.893 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002958
2025-07-25T17:57:38.147Z,1753466258.147 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2025-07-25T17:57:38.162Z,1753466258.162 [keepstation:NeedComms:D] Stopped
2025-07-25T17:57:38.162Z,1753466258.162 [keepstation:NeedComms:E] Running Loop=1
2025-07-25T17:57:40.481Z,1753466260.481 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175744.00,A,3648.37483,N,12149.34462,W,0.447,206.65,250725,,,D*70
2025-07-25T17:57:40.483Z,1753466260.483 [NAL9602](INFO): GPS fix at 20250725T175744: (36.806247, -121.822410)
2025-07-25T17:57:40.517Z,1753466260.517 [keepstation:NeedComms:E] Stopped
2025-07-25T17:57:40.562Z,1753466260.562 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-07-25T17:57:40.562Z,1753466260.562 [keepstation:NeedComms] Stopped
2025-07-25T17:57:40.562Z,1753466260.562 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T17:57:40.562Z,1753466260.562 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T17:57:40.562Z,1753466260.562 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T17:57:40.922Z,1753466260.922 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B
2025-07-25T17:57:40.922Z,1753466260.922 [keepstation:SurfaceComms:B] Stopped
2025-07-25T17:57:40.923Z,1753466260.923 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-07-25T17:57:40.923Z,1753466260.923 [keepstation:SurfaceComms:setTransit] Running Loop=1
2025-07-25T17:57:40.923Z,1753466260.923 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit
2025-07-25T17:57:40.923Z,1753466260.923 [keepstation:SurfaceComms:setTransit:A] Running Loop=1
2025-07-25T17:57:41.329Z,1753466261.329 [keepstation:SurfaceComms:setTransit] Stopped
2025-07-25T17:57:41.329Z,1753466261.329 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit
2025-07-25T17:57:41.329Z,1753466261.329 [keepstation:SurfaceComms:setTransit:A] Stopped
2025-07-25T17:57:41.330Z,1753466261.330 [keepstation:SurfaceComms:setStation] Running Loop=1
2025-07-25T17:57:41.330Z,1753466261.330 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation
2025-07-25T17:57:41.330Z,1753466261.330 [keepstation:SurfaceComms:setStation:A] Running Loop=1
2025-07-25T17:57:41.744Z,1753466261.744 [keepstation:SurfaceComms:setStation:A] Stopped
2025-07-25T17:57:41.744Z,1753466261.744 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation
2025-07-25T17:57:41.744Z,1753466261.744 [keepstation:SurfaceComms:setStation] Stopped
2025-07-25T17:57:41.744Z,1753466261.744 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation
2025-07-25T17:57:41.744Z,1753466261.744 [keepstation:SurfaceComms:setSink] Running Loop=1
2025-07-25T17:57:41.744Z,1753466261.744 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink
2025-07-25T17:57:41.744Z,1753466261.744 [keepstation:SurfaceComms:setSink:A] Running Loop=1
2025-07-25T17:57:42.119Z,1753466262.119 [keepstation:KeepStation:Dive] Running Loop=1
2025-07-25T17:57:42.119Z,1753466262.119 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive
2025-07-25T17:57:42.119Z,1753466262.119 [keepstation:KeepStation:Dive:A] Running Loop=1
2025-07-25T17:57:42.119Z,1753466262.119 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A
2025-07-25T17:57:42.120Z,1753466262.120 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-07-25T17:57:42.120Z,1753466262.120 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep
2025-07-25T17:57:42.120Z,1753466262.120 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-07-25T17:57:42.120Z,1753466262.120 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-07-25T17:57:42.120Z,1753466262.120 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize.
2025-07-25T17:57:42.120Z,1753466262.120 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-07-25T17:57:42.120Z,1753466262.120 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-07-25T17:57:42.126Z,1753466262.126 [keepstation:SurfaceComms:setSink] Stopped
2025-07-25T17:57:42.126Z,1753466262.126 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink
2025-07-25T17:57:42.126Z,1753466262.126 [keepstation:SurfaceComms:setSink:A] Stopped
2025-07-25T17:57:42.126Z,1753466262.126 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms
2025-07-25T17:57:42.126Z,1753466262.126 [keepstation:SurfaceComms] Stopped
2025-07-25T17:57:42.127Z,1753466262.127 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-07-25T17:58:12.395Z,1753466292.395 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T18:00:11.582Z,1753466411.582 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:00:36.137Z,1753466436.137 [Radio_Surface](INFO): Powering down
2025-07-25T18:00:42.705Z,1753466442.705 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:00:43.709Z,1753466443.709 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-07-25T18:02:00.042Z,1753466520.042 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.182816
2025-07-25T18:27:40.752Z,1753468060.752 [keepstation:SurfaceComms] Running Loop=1
2025-07-25T18:27:40.752Z,1753468060.752 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-07-25T18:27:40.753Z,1753468060.753 [keepstation:SurfaceComms:A] Running Loop=1
2025-07-25T18:27:40.753Z,1753468060.753 [keepstation:SurfaceComms:A] Stopped
2025-07-25T18:27:40.753Z,1753468060.753 [keepstation:SurfaceComms:B] Running Loop=1
2025-07-25T18:27:40.754Z,1753468060.754 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-07-25T18:27:40.758Z,1753468060.758 [keepstation:NeedComms] Running Loop=1
2025-07-25T18:27:40.758Z,1753468060.758 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T18:27:40.758Z,1753468060.758 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T18:27:40.758Z,1753468060.758 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T18:27:40.758Z,1753468060.758 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T18:27:40.759Z,1753468060.759 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T18:27:40.759Z,1753468060.759 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T18:27:40.759Z,1753468060.759 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T18:27:40.760Z,1753468060.760 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T18:27:40.760Z,1753468060.760 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T18:27:40.760Z,1753468060.760 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T18:27:40.762Z,1753468060.762 [keepstation:NeedComms:A](INFO): last time_fix was: 1753466264.000000 second since 1970/01/01T00:00:00Z
2025-07-25T18:27:40.762Z,1753468060.762 [keepstation:NeedComms:A] Stopped
2025-07-25T18:27:41.161Z,1753468061.161 [keepstation:KeepStation:Dive] Stopped
2025-07-25T18:27:41.161Z,1753468061.161 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive
2025-07-25T18:27:41.161Z,1753468061.161 [keepstation:KeepStation:Dive:A] Stopped
2025-07-25T18:27:41.161Z,1753468061.161 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A
2025-07-25T18:27:41.162Z,1753468061.162 [keepstation:DiveCmd:StationKeep] Stopped
2025-07-25T18:27:41.162Z,1753468061.162 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep
2025-07-25T18:27:41.162Z,1753468061.162 [keepstation:DiveCmd:StationKeep:A] Stopped
2025-07-25T18:27:41.162Z,1753468061.162 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped
2025-07-25T18:27:41.162Z,1753468061.162 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped
2025-07-25T18:27:41.162Z,1753468061.162 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-07-25T18:29:48.959Z,1753468188.959 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T18:29:49.497Z,1753468189.497 [Radio_Surface](INFO): Powering up
2025-07-25T18:29:54.969Z,1753468194.969 [DataOverHttps](INFO): Radio surface powered ON.
2025-07-25T18:30:25.089Z,1753468225.089 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:30:39.048Z,1753468239.048 [NAL9602](INFO): SBD MO Status=0, MOMSN=26298, MT Status=0, MTMSN=0
2025-07-25T18:30:39.048Z,1753468239.048 [NAL9602](INFO): No messages in MT queue
2025-07-25T18:30:40.259Z,1753468240.259 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183044.00,A,3648.37305,N,12149.27865,W,0.447,194.85,250725,,,D*78
2025-07-25T18:30:40.261Z,1753468240.261 [NAL9602](INFO): GPS fix at 20250725T183044: (36.806218, -121.821311)
2025-07-25T18:30:40.278Z,1753468240.278 [keepstation:NeedComms:C] Stopped
2025-07-25T18:30:40.279Z,1753468240.279 [keepstation:NeedComms:D] Running Loop=1
2025-07-25T18:30:56.213Z,1753468256.213 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:30:56.923Z,1753468256.923 [NAL9602](INFO): SBD MO Status=1, MOMSN=26299, MT Status=0, MTMSN=0
2025-07-25T18:30:56.981Z,1753468256.981 [NAL9602](INFO): Sent 72 bytes from file Logs/20250725T160334/Courier0028.lzma
2025-07-25T18:30:56.981Z,1753468256.981 [NAL9602](INFO): Packets left to send: 0
2025-07-25T18:31:13.176Z,1753468273.176 [NAL9602](INFO): SBD MO Status=2, MOMSN=26300, MT Status=2, MTMSN=0
2025-07-25T18:31:13.176Z,1753468273.176 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T18:31:27.337Z,1753468287.337 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:31:39.137Z,1753468299.137 [NAL9602](INFO): SBD MO Status=2, MOMSN=26300, MT Status=2, MTMSN=0
2025-07-25T18:31:39.137Z,1753468299.137 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T18:31:58.461Z,1753468318.461 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:32:02.648Z,1753468322.648 [NAL9602](INFO): SBD MO Status=2, MOMSN=26300, MT Status=2, MTMSN=0
2025-07-25T18:32:02.648Z,1753468322.648 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T18:32:24.131Z,1753468344.131 [NAL9602](INFO): SBD MO Status=2, MOMSN=26300, MT Status=2, MTMSN=0
2025-07-25T18:32:24.131Z,1753468344.131 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T18:32:29.597Z,1753468349.597 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:32:46.019Z,1753468366.019 [NAL9602](INFO): SBD MO Status=1, MOMSN=26300, MT Status=0, MTMSN=0
2025-07-25T18:32:46.077Z,1753468366.077 [NAL9602](INFO): Sent 299 bytes from file Logs/20250725T160334/Express0029.lzma
2025-07-25T18:32:46.077Z,1753468366.077 [NAL9602](INFO): Packets left to send: 0
2025-07-25T18:32:58.953Z,1753468378.953 [NAL9602](INFO): SBD MO Status=2, MOMSN=26301, MT Status=2, MTMSN=0
2025-07-25T18:32:58.954Z,1753468378.954 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T18:33:00.721Z,1753468380.721 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:33:15.110Z,1753468395.110 [NAL9602](INFO): SBD MO Status=0, MOMSN=26301, MT Status=0, MTMSN=0
2025-07-25T18:33:15.206Z,1753468395.206 [keepstation:NeedComms:D] Stopped
2025-07-25T18:33:15.206Z,1753468395.206 [keepstation:NeedComms:E] Running Loop=1
2025-07-25T18:33:17.536Z,1753468397.536 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183321.00,A,3648.36456,N,12149.28297,W,0.486,238.31,250725,,,D*77
2025-07-25T18:33:17.538Z,1753468397.538 [NAL9602](INFO): GPS fix at 20250725T183321: (36.806076, -121.821383)
2025-07-25T18:33:17.554Z,1753468397.554 [keepstation:NeedComms:E] Stopped
2025-07-25T18:33:17.555Z,1753468397.555 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-07-25T18:33:17.555Z,1753468397.555 [keepstation:NeedComms] Stopped
2025-07-25T18:33:17.555Z,1753468397.555 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T18:33:17.555Z,1753468397.555 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T18:33:17.555Z,1753468397.555 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T18:33:17.971Z,1753468397.971 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B
2025-07-25T18:33:17.971Z,1753468397.971 [keepstation:SurfaceComms:B] Stopped
2025-07-25T18:33:17.971Z,1753468397.971 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-07-25T18:33:17.971Z,1753468397.971 [keepstation:SurfaceComms:setTransit] Running Loop=1
2025-07-25T18:33:17.972Z,1753468397.972 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit
2025-07-25T18:33:17.972Z,1753468397.972 [keepstation:SurfaceComms:setTransit:A] Running Loop=1
2025-07-25T18:33:18.352Z,1753468398.352 [keepstation:SurfaceComms:setTransit] Stopped
2025-07-25T18:33:18.352Z,1753468398.352 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit
2025-07-25T18:33:18.352Z,1753468398.352 [keepstation:SurfaceComms:setTransit:A] Stopped
2025-07-25T18:33:18.352Z,1753468398.352 [keepstation:SurfaceComms:setStation] Running Loop=1
2025-07-25T18:33:18.352Z,1753468398.352 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation
2025-07-25T18:33:18.352Z,1753468398.352 [keepstation:SurfaceComms:setStation:A] Running Loop=1
2025-07-25T18:33:18.768Z,1753468398.768 [keepstation:SurfaceComms:setStation:A] Stopped
2025-07-25T18:33:18.768Z,1753468398.768 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation
2025-07-25T18:33:18.768Z,1753468398.768 [keepstation:SurfaceComms:setStation] Stopped
2025-07-25T18:33:18.768Z,1753468398.768 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation
2025-07-25T18:33:18.768Z,1753468398.768 [keepstation:SurfaceComms:setSink] Running Loop=1
2025-07-25T18:33:18.768Z,1753468398.768 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink
2025-07-25T18:33:18.768Z,1753468398.768 [keepstation:SurfaceComms:setSink:A] Running Loop=1
2025-07-25T18:33:19.164Z,1753468399.164 [keepstation:KeepStation:Dive] Running Loop=1
2025-07-25T18:33:19.164Z,1753468399.164 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive
2025-07-25T18:33:19.164Z,1753468399.164 [keepstation:KeepStation:Dive:A] Running Loop=1
2025-07-25T18:33:19.164Z,1753468399.164 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A
2025-07-25T18:33:19.165Z,1753468399.165 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-07-25T18:33:19.165Z,1753468399.165 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep
2025-07-25T18:33:19.165Z,1753468399.165 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-07-25T18:33:19.165Z,1753468399.165 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-07-25T18:33:19.166Z,1753468399.166 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize.
2025-07-25T18:33:19.166Z,1753468399.166 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-07-25T18:33:19.166Z,1753468399.166 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-07-25T18:33:19.167Z,1753468399.167 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Rest->Waypoint
2025-07-25T18:33:19.168Z,1753468399.168 [keepstation:SurfaceComms:setSink] Stopped
2025-07-25T18:33:19.168Z,1753468399.168 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink
2025-07-25T18:33:19.169Z,1753468399.169 [keepstation:SurfaceComms:setSink:A] Stopped
2025-07-25T18:33:19.169Z,1753468399.169 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms
2025-07-25T18:33:19.169Z,1753468399.169 [keepstation:SurfaceComms] Stopped
2025-07-25T18:33:19.169Z,1753468399.169 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-07-25T18:33:31.849Z,1753468411.849 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:33:49.385Z,1753468429.385 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T18:34:03.185Z,1753468443.185 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2025-07-25T18:34:34.310Z,1753468474.310 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:34:49.781Z,1753468489.781 [Radio_Surface](INFO): Powering down
2025-07-25T18:35:05.433Z,1753468505.433 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T18:35:06.438Z,1753468506.438 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-07-25T18:41:43.072Z,1753468903.072 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Waypoint->Rest
2025-07-25T18:44:24.254Z,1753469064.254 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:46:46.462Z,1753469206.462 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:46:53.343Z,1753469213.343 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:47:09.497Z,1753469229.497 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:47:24.439Z,1753469244.439 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:47:39.385Z,1753469259.385 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:47:54.738Z,1753469274.738 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:48:09.686Z,1753469289.686 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:48:24.633Z,1753469304.633 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:48:39.984Z,1753469319.984 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:48:55.337Z,1753469335.337 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:51:30.084Z,1753469490.084 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:51:44.229Z,1753469504.229 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:51:57.954Z,1753469517.954 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:52:11.689Z,1753469531.689 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:52:25.426Z,1753469545.426 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:52:39.160Z,1753469559.160 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:52:52.899Z,1753469572.899 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:53:07.049Z,1753469587.049 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:53:20.776Z,1753469600.776 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:53:34.510Z,1753469614.510 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:56:10.453Z,1753469770.453 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:56:25.806Z,1753469785.806 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:56:40.754Z,1753469800.754 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:56:55.297Z,1753469815.297 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:57:10.661Z,1753469830.661 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:57:25.597Z,1753469845.597 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:57:40.949Z,1753469860.949 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:57:56.300Z,1753469876.300 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:58:12.058Z,1753469892.058 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T18:58:26.600Z,1753469906.600 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2025-07-25T19:00:48.809Z,1753470048.809 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:00:55.689Z,1753470055.689 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:01:09.817Z,1753470069.817 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:01:23.558Z,1753470083.558 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:01:37.291Z,1753470097.291 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:01:51.428Z,1753470111.428 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:02:05.571Z,1753470125.571 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:02:19.715Z,1753470139.715 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:02:33.445Z,1753470153.445 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:02:47.587Z,1753470167.587 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:03:01.728Z,1753470181.728 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:03:17.902Z,1753470197.902 [keepstation:SurfaceComms] Running Loop=1
2025-07-25T19:03:17.903Z,1753470197.903 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-07-25T19:03:17.903Z,1753470197.903 [keepstation:SurfaceComms:A] Running Loop=1
2025-07-25T19:03:17.903Z,1753470197.903 [keepstation:SurfaceComms:A] Stopped
2025-07-25T19:03:17.903Z,1753470197.903 [keepstation:SurfaceComms:B] Running Loop=1
2025-07-25T19:03:17.903Z,1753470197.903 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-07-25T19:03:18.311Z,1753470198.311 [keepstation:KeepStation:Dive] Stopped
2025-07-25T19:03:18.311Z,1753470198.311 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive
2025-07-25T19:03:18.311Z,1753470198.311 [keepstation:KeepStation:Dive:A] Stopped
2025-07-25T19:03:18.311Z,1753470198.311 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A
2025-07-25T19:03:18.311Z,1753470198.311 [keepstation:DiveCmd:StationKeep] Stopped
2025-07-25T19:03:18.311Z,1753470198.311 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep
2025-07-25T19:03:18.311Z,1753470198.311 [keepstation:DiveCmd:StationKeep:A] Stopped
2025-07-25T19:03:18.312Z,1753470198.312 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped
2025-07-25T19:03:18.312Z,1753470198.312 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped
2025-07-25T19:03:18.312Z,1753470198.312 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-07-25T19:03:18.314Z,1753470198.314 [keepstation:NeedComms] Running Loop=1
2025-07-25T19:03:18.314Z,1753470198.314 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T19:03:18.314Z,1753470198.314 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T19:03:18.314Z,1753470198.314 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T19:03:18.314Z,1753470198.314 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T19:03:18.315Z,1753470198.315 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T19:03:18.315Z,1753470198.315 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T19:03:18.315Z,1753470198.315 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T19:03:18.316Z,1753470198.316 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T19:03:18.316Z,1753470198.316 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T19:03:18.316Z,1753470198.316 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T19:03:18.318Z,1753470198.318 [keepstation:NeedComms:A](INFO): last time_fix was: 1753468401.000000 second since 1970/01/01T00:00:00Z
2025-07-25T19:03:18.318Z,1753470198.318 [keepstation:NeedComms:A] Stopped
2025-07-25T19:05:06.699Z,1753470306.699 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T19:05:07.165Z,1753470307.165 [Radio_Surface](INFO): Powering up
2025-07-25T19:05:12.941Z,1753470312.941 [DataOverHttps](INFO): Radio surface powered ON.
2025-07-25T19:05:24.869Z,1753470324.869 [NAL9602](INFO): SBD MO Status=0, MOMSN=26302, MT Status=0, MTMSN=0
2025-07-25T19:05:24.869Z,1753470324.869 [NAL9602](INFO): No messages in MT queue
2025-07-25T19:05:26.086Z,1753470326.086 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190530.00,A,3648.41327,N,12149.46369,W,0.486,11.12,250725,,,A*47
2025-07-25T19:05:26.088Z,1753470326.088 [NAL9602](INFO): GPS fix at 20250725T190530: (36.806888, -121.824395)
2025-07-25T19:05:26.101Z,1753470326.101 [UniversalFixResidualReporter](INFO): Fix residual: 34.8 %DT, over the last 581.6 m. Residual distance 202.2 m at bearing -40.3 degrees. Fix at (36.8069, -121.8244) with 282.9 m made good.
2025-07-25T19:05:26.106Z,1753470326.106 [keepstation:NeedComms:C] Stopped
2025-07-25T19:05:26.106Z,1753470326.106 [keepstation:NeedComms:D] Running Loop=1
2025-07-25T19:05:32.618Z,1753470332.618 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:05:39.079Z,1753470339.079 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:05:43.075Z,1753470343.075 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:05:54.429Z,1753470354.429 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:05:58.891Z,1753470358.891 [NAL9602](INFO): SBD MO Status=2, MOMSN=26303, MT Status=2, MTMSN=0
2025-07-25T19:05:58.891Z,1753470358.891 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T19:06:10.721Z,1753470370.721 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:06:14.206Z,1753470374.206 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:06:26.461Z,1753470386.461 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:06:32.527Z,1753470392.527 [NAL9602](INFO): SBD MO Status=1, MOMSN=26303, MT Status=0, MTMSN=0
2025-07-25T19:06:32.585Z,1753470392.585 [NAL9602](INFO): Sent 83 bytes from file Logs/20250725T160334/Courier0031.lzma
2025-07-25T19:06:32.585Z,1753470392.585 [NAL9602](INFO): Packets left to send: 0
2025-07-25T19:06:41.903Z,1753470401.903 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:06:45.329Z,1753470405.329 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:06:46.757Z,1753470406.757 [NAL9602](INFO): SBD MO Status=1, MOMSN=26304, MT Status=0, MTMSN=0
2025-07-25T19:06:46.805Z,1753470406.805 [NAL9602](INFO): Sent 332 bytes from file Logs/20250725T160334/Express0032.lzma
2025-07-25T19:06:46.805Z,1753470406.805 [NAL9602](INFO): Packets left to send: 1
2025-07-25T19:06:54.101Z,1753470414.101 [NAL9602](INFO): SBD MO Status=1, MOMSN=26305, MT Status=0, MTMSN=0
2025-07-25T19:06:54.149Z,1753470414.149 [NAL9602](INFO): Sent 51 bytes from file Logs/20250725T160334/Express0032.lzma
2025-07-25T19:06:54.150Z,1753470414.150 [NAL9602](INFO): Packets left to send: 0
2025-07-25T19:06:56.915Z,1753470416.915 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:07:02.581Z,1753470422.581 [NAL9602](INFO): SBD MO Status=0, MOMSN=26306, MT Status=0, MTMSN=0
2025-07-25T19:07:02.667Z,1753470422.667 [keepstation:NeedComms:D] Stopped
2025-07-25T19:07:02.668Z,1753470422.668 [keepstation:NeedComms:E] Running Loop=1
2025-07-25T19:07:04.999Z,1753470424.999 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190709.00,A,3648.41333,N,12149.46445,W,0.408,38.17,250725,,,D*4E
2025-07-25T19:07:05.001Z,1753470425.001 [NAL9602](INFO): GPS fix at 20250725T190709: (36.806889, -121.824408)
2025-07-25T19:07:05.022Z,1753470425.022 [keepstation:NeedComms:E] Stopped
2025-07-25T19:07:05.023Z,1753470425.023 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-07-25T19:07:05.023Z,1753470425.023 [keepstation:NeedComms] Stopped
2025-07-25T19:07:05.023Z,1753470425.023 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T19:07:05.023Z,1753470425.023 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T19:07:05.023Z,1753470425.023 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T19:07:05.442Z,1753470425.442 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B
2025-07-25T19:07:05.442Z,1753470425.442 [keepstation:SurfaceComms:B] Stopped
2025-07-25T19:07:05.442Z,1753470425.442 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-07-25T19:07:05.442Z,1753470425.442 [keepstation:SurfaceComms:setTransit] Running Loop=1
2025-07-25T19:07:05.443Z,1753470425.443 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit
2025-07-25T19:07:05.443Z,1753470425.443 [keepstation:SurfaceComms:setTransit:A] Running Loop=1
2025-07-25T19:07:05.842Z,1753470425.842 [keepstation:SurfaceComms:setTransit] Stopped
2025-07-25T19:07:05.842Z,1753470425.842 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit
2025-07-25T19:07:05.842Z,1753470425.842 [keepstation:SurfaceComms:setTransit:A] Stopped
2025-07-25T19:07:05.842Z,1753470425.842 [keepstation:SurfaceComms:setStation] Running Loop=1
2025-07-25T19:07:05.843Z,1753470425.843 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation
2025-07-25T19:07:05.843Z,1753470425.843 [keepstation:SurfaceComms:setStation:A] Running Loop=1
2025-07-25T19:07:06.228Z,1753470426.228 [keepstation:SurfaceComms:setStation:A] Stopped
2025-07-25T19:07:06.229Z,1753470426.229 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation
2025-07-25T19:07:06.229Z,1753470426.229 [keepstation:SurfaceComms:setStation] Stopped
2025-07-25T19:07:06.229Z,1753470426.229 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation
2025-07-25T19:07:06.229Z,1753470426.229 [keepstation:SurfaceComms:setSink] Running Loop=1
2025-07-25T19:07:06.229Z,1753470426.229 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink
2025-07-25T19:07:06.229Z,1753470426.229 [keepstation:SurfaceComms:setSink:A] Running Loop=1
2025-07-25T19:07:06.638Z,1753470426.638 [keepstation:KeepStation:Dive] Running Loop=1
2025-07-25T19:07:06.638Z,1753470426.638 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive
2025-07-25T19:07:06.638Z,1753470426.638 [keepstation:KeepStation:Dive:A] Running Loop=1
2025-07-25T19:07:06.638Z,1753470426.638 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A
2025-07-25T19:07:06.638Z,1753470426.638 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-07-25T19:07:06.639Z,1753470426.639 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep
2025-07-25T19:07:06.639Z,1753470426.639 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-07-25T19:07:06.639Z,1753470426.639 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-07-25T19:07:06.639Z,1753470426.639 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize.
2025-07-25T19:07:06.639Z,1753470426.639 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-07-25T19:07:06.639Z,1753470426.639 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-07-25T19:07:06.641Z,1753470426.641 [keepstation:SurfaceComms:setSink] Stopped
2025-07-25T19:07:06.641Z,1753470426.641 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink
2025-07-25T19:07:06.641Z,1753470426.641 [keepstation:SurfaceComms:setSink:A] Stopped
2025-07-25T19:07:06.641Z,1753470426.641 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms
2025-07-25T19:07:06.641Z,1753470426.641 [keepstation:SurfaceComms] Stopped
2025-07-25T19:07:06.641Z,1753470426.641 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-07-25T19:07:11.865Z,1753470431.865 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:07:16.453Z,1753470436.453 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:07:26.818Z,1753470446.818 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:07:37.321Z,1753470457.321 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T19:07:41.759Z,1753470461.759 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:07:47.577Z,1753470467.577 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:08:18.705Z,1753470498.705 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:08:49.829Z,1753470529.829 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:09:20.966Z,1753470560.966 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:09:27.817Z,1753470567.817 [Radio_Surface](INFO): Powering down
2025-07-25T19:09:52.093Z,1753470592.093 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:09:53.097Z,1753470593.097 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-07-25T19:10:10.833Z,1753470610.833 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:10:17.298Z,1753470617.298 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:10:31.034Z,1753470631.034 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:10:45.173Z,1753470645.173 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:10:58.506Z,1753470658.506 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:11:12.242Z,1753470672.242 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:11:26.381Z,1753470686.381 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:11:40.117Z,1753470700.117 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:11:54.256Z,1753470714.256 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:12:07.589Z,1753470727.589 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:12:21.324Z,1753470741.324 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T19:13:42.940Z,1753470822.940 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-07-25T19:14:11.215Z,1753470851.215 [BPC1](ERROR): Battery stick #16 (s/n: 00F8) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T19:14:11.216Z,1753470851.216 [BPC1](FAULT): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T19:14:11.216Z,1753470851.216 [BPC1](FAULT): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-07-25T19:14:11.217Z,1753470851.217 [BPC1](FAULT): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T19:14:11.218Z,1753470851.218 [BPC1](FAULT): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-07-25T19:14:11.219Z,1753470851.219 [BPC1](FAULT): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2025-07-25T19:14:11.219Z,1753470851.219 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 4.
2025-07-25T19:14:11.245Z,1753470851.245 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2025-07-25T19:37:05.243Z,1753472225.243 [keepstation:SurfaceComms] Running Loop=1
2025-07-25T19:37:05.243Z,1753472225.243 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-07-25T19:37:05.244Z,1753472225.244 [keepstation:SurfaceComms:A] Running Loop=1
2025-07-25T19:37:05.244Z,1753472225.244 [keepstation:SurfaceComms:A] Stopped
2025-07-25T19:37:05.244Z,1753472225.244 [keepstation:SurfaceComms:B] Running Loop=1
2025-07-25T19:37:05.244Z,1753472225.244 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-07-25T19:37:05.250Z,1753472225.250 [keepstation:NeedComms] Running Loop=1
2025-07-25T19:37:05.250Z,1753472225.250 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T19:37:05.250Z,1753472225.250 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T19:37:05.250Z,1753472225.250 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T19:37:05.250Z,1753472225.250 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T19:37:05.251Z,1753472225.251 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T19:37:05.251Z,1753472225.251 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T19:37:05.252Z,1753472225.252 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T19:37:05.252Z,1753472225.252 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T19:37:05.252Z,1753472225.252 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T19:37:05.252Z,1753472225.252 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T19:37:05.254Z,1753472225.254 [keepstation:NeedComms:A](INFO): last time_fix was: 1753470429.000000 second since 1970/01/01T00:00:00Z
2025-07-25T19:37:05.254Z,1753472225.254 [keepstation:NeedComms:A] Stopped
2025-07-25T19:37:05.655Z,1753472225.655 [keepstation:KeepStation:Dive] Stopped
2025-07-25T19:37:05.655Z,1753472225.655 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive
2025-07-25T19:37:05.655Z,1753472225.655 [keepstation:KeepStation:Dive:A] Stopped
2025-07-25T19:37:05.655Z,1753472225.655 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A
2025-07-25T19:37:05.656Z,1753472225.656 [keepstation:DiveCmd:StationKeep] Stopped
2025-07-25T19:37:05.656Z,1753472225.656 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep
2025-07-25T19:37:05.656Z,1753472225.656 [keepstation:DiveCmd:StationKeep:A] Stopped
2025-07-25T19:37:05.656Z,1753472225.656 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped
2025-07-25T19:37:05.656Z,1753472225.656 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped
2025-07-25T19:37:05.656Z,1753472225.656 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-07-25T19:39:13.007Z,1753472353.007 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T19:39:13.505Z,1753472353.505 [Radio_Surface](INFO): Powering up
2025-07-25T19:39:19.329Z,1753472359.329 [DataOverHttps](INFO): Radio surface powered ON.
2025-07-25T19:39:30.361Z,1753472370.361 [NAL9602](INFO): SBD MO Status=0, MOMSN=26307, MT Status=0, MTMSN=0
2025-07-25T19:39:30.361Z,1753472370.361 [NAL9602](INFO): No messages in MT queue
2025-07-25T19:39:31.577Z,1753472371.577 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193936.00,A,3648.37359,N,12149.46767,W,0.875,255.98,250725,,,A*7C
2025-07-25T19:39:31.579Z,1753472371.579 [NAL9602](INFO): GPS fix at 20250725T193936: (36.806227, -121.824461)
2025-07-25T19:39:31.621Z,1753472371.621 [keepstation:NeedComms:C] Stopped
2025-07-25T19:39:31.621Z,1753472371.621 [keepstation:NeedComms:D] Running Loop=1
2025-07-25T19:39:49.449Z,1753472389.449 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:40:02.398Z,1753472402.398 [NAL9602](INFO): SBD MO Status=1, MOMSN=26308, MT Status=0, MTMSN=0
2025-07-25T19:40:02.453Z,1753472402.453 [NAL9602](INFO): Sent 84 bytes from file Logs/20250725T160334/Courier0034.lzma
2025-07-25T19:40:02.453Z,1753472402.453 [NAL9602](INFO): Packets left to send: 0
2025-07-25T19:40:13.414Z,1753472413.414 [NAL9602](INFO): SBD MO Status=1, MOMSN=26309, MT Status=0, MTMSN=0
2025-07-25T19:40:13.461Z,1753472413.461 [NAL9602](INFO): Sent 332 bytes from file Logs/20250725T160334/Express0035.lzma
2025-07-25T19:40:13.461Z,1753472413.461 [NAL9602](INFO): Packets left to send: 1
2025-07-25T19:40:20.573Z,1753472420.573 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:40:36.126Z,1753472436.126 [NAL9602](INFO): SBD MO Status=2, MOMSN=26310, MT Status=2, MTMSN=0
2025-07-25T19:40:36.126Z,1753472436.126 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T19:40:51.705Z,1753472451.705 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:40:58.845Z,1753472458.845 [NAL9602](INFO): SBD MO Status=1, MOMSN=26310, MT Status=0, MTMSN=0
2025-07-25T19:40:58.893Z,1753472458.893 [NAL9602](INFO): Sent 130 bytes from file Logs/20250725T160334/Express0035.lzma
2025-07-25T19:40:58.893Z,1753472458.893 [NAL9602](INFO): Packets left to send: 0
2025-07-25T19:41:09.355Z,1753472469.355 [NAL9602](INFO): SBD MO Status=0, MOMSN=26311, MT Status=0, MTMSN=0
2025-07-25T19:41:09.478Z,1753472469.478 [keepstation:NeedComms:D] Stopped
2025-07-25T19:41:09.478Z,1753472469.478 [keepstation:NeedComms:E] Running Loop=1
2025-07-25T19:41:11.778Z,1753472471.778 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194116.00,A,3648.36828,N,12149.47535,W,0.486,192.38,250725,,,A*7B
2025-07-25T19:41:11.780Z,1753472471.780 [NAL9602](INFO): GPS fix at 20250725T194116: (36.806138, -121.824589)
2025-07-25T19:41:11.818Z,1753472471.818 [keepstation:NeedComms:E] Stopped
2025-07-25T19:41:11.819Z,1753472471.819 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-07-25T19:41:11.819Z,1753472471.819 [keepstation:NeedComms] Stopped
2025-07-25T19:41:11.819Z,1753472471.819 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T19:41:11.819Z,1753472471.819 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T19:41:11.819Z,1753472471.819 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T19:41:12.210Z,1753472472.210 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B
2025-07-25T19:41:12.210Z,1753472472.210 [keepstation:SurfaceComms:B] Stopped
2025-07-25T19:41:12.210Z,1753472472.210 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-07-25T19:41:12.210Z,1753472472.210 [keepstation:SurfaceComms:setTransit] Running Loop=1
2025-07-25T19:41:12.210Z,1753472472.210 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit
2025-07-25T19:41:12.211Z,1753472472.211 [keepstation:SurfaceComms:setTransit:A] Running Loop=1
2025-07-25T19:41:12.604Z,1753472472.604 [keepstation:SurfaceComms:setTransit] Stopped
2025-07-25T19:41:12.604Z,1753472472.604 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit
2025-07-25T19:41:12.604Z,1753472472.604 [keepstation:SurfaceComms:setTransit:A] Stopped
2025-07-25T19:41:12.604Z,1753472472.604 [keepstation:SurfaceComms:setStation] Running Loop=1
2025-07-25T19:41:12.605Z,1753472472.605 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation
2025-07-25T19:41:12.605Z,1753472472.605 [keepstation:SurfaceComms:setStation:A] Running Loop=1
2025-07-25T19:41:12.996Z,1753472472.996 [keepstation:SurfaceComms:setStation:A] Stopped
2025-07-25T19:41:12.996Z,1753472472.996 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation
2025-07-25T19:41:12.996Z,1753472472.996 [keepstation:SurfaceComms:setStation] Stopped
2025-07-25T19:41:12.996Z,1753472472.996 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation
2025-07-25T19:41:12.996Z,1753472472.996 [keepstation:SurfaceComms:setSink] Running Loop=1
2025-07-25T19:41:12.996Z,1753472472.996 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink
2025-07-25T19:41:12.996Z,1753472472.996 [keepstation:SurfaceComms:setSink:A] Running Loop=1
2025-07-25T19:41:13.407Z,1753472473.407 [keepstation:KeepStation:Dive] Running Loop=1
2025-07-25T19:41:13.407Z,1753472473.407 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive
2025-07-25T19:41:13.407Z,1753472473.407 [keepstation:KeepStation:Dive:A] Running Loop=1
2025-07-25T19:41:13.407Z,1753472473.407 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A
2025-07-25T19:41:13.408Z,1753472473.408 [keepstation:DiveCmd:StationKeep] Running Loop=1
2025-07-25T19:41:13.408Z,1753472473.408 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep
2025-07-25T19:41:13.408Z,1753472473.408 [keepstation:DiveCmd:StationKeep:A] Running Loop=1
2025-07-25T19:41:13.408Z,1753472473.408 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1
2025-07-25T19:41:13.408Z,1753472473.408 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize.
2025-07-25T19:41:13.408Z,1753472473.408 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1
2025-07-25T19:41:13.408Z,1753472473.408 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-07-25T19:41:13.410Z,1753472473.410 [keepstation:SurfaceComms:setSink] Stopped
2025-07-25T19:41:13.410Z,1753472473.410 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink
2025-07-25T19:41:13.410Z,1753472473.410 [keepstation:SurfaceComms:setSink:A] Stopped
2025-07-25T19:41:13.411Z,1753472473.411 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms
2025-07-25T19:41:13.411Z,1753472473.411 [keepstation:SurfaceComms] Stopped
2025-07-25T19:41:13.411Z,1753472473.411 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-07-25T19:41:22.829Z,1753472482.829 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:41:44.497Z,1753472504.497 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T19:41:53.954Z,1753472513.954 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:42:25.077Z,1753472545.077 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:42:56.201Z,1753472576.201 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:43:27.325Z,1753472607.325 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:43:45.397Z,1753472625.397 [Radio_Surface](INFO): Powering down
2025-07-25T19:43:58.454Z,1753472638.454 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T19:43:59.457Z,1753472639.457 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-07-25T20:11:12.019Z,1753474272.019 [keepstation:SurfaceComms] Running Loop=1
2025-07-25T20:11:12.019Z,1753474272.019 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-07-25T20:11:12.019Z,1753474272.019 [keepstation:SurfaceComms:A] Running Loop=1
2025-07-25T20:11:12.019Z,1753474272.019 [keepstation:SurfaceComms:A] Stopped
2025-07-25T20:11:12.019Z,1753474272.019 [keepstation:SurfaceComms:B] Running Loop=1
2025-07-25T20:11:12.020Z,1753474272.020 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-07-25T20:11:12.022Z,1753474272.022 [keepstation:NeedComms] Running Loop=1
2025-07-25T20:11:12.022Z,1753474272.022 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-07-25T20:11:12.022Z,1753474272.022 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-07-25T20:11:12.022Z,1753474272.022 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T20:11:12.022Z,1753474272.022 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-07-25T20:11:12.023Z,1753474272.023 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-07-25T20:11:12.023Z,1753474272.023 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-07-25T20:11:12.023Z,1753474272.023 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-07-25T20:11:12.024Z,1753474272.024 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T20:11:12.024Z,1753474272.024 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T20:11:12.024Z,1753474272.024 [keepstation:NeedComms:A] Running Loop=1
2025-07-25T20:11:12.026Z,1753474272.026 [keepstation:NeedComms:A](INFO): last time_fix was: 1753472476.000000 second since 1970/01/01T00:00:00Z
2025-07-25T20:11:12.026Z,1753474272.026 [keepstation:NeedComms:A] Stopped
2025-07-25T20:11:12.424Z,1753474272.424 [keepstation:KeepStation:Dive] Stopped
2025-07-25T20:11:12.424Z,1753474272.424 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive
2025-07-25T20:11:12.424Z,1753474272.424 [keepstation:KeepStation:Dive:A] Stopped
2025-07-25T20:11:12.424Z,1753474272.424 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A
2025-07-25T20:11:12.425Z,1753474272.425 [keepstation:DiveCmd:StationKeep] Stopped
2025-07-25T20:11:12.425Z,1753474272.425 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep
2025-07-25T20:11:12.425Z,1753474272.425 [keepstation:DiveCmd:StationKeep:A] Stopped
2025-07-25T20:11:12.425Z,1753474272.425 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped
2025-07-25T20:11:12.425Z,1753474272.425 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped
2025-07-25T20:11:12.425Z,1753474272.425 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-07-25T20:13:17.768Z,1753474397.768 [keepstation:NeedComms:C] Running Loop=1
2025-07-25T20:13:18.222Z,1753474398.222 [Radio_Surface](INFO): Powering up
2025-07-25T20:13:23.757Z,1753474403.757 [DataOverHttps](INFO): Radio surface powered ON.
2025-07-25T20:13:45.221Z,1753474425.221 [NAL9602](INFO): SBD MO Status=2, MOMSN=26312, MT Status=2, MTMSN=0
2025-07-25T20:13:45.228Z,1753474425.228 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:13:53.877Z,1753474433.877 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:14:10.680Z,1753474450.680 [keepstation](INFO): Timed out from 2025-07-25T16:14:10.4Z
2025-07-25T20:14:10.680Z,1753474450.680 [MissionManager](INFO): keepstation is completed.
2025-07-25T20:14:10.681Z,1753474450.681 [MissionManager](INFO): Uninitializing Mission keepstation
2025-07-25T20:14:10.681Z,1753474450.681 [keepstation] Stopped
2025-07-25T20:14:10.681Z,1753474450.681 [keepstation](DEBUG): Aggregate::uninitialize keepstation
2025-07-25T20:14:10.681Z,1753474450.681 [keepstation:NeedComms] Stopped
2025-07-25T20:14:10.681Z,1753474450.681 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-07-25T20:14:10.681Z,1753474450.681 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-07-25T20:14:10.681Z,1753474450.681 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-07-25T20:14:10.681Z,1753474450.681 [keepstation:NeedComms:C] Stopped
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes] Stopped
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:BackseatDriver] Stopped
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:BackseatDriver](DEBUG): Aggregate::uninitialize keepstation:BackseatDriver
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:BackseatDriver:A.BackseatDriver] Stopped
2025-07-25T20:14:10.682Z,1753474450.682 [keepstation:PowerOnly] Stopped
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:PowerOnly](DEBUG): Aggregate::uninitialize keepstation:PowerOnly
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:PowerOnly:E.Wait] Stopped
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:H.Pitch] Stopped
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:SurfaceComms] Stopped
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:SurfaceComms:B] Stopped
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:DiveCmd] Stopped
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:DiveCmd](DEBUG): Aggregate::uninitialize keepstation:DiveCmd
2025-07-25T20:14:10.683Z,1753474450.683 [keepstation:KeepStation] Stopped
2025-07-25T20:14:10.684Z,1753474450.684 [keepstation:KeepStation](DEBUG): Aggregate::uninitialize keepstation:KeepStation
2025-07-25T20:14:10.684Z,1753474450.684 [keepstation:KeepStation:B.Wait] Stopped
2025-07-25T20:14:10.684Z,1753474450.684 [keepstation:KeepStation:B.Wait](DEBUG): Uninitialize Wait Component.
2025-07-25T20:14:11.092Z,1753474451.092 [MissionManager](IMPORTANT): Started mission Default
2025-07-25T20:14:11.092Z,1753474451.092 [Default] Running Loop=1
2025-07-25T20:14:11.092Z,1753474451.092 [Default](DEBUG): Aggregate::initialize Default
2025-07-25T20:14:11.092Z,1753474451.092 [Default:B.GoToSurface] Running Loop=1
2025-07-25T20:14:11.092Z,1753474451.092 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-07-25T20:14:11.093Z,1753474451.093 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-07-25T20:14:11.093Z,1753474451.093 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-07-25T20:14:11.093Z,1753474451.093 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-07-25T20:14:11.094Z,1753474451.094 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-07-25T20:14:11.094Z,1753474451.094 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-07-25T20:14:11.094Z,1753474451.094 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-07-25T20:14:11.095Z,1753474451.095 [Default:A.Wait] Running Loop=1
2025-07-25T20:14:11.095Z,1753474451.095 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-07-25T20:14:11.432Z,1753474451.432 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-07-25T20:14:11.433Z,1753474451.433 [BackseatComponent](INFO): Shutdown requested. Waiting (30.00 sec to power down.).
2025-07-25T20:14:12.287Z,1753474452.287 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=26312, MT Status=1, MTMSN=948
2025-07-25T20:14:12.287Z,1753474452.287 [NAL9602](INFO): Data available in MT queue
2025-07-25T20:14:12.773Z,1753474452.773 [NAL9602](INFO): Received command: stop
2025-07-25T20:14:12.855Z,1753474452.855 [CommandExec](IMPORTANT): got command stop
2025-07-25T20:14:12.856Z,1753474452.856 [CommandExec](IMPORTANT): Scheduling is paused
2025-07-25T20:14:12.856Z,1753474452.856 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-07-25T20:14:24.414Z,1753474464.414 [Default:A.Wait](INFO): Done Waiting.
2025-07-25T20:14:24.415Z,1753474464.415 [Default:A.Wait] Stopped
2025-07-25T20:14:24.415Z,1753474464.415 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-07-25T20:14:24.823Z,1753474464.823 [Default:CheckIn] Running Loop=1
2025-07-25T20:14:24.823Z,1753474464.823 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-07-25T20:14:24.823Z,1753474464.823 [Default:CheckIn:Read_GPS] Running Loop=1
2025-07-25T20:14:25.001Z,1753474465.001 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:14:26.837Z,1753474466.837 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201431.00,A,3648.26915,N,12149.48687,W,0.447,200.75,250725,,,A*73
2025-07-25T20:14:26.839Z,1753474466.839 [NAL9602](INFO): GPS fix at 20250725T201431: (36.804486, -121.824781)
2025-07-25T20:14:26.852Z,1753474466.852 [Default:CheckIn:Read_GPS] Stopped
2025-07-25T20:14:26.852Z,1753474466.852 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-07-25T20:14:41.486Z,1753474481.486 [BackseatComponent](INFO): Powering down and starting shutdown timer (30.00 sec).
2025-07-25T20:14:41.486Z,1753474481.486 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-07-25T20:14:41.487Z,1753474481.487 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-07-25T20:14:41.846Z,1753474481.846 [Depth_Keller](INFO): Deactivating messaging.
2025-07-25T20:14:43.467Z,1753474483.467 [NAL9602](INFO): SBD MO Status=1, MOMSN=26313, MT Status=0, MTMSN=0
2025-07-25T20:14:43.537Z,1753474483.537 [NAL9602](INFO): Sent 73 bytes from file Logs/20250725T160334/Courier0037.lzma
2025-07-25T20:14:43.537Z,1753474483.537 [NAL9602](INFO): Packets left to send: 0
2025-07-25T20:14:55.263Z,1753474495.263 [NAL9602](INFO): SBD MO Status=1, MOMSN=26314, MT Status=0, MTMSN=0
2025-07-25T20:14:55.321Z,1753474495.321 [NAL9602](INFO): Sent 332 bytes from file Logs/20250725T160334/Express0038.lzma
2025-07-25T20:14:55.321Z,1753474495.321 [NAL9602](INFO): Packets left to send: 1
2025-07-25T20:14:56.125Z,1753474496.125 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:15:09.068Z,1753474509.068 [NAL9602](INFO): SBD MO Status=1, MOMSN=26315, MT Status=0, MTMSN=0
2025-07-25T20:15:09.133Z,1753474509.133 [NAL9602](INFO): Sent 131 bytes from file Logs/20250725T160334/Express0038.lzma
2025-07-25T20:15:09.133Z,1753474509.133 [NAL9602](INFO): Packets left to send: 0
2025-07-25T20:15:27.249Z,1753474527.249 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:15:27.655Z,1753474527.655 [NAL9602](INFO): SBD MO Status=2, MOMSN=26316, MT Status=2, MTMSN=0
2025-07-25T20:15:27.655Z,1753474527.655 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:15:43.005Z,1753474543.005 [NAL9602](INFO): SBD MO Status=2, MOMSN=26316, MT Status=2, MTMSN=0
2025-07-25T20:15:43.006Z,1753474543.006 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:15:49.062Z,1753474549.062 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:15:58.381Z,1753474558.381 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:16:02.802Z,1753474562.802 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:16:05.635Z,1753474565.635 [NAL9602](INFO): SBD MO Status=2, MOMSN=26316, MT Status=2, MTMSN=0
2025-07-25T20:16:05.636Z,1753474565.636 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:16:16.533Z,1753474576.533 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:16:22.596Z,1753474582.596 [NAL9602](INFO): SBD MO Status=2, MOMSN=26316, MT Status=2, MTMSN=0
2025-07-25T20:16:22.596Z,1753474582.596 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:16:29.505Z,1753474589.505 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:16:29.865Z,1753474589.865 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:16:42.393Z,1753474602.393 [NAL9602](INFO): SBD MO Status=2, MOMSN=26316, MT Status=2, MTMSN=0
2025-07-25T20:16:42.393Z,1753474602.393 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:16:43.601Z,1753474603.601 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:16:47.348Z,1753474607.348 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2025-07-25T20:16:57.754Z,1753474617.754 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:17:00.633Z,1753474620.633 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:17:07.037Z,1753474627.037 [NAL9602](INFO): SBD MO Status=0, MOMSN=26316, MT Status=0, MTMSN=0
2025-07-25T20:17:11.881Z,1753474631.881 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:17:23.697Z,1753474643.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=26317, MT Status=2, MTMSN=0
2025-07-25T20:17:23.697Z,1753474643.697 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:17:27.321Z,1753474647.321 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:17:31.757Z,1753474651.757 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-07-25T20:17:41.510Z,1753474661.510 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:17:55.650Z,1753474675.650 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2025-07-25T20:17:59.297Z,1753474679.297 [NAL9602](INFO): SBD MO Status=2, MOMSN=26317, MT Status=2, MTMSN=0
2025-07-25T20:17:59.297Z,1753474679.297 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:18:03.550Z,1753474683.550 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2025-07-25T20:18:22.226Z,1753474702.226 [DataOverHttps](IMPORTANT): SBD MTMSN=20250725T201826
2025-07-25T20:18:22.230Z,1753474702.230 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003834
2025-07-25T20:18:24.868Z,1753474704.868 [NAL9602](INFO): SBD MO Status=2, MOMSN=26317, MT Status=2, MTMSN=0
2025-07-25T20:18:24.868Z,1753474704.868 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-07-25T20:18:29.820Z,1753474709.820 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250725T160334/Courier0040.lzma
2025-07-25T20:18:29.823Z,1753474709.823 [DataOverHttps](INFO): Received command: stop
2025-07-25T20:18:29.874Z,1753474709.874 [CommandExec](IMPORTANT): got command stop
2025-07-25T20:18:40.866Z,1753474720.866 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Courier0040.lzma.bak
2025-07-25T20:18:40.866Z,1753474720.866 [DataOverHttps](INFO): SBD MOMSN=25612354
2025-07-25T20:18:55.602Z,1753474735.602 [NAL9602](INFO): Not Powering down - fast GPS
2025-07-25T20:19:03.322Z,1753474743.322 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-07-25T20:19:14.140Z,1753474754.140 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250725T160334/Courier0043.lzma
2025-07-25T20:19:28.195Z,1753474768.195 [DataOverHttps](INFO): Moved sent file to Logs/20250725T160334/Courier0043.lzma.bak
2025-07-25T20:19:28.195Z,1753474768.195 [DataOverHttps](INFO): SBD MOMSN=25612357
2025-07-25T20:19:46.886Z,1753474786.886 [DataOverHttps](IMPORTANT): SBD MTMSN=20250725T201951
2025-07-25T20:19:54.297Z,1753474794.297 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250725T160334/Express0041.lzma
2025-07-25T20:19:54.299Z,1753474794.299 [DataOverHttps](INFO): Received command: restart logs