2025-01-22T18:34:49.942Z,1737570889.942 [Supervisor](DEBUG): Initializing supervisor.
2025-01-22T18:34:49.946Z,1737570889.946 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-01-22T18:34:49.946Z,1737570889.946 [SyncHandler](INFO): Protected caller Thread ID is 2289
2025-01-22T18:34:49.947Z,1737570889.947 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-01-22T18:34:49.948Z,1737570889.948 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-01-22T18:34:49.948Z,1737570889.948 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2290
2025-01-22T18:34:49.952Z,1737570889.952 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-01-22T18:34:49.969Z,1737570889.969 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-01-22T18:34:49.970Z,1737570889.970 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-01-22T18:34:49.971Z,1737570889.971 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2291
2025-01-22T18:34:49.975Z,1737570889.975 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-01-22T18:34:49.976Z,1737570889.976 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-01-22T18:34:49.976Z,1737570889.976 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2292
2025-01-22T18:34:49.978Z,1737570889.978 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-01-22T18:34:49.979Z,1737570889.979 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-01-22T18:34:49.979Z,1737570889.979 [logger ThreadHandler](INFO): Protected caller Thread ID is 2293
2025-01-22T18:34:49.983Z,1737570889.983 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-01-22T18:34:49.983Z,1737570889.983 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-01-22T18:34:49.988Z,1737570889.988 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-01-22T18:34:50.320Z,1737570890.320 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-01-22T18:34:50.321Z,1737570890.321 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-01-22T18:34:50.547Z,1737570890.547 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-01-22T18:34:50.549Z,1737570890.549 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-01-22T18:34:50.662Z,1737570890.662 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-01-22T18:34:50.664Z,1737570890.664 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-01-22T18:34:50.863Z,1737570890.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-01-22T18:34:50.863Z,1737570890.863 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-01-22T18:34:51.368Z,1737570891.368 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-01-22T18:34:51.370Z,1737570891.370 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-01-22T18:34:51.498Z,1737570891.498 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-01-22T18:34:51.499Z,1737570891.499 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-01-22T18:34:51.800Z,1737570891.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-01-22T18:34:51.801Z,1737570891.801 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-01-22T18:34:57.357Z,1737570897.357 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-01-22T18:34:57.357Z,1737570897.357 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-01-22T18:34:58.805Z,1737570898.805 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-01-22T18:34:58.806Z,1737570898.806 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-01-22T18:35:00.486Z,1737570900.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-01-22T18:35:00.487Z,1737570900.487 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-01-22T18:35:00.587Z,1737570900.587 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-01-22T18:35:00.974Z,1737570900.974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-01-22T18:35:00.974Z,1737570900.974 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-01-22T18:35:01.132Z,1737570901.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-01-22T18:35:01.133Z,1737570901.133 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-01-22T18:35:01.987Z,1737570901.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-01-22T18:35:01.987Z,1737570901.987 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-01-22T18:35:02.351Z,1737570902.351 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-01-22T18:35:02.354Z,1737570902.354 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-01-22T18:35:02.454Z,1737570902.454 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-aku/
2025-01-22T18:35:02.457Z,1737570902.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/secure.cfg
2025-01-22T18:35:02.558Z,1737570902.558 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/logger.cfg
2025-01-22T18:35:02.680Z,1737570902.680 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/vehicle.cfg
2025-01-22T18:35:02.803Z,1737570902.803 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/BIT.cfg
2025-01-22T18:35:02.908Z,1737570902.908 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Simulator.cfg
2025-01-22T18:35:03.011Z,1737570903.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Servo.cfg
2025-01-22T18:35:03.132Z,1737570903.132 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Science.cfg
2025-01-22T18:35:03.291Z,1737570903.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Sensor.cfg
2025-01-22T18:35:03.474Z,1737570903.474 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Control.cfg
2025-01-22T18:35:03.588Z,1737570903.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-aku/Battery.cfg
2025-01-22T18:35:03.870Z,1737570903.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-01-22T18:35:03.871Z,1737570903.871 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-01-22T18:35:06.647Z,1737570906.647 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-01-22T18:35:09.882Z,1737570909.882 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-01-22T18:35:09.883Z,1737570909.883 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-01-22T18:35:12.163Z,1737570912.163 [AHRS_M2] Loaded
2025-01-22T18:35:12.164Z,1737570912.164 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-01-22T18:35:12.205Z,1737570912.205 [BackseatComponent] Loaded
2025-01-22T18:35:12.205Z,1737570912.205 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-01-22T18:35:12.206Z,1737570912.206 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408C14E0
2025-01-22T18:35:12.206Z,1737570912.206 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2372
2025-01-22T18:35:12.209Z,1737570912.209 [LcmUniversalReporter] Loaded
2025-01-22T18:35:12.210Z,1737570912.210 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-01-22T18:35:12.216Z,1737570912.216 [BioacousticsDataBridge] Loaded
2025-01-22T18:35:12.216Z,1737570912.216 [ComponentRegistry](DEBUG): SyncComponent "BioacousticsDataBridge" handled in the control thread.
2025-01-22T18:35:13.013Z,1737570913.013 [BPC1] Loaded
2025-01-22T18:35:13.013Z,1737570913.013 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-01-22T18:35:13.097Z,1737570913.097 [DATMMP] Loaded
2025-01-22T18:35:13.097Z,1737570913.097 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2025-01-22T18:35:13.098Z,1737570913.098 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 408F24E0
2025-01-22T18:35:13.098Z,1737570913.098 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 2373
2025-01-22T18:35:13.173Z,1737570913.173 [DataOverHttps] Loaded
2025-01-22T18:35:13.173Z,1737570913.173 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-01-22T18:35:13.174Z,1737570913.174 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409224E0
2025-01-22T18:35:13.174Z,1737570913.174 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2374
2025-01-22T18:35:13.197Z,1737570913.197 [Depth_Keller] Loaded
2025-01-22T18:35:13.197Z,1737570913.197 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-01-22T18:35:13.202Z,1737570913.202 [DropWeight] Loaded
2025-01-22T18:35:13.202Z,1737570913.202 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-01-22T18:35:13.265Z,1737570913.265 [NAL9602] Loaded
2025-01-22T18:35:13.265Z,1737570913.265 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-01-22T18:35:13.294Z,1737570913.294 [Onboard] Loaded
2025-01-22T18:35:13.294Z,1737570913.294 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-01-22T18:35:13.295Z,1737570913.295 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409524E0
2025-01-22T18:35:13.295Z,1737570913.295 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2375
2025-01-22T18:35:13.309Z,1737570913.309 [Power24vConverter] Loaded
2025-01-22T18:35:13.310Z,1737570913.310 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-01-22T18:35:13.326Z,1737570913.326 [Radio_Surface] Loaded
2025-01-22T18:35:13.326Z,1737570913.326 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-01-22T18:35:13.327Z,1737570913.327 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409824E0
2025-01-22T18:35:13.328Z,1737570913.328 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2376
2025-01-22T18:35:13.343Z,1737570913.343 [Sonardyne_Nano] Loaded
2025-01-22T18:35:13.343Z,1737570913.343 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-01-22T18:35:13.344Z,1737570913.344 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-01-22T18:35:13.344Z,1737570913.344 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-01-22T18:35:13.512Z,1737570913.512 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-01-22T18:35:13.514Z,1737570913.514 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-01-22T18:35:13.586Z,1737570913.586 [VerticalControl](DEBUG): Construct VerticalControl.
2025-01-22T18:35:13.645Z,1737570913.645 [VerticalControl] Loaded
2025-01-22T18:35:13.645Z,1737570913.645 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-01-22T18:35:13.648Z,1737570913.648 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-01-22T18:35:13.696Z,1737570913.696 [HorizontalControl] Loaded
2025-01-22T18:35:13.696Z,1737570913.696 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-01-22T18:35:13.698Z,1737570913.698 [SpeedControl](DEBUG): Construct SpeedControl.
2025-01-22T18:35:13.702Z,1737570913.702 [SpeedControl] Loaded
2025-01-22T18:35:13.702Z,1737570913.702 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-01-22T18:35:13.705Z,1737570913.705 [LoopControl](DEBUG): Construct LoopControl.
2025-01-22T18:35:13.705Z,1737570913.705 [LoopControl] Loaded
2025-01-22T18:35:13.705Z,1737570913.705 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-01-22T18:35:13.706Z,1737570913.706 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-01-22T18:35:13.706Z,1737570913.706 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-01-22T18:35:13.723Z,1737570913.723 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-01-22T18:35:13.723Z,1737570913.723 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-01-22T18:35:13.768Z,1737570913.768 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-01-22T18:35:13.768Z,1737570913.768 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-01-22T18:35:13.915Z,1737570913.915 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-01-22T18:35:13.915Z,1737570913.915 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-01-22T18:35:13.929Z,1737570913.929 [NavChart] Loaded
2025-01-22T18:35:13.929Z,1737570913.929 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-01-22T18:35:13.935Z,1737570913.935 [UniversalFixResidualReporter] Loaded
2025-01-22T18:35:13.935Z,1737570913.935 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-01-22T18:35:13.935Z,1737570913.935 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-01-22T18:35:13.936Z,1737570913.936 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-01-22T18:35:14.108Z,1737570914.108 [SBIT](DEBUG): Construct Startup Built In Test.
2025-01-22T18:35:14.118Z,1737570914.118 [SBIT] Loaded
2025-01-22T18:35:14.118Z,1737570914.118 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-01-22T18:35:14.120Z,1737570914.120 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-01-22T18:35:14.133Z,1737570914.133 [IBIT] Loaded
2025-01-22T18:35:14.133Z,1737570914.133 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-01-22T18:35:14.139Z,1737570914.139 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-01-22T18:35:14.244Z,1737570914.244 [CBIT] Loaded
2025-01-22T18:35:14.244Z,1737570914.244 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-01-22T18:35:14.245Z,1737570914.245 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-01-22T18:35:14.246Z,1737570914.246 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-01-22T18:35:14.459Z,1737570914.459 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-01-22T18:35:14.460Z,1737570914.460 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-01-22T18:35:14.634Z,1737570914.634 [BuoyancyServo] Loaded
2025-01-22T18:35:14.634Z,1737570914.634 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-01-22T18:35:14.657Z,1737570914.657 [ElevatorServo] Loaded
2025-01-22T18:35:14.657Z,1737570914.657 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-01-22T18:35:14.678Z,1737570914.678 [MassServo] Loaded
2025-01-22T18:35:14.679Z,1737570914.679 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-01-22T18:35:14.699Z,1737570914.699 [RudderServo] Loaded
2025-01-22T18:35:14.699Z,1737570914.699 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-01-22T18:35:14.717Z,1737570914.717 [ThrusterHE] Loaded
2025-01-22T18:35:14.717Z,1737570914.717 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-01-22T18:35:14.717Z,1737570914.717 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-01-22T18:35:14.718Z,1737570914.718 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-01-22T18:35:14.951Z,1737570914.951 [CTD_Seabird] Loaded
2025-01-22T18:35:14.952Z,1737570914.952 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-01-22T18:35:14.955Z,1737570914.955 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BAA4E0
2025-01-22T18:35:14.956Z,1737570914.956 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2377
2025-01-22T18:35:14.978Z,1737570914.978 [PAR_Licor] Loaded
2025-01-22T18:35:14.978Z,1737570914.978 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-01-22T18:35:15.023Z,1737570915.023 [WetLabsBB2FL] Loaded
2025-01-22T18:35:15.024Z,1737570915.024 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-01-22T18:35:15.025Z,1737570915.025 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BDA4E0
2025-01-22T18:35:15.025Z,1737570915.025 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2378
2025-01-22T18:35:15.026Z,1737570915.026 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-01-22T18:35:15.026Z,1737570915.026 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-01-22T18:35:15.097Z,1737570915.097 [DepthRateCalculator] Loaded
2025-01-22T18:35:15.098Z,1737570915.098 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-01-22T18:35:15.103Z,1737570915.103 [PitchRateCalculator] Loaded
2025-01-22T18:35:15.103Z,1737570915.103 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-01-22T18:35:15.112Z,1737570915.112 [SpeedCalculator] Loaded
2025-01-22T18:35:15.112Z,1737570915.112 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-01-22T18:35:15.117Z,1737570915.117 [YawRateCalculator] Loaded
2025-01-22T18:35:15.117Z,1737570915.117 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-01-22T18:35:15.136Z,1737570915.136 [ElevatorOffsetCalculator] Loaded
2025-01-22T18:35:15.137Z,1737570915.137 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-01-22T18:35:15.137Z,1737570915.137 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-01-22T18:35:15.138Z,1737570915.138 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-01-22T18:35:15.241Z,1737570915.241 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-01-22T18:35:15.248Z,1737570915.248 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-01-22T18:35:15.250Z,1737570915.250 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-01-22T18:35:15.262Z,1737570915.262 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-01-22T18:35:15.265Z,1737570915.265 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C6A4E0
2025-01-22T18:35:15.266Z,1737570915.266 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2379
2025-01-22T18:35:15.270Z,1737570915.270 [Supervisor](INFO): Main Thread ID is 827
2025-01-22T18:35:15.270Z,1737570915.270 [Supervisor](DEBUG): Running supervisor.
2025-01-22T18:35:15.271Z,1737570915.271 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2380
2025-01-22T18:35:15.271Z,1737570915.271 [CommandExec](INFO): Initializing the command executive.
2025-01-22T18:35:15.273Z,1737570915.273 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2381
2025-01-22T18:35:15.275Z,1737570915.275 [controlThread ThreadHandler](INFO): Handler Thread ID is 2382
2025-01-22T18:35:15.275Z,1737570915.275 [controlThread](DEBUG): Initializing ControlThread
2025-01-22T18:35:15.283Z,1737570915.283 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-01-22T18:35:15.285Z,1737570915.285 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-01-22T18:35:15.285Z,1737570915.285 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-01-22T18:35:15.286Z,1737570915.286 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-01-22T18:35:15.287Z,1737570915.287 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-01-22T18:35:15.287Z,1737570915.287 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-01-22T18:35:15.287Z,1737570915.287 [SBIT](INFO): Initialize SBIT Component.
2025-01-22T18:35:15.288Z,1737570915.288 [SBIT](IMPORTANT): git: 2025-01-21
2025-01-22T18:35:15.288Z,1737570915.288 [SBIT](INFO): git hash: 6b2695e6425a6d448ed529835007678bdc61cede
2025-01-22T18:35:15.288Z,1737570915.288 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-01-22T18:35:15.290Z,1737570915.290 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Dec 4 01:17:04 UTC 2024
2025-01-22T18:35:15.291Z,1737570915.291 [SBIT](INFO): Beginning SBIT in 46.000000 seconds.
2025-01-22T18:35:15.291Z,1737570915.291 [IBIT](INFO): Initialize IBIT Component.
2025-01-22T18:35:15.292Z,1737570915.292 [CBIT](DEBUG): Initialize CBIT Component.
2025-01-22T18:35:15.293Z,1737570915.293 [logger ThreadHandler](INFO): Handler Thread ID is 2383
2025-01-22T18:35:15.305Z,1737570915.305 [CBIT](DEBUG): Initialized mux pins.
2025-01-22T18:35:15.305Z,1737570915.305 [CBIT](DEBUG): Initializing the watchdog timer.
2025-01-22T18:35:15.313Z,1737570915.313 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2384
2025-01-22T18:35:15.325Z,1737570915.325 [DATMMP ThreadHandler](INFO): Handler Thread ID is 2385
2025-01-22T18:35:15.326Z,1737570915.326 [DATMMP](INFO): Start
2025-01-22T18:35:15.326Z,1737570915.326 [DATMMP](INFO): Powering up
2025-01-22T18:35:15.326Z,1737570915.326 [DATMMP](DEBUG): Initializing DATMMP.
2025-01-22T18:35:15.329Z,1737570915.329 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-01-22T18:35:15.330Z,1737570915.330 [CBIT](DEBUG): Initializing heartbeat.
2025-01-22T18:35:15.331Z,1737570915.331 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2387
2025-01-22T18:35:15.333Z,1737570915.333 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-01-22T18:35:15.342Z,1737570915.342 [Onboard ThreadHandler](INFO): Handler Thread ID is 2388
2025-01-22T18:35:15.372Z,1737570915.372 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2389
2025-01-22T18:35:15.385Z,1737570915.385 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2390
2025-01-22T18:35:15.386Z,1737570915.386 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-01-22T18:35:15.390Z,1737570915.390 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2392
2025-01-22T18:35:15.393Z,1737570915.393 [WetLabsBB2FL](INFO): Powering up
2025-01-22T18:35:15.395Z,1737570915.395 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2394
2025-01-22T18:35:15.401Z,1737570915.401 [CBIT](DEBUG): Deactivating GF circuits.
2025-01-22T18:35:15.401Z,1737570915.401 [CBIT](DEBUG): Deactivating emergency mode.
2025-01-22T18:35:15.405Z,1737570915.405 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-01-22T18:35:15.405Z,1737570915.405 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-01-22T18:35:15.405Z,1737570915.405 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-01-22T18:35:15.405Z,1737570915.405 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-01-22T18:35:15.406Z,1737570915.406 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-01-22T18:35:15.406Z,1737570915.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-01-22T18:35:15.406Z,1737570915.406 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-01-22T18:35:15.406Z,1737570915.406 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-01-22T18:35:15.441Z,1737570915.441 [CBIT](DEBUG): Backplane powered.
2025-01-22T18:35:15.445Z,1737570915.445 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-01-22T18:35:15.446Z,1737570915.446 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-01-22T18:35:15.446Z,1737570915.446 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-01-22T18:35:15.446Z,1737570915.446 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-01-22T18:35:15.447Z,1737570915.447 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-01-22T18:35:15.448Z,1737570915.448 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-01-22T18:35:15.449Z,1737570915.449 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-01-22T18:35:15.449Z,1737570915.449 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-01-22T18:35:15.453Z,1737570915.453 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-01-22T18:35:15.522Z,1737570915.522 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-01-22T18:35:15.542Z,1737570915.542 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-01-22T18:35:15.577Z,1737570915.577 [DATMMP](INFO): Starting
2025-01-22T18:35:15.598Z,1737570915.598 [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-01-22T18:35:15.599Z,1737570915.599 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-01-22T18:35:15.599Z,1737570915.599 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-01-22T18:35:15.602Z,1737570915.602 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-01-22T18:35:15.773Z,1737570915.773 [Radio_Surface](INFO): Powering up
2025-01-22T18:35:15.829Z,1737570915.829 [DATMMP](INFO): Starting
2025-01-22T18:35:15.883Z,1737570915.883 [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-01-22T18:35:15.888Z,1737570915.888 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-01-22T18:35:15.906Z,1737570915.906 [Default:A.Wait](DEBUG): Construct Wait.
2025-01-22T18:35:15.908Z,1737570915.908 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-01-22T18:35:15.936Z,1737570915.936 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-01-22T18:35:15.955Z,1737570915.955 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-01-22T18:35:15.981Z,1737570915.981 [Default:E.Execute](DEBUG): Construct Execute.
2025-01-22T18:35:15.984Z,1737570915.984 [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-01-22T18:35:15.988Z,1737570915.988 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BioacousticsDataBridge,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,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,LcmUniversalReporter,Reporter,LogSplitter,
2025-01-22T18:35:16.007Z,1737570916.007 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-01-22T18:35:16.075Z,1737570916.075 [Power24vConverter](INFO): Powering up.
2025-01-22T18:35:16.076Z,1737570916.076 [Sonardyne_Nano](INFO): Initializing.
2025-01-22T18:35:16.081Z,1737570916.081 [DATMMP](INFO): Starting
2025-01-22T18:35:16.127Z,1737570916.127 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-01-22T18:35:16.133Z,1737570916.133 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-01-22T18:35:16.134Z,1737570916.134 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-01-22T18:35:16.141Z,1737570916.141 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-01-22T18:35:16.142Z,1737570916.142 [MassServo](DEBUG): Initializing EZServoServo.
2025-01-22T18:35:16.149Z,1737570916.149 [MassServo](DEBUG): Initializing MassServo.
2025-01-22T18:35:16.150Z,1737570916.150 [RudderServo](DEBUG): Initializing EZServoServo.
2025-01-22T18:35:16.157Z,1737570916.157 [RudderServo](DEBUG): Initializing RudderServo.
2025-01-22T18:35:16.158Z,1737570916.158 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T18:35:16.169Z,1737570916.169 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T18:35:16.334Z,1737570916.334 [DATMMP](INFO): Starting
2025-01-22T18:35:16.585Z,1737570916.585 [DATMMP](INFO): Starting
2025-01-22T18:35:16.837Z,1737570916.837 [DATMMP](INFO): Starting
2025-01-22T18:35:17.089Z,1737570917.089 [DATMMP](INFO): Starting
2025-01-22T18:35:17.341Z,1737570917.341 [DATMMP](INFO): Starting
2025-01-22T18:35:17.501Z,1737570917.501 [WetLabsBB2FL](INFO): Powering down
2025-01-22T18:35:17.593Z,1737570917.593 [DATMMP](INFO): Starting
2025-01-22T18:35:17.845Z,1737570917.845 [DATMMP](INFO): Starting
2025-01-22T18:35:18.015Z,1737570918.015 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-01-22T18:35:18.097Z,1737570918.097 [DATMMP](INFO): Starting
2025-01-22T18:35:18.349Z,1737570918.349 [DATMMP](INFO): Starting
2025-01-22T18:35:18.601Z,1737570918.601 [DATMMP](INFO): Starting
2025-01-22T18:35:18.853Z,1737570918.853 [DATMMP](INFO): Starting
2025-01-22T18:35:19.105Z,1737570919.105 [DATMMP](INFO): Starting
2025-01-22T18:35:19.302Z,1737570919.302 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2409
2025-01-22T18:35:19.357Z,1737570919.357 [DATMMP](INFO): Starting
2025-01-22T18:35:19.609Z,1737570919.609 [DATMMP](INFO): Starting
2025-01-22T18:35:19.866Z,1737570919.866 [DATMMP](INFO): Starting
2025-01-22T18:35:20.118Z,1737570920.118 [DATMMP](INFO): Starting
2025-01-22T18:35:20.371Z,1737570920.371 [DATMMP](INFO): Starting
2025-01-22T18:35:20.621Z,1737570920.621 [DATMMP](INFO): Starting
2025-01-22T18:35:20.873Z,1737570920.873 [DATMMP](INFO): Starting
2025-01-22T18:35:21.125Z,1737570921.125 [DATMMP](INFO): Starting
2025-01-22T18:35:21.377Z,1737570921.377 [DATMMP](INFO): Starting
2025-01-22T18:35:21.629Z,1737570921.629 [DATMMP](INFO): Starting
2025-01-22T18:35:21.881Z,1737570921.881 [DATMMP](INFO): Starting
2025-01-22T18:35:22.010Z,1737570922.010 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-22T18:35:22.133Z,1737570922.133 [DATMMP](INFO): Starting
2025-01-22T18:35:22.385Z,1737570922.385 [DATMMP](INFO): Starting
2025-01-22T18:35:22.637Z,1737570922.637 [DATMMP](INFO): Starting
2025-01-22T18:35:22.889Z,1737570922.889 [DATMMP](INFO): Starting
2025-01-22T18:35:23.141Z,1737570923.141 [DATMMP](INFO): Starting
2025-01-22T18:35:23.393Z,1737570923.393 [DATMMP](INFO): Starting
2025-01-22T18:35:23.645Z,1737570923.645 [DATMMP](INFO): Starting
2025-01-22T18:35:23.897Z,1737570923.897 [DATMMP](INFO): Starting
2025-01-22T18:35:24.149Z,1737570924.149 [DATMMP](INFO): Starting
2025-01-22T18:35:24.401Z,1737570924.401 [DATMMP](INFO): Starting
2025-01-22T18:35:24.653Z,1737570924.653 [DATMMP](INFO): Starting
2025-01-22T18:35:24.905Z,1737570924.905 [DATMMP](INFO): Starting
2025-01-22T18:35:25.157Z,1737570925.157 [DATMMP](INFO): Starting
2025-01-22T18:35:25.409Z,1737570925.409 [DATMMP](INFO): Starting
2025-01-22T18:35:25.661Z,1737570925.661 [DATMMP](INFO): Starting
2025-01-22T18:35:25.913Z,1737570925.913 [DATMMP](INFO): Starting
2025-01-22T18:35:26.165Z,1737570926.165 [DATMMP](INFO): Starting
2025-01-22T18:35:26.417Z,1737570926.417 [DATMMP](INFO): Starting
2025-01-22T18:35:26.669Z,1737570926.669 [DATMMP](INFO): Starting
2025-01-22T18:35:26.921Z,1737570926.921 [DATMMP](INFO): Starting
2025-01-22T18:35:26.922Z,1737570926.922 [DATMMP](INFO): DAT read:
2025-01-22T18:35:26.922Z,1737570926.922 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-01-22T18:35:27.173Z,1737570927.173 [DATMMP](INFO): Starting
2025-01-22T18:35:27.425Z,1737570927.425 [DATMMP](INFO): Starting
2025-01-22T18:35:27.677Z,1737570927.677 [DATMMP](INFO): Starting
2025-01-22T18:35:27.929Z,1737570927.929 [DATMMP](INFO): Starting
2025-01-22T18:35:28.181Z,1737570928.181 [DATMMP](INFO): Starting
2025-01-22T18:35:28.433Z,1737570928.433 [DATMMP](INFO): Starting
2025-01-22T18:35:28.437Z,1737570928.437 [DATMMP](INFO): DAT read: MF Frequency Band
2025-01-22T18:35:28.438Z,1737570928.438 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-01-22T18:35:28.438Z,1737570928.438 [DATMMP](INFO): DAT read: Jan 22 2000 18:34:46
2025-01-22T18:35:28.685Z,1737570928.685 [DATMMP](INFO): Starting
2025-01-22T18:35:28.937Z,1737570928.937 [DATMMP](INFO): Starting
2025-01-22T18:35:29.189Z,1737570929.189 [DATMMP](INFO): Starting
2025-01-22T18:35:29.441Z,1737570929.441 [DATMMP](INFO): Starting
2025-01-22T18:35:29.693Z,1737570929.693 [DATMMP](INFO): Starting
2025-01-22T18:35:29.694Z,1737570929.694 [DATMMP](INFO): DAT read: Features enabled [Bearing]
2025-01-22T18:35:29.695Z,1737570929.695 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2025-01-22T18:35:29.695Z,1737570929.695 [DATMMP](INFO): commRate: 800
2025-01-22T18:35:29.945Z,1737570929.945 [DATMMP](INFO): Starting
2025-01-22T18:35:30.197Z,1737570930.197 [DATMMP](INFO): Starting
2025-01-22T18:35:30.449Z,1737570930.449 [DATMMP](INFO): Starting
2025-01-22T18:35:30.701Z,1737570930.701 [DATMMP](INFO): Starting
2025-01-22T18:35:30.953Z,1737570930.953 [DATMMP](INFO): Starting
2025-01-22T18:35:31.205Z,1737570931.205 [DATMMP](INFO): Starting
2025-01-22T18:35:31.457Z,1737570931.457 [DATMMP](INFO): Starting
2025-01-22T18:35:31.709Z,1737570931.709 [DATMMP](INFO): Starting
2025-01-22T18:35:31.761Z,1737570931.761 [DATMMP](INFO): entering command mode
2025-01-22T18:35:31.961Z,1737570931.961 [DATMMP](INFO): Starting
2025-01-22T18:35:31.961Z,1737570931.961 [DATMMP](INFO): DAT read:
2025-01-22T18:35:31.962Z,1737570931.962 [DATMMP](INFO): DAT read: user:1>
2025-01-22T18:35:31.962Z,1737570931.962 [DATMMP](DEBUG): read user prompt 1: user:1>
2025-01-22T18:35:31.963Z,1737570931.963 [DATMMP](INFO): entering MMP mode
2025-01-22T18:35:32.213Z,1737570932.213 [DATMMP](INFO): Starting
2025-01-22T18:35:32.214Z,1737570932.214 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T18:35:32.216Z,1737570932.216 [DATMMP](INFO): status rx: x1
2025-01-22T18:35:32.216Z,1737570932.216 [DATMMP](INFO): MMP status: 1: started
2025-01-22T18:35:32.216Z,1737570932.216 [DATMMP](INFO): Received message type: status
2025-01-22T18:35:32.216Z,1737570932.216 [DATMMP](INFO): Handled
2025-01-22T18:35:32.465Z,1737570932.465 [DATMMP](INFO): Starting
2025-01-22T18:35:32.466Z,1737570932.466 [DATMMP](INFO): Sent Tx Power Config 8
2025-01-22T18:35:32.467Z,1737570932.467 [DATMMP](INFO): Setting local address: 2
2025-01-22T18:35:32.469Z,1737570932.469 [DATMMP](INFO): Setting time to: 18:35:32 And date to:1/22/2025
2025-01-22T18:35:32.717Z,1737570932.717 [DATMMP](INFO): Starting
2025-01-22T18:35:32.718Z,1737570932.718 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T18:35:32.718Z,1737570932.718 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0
2025-01-22T18:35:32.719Z,1737570932.719 [DATMMP](INFO): Received message type: mdmpower
2025-01-22T18:35:32.719Z,1737570932.719 [DATMMP](INFO): Handled
2025-01-22T18:35:32.969Z,1737570932.969 [DATMMP](INFO): Starting
2025-01-22T18:35:32.970Z,1737570932.970 [DATMMP](INFO): GSXN notify for xid: 10
2025-01-22T18:35:32.970Z,1737570932.970 [DATMMP](INFO): sreg_txpower rx: x8
2025-01-22T18:35:32.970Z,1737570932.970 [DATMMP](INFO): Received message type: sreg_txpower
2025-01-22T18:35:32.971Z,1737570932.971 [DATMMP](INFO): Match for : sreg_txpower
2025-01-22T18:35:32.971Z,1737570932.971 [DATMMP](INFO): ACK
2025-01-22T18:35:33.221Z,1737570933.221 [DATMMP](INFO): Starting
2025-01-22T18:35:33.222Z,1737570933.222 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T18:35:33.222Z,1737570933.222 [DATMMP](INFO): mdmlocal rx: x2 x0 x0 x0
2025-01-22T18:35:33.223Z,1737570933.223 [DATMMP](INFO): Received message type: mdmlocal
2025-01-22T18:35:33.223Z,1737570933.223 [DATMMP](INFO): Handled
2025-01-22T18:35:33.473Z,1737570933.473 [DATMMP](INFO): Starting
2025-01-22T18:35:33.474Z,1737570933.474 [DATMMP](INFO): GSXN notify for xid: 11
2025-01-22T18:35:33.474Z,1737570933.474 [DATMMP](INFO): sreg_locaddr rx: x2
2025-01-22T18:35:33.474Z,1737570933.474 [DATMMP](INFO): Received message type: sreg_locaddr
2025-01-22T18:35:33.475Z,1737570933.475 [DATMMP](INFO): Match for : sreg_locaddr
2025-01-22T18:35:33.475Z,1737570933.475 [DATMMP](INFO): ACK
2025-01-22T18:35:33.725Z,1737570933.725 [DATMMP](INFO): Starting
2025-01-22T18:35:33.726Z,1737570933.726 [DATMMP](INFO): GSXN notify for xid: 12
2025-01-22T18:35:33.727Z,1737570933.727 [DATMMP](INFO): timedate rx: x0 x12 x23 x20 x0 x16 x7D x0
2025-01-22T18:35:33.727Z,1737570933.727 [DATMMP](INFO): Received message type: timedate
2025-01-22T18:35:33.727Z,1737570933.727 [DATMMP](INFO): Match for : timedate
2025-01-22T18:35:33.727Z,1737570933.727 [DATMMP](INFO): ACK
2025-01-22T18:35:33.977Z,1737570933.977 [DATMMP](INFO): Starting
2025-01-22T18:35:33.978Z,1737570933.978 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T18:35:33.978Z,1737570933.978 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0
2025-01-22T18:35:33.979Z,1737570933.979 [DATMMP](INFO): Received message type: sys_verb
2025-01-22T18:35:33.979Z,1737570933.979 [DATMMP](INFO): Handled
2025-01-22T18:35:34.229Z,1737570934.229 [DATMMP](INFO): Starting
2025-01-22T18:35:34.230Z,1737570934.230 [DATMMP](INFO): GSXN notify for xid: 13
2025-01-22T18:35:34.230Z,1737570934.230 [DATMMP](INFO): sreg_verbosity rx: x0
2025-01-22T18:35:34.230Z,1737570934.230 [DATMMP](INFO): Received message type: sreg_verbosity
2025-01-22T18:35:34.231Z,1737570934.231 [DATMMP](INFO): Match for : sreg_verbosity
2025-01-22T18:35:34.231Z,1737570934.231 [DATMMP](INFO): ACK
2025-01-22T18:35:34.481Z,1737570934.481 [DATMMP](INFO): Starting
2025-01-22T18:35:34.481Z,1737570934.481 [DATMMP](INFO): GSXN notify for xid: 14
2025-01-22T18:35:34.482Z,1737570934.482 [DATMMP](INFO): version rx: x2 x5
2025-01-22T18:35:34.482Z,1737570934.482 [DATMMP](INFO): DatMMPVersion: 2.5
2025-01-22T18:35:34.483Z,1737570934.483 [DATMMP](INFO): Received message type: version
2025-01-22T18:35:34.483Z,1737570934.483 [DATMMP](INFO): Match for : version
2025-01-22T18:35:34.483Z,1737570934.483 [DATMMP](INFO): ACK
2025-01-22T18:35:34.483Z,1737570934.483 [DATMMP](INFO): in MMP mode: config complete going to runnable
2025-01-22T18:35:43.519Z,1737570943.519 [NAL9602](INFO): Powering up NAL9602
2025-01-22T18:35:48.846Z,1737570948.846 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T18:35:48.847Z,1737570948.847 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2025-01-22T18:35:48.847Z,1737570948.847 [DATMMP](INFO): Received message type: timesync
2025-01-22T18:35:48.847Z,1737570948.847 [DATMMP](INFO): Handled
2025-01-22T18:35:54.431Z,1737570954.431 [NAL9602](INFO): NAL9602 initialized
2025-01-22T18:35:58.941Z,1737570958.941 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T18:35:58.942Z,1737570958.942 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2025-01-22T18:35:58.942Z,1737570958.942 [DATMMP](INFO): Received message type: timesync
2025-01-22T18:35:58.942Z,1737570958.942 [DATMMP](INFO): Handled
2025-01-22T18:36:01.947Z,1737570961.947 [SBIT](IMPORTANT): Beginning Startup BIT
2025-01-22T18:36:01.951Z,1737570961.951 [CBIT](IMPORTANT): Beginning ground fault scan
2025-01-22T18:36:09.384Z,1737570969.384 [NAL9602](INFO): SBD MO Status=0, MOMSN=12450, MT Status=0, MTMSN=0
2025-01-22T18:36:09.384Z,1737570969.384 [NAL9602](INFO): No messages in MT queue
2025-01-22T18:36:12.782Z,1737570972.782 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.000764
CHAN A1 (24V): -0.000633
CHAN A2 (12V): 0.000319
CHAN A3 (5V): -0.002130
CHAN B0 (3.3V): -0.000781
CHAN B1 (3.15aV): -0.000938
CHAN B2 (3.15bV): -0.001362
CHAN B3 (GND): -0.002101
OPEN: 0.004824
Full Scale: +/- 1 mA
2025-01-22T18:36:51.869Z,1737571011.869 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183648.00,A,3647.95529,N,12150.19521,W,0.389,91.41,220125,,,A*48
2025-01-22T18:36:51.872Z,1737571011.872 [NAL9602](INFO): GPS fix at 20250122T183648: (36.799255, -121.836587)
2025-01-22T18:36:56.078Z,1737571016.078 [SBIT](IMPORTANT): SBIT PASSED
2025-01-22T18:36:56.078Z,1737571016.078 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-01-22T18:36:56.079Z,1737571016.079 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=1 bool;
2025-01-22T18:36:56.079Z,1737571016.079 [SBIT](IMPORTANT): BioacousticsDataBridge.loadAtStartup=1 bool;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): Express linearApproximation acoustic_contact_range 100.000000 meter;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): Express none platform_roll_angle;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=20 ampere_hour;
2025-01-22T18:36:56.080Z,1737571016.080 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=12 volt;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): SpeedControl.rollOptimum=0.925 meter_per_second;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=424.293083 cubic_centimeter;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): VerticalControl.kdPitchMass=0.1 second;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): VerticalControl.kiPitchMass=0.001 reciprocal_second;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): VerticalControl.kpPitchMass=0.1 none;
2025-01-22T18:36:56.081Z,1737571016.081 [SBIT](IMPORTANT): VerticalControl.massDeadband=0 millimeter;
2025-01-22T18:36:56.082Z,1737571016.082 [SBIT](IMPORTANT): VerticalControl.massDefault=6.708742 millimeter;
2025-01-22T18:36:56.082Z,1737571016.082 [SBIT](IMPORTANT): VerticalControl.massOnlyForceInt=1 bool;
2025-01-22T18:36:56.082Z,1737571016.082 [SBIT](IMPORTANT): WetLabsBB2FL.loadAtStartup=1 bool;
2025-01-22T18:36:56.365Z,1737571016.365 [MissionManager](IMPORTANT): Started mission Startup
2025-01-22T18:36:56.365Z,1737571016.365 [Startup] Running Loop=1
2025-01-22T18:36:56.365Z,1737571016.365 [Startup](DEBUG): Aggregate::initialize Startup
2025-01-22T18:36:56.366Z,1737571016.366 [Startup:A.GoToSurface] Running Loop=1
2025-01-22T18:36:56.366Z,1737571016.366 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T18:36:56.366Z,1737571016.366 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-01-22T18:36:56.367Z,1737571016.367 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-01-22T18:36:56.367Z,1737571016.367 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-01-22T18:36:56.367Z,1737571016.367 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-01-22T18:36:56.368Z,1737571016.368 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T18:36:56.368Z,1737571016.368 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T18:36:56.374Z,1737571016.374 [Startup:StartupSatComms] Running Loop=1
2025-01-22T18:36:56.374Z,1737571016.374 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-01-22T18:36:56.374Z,1737571016.374 [Startup:StartupSatComms:A] Running Loop=1
2025-01-22T18:36:56.724Z,1737571016.724 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-01-22T18:36:58.340Z,1737571018.340 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183654.00,A,3647.95488,N,12150.19568,W,0.758,93.07,220125,,,A*4A
2025-01-22T18:36:58.342Z,1737571018.342 [NAL9602](INFO): GPS fix at 20250122T183654: (36.799248, -121.836595)
2025-01-22T18:36:58.354Z,1737571018.354 [Startup:StartupSatComms:A] Stopped
2025-01-22T18:36:58.354Z,1737571018.354 [Startup:StartupSatComms:B] Running Loop=1
2025-01-22T18:36:58.769Z,1737571018.769 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-01-22T18:37:27.827Z,1737571047.827 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004146
2025-01-22T18:37:29.280Z,1737571049.280 [NAL9602](INFO): SBD MO Status=2, MOMSN=12451, MT Status=2, MTMSN=0
2025-01-22T18:37:29.281Z,1737571049.281 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T18:37:36.081Z,1737571056.081 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20250121T215647/Courier0147.lzma
2025-01-22T18:37:37.083Z,1737571057.083 [DataOverHttps](INFO): Moved sent file to Logs/20250121T215647/Courier0147.lzma.bak
2025-01-22T18:37:37.083Z,1737571057.083 [DataOverHttps](INFO): SBD MOMSN=23924302
2025-01-22T18:37:56.334Z,1737571076.334 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20250122T183449/Courier0000.lzma
2025-01-22T18:37:57.335Z,1737571077.335 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0000.lzma.bak
2025-01-22T18:37:57.335Z,1737571077.335 [DataOverHttps](INFO): SBD MOMSN=23924305
2025-01-22T18:37:58.400Z,1737571078.400 [Startup:StartupSatComms:B](INFO): Timed out from 2025-01-22T18:36:58.4Z
2025-01-22T18:37:58.400Z,1737571078.400 [Startup:StartupSatComms:B] Stopped
2025-01-22T18:37:58.400Z,1737571078.400 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-01-22T18:37:58.400Z,1737571078.400 [Startup:StartupSatComms] Stopped
2025-01-22T18:37:58.400Z,1737571078.400 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-01-22T18:37:58.406Z,1737571078.406 [Startup](INFO): Completed Startup
2025-01-22T18:37:58.406Z,1737571078.406 [MissionManager](INFO): Startup is completed.
2025-01-22T18:37:58.406Z,1737571078.406 [MissionManager](INFO): Uninitializing Mission Startup
2025-01-22T18:37:58.406Z,1737571078.406 [Startup] Stopped
2025-01-22T18:37:58.406Z,1737571078.406 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-01-22T18:37:58.406Z,1737571078.406 [Startup:A.GoToSurface] Stopped
2025-01-22T18:37:58.407Z,1737571078.407 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T18:37:58.781Z,1737571078.781 [MissionManager](IMPORTANT): Started mission Default
2025-01-22T18:37:58.781Z,1737571078.781 [Default] Running Loop=1
2025-01-22T18:37:58.781Z,1737571078.781 [Default](DEBUG): Aggregate::initialize Default
2025-01-22T18:37:58.781Z,1737571078.781 [Default:B.GoToSurface] Running Loop=1
2025-01-22T18:37:58.781Z,1737571078.781 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T18:37:58.782Z,1737571078.782 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-01-22T18:37:58.782Z,1737571078.782 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-01-22T18:37:58.782Z,1737571078.782 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-01-22T18:37:58.782Z,1737571078.782 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-01-22T18:37:58.783Z,1737571078.783 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T18:37:58.783Z,1737571078.783 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T18:37:58.783Z,1737571078.783 [Default:A.Wait] Running Loop=1
2025-01-22T18:37:58.783Z,1737571078.783 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-01-22T18:37:59.982Z,1737571079.982 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T18:38:12.129Z,1737571092.129 [Default:A.Wait](INFO): Done Waiting.
2025-01-22T18:38:12.129Z,1737571092.129 [Default:A.Wait] Stopped
2025-01-22T18:38:12.129Z,1737571092.129 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01-22T18:38:12.530Z,1737571092.530 [Default:CheckIn] Running Loop=1
2025-01-22T18:38:12.530Z,1737571092.530 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-01-22T18:38:12.530Z,1737571092.530 [Default:CheckIn:Read_GPS] Running Loop=1
2025-01-22T18:38:12.946Z,1737571092.946 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-22T18:38:14.540Z,1737571094.540 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183810.00,A,3647.95022,N,12150.19611,W,0.194,221.53,220125,,,A*71
2025-01-22T18:38:14.543Z,1737571094.543 [NAL9602](INFO): GPS fix at 20250122T183810: (36.799170, -121.836602)
2025-01-22T18:38:14.570Z,1737571094.570 [Default:CheckIn:Read_GPS] Stopped
2025-01-22T18:38:14.570Z,1737571094.570 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-01-22T18:38:14.979Z,1737571094.979 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-01-22T18:38:22.647Z,1737571102.647 [DataOverHttps](INFO): Sending 498 bytes from file Logs/20250121T215647/Express0149.lzma
2025-01-22T18:38:23.647Z,1737571103.647 [DataOverHttps](INFO): Moved sent file to Logs/20250121T215647/Express0149.lzma.bak
2025-01-22T18:38:23.647Z,1737571103.647 [DataOverHttps](INFO): SBD MOMSN=23924309
2025-01-22T18:38:27.868Z,1737571107.868 [NAL9602](INFO): SBD MO Status=1, MOMSN=12451, MT Status=0, MTMSN=0
2025-01-22T18:38:27.868Z,1737571107.868 [NAL9602](INFO): No messages in MT queue
2025-01-22T18:38:40.821Z,1737571120.821 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250122T183449/Courier0004.lzma
2025-01-22T18:38:41.823Z,1737571121.823 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0004.lzma.bak
2025-01-22T18:38:41.823Z,1737571121.823 [DataOverHttps](INFO): SBD MOMSN=23924317
2025-01-22T18:38:58.610Z,1737571138.610 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T18:39:00.161Z,1737571140.161 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20250121T215647/Express0154.lzma
2025-01-22T18:39:01.164Z,1737571141.164 [DataOverHttps](INFO): Moved sent file to Logs/20250121T215647/Express0154.lzma.bak
2025-01-22T18:39:01.164Z,1737571141.164 [DataOverHttps](INFO): SBD MOMSN=23924322
2025-01-22T18:39:14.099Z,1737571154.099 [DataOverHttps](IMPORTANT): SBD MTMSN=20250122T183913
2025-01-22T18:39:21.671Z,1737571161.671 [DataOverHttps](INFO): Sending 1138 bytes from file Logs/20250122T183449/Express0001.lzma
2025-01-22T18:39:21.677Z,1737571161.677 [DataOverHttps](INFO): Received command: sched asap "load Transport/keepstation.tl;set keepstation.MissionTimeout 4 h;set keepstation.NeedCommsTime 20 min;set keepstation.Latitude 36.806966 degree;set keepstation.Longitude -121.824326 degree;set keepstation.Depth 15 m" jyh0 1 2
2025-01-22T18:39:21.722Z,1737571161.722 [CommandExec](IMPORTANT): got command schedule asap "load Transport/keepstation.tl;set keepstation.MissionTimeout 4 h;set keepstation.NeedCommsTime 20 min;set keepstation.Latitude 36.806966 degree;set keepstation.Longitude -121.824326 degree;set keepstation.Depth 15 m" jyh0 1 2.000000
2025-01-22T18:39:21.723Z,1737571161.723 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=jyh0
2025-01-22T18:39:21.724Z,1737571161.724 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='jyh0'): "load Transport/keepstation.tl;set keepstation.MissionTimeout 4 h;set keepstation.NeedCommsTime 20 min;set keepstation.Latitude 36.806966 degree;set keepstation.Longitude -121.824326 degree;set keepstation.Depth 15 m", ASAP
2025-01-22T18:39:22.876Z,1737571162.876 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0001.lzma.bak
2025-01-22T18:39:22.876Z,1737571162.876 [DataOverHttps](IMPORTANT): SBD MOMSN=23924326, MTMSN=20250122T183922
2025-01-22T18:39:30.377Z,1737571170.377 [DataOverHttps](INFO): Received command: sched asap "set keepstation.DepthDeadband 4 m;set keepstation.MaxDepth 35 m;set keepstation:BackseatDriver.EnableBackseat 1 bool;run" jyh0 2 2
2025-01-22T18:39:30.465Z,1737571170.465 [CommandExec](IMPORTANT): got command schedule asap "set keepstation.DepthDeadband 4 m;set keepstation.MaxDepth 35 m;set keepstation:BackseatDriver.EnableBackseat 1 bool;run" jyh0 2 2.000000
2025-01-22T18:39:30.466Z,1737571170.466 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=jyh0
2025-01-22T18:39:30.467Z,1737571170.467 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='jyh0'): "set keepstation.DepthDeadband 4 m;set keepstation.MaxDepth 35 m;set keepstation:BackseatDriver.EnableBackseat 1 bool;run", ASAP
2025-01-22T18:39:30.587Z,1737571170.587 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl
2025-01-22T18:39:30.587Z,1737571170.587 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl
2025-01-22T18:39:30.587Z,1737571170.587 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl
2025-01-22T18:39:30.590Z,1737571170.590 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl
2025-01-22T18:39:31.309Z,1737571171.309 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/keepstation.tl translated into:
4
45
NaN
NaN
30
15
4
0.75
200
45
2
2025-01-22T18:39:31.314Z,1737571171.314 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h
2025-01-22T18:39:31.318Z,1737571171.318 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min
2025-01-22T18:39:31.320Z,1737571171.320 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg
2025-01-22T18:39:31.323Z,1737571171.323 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg
2025-01-22T18:39:31.326Z,1737571171.326 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m
2025-01-22T18:39:31.330Z,1737571171.330 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m
2025-01-22T18:39:31.333Z,1737571171.333 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m
2025-01-22T18:39:31.336Z,1737571171.336 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s
2025-01-22T18:39:31.339Z,1737571171.339 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m
2025-01-22T18:39:31.342Z,1737571171.342 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m
2025-01-22T18:39:31.365Z,1737571171.365 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km
2025-01-22T18:39:31.366Z,1737571171.366 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl
2025-01-22T18:39:31.366Z,1737571171.366 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl
2025-01-22T18:39:31.367Z,1737571171.367 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl
2025-01-22T18:39:31.937Z,1737571171.937 [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-01-22T18:39:31.963Z,1737571171.963 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h
2025-01-22T18:39:31.968Z,1737571171.968 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min
2025-01-22T18:39:31.975Z,1737571171.975 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg
2025-01-22T18:39:31.979Z,1737571171.979 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s
2025-01-22T18:39:31.990Z,1737571171.990 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s
2025-01-22T18:39:31.997Z,1737571171.997 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s
2025-01-22T18:39:32.000Z,1737571172.000 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min
2025-01-22T18:39:32.008Z,1737571172.008 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min
2025-01-22T18:39:32.022Z,1737571172.022 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-01-22T18:39:32.072Z,1737571172.072 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl
2025-01-22T18:39:32.081Z,1737571172.081 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl
2025-01-22T18:39:32.082Z,1737571172.082 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl
2025-01-22T18:39:32.223Z,1737571172.223 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into:
5
0
200
2000
2025-01-22T18:39:32.263Z,1737571172.263 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m
2025-01-22T18:39:32.266Z,1737571172.266 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2025-01-22T18:39:32.285Z,1737571172.285 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m
2025-01-22T18:39:32.288Z,1737571172.288 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m
2025-01-22T18:39:32.294Z,1737571172.294 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2025-01-22T18:39:32.319Z,1737571172.319 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2025-01-22T18:39:32.342Z,1737571172.342 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2025-01-22T18:39:32.351Z,1737571172.351 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-01-22T18:39:32.351Z,1737571172.351 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-01-22T18:39:32.352Z,1737571172.352 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-01-22T18:39:32.399Z,1737571172.399 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-01-22T18:39:32.422Z,1737571172.422 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool
2025-01-22T18:39:32.440Z,1737571172.440 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-01-22T18:39:32.448Z,1737571172.448 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2025-01-22T18:39:32.448Z,1737571172.448 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2025-01-22T18:39:32.454Z,1737571172.454 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2025-01-22T18:39:32.716Z,1737571172.716 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
99999
2025-01-22T18:39:32.727Z,1737571172.727 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool
2025-01-22T18:39:32.730Z,1737571172.730 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool
2025-01-22T18:39:32.737Z,1737571172.737 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool
2025-01-22T18:39:32.746Z,1737571172.746 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool
2025-01-22T18:39:32.753Z,1737571172.753 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool
2025-01-22T18:39:32.765Z,1737571172.765 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait.
2025-01-22T18:39:32.771Z,1737571172.771 [keepstation:H.Pitch](DEBUG): Construct.
2025-01-22T18:39:32.794Z,1737571172.794 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Construct Buoyancy.
2025-01-22T18:39:32.802Z,1737571172.802 [keepstation:TransitToStation:B.Pitch](DEBUG): Construct.
2025-01-22T18:39:32.819Z,1737571172.819 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Construct.
2025-01-22T18:39:32.832Z,1737571172.832 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2025-01-22T18:39:32.866Z,1737571172.866 [keepstation:KeepStation:B.Pitch](DEBUG): Construct.
2025-01-22T18:39:32.891Z,1737571172.891 [keepstation:KeepStation:C.KeepStation](DEBUG): Construct KeepStation.
2025-01-22T18:39:32.908Z,1737571172.908 [keepstation:KeepStation:D.Wait](DEBUG): Construct Wait.
2025-01-22T18:39:32.930Z,1737571172.930 [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.
"""
MaxDepth = 45 meter
"""
Maximum allowable depth during the mission.
"""
MinOffshore = 2 kilometer
"""
Minimum distance from the shoreline to maintain
"""
}
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
}
call id="StartingMission" refId="NeedComms"
aggregate TransitToStation {
"""
Need a separate aggregate for transit if we want to specify a
different depth for the approach.
"""
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
}
behavior Guidance:Waypoint id="Wpt1" {
run in sequence
set latitude = Latitude
set longitude = Longitude
}
}
call id="OnStation" refId="NeedComms"
aggregate KeepStation {
run in sequence
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
}
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-01-22T18:39:32.931Z,1737571172.931 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation
2025-01-22T18:39:43.070Z,1737571183.070 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250122T183449/Courier0007.lzma
2025-01-22T18:39:44.071Z,1737571184.071 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0007.lzma.bak
2025-01-22T18:39:44.071Z,1737571184.071 [DataOverHttps](INFO): SBD MOMSN=23924364
2025-01-22T18:39:46.102Z,1737571186.102 [CommandExec](IMPORTANT): got command set keepstation.MissionTimeout 4 hour
2025-01-22T18:39:46.103Z,1737571186.103 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 20 minute
2025-01-22T18:39:46.104Z,1737571186.104 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.806966 degree
2025-01-22T18:39:46.104Z,1737571186.104 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.824326 degree
2025-01-22T18:39:46.130Z,1737571186.130 [CommandExec](IMPORTANT): got command set keepstation.Depth 15 meter
2025-01-22T18:39:56.762Z,1737571196.762 [CommandExec](IMPORTANT): got command set keepstation.DepthDeadband 4 meter
2025-01-22T18:39:56.762Z,1737571196.762 [CommandExec](IMPORTANT): got command set keepstation.MaxDepth 35 meter
2025-01-22T18:39:56.763Z,1737571196.763 [CommandExec](IMPORTANT): got command set keepstation:BackseatDriver.EnableBackseat 1 bool
2025-01-22T18:39:56.763Z,1737571196.763 [CommandExec](IMPORTANT): got command run
2025-01-22T18:39:56.766Z,1737571196.766 [CommandExec](IMPORTANT): Running
2025-01-22T18:39:56.912Z,1737571196.912 [Default] Stopped
2025-01-22T18:39:56.912Z,1737571196.912 [Default](DEBUG): Aggregate::uninitialize Default
2025-01-22T18:39:56.912Z,1737571196.912 [Default:B.GoToSurface] Stopped
2025-01-22T18:39:56.912Z,1737571196.912 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T18:39:56.912Z,1737571196.912 [Default:CheckIn] Stopped
2025-01-22T18:39:56.912Z,1737571196.912 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-01-22T18:39:56.912Z,1737571196.912 [Default:CheckIn:Read_Iridium] Stopped
2025-01-22T18:39:56.912Z,1737571196.912 [MissionManager](IMPORTANT): Started mission keepstation
2025-01-22T18:39:56.913Z,1737571196.913 [keepstation] Running Loop=1
2025-01-22T18:39:56.913Z,1737571196.913 [keepstation](DEBUG): Aggregate::initialize keepstation
2025-01-22T18:39:56.913Z,1737571196.913 [keepstation:StandardEnvelopes] Running Loop=1
2025-01-22T18:39:56.913Z,1737571196.913 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes
2025-01-22T18:39:56.913Z,1737571196.913 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:BackseatDriver] Running Loop=1
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver
2025-01-22T18:39:56.914Z,1737571196.914 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly:A] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly:B] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly:C] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly:D] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly:E.Wait] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:H.Pitch] Running Loop=1
2025-01-22T18:39:56.915Z,1737571196.915 [keepstation:H.Pitch](DEBUG): Initialize.
2025-01-22T18:39:56.916Z,1737571196.916 [keepstation:B] Running Loop=1
2025-01-22T18:39:56.916Z,1737571196.916 [keepstation:H.Pitch] Running Loop=1
2025-01-22T18:39:56.916Z,1737571196.916 [keepstation:PowerOnly] Running Loop=1
2025-01-22T18:39:56.917Z,1737571196.917 [keepstation:PowerOnly:D] Stopped
2025-01-22T18:39:56.917Z,1737571196.917 [keepstation:PowerOnly:C] Stopped
2025-01-22T18:39:56.917Z,1737571196.917 [keepstation:PowerOnly:B] Stopped
2025-01-22T18:39:56.917Z,1737571196.917 [keepstation:PowerOnly:A] Stopped
2025-01-22T18:39:56.917Z,1737571196.917 [keepstation:BackseatDriver] Running Loop=1
2025-01-22T18:39:56.918Z,1737571196.918 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat
2025-01-22T18:39:56.937Z,1737571196.937 [keepstation:StandardEnvelopes] Running Loop=1
2025-01-22T18:39:56.937Z,1737571196.937 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-01-22T18:39:56.938Z,1737571196.938 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-01-22T18:39:56.939Z,1737571196.939 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-01-22T18:39:56.939Z,1737571196.939 [keepstation:B] Stopped
2025-01-22T18:39:56.939Z,1737571196.939 [keepstation:D] Running Loop=1
2025-01-22T18:39:56.981Z,1737571196.981 [BackseatComponent](INFO): Powering up
2025-01-22T18:39:56.982Z,1737571196.982 [BackseatComponent](INFO): Subscribing to LCM channels.
2025-01-22T18:39:57.313Z,1737571197.313 [keepstation:D] Stopped
2025-01-22T18:39:57.313Z,1737571197.313 [keepstation:E] Running Loop=1
2025-01-22T18:39:57.713Z,1737571197.713 [keepstation:E] Stopped
2025-01-22T18:39:57.713Z,1737571197.713 [keepstation:StartingMission] Running Loop=1
2025-01-22T18:39:57.714Z,1737571197.714 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission
2025-01-22T18:39:58.130Z,1737571198.130 [keepstation:NeedComms] Running Loop=1
2025-01-22T18:39:58.130Z,1737571198.130 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T18:39:58.130Z,1737571198.130 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T18:39:58.130Z,1737571198.130 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T18:39:58.130Z,1737571198.130 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T18:39:58.131Z,1737571198.131 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T18:39:58.131Z,1737571198.131 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T18:39:58.131Z,1737571198.131 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T18:39:58.132Z,1737571198.132 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T18:39:58.132Z,1737571198.132 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T18:39:58.132Z,1737571198.132 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T18:39:58.134Z,1737571198.134 [keepstation:NeedComms:A](INFO): last time_fix was: 1737571090.000000 second since 1970/01/01T00:00:00Z
2025-01-22T18:39:58.134Z,1737571198.134 [keepstation:NeedComms:A] Stopped
2025-01-22T18:39:58.582Z,1737571198.582 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2025-01-22T18:39:58.583Z,1737571198.583 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T18:39:58.931Z,1737571198.931 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-22T18:40:00.536Z,1737571200.536 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183956.00,A,3647.94548,N,12150.19350,W,0.505,157.11,220125,,,D*77
2025-01-22T18:40:00.538Z,1737571200.538 [NAL9602](INFO): GPS fix at 20250122T183956: (36.799091, -121.836558)
2025-01-22T18:40:00.582Z,1737571200.582 [keepstation:NeedComms:C] Stopped
2025-01-22T18:40:00.582Z,1737571200.582 [keepstation:NeedComms:D] Running Loop=1
2025-01-22T18:40:00.995Z,1737571200.995 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-01-22T18:40:04.449Z,1737571204.449 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250122T183449/Courier0010.lzma
2025-01-22T18:40:05.447Z,1737571205.447 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0010.lzma.bak
2025-01-22T18:40:05.447Z,1737571205.447 [DataOverHttps](INFO): SBD MOMSN=23924366
2025-01-22T18:40:24.107Z,1737571224.107 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20250122T183449/Courier0013.lzma
2025-01-22T18:40:25.182Z,1737571225.182 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0013.lzma.bak
2025-01-22T18:40:25.182Z,1737571225.182 [DataOverHttps](INFO): SBD MOMSN=23924368
2025-01-22T18:40:41.597Z,1737571241.597 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20250122T183449/Express0005.lzma
2025-01-22T18:40:42.599Z,1737571242.599 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0005.lzma.bak
2025-01-22T18:40:42.599Z,1737571242.599 [DataOverHttps](INFO): SBD MOMSN=23924371
2025-01-22T18:40:48.047Z,1737571248.047 [NAL9602](INFO): SBD MO Status=2, MOMSN=12452, MT Status=2, MTMSN=0
2025-01-22T18:40:48.048Z,1737571248.048 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T18:41:00.277Z,1737571260.277 [NAL9602](INFO): SBD MO Status=1, MOMSN=12452, MT Status=0, MTMSN=0
2025-01-22T18:41:00.277Z,1737571260.277 [NAL9602](INFO): No messages in MT queue
2025-01-22T18:41:06.814Z,1737571266.814 [DataOverHttps](INFO): Sending 360 bytes from file Logs/20250122T183449/Express0008.lzma
2025-01-22T18:41:07.807Z,1737571267.807 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0008.lzma.bak
2025-01-22T18:41:07.807Z,1737571267.807 [DataOverHttps](INFO): SBD MOMSN=23924374
2025-01-22T18:41:08.334Z,1737571268.334 [BackseatComponent](IMPORTANT): IBASE811F-02: Running bioacoustics backseat app. Logging to: 20250122T184106
2025-01-22T18:41:11.062Z,1737571271.062 [BackseatComponent](INFO): Created universal data reader for depth with code: 6
2025-01-22T18:41:11.062Z,1737571271.062 [BackseatComponent](INFO): Requesting data from depth (6). Requested size is: 1
2025-01-22T18:41:11.065Z,1737571271.065 [BackseatComponent](INFO): Created universal data reader for latitude with code: 23
2025-01-22T18:41:11.066Z,1737571271.066 [BackseatComponent](INFO): Requesting data from latitude (23). Requested size is: 2
2025-01-22T18:41:11.068Z,1737571271.068 [BackseatComponent](INFO): Created universal data reader for longitude with code: 26
2025-01-22T18:41:11.069Z,1737571271.069 [BackseatComponent](INFO): Requesting data from longitude (26). Requested size is: 3
2025-01-22T18:41:11.072Z,1737571271.072 [BackseatComponent](INFO): Created universal data reader for platform_orientation with code: 52
2025-01-22T18:41:11.073Z,1737571271.073 [BackseatComponent](INFO): Requesting data from platform_orientation (52). Requested size is: 4
2025-01-22T18:41:11.096Z,1737571271.096 [BackseatComponent](INFO): Created universal data reader for platform_pitch_angle with code: 54
2025-01-22T18:41:11.096Z,1737571271.096 [BackseatComponent](INFO): Requesting data from platform_pitch_angle (54). Requested size is: 5
2025-01-22T18:41:11.102Z,1737571271.102 [BackseatComponent](INFO): Created universal data reader for platform_roll_angle with code: 59
2025-01-22T18:41:11.103Z,1737571271.103 [BackseatComponent](INFO): Requesting data from platform_roll_angle (59). Requested size is: 6
2025-01-22T18:41:11.168Z,1737571271.168 [BackseatComponent](INFO): Created universal data reader for platform_x_velocity_wrt_sea_water with code: 70
2025-01-22T18:41:11.168Z,1737571271.168 [BackseatComponent](INFO): Requesting data from platform_x_velocity_wrt_sea_water (70). Requested size is: 7
2025-01-22T18:41:30.714Z,1737571290.714 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T18:41:30.869Z,1737571290.869 [DataOverHttps](INFO): Sending 320 bytes from file Logs/20250122T183449/Express0011.lzma
2025-01-22T18:41:31.871Z,1737571291.871 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0011.lzma.bak
2025-01-22T18:41:31.871Z,1737571291.871 [DataOverHttps](INFO): SBD MOMSN=23924382
2025-01-22T18:41:53.954Z,1737571313.954 [DataOverHttps](INFO): Sending 339 bytes from file Logs/20250122T183449/Express0014.lzma
2025-01-22T18:41:54.955Z,1737571314.955 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0014.lzma.bak
2025-01-22T18:41:54.955Z,1737571314.955 [DataOverHttps](INFO): SBD MOMSN=23924389
2025-01-22T18:41:56.670Z,1737571316.670 [keepstation:NeedComms:D] Stopped
2025-01-22T18:41:56.670Z,1737571316.670 [keepstation:NeedComms:E] Running Loop=1
2025-01-22T18:41:57.067Z,1737571317.067 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-01-22T18:41:58.852Z,1737571318.852 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184155.00,A,3647.93962,N,12150.19326,W,0.486,184.94,220125,,,D*70
2025-01-22T18:41:58.866Z,1737571318.866 [NAL9602](INFO): GPS fix at 20250122T184155: (36.798994, -121.836554)
2025-01-22T18:41:58.942Z,1737571318.942 [keepstation:NeedComms:E] Stopped
2025-01-22T18:41:58.943Z,1737571318.943 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-01-22T18:41:58.943Z,1737571318.943 [keepstation:NeedComms] Stopped
2025-01-22T18:41:58.943Z,1737571318.943 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T18:41:58.943Z,1737571318.943 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T18:41:58.944Z,1737571318.944 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T18:41:59.288Z,1737571319.288 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission
2025-01-22T18:41:59.288Z,1737571319.288 [keepstation:StartingMission] Stopped
2025-01-22T18:41:59.288Z,1737571319.288 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission
2025-01-22T18:41:59.288Z,1737571319.288 [keepstation:TransitToStation] Running Loop=1
2025-01-22T18:41:59.288Z,1737571319.288 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation
2025-01-22T18:41:59.288Z,1737571319.288 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1
2025-01-22T18:41:59.288Z,1737571319.288 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2025-01-22T18:41:59.289Z,1737571319.289 [keepstation:TransitToStation:B.Pitch] Running Loop=1
2025-01-22T18:41:59.289Z,1737571319.289 [keepstation:TransitToStation:B.Pitch](DEBUG): Initialize.
2025-01-22T18:41:59.301Z,1737571319.301 [keepstation:TransitToStation:C.SetSpeed] Running Loop=1
2025-01-22T18:41:59.301Z,1737571319.301 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Initialize.
2025-01-22T18:41:59.301Z,1737571319.301 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1
2025-01-22T18:41:59.302Z,1737571319.302 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2025-01-22T18:41:59.303Z,1737571319.303 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.806965,-121.824326
2025-01-22T18:41:59.663Z,1737571319.663 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326
2025-01-22T18:41:59.664Z,1737571319.664 [keepstation:TransitToStation:C.SetSpeed] Running Loop=1
2025-01-22T18:41:59.664Z,1737571319.664 [keepstation:TransitToStation:B.Pitch] Running Loop=1
2025-01-22T18:41:59.664Z,1737571319.664 [keepstation:TransitToStation:A.Buoyancy] Running Loop=1
2025-01-22T18:41:59.737Z,1737571319.737 [HorizontalControl](DEBUG): kpHeading = 0.400000
2025-01-22T18:41:59.738Z,1737571319.738 [HorizontalControl](DEBUG): kiHeading = 0.001000
2025-01-22T18:41:59.738Z,1737571319.738 [HorizontalControl](DEBUG): kdHeading = 0.050000
2025-01-22T18:42:10.332Z,1737571330.332 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.height_above_sea_floor with code: 1959
2025-01-22T18:42:21.989Z,1737571341.989 [NAL9602](INFO): SBD MO Status=2, MOMSN=12453, MT Status=2, MTMSN=0
2025-01-22T18:42:21.989Z,1737571341.989 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T18:43:27.697Z,1737571407.697 [NAL9602](INFO): SBD MO Status=1, MOMSN=12453, MT Status=0, MTMSN=0
2025-01-22T18:43:27.698Z,1737571407.698 [NAL9602](INFO): No messages in MT queue
2025-01-22T18:43:58.344Z,1737571438.344 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T18:44:58.941Z,1737571498.941 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T18:45:10.997Z,1737571510.997 [Radio_Surface](INFO): Powering down
2025-01-22T18:45:30.065Z,1737571530.065 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T18:45:31.070Z,1737571531.070 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-22T18:46:08.936Z,1737571568.936 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.simrad_data_logging_rate with code: 1960
2025-01-22T18:47:07.453Z,1737571627.453 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.731262
2025-01-22T18:49:46.278Z,1737571786.278 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-01-22T18:49:46.278Z,1737571786.278 [ThrusterHE](INFO): Powering down
2025-01-22T18:49:46.966Z,1737571786.966 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T18:49:47.086Z,1737571787.086 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T18:49:52.610Z,1737571792.610 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-22T18:50:35.939Z,1737571835.939 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-01-22T18:50:35.939Z,1737571835.939 [ThrusterHE](INFO): Powering down
2025-01-22T18:50:36.730Z,1737571836.730 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T18:50:36.850Z,1737571836.850 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T18:50:42.394Z,1737571842.394 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-22T18:51:10.402Z,1737571870.402 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-01-22T18:51:10.402Z,1737571870.402 [ThrusterHE](INFO): Powering down
2025-01-22T18:51:11.262Z,1737571871.262 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T18:51:11.388Z,1737571871.388 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T18:58:32.290Z,1737572312.290 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-01-22T18:58:32.290Z,1737572312.290 [ThrusterHE](INFO): Powering down
2025-01-22T18:58:33.083Z,1737572313.083 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T18:58:33.202Z,1737572313.202 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T18:58:38.898Z,1737572318.898 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-22T18:59:46.654Z,1737572386.654 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-01-22T18:59:46.654Z,1737572386.654 [ThrusterHE](INFO): Powering down
2025-01-22T18:59:47.474Z,1737572387.474 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T18:59:47.594Z,1737572387.594 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T18:59:53.118Z,1737572393.118 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-22T19:02:27.486Z,1737572547.486 [keepstation:NeedComms] Running Loop=1
2025-01-22T19:02:27.486Z,1737572547.486 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T19:02:27.486Z,1737572547.486 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T19:02:27.486Z,1737572547.486 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T19:02:27.486Z,1737572547.486 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T19:02:27.487Z,1737572547.487 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T19:02:27.487Z,1737572547.487 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T19:02:27.487Z,1737572547.487 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T19:02:27.488Z,1737572547.488 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T19:02:27.488Z,1737572547.488 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T19:02:27.489Z,1737572547.489 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T19:02:27.490Z,1737572547.490 [keepstation:NeedComms:A](INFO): last time_fix was: 1737571315.000000 second since 1970/01/01T00:00:00Z
2025-01-22T19:02:27.491Z,1737572547.491 [keepstation:NeedComms:A] Stopped
2025-01-22T19:03:20.603Z,1737572600.603 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T19:03:21.141Z,1737572601.141 [Radio_Surface](INFO): Powering up
2025-01-22T19:03:26.453Z,1737572606.453 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-22T19:03:56.573Z,1737572636.573 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:04:03.816Z,1737572643.816 [NAL9602](INFO): SBD MO Status=1, MOMSN=12454, MT Status=0, MTMSN=0
2025-01-22T19:04:03.816Z,1737572643.816 [NAL9602](INFO): No messages in MT queue
2025-01-22T19:04:05.028Z,1737572645.028 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190401.00,A,3648.16539,N,12149.69074,W,0.253,101.87,220125,,,A*7E
2025-01-22T19:04:05.031Z,1737572645.031 [NAL9602](INFO): GPS fix at 20250122T190401: (36.802757, -121.828179)
2025-01-22T19:04:05.064Z,1737572645.064 [UniversalFixResidualReporter](INFO): Fix residual: 17.3 %DT, over the last 941.3 m. Residual distance 163.2 m at bearing -3.6 degrees. Fix at (36.8028, -121.8282) with 855.1 m made good.
2025-01-22T19:04:05.070Z,1737572645.070 [keepstation:NeedComms:C] Stopped
2025-01-22T19:04:05.070Z,1737572645.070 [keepstation:NeedComms:D] Running Loop=1
2025-01-22T19:04:24.661Z,1737572664.661 [NAL9602](INFO): SBD MO Status=1, MOMSN=12455, MT Status=0, MTMSN=0
2025-01-22T19:04:24.711Z,1737572664.711 [NAL9602](INFO): Sent 205 bytes from file Logs/20250122T183449/Courier0016.lzma
2025-01-22T19:04:24.711Z,1737572664.711 [NAL9602](INFO): Packets left to send: 0
2025-01-22T19:04:27.709Z,1737572667.709 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:04:40.390Z,1737572680.390 [NAL9602](INFO): SBD MO Status=2, MOMSN=12456, MT Status=2, MTMSN=0
2025-01-22T19:04:40.390Z,1737572680.390 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T19:04:58.396Z,1737572698.396 [NAL9602](INFO): SBD MO Status=1, MOMSN=12456, MT Status=0, MTMSN=0
2025-01-22T19:04:58.449Z,1737572698.449 [NAL9602](INFO): Sent 332 bytes from file Logs/20250122T183449/Express0017.lzma
2025-01-22T19:04:58.449Z,1737572698.449 [NAL9602](INFO): Packets left to send: 1
2025-01-22T19:04:58.833Z,1737572698.833 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:05:09.166Z,1737572709.166 [NAL9602](INFO): SBD MO Status=1, MOMSN=12457, MT Status=0, MTMSN=0
2025-01-22T19:05:09.214Z,1737572709.214 [NAL9602](INFO): Sent 146 bytes from file Logs/20250122T183449/Express0017.lzma
2025-01-22T19:05:09.215Z,1737572709.215 [NAL9602](INFO): Packets left to send: 0
2025-01-22T19:05:16.916Z,1737572716.916 [NAL9602](INFO): SBD MO Status=0, MOMSN=12458, MT Status=0, MTMSN=0
2025-01-22T19:05:17.002Z,1737572717.002 [keepstation:NeedComms:D] Stopped
2025-01-22T19:05:17.002Z,1737572717.002 [keepstation:NeedComms:E] Running Loop=1
2025-01-22T19:05:19.322Z,1737572719.322 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190515.00,A,3648.16394,N,12149.68675,W,0.233,156.58,220125,,,A*7B
2025-01-22T19:05:19.324Z,1737572719.324 [NAL9602](INFO): GPS fix at 20250122T190515: (36.802732, -121.828113)
2025-01-22T19:05:19.342Z,1737572719.342 [keepstation:NeedComms:E] Stopped
2025-01-22T19:05:19.343Z,1737572719.343 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-01-22T19:05:19.343Z,1737572719.343 [keepstation:NeedComms] Stopped
2025-01-22T19:05:19.343Z,1737572719.343 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T19:05:19.343Z,1737572719.343 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T19:05:19.343Z,1737572719.343 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T19:05:29.958Z,1737572729.958 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:05:39.341Z,1737572739.341 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002909
2025-01-22T19:05:51.034Z,1737572751.034 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T19:06:16.489Z,1737572776.489 [BPC1](ERROR): Battery stick #62 (s/n: 00CC) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-01-22T19:06:16.490Z,1737572776.490 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 3.
2025-01-22T19:06:16.493Z,1737572776.493 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2025-01-22T19:06:25.592Z,1737572785.592 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 0.75 m/s, pitch 20.00 deg, mass-position 6.71 mm (1 active estimators).
2025-01-22T19:07:01.811Z,1737572821.811 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:07:26.061Z,1737572846.061 [Radio_Surface](INFO): Powering down
2025-01-22T19:07:32.942Z,1737572852.942 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:07:33.946Z,1737572853.946 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-22T19:09:12.358Z,1737572952.358 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.751205
2025-01-22T19:13:54.018Z,1737573234.018 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-01-22T19:19:45.257Z,1737573585.257 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Reached waypoint: 36.806965,-121.824326
2025-01-22T19:19:45.257Z,1737573585.257 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped
2025-01-22T19:19:45.257Z,1737573585.257 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2025-01-22T19:19:45.258Z,1737573585.258 [keepstation:TransitToStation](INFO): Completed keepstation:TransitToStation
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:TransitToStation] Stopped
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:TransitToStation:A.Buoyancy] Stopped
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:TransitToStation:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:TransitToStation:B.Pitch] Stopped
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:TransitToStation:C.SetSpeed] Stopped
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:TransitToStation:C.SetSpeed](DEBUG): Uninitialize.
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:OnStation] Running Loop=1
2025-01-22T19:19:45.259Z,1737573585.259 [keepstation:OnStation](DEBUG): Aggregate::initialize keepstation:OnStation
2025-01-22T19:19:45.666Z,1737573585.666 [keepstation:NeedComms] Running Loop=1
2025-01-22T19:19:45.666Z,1737573585.666 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T19:19:45.666Z,1737573585.666 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T19:19:45.666Z,1737573585.666 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T19:19:45.666Z,1737573585.666 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T19:19:45.667Z,1737573585.667 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T19:19:45.667Z,1737573585.667 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T19:19:45.667Z,1737573585.667 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T19:19:45.668Z,1737573585.668 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T19:19:45.668Z,1737573585.668 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T19:19:45.668Z,1737573585.668 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T19:19:45.670Z,1737573585.670 [keepstation:NeedComms:A](INFO): last time_fix was: 1737572715.000000 second since 1970/01/01T00:00:00Z
2025-01-22T19:19:45.670Z,1737573585.670 [keepstation:NeedComms:A] Stopped
2025-01-22T19:20:41.047Z,1737573641.047 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T19:20:41.691Z,1737573641.691 [Radio_Surface](INFO): Powering up
2025-01-22T19:20:47.225Z,1737573647.225 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-22T19:21:17.369Z,1737573677.369 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:21:22.648Z,1737573682.648 [NAL9602](INFO): SBD MO Status=0, MOMSN=12459, MT Status=0, MTMSN=0
2025-01-22T19:21:22.648Z,1737573682.648 [NAL9602](INFO): No messages in MT queue
2025-01-22T19:21:23.857Z,1737573683.857 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192120.00,A,3648.36449,N,12149.42010,W,0.214,140.34,220125,,,A*7B
2025-01-22T19:21:23.859Z,1737573683.859 [NAL9602](INFO): GPS fix at 20250122T192120: (36.806075, -121.823668)
2025-01-22T19:21:23.872Z,1737573683.872 [UniversalFixResidualReporter](INFO): Fix residual: 17.5 %DT, over the last 680.8 m. Residual distance 119.4 m at bearing -5.9 degrees. Fix at (36.8061, -121.8237) with 542.9 m made good.
2025-01-22T19:21:23.878Z,1737573683.878 [keepstation:NeedComms:C] Stopped
2025-01-22T19:21:23.878Z,1737573683.878 [keepstation:NeedComms:D] Running Loop=1
2025-01-22T19:21:39.128Z,1737573699.128 [NAL9602](INFO): SBD MO Status=1, MOMSN=12460, MT Status=0, MTMSN=0
2025-01-22T19:21:39.177Z,1737573699.177 [NAL9602](INFO): Sent 211 bytes from file Logs/20250122T183449/Courier0019.lzma
2025-01-22T19:21:39.177Z,1737573699.177 [NAL9602](INFO): Packets left to send: 0
2025-01-22T19:21:48.498Z,1737573708.498 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:21:50.829Z,1737573710.829 [NAL9602](INFO): SBD MO Status=1, MOMSN=12461, MT Status=0, MTMSN=0
2025-01-22T19:21:50.885Z,1737573710.885 [NAL9602](INFO): Sent 210 bytes from file Logs/20250122T183449/Express0020.lzma
2025-01-22T19:21:50.885Z,1737573710.885 [NAL9602](INFO): Packets left to send: 0
2025-01-22T19:21:55.595Z,1737573715.595 [NAL9602](INFO): SBD MO Status=0, MOMSN=12462, MT Status=0, MTMSN=0
2025-01-22T19:21:55.682Z,1737573715.682 [keepstation:NeedComms:D] Stopped
2025-01-22T19:21:55.682Z,1737573715.682 [keepstation:NeedComms:E] Running Loop=1
2025-01-22T19:21:58.025Z,1737573718.025 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192154.00,A,3648.36236,N,12149.41717,W,0.156,131.60,220125,,,D*72
2025-01-22T19:21:58.027Z,1737573718.027 [NAL9602](INFO): GPS fix at 20250122T192154: (36.806039, -121.823620)
2025-01-22T19:21:58.042Z,1737573718.042 [keepstation:NeedComms:E] Stopped
2025-01-22T19:21:58.043Z,1737573718.043 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-01-22T19:21:58.043Z,1737573718.043 [keepstation:NeedComms] Stopped
2025-01-22T19:21:58.043Z,1737573718.043 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T19:21:58.044Z,1737573718.044 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T19:21:58.044Z,1737573718.044 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T19:21:58.465Z,1737573718.465 [keepstation:OnStation](INFO): Completed keepstation:OnStation
2025-01-22T19:21:58.465Z,1737573718.465 [keepstation:OnStation] Stopped
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:OnStation](DEBUG): Aggregate::uninitialize keepstation:OnStation
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:KeepStation] Running Loop=1
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:KeepStation](DEBUG): Aggregate::initialize keepstation:KeepStation
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:KeepStation:A] Running Loop=1
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:KeepStation:B.Pitch] Running Loop=1
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:KeepStation:B.Pitch](DEBUG): Initialize.
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:KeepStation:C.KeepStation] Running Loop=1
2025-01-22T19:21:58.466Z,1737573718.466 [keepstation:KeepStation:C.KeepStation](DEBUG): Initialize KeepStationComponent.
2025-01-22T19:21:58.467Z,1737573718.467 [keepstation:KeepStation:D.Wait] Running Loop=1
2025-01-22T19:21:58.467Z,1737573718.467 [keepstation:KeepStation:D.Wait](DEBUG): Initialize Wait Component.
2025-01-22T19:21:58.841Z,1737573718.841 [keepstation:KeepStation:C.KeepStation] Running Loop=1
2025-01-22T19:21:58.842Z,1737573718.842 [keepstation:KeepStation:B.Pitch] Running Loop=1
2025-01-22T19:21:58.843Z,1737573718.843 [keepstation:KeepStation:A] Running Loop=1
2025-01-22T19:22:19.622Z,1737573739.622 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:22:30.346Z,1737573750.346 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T19:22:50.769Z,1737573770.769 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:23:02.964Z,1737573782.964 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003145
2025-01-22T19:23:07.817Z,1737573787.817 [BuoyancyServo](FAULT): Overload Error
2025-01-22T19:23:07.817Z,1737573787.817 [BuoyancyServo] Hardware Fault, FailCount= 1
2025-01-22T19:23:07.817Z,1737573787.817 [BuoyancyServo](ERROR): Hardware Fault
2025-01-22T19:23:08.069Z,1737573788.069 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo
2025-01-22T19:23:09.819Z,1737573789.819 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-01-22T19:23:09.819Z,1737573789.819 [BuoyancyServo](INFO): Powering down
2025-01-22T19:23:10.734Z,1737573790.734 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2025-01-22T19:23:10.734Z,1737573790.734 [BuoyancyServo] No Fault, FailCount= 1
2025-01-22T19:23:11.020Z,1737573791.020 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-01-22T19:23:11.034Z,1737573791.034 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-01-22T19:24:23.949Z,1737573863.949 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:24:32.197Z,1737573872.197 [Radio_Surface](INFO): Powering down
2025-01-22T19:24:55.073Z,1737573895.073 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:24:56.077Z,1737573896.077 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-22T19:26:03.378Z,1737573963.378 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.417404
2025-01-22T19:41:58.086Z,1737574918.086 [keepstation:NeedComms] Running Loop=1
2025-01-22T19:41:58.086Z,1737574918.086 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T19:41:58.086Z,1737574918.086 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T19:41:58.086Z,1737574918.086 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T19:41:58.086Z,1737574918.086 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T19:41:58.087Z,1737574918.087 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T19:41:58.087Z,1737574918.087 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T19:41:58.087Z,1737574918.087 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T19:41:58.088Z,1737574918.088 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T19:41:58.088Z,1737574918.088 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T19:41:58.088Z,1737574918.088 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T19:41:58.090Z,1737574918.090 [keepstation:NeedComms:A](INFO): last time_fix was: 1737573714.000000 second since 1970/01/01T00:00:00Z
2025-01-22T19:41:58.090Z,1737574918.090 [keepstation:NeedComms:A] Stopped
2025-01-22T19:43:22.723Z,1737575002.723 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T19:43:23.425Z,1737575003.425 [Radio_Surface](INFO): Powering up
2025-01-22T19:43:28.697Z,1737575008.697 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-22T19:43:58.823Z,1737575038.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:44:29.943Z,1737575069.943 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:44:40.827Z,1737575080.827 [NAL9602](INFO): SBD MO Status=0, MOMSN=12463, MT Status=0, MTMSN=0
2025-01-22T19:44:40.827Z,1737575080.827 [NAL9602](INFO): No messages in MT queue
2025-01-22T19:44:42.048Z,1737575082.048 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194438.00,A,3648.27740,N,12149.39684,W,1.069,235.14,220125,,,A*76
2025-01-22T19:44:42.050Z,1737575082.050 [NAL9602](INFO): GPS fix at 20250122T194438: (36.804623, -121.823281)
2025-01-22T19:44:42.063Z,1737575082.063 [keepstation:KeepStation:C.KeepStation](INFO): Rest->Waypoint
2025-01-22T19:44:42.066Z,1737575082.066 [keepstation:NeedComms:C] Stopped
2025-01-22T19:44:42.066Z,1737575082.066 [keepstation:NeedComms:D] Running Loop=1
2025-01-22T19:45:01.065Z,1737575101.065 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:45:02.943Z,1737575102.943 [NAL9602](INFO): SBD MO Status=2, MOMSN=12464, MT Status=2, MTMSN=0
2025-01-22T19:45:02.943Z,1737575102.943 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T19:45:13.315Z,1737575113.315 [NAL9602](INFO): SBD MO Status=1, MOMSN=12464, MT Status=0, MTMSN=0
2025-01-22T19:45:13.365Z,1737575113.365 [NAL9602](INFO): Sent 73 bytes from file Logs/20250122T183449/Courier0022.lzma
2025-01-22T19:45:13.365Z,1737575113.365 [NAL9602](INFO): Packets left to send: 0
2025-01-22T19:45:30.432Z,1737575130.432 [NAL9602](INFO): SBD MO Status=1, MOMSN=12465, MT Status=0, MTMSN=0
2025-01-22T19:45:30.481Z,1737575130.481 [NAL9602](INFO): Sent 237 bytes from file Logs/20250122T183449/Express0023.lzma
2025-01-22T19:45:30.482Z,1737575130.482 [NAL9602](INFO): Packets left to send: 0
2025-01-22T19:45:32.189Z,1737575132.189 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:45:41.143Z,1737575141.143 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003114
2025-01-22T19:45:42.630Z,1737575142.630 [keepstation:NeedComms:D] Stopped
2025-01-22T19:45:42.630Z,1737575142.630 [keepstation:NeedComms:E] Running Loop=1
2025-01-22T19:45:48.708Z,1737575148.708 [NAL9602](INFO): SBD MO Status=2, MOMSN=12466, MT Status=2, MTMSN=0
2025-01-22T19:45:48.708Z,1737575148.708 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T19:45:49.925Z,1737575149.925 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194546.00,A,3648.27321,N,12149.40374,W,0.914,212.60,220125,,,A*7D
2025-01-22T19:45:49.927Z,1737575149.927 [NAL9602](INFO): GPS fix at 20250122T194546: (36.804553, -121.823396)
2025-01-22T19:45:50.006Z,1737575150.006 [keepstation:NeedComms:E] Stopped
2025-01-22T19:45:50.007Z,1737575150.007 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-01-22T19:45:50.007Z,1737575150.007 [keepstation:NeedComms] Stopped
2025-01-22T19:45:50.007Z,1737575150.007 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T19:45:50.007Z,1737575150.007 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T19:45:50.007Z,1737575150.007 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T19:46:22.345Z,1737575182.345 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T19:47:13.133Z,1737575233.133 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:47:36.406Z,1737575256.406 [Radio_Surface](INFO): Powering down
2025-01-22T19:47:44.285Z,1737575264.285 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T19:47:45.289Z,1737575265.289 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-22T19:49:23.693Z,1737575363.694 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.759216
2025-01-22T19:49:46.634Z,1737575386.634 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-01-22T19:49:46.634Z,1737575386.634 [ThrusterHE](INFO): Powering down
2025-01-22T19:49:47.590Z,1737575387.590 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T19:49:47.710Z,1737575387.710 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T19:49:53.286Z,1737575393.286 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-22T19:56:11.338Z,1737575771.338 [keepstation:KeepStation:C.KeepStation](INFO): Waypoint->Rest
2025-01-22T20:05:49.986Z,1737576349.986 [keepstation:NeedComms] Running Loop=1
2025-01-22T20:05:49.986Z,1737576349.986 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T20:05:49.986Z,1737576349.986 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T20:05:49.986Z,1737576349.986 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T20:05:49.986Z,1737576349.986 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T20:05:49.987Z,1737576349.987 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T20:05:49.987Z,1737576349.987 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T20:05:49.987Z,1737576349.987 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T20:05:49.988Z,1737576349.988 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T20:05:49.988Z,1737576349.988 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T20:05:49.989Z,1737576349.989 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T20:05:49.990Z,1737576349.990 [keepstation:NeedComms:A](INFO): last time_fix was: 1737575146.000000 second since 1970/01/01T00:00:00Z
2025-01-22T20:05:49.990Z,1737576349.990 [keepstation:NeedComms:A] Stopped
2025-01-22T20:07:15.491Z,1737576435.491 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T20:07:16.237Z,1737576436.237 [Radio_Surface](INFO): Powering up
2025-01-22T20:07:22.165Z,1737576442.165 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-22T20:07:52.288Z,1737576472.288 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:08:15.060Z,1737576495.060 [NAL9602](INFO): SBD MO Status=0, MOMSN=12466, MT Status=0, MTMSN=0
2025-01-22T20:08:15.061Z,1737576495.061 [NAL9602](INFO): No messages in MT queue
2025-01-22T20:08:16.266Z,1737576496.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200812.00,A,3648.40775,N,12149.39163,W,1.050,129.43,220125,,,A*73
2025-01-22T20:08:16.270Z,1737576496.270 [NAL9602](INFO): GPS fix at 20250122T200812: (36.806796, -121.823194)
2025-01-22T20:08:16.282Z,1737576496.282 [UniversalFixResidualReporter](INFO): Fix residual: 28.1 %DT, over the last 548.1 m. Residual distance 154.0 m at bearing -23.0 degrees. Fix at (36.8068, -121.8232) with 250.0 m made good.
2025-01-22T20:08:16.290Z,1737576496.290 [keepstation:NeedComms:C] Stopped
2025-01-22T20:08:16.290Z,1737576496.290 [keepstation:NeedComms:D] Running Loop=1
2025-01-22T20:08:23.409Z,1737576503.409 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:08:24.865Z,1737576504.865 [NAL9602](INFO): SBD MO Status=1, MOMSN=12467, MT Status=0, MTMSN=0
2025-01-22T20:08:24.913Z,1737576504.913 [NAL9602](INFO): Sent 82 bytes from file Logs/20250122T183449/Courier0025.lzma
2025-01-22T20:08:24.913Z,1737576504.913 [NAL9602](INFO): Packets left to send: 0
2025-01-22T20:08:34.937Z,1737576514.937 [NAL9602](INFO): SBD MO Status=1, MOMSN=12468, MT Status=0, MTMSN=0
2025-01-22T20:08:34.994Z,1737576514.994 [NAL9602](INFO): Sent 176 bytes from file Logs/20250122T183449/Express0026.lzma
2025-01-22T20:08:34.994Z,1737576514.994 [NAL9602](INFO): Packets left to send: 0
2025-01-22T20:08:42.709Z,1737576522.709 [NAL9602](INFO): SBD MO Status=0, MOMSN=12469, MT Status=0, MTMSN=0
2025-01-22T20:08:42.806Z,1737576522.806 [keepstation:NeedComms:D] Stopped
2025-01-22T20:08:42.806Z,1737576522.806 [keepstation:NeedComms:E] Running Loop=1
2025-01-22T20:08:45.156Z,1737576525.156 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200841.00,A,3648.40477,N,12149.38712,W,0.719,99.93,220125,,,D*4C
2025-01-22T20:08:45.158Z,1737576525.158 [NAL9602](INFO): GPS fix at 20250122T200841: (36.806746, -121.823119)
2025-01-22T20:08:45.174Z,1737576525.174 [keepstation:NeedComms:E] Stopped
2025-01-22T20:08:45.175Z,1737576525.175 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-01-22T20:08:45.175Z,1737576525.175 [keepstation:NeedComms] Stopped
2025-01-22T20:08:45.175Z,1737576525.175 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T20:08:45.175Z,1737576525.175 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T20:08:45.175Z,1737576525.175 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T20:08:54.533Z,1737576534.533 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:09:17.476Z,1737576557.476 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T20:09:25.665Z,1737576565.665 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:09:36.050Z,1737576576.050 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003193
2025-01-22T20:10:00.833Z,1737576600.833 [BuoyancyServo](FAULT): Overload Error
2025-01-22T20:10:00.833Z,1737576600.833 [BuoyancyServo] Hardware Fault, FailCount= 1
2025-01-22T20:10:00.833Z,1737576600.833 [BuoyancyServo](ERROR): Hardware Fault
2025-01-22T20:10:01.085Z,1737576601.085 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo
2025-01-22T20:10:02.838Z,1737576602.838 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-01-22T20:10:02.838Z,1737576602.838 [BuoyancyServo](INFO): Powering down
2025-01-22T20:10:03.749Z,1737576603.749 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2025-01-22T20:10:03.750Z,1737576603.750 [BuoyancyServo] No Fault, FailCount= 1
2025-01-22T20:10:04.154Z,1737576604.154 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-01-22T20:10:04.181Z,1737576604.181 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-01-22T20:10:58.169Z,1737576658.169 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:11:16.289Z,1737576676.289 [Radio_Surface](INFO): Powering down
2025-01-22T20:11:29.297Z,1737576689.297 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:11:30.301Z,1737576690.301 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-22T20:13:05.706Z,1737576785.706 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.746811
2025-01-22T20:28:47.938Z,1737577727.938 [keepstation:NeedComms] Running Loop=1
2025-01-22T20:28:47.938Z,1737577727.938 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T20:28:47.938Z,1737577727.938 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T20:28:47.938Z,1737577727.938 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T20:28:47.938Z,1737577727.938 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T20:28:47.939Z,1737577727.939 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T20:28:47.939Z,1737577727.939 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T20:28:47.939Z,1737577727.939 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T20:28:47.940Z,1737577727.940 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T20:28:47.940Z,1737577727.940 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T20:28:47.953Z,1737577727.953 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T20:28:47.954Z,1737577727.954 [keepstation:NeedComms:A](INFO): last time_fix was: 1737576521.000000 second since 1970/01/01T00:00:00Z
2025-01-22T20:28:47.955Z,1737577727.955 [keepstation:NeedComms:A] Stopped
2025-01-22T20:30:10.799Z,1737577810.799 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T20:30:11.561Z,1737577811.561 [Radio_Surface](INFO): Powering up
2025-01-22T20:30:16.989Z,1737577816.989 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-22T20:30:22.491Z,1737577822.491 [NAL9602](INFO): SBD MO Status=0, MOMSN=12470, MT Status=0, MTMSN=0
2025-01-22T20:30:22.492Z,1737577822.492 [NAL9602](INFO): No messages in MT queue
2025-01-22T20:30:23.708Z,1737577823.708 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203020.00,A,3648.32254,N,12149.39515,W,1.283,206.87,220125,,,A*75
2025-01-22T20:30:23.710Z,1737577823.710 [NAL9602](INFO): GPS fix at 20250122T203020: (36.805376, -121.823252)
2025-01-22T20:30:23.749Z,1737577823.749 [keepstation:KeepStation:C.KeepStation](INFO): Rest->Waypoint
2025-01-22T20:30:23.754Z,1737577823.754 [keepstation:NeedComms:C] Stopped
2025-01-22T20:30:23.754Z,1737577823.754 [keepstation:NeedComms:D] Running Loop=1
2025-01-22T20:30:47.109Z,1737577847.109 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:30:57.882Z,1737577857.882 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T20:31:18.233Z,1737577878.233 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:31:49.357Z,1737577909.357 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:32:20.481Z,1737577940.481 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:32:29.393Z,1737577949.393 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003156
2025-01-22T20:32:40.706Z,1737577960.706 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250122T183449/Courier0028.lzma
2025-01-22T20:32:41.699Z,1737577961.699 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0028.lzma.bak
2025-01-22T20:32:41.699Z,1737577961.699 [DataOverHttps](INFO): SBD MOMSN=23924511
2025-01-22T20:32:59.165Z,1737577979.165 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20250122T183449/Express0029.lzma
2025-01-22T20:33:00.167Z,1737577980.167 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0029.lzma.bak
2025-01-22T20:33:00.167Z,1737577980.167 [DataOverHttps](INFO): SBD MOMSN=23924514
2025-01-22T20:33:01.922Z,1737577981.922 [keepstation:NeedComms:D] Stopped
2025-01-22T20:33:01.922Z,1737577981.922 [keepstation:NeedComms:E] Running Loop=1
2025-01-22T20:33:03.848Z,1737577983.848 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203300.00,A,3648.30926,N,12149.41875,W,0.214,211.90,220125,,,A*73
2025-01-22T20:33:03.870Z,1737577983.870 [NAL9602](INFO): GPS fix at 20250122T203300: (36.805154, -121.823646)
2025-01-22T20:33:03.954Z,1737577983.954 [keepstation:NeedComms:E] Stopped
2025-01-22T20:33:03.955Z,1737577983.955 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-01-22T20:33:03.955Z,1737577983.955 [keepstation:NeedComms] Stopped
2025-01-22T20:33:03.955Z,1737577983.955 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T20:33:03.955Z,1737577983.955 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T20:33:03.955Z,1737577983.955 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T20:33:19.503Z,1737577999.503 [NAL9602](INFO): SBD MO Status=0, MOMSN=12471, MT Status=0, MTMSN=0
2025-01-22T20:33:19.503Z,1737577999.503 [NAL9602](INFO): No messages in MT queue
2025-01-22T20:33:50.152Z,1737578030.152 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T20:34:33.581Z,1737578073.581 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:34:39.193Z,1737578079.193 [Radio_Surface](INFO): Powering down
2025-01-22T20:34:59.869Z,1737578099.869 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-01-22T20:35:04.705Z,1737578104.705 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:35:05.710Z,1737578105.710 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-22T20:36:13.990Z,1737578173.990 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.926865
2025-01-22T20:37:17.425Z,1737578237.425 [BPC1](ERROR): Battery stick #62 (s/n: 00CC) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0.
2025-01-22T20:37:17.426Z,1737578237.426 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 3.
2025-01-22T20:37:17.428Z,1737578237.428 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2025-01-22T20:40:46.459Z,1737578446.459 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2025-01-22T20:40:46.459Z,1737578446.459 [ThrusterHE](INFO): Powering down
2025-01-22T20:40:47.410Z,1737578447.410 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-01-22T20:40:47.530Z,1737578447.530 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-01-22T20:40:53.230Z,1737578453.230 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-01-22T20:41:32.467Z,1737578492.467 [keepstation:KeepStation:C.KeepStation](INFO): Waypoint->Rest
2025-01-22T20:53:52.310Z,1737579232.310 [keepstation:NeedComms] Running Loop=1
2025-01-22T20:53:52.310Z,1737579232.310 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T20:53:52.310Z,1737579232.310 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T20:53:52.310Z,1737579232.310 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T20:53:52.310Z,1737579232.310 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T20:53:52.311Z,1737579232.311 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T20:53:52.311Z,1737579232.311 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T20:53:52.312Z,1737579232.312 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T20:53:52.312Z,1737579232.312 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T20:53:52.312Z,1737579232.312 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T20:53:52.313Z,1737579232.313 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T20:53:52.330Z,1737579232.330 [keepstation:NeedComms:A](INFO): last time_fix was: 1737577980.000000 second since 1970/01/01T00:00:00Z
2025-01-22T20:53:52.330Z,1737579232.330 [keepstation:NeedComms:A] Stopped
2025-01-22T20:54:55.835Z,1737579295.835 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T20:54:56.265Z,1737579296.265 [Radio_Surface](INFO): Powering up
2025-01-22T20:55:01.631Z,1737579301.631 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-22T20:55:31.749Z,1737579331.749 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:56:02.873Z,1737579362.873 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:56:06.004Z,1737579366.004 [NAL9602](INFO): SBD MO Status=0, MOMSN=12472, MT Status=0, MTMSN=0
2025-01-22T20:56:06.004Z,1737579366.004 [NAL9602](INFO): No messages in MT queue
2025-01-22T20:56:06.958Z,1737579366.958 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T20:56:06.958Z,1737579366.958 [DATMMP](INFO): doppler rx: x0
2025-01-22T20:56:06.958Z,1737579366.958 [DATMMP](INFO): Received message type: doppler
2025-01-22T20:56:06.959Z,1737579366.959 [DATMMP](INFO): Handled
2025-01-22T20:56:07.210Z,1737579367.210 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T20:56:07.211Z,1737579367.211 [DATMMP](INFO): nav_stat rx: x0 x1 x1
2025-01-22T20:56:07.211Z,1737579367.211 [DATMMP](INFO): Received message type: nav_stat
2025-01-22T20:56:07.211Z,1737579367.211 [DATMMP](INFO): Handled
2025-01-22T20:56:07.214Z,1737579367.214 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205603.00,A,3648.42180,N,12149.41581,W,0.933,118.81,220125,,,A*70
2025-01-22T20:56:07.216Z,1737579367.216 [NAL9602](INFO): GPS fix at 20250122T205603: (36.807030, -121.823597)
2025-01-22T20:56:07.266Z,1737579367.266 [keepstation:NeedComms:C] Stopped
2025-01-22T20:56:07.266Z,1737579367.266 [keepstation:NeedComms:D] Running Loop=1
2025-01-22T20:56:07.462Z,1737579367.462 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T20:56:07.463Z,1737579367.463 [DATMMP](INFO): timestamp rx: x1 x14 x38 x5 x705
2025-01-22T20:56:07.463Z,1737579367.463 [DATMMP](INFO): Rx dataTimestamp_ set to:1737579382.575488
2025-01-22T20:56:07.464Z,1737579367.464 [DATMMP](INFO): Rx ping set to:1737579367.462643
2025-01-22T20:56:07.464Z,1737579367.464 [DATMMP](INFO): Received message type: timestamp
2025-01-22T20:56:07.464Z,1737579367.464 [DATMMP](INFO): Handled
2025-01-22T20:56:07.714Z,1737579367.714 [DATMMP](INFO): GSXN notify for xid: 0
2025-01-22T20:56:07.715Z,1737579367.715 [DATMMP](INFO): acstats rx: x0 x0 x0 x57 x206 x28 x64 x0 x0 xFFFF x0 x48 x0 x0
2025-01-22T20:56:07.716Z,1737579367.716 [DATMMP](INFO): Received message type: acstats
2025-01-22T20:56:07.716Z,1737579367.716 [DATMMP](INFO): Handled
2025-01-22T20:56:32.084Z,1737579392.084 [NAL9602](INFO): SBD MO Status=2, MOMSN=12473, MT Status=2, MTMSN=0
2025-01-22T20:56:32.084Z,1737579392.084 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T20:56:33.998Z,1737579393.998 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:57:05.126Z,1737579425.126 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:57:14.762Z,1737579434.762 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003211
2025-01-22T20:57:22.637Z,1737579442.637 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20250122T183449/Courier0031.lzma
2025-01-22T20:57:23.639Z,1737579443.639 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0031.lzma.bak
2025-01-22T20:57:23.639Z,1737579443.639 [DataOverHttps](INFO): SBD MOMSN=23924532
2025-01-22T20:57:40.381Z,1737579460.381 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20250122T183449/Express0032.lzma
2025-01-22T20:57:41.383Z,1737579461.383 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0032.lzma.bak
2025-01-22T20:57:41.383Z,1737579461.383 [DataOverHttps](INFO): SBD MOMSN=23924535
2025-01-22T20:57:42.710Z,1737579462.710 [keepstation:NeedComms:D] Stopped
2025-01-22T20:57:42.710Z,1737579462.710 [keepstation:NeedComms:E] Running Loop=1
2025-01-22T20:57:44.696Z,1737579464.696 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205741.00,A,3648.41554,N,12149.40771,W,0.544,129.79,220125,,,A*7C
2025-01-22T20:57:44.698Z,1737579464.698 [NAL9602](INFO): GPS fix at 20250122T205741: (36.806926, -121.823462)
2025-01-22T20:57:44.746Z,1737579464.746 [keepstation:NeedComms:E] Stopped
2025-01-22T20:57:44.747Z,1737579464.747 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms
2025-01-22T20:57:44.747Z,1737579464.747 [keepstation:NeedComms] Stopped
2025-01-22T20:57:44.747Z,1737579464.747 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T20:57:44.747Z,1737579464.747 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T20:57:44.747Z,1737579464.747 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T20:58:17.422Z,1737579497.422 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T20:58:58.685Z,1737579538.685 [BuoyancyServo](FAULT): Overload Error
2025-01-22T20:58:58.685Z,1737579538.685 [BuoyancyServo] Hardware Fault, FailCount= 1
2025-01-22T20:58:58.685Z,1737579538.685 [BuoyancyServo](ERROR): Hardware Fault
2025-01-22T20:58:58.926Z,1737579538.926 [CBIT](ERROR): Hardware Fault in component: BuoyancyServo
2025-01-22T20:59:00.686Z,1737579540.686 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2025-01-22T20:59:00.687Z,1737579540.687 [BuoyancyServo](INFO): Powering down
2025-01-22T20:59:01.629Z,1737579541.629 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2025-01-22T20:59:01.629Z,1737579541.629 [BuoyancyServo] No Fault, FailCount= 1
2025-01-22T20:59:01.882Z,1737579541.882 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-01-22T20:59:01.883Z,1737579541.883 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-01-22T20:59:14.057Z,1737579554.057 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2025-01-22T20:59:45.181Z,1737579585.181 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T20:59:57.733Z,1737579597.733 [Radio_Surface](INFO): Powering down
2025-01-22T21:00:16.321Z,1737579616.321 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T21:00:17.325Z,1737579617.325 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2025-01-22T21:01:21.582Z,1737579681.582 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.250183
2025-01-22T21:17:45.006Z,1737580665.006 [keepstation:NeedComms] Running Loop=1
2025-01-22T21:17:45.006Z,1737580665.006 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-01-22T21:17:45.006Z,1737580665.006 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-01-22T21:17:45.006Z,1737580665.006 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T21:17:45.006Z,1737580665.006 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-01-22T21:17:45.007Z,1737580665.007 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-01-22T21:17:45.007Z,1737580665.007 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-01-22T21:17:45.007Z,1737580665.007 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-01-22T21:17:45.008Z,1737580665.008 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T21:17:45.008Z,1737580665.008 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T21:17:45.008Z,1737580665.008 [keepstation:NeedComms:A] Running Loop=1
2025-01-22T21:17:45.010Z,1737580665.010 [keepstation:NeedComms:A](INFO): last time_fix was: 1737579461.000000 second since 1970/01/01T00:00:00Z
2025-01-22T21:17:45.010Z,1737580665.010 [keepstation:NeedComms:A] Stopped
2025-01-22T21:19:12.623Z,1737580752.623 [keepstation:NeedComms:C] Running Loop=1
2025-01-22T21:19:13.194Z,1737580753.194 [Radio_Surface](INFO): Powering up
2025-01-22T21:19:18.945Z,1737580758.945 [DataOverHttps](INFO): Radio surface powered ON.
2025-01-22T21:19:27.555Z,1737580767.555 [NAL9602](INFO): SBD MO Status=2, MOMSN=12473, MT Status=2, MTMSN=0
2025-01-22T21:19:27.555Z,1737580767.555 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T21:19:49.065Z,1737580789.065 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T21:20:20.123Z,1737580820.123 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=12473, MT Status=1, MTMSN=223
2025-01-22T21:20:20.123Z,1737580820.123 [NAL9602](INFO): Data available in MT queue
2025-01-22T21:20:20.189Z,1737580820.189 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T21:20:20.610Z,1737580820.610 [NAL9602](INFO): Received command: stop
2025-01-22T21:20:20.611Z,1737580820.611 [CommandExec](IMPORTANT): got command stop
2025-01-22T21:20:20.611Z,1737580820.611 [CommandExec](IMPORTANT): Scheduling is paused
2025-01-22T21:20:20.611Z,1737580820.611 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2025-01-22T21:20:20.635Z,1737580820.635 [MissionManager](INFO): MissionManager is completed.
2025-01-22T21:20:20.635Z,1737580820.635 [MissionManager](INFO): Uninitializing Mission keepstation
2025-01-22T21:20:20.635Z,1737580820.635 [keepstation] Stopped
2025-01-22T21:20:20.635Z,1737580820.635 [keepstation](DEBUG): Aggregate::uninitialize keepstation
2025-01-22T21:20:20.635Z,1737580820.635 [keepstation:NeedComms] Stopped
2025-01-22T21:20:20.635Z,1737580820.635 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms
2025-01-22T21:20:20.635Z,1737580820.635 [keepstation:NeedComms:B.GoToSurface] Stopped
2025-01-22T21:20:20.635Z,1737580820.635 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-01-22T21:20:20.635Z,1737580820.635 [keepstation:NeedComms:C] Stopped
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes] Stopped
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:BackseatDriver] Stopped
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:BackseatDriver](DEBUG): Aggregate::uninitialize keepstation:BackseatDriver
2025-01-22T21:20:20.636Z,1737580820.636 [keepstation:BackseatDriver:A.BackseatDriver] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:PowerOnly] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:PowerOnly](DEBUG): Aggregate::uninitialize keepstation:PowerOnly
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:PowerOnly:E.Wait] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:H.Pitch] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation](DEBUG): Aggregate::uninitialize keepstation:KeepStation
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation:A] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation:B.Pitch] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation:C.KeepStation] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation:C.KeepStation](DEBUG): Uninitialize KeepStationComponent.
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation:D.Wait] Stopped
2025-01-22T21:20:20.637Z,1737580820.637 [keepstation:KeepStation:D.Wait](DEBUG): Uninitialize Wait Component.
2025-01-22T21:20:20.781Z,1737580820.781 [BackseatComponent](INFO): Sent LCM shutdown request.
2025-01-22T21:20:20.781Z,1737580820.781 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.).
2025-01-22T21:20:20.928Z,1737580820.928 [BioacousticsDataBridge](DEBUG): Backseat LCM timeout, waiting for message to resume
2025-01-22T21:20:20.947Z,1737580820.947 [MissionManager](IMPORTANT): Started mission Default
2025-01-22T21:20:20.947Z,1737580820.947 [Default] Running Loop=1
2025-01-22T21:20:20.947Z,1737580820.947 [Default](DEBUG): Aggregate::initialize Default
2025-01-22T21:20:20.947Z,1737580820.947 [Default:B.GoToSurface] Running Loop=1
2025-01-22T21:20:20.947Z,1737580820.947 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-01-22T21:20:20.947Z,1737580820.947 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-01-22T21:20:20.948Z,1737580820.948 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-01-22T21:20:20.948Z,1737580820.948 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-01-22T21:20:20.948Z,1737580820.948 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-01-22T21:20:20.948Z,1737580820.948 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-01-22T21:20:20.949Z,1737580820.949 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-01-22T21:20:20.949Z,1737580820.949 [Default:A.Wait] Running Loop=1
2025-01-22T21:20:20.950Z,1737580820.950 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-01-22T21:20:34.289Z,1737580834.289 [Default:A.Wait](INFO): Done Waiting.
2025-01-22T21:20:34.290Z,1737580834.290 [Default:A.Wait] Stopped
2025-01-22T21:20:34.290Z,1737580834.290 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-01-22T21:20:34.682Z,1737580834.682 [Default:CheckIn] Running Loop=1
2025-01-22T21:20:34.682Z,1737580834.682 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-01-22T21:20:34.683Z,1737580834.683 [Default:CheckIn:Read_GPS] Running Loop=1
2025-01-22T21:20:36.688Z,1737580836.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212033.00,A,3648.31961,N,12149.43558,W,0.564,219.32,220125,,,A*72
2025-01-22T21:20:36.691Z,1737580836.691 [NAL9602](INFO): GPS fix at 20250122T212033: (36.805327, -121.823926)
2025-01-22T21:20:36.706Z,1737580836.706 [Default:CheckIn:Read_GPS] Stopped
2025-01-22T21:20:36.706Z,1737580836.706 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-01-22T21:20:38.953Z,1737580838.953 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec).
2025-01-22T21:20:38.954Z,1737580838.954 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2025-01-22T21:20:38.954Z,1737580838.954 [LcmUniversalReporter](INFO): Deactivating messaging.
2025-01-22T21:20:51.325Z,1737580851.325 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T21:21:06.755Z,1737580866.755 [NAL9602](INFO): SBD MO Status=1, MOMSN=12474, MT Status=0, MTMSN=0
2025-01-22T21:21:06.805Z,1737580866.805 [NAL9602](INFO): Sent 73 bytes from file Logs/20250122T183449/Courier0034.lzma
2025-01-22T21:21:06.805Z,1737580866.805 [NAL9602](INFO): Packets left to send: 0
2025-01-22T21:21:22.450Z,1737580882.450 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-01-22T21:21:30.139Z,1737580890.139 [NAL9602](INFO): SBD MO Status=2, MOMSN=12475, MT Status=2, MTMSN=0
2025-01-22T21:21:30.139Z,1737580890.139 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-01-22T21:21:31.002Z,1737580891.002 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003160
2025-01-22T21:21:41.165Z,1737580901.165 [DataOverHttps](INFO): Sending 366 bytes from file Logs/20250122T183449/Express0035.lzma
2025-01-22T21:21:42.167Z,1737580902.167 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0035.lzma.bak
2025-01-22T21:21:42.167Z,1737580902.167 [DataOverHttps](INFO): SBD MOMSN=23924555
2025-01-22T21:21:43.964Z,1737580903.964 [Default:CheckIn:Read_Iridium] Stopped
2025-01-22T21:21:43.970Z,1737580903.970 [Default:CheckIn:C.Wait] Running Loop=1
2025-01-22T21:21:43.970Z,1737580903.970 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-01-22T21:22:06.160Z,1737580926.160 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T21:26:44.522Z,1737581204.522 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-01-22T21:26:44.522Z,1737581204.522 [Default:CheckIn:C.Wait] Stopped
2025-01-22T21:26:44.522Z,1737581204.522 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-01-22T21:26:44.522Z,1737581204.522 [Default:CheckIn:D] Running Loop=1
2025-01-22T21:26:44.938Z,1737581204.938 [Default:CheckIn:D] Stopped
2025-01-22T21:26:44.938Z,1737581204.938 [Default:CheckIn:E] Running Loop=1
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.399850 min
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn:E] Stopped
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn] Stopped
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn](INFO): Running loop #2
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn] Running Loop=2
2025-01-22T21:26:45.328Z,1737581205.328 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-01-22T21:26:45.329Z,1737581205.329 [Default:CheckIn:Read_GPS] Running Loop=1
2025-01-22T21:26:47.344Z,1737581207.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212643.00,A,3648.27770,N,12149.42467,W,0.525,165.90,220125,,,D*76
2025-01-22T21:26:47.346Z,1737581207.346 [NAL9602](INFO): GPS fix at 20250122T212643: (36.804628, -121.823745)
2025-01-22T21:26:47.357Z,1737581207.357 [Default:CheckIn:Read_GPS] Stopped
2025-01-22T21:26:47.357Z,1737581207.357 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-01-22T21:26:55.813Z,1737581215.813 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250122T183449/Courier0037.lzma
2025-01-22T21:26:56.815Z,1737581216.815 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0037.lzma.bak
2025-01-22T21:26:56.815Z,1737581216.815 [DataOverHttps](INFO): SBD MOMSN=23924570
2025-01-22T21:27:04.776Z,1737581224.776 [NAL9602](INFO): SBD MO Status=1, MOMSN=12475, MT Status=0, MTMSN=0
2025-01-22T21:27:04.776Z,1737581224.776 [NAL9602](INFO): No messages in MT queue
2025-01-22T21:27:16.181Z,1737581236.181 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20250122T183449/Express0038.lzma
2025-01-22T21:27:17.183Z,1737581237.183 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0038.lzma.bak
2025-01-22T21:27:17.183Z,1737581237.183 [DataOverHttps](INFO): SBD MOMSN=23924573
2025-01-22T21:27:18.524Z,1737581238.524 [Default:CheckIn:Read_Iridium] Stopped
2025-01-22T21:27:18.524Z,1737581238.524 [Default:CheckIn:C.Wait] Running Loop=1
2025-01-22T21:27:18.524Z,1737581238.524 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-01-22T21:27:35.478Z,1737581255.478 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T21:32:19.156Z,1737581539.156 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-01-22T21:32:19.156Z,1737581539.156 [Default:CheckIn:C.Wait] Stopped
2025-01-22T21:32:19.156Z,1737581539.156 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-01-22T21:32:19.157Z,1737581539.157 [Default:CheckIn:D] Running Loop=1
2025-01-22T21:32:19.566Z,1737581539.566 [Default:CheckIn:D] Stopped
2025-01-22T21:32:19.567Z,1737581539.567 [Default:CheckIn:E] Running Loop=1
2025-01-22T21:32:19.962Z,1737581539.962 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.976994 min
2025-01-22T21:32:19.962Z,1737581539.962 [Default:CheckIn:E] Stopped
2025-01-22T21:32:19.962Z,1737581539.962 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-01-22T21:32:19.962Z,1737581539.962 [Default:CheckIn] Stopped
2025-01-22T21:32:19.962Z,1737581539.962 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-01-22T21:32:19.962Z,1737581539.962 [Default:CheckIn](INFO): Running loop #3
2025-01-22T21:32:19.962Z,1737581539.962 [Default:CheckIn] Running Loop=3
2025-01-22T21:32:19.963Z,1737581539.963 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-01-22T21:32:19.963Z,1737581539.963 [Default:CheckIn:Read_GPS] Running Loop=1
2025-01-22T21:32:21.973Z,1737581541.973 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213221.00,A,3648.23708,N,12149.41078,W,0.894,190.75,220125,,,D*73
2025-01-22T21:32:21.975Z,1737581541.975 [NAL9602](INFO): GPS fix at 20250122T213221: (36.803951, -121.823513)
2025-01-22T21:32:21.986Z,1737581541.986 [Default:CheckIn:Read_GPS] Stopped
2025-01-22T21:32:21.986Z,1737581541.986 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-01-22T21:32:29.661Z,1737581549.661 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250122T183449/Courier0040.lzma
2025-01-22T21:32:30.663Z,1737581550.663 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Courier0040.lzma.bak
2025-01-22T21:32:30.663Z,1737581550.663 [DataOverHttps](INFO): SBD MOMSN=23924577
2025-01-22T21:32:42.575Z,1737581562.575 [NAL9602](INFO): SBD MO Status=1, MOMSN=12476, MT Status=0, MTMSN=0
2025-01-22T21:32:42.575Z,1737581562.575 [NAL9602](INFO): No messages in MT queue
2025-01-22T21:32:47.965Z,1737581567.965 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20250122T183449/Express0041.lzma
2025-01-22T21:32:48.967Z,1737581568.967 [DataOverHttps](INFO): Moved sent file to Logs/20250122T183449/Express0041.lzma.bak
2025-01-22T21:32:48.967Z,1737581568.967 [DataOverHttps](INFO): SBD MOMSN=23924580
2025-01-22T21:32:50.270Z,1737581570.270 [Default:CheckIn:Read_Iridium] Stopped
2025-01-22T21:32:50.271Z,1737581570.271 [Default:CheckIn:C.Wait] Running Loop=1
2025-01-22T21:32:50.271Z,1737581570.271 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-01-22T21:33:13.279Z,1737581593.279 [NAL9602](INFO): Not Powering down - fast GPS
2025-01-22T21:37:08.370Z,1737581828.370 [DataOverHttps](IMPORTANT): SBD MTMSN=20250122T213707
2025-01-22T21:37:15.901Z,1737581835.901 [DataOverHttps](INFO): Received command: restart logs