2025-07-18T13:53:52.407Z,1752846832.407 [Supervisor](DEBUG): Initializing supervisor. 2025-07-18T13:53:52.411Z,1752846832.411 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-07-18T13:53:52.412Z,1752846832.412 [SyncHandler](INFO): Protected caller Thread ID is 1730 2025-07-18T13:53:52.412Z,1752846832.412 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-07-18T13:53:52.413Z,1752846832.413 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-07-18T13:53:52.414Z,1752846832.414 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1731 2025-07-18T13:53:52.418Z,1752846832.418 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-07-18T13:53:52.438Z,1752846832.438 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-07-18T13:53:52.439Z,1752846832.439 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-07-18T13:53:52.440Z,1752846832.440 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1732 2025-07-18T13:53:52.444Z,1752846832.444 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-07-18T13:53:52.445Z,1752846832.445 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-07-18T13:53:52.445Z,1752846832.445 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1733 2025-07-18T13:53:52.448Z,1752846832.448 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-07-18T13:53:52.449Z,1752846832.449 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-07-18T13:53:52.449Z,1752846832.449 [logger ThreadHandler](INFO): Protected caller Thread ID is 1734 2025-07-18T13:53:52.453Z,1752846832.453 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-07-18T13:53:52.453Z,1752846832.453 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-07-18T13:53:52.455Z,1752846832.455 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-07-18T13:53:52.948Z,1752846832.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-07-18T13:53:52.949Z,1752846832.949 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-07-18T13:53:53.169Z,1752846833.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-07-18T13:53:53.170Z,1752846833.170 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-07-18T13:53:53.268Z,1752846833.268 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-07-18T13:53:53.269Z,1752846833.269 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-07-18T13:53:53.513Z,1752846833.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-07-18T13:53:53.514Z,1752846833.514 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-07-18T13:53:53.602Z,1752846833.602 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-07-18T13:53:53.708Z,1752846833.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-07-18T13:53:53.708Z,1752846833.708 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-07-18T13:53:54.074Z,1752846834.074 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-07-18T13:53:54.075Z,1752846834.075 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-07-18T13:53:54.217Z,1752846834.217 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-07-18T13:53:54.218Z,1752846834.218 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-07-18T13:53:54.764Z,1752846834.764 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-07-18T13:53:54.765Z,1752846834.765 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-07-18T13:53:54.955Z,1752846834.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-07-18T13:53:54.955Z,1752846834.955 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-07-18T13:53:55.383Z,1752846835.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-07-18T13:53:55.384Z,1752846835.384 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-07-18T13:53:55.708Z,1752846835.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-07-18T13:53:55.709Z,1752846835.709 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-07-18T13:53:56.040Z,1752846836.040 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-07-18T13:53:56.041Z,1752846836.041 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-07-18T13:53:57.201Z,1752846837.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-07-18T13:53:57.202Z,1752846837.202 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-07-18T13:53:57.559Z,1752846837.559 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-07-18T13:53:57.559Z,1752846837.559 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-07-18T13:53:57.813Z,1752846837.813 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-07-18T13:53:57.816Z,1752846837.816 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/ 2025-07-18T13:53:57.817Z,1752846837.817 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg 2025-07-18T13:53:57.946Z,1752846837.946 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg 2025-07-18T13:53:58.039Z,1752846838.039 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg 2025-07-18T13:53:58.184Z,1752846838.184 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg 2025-07-18T13:53:58.278Z,1752846838.278 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg 2025-07-18T13:53:58.556Z,1752846838.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-07-18T13:53:58.557Z,1752846838.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg 2025-07-18T13:53:58.669Z,1752846838.669 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg 2025-07-18T13:53:58.785Z,1752846838.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg 2025-07-18T13:53:58.892Z,1752846838.892 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg 2025-07-18T13:53:59.054Z,1752846839.054 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg 2025-07-18T13:53:59.160Z,1752846839.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg 2025-07-18T13:53:59.255Z,1752846839.255 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-07-18T13:53:59.267Z,1752846839.267 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-07-18T13:53:59.279Z,1752846839.279 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-07-18T13:53:59.279Z,1752846839.279 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-07-18T13:53:59.418Z,1752846839.418 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-07-18T13:53:59.418Z,1752846839.418 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-07-18T13:53:59.475Z,1752846839.475 [VerticalControl](DEBUG): Construct VerticalControl. 2025-07-18T13:53:59.538Z,1752846839.538 [VerticalControl] Loaded 2025-07-18T13:53:59.538Z,1752846839.538 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-07-18T13:53:59.541Z,1752846839.541 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-07-18T13:53:59.590Z,1752846839.590 [HorizontalControl] Loaded 2025-07-18T13:53:59.590Z,1752846839.590 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-07-18T13:53:59.593Z,1752846839.593 [SpeedControl](DEBUG): Construct SpeedControl. 2025-07-18T13:53:59.596Z,1752846839.596 [SpeedControl] Loaded 2025-07-18T13:53:59.596Z,1752846839.596 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-07-18T13:53:59.599Z,1752846839.599 [LoopControl](DEBUG): Construct LoopControl. 2025-07-18T13:53:59.600Z,1752846839.600 [LoopControl] Loaded 2025-07-18T13:53:59.600Z,1752846839.600 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-07-18T13:53:59.600Z,1752846839.600 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-07-18T13:53:59.601Z,1752846839.601 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-07-18T13:53:59.934Z,1752846839.934 [BuoyancyServo] Loaded 2025-07-18T13:53:59.935Z,1752846839.935 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-07-18T13:53:59.996Z,1752846839.996 [MassServo] Loaded 2025-07-18T13:53:59.997Z,1752846839.997 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-07-18T13:54:00.056Z,1752846840.056 [RudderServo] Loaded 2025-07-18T13:54:00.056Z,1752846840.056 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-07-18T13:54:00.098Z,1752846840.098 [ThrusterHE] Loaded 2025-07-18T13:54:00.098Z,1752846840.098 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-07-18T13:54:00.098Z,1752846840.098 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-07-18T13:54:00.099Z,1752846840.099 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-07-18T13:54:00.207Z,1752846840.207 [DepthRateCalculator] Loaded 2025-07-18T13:54:00.208Z,1752846840.208 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-07-18T13:54:00.239Z,1752846840.239 [PitchRateCalculator] Loaded 2025-07-18T13:54:00.239Z,1752846840.239 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-07-18T13:54:00.254Z,1752846840.254 [SpeedCalculator] Loaded 2025-07-18T13:54:00.254Z,1752846840.254 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-07-18T13:54:00.259Z,1752846840.259 [YawRateCalculator] Loaded 2025-07-18T13:54:00.259Z,1752846840.259 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-07-18T13:54:00.278Z,1752846840.278 [ElevatorOffsetCalculator] Loaded 2025-07-18T13:54:00.278Z,1752846840.278 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-07-18T13:54:00.279Z,1752846840.279 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-07-18T13:54:00.279Z,1752846840.279 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-07-18T13:54:00.767Z,1752846840.767 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-07-18T13:54:00.768Z,1752846840.768 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-07-18T13:54:00.864Z,1752846840.864 [NavChart] Loaded 2025-07-18T13:54:00.864Z,1752846840.864 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-07-18T13:54:00.886Z,1752846840.886 [UniversalFixResidualReporter] Loaded 2025-07-18T13:54:00.886Z,1752846840.886 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-07-18T13:54:00.887Z,1752846840.887 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-07-18T13:54:00.887Z,1752846840.887 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-07-18T13:54:02.017Z,1752846842.017 [AHRS_M2] Loaded 2025-07-18T13:54:02.017Z,1752846842.017 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-07-18T13:54:02.057Z,1752846842.057 [BackseatComponent] Loaded 2025-07-18T13:54:02.057Z,1752846842.057 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-07-18T13:54:02.059Z,1752846842.059 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409294E0 2025-07-18T13:54:02.059Z,1752846842.059 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1816 2025-07-18T13:54:02.062Z,1752846842.062 [LcmUniversalReporter] Loaded 2025-07-18T13:54:02.062Z,1752846842.062 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-07-18T13:54:02.068Z,1752846842.068 [BioacousticsDataBridge] Loaded 2025-07-18T13:54:02.069Z,1752846842.069 [ComponentRegistry](DEBUG): SyncComponent "BioacousticsDataBridge" handled in the control thread. 2025-07-18T13:54:02.930Z,1752846842.930 [BPC1] Loaded 2025-07-18T13:54:02.931Z,1752846842.931 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-07-18T13:54:03.032Z,1752846843.032 [DAT] Loaded 2025-07-18T13:54:03.032Z,1752846843.032 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-07-18T13:54:03.033Z,1752846843.033 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409594E0 2025-07-18T13:54:03.034Z,1752846843.034 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1817 2025-07-18T13:54:03.106Z,1752846843.106 [DataOverHttps] Loaded 2025-07-18T13:54:03.107Z,1752846843.107 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-07-18T13:54:03.108Z,1752846843.108 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409894E0 2025-07-18T13:54:03.108Z,1752846843.108 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1818 2025-07-18T13:54:03.132Z,1752846843.132 [Depth_Keller] Loaded 2025-07-18T13:54:03.132Z,1752846843.132 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-07-18T13:54:03.137Z,1752846843.137 [DropWeight] Loaded 2025-07-18T13:54:03.138Z,1752846843.138 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-07-18T13:54:03.204Z,1752846843.204 [NAL9602] Loaded 2025-07-18T13:54:03.204Z,1752846843.204 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-07-18T13:54:03.235Z,1752846843.235 [Onboard] Loaded 2025-07-18T13:54:03.235Z,1752846843.235 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-07-18T13:54:03.236Z,1752846843.236 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409B94E0 2025-07-18T13:54:03.236Z,1752846843.236 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1819 2025-07-18T13:54:03.251Z,1752846843.251 [Power24vConverter] Loaded 2025-07-18T13:54:03.251Z,1752846843.251 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-07-18T13:54:03.268Z,1752846843.268 [Radio_Surface] Loaded 2025-07-18T13:54:03.268Z,1752846843.268 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-07-18T13:54:03.269Z,1752846843.269 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409E94E0 2025-07-18T13:54:03.269Z,1752846843.269 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1820 2025-07-18T13:54:03.285Z,1752846843.285 [Sonardyne_Nano] Loaded 2025-07-18T13:54:03.286Z,1752846843.286 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-07-18T13:54:03.286Z,1752846843.286 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-07-18T13:54:03.287Z,1752846843.287 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-07-18T13:54:03.348Z,1752846843.348 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-07-18T13:54:03.349Z,1752846843.349 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-07-18T13:54:03.535Z,1752846843.535 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-07-18T13:54:03.536Z,1752846843.536 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-07-18T13:54:03.566Z,1752846843.566 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-07-18T13:54:03.566Z,1752846843.566 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-07-18T13:54:03.748Z,1752846843.748 [CTD_Seabird] Loaded 2025-07-18T13:54:03.749Z,1752846843.749 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-07-18T13:54:03.750Z,1752846843.750 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B314E0 2025-07-18T13:54:03.750Z,1752846843.750 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1821 2025-07-18T13:54:03.773Z,1752846843.773 [PAR_Licor] Loaded 2025-07-18T13:54:03.774Z,1752846843.774 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-07-18T13:54:03.819Z,1752846843.819 [WetLabsBB2FL] Loaded 2025-07-18T13:54:03.820Z,1752846843.820 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-07-18T13:54:03.821Z,1752846843.821 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B614E0 2025-07-18T13:54:03.821Z,1752846843.821 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1822 2025-07-18T13:54:03.822Z,1752846843.822 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-07-18T13:54:03.822Z,1752846843.822 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-07-18T13:54:04.183Z,1752846844.183 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-07-18T13:54:04.183Z,1752846844.183 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-07-18T13:54:04.353Z,1752846844.353 [SBIT](DEBUG): Construct Startup Built In Test. 2025-07-18T13:54:04.363Z,1752846844.363 [SBIT] Loaded 2025-07-18T13:54:04.363Z,1752846844.363 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-07-18T13:54:04.366Z,1752846844.366 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-07-18T13:54:04.379Z,1752846844.379 [IBIT] Loaded 2025-07-18T13:54:04.379Z,1752846844.379 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-07-18T13:54:04.385Z,1752846844.385 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-07-18T13:54:04.468Z,1752846844.468 [CBIT] Loaded 2025-07-18T13:54:04.468Z,1752846844.468 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-07-18T13:54:04.502Z,1752846844.502 [GFScanner] Loaded 2025-07-18T13:54:04.502Z,1752846844.502 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-07-18T13:54:04.503Z,1752846844.503 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-07-18T13:54:04.509Z,1752846844.509 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-07-18T13:54:04.512Z,1752846844.512 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-07-18T13:54:04.524Z,1752846844.524 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-07-18T13:54:04.525Z,1752846844.525 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C694E0 2025-07-18T13:54:04.525Z,1752846844.525 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1823 2025-07-18T13:54:04.530Z,1752846844.530 [Supervisor](INFO): Main Thread ID is 830 2025-07-18T13:54:04.530Z,1752846844.530 [Supervisor](DEBUG): Running supervisor. 2025-07-18T13:54:04.531Z,1752846844.531 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1824 2025-07-18T13:54:04.531Z,1752846844.531 [CommandExec](INFO): Initializing the command executive. 2025-07-18T13:54:04.533Z,1752846844.533 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1825 2025-07-18T13:54:04.535Z,1752846844.535 [controlThread ThreadHandler](INFO): Handler Thread ID is 1826 2025-07-18T13:54:04.535Z,1752846844.535 [controlThread](DEBUG): Initializing ControlThread 2025-07-18T13:54:04.536Z,1752846844.536 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-07-18T13:54:04.538Z,1752846844.538 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-07-18T13:54:04.539Z,1752846844.539 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-07-18T13:54:04.539Z,1752846844.539 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-07-18T13:54:04.540Z,1752846844.540 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-07-18T13:54:04.541Z,1752846844.541 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-07-18T13:54:04.541Z,1752846844.541 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-07-18T13:54:04.541Z,1752846844.541 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-07-18T13:54:04.542Z,1752846844.542 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-07-18T13:54:04.543Z,1752846844.543 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-07-18T13:54:04.543Z,1752846844.543 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-07-18T13:54:04.550Z,1752846844.550 [SBIT](INFO): Initialize SBIT Component. 2025-07-18T13:54:04.551Z,1752846844.551 [SBIT](IMPORTANT): git: 2025-07-16 2025-07-18T13:54:04.551Z,1752846844.551 [SBIT](INFO): git hash: d69d2715ddd00fa751675e8858faf22d094d5d81 2025-07-18T13:54:04.551Z,1752846844.551 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-07-18T13:54:04.552Z,1752846844.552 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2025-07-18T13:54:04.554Z,1752846844.554 [SBIT](INFO): Beginning SBIT in 26.000000 seconds. 2025-07-18T13:54:04.554Z,1752846844.554 [IBIT](INFO): Initialize IBIT Component. 2025-07-18T13:54:04.555Z,1752846844.555 [CBIT](DEBUG): Initialize CBIT Component. 2025-07-18T13:54:04.556Z,1752846844.556 [logger ThreadHandler](INFO): Handler Thread ID is 1827 2025-07-18T13:54:04.566Z,1752846844.566 [CBIT](DEBUG): Initialized mux pins. 2025-07-18T13:54:04.566Z,1752846844.566 [CBIT](DEBUG): Initializing the watchdog timer. 2025-07-18T13:54:04.575Z,1752846844.575 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1828 2025-07-18T13:54:04.587Z,1752846844.587 [DAT ThreadHandler](INFO): Handler Thread ID is 1829 2025-07-18T13:54:04.587Z,1752846844.587 [DAT](INFO): Powering up 2025-07-18T13:54:04.587Z,1752846844.587 [DAT](DEBUG): Initializing DAT. 2025-07-18T13:54:04.590Z,1752846844.590 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-07-18T13:54:04.591Z,1752846844.591 [CBIT](DEBUG): Initializing heartbeat. 2025-07-18T13:54:04.592Z,1752846844.592 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1831 2025-07-18T13:54:04.594Z,1752846844.594 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-07-18T13:54:04.603Z,1752846844.603 [Onboard ThreadHandler](INFO): Handler Thread ID is 1832 2025-07-18T13:54:04.620Z,1752846844.620 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1833 2025-07-18T13:54:04.639Z,1752846844.639 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1834 2025-07-18T13:54:04.640Z,1752846844.640 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-07-18T13:54:04.643Z,1752846844.643 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1836 2025-07-18T13:54:04.647Z,1752846844.647 [WetLabsBB2FL](INFO): Powering up 2025-07-18T13:54:04.648Z,1752846844.648 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1838 2025-07-18T13:54:04.651Z,1752846844.651 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI79M.000 2025-07-18T13:54:04.652Z,1752846844.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI79M.000 2025-07-18T13:54:04.652Z,1752846844.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QL.000 2025-07-18T13:54:04.652Z,1752846844.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QL.000 2025-07-18T13:54:04.652Z,1752846844.652 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QM.000 2025-07-18T13:54:04.652Z,1752846844.652 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QM.000 2025-07-18T13:54:04.653Z,1752846844.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2PM.000 2025-07-18T13:54:04.653Z,1752846844.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2PM.000 2025-07-18T13:54:04.653Z,1752846844.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI74M.000 2025-07-18T13:54:04.653Z,1752846844.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI74M.000 2025-07-18T13:54:04.653Z,1752846844.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QN.000 2025-07-18T13:54:04.653Z,1752846844.653 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QN.000 2025-07-18T13:54:04.653Z,1752846844.653 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QO.000 2025-07-18T13:54:04.654Z,1752846844.654 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QO.000 2025-07-18T13:54:04.655Z,1752846844.655 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2RO.000 2025-07-18T13:54:04.655Z,1752846844.655 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2RO.000 2025-07-18T13:54:04.655Z,1752846844.655 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2RN.000 2025-07-18T13:54:04.655Z,1752846844.655 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2RN.000 2025-07-18T13:54:04.655Z,1752846844.655 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI2QP.000 2025-07-18T13:54:04.655Z,1752846844.655 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI2QP.000 2025-07-18T13:54:04.662Z,1752846844.662 [CBIT](DEBUG): Deactivating emergency mode. 2025-07-18T13:54:04.702Z,1752846844.702 [CBIT](DEBUG): Backplane powered. 2025-07-18T13:54:04.702Z,1752846844.702 [GFScanner](DEBUG): Initializing GFScanner 2025-07-18T13:54:04.703Z,1752846844.703 [GFScanner](DEBUG): Deactivating GF circuits. 2025-07-18T13:54:04.707Z,1752846844.707 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-07-18T13:54:04.708Z,1752846844.708 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-07-18T13:54:04.708Z,1752846844.708 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-07-18T13:54:04.709Z,1752846844.709 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-07-18T13:54:04.771Z,1752846844.771 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-07-18T13:54:04.775Z,1752846844.775 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-07-18T13:54:04.824Z,1752846844.824 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2025-07-18T13:54:04.824Z,1752846844.824 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-07-18T13:54:04.825Z,1752846844.825 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-07-18T13:54:04.826Z,1752846844.826 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-07-18T13:54:05.026Z,1752846845.026 [Radio_Surface](INFO): Powering up 2025-07-18T13:54:05.129Z,1752846845.129 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2025-07-18T13:54:05.151Z,1752846845.151 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-07-18T13:54:05.152Z,1752846845.152 [Default:A.Wait](DEBUG): Construct Wait. 2025-07-18T13:54:05.178Z,1752846845.178 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-07-18T13:54:05.220Z,1752846845.220 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-07-18T13:54:05.222Z,1752846845.222 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-07-18T13:54:05.240Z,1752846845.240 [Default:E.Execute](DEBUG): Construct Execute. 2025-07-18T13:54:05.243Z,1752846845.243 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2025-07-18T13:54:05.263Z,1752846845.263 [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,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter, 2025-07-18T13:54:05.286Z,1752846845.286 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-07-18T13:54:05.351Z,1752846845.351 [Depth_Keller](INFO): Initializing. 2025-07-18T13:54:05.352Z,1752846845.352 [Power24vConverter](INFO): Powering up. 2025-07-18T13:54:05.353Z,1752846845.353 [Sonardyne_Nano](INFO): Initializing. 2025-07-18T13:54:05.394Z,1752846845.394 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-07-18T13:54:05.421Z,1752846845.421 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-07-18T13:54:05.426Z,1752846845.426 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-07-18T13:54:05.427Z,1752846845.427 [MassServo](DEBUG): Initializing EZServoServo. 2025-07-18T13:54:05.434Z,1752846845.434 [MassServo](DEBUG): Initializing MassServo. 2025-07-18T13:54:05.435Z,1752846845.435 [RudderServo](DEBUG): Initializing EZServoServo. 2025-07-18T13:54:05.442Z,1752846845.442 [RudderServo](DEBUG): Initializing RudderServo. 2025-07-18T13:54:05.443Z,1752846845.443 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-07-18T13:54:05.450Z,1752846845.450 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-07-18T13:54:07.258Z,1752846847.258 [WetLabsBB2FL](INFO): Powering down 2025-07-18T13:54:07.292Z,1752846847.292 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-07-18T13:54:08.578Z,1752846848.578 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2107 2025-07-18T13:54:11.175Z,1752846851.175 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-07-18T13:54:16.939Z,1752846856.939 [DAT](INFO): DAT read: 2025-07-18T13:54:16.940Z,1752846856.940 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-07-18T13:54:18.703Z,1752846858.703 [DAT](INFO): DAT read: MF Frequency Band 2025-07-18T13:54:18.704Z,1752846858.704 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-07-18T13:54:18.705Z,1752846858.705 [DAT](INFO): DAT read: Jul 18 2025 13:54:13 2025-07-18T13:54:19.711Z,1752846859.711 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-07-18T13:54:19.713Z,1752846859.713 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-07-18T13:54:19.713Z,1752846859.713 [DAT](INFO): commRate: 800 2025-07-18T13:54:21.778Z,1752846861.778 [DAT](INFO): entering command mode 2025-07-18T13:54:21.979Z,1752846861.979 [DAT](INFO): DAT read: 2025-07-18T13:54:21.979Z,1752846861.979 [DAT](INFO): DAT read: user:1> 2025-07-18T13:54:21.980Z,1752846861.980 [DAT](INFO): setting verbose to 3 2025-07-18T13:54:22.231Z,1752846862.231 [DAT](INFO): DAT read: user:1> 2025-07-18T13:54:22.232Z,1752846862.232 [DAT](INFO): DAT read: Verbose | 3 2025-07-18T13:54:22.232Z,1752846862.232 [DAT](INFO): set verbose to 3 2025-07-18T13:54:22.232Z,1752846862.232 [DAT](INFO): setting DatVerbose to 27440 2025-07-18T13:54:22.483Z,1752846862.483 [DAT](INFO): DAT read: user:2> 2025-07-18T13:54:22.484Z,1752846862.484 [DAT](INFO): DAT read: DatVerbose | 27440 2025-07-18T13:54:22.484Z,1752846862.484 [DAT](INFO): set DatVerbose to 27440 2025-07-18T13:54:22.484Z,1752846862.484 [DAT](INFO): setting transmit power to 8 2025-07-18T13:54:22.735Z,1752846862.735 [DAT](INFO): DAT read: user:3> 2025-07-18T13:54:22.736Z,1752846862.736 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-07-18T13:54:22.736Z,1752846862.736 [DAT](INFO): set transmit power to 8 2025-07-18T13:54:22.737Z,1752846862.737 [DAT](INFO): setting local address to 12 2025-07-18T13:54:22.987Z,1752846862.987 [DAT](INFO): DAT read: user:4> 2025-07-18T13:54:22.988Z,1752846862.988 [DAT](INFO): DAT read: LocalAddr | 12 2025-07-18T13:54:22.988Z,1752846862.988 [DAT](INFO): set local address to 12 2025-07-18T13:54:22.989Z,1752846862.989 [DAT](INFO): Setting time to: 13:54:22 And date to:7/18/2025 2025-07-18T13:54:23.239Z,1752846863.239 [DAT](INFO): DAT read: user:5> 2025-07-18T13:54:23.240Z,1752846863.240 [DAT](INFO): DAT read: Fri Jul 18, 2025 13:54:22 2025-07-18T13:54:23.240Z,1752846863.240 [DAT](INFO): Local DAT time set to Fri Jul 18, 2025 13:54:22 2025-07-18T13:54:31.149Z,1752846871.149 [SBIT](IMPORTANT): Beginning Startup BIT 2025-07-18T13:54:31.153Z,1752846871.153 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-07-18T13:54:33.556Z,1752846873.556 [NAL9602](INFO): Powering up NAL9602 2025-07-18T13:54:35.764Z,1752846875.764 [GFScanner](IMPORTANT): Low side ground fault detected mA: CHAN A0 (Batt): 0.836499 CHAN A1 (24V): 0.778411 CHAN A2 (12V): 0.591871 CHAN A3 (5V): 0.209066 CHAN B0 (3.3V): 0.141370 CHAN B1 (3.15aV): 0.150924 CHAN B2 (3.15bV): 0.151241 CHAN B3 (GND): -0.018720 OPEN: 0.021229 Full Scale: +/- 1 mA 2025-07-18T13:54:44.468Z,1752846884.468 [NAL9602](INFO): NAL9602 initialized 2025-07-18T13:54:44.493Z,1752846884.493 [SBIT](ERROR): Could not read elevatorAngleReader_. 2025-07-18T13:55:11.145Z,1752846911.145 [SBIT](ERROR): Could not read elevatorAngleReader_. 2025-07-18T13:55:11.146Z,1752846911.146 [SBIT](FAULT): Control surface position failure. 2025-07-18T13:55:16.789Z,1752846916.789 [NAL9602](INFO): SBD MO Status=0, MOMSN=10181, MT Status=0, MTMSN=0 2025-07-18T13:55:16.789Z,1752846916.789 [NAL9602](INFO): No messages in MT queue 2025-07-18T13:55:20.829Z,1752846920.829 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,135519.00,A,3647.82943,N,12150.95812,W,0.544,343.91,180725,,,A*74 2025-07-18T13:55:20.833Z,1752846920.833 [NAL9602](INFO): GPS fix at 20250718T135519: (36.797157, -121.849302) 2025-07-18T13:55:24.902Z,1752846924.902 [SBIT](ERROR): Could not read elevatorAngleReader_. 2025-07-18T13:55:24.902Z,1752846924.902 [SBIT](FAULT): Control surface position failure. 2025-07-18T13:55:25.296Z,1752846925.296 [SBIT](CRITICAL): SBIT FAILED 2025-07-18T13:55:25.296Z,1752846925.296 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-07-18T13:55:25.297Z,1752846925.297 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=15 count; 2025-07-18T13:55:25.297Z,1752846925.297 [SBIT](IMPORTANT): ElevatorServo.loadAtStartup=0 bool; 2025-07-18T13:55:25.297Z,1752846925.297 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity; 2025-07-18T13:55:25.297Z,1752846925.297 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_temperature; 2025-07-18T13:55:25.297Z,1752846925.297 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water; 2025-07-18T13:55:25.298Z,1752846925.298 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 1.000000 count_per_second; 2025-07-18T13:55:25.298Z,1752846925.298 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=245.648064 cubic_centimeter; 2025-07-18T13:55:25.298Z,1752846925.298 [SBIT](IMPORTANT): VerticalControl.kdPitchMass=0.25 second; 2025-07-18T13:55:25.298Z,1752846925.298 [SBIT](IMPORTANT): VerticalControl.kiPitchMass=0.25 reciprocal_second; 2025-07-18T13:55:25.298Z,1752846925.298 [SBIT](IMPORTANT): VerticalControl.kpPitchMass=0.25 none; 2025-07-18T13:55:25.298Z,1752846925.298 [SBIT](IMPORTANT): VerticalControl.massDefault=-1.746382 millimeter; 2025-07-18T13:55:25.298Z,1752846925.298 [SBIT](IMPORTANT): VerticalControl.massOnlyForceInt=1 bool; 2025-07-18T13:55:25.299Z,1752846925.299 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool; 2025-07-18T13:55:25.300Z,1752846925.300 [CommandExec](FAULT): Scheduling is paused 2025-07-18T13:55:25.300Z,1752846925.300 [CBIT](INFO): Critical error at 20250718T135525 2025-07-18T13:55:25.301Z,1752846925.301 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-07-18T13:55:25.810Z,1752846925.810 [MissionManager](IMPORTANT): Started mission Startup 2025-07-18T13:55:25.811Z,1752846925.811 [Startup] Running Loop=1 2025-07-18T13:55:25.811Z,1752846925.811 [Startup](DEBUG): Aggregate::initialize Startup 2025-07-18T13:55:25.811Z,1752846925.811 [Startup:A.GoToSurface] Running Loop=1 2025-07-18T13:55:25.811Z,1752846925.811 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T13:55:25.812Z,1752846925.812 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-07-18T13:55:25.812Z,1752846925.812 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-07-18T13:55:25.812Z,1752846925.812 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-07-18T13:55:25.813Z,1752846925.813 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-07-18T13:55:25.813Z,1752846925.813 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T13:55:25.813Z,1752846925.813 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T13:55:25.815Z,1752846925.815 [Startup:StartupSatComms] Running Loop=1 2025-07-18T13:55:25.815Z,1752846925.815 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-07-18T13:55:25.815Z,1752846925.815 [Startup:StartupSatComms:A] Running Loop=1 2025-07-18T13:55:26.105Z,1752846926.105 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-07-18T13:55:27.698Z,1752846927.698 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,135525.00,A,3647.82937,N,12150.95799,W,0.233,343.91,180725,,,A*73 2025-07-18T13:55:27.700Z,1752846927.700 [NAL9602](INFO): GPS fix at 20250718T135525: (36.797156, -121.849300) 2025-07-18T13:55:27.711Z,1752846927.711 [Startup:StartupSatComms:A] Stopped 2025-07-18T13:55:27.711Z,1752846927.711 [Startup:StartupSatComms:B] Running Loop=1 2025-07-18T13:55:28.131Z,1752846928.131 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-07-18T13:56:03.335Z,1752846963.335 [NAL9602](INFO): SBD MO Status=1, MOMSN=10182, MT Status=0, MTMSN=0 2025-07-18T13:56:03.384Z,1752846963.384 [NAL9602](INFO): Sent 39 bytes from file Logs/20250718T132925/Courier0025.lzma 2025-07-18T13:56:03.384Z,1752846963.384 [NAL9602](INFO): Packets left to send: 0 2025-07-18T13:56:18.322Z,1752846978.322 [NAL9602](INFO): SBD MO Status=2, MOMSN=10183, MT Status=2, MTMSN=0 2025-07-18T13:56:18.322Z,1752846978.322 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T13:56:28.090Z,1752846988.090 [Startup:StartupSatComms:B](INFO): Timed out from 2025-07-18T13:55:27.7Z 2025-07-18T13:56:28.090Z,1752846988.090 [Startup:StartupSatComms:B] Stopped 2025-07-18T13:56:28.091Z,1752846988.091 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-07-18T13:56:28.091Z,1752846988.091 [Startup:StartupSatComms] Stopped 2025-07-18T13:56:28.091Z,1752846988.091 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-07-18T13:56:28.092Z,1752846988.092 [Startup](INFO): Completed Startup 2025-07-18T13:56:28.092Z,1752846988.092 [MissionManager](INFO): Startup is completed. 2025-07-18T13:56:28.092Z,1752846988.092 [MissionManager](INFO): Uninitializing Mission Startup 2025-07-18T13:56:28.092Z,1752846988.092 [Startup] Stopped 2025-07-18T13:56:28.092Z,1752846988.092 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-07-18T13:56:28.092Z,1752846988.092 [Startup:A.GoToSurface] Stopped 2025-07-18T13:56:28.092Z,1752846988.092 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T13:56:28.502Z,1752846988.502 [MissionManager](IMPORTANT): Started mission Default 2025-07-18T13:56:28.502Z,1752846988.502 [Default] Running Loop=1 2025-07-18T13:56:28.502Z,1752846988.502 [Default](DEBUG): Aggregate::initialize Default 2025-07-18T13:56:28.502Z,1752846988.502 [Default:B.GoToSurface] Running Loop=1 2025-07-18T13:56:28.502Z,1752846988.502 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T13:56:28.503Z,1752846988.503 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-07-18T13:56:28.503Z,1752846988.503 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-07-18T13:56:28.503Z,1752846988.503 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-07-18T13:56:28.503Z,1752846988.503 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-07-18T13:56:28.504Z,1752846988.504 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T13:56:28.504Z,1752846988.504 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T13:56:28.504Z,1752846988.504 [Default:A.Wait] Running Loop=1 2025-07-18T13:56:28.504Z,1752846988.504 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-07-18T13:56:36.561Z,1752846996.561 [NAL9602](INFO): SBD MO Status=2, MOMSN=10183, MT Status=2, MTMSN=0 2025-07-18T13:56:36.562Z,1752846996.562 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T13:56:41.823Z,1752847001.823 [Default:A.Wait](INFO): Done Waiting. 2025-07-18T13:56:41.823Z,1752847001.823 [Default:A.Wait] Stopped 2025-07-18T13:56:41.823Z,1752847001.823 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-07-18T13:56:42.235Z,1752847002.235 [Default:CheckIn] Running Loop=1 2025-07-18T13:56:42.235Z,1752847002.235 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-07-18T13:56:42.235Z,1752847002.235 [Default:CheckIn:Read_GPS] Running Loop=1 2025-07-18T13:56:42.643Z,1752847002.643 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-07-18T13:56:44.249Z,1752847004.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,135642.00,A,3647.82735,N,12150.96071,W,0.156,274.42,180725,,,A*74 2025-07-18T13:56:44.251Z,1752847004.251 [NAL9602](INFO): GPS fix at 20250718T135642: (36.797123, -121.849345) 2025-07-18T13:56:44.261Z,1752847004.261 [Default:CheckIn:Read_GPS] Stopped 2025-07-18T13:56:44.261Z,1752847004.261 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-07-18T13:56:44.678Z,1752847004.678 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-07-18T13:57:19.849Z,1752847039.849 [NAL9602](INFO): SBD MO Status=2, MOMSN=10183, MT Status=2, MTMSN=0 2025-07-18T13:57:19.849Z,1752847039.849 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T13:57:30.847Z,1752847050.847 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-07-18T13:57:44.551Z,1752847064.551 [NAL9602](INFO): SBD MO Status=2, MOMSN=10183, MT Status=2, MTMSN=0 2025-07-18T13:57:44.551Z,1752847064.551 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T13:57:53.548Z,1752847073.548 [DataOverHttps](IMPORTANT): SBD MTMSN=20250718T135752 2025-07-18T13:57:53.551Z,1752847073.551 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003667 2025-07-18T13:58:01.118Z,1752847081.118 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20250718T135352/Courier0000.lzma 2025-07-18T13:58:01.122Z,1752847081.122 [DataOverHttps](INFO): Received command: ! echo i > /dev/loadA4 2025-07-18T13:58:01.136Z,1752847081.136 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadA4 2025-07-18T13:58:12.160Z,1752847092.160 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0000.lzma.bak 2025-07-18T13:58:12.161Z,1752847092.161 [DataOverHttps](IMPORTANT): SBD MOMSN=25545184, MTMSN=20250718T135811 2025-07-18T13:58:19.610Z,1752847099.610 [DataOverHttps](INFO): Received command: gfscan 2025-07-18T13:58:19.659Z,1752847099.659 [CommandExec](IMPORTANT): got command gfscan 2025-07-18T13:58:19.707Z,1752847099.707 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-07-18T13:58:24.161Z,1752847104.161 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.184628 CHAN A1 (24V): 0.286487 CHAN A2 (12V): 0.132638 CHAN A3 (5V): 0.045728 CHAN B0 (3.3V): 0.031207 CHAN B1 (3.15aV): 0.030567 CHAN B2 (3.15bV): 0.030780 CHAN B3 (GND): 0.000777 OPEN: 0.013374 Full Scale: +/- 1 mA 2025-07-18T13:58:27.372Z,1752847107.372 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T13:58:38.322Z,1752847118.322 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250718T135352/Courier0004.lzma 2025-07-18T13:58:49.364Z,1752847129.364 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0004.lzma.bak 2025-07-18T13:58:49.364Z,1752847129.364 [DataOverHttps](INFO): SBD MOMSN=25545191 2025-07-18T13:59:02.106Z,1752847142.106 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:03.723Z,1752847143.723 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:14.630Z,1752847154.630 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:15.314Z,1752847155.314 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250718T135352/Courier0007.lzma 2025-07-18T13:59:19.075Z,1752847159.075 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:26.356Z,1752847166.356 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0007.lzma.bak 2025-07-18T13:59:26.356Z,1752847166.356 [DataOverHttps](INFO): SBD MOMSN=25545194 2025-07-18T13:59:27.558Z,1752847167.558 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:34.430Z,1752847174.430 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:40.486Z,1752847180.486 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:44.788Z,1752847184.788 [DataOverHttps](IMPORTANT): SBD MTMSN=20250718T135943 2025-07-18T13:59:49.374Z,1752847189.374 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:52.614Z,1752847192.614 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250718T135352/Courier0010.lzma 2025-07-18T13:59:52.616Z,1752847192.616 [DataOverHttps](INFO): Received command: load Transport/keepstation.tl;set keepstation.Latitude 36.797 degree;set keepstation.Longitude -121.847 degree;set keepstation.Speed 0.9 m/s;run 2025-07-18T13:59:52.671Z,1752847192.671 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl 2025-07-18T13:59:52.672Z,1752847192.672 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl 2025-07-18T13:59:52.672Z,1752847192.672 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl 2025-07-18T13:59:52.674Z,1752847192.674 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl 2025-07-18T13:59:53.011Z,1752847193.011 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T13:59:54.060Z,1752847194.060 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/keepstation.tl translated into: 4 45 NaN NaN 30 15 4 0.75 200 10 10 45 2 0 0 1 2 3 NaN 0 Sinking to Timed out while trying to reach target sink depth at current depth of 2025-07-18T13:59:54.069Z,1752847194.069 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h 2025-07-18T13:59:54.072Z,1752847194.072 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min 2025-07-18T13:59:54.075Z,1752847194.075 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg 2025-07-18T13:59:54.078Z,1752847194.078 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg 2025-07-18T13:59:54.081Z,1752847194.081 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m 2025-07-18T13:59:54.085Z,1752847194.085 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m 2025-07-18T13:59:54.088Z,1752847194.088 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m 2025-07-18T13:59:54.091Z,1752847194.091 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s 2025-07-18T13:59:54.094Z,1752847194.094 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m 2025-07-18T13:59:54.097Z,1752847194.097 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool 2025-07-18T13:59:54.116Z,1752847194.116 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m 2025-07-18T13:59:54.120Z,1752847194.120 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min 2025-07-18T13:59:54.131Z,1752847194.131 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m 2025-07-18T13:59:54.138Z,1752847194.138 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km 2025-07-18T13:59:54.141Z,1752847194.141 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count 2025-07-18T13:59:54.156Z,1752847194.156 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count 2025-07-18T13:59:54.160Z,1752847194.160 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count 2025-07-18T13:59:54.171Z,1752847194.171 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count 2025-07-18T13:59:54.178Z,1752847194.178 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count 2025-07-18T13:59:54.181Z,1752847194.181 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool 2025-07-18T13:59:54.181Z,1752847194.181 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2025-07-18T13:59:54.182Z,1752847194.182 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2025-07-18T13:59:54.191Z,1752847194.191 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2025-07-18T13:59:54.587Z,1752847194.587 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into: 1 10 20 NaN 1 1000 7 30 0 last time_fix was: first GPS update timeout Comms timed out after minutes second GPS update timeout 2025-07-18T13:59:54.593Z,1752847194.593 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h 2025-07-18T13:59:54.596Z,1752847194.596 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min 2025-07-18T13:59:54.599Z,1752847194.599 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg 2025-07-18T13:59:54.602Z,1752847194.602 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s 2025-07-18T13:59:54.605Z,1752847194.605 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s 2025-07-18T13:59:54.608Z,1752847194.608 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s 2025-07-18T13:59:54.656Z,1752847194.656 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min 2025-07-18T13:59:54.667Z,1752847194.667 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min 2025-07-18T13:59:54.701Z,1752847194.701 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-07-18T13:59:54.763Z,1752847194.763 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-07-18T13:59:54.763Z,1752847194.763 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-07-18T13:59:54.764Z,1752847194.764 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-07-18T13:59:54.890Z,1752847194.890 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 1.5 200 2000 2025-07-18T13:59:54.934Z,1752847194.934 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m 2025-07-18T13:59:54.937Z,1752847194.937 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 1.500000 m 2025-07-18T13:59:54.940Z,1752847194.940 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m 2025-07-18T13:59:54.943Z,1752847194.943 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-07-18T13:59:54.944Z,1752847194.944 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-07-18T13:59:54.961Z,1752847194.961 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-07-18T13:59:54.983Z,1752847194.983 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-07-18T13:59:55.002Z,1752847195.002 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-07-18T13:59:55.006Z,1752847195.006 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-07-18T13:59:55.007Z,1752847195.007 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-07-18T13:59:55.098Z,1752847195.098 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-07-18T13:59:55.107Z,1752847195.107 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool 2025-07-18T13:59:55.119Z,1752847195.119 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-07-18T13:59:55.122Z,1752847195.122 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-07-18T13:59:55.126Z,1752847195.126 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-07-18T13:59:55.127Z,1752847195.127 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-07-18T13:59:55.334Z,1752847195.334 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-07-18T13:59:55.347Z,1752847195.347 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool 2025-07-18T13:59:55.349Z,1752847195.349 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool 2025-07-18T13:59:55.357Z,1752847195.357 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool 2025-07-18T13:59:55.360Z,1752847195.360 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool 2025-07-18T13:59:55.371Z,1752847195.371 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool 2025-07-18T13:59:55.387Z,1752847195.387 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-07-18T13:59:55.459Z,1752847195.459 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-07-18T13:59:55.470Z,1752847195.470 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct. 2025-07-18T13:59:55.483Z,1752847195.483 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct. 2025-07-18T13:59:55.525Z,1752847195.525 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy. 2025-07-18T13:59:55.537Z,1752847195.537 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct. 2025-07-18T13:59:55.555Z,1752847195.555 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct. 2025-07-18T13:59:55.568Z,1752847195.568 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct. 2025-07-18T13:59:55.578Z,1752847195.578 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation. 2025-07-18T13:59:55.596Z,1752847195.596 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-07-18T13:59:55.633Z,1752847195.633 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait. 2025-07-18T13:59:55.675Z,1752847195.675 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission keepstation { """ Vehicle transits to desired waypoint (or stays put if none is commanded) and stays within the specified radius. """ arguments { MissionTimeout = 4 hour """ Maximum duration of mission """ NeedCommsTime = 45 minute """ How often to surface for communications """ Latitude = NaN degree """ Latitude of waypoint to hold. If NaN, hold the latitude at start of mission. """ Longitude = NaN degree """ Longitude of waypoint to hold. If NaN, hold the longitude at start of mission. """ Depth = 30 meter """ Depth held during drift mode """ ApproachDepth = 15 meter """ Depth for initial approach to station. """ DepthDeadband = 4 meter """ How much vertical drift from the specified depth is allowed in drift mode """ Speed = 0.75 meter_per_second """ Vehicle transit speed. """ Radius = 200 meter """ Radius of circle around waypoint to hold. """ SinkOffSurface = false """ If true, use buoyancy only to decend to SinkDepth before driving to first target depth """ SinkDepth = 10 meter """ Initial depth to decend using only buoyancy before driving """ SinkDepthTimeout = 10 minute """ Max wait time for the vehicle to reach the target depth """ MaxDepth = 45 meter """ Maximum allowable depth during the mission. """ MinOffshore = 2 kilometer """ Minimum distance from the shoreline to maintain """ } output { DiveMode = 0 count """ Mission variable (don't change). The mission sets this variable to switch between dive modes. Initialized to DoingComms. """ DoingComms = 0 count """ Mission variable (don't change). The mission will run in this mode when doing surface comms. """ SurfaceSink = 1 count """ Mission variable (don't change). The mission will run in this mode when sinking from the surface using only buoyancy. """ TransitToStation = 2 count """ Mission variable (don't change). The mission will run in this mode when performing the transit to station """ StationKeep = 3 count """ Mission variable (don't change). The mission will run in this mode when keeping station """ OnStation = false """ Mission variable (don't change). Determines last mode (Transit or StationKeep) to resume after needcomms """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl aggregate SurfaceComms { run when ( called or ( elapsed ( Universal:time_fix ) > NeedCommsTime ) ) assign in sequence DiveMode = DoingComms call priorityHere=false refId="NeedComms" aggregate setTransit { run in sequence break if ( SinkOffSurface or OnStation ) assign in sequence DiveMode = TransitToStation } aggregate setStation { run in sequence break if ( SinkOffSurface or not OnStation ) assign in sequence DiveMode = StationKeep } aggregate setSink { run in sequence break if ( not SinkOffSurface ) assign in sequence DiveMode = SurfaceSink } } call id="StartingMission" priorityHere=false refId="SurfaceComms" aggregate DiveCmd { run when ( called ) aggregate SurfaceSink { run while ( DiveMode == SurfaceSink ) aggregate sink { run in sequence behavior Guidance:Buoyancy id="BuoyancyHold" { run in parallel set position = NaN cc } behavior Guidance:SetSpeed { run in parallel set speed = 0 m/s } syslog info "Sinking to " + SinkDepth~meter behavior Guidance:Pitch { run in sequence timeout duration=SinkDepthTimeout { syslog important "Timed out while trying to reach target sink depth at current depth of " + Universal:depth~meter } set depth = SinkDepth } # Once we've sunk, either resume transit or station keeping depths and speeds aggregate sinkToTransit { run in sequence break if ( OnStation ) assign in sequence DiveMode = TransitToStation } aggregate sinkToStation { run in sequence break if ( not OnStation ) assign in sequence DiveMode = StationKeep } } } aggregate TransitToStation { run while ( DiveMode == TransitToStation ) aggregate dive { run in sequence behavior Guidance:Buoyancy { run in parallel set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch { run in parallel set depth = ApproachDepth } behavior Guidance:SetSpeed { run in parallel set speed = Speed } } } aggregate StationKeep { run while ( DiveMode == StationKeep ) assign in parallel Control:VerticalControl.depthDeadband = DepthDeadband behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:KeepStation { run in parallel set latitude = Latitude set longitude = Longitude set radius = Radius set speed = Speed } } } aggregate TransitToStation { """ Need a separate aggregate for transit if we want to specify a different depth for the approach. """ run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call priorityHere=false refId="DiveCmd" } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude } assign in sequence DiveMode = StationKeep assign in sequence OnStation = true } call id="OnStation" priorityHere=false refId="NeedComms" aggregate KeepStation { run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call priorityHere=false refId="DiveCmd" } behavior Guidance:Wait { """ Due to the way the KeepStation behavior is currently implemented, we must run it in parallel and use a Wait to keep from completing the mission before the timeout expires. However, this new version of the mission uses a top-level timeout so that the entire mission will not run for longer then MissionTimeout. """ run in sequence set duration = MissionTimeout } } } 2025-07-18T13:59:55.677Z,1752847195.677 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation 2025-07-18T14:00:03.362Z,1752847203.362 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.797 degree 2025-07-18T14:00:03.364Z,1752847203.364 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.847 degree 2025-07-18T14:00:03.365Z,1752847203.365 [CommandExec](IMPORTANT): got command set keepstation.Speed 0.9 meter_per_second 2025-07-18T14:00:03.365Z,1752847203.365 [CommandExec](IMPORTANT): got command run 2025-07-18T14:00:03.368Z,1752847203.368 [CommandExec](IMPORTANT): Running 2025-07-18T14:00:03.534Z,1752847203.534 [Default] Stopped 2025-07-18T14:00:03.534Z,1752847203.534 [Default](DEBUG): Aggregate::uninitialize Default 2025-07-18T14:00:03.534Z,1752847203.534 [Default:B.GoToSurface] Stopped 2025-07-18T14:00:03.534Z,1752847203.534 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T14:00:03.534Z,1752847203.534 [Default:CheckIn] Stopped 2025-07-18T14:00:03.534Z,1752847203.534 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-07-18T14:00:03.534Z,1752847203.534 [Default:CheckIn:Read_Iridium] Stopped 2025-07-18T14:00:03.535Z,1752847203.535 [MissionManager](IMPORTANT): Started mission keepstation 2025-07-18T14:00:03.535Z,1752847203.535 [keepstation] Running Loop=1 2025-07-18T14:00:03.535Z,1752847203.535 [keepstation](DEBUG): Aggregate::initialize keepstation 2025-07-18T14:00:03.535Z,1752847203.535 [keepstation:StandardEnvelopes] Running Loop=1 2025-07-18T14:00:03.535Z,1752847203.535 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes 2025-07-18T14:00:03.535Z,1752847203.535 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-07-18T14:00:03.535Z,1752847203.535 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:BackseatDriver] Running Loop=1 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-07-18T14:00:03.536Z,1752847203.536 [keepstation:PowerOnly] Running Loop=1 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:PowerOnly:A] Running Loop=1 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:PowerOnly:B] Running Loop=1 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:PowerOnly:C] Running Loop=1 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:PowerOnly:D] Running Loop=1 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:PowerOnly:E.Wait] Running Loop=1 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-07-18T14:00:03.537Z,1752847203.537 [keepstation:B] Running Loop=1 2025-07-18T14:00:03.538Z,1752847203.538 [keepstation:PowerOnly] Running Loop=1 2025-07-18T14:00:03.538Z,1752847203.538 [keepstation:PowerOnly:D] Stopped 2025-07-18T14:00:03.538Z,1752847203.538 [keepstation:PowerOnly:C] Stopped 2025-07-18T14:00:03.539Z,1752847203.539 [keepstation:PowerOnly:B] Stopped 2025-07-18T14:00:03.539Z,1752847203.539 [keepstation:PowerOnly:A] Stopped 2025-07-18T14:00:03.539Z,1752847203.539 [keepstation:BackseatDriver] Running Loop=1 2025-07-18T14:00:03.539Z,1752847203.539 [keepstation:StandardEnvelopes] Running Loop=1 2025-07-18T14:00:03.539Z,1752847203.539 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-07-18T14:00:03.540Z,1752847203.540 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-07-18T14:00:03.540Z,1752847203.540 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-07-18T14:00:03.541Z,1752847203.541 [keepstation:B] Stopped 2025-07-18T14:00:03.541Z,1752847203.541 [keepstation:D] Running Loop=1 2025-07-18T14:00:03.656Z,1752847203.656 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0010.lzma.bak 2025-07-18T14:00:03.656Z,1752847203.656 [DataOverHttps](INFO): SBD MOMSN=25545197 2025-07-18T14:00:03.987Z,1752847203.987 [keepstation:D] Stopped 2025-07-18T14:00:03.987Z,1752847203.987 [keepstation:E] Running Loop=1 2025-07-18T14:00:04.322Z,1752847204.322 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:04.361Z,1752847204.361 [keepstation:E] Stopped 2025-07-18T14:00:04.361Z,1752847204.361 [keepstation:StartingMission] Running Loop=1 2025-07-18T14:00:04.361Z,1752847204.361 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission 2025-07-18T14:00:04.771Z,1752847204.771 [keepstation:SurfaceComms] Running Loop=1 2025-07-18T14:00:04.771Z,1752847204.771 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-07-18T14:00:04.771Z,1752847204.771 [keepstation:SurfaceComms:A] Running Loop=1 2025-07-18T14:00:04.771Z,1752847204.771 [keepstation:SurfaceComms:A] Stopped 2025-07-18T14:00:04.771Z,1752847204.771 [keepstation:SurfaceComms:B] Running Loop=1 2025-07-18T14:00:04.771Z,1752847204.771 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-07-18T14:00:05.204Z,1752847205.204 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2025-07-18T14:00:05.205Z,1752847205.205 [keepstation:NeedComms] Running Loop=1 2025-07-18T14:00:05.205Z,1752847205.205 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-07-18T14:00:05.205Z,1752847205.205 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-07-18T14:00:05.205Z,1752847205.205 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T14:00:05.205Z,1752847205.205 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-07-18T14:00:05.206Z,1752847205.206 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-07-18T14:00:05.206Z,1752847205.206 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-07-18T14:00:05.207Z,1752847205.207 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-07-18T14:00:05.207Z,1752847205.207 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T14:00:05.207Z,1752847205.207 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T14:00:05.208Z,1752847205.208 [keepstation:NeedComms:A] Running Loop=1 2025-07-18T14:00:05.209Z,1752847205.209 [keepstation:NeedComms:A](INFO): last time_fix was: 1752847002.000000 second since 1970/01/01T00:00:00Z 2025-07-18T14:00:05.209Z,1752847205.209 [keepstation:NeedComms:A] Stopped 2025-07-18T14:00:05.534Z,1752847205.534 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:05.582Z,1752847205.582 [keepstation:NeedComms:C] Running Loop=1 2025-07-18T14:00:05.973Z,1752847205.973 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-07-18T14:00:07.561Z,1752847207.561 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140005.00,A,3647.82481,N,12150.96308,W,0.156,185.16,180725,,,D*7B 2025-07-18T14:00:07.563Z,1752847207.563 [NAL9602](INFO): GPS fix at 20250718T140005: (36.797080, -121.849385) 2025-07-18T14:00:07.611Z,1752847207.611 [keepstation:NeedComms:C] Stopped 2025-07-18T14:00:07.611Z,1752847207.611 [keepstation:NeedComms:D] Running Loop=1 2025-07-18T14:00:08.019Z,1752847208.019 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-07-18T14:00:18.949Z,1752847218.949 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:19.754Z,1752847219.754 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:26.653Z,1752847226.653 [NAL9602](INFO): SBD MO Status=2, MOMSN=10183, MT Status=2, MTMSN=0 2025-07-18T14:00:26.653Z,1752847226.653 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T14:00:32.315Z,1752847232.315 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:32.885Z,1752847232.885 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250718T135352/Courier0013.lzma 2025-07-18T14:00:35.542Z,1752847235.542 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:43.928Z,1752847243.928 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0013.lzma.bak 2025-07-18T14:00:43.928Z,1752847243.928 [DataOverHttps](INFO): SBD MOMSN=25545200 2025-07-18T14:00:45.642Z,1752847245.642 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:50.490Z,1752847250.490 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T14:00:58.571Z,1752847258.571 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T14:01:05.440Z,1752847265.440 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T14:01:10.122Z,1752847270.122 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250718T135352/Courier0016.lzma 2025-07-18T14:01:11.499Z,1752847271.499 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T14:01:15.948Z,1752847275.948 [NAL9602](INFO): SBD MO Status=1, MOMSN=10183, MT Status=0, MTMSN=0 2025-07-18T14:01:15.948Z,1752847275.948 [NAL9602](INFO): No messages in MT queue 2025-07-18T14:01:20.389Z,1752847280.389 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T14:01:20.932Z,1752847280.932 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0016.lzma.bak 2025-07-18T14:01:20.932Z,1752847280.932 [DataOverHttps](INFO): SBD MOMSN=25545202 2025-07-18T14:01:24.838Z,1752847284.838 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 5. 2025-07-18T14:01:24.841Z,1752847284.841 [BPC1](INFO): Received data from all battery sticks. 2025-07-18T14:01:46.655Z,1752847306.655 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T14:01:47.038Z,1752847307.038 [DataOverHttps](INFO): Sending 313 bytes from file Logs/20250718T132925/Express0026.lzma 2025-07-18T14:01:58.076Z,1752847318.076 [DataOverHttps](INFO): Moved sent file to Logs/20250718T132925/Express0026.lzma.bak 2025-07-18T14:01:58.076Z,1752847318.076 [DataOverHttps](INFO): SBD MOMSN=25545205 2025-07-18T14:02:23.953Z,1752847343.953 [DataOverHttps](INFO): Sending 1218 bytes from file Logs/20250718T135352/Express0001.lzma 2025-07-18T14:02:34.993Z,1752847354.993 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0001.lzma.bak 2025-07-18T14:02:34.993Z,1752847354.993 [DataOverHttps](INFO): SBD MOMSN=25545215 2025-07-18T14:03:01.290Z,1752847381.290 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20250718T135352/Express0005.lzma 2025-07-18T14:03:12.332Z,1752847392.332 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0005.lzma.bak 2025-07-18T14:03:12.332Z,1752847392.332 [DataOverHttps](INFO): SBD MOMSN=25545247 2025-07-18T14:03:38.154Z,1752847418.154 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250718T135352/Express0008.lzma 2025-07-18T14:03:49.196Z,1752847429.196 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0008.lzma.bak 2025-07-18T14:03:49.196Z,1752847429.196 [DataOverHttps](INFO): SBD MOMSN=25545253 2025-07-18T14:04:15.094Z,1752847455.094 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20250718T135352/Express0011.lzma 2025-07-18T14:04:26.136Z,1752847466.136 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0011.lzma.bak 2025-07-18T14:04:26.136Z,1752847466.136 [DataOverHttps](INFO): SBD MOMSN=25545257 2025-07-18T14:04:54.078Z,1752847494.078 [DataOverHttps](INFO): Sending 319 bytes from file Logs/20250718T135352/Express0014.lzma 2025-07-18T14:05:05.120Z,1752847505.120 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0014.lzma.bak 2025-07-18T14:05:05.121Z,1752847505.121 [DataOverHttps](INFO): SBD MOMSN=25545262 2025-07-18T14:05:31.015Z,1752847531.015 [DataOverHttps](INFO): Sending 273 bytes from file Logs/20250718T135352/Express0017.lzma 2025-07-18T14:05:42.056Z,1752847542.056 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0017.lzma.bak 2025-07-18T14:05:42.056Z,1752847542.056 [DataOverHttps](INFO): SBD MOMSN=25545267 2025-07-18T14:05:43.420Z,1752847543.420 [keepstation:NeedComms:D] Stopped 2025-07-18T14:05:43.420Z,1752847543.420 [keepstation:NeedComms:E] Running Loop=1 2025-07-18T14:05:43.819Z,1752847543.819 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-07-18T14:05:45.421Z,1752847545.421 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,140543.00,A,3647.81922,N,12150.96845,W,0.194,216.56,180725,,,D*7A 2025-07-18T14:05:45.424Z,1752847545.424 [NAL9602](INFO): GPS fix at 20250718T140543: (36.796987, -121.849474) 2025-07-18T14:05:45.444Z,1752847545.444 [keepstation:NeedComms:E] Stopped 2025-07-18T14:05:45.445Z,1752847545.445 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-07-18T14:05:45.445Z,1752847545.445 [keepstation:NeedComms] Stopped 2025-07-18T14:05:45.445Z,1752847545.445 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-07-18T14:05:45.445Z,1752847545.445 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-07-18T14:05:45.445Z,1752847545.445 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T14:05:45.859Z,1752847545.859 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-07-18T14:05:45.859Z,1752847545.859 [keepstation:SurfaceComms:B] Stopped 2025-07-18T14:05:45.859Z,1752847545.859 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-07-18T14:05:45.859Z,1752847545.859 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-07-18T14:05:45.859Z,1752847545.859 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-07-18T14:05:45.859Z,1752847545.859 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-07-18T14:05:46.263Z,1752847546.263 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-07-18T14:05:46.263Z,1752847546.263 [keepstation:SurfaceComms:setTransit](INFO): Completed keepstation:SurfaceComms:setTransit 2025-07-18T14:05:46.263Z,1752847546.263 [keepstation:SurfaceComms:setTransit] Stopped 2025-07-18T14:05:46.263Z,1752847546.263 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-07-18T14:05:46.263Z,1752847546.263 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-07-18T14:05:46.264Z,1752847546.264 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-07-18T14:05:46.264Z,1752847546.264 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-07-18T14:05:46.685Z,1752847546.685 [keepstation:SurfaceComms:setStation] Stopped 2025-07-18T14:05:46.685Z,1752847546.685 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-07-18T14:05:46.685Z,1752847546.685 [keepstation:SurfaceComms:setStation:A] Stopped 2025-07-18T14:05:46.685Z,1752847546.685 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-07-18T14:05:46.686Z,1752847546.686 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-07-18T14:05:46.686Z,1752847546.686 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-07-18T14:05:47.074Z,1752847547.074 [keepstation:SurfaceComms:setSink] Stopped 2025-07-18T14:05:47.074Z,1752847547.074 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-07-18T14:05:47.074Z,1752847547.074 [keepstation:SurfaceComms:setSink:A] Stopped 2025-07-18T14:05:47.094Z,1752847547.094 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-07-18T14:05:47.094Z,1752847547.094 [keepstation:SurfaceComms] Stopped 2025-07-18T14:05:47.094Z,1752847547.094 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-07-18T14:05:47.470Z,1752847547.470 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:StartingMission] Stopped 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:TransitToStation] Running Loop=1 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:TransitToStation:Dive] Running Loop=1 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-07-18T14:05:47.471Z,1752847547.471 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1 2025-07-18T14:05:47.472Z,1752847547.472 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2025-07-18T14:05:47.473Z,1752847547.473 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.797001,-121.847000 2025-07-18T14:05:47.881Z,1752847547.881 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.797001,-121.847000 2025-07-18T14:05:47.881Z,1752847547.881 [keepstation:TransitToStation:Dive] Running Loop=1 2025-07-18T14:05:47.881Z,1752847547.881 [keepstation:DiveCmd] Running Loop=1 2025-07-18T14:05:47.881Z,1752847547.881 [keepstation:DiveCmd](DEBUG): Aggregate::initialize keepstation:DiveCmd 2025-07-18T14:05:47.881Z,1752847547.881 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-07-18T14:05:47.882Z,1752847547.882 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-07-18T14:05:47.882Z,1752847547.882 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-07-18T14:05:47.886Z,1752847547.886 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-07-18T14:05:47.886Z,1752847547.886 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-07-18T14:05:47.886Z,1752847547.886 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-07-18T14:05:47.886Z,1752847547.886 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-07-18T14:05:47.886Z,1752847547.886 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-07-18T14:05:47.887Z,1752847547.887 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-07-18T14:05:47.888Z,1752847547.888 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-07-18T14:05:47.889Z,1752847547.889 [keepstation:DiveCmd:StationKeep] Stopped 2025-07-18T14:05:47.889Z,1752847547.889 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-07-18T14:05:47.889Z,1752847547.889 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-07-18T14:05:47.889Z,1752847547.889 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-07-18T14:05:47.889Z,1752847547.889 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-07-18T14:05:47.889Z,1752847547.889 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-07-18T14:05:47.890Z,1752847547.890 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-07-18T14:05:47.890Z,1752847547.890 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-07-18T14:05:47.894Z,1752847547.894 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-07-18T14:05:47.895Z,1752847547.895 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-07-18T14:05:47.895Z,1752847547.895 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-07-18T14:05:47.895Z,1752847547.895 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-07-18T14:05:47.895Z,1752847547.895 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-07-18T14:05:47.895Z,1752847547.895 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-07-18T14:05:47.895Z,1752847547.895 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-07-18T14:05:47.896Z,1752847547.896 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-07-18T14:05:47.896Z,1752847547.896 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-07-18T14:05:47.896Z,1752847547.896 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-07-18T14:05:47.896Z,1752847547.896 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-07-18T14:05:47.928Z,1752847547.928 [HorizontalControl](DEBUG): kpHeading = 0.400000 2025-07-18T14:05:47.929Z,1752847547.929 [HorizontalControl](DEBUG): kiHeading = 0.001000 2025-07-18T14:05:47.929Z,1752847547.929 [HorizontalControl](DEBUG): kdHeading = 0.050000 2025-07-18T14:06:12.977Z,1752847572.977 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T14:06:12.977Z,1752847572.977 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T14:06:28.049Z,1752847588.049 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T14:06:28.049Z,1752847588.049 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T14:06:48.633Z,1752847608.633 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T14:06:48.633Z,1752847608.633 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T14:07:04.853Z,1752847624.853 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T14:07:04.853Z,1752847624.853 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T14:07:37.091Z,1752847657.091 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.102760 2025-07-18T14:08:03.934Z,1752847683.934 [Radio_Surface](INFO): Powering down 2025-07-18T14:08:04.203Z,1752847684.203 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-07-18T14:10:47.077Z,1752847847.077 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-07-18T14:11:17.788Z,1752847877.788 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T14:14:40.653Z,1752848080.653 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Reached waypoint: 36.797001,-121.847000 2025-07-18T14:14:40.653Z,1752848080.653 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped 2025-07-18T14:14:40.653Z,1752848080.653 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2025-07-18T14:14:40.654Z,1752848080.654 [keepstation:TransitToStation:C] Running Loop=1 2025-07-18T14:14:41.035Z,1752848081.035 [keepstation:TransitToStation:C] Stopped 2025-07-18T14:14:41.035Z,1752848081.035 [keepstation:TransitToStation:D] Running Loop=1 2025-07-18T14:14:41.036Z,1752848081.036 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-07-18T14:14:41.036Z,1752848081.036 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-07-18T14:14:41.036Z,1752848081.036 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-07-18T14:14:41.036Z,1752848081.036 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-07-18T14:14:41.036Z,1752848081.036 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-07-18T14:14:41.036Z,1752848081.036 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-07-18T14:14:41.036Z,1752848081.036 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-07-18T14:14:41.037Z,1752848081.037 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-07-18T14:14:41.037Z,1752848081.037 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-07-18T14:14:41.037Z,1752848081.037 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-07-18T14:14:41.038Z,1752848081.038 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-07-18T14:14:41.038Z,1752848081.038 [keepstation:DiveCmd:TransitToStation] Stopped 2025-07-18T14:14:41.038Z,1752848081.038 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-07-18T14:14:41.038Z,1752848081.038 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-07-18T14:14:41.039Z,1752848081.039 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-07-18T14:14:41.039Z,1752848081.039 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-07-18T14:14:41.039Z,1752848081.039 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-07-18T14:14:41.039Z,1752848081.039 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-07-18T14:14:41.039Z,1752848081.039 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-07-18T14:14:41.039Z,1752848081.039 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-07-18T14:14:41.451Z,1752848081.451 [keepstation:TransitToStation:D] Stopped 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:TransitToStation](INFO): Completed keepstation:TransitToStation 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:TransitToStation] Stopped 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:TransitToStation:Dive] Stopped 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:TransitToStation:Dive:A] Stopped 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:OnStation] Running Loop=1 2025-07-18T14:14:41.452Z,1752848081.452 [keepstation:OnStation](DEBUG): Aggregate::initialize keepstation:OnStation 2025-07-18T14:14:41.839Z,1752848081.839 [keepstation:NeedComms] Running Loop=1 2025-07-18T14:14:41.839Z,1752848081.839 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-07-18T14:14:41.839Z,1752848081.839 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-07-18T14:14:41.839Z,1752848081.839 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T14:14:41.839Z,1752848081.839 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-07-18T14:14:41.840Z,1752848081.840 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-07-18T14:14:41.840Z,1752848081.840 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-07-18T14:14:41.841Z,1752848081.841 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-07-18T14:14:41.841Z,1752848081.841 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T14:14:41.841Z,1752848081.841 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T14:14:41.841Z,1752848081.841 [keepstation:NeedComms:A] Running Loop=1 2025-07-18T14:14:41.843Z,1752848081.843 [keepstation:NeedComms:A](INFO): last time_fix was: 1752847543.000000 second since 1970/01/01T00:00:00Z 2025-07-18T14:14:41.843Z,1752848081.843 [keepstation:NeedComms:A] Stopped 2025-07-18T14:15:59.405Z,1752848159.405 [keepstation:NeedComms:C] Running Loop=1 2025-07-18T14:15:59.894Z,1752848159.894 [Radio_Surface](INFO): Powering up 2025-07-18T14:16:05.170Z,1752848165.170 [DataOverHttps](INFO): Radio surface powered ON. 2025-07-18T14:16:32.120Z,1752848192.120 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-07-18T14:16:32.194Z,1752848192.194 [NAL9602](ERROR): received: +CSQ:0 OK184, 2, 0, 0, 0 OK 2025-07-18T14:16:35.311Z,1752848195.311 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T14:17:10.450Z,1752848230.450 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T14:17:45.594Z,1752848265.594 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T14:18:20.736Z,1752848300.736 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T14:18:55.878Z,1752848335.878 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T14:19:31.503Z,1752848371.503 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-07-18T14:19:54.022Z,1752848394.022 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002609 2025-07-18T14:20:23.587Z,1752848423.587 [CommandExec](IMPORTANT): got command show stack 2025-07-18T14:20:23.587Z,1752848423.587 [CommandExec](IMPORTANT): Behavior Stack: 2025-07-18T14:20:23.588Z,1752848423.588 [keepstation:NeedComms](IMPORTANT): Priority 0: keepstation:NeedComms:B.GoToSurface 2025-07-18T14:20:23.588Z,1752848423.588 [keepstation:NeedComms](IMPORTANT): Priority 1: keepstation:NeedComms:C 2025-07-18T14:20:23.589Z,1752848423.589 [keepstation:StandardEnvelopes](IMPORTANT): Priority 2: keepstation:StandardEnvelopes:A.AltitudeEnvelope 2025-07-18T14:20:23.589Z,1752848423.589 [keepstation:StandardEnvelopes](IMPORTANT): Priority 3: keepstation:StandardEnvelopes:B.DepthEnvelope 2025-07-18T14:20:23.589Z,1752848423.589 [keepstation:StandardEnvelopes](IMPORTANT): Priority 4: keepstation:StandardEnvelopes:C.OffshoreEnvelope 2025-07-18T14:20:23.589Z,1752848423.589 [keepstation:BackseatDriver](IMPORTANT): Priority 5: keepstation:BackseatDriver:A.BackseatDriver 2025-07-18T14:20:23.590Z,1752848423.590 [keepstation:PowerOnly](IMPORTANT): Priority 6: keepstation:PowerOnly:E.Wait 2025-07-18T14:20:23.591Z,1752848423.591 [keepstation:DiveCmd:StationKeep](IMPORTANT): Priority 7: keepstation:DiveCmd:StationKeep:A 2025-07-18T14:20:23.591Z,1752848423.591 [keepstation:DiveCmd:StationKeep](IMPORTANT): Priority 8: keepstation:DiveCmd:StationKeep:B.Pitch 2025-07-18T14:20:23.591Z,1752848423.591 [keepstation:DiveCmd:StationKeep](IMPORTANT): Priority 9: keepstation:DiveCmd:StationKeep:C.KeepStation 2025-07-18T14:21:03.216Z,1752848463.216 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-07-18T14:21:14.129Z,1752848474.129 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142113.00,A,3647.80267,N,12150.74819,W,0.797,308.21,180725,,,D*7C 2025-07-18T14:21:14.131Z,1752848474.131 [NAL9602](INFO): GPS fix at 20250718T142113: (36.796711, -121.845803) 2025-07-18T14:21:14.161Z,1752848474.161 [keepstation:NeedComms:C] Stopped 2025-07-18T14:21:14.161Z,1752848474.161 [keepstation:NeedComms:D] Running Loop=1 2025-07-18T14:21:21.218Z,1752848481.218 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20250718T135352/Courier0019.lzma 2025-07-18T14:21:32.260Z,1752848492.260 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0019.lzma.bak 2025-07-18T14:21:32.260Z,1752848492.260 [DataOverHttps](INFO): SBD MOMSN=25545295 2025-07-18T14:21:46.460Z,1752848506.460 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T14:21:58.192Z,1752848518.192 [DataOverHttps](INFO): Sending 827 bytes from file Logs/20250718T135352/Express0020.lzma 2025-07-18T14:22:09.232Z,1752848529.232 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0020.lzma.bak 2025-07-18T14:22:09.232Z,1752848529.232 [DataOverHttps](INFO): SBD MOMSN=25545298 2025-07-18T14:22:10.746Z,1752848530.746 [keepstation:NeedComms:D] Stopped 2025-07-18T14:22:10.746Z,1752848530.746 [keepstation:NeedComms:E] Running Loop=1 2025-07-18T14:22:12.745Z,1752848532.745 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,142212.00,A,3647.80317,N,12150.74848,W,0.428,348.60,180725,,,D*7A 2025-07-18T14:22:12.747Z,1752848532.747 [NAL9602](INFO): GPS fix at 20250718T142212: (36.796720, -121.845808) 2025-07-18T14:22:12.785Z,1752848532.785 [keepstation:NeedComms:E] Stopped 2025-07-18T14:22:12.791Z,1752848532.791 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-07-18T14:22:12.791Z,1752848532.791 [keepstation:NeedComms] Stopped 2025-07-18T14:22:12.791Z,1752848532.791 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-07-18T14:22:12.791Z,1752848532.791 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-07-18T14:22:12.791Z,1752848532.791 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T14:22:13.198Z,1752848533.198 [keepstation:OnStation](INFO): Completed keepstation:OnStation 2025-07-18T14:22:13.198Z,1752848533.198 [keepstation:OnStation] Stopped 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:OnStation](DEBUG): Aggregate::uninitialize keepstation:OnStation 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:KeepStation] Running Loop=1 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:KeepStation](DEBUG): Aggregate::initialize keepstation:KeepStation 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:KeepStation:Dive] Running Loop=1 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-07-18T14:22:13.203Z,1752848533.203 [keepstation:KeepStation:B.Wait] Running Loop=1 2025-07-18T14:22:13.204Z,1752848533.204 [keepstation:KeepStation:B.Wait](DEBUG): Initialize Wait Component. 2025-07-18T14:22:13.578Z,1752848533.578 [keepstation:KeepStation:Dive] Running Loop=1 2025-07-18T14:22:43.464Z,1752848563.464 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-07-18T14:22:43.538Z,1752848563.538 [NAL9602](ERROR): received: +CSQ:0 OK184, 2, 0, 0, 0 OK 2025-07-18T14:23:37.223Z,1752848617.223 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T14:23:37.223Z,1752848617.223 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T14:24:04.619Z,1752848644.619 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.851505 2025-07-18T14:24:35.482Z,1752848675.482 [Radio_Surface](INFO): Powering down 2025-07-18T14:25:02.854Z,1752848702.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T14:25:03.858Z,1752848703.858 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-07-18T14:27:15.379Z,1752848835.379 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-07-18T14:27:46.087Z,1752848866.087 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T15:06:24.295Z,1752851184.295 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:06:24.643Z,1752851184.643 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:06:39.229Z,1752851199.229 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:06:39.586Z,1752851199.586 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:06:54.535Z,1752851214.535 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:06:54.541Z,1752851214.541 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:09.484Z,1752851229.484 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:09.490Z,1752851229.490 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:13.138Z,1752851233.138 [keepstation:SurfaceComms] Running Loop=1 2025-07-18T15:07:13.138Z,1752851233.138 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-07-18T15:07:13.139Z,1752851233.139 [keepstation:SurfaceComms:A] Running Loop=1 2025-07-18T15:07:13.139Z,1752851233.139 [keepstation:SurfaceComms:A] Stopped 2025-07-18T15:07:13.139Z,1752851233.139 [keepstation:SurfaceComms:B] Running Loop=1 2025-07-18T15:07:13.139Z,1752851233.139 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-07-18T15:07:13.141Z,1752851233.141 [keepstation:NeedComms] Running Loop=1 2025-07-18T15:07:13.141Z,1752851233.141 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-07-18T15:07:13.141Z,1752851233.141 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-07-18T15:07:13.141Z,1752851233.141 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T15:07:13.141Z,1752851233.141 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-07-18T15:07:13.142Z,1752851233.142 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-07-18T15:07:13.142Z,1752851233.142 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-07-18T15:07:13.142Z,1752851233.142 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-07-18T15:07:13.143Z,1752851233.143 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T15:07:13.143Z,1752851233.143 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T15:07:13.143Z,1752851233.143 [keepstation:NeedComms:A] Running Loop=1 2025-07-18T15:07:13.145Z,1752851233.145 [keepstation:NeedComms:A](INFO): last time_fix was: 1752848532.000000 second since 1970/01/01T00:00:00Z 2025-07-18T15:07:13.145Z,1752851233.145 [keepstation:NeedComms:A] Stopped 2025-07-18T15:07:13.533Z,1752851233.533 [keepstation:KeepStation:Dive] Stopped 2025-07-18T15:07:13.533Z,1752851233.533 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-07-18T15:07:13.533Z,1752851233.533 [keepstation:KeepStation:Dive:A] Stopped 2025-07-18T15:07:13.533Z,1752851233.533 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-07-18T15:07:13.534Z,1752851233.534 [keepstation:DiveCmd:StationKeep] Stopped 2025-07-18T15:07:13.534Z,1752851233.534 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-07-18T15:07:13.534Z,1752851233.534 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-07-18T15:07:13.534Z,1752851233.534 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-07-18T15:07:13.534Z,1752851233.534 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-07-18T15:07:13.534Z,1752851233.534 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-07-18T15:07:24.480Z,1752851244.480 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:24.833Z,1752851244.833 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:39.782Z,1752851259.782 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:39.788Z,1752851259.788 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:54.326Z,1752851274.326 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:07:55.944Z,1752851275.944 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:08:09.275Z,1752851289.275 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:08:11.296Z,1752851291.296 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:08:23.818Z,1752851303.818 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:08:26.646Z,1752851306.646 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:08:38.768Z,1752851318.768 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T15:08:42.402Z,1752851322.402 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T15:08:42.425Z,1752851322.425 [BPC1](INFO): Calculating totals. Valid battery stick count: 45. Valid reserve battery stick count: 5. 2025-07-18T15:08:42.431Z,1752851322.431 [BPC1](INFO): Received data from all battery sticks. 2025-07-18T15:09:03.022Z,1752851343.022 [keepstation:NeedComms:C] Running Loop=1 2025-07-18T15:09:03.567Z,1752851343.567 [Radio_Surface](INFO): Powering up 2025-07-18T15:09:09.758Z,1752851349.758 [DataOverHttps](INFO): Radio surface powered ON. 2025-07-18T15:09:35.736Z,1752851375.736 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-07-18T15:09:35.810Z,1752851375.810 [NAL9602](ERROR): received: +CSQ:0 OK184, 2, 0, 0, 0 OK 2025-07-18T15:09:39.902Z,1752851379.902 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T15:10:01.995Z,1752851401.995 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T15:10:01.995Z,1752851401.995 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T15:10:15.043Z,1752851415.043 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T15:10:33.519Z,1752851433.519 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T15:10:33.520Z,1752851433.520 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T15:10:50.183Z,1752851450.183 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T15:11:25.334Z,1752851485.334 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T15:12:00.474Z,1752851520.474 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T15:12:36.022Z,1752851556.022 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-07-18T15:12:58.578Z,1752851578.578 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002638 2025-07-18T15:13:02.625Z,1752851582.625 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T15:13:02.625Z,1752851582.625 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T15:13:07.481Z,1752851587.481 [NAL9602](INFO): SBD MO Status=2, MOMSN=10184, MT Status=2, MTMSN=0 2025-07-18T15:13:07.481Z,1752851587.481 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T15:13:24.448Z,1752851604.448 [NAL9602](INFO): SBD MO Status=1, MOMSN=10184, MT Status=0, MTMSN=0 2025-07-18T15:13:24.448Z,1752851604.448 [NAL9602](INFO): No messages in MT queue 2025-07-18T15:13:25.655Z,1752851605.655 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151324.00,A,3647.72659,N,12150.76832,W,0.311,27.74,180725,,,D*43 2025-07-18T15:13:25.658Z,1752851605.658 [NAL9602](INFO): GPS fix at 20250718T151324: (36.795443, -121.846139) 2025-07-18T15:13:25.670Z,1752851605.670 [keepstation:NeedComms:C] Stopped 2025-07-18T15:13:25.671Z,1752851605.671 [keepstation:NeedComms:D] Running Loop=1 2025-07-18T15:13:41.722Z,1752851621.722 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20250718T135352/Courier0022.lzma 2025-07-18T15:13:52.764Z,1752851632.764 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Courier0022.lzma.bak 2025-07-18T15:13:52.764Z,1752851632.764 [DataOverHttps](INFO): SBD MOMSN=25545454 2025-07-18T15:13:58.787Z,1752851638.787 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T15:14:18.687Z,1752851658.687 [DataOverHttps](INFO): Sending 373 bytes from file Logs/20250718T135352/Express0023.lzma 2025-07-18T15:14:29.728Z,1752851669.728 [DataOverHttps](INFO): Moved sent file to Logs/20250718T135352/Express0023.lzma.bak 2025-07-18T15:14:29.728Z,1752851669.728 [DataOverHttps](INFO): SBD MOMSN=25545458 2025-07-18T15:14:31.131Z,1752851671.131 [keepstation:NeedComms:D] Stopped 2025-07-18T15:14:31.131Z,1752851671.131 [keepstation:NeedComms:E] Running Loop=1 2025-07-18T15:14:33.121Z,1752851673.121 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151432.00,A,3647.73080,N,12150.76170,W,0.544,42.29,180725,,,D*42 2025-07-18T15:14:33.123Z,1752851673.123 [NAL9602](INFO): GPS fix at 20250718T151432: (36.795513, -121.846028) 2025-07-18T15:14:33.179Z,1752851673.179 [keepstation:NeedComms:E] Stopped 2025-07-18T15:14:33.180Z,1752851673.180 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-07-18T15:14:33.181Z,1752851673.181 [keepstation:NeedComms] Stopped 2025-07-18T15:14:33.181Z,1752851673.181 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-07-18T15:14:33.181Z,1752851673.181 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-07-18T15:14:33.181Z,1752851673.181 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T15:14:33.564Z,1752851673.564 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-07-18T15:14:33.564Z,1752851673.564 [keepstation:SurfaceComms:B] Stopped 2025-07-18T15:14:33.564Z,1752851673.564 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-07-18T15:14:33.564Z,1752851673.564 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-07-18T15:14:33.565Z,1752851673.565 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-07-18T15:14:33.565Z,1752851673.565 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-07-18T15:14:33.966Z,1752851673.966 [keepstation:SurfaceComms:setTransit] Stopped 2025-07-18T15:14:33.967Z,1752851673.967 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-07-18T15:14:33.967Z,1752851673.967 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-07-18T15:14:33.967Z,1752851673.967 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-07-18T15:14:33.967Z,1752851673.967 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-07-18T15:14:33.967Z,1752851673.967 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-07-18T15:14:34.378Z,1752851674.378 [keepstation:SurfaceComms:setStation:A] Stopped 2025-07-18T15:14:34.379Z,1752851674.379 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation 2025-07-18T15:14:34.379Z,1752851674.379 [keepstation:SurfaceComms:setStation] Stopped 2025-07-18T15:14:34.379Z,1752851674.379 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-07-18T15:14:34.379Z,1752851674.379 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-07-18T15:14:34.379Z,1752851674.379 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-07-18T15:14:34.379Z,1752851674.379 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-07-18T15:14:34.795Z,1752851674.795 [keepstation:KeepStation:Dive] Running Loop=1 2025-07-18T15:14:34.796Z,1752851674.796 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-07-18T15:14:34.796Z,1752851674.796 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-07-18T15:14:34.796Z,1752851674.796 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-07-18T15:14:34.796Z,1752851674.796 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-07-18T15:14:34.796Z,1752851674.796 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-07-18T15:14:34.796Z,1752851674.796 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-07-18T15:14:34.796Z,1752851674.796 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-07-18T15:14:34.797Z,1752851674.797 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-07-18T15:14:34.797Z,1752851674.797 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-07-18T15:14:34.797Z,1752851674.797 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-07-18T15:14:34.803Z,1752851674.803 [keepstation:SurfaceComms:setSink] Stopped 2025-07-18T15:14:34.803Z,1752851674.803 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-07-18T15:14:34.803Z,1752851674.803 [keepstation:SurfaceComms:setSink:A] Stopped 2025-07-18T15:14:34.803Z,1752851674.803 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-07-18T15:14:34.803Z,1752851674.803 [keepstation:SurfaceComms] Stopped 2025-07-18T15:14:34.803Z,1752851674.803 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-07-18T15:14:49.291Z,1752851689.291 [NAL9602](INFO): SBD MO Status=1, MOMSN=10185, MT Status=0, MTMSN=0 2025-07-18T15:14:49.291Z,1752851689.291 [NAL9602](INFO): No messages in MT queue 2025-07-18T15:15:20.003Z,1752851720.003 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T15:16:24.528Z,1752851784.528 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.260315 2025-07-18T15:16:57.490Z,1752851817.490 [Radio_Surface](INFO): Powering down 2025-07-18T15:17:22.770Z,1752851842.770 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T15:17:23.774Z,1752851843.774 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-07-18T15:59:33.493Z,1752854373.493 [keepstation:SurfaceComms] Running Loop=1 2025-07-18T15:59:33.493Z,1752854373.493 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-07-18T15:59:33.493Z,1752854373.493 [keepstation:SurfaceComms:A] Running Loop=1 2025-07-18T15:59:33.494Z,1752854373.494 [keepstation:SurfaceComms:A] Stopped 2025-07-18T15:59:33.494Z,1752854373.494 [keepstation:SurfaceComms:B] Running Loop=1 2025-07-18T15:59:33.494Z,1752854373.494 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-07-18T15:59:33.495Z,1752854373.495 [keepstation:NeedComms] Running Loop=1 2025-07-18T15:59:33.495Z,1752854373.495 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-07-18T15:59:33.496Z,1752854373.496 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-07-18T15:59:33.496Z,1752854373.496 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T15:59:33.496Z,1752854373.496 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-07-18T15:59:33.496Z,1752854373.496 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-07-18T15:59:33.497Z,1752854373.497 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-07-18T15:59:33.497Z,1752854373.497 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-07-18T15:59:33.497Z,1752854373.497 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T15:59:33.498Z,1752854373.498 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T15:59:33.498Z,1752854373.498 [keepstation:NeedComms:A] Running Loop=1 2025-07-18T15:59:33.500Z,1752854373.500 [keepstation:NeedComms:A](INFO): last time_fix was: 1752851672.000000 second since 1970/01/01T00:00:00Z 2025-07-18T15:59:33.500Z,1752854373.500 [keepstation:NeedComms:A] Stopped 2025-07-18T15:59:33.895Z,1752854373.895 [keepstation:KeepStation:Dive] Stopped 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:KeepStation:Dive:A] Stopped 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:DiveCmd:StationKeep] Stopped 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-07-18T15:59:33.896Z,1752854373.896 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-07-18T15:59:33.897Z,1752854373.897 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-07-18T16:01:25.425Z,1752854485.425 [keepstation:NeedComms:C] Running Loop=1 2025-07-18T16:01:25.942Z,1752854485.942 [Radio_Surface](INFO): Powering up 2025-07-18T16:01:31.682Z,1752854491.682 [DataOverHttps](INFO): Radio surface powered ON. 2025-07-18T16:02:01.802Z,1752854521.802 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:02:07.831Z,1752854527.831 [NAL9602](INFO): SBD MO Status=2, MOMSN=10186, MT Status=2, MTMSN=0 2025-07-18T16:02:07.831Z,1752854527.831 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T16:02:33.278Z,1752854553.278 [NAL9602](INFO): SBD MO Status=1, MOMSN=10186, MT Status=0, MTMSN=0 2025-07-18T16:02:33.278Z,1752854553.278 [NAL9602](INFO): No messages in MT queue 2025-07-18T16:02:34.497Z,1752854554.497 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160233.00,A,3647.63123,N,12150.66494,W,0.428,77.09,180725,,,D*4F 2025-07-18T16:02:34.500Z,1752854554.500 [NAL9602](INFO): GPS fix at 20250718T160233: (36.793854, -121.844416) 2025-07-18T16:02:34.532Z,1752854554.532 [keepstation:NeedComms:C] Stopped 2025-07-18T16:02:34.532Z,1752854554.532 [keepstation:NeedComms:D] Running Loop=1 2025-07-18T16:02:36.943Z,1752854556.943 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:02:55.997Z,1752854575.997 [NAL9602](INFO): SBD MO Status=1, MOMSN=10187, MT Status=0, MTMSN=0 2025-07-18T16:02:56.046Z,1752854576.046 [NAL9602](INFO): Sent 73 bytes from file Logs/20250718T135352/Courier0025.lzma 2025-07-18T16:02:56.047Z,1752854576.047 [NAL9602](INFO): Packets left to send: 0 2025-07-18T16:03:12.082Z,1752854592.082 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:03:18.703Z,1752854598.703 [NAL9602](INFO): SBD MO Status=1, MOMSN=10188, MT Status=0, MTMSN=0 2025-07-18T16:03:18.758Z,1752854598.758 [NAL9602](INFO): Sent 307 bytes from file Logs/20250718T135352/Express0026.lzma 2025-07-18T16:03:18.758Z,1752854598.758 [NAL9602](INFO): Packets left to send: 0 2025-07-18T16:03:33.257Z,1752854613.257 [NAL9602](INFO): SBD MO Status=2, MOMSN=10189, MT Status=2, MTMSN=0 2025-07-18T16:03:33.257Z,1752854613.257 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T16:03:38.254Z,1752854618.254 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:03:41.488Z,1752854621.488 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:03:47.231Z,1752854627.231 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:03:49.972Z,1752854629.972 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:03:54.453Z,1752854634.453 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:04.513Z,1752854644.513 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:08.963Z,1752854648.963 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:17.441Z,1752854657.441 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:21.892Z,1752854661.892 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:22.394Z,1752854662.394 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:04:26.339Z,1752854666.339 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:30.376Z,1752854670.376 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:51.221Z,1752854691.221 [NAL9602](INFO): SBD MO Status=2, MOMSN=10189, MT Status=2, MTMSN=0 2025-07-18T16:04:51.221Z,1752854691.221 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T16:04:55.827Z,1752854695.827 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:04:57.951Z,1752854697.951 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-07-18T16:04:59.148Z,1752854699.148 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:05:08.091Z,1752854708.091 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:05:11.980Z,1752854711.980 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:05:20.472Z,1752854720.472 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T16:05:20.666Z,1752854720.666 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002646 2025-07-18T16:05:21.937Z,1752854721.937 [keepstation:NeedComms:D] Stopped 2025-07-18T16:05:21.937Z,1752854721.937 [keepstation:NeedComms:E] Running Loop=1 2025-07-18T16:05:23.941Z,1752854723.941 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160523.00,A,3647.63950,N,12150.64076,W,0.583,69.30,180725,,,D*4A 2025-07-18T16:05:23.944Z,1752854723.944 [NAL9602](INFO): GPS fix at 20250718T160523: (36.793992, -121.844013) 2025-07-18T16:05:24.001Z,1752854724.001 [keepstation:NeedComms:E] Stopped 2025-07-18T16:05:24.002Z,1752854724.002 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-07-18T16:05:24.002Z,1752854724.002 [keepstation:NeedComms] Stopped 2025-07-18T16:05:24.010Z,1752854724.010 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-07-18T16:05:24.010Z,1752854724.010 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-07-18T16:05:24.010Z,1752854724.010 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T16:05:24.386Z,1752854724.386 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-07-18T16:05:24.386Z,1752854724.386 [keepstation:SurfaceComms:B] Stopped 2025-07-18T16:05:24.387Z,1752854724.387 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-07-18T16:05:24.387Z,1752854724.387 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-07-18T16:05:24.387Z,1752854724.387 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-07-18T16:05:24.387Z,1752854724.387 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-07-18T16:05:24.784Z,1752854724.784 [keepstation:SurfaceComms:setTransit] Stopped 2025-07-18T16:05:24.784Z,1752854724.784 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-07-18T16:05:24.785Z,1752854724.785 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-07-18T16:05:24.785Z,1752854724.785 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-07-18T16:05:24.785Z,1752854724.785 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-07-18T16:05:24.785Z,1752854724.785 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-07-18T16:05:25.189Z,1752854725.189 [keepstation:SurfaceComms:setStation:A] Stopped 2025-07-18T16:05:25.189Z,1752854725.189 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation 2025-07-18T16:05:25.190Z,1752854725.190 [keepstation:SurfaceComms:setStation] Stopped 2025-07-18T16:05:25.190Z,1752854725.190 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-07-18T16:05:25.190Z,1752854725.190 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-07-18T16:05:25.194Z,1752854725.194 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-07-18T16:05:25.194Z,1752854725.194 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-07-18T16:05:25.578Z,1752854725.578 [keepstation:KeepStation:Dive] Running Loop=1 2025-07-18T16:05:25.582Z,1752854725.582 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-07-18T16:05:25.582Z,1752854725.582 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-07-18T16:05:25.582Z,1752854725.582 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-07-18T16:05:25.583Z,1752854725.583 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-07-18T16:05:25.583Z,1752854725.583 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-07-18T16:05:25.583Z,1752854725.583 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-07-18T16:05:25.583Z,1752854725.583 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-07-18T16:05:25.583Z,1752854725.583 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-07-18T16:05:25.583Z,1752854725.583 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-07-18T16:05:25.583Z,1752854725.583 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-07-18T16:05:25.584Z,1752854725.584 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Rest->Waypoint 2025-07-18T16:05:25.586Z,1752854725.586 [keepstation:SurfaceComms:setSink] Stopped 2025-07-18T16:05:25.610Z,1752854725.610 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-07-18T16:05:25.610Z,1752854725.610 [keepstation:SurfaceComms:setSink:A] Stopped 2025-07-18T16:05:25.610Z,1752854725.610 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-07-18T16:05:25.610Z,1752854725.610 [keepstation:SurfaceComms] Stopped 2025-07-18T16:05:25.610Z,1752854725.610 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-07-18T16:05:56.667Z,1752854756.667 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T16:06:27.618Z,1752854787.618 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:06:39.667Z,1752854799.667 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.239140 2025-07-18T16:06:51.170Z,1752854811.170 [Radio_Surface](INFO): Powering down 2025-07-18T16:06:51.715Z,1752854811.715 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-07-18T16:13:39.253Z,1752855219.253 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:13:40.070Z,1752855220.070 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:13:46.927Z,1752855226.927 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:13:54.204Z,1752855234.204 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:01.876Z,1752855241.876 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:09.551Z,1752855249.551 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:16.822Z,1752855256.822 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:25.307Z,1752855265.307 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:32.174Z,1752855272.174 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:40.659Z,1752855280.659 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:47.526Z,1752855287.526 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:14:56.010Z,1752855296.010 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:03.284Z,1752855303.284 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:11.364Z,1752855311.364 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:18.635Z,1752855318.635 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:27.118Z,1752855327.118 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:33.986Z,1752855333.986 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:42.472Z,1752855342.472 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:49.338Z,1752855349.338 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T16:15:58.226Z,1752855358.226 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T16:16:03.889Z,1752855363.889 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 5. 2025-07-18T16:16:03.900Z,1752855363.900 [BPC1](INFO): Received data from all battery sticks. 2025-07-18T16:23:15.784Z,1752855795.784 [keepstation:DiveCmd:StationKeep:C.KeepStation](INFO): Waypoint->Rest 2025-07-18T16:50:24.309Z,1752857424.309 [keepstation:SurfaceComms] Running Loop=1 2025-07-18T16:50:24.309Z,1752857424.309 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-07-18T16:50:24.309Z,1752857424.309 [keepstation:SurfaceComms:A] Running Loop=1 2025-07-18T16:50:24.309Z,1752857424.309 [keepstation:SurfaceComms:A] Stopped 2025-07-18T16:50:24.309Z,1752857424.309 [keepstation:SurfaceComms:B] Running Loop=1 2025-07-18T16:50:24.310Z,1752857424.310 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-07-18T16:50:24.717Z,1752857424.717 [keepstation:KeepStation:Dive] Stopped 2025-07-18T16:50:24.717Z,1752857424.717 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-07-18T16:50:24.717Z,1752857424.717 [keepstation:KeepStation:Dive:A] Stopped 2025-07-18T16:50:24.717Z,1752857424.717 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-07-18T16:50:24.718Z,1752857424.718 [keepstation:DiveCmd:StationKeep] Stopped 2025-07-18T16:50:24.718Z,1752857424.718 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-07-18T16:50:24.718Z,1752857424.718 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-07-18T16:50:24.718Z,1752857424.718 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-07-18T16:50:24.718Z,1752857424.718 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-07-18T16:50:24.718Z,1752857424.718 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-07-18T16:50:24.720Z,1752857424.720 [keepstation:NeedComms] Running Loop=1 2025-07-18T16:50:24.720Z,1752857424.720 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-07-18T16:50:24.720Z,1752857424.720 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-07-18T16:50:24.720Z,1752857424.720 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T16:50:24.720Z,1752857424.720 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-07-18T16:50:24.721Z,1752857424.721 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-07-18T16:50:24.721Z,1752857424.721 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-07-18T16:50:24.721Z,1752857424.721 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-07-18T16:50:24.722Z,1752857424.722 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T16:50:24.722Z,1752857424.722 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T16:50:24.723Z,1752857424.723 [keepstation:NeedComms:A] Running Loop=1 2025-07-18T16:50:24.724Z,1752857424.724 [keepstation:NeedComms:A](INFO): last time_fix was: 1752854723.000000 second since 1970/01/01T00:00:00Z 2025-07-18T16:50:24.724Z,1752857424.724 [keepstation:NeedComms:A] Stopped 2025-07-18T16:52:40.860Z,1752857560.860 [keepstation:NeedComms:C] Running Loop=1 2025-07-18T16:52:41.606Z,1752857561.606 [Radio_Surface](INFO): Powering up 2025-07-18T16:52:47.010Z,1752857567.010 [DataOverHttps](INFO): Radio surface powered ON. 2025-07-18T16:53:13.171Z,1752857593.171 [NAL9602](INFO): SBD MO Status=0, MOMSN=10189, MT Status=0, MTMSN=0 2025-07-18T16:53:13.171Z,1752857593.171 [NAL9602](INFO): No messages in MT queue 2025-07-18T16:53:14.385Z,1752857594.385 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165313.00,A,3647.79104,N,12150.88400,W,0.583,340.57,180725,,,D*76 2025-07-18T16:53:14.388Z,1752857594.388 [NAL9602](INFO): GPS fix at 20250718T165313: (36.796517, -121.848067) 2025-07-18T16:53:14.400Z,1752857594.400 [UniversalFixResidualReporter](INFO): Fix residual: 7.4 %DT, over the last 563.9 m. Residual distance 41.7 m at bearing -17.1 degrees. Fix at (36.7965, -121.8481) with 457.4 m made good. 2025-07-18T16:53:14.403Z,1752857594.403 [keepstation:NeedComms:C] Stopped 2025-07-18T16:53:14.403Z,1752857594.403 [keepstation:NeedComms:D] Running Loop=1 2025-07-18T16:53:17.130Z,1752857597.130 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:53:24.166Z,1752857604.166 [NAL9602](INFO): SBD MO Status=1, MOMSN=10190, MT Status=0, MTMSN=0 2025-07-18T16:53:24.218Z,1752857604.218 [NAL9602](INFO): Sent 218 bytes from file Logs/20250718T135352/Courier0028.lzma 2025-07-18T16:53:24.219Z,1752857604.219 [NAL9602](INFO): Packets left to send: 0 2025-07-18T16:53:37.182Z,1752857617.182 [NAL9602](INFO): SBD MO Status=1, MOMSN=10191, MT Status=0, MTMSN=0 2025-07-18T16:53:37.235Z,1752857617.235 [NAL9602](INFO): Sent 332 bytes from file Logs/20250718T135352/Express0029.lzma 2025-07-18T16:53:37.235Z,1752857617.235 [NAL9602](INFO): Packets left to send: 1 2025-07-18T16:53:48.993Z,1752857628.993 [NAL9602](INFO): SBD MO Status=1, MOMSN=10192, MT Status=0, MTMSN=0 2025-07-18T16:53:49.046Z,1752857629.046 [NAL9602](INFO): Sent 219 bytes from file Logs/20250718T135352/Express0029.lzma 2025-07-18T16:53:49.047Z,1752857629.047 [NAL9602](INFO): Packets left to send: 0 2025-07-18T16:53:52.286Z,1752857632.286 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:54:05.560Z,1752857645.560 [NAL9602](INFO): SBD MO Status=0, MOMSN=10193, MT Status=0, MTMSN=0 2025-07-18T16:54:05.648Z,1752857645.648 [keepstation:NeedComms:D] Stopped 2025-07-18T16:54:05.650Z,1752857645.650 [keepstation:NeedComms:E] Running Loop=1 2025-07-18T16:54:07.984Z,1752857647.984 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165407.00,A,3647.79749,N,12150.88706,W,0.311,328.86,180725,,,D*71 2025-07-18T16:54:07.987Z,1752857647.987 [NAL9602](INFO): GPS fix at 20250718T165407: (36.796625, -121.848118) 2025-07-18T16:54:07.999Z,1752857647.999 [keepstation:NeedComms:E] Stopped 2025-07-18T16:54:08.000Z,1752857648.000 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-07-18T16:54:08.000Z,1752857648.000 [keepstation:NeedComms] Stopped 2025-07-18T16:54:08.000Z,1752857648.000 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-07-18T16:54:08.001Z,1752857648.001 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-07-18T16:54:08.001Z,1752857648.001 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T16:54:08.416Z,1752857648.416 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-07-18T16:54:08.416Z,1752857648.416 [keepstation:SurfaceComms:B] Stopped 2025-07-18T16:54:08.416Z,1752857648.416 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-07-18T16:54:08.416Z,1752857648.416 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-07-18T16:54:08.416Z,1752857648.416 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-07-18T16:54:08.416Z,1752857648.416 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-07-18T16:54:08.820Z,1752857648.820 [keepstation:SurfaceComms:setTransit] Stopped 2025-07-18T16:54:08.820Z,1752857648.820 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-07-18T16:54:08.820Z,1752857648.820 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-07-18T16:54:08.820Z,1752857648.820 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-07-18T16:54:08.820Z,1752857648.820 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-07-18T16:54:08.820Z,1752857648.820 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-07-18T16:54:09.211Z,1752857649.211 [keepstation:SurfaceComms:setStation:A] Stopped 2025-07-18T16:54:09.211Z,1752857649.211 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation 2025-07-18T16:54:09.211Z,1752857649.211 [keepstation:SurfaceComms:setStation] Stopped 2025-07-18T16:54:09.211Z,1752857649.211 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-07-18T16:54:09.211Z,1752857649.211 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-07-18T16:54:09.211Z,1752857649.211 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-07-18T16:54:09.211Z,1752857649.211 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-07-18T16:54:09.608Z,1752857649.608 [keepstation:KeepStation:Dive] Running Loop=1 2025-07-18T16:54:09.608Z,1752857649.608 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-07-18T16:54:09.608Z,1752857649.608 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-07-18T16:54:09.608Z,1752857649.608 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-07-18T16:54:09.609Z,1752857649.609 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-07-18T16:54:09.609Z,1752857649.609 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-07-18T16:54:09.609Z,1752857649.609 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-07-18T16:54:09.609Z,1752857649.609 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-07-18T16:54:09.609Z,1752857649.609 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-07-18T16:54:09.609Z,1752857649.609 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-07-18T16:54:09.609Z,1752857649.609 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-07-18T16:54:09.611Z,1752857649.611 [keepstation:SurfaceComms:setSink] Stopped 2025-07-18T16:54:09.611Z,1752857649.611 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-07-18T16:54:09.611Z,1752857649.611 [keepstation:SurfaceComms:setSink:A] Stopped 2025-07-18T16:54:09.611Z,1752857649.611 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-07-18T16:54:09.612Z,1752857649.612 [keepstation:SurfaceComms] Stopped 2025-07-18T16:54:09.612Z,1752857649.612 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-07-18T16:54:27.426Z,1752857667.426 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:54:40.703Z,1752857680.703 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T16:55:02.587Z,1752857702.587 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:55:37.726Z,1752857737.726 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:56:12.867Z,1752857772.867 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T16:56:17.886Z,1752857777.886 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-07-18T16:56:18.182Z,1752857778.182 [Radio_Surface](INFO): Powering down 2025-07-18T17:05:42.951Z,1752858342.951 [DAT](INFO): DAT read: user:6>Rx Time:17:05:41.5339 2025-07-18T17:05:42.952Z,1752858342.952 [DAT](INFO): Rx dataTimestamp_ set to:1752858342.951438 2025-07-18T17:05:43.713Z,1752858343.713 [DAT](INFO): DAT read: 17:05:41.5339 LVL= 18160, 14993, 31538, 22899, AGC= 80, IDX= 11,-0.24,-2.607,-0.850,-1.371,-1.208, PHS=-1.414, 0.433,-0.115, RAW= 286.8, 13.3, CAL= 287.3, 22.6, ROT= 222.7, -22.6 2025-07-18T17:05:43.715Z,1752858343.715 [DAT](INFO): got valid direction response: 17:05:41.5339 LVL= 18160, 14993, 31538, 22899, AGC= 80, IDX= 11,-0.24,-2.607,-0.850,-1.371,-1.208, PHS=-1.414, 0.433,-0.115, RAW= 286.8, 13.3, CAL= 287.3, 22.6, ROT= 222.7, -22.6 2025-07-18T17:05:43.716Z,1752858343.716 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:05:43.716Z,1752858343.716 [DAT](INFO): Received a bad header 2025-07-18T17:05:43.730Z,1752858343.730 [DAT](INFO): #Rx 1: Read direction message, but no range. 2025-07-18T17:05:43.735Z,1752858343.735 [DAT](INFO): direction in FSK: [-0.678481,-0.626084,0.384295] 2025-07-18T17:06:43.207Z,1752858403.207 [DAT](INFO): DAT read: Rx Time:17:06:41.5743 2025-07-18T17:06:43.208Z,1752858403.208 [DAT](INFO): Rx dataTimestamp_ set to:1752858403.207282 2025-07-18T17:06:43.717Z,1752858403.717 [DAT](INFO): DAT read: 17:06:41.5743 LVL= 32752, 29265, 32754, 32755, AGC= 84, IDX= 394, 0.26, 2.468,-2.258,-2.923,-2.757, PHS=-1.074, 0.573,-0.119, RAW= 294.7, 8.7, CAL= 294.3, 15.4, ROT= 215.7, -15.4 2025-07-18T17:06:43.718Z,1752858403.718 [DAT](INFO): got valid direction response: 17:06:41.5743 LVL= 32752, 29265, 32754, 32755, AGC= 84, IDX= 394, 0.26, 2.468,-2.258,-2.923,-2.757, PHS=-1.074, 0.573,-0.119, RAW= 294.7, 8.7, CAL= 294.3, 15.4, ROT= 215.7, -15.4 2025-07-18T17:06:43.719Z,1752858403.719 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:06:43.719Z,1752858403.719 [DAT](INFO): Received a bad header 2025-07-18T17:06:43.730Z,1752858403.730 [DAT](INFO): #Rx 2: Read direction message, but no range. 2025-07-18T17:06:43.731Z,1752858403.731 [DAT](INFO): direction in FSK: [-0.782926,-0.562589,0.265556] 2025-07-18T17:06:44.719Z,1752858404.719 [DAT](INFO): DAT read: Rx Time:17:06:43.2098 2025-07-18T17:06:44.720Z,1752858404.720 [DAT](INFO): Rx dataTimestamp_ set to:1752858404.719396 2025-07-18T17:06:45.229Z,1752858405.229 [DAT](INFO): DAT read: 17:06:43.2098 LVL= 32752, 28657, 30066, 32755, AGC= 83, IDX= 337, 0.24,-3.134,-1.316,-2.132,-1.937, PHS=-1.214, 0.696,-0.148, RAW= 296.1, 8.1, CAL= 295.9, 14.0, ROT= 214.1, -14.0 2025-07-18T17:06:45.230Z,1752858405.230 [DAT](INFO): got valid direction response: 17:06:43.2098 LVL= 32752, 28657, 30066, 32755, AGC= 83, IDX= 337, 0.24,-3.134,-1.316,-2.132,-1.937, PHS=-1.214, 0.696,-0.148, RAW= 296.1, 8.1, CAL= 295.9, 14.0, ROT= 214.1, -14.0 2025-07-18T17:06:45.231Z,1752858405.231 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:06:45.231Z,1752858405.231 [DAT](INFO): Received a bad header 2025-07-18T17:06:45.242Z,1752858405.242 [DAT](INFO): #Rx 3: Read direction message, but no range. 2025-07-18T17:06:45.243Z,1752858405.243 [DAT](INFO): direction in FSK: [-0.803463,-0.543986,0.241922] 2025-07-18T17:07:43.463Z,1752858463.463 [DAT](INFO): DAT read: Rx Time:17:07:41.8643 2025-07-18T17:07:43.464Z,1752858463.464 [DAT](INFO): Rx dataTimestamp_ set to:1752858463.463290 2025-07-18T17:07:43.973Z,1752858463.973 [DAT](INFO): DAT read: 17:07:41.8643 LVL= 32752, 26785, 32114, 32755, AGC= 91, IDX= 29,-0.39, 0.493, 2.739, 1.522, 1.913, PHS=-1.436, 0.901,-0.343, RAW= 302.1, 8.7, CAL= 302.3, 13.9, ROT= 207.7, -13.9 2025-07-18T17:07:43.974Z,1752858463.974 [DAT](INFO): got valid direction response: 17:07:41.8643 LVL= 32752, 26785, 32114, 32755, AGC= 91, IDX= 29,-0.39, 0.493, 2.739, 1.522, 1.913, PHS=-1.436, 0.901,-0.343, RAW= 302.1, 8.7, CAL= 302.3, 13.9, ROT= 207.7, -13.9 2025-07-18T17:07:43.975Z,1752858463.975 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:07:43.975Z,1752858463.975 [DAT](INFO): Received a bad header 2025-07-18T17:07:43.986Z,1752858463.986 [DAT](INFO): #Rx 4: Read direction message, but no range. 2025-07-18T17:07:43.987Z,1752858463.987 [DAT](INFO): direction in FSK: [-0.859466,-0.451230,0.240228] 2025-07-18T17:08:43.495Z,1752858523.495 [DAT](INFO): DAT read: Rx Time:17:08:41.9142 2025-07-18T17:08:43.496Z,1752858523.496 [DAT](INFO): Rx dataTimestamp_ set to:1752858523.495386 2025-07-18T17:08:44.005Z,1752858524.005 [DAT](INFO): DAT read: 17:08:41.9142 LVL= 32752, 32753, 32754, 32755, AGC= 91, IDX= 488,-0.31,-1.944, 0.026,-1.169,-1.294, PHS=-0.666, 1.395, 0.173, RAW= 306.1, -10.1, CAL= 307.3, -10.8, ROT= 202.7, 10.8 2025-07-18T17:08:44.006Z,1752858524.006 [DAT](INFO): got valid direction response: 17:08:41.9142 LVL= 32752, 32753, 32754, 32755, AGC= 91, IDX= 488,-0.31,-1.944, 0.026,-1.169,-1.294, PHS=-0.666, 1.395, 0.173, RAW= 306.1, -10.1, CAL= 307.3, -10.8, ROT= 202.7, 10.8 2025-07-18T17:08:44.007Z,1752858524.007 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:08:44.007Z,1752858524.007 [DAT](INFO): Received a bad header 2025-07-18T17:08:44.018Z,1752858524.018 [DAT](INFO): #Rx 5: Read direction message, but no range. 2025-07-18T17:08:44.019Z,1752858524.019 [DAT](INFO): direction in FSK: [-0.906197,-0.379071,-0.187381] 2025-07-18T17:11:45.867Z,1752858705.867 [DAT](INFO): DAT read: Rx Time:17:11:44.3453 2025-07-18T17:11:45.868Z,1752858705.868 [DAT](INFO): Rx dataTimestamp_ set to:1752858705.867273 2025-07-18T17:11:46.378Z,1752858706.378 [DAT](INFO): DAT read: 17:11:44.3453 LVL= 32752, 27841, 32754, 32755, AGC= 88, IDX= 195,-0.25, 1.091, 2.530, 0.168, 1.144, PHS=-0.069, 1.461,-0.928, RAW= 350.8, -4.5, CAL= 350.8, -8.2, ROT= 159.2, 8.2 2025-07-18T17:11:46.379Z,1752858706.379 [DAT](INFO): got valid direction response: 17:11:44.3453 LVL= 32752, 27841, 32754, 32755, AGC= 88, IDX= 195,-0.25, 1.091, 2.530, 0.168, 1.144, PHS=-0.069, 1.461,-0.928, RAW= 350.8, -4.5, CAL= 350.8, -8.2, ROT= 159.2, 8.2 2025-07-18T17:11:46.380Z,1752858706.380 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:11:46.380Z,1752858706.380 [DAT](INFO): Received a bad header 2025-07-18T17:11:46.394Z,1752858706.394 [DAT](INFO): #Rx 6: Read direction message, but no range. 2025-07-18T17:11:46.395Z,1752858706.395 [DAT](INFO): direction in FSK: [-0.925268,0.351476,-0.142629] 2025-07-18T17:12:44.383Z,1752858764.383 [DAT](INFO): DAT read: Rx Time:17:12:42.9349 2025-07-18T17:12:44.384Z,1752858764.384 [DAT](INFO): Rx dataTimestamp_ set to:1752858764.383312 2025-07-18T17:12:45.145Z,1752858765.145 [DAT](INFO): DAT read: 17:12:42.9350 LVL= 32752, 26433, 32754, 32755, AGC= 82, IDX= 383, 0.06, 2.567, 2.877, 0.923, 2.587, PHS=-0.036, 0.365,-1.617, RAW= 19.0, 14.1, CAL= 18.0, 18.2, ROT= 132.0, -18.2 2025-07-18T17:12:45.146Z,1752858765.146 [DAT](INFO): got valid direction response: 17:12:42.9350 LVL= 32752, 26433, 32754, 32755, AGC= 82, IDX= 383, 0.06, 2.567, 2.877, 0.923, 2.587, PHS=-0.036, 0.365,-1.617, RAW= 19.0, 14.1, CAL= 18.0, 18.2, ROT= 132.0, -18.2 2025-07-18T17:12:45.147Z,1752858765.147 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:12:45.147Z,1752858765.147 [DAT](INFO): Received a bad header 2025-07-18T17:12:45.158Z,1752858765.158 [DAT](INFO): #Rx 7: Read direction message, but no range. 2025-07-18T17:12:45.159Z,1752858765.159 [DAT](INFO): direction in FSK: [-0.635655,0.705967,0.312335] 2025-07-18T17:12:46.147Z,1752858766.147 [DAT](INFO): DAT read: Rx Time:17:12:44.6009 2025-07-18T17:12:46.148Z,1752858766.148 [DAT](INFO): Rx dataTimestamp_ set to:1752858766.147299 2025-07-18T17:12:46.657Z,1752858766.657 [DAT](INFO): DAT read: 17:12:44.6009 LVL= 16752, 13873, 18642, 22195, AGC= 82, IDX= 89, 0.15, 2.480,-2.999, 1.238, 2.538, PHS=-0.075, 0.821,-1.252, RAW= 4.5, 5.7, CAL= 4.7, 3.2, ROT= 145.3, -3.2 2025-07-18T17:12:46.658Z,1752858766.658 [DAT](INFO): got valid direction response: 17:12:44.6009 LVL= 16752, 13873, 18642, 22195, AGC= 82, IDX= 89, 0.15, 2.480,-2.999, 1.238, 2.538, PHS=-0.075, 0.821,-1.252, RAW= 4.5, 5.7, CAL= 4.7, 3.2, ROT= 145.3, -3.2 2025-07-18T17:12:46.659Z,1752858766.659 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:12:46.659Z,1752858766.659 [DAT](INFO): Received a bad header 2025-07-18T17:12:46.670Z,1752858766.670 [DAT](INFO): #Rx 8: Read direction message, but no range. 2025-07-18T17:12:46.671Z,1752858766.671 [DAT](INFO): direction in FSK: [-0.820862,0.568392,0.055822] 2025-07-18T17:13:46.463Z,1752858826.463 [DAT](INFO): DAT read: Rx Time:17:13:44.8854 2025-07-18T17:13:46.464Z,1752858826.464 [DAT](INFO): Rx dataTimestamp_ set to:1752858826.463412 2025-07-18T17:13:46.973Z,1752858826.973 [DAT](INFO): DAT read: 17:13:44.8854 LVL= 21648, 17393, 28242, 30755, AGC= 83, IDX= 336,-0.41,-1.668,-1.571, 2.775,-2.043, PHS= 0.359, 0.547,-1.417, RAW= 25.0, 5.5, CAL= 25.0, 3.4, ROT= 125.0, -3.4 2025-07-18T17:13:46.974Z,1752858826.974 [DAT](INFO): got valid direction response: 17:13:44.8854 LVL= 21648, 17393, 28242, 30755, AGC= 83, IDX= 336,-0.41,-1.668,-1.571, 2.775,-2.043, PHS= 0.359, 0.547,-1.417, RAW= 25.0, 5.5, CAL= 25.0, 3.4, ROT= 125.0, -3.4 2025-07-18T17:13:46.975Z,1752858826.975 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:13:46.975Z,1752858826.975 [DAT](INFO): Received a bad header 2025-07-18T17:13:46.986Z,1752858826.986 [DAT](INFO): #Rx 9: Read direction message, but no range. 2025-07-18T17:13:46.987Z,1752858826.987 [DAT](INFO): direction in FSK: [-0.572567,0.817710,0.059306] 2025-07-18T17:14:46.743Z,1752858886.743 [DAT](INFO): DAT read: Rx Time:17:14:45.1140 2025-07-18T17:14:46.744Z,1752858886.744 [DAT](INFO): Rx dataTimestamp_ set to:1752858886.743361 2025-07-18T17:14:47.253Z,1752858887.253 [DAT](INFO): DAT read: 17:14:45.1140 LVL= 23184, 20529, 28626, 25523, AGC= 82, IDX= 274, 0.39,-2.347,-3.074, 1.546,-2.863, PHS= 0.501,-0.136,-1.826, RAW= 45.3, 13.9, CAL= 42.0, 18.0, ROT= 108.0, -18.0 2025-07-18T17:14:47.255Z,1752858887.255 [DAT](INFO): got valid direction response: 17:14:45.1140 LVL= 23184, 20529, 28626, 25523, AGC= 82, IDX= 274, 0.39,-2.347,-3.074, 1.546,-2.863, PHS= 0.501,-0.136,-1.826, RAW= 45.3, 13.9, CAL= 42.0, 18.0, ROT= 108.0, -18.0 2025-07-18T17:14:47.256Z,1752858887.256 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:14:47.256Z,1752858887.256 [DAT](INFO): Received a bad header 2025-07-18T17:14:47.270Z,1752858887.270 [DAT](INFO): #Rx 10: Read direction message, but no range. 2025-07-18T17:14:47.271Z,1752858887.271 [DAT](INFO): direction in FSK: [-0.293893,0.904508,0.309017] 2025-07-18T17:15:47.015Z,1752858947.015 [DAT](INFO): DAT read: Rx Time:17:15:45.4146 2025-07-18T17:15:47.016Z,1752858947.016 [DAT](INFO): Rx dataTimestamp_ set to:1752858947.015386 2025-07-18T17:15:47.519Z,1752858947.519 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:15:47.519Z,1752858947.519 [DAT](INFO): Received a bad header 2025-07-18T17:16:45.511Z,1752859005.511 [DAT](INFO): DAT read: Rx Time:17:16:44.0083 2025-07-18T17:16:45.512Z,1752859005.512 [DAT](INFO): Rx dataTimestamp_ set to:1752859005.511340 2025-07-18T17:16:46.025Z,1752859006.025 [DAT](INFO): DAT read: 17:16:44.0083 LVL= 22432, 22625, 25970, 28963, AGC= 82, IDX= 417, 0.09, 2.142, 0.696,-0.079, 1.141, PHS= 0.985,-0.371,-1.172, RAW= 68.4, 6.0, CAL= 67.9, 8.2, ROT= 82.1, -8.2 2025-07-18T17:16:46.026Z,1752859006.026 [DAT](INFO): got valid direction response: 17:16:44.0083 LVL= 22432, 22625, 25970, 28963, AGC= 82, IDX= 417, 0.09, 2.142, 0.696,-0.079, 1.141, PHS= 0.985,-0.371,-1.172, RAW= 68.4, 6.0, CAL= 67.9, 8.2, ROT= 82.1, -8.2 2025-07-18T17:16:46.027Z,1752859006.027 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:16:46.027Z,1752859006.027 [DAT](INFO): Received a bad header 2025-07-18T17:16:46.040Z,1752859006.040 [DAT](INFO): #Rx 11: Read direction message, but no range. 2025-07-18T17:16:46.041Z,1752859006.041 [DAT](INFO): direction in FSK: [0.136039,0.980383,0.142629] 2025-07-18T17:18:46.083Z,1752859126.083 [DAT](INFO): DAT read: Rx Time:17:18:44.5139 2025-07-18T17:18:46.084Z,1752859126.084 [DAT](INFO): Rx dataTimestamp_ set to:1752859126.083310 2025-07-18T17:18:46.593Z,1752859126.593 [DAT](INFO): DAT read: 17:18:44.5139 LVL= 21648, 19953, 24754, 22003, AGC= 84, IDX= 38,-0.48,-0.200,-2.111,-2.257,-1.359, PHS= 1.143,-0.677,-0.850, RAW= 85.5, 4.1, CAL= 85.6, 2.6, ROT= 64.4, -2.6 2025-07-18T17:18:46.594Z,1752859126.594 [DAT](INFO): got valid direction response: 17:18:44.5139 LVL= 21648, 19953, 24754, 22003, AGC= 84, IDX= 38,-0.48,-0.200,-2.111,-2.257,-1.359, PHS= 1.143,-0.677,-0.850, RAW= 85.5, 4.1, CAL= 85.6, 2.6, ROT= 64.4, -2.6 2025-07-18T17:18:46.595Z,1752859126.595 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:18:46.595Z,1752859126.595 [DAT](INFO): Received a bad header 2025-07-18T17:18:46.606Z,1752859126.606 [DAT](INFO): #Rx 12: Read direction message, but no range. 2025-07-18T17:18:46.607Z,1752859126.607 [DAT](INFO): direction in FSK: [0.431641,0.900904,0.045363] 2025-07-18T17:19:46.351Z,1752859186.351 [DAT](INFO): DAT read: Rx Time:17:19:44.8020 2025-07-18T17:19:46.352Z,1752859186.352 [DAT](INFO): Rx dataTimestamp_ set to:1752859186.351292 2025-07-18T17:19:46.861Z,1752859186.861 [DAT](INFO): DAT read: 17:19:44.8020 LVL= 32752, 32753, 32754, 32755, AGC= 82, IDX= 359, 0.44, 1.948,-0.200, 0.347, 1.051, PHS= 0.881,-1.176,-0.657, RAW= 104.1, 10.3, CAL= 106.3, 13.6, ROT= 43.7, -13.6 2025-07-18T17:19:46.871Z,1752859186.871 [DAT](INFO): got valid direction response: 17:19:44.8020 LVL= 32752, 32753, 32754, 32755, AGC= 82, IDX= 359, 0.44, 1.948,-0.200, 0.347, 1.051, PHS= 0.881,-1.176,-0.657, RAW= 104.1, 10.3, CAL= 106.3, 13.6, ROT= 43.7, -13.6 2025-07-18T17:19:46.872Z,1752859186.872 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:19:46.872Z,1752859186.872 [DAT](INFO): Received a bad header 2025-07-18T17:19:46.887Z,1752859186.887 [DAT](INFO): #Rx 13: Read direction message, but no range. 2025-07-18T17:19:46.888Z,1752859186.888 [DAT](INFO): direction in FSK: [0.702696,0.671511,0.235142] 2025-07-18T17:19:48.371Z,1752859188.371 [DAT](INFO): DAT read: Rx Time:17:19:46.9124 2025-07-18T17:19:48.372Z,1752859188.372 [DAT](INFO): Rx dataTimestamp_ set to:1752859188.371216 2025-07-18T17:19:49.132Z,1752859189.132 [DAT](INFO): DAT read: 17:19:46.9124 LVL= 20208, 21121, 20338, 24339, AGC= 86, IDX= 81, 0.31, 0.219,-1.652,-1.311,-0.758, PHS= 0.961,-0.819,-0.505, RAW= 99.5, 4.5, CAL= 101.1, 5.2, ROT= 48.9, -5.2 2025-07-18T17:19:49.133Z,1752859189.133 [DAT](INFO): got valid direction response: 17:19:46.9124 LVL= 20208, 21121, 20338, 24339, AGC= 86, IDX= 81, 0.31, 0.219,-1.652,-1.311,-0.758, PHS= 0.961,-0.819,-0.505, RAW= 99.5, 4.5, CAL= 101.1, 5.2, ROT= 48.9, -5.2 2025-07-18T17:19:49.133Z,1752859189.133 [DAT](INFO): DAT read: 2025-07-18T17:19:49.134Z,1752859189.134 [DAT](INFO): DAT read: $Packet for address 11 2025-07-18T17:19:49.134Z,1752859189.134 [DAT](INFO): received a packet notification 2025-07-18T17:19:49.146Z,1752859189.146 [DAT](INFO): #Rx 14: Read direction message, but no range. 2025-07-18T17:19:49.147Z,1752859189.147 [DAT](INFO): direction in FSK: [0.654670,0.750462,0.090633] 2025-07-18T17:20:46.639Z,1752859246.639 [DAT](INFO): DAT read: Rx Time:17:20:45.0459 2025-07-18T17:20:46.640Z,1752859246.640 [DAT](INFO): Rx dataTimestamp_ set to:1752859246.639476 2025-07-18T17:20:47.149Z,1752859247.149 [DAT](INFO): DAT read: 17:20:45.0459 LVL= 32752, 32753, 32754, 32755, AGC= 86, IDX= 309,-0.28, 2.367, 0.241, 1.282, 1.613, PHS= 0.738,-1.297,-0.283, RAW= 119.9, 9.6, CAL= 121.8, 11.8, ROT= 28.2, -11.8 2025-07-18T17:20:47.150Z,1752859247.150 [DAT](INFO): got valid direction response: 17:20:45.0459 LVL= 32752, 32753, 32754, 32755, AGC= 86, IDX= 309,-0.28, 2.367, 0.241, 1.282, 1.613, PHS= 0.738,-1.297,-0.283, RAW= 119.9, 9.6, CAL= 121.8, 11.8, ROT= 28.2, -11.8 2025-07-18T17:20:47.151Z,1752859247.151 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:20:47.151Z,1752859247.151 [DAT](INFO): Received a bad header 2025-07-18T17:20:47.162Z,1752859247.162 [DAT](INFO): #Rx 15: Read direction message, but no range. 2025-07-18T17:20:47.163Z,1752859247.163 [DAT](INFO): direction in FSK: [0.862679,0.462565,0.204496] 2025-07-18T17:20:59.536Z,1752859259.536 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:03.978Z,1752859263.978 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:05.000Z,1752859266.000 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:20.138Z,1752859280.138 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:21.350Z,1752859281.350 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:35.492Z,1752859295.492 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:36.297Z,1752859296.297 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:49.167Z,1752859309.167 [DAT](INFO): DAT read: Rx Time:17:21:47.5661 2025-07-18T17:21:49.168Z,1752859309.168 [DAT](INFO): Rx dataTimestamp_ set to:1752859309.167255 2025-07-18T17:21:49.677Z,1752859309.677 [DAT](INFO): DAT read: 17:21:47.5661 LVL= 32752, 31505, 30914, 32755, AGC= 91, IDX= 61,-0.03, 2.635, 2.482, 1.938, 1.207, PHS= 1.412, 1.350, 0.779, RAW= 35.1, -64.2, CAL= 37.6, -64.2, ROT= 112.4, 64.2 2025-07-18T17:21:49.679Z,1752859309.679 [DAT](INFO): got valid direction response: 17:21:47.5661 LVL= 32752, 31505, 30914, 32755, AGC= 91, IDX= 61,-0.03, 2.635, 2.482, 1.938, 1.207, PHS= 1.412, 1.350, 0.779, RAW= 35.1, -64.2, CAL= 37.6, -64.2, ROT= 112.4, 64.2 2025-07-18T17:21:49.680Z,1752859309.680 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:21:49.680Z,1752859309.680 [DAT](INFO): Received a bad header 2025-07-18T17:21:49.694Z,1752859309.694 [DAT](INFO): #Rx 16: Read direction message, but no range. 2025-07-18T17:21:49.695Z,1752859309.695 [DAT](INFO): direction in FSK: [-0.165854,0.402391,-0.900319] 2025-07-18T17:21:51.250Z,1752859311.250 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:21:51.257Z,1752859311.257 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:06.196Z,1752859326.196 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:06.616Z,1752859326.616 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:21.546Z,1752859341.546 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:21.552Z,1752859341.552 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:36.897Z,1752859356.897 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:36.904Z,1752859356.904 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:51.893Z,1752859371.893 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:22:52.251Z,1752859372.251 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:23:06.794Z,1752859386.794 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:23:07.602Z,1752859387.602 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-07-18T17:23:22.146Z,1752859402.146 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7). 2025-07-18T17:23:22.151Z,1752859402.151 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-07-18T17:23:22.158Z,1752859402.158 [BPC1](INFO): Calculating totals. Valid battery stick count: 48. Valid reserve battery stick count: 5. 2025-07-18T17:23:22.160Z,1752859402.160 [BPC1](INFO): Received data from all battery sticks. 2025-07-18T17:23:49.755Z,1752859429.755 [DAT](INFO): DAT read: Rx Time:17:23:48.2103 2025-07-18T17:23:49.756Z,1752859429.756 [DAT](INFO): Rx dataTimestamp_ set to:1752859429.755379 2025-07-18T17:23:50.265Z,1752859430.265 [DAT](INFO): DAT read: 17:23:48.2103 LVL= 32752, 32753, 32754, 32755, AGC= 88, IDX= 441,-0.29,-1.958, 3.100,-1.767,-2.337, PHS= 0.363,-0.771, 0.618, RAW= 159.9, -3.3, CAL= 160.3, -3.7, ROT= 349.7, 3.7 2025-07-18T17:23:50.266Z,1752859430.266 [DAT](INFO): got valid direction response: 17:23:48.2103 LVL= 32752, 32753, 32754, 32755, AGC= 88, IDX= 441,-0.29,-1.958, 3.100,-1.767,-2.337, PHS= 0.363,-0.771, 0.618, RAW= 159.9, -3.3, CAL= 160.3, -3.7, ROT= 349.7, 3.7 2025-07-18T17:23:50.267Z,1752859430.267 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:23:50.267Z,1752859430.267 [DAT](INFO): Received a bad header 2025-07-18T17:23:50.278Z,1752859430.278 [DAT](INFO): #Rx 17: Read direction message, but no range. 2025-07-18T17:23:50.279Z,1752859430.279 [DAT](INFO): direction in FSK: [0.981834,-0.178429,-0.064532] 2025-07-18T17:24:48.027Z,1752859488.027 [DAT](INFO): DAT read: Rx Time:17:24:46.3789 2025-07-18T17:24:48.028Z,1752859488.028 [DAT](INFO): Rx dataTimestamp_ set to:1752859488.027306 2025-07-18T17:24:48.536Z,1752859488.536 [DAT](INFO): DAT read: 17:24:46.3789 LVL= 17392, 17649, 19522, 19699, AGC= 81, IDX= 170, 0.24, 0.278,-0.674, 1.420, 0.469, PHS=-0.207,-1.069, 0.999, RAW= 185.5, 3.1, CAL= 187.0, 3.8, ROT= 323.0, -3.8 2025-07-18T17:24:48.537Z,1752859488.537 [DAT](INFO): got valid direction response: 17:24:46.3789 LVL= 17392, 17649, 19522, 19699, AGC= 81, IDX= 170, 0.24, 0.278,-0.674, 1.420, 0.469, PHS=-0.207,-1.069, 0.999, RAW= 185.5, 3.1, CAL= 187.0, 3.8, ROT= 323.0, -3.8 2025-07-18T17:24:48.537Z,1752859488.537 [DAT](INFO): DAT read: 2025-07-18T17:24:48.538Z,1752859488.538 [DAT](INFO): DAT read: $Packet for address 21 2025-07-18T17:24:48.538Z,1752859488.538 [DAT](INFO): received a packet notification 2025-07-18T17:24:48.550Z,1752859488.550 [DAT](INFO): #Rx 18: Read direction message, but no range. 2025-07-18T17:24:48.551Z,1752859488.551 [DAT](INFO): direction in FSK: [0.796880,-0.600492,0.066274] 2025-07-18T17:25:48.043Z,1752859548.043 [DAT](INFO): DAT read: Rx Time:17:25:46.3928 2025-07-18T17:25:48.044Z,1752859548.044 [DAT](INFO): Rx dataTimestamp_ set to:1752859548.043558 2025-07-18T17:25:48.552Z,1752859548.552 [DAT](INFO): DAT read: 17:25:46.3928 LVL= 32752, 32753, 28722, 32755, AGC= 83, IDX= 102, 0.26,-0.355,-0.949, 0.926, 0.133, PHS=-0.504,-1.007, 0.841, RAW= 194.7, 8.2, CAL= 195.6, 10.9, ROT= 314.4, -10.9 2025-07-18T17:25:48.553Z,1752859548.553 [DAT](INFO): got valid direction response: 17:25:46.3928 LVL= 32752, 32753, 28722, 32755, AGC= 83, IDX= 102, 0.26,-0.355,-0.949, 0.926, 0.133, PHS=-0.504,-1.007, 0.841, RAW= 194.7, 8.2, CAL= 195.6, 10.9, ROT= 314.4, -10.9 2025-07-18T17:25:48.553Z,1752859548.553 [DAT](INFO): DAT read: 2025-07-18T17:25:48.554Z,1752859548.554 [DAT](INFO): DAT read: $Packet for address 21 2025-07-18T17:25:48.554Z,1752859548.554 [DAT](INFO): received a packet notification 2025-07-18T17:25:48.566Z,1752859548.566 [DAT](INFO): #Rx 19: Read direction message, but no range. 2025-07-18T17:25:48.567Z,1752859548.567 [DAT](INFO): direction in FSK: [0.687041,-0.701583,0.189095] 2025-07-18T17:25:50.059Z,1752859550.059 [DAT](INFO): DAT read: Rx Time:17:25:48.5029 2025-07-18T17:25:50.060Z,1752859550.060 [DAT](INFO): Rx dataTimestamp_ set to:1752859550.059427 2025-07-18T17:25:50.569Z,1752859550.569 [DAT](INFO): DAT read: 17:25:48.5029 LVL= 32752, 32753, 32242, 32755, AGC= 90, IDX= 45, 0.26,-1.483,-1.778,-0.341,-1.325, PHS=-0.174,-0.377, 1.032, RAW= 202.3, -7.3, CAL= 204.0, -5.3, ROT= 306.0, 5.3 2025-07-18T17:25:50.571Z,1752859550.571 [DAT](INFO): got valid direction response: 17:25:48.5029 LVL= 32752, 32753, 32242, 32755, AGC= 90, IDX= 45, 0.26,-1.483,-1.778,-0.341,-1.325, PHS=-0.174,-0.377, 1.032, RAW= 202.3, -7.3, CAL= 204.0, -5.3, ROT= 306.0, 5.3 2025-07-18T17:25:50.572Z,1752859550.572 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:25:50.572Z,1752859550.572 [DAT](INFO): Received a bad header 2025-07-18T17:25:50.586Z,1752859550.586 [DAT](INFO): #Rx 20: Read direction message, but no range. 2025-07-18T17:25:50.588Z,1752859550.588 [DAT](INFO): direction in FSK: [0.585272,-0.805558,-0.092371] 2025-07-18T17:26:48.311Z,1752859608.311 [DAT](INFO): DAT read: Rx Time:17:26:46.6603 2025-07-18T17:26:48.312Z,1752859608.312 [DAT](INFO): Rx dataTimestamp_ set to:1752859608.311261 2025-07-18T17:26:48.820Z,1752859608.820 [DAT](INFO): DAT read: 17:26:46.6603 LVL= 32752, 32753, 28434, 32755, AGC= 83, IDX= 54,-0.42, 2.287, 1.748,-2.596, 2.993, PHS=-0.722,-1.171, 0.742, RAW= 197.0, 13.2, CAL= 197.3, 17.5, ROT= 312.7, -17.5 2025-07-18T17:26:48.821Z,1752859608.821 [DAT](INFO): got valid direction response: 17:26:46.6603 LVL= 32752, 32753, 28434, 32755, AGC= 83, IDX= 54,-0.42, 2.287, 1.748,-2.596, 2.993, PHS=-0.722,-1.171, 0.742, RAW= 197.0, 13.2, CAL= 197.3, 17.5, ROT= 312.7, -17.5 2025-07-18T17:26:48.821Z,1752859608.821 [DAT](INFO): DAT read: 2025-07-18T17:26:48.822Z,1752859608.822 [DAT](INFO): DAT read: $Packet for address 21 2025-07-18T17:26:48.822Z,1752859608.822 [DAT](INFO): received a packet notification 2025-07-18T17:26:48.834Z,1752859608.834 [DAT](INFO): #Rx 21: Read direction message, but no range. 2025-07-18T17:26:48.835Z,1752859608.835 [DAT](INFO): direction in FSK: [0.646773,-0.700900,0.300706] 2025-07-18T17:27:48.601Z,1752859668.601 [DAT](INFO): DAT read: 17:27:46.8966 LVL= 32752, 32753, 32754, 32755, AGC= 73, IDX= 329,-0.06, 0.764, 0.729, 2.346, 1.588, PHS=-0.841,-0.784, 0.806, RAW= 211.7, 10.1, CAL= 213.1, 13.6, ROT= 296.9, -13.6 2025-07-18T17:27:48.602Z,1752859668.602 [DAT](INFO): got valid direction response: 17:27:46.8966 LVL= 32752, 32753, 32754, 32755, AGC= 73, IDX= 329,-0.06, 0.764, 0.729, 2.346, 1.588, PHS=-0.841,-0.784, 0.806, RAW= 211.7, 10.1, CAL= 213.1, 13.6, ROT= 296.9, -13.6 2025-07-18T17:27:48.603Z,1752859668.603 [DAT](INFO): DAT read: Rx Time:17:27:46.8966 2025-07-18T17:27:48.603Z,1752859668.603 [DAT](INFO): Rx dataTimestamp_ set to:1752859668.602774 2025-07-18T17:27:48.604Z,1752859668.604 [DAT](INFO): DAT read: $Low SNR acquisition 2025-07-18T17:27:48.604Z,1752859668.604 [DAT](INFO): Received low SNR in chirp 2025-07-18T17:27:48.618Z,1752859668.618 [DAT](INFO): #Rx 22: Read direction message, but no range. 2025-07-18T17:27:48.619Z,1752859668.619 [DAT](INFO): direction in FSK: [0.439749,-0.866792,0.235142] 2025-07-18T17:28:48.847Z,1752859728.847 [DAT](INFO): DAT read: Rx Time:17:28:47.1740 2025-07-18T17:28:48.847Z,1752859728.847 [DAT](INFO): Rx dataTimestamp_ set to:1752859728.847192 2025-07-18T17:28:49.356Z,1752859729.356 [DAT](INFO): DAT read: 17:28:47.1740 LVL= 32752, 30641, 22226, 32755, AGC= 81, IDX= 234,-0.01,-0.236, 0.298, 1.801, 0.853, PHS=-1.105,-0.480, 0.996, RAW= 226.8, 6.4, CAL= 227.2, 10.1, ROT= 282.8, -10.1 2025-07-18T17:28:49.357Z,1752859729.357 [DAT](INFO): got valid direction response: 17:28:47.1740 LVL= 32752, 30641, 22226, 32755, AGC= 81, IDX= 234,-0.01,-0.236, 0.298, 1.801, 0.853, PHS=-1.105,-0.480, 0.996, RAW= 226.8, 6.4, CAL= 227.2, 10.1, ROT= 282.8, -10.1 2025-07-18T17:28:49.358Z,1752859729.358 [DAT](INFO): DAT read: 2025-07-18T17:28:49.369Z,1752859729.369 [DAT](INFO): DAT read: $Packet for address 21 2025-07-18T17:28:49.369Z,1752859729.369 [DAT](INFO): received a packet notification 2025-07-18T17:28:49.387Z,1752859729.387 [DAT](INFO): #Rx 23: Read direction message, but no range. 2025-07-18T17:28:49.388Z,1752859729.388 [DAT](INFO): direction in FSK: [0.218115,-0.960038,0.175367] 2025-07-18T17:29:48.903Z,1752859788.903 [DAT](INFO): DAT read: Rx Time:17:29:47.4215 2025-07-18T17:29:48.904Z,1752859788.904 [DAT](INFO): Rx dataTimestamp_ set to:1752859788.903340 2025-07-18T17:29:49.664Z,1752859789.664 [DAT](INFO): DAT read: 17:29:47.4215 LVL= 29664, 24641, 18162, 26339, AGC= 75, IDX= 445, 0.42,-1.299,-0.295, 0.897,-0.152, PHS=-1.162,-0.067, 1.098, RAW= 239.0, 1.4, CAL= 237.0, 5.2, ROT= 273.0, -5.2 2025-07-18T17:29:49.665Z,1752859789.665 [DAT](INFO): got valid direction response: 17:29:47.4215 LVL= 29664, 24641, 18162, 26339, AGC= 75, IDX= 445, 0.42,-1.299,-0.295, 0.897,-0.152, PHS=-1.162,-0.067, 1.098, RAW= 239.0, 1.4, CAL= 237.0, 5.2, ROT= 273.0, -5.2 2025-07-18T17:29:49.665Z,1752859789.665 [DAT](INFO): DAT read: 2025-07-18T17:29:49.667Z,1752859789.667 [DAT](INFO): DAT read: $Packet for address 21 2025-07-18T17:29:49.667Z,1752859789.667 [DAT](INFO): received a packet notification 2025-07-18T17:29:49.679Z,1752859789.679 [DAT](INFO): #Rx 24: Read direction message, but no range. 2025-07-18T17:29:49.680Z,1752859789.680 [DAT](INFO): direction in FSK: [0.052121,-0.994520,0.090633] 2025-07-18T17:30:49.405Z,1752859849.405 [DAT](INFO): DAT read: Rx Time:17:30:47.7409 2025-07-18T17:30:49.405Z,1752859849.405 [DAT](INFO): Rx dataTimestamp_ set to:1752859849.405140 2025-07-18T17:30:49.913Z,1752859849.913 [DAT](INFO): DAT read: 17:30:47.7409 LVL= 24480, 19041, 17986, 22291, AGC= 85, IDX= 144,-0.20,-1.522,-0.506, 0.635,-0.434, PHS=-1.104, 0.003, 1.117, RAW= 239.9, -0.2, CAL= 237.3, 3.7, ROT= 272.7, -3.7 2025-07-18T17:30:49.914Z,1752859849.914 [DAT](INFO): got valid direction response: 17:30:47.7409 LVL= 24480, 19041, 17986, 22291, AGC= 85, IDX= 144,-0.20,-1.522,-0.506, 0.635,-0.434, PHS=-1.104, 0.003, 1.117, RAW= 239.9, -0.2, CAL= 237.3, 3.7, ROT= 272.7, -3.7 2025-07-18T17:30:49.915Z,1752859849.915 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:30:49.915Z,1752859849.915 [DAT](INFO): Received a bad header 2025-07-18T17:30:49.926Z,1752859849.926 [DAT](INFO): #Rx 25: Read direction message, but no range. 2025-07-18T17:30:49.927Z,1752859849.927 [DAT](INFO): direction in FSK: [0.047008,-0.996808,0.064532] 2025-07-18T17:31:49.439Z,1752859909.439 [DAT](INFO): DAT read: Rx Time:17:31:47.9964 2025-07-18T17:31:49.440Z,1752859909.440 [DAT](INFO): Rx dataTimestamp_ set to:1752859909.439350 2025-07-18T17:31:50.201Z,1752859910.201 [DAT](INFO): DAT read: 17:31:47.9964 LVL= 22128, 14289, 12530, 19571, AGC= 81, IDX= 21, 0.49,-0.351, 0.884, 1.733, 0.895, PHS=-1.262, 0.064, 0.886, RAW= 247.7, 3.4, CAL= 246.2, 6.7, ROT= 263.8, -6.7 2025-07-18T17:31:50.202Z,1752859910.202 [DAT](INFO): got valid direction response: 17:31:47.9964 LVL= 22128, 14289, 12530, 19571, AGC= 81, IDX= 21, 0.49,-0.351, 0.884, 1.733, 0.895, PHS=-1.262, 0.064, 0.886, RAW= 247.7, 3.4, CAL= 246.2, 6.7, ROT= 263.8, -6.7 2025-07-18T17:31:50.203Z,1752859910.203 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:31:50.203Z,1752859910.203 [DAT](INFO): Received a bad header 2025-07-18T17:31:50.214Z,1752859910.214 [DAT](INFO): #Rx 26: Read direction message, but no range. 2025-07-18T17:31:50.215Z,1752859910.215 [DAT](INFO): direction in FSK: [-0.107262,-0.987362,0.116671] 2025-07-18T17:32:49.947Z,1752859969.947 [DAT](INFO): DAT read: Rx Time:17:32:48.2769 2025-07-18T17:32:49.948Z,1752859969.948 [DAT](INFO): Rx dataTimestamp_ set to:1752859969.947268 2025-07-18T17:32:50.456Z,1752859970.456 [DAT](INFO): DAT read: 17:32:48.2769 LVL= 32752, 22609, 19186, 32435, AGC= 79, IDX= 282,-0.25,-1.931,-0.573, 0.202,-0.694, PHS=-1.254, 0.196, 0.944, RAW= 250.4, 1.2, CAL= 247.9, 4.1, ROT= 262.1, -4.1 2025-07-18T17:32:50.457Z,1752859970.457 [DAT](INFO): got valid direction response: 17:32:48.2769 LVL= 32752, 22609, 19186, 32435, AGC= 79, IDX= 282,-0.25,-1.931,-0.573, 0.202,-0.694, PHS=-1.254, 0.196, 0.944, RAW= 250.4, 1.2, CAL= 247.9, 4.1, ROT= 262.1, -4.1 2025-07-18T17:32:50.457Z,1752859970.457 [DAT](INFO): DAT read: 2025-07-18T17:32:50.458Z,1752859970.458 [DAT](INFO): DAT read: $Packet for address 21 2025-07-18T17:32:50.458Z,1752859970.458 [DAT](INFO): received a packet notification 2025-07-18T17:32:50.470Z,1752859970.470 [DAT](INFO): #Rx 27: Read direction message, but no range. 2025-07-18T17:32:50.471Z,1752859970.471 [DAT](INFO): direction in FSK: [-0.137093,-0.987975,0.071497] 2025-07-18T17:32:51.963Z,1752859971.963 [DAT](INFO): DAT read: Rx Time:17:32:50.3829 2025-07-18T17:32:51.964Z,1752859971.964 [DAT](INFO): Rx dataTimestamp_ set to:1752859971.963236 2025-07-18T17:32:52.472Z,1752859972.472 [DAT](INFO): DAT read: 17:32:50.3829 LVL= 23856, 20785, 16226, 24051, AGC= 85, IDX= 23,-0.32,-1.179, 0.146, 0.779, 0.563, PHS=-1.758,-0.342, 0.264, RAW= 253.0, 19.9, CAL= 256.4, 27.5, ROT= 253.6, -27.5 2025-07-18T17:32:52.473Z,1752859972.473 [DAT](INFO): got valid direction response: 17:32:50.3829 LVL= 23856, 20785, 16226, 24051, AGC= 85, IDX= 23,-0.32,-1.179, 0.146, 0.779, 0.563, PHS=-1.758,-0.342, 0.264, RAW= 253.0, 19.9, CAL= 256.4, 27.5, ROT= 253.6, -27.5 2025-07-18T17:32:52.473Z,1752859972.473 [DAT](INFO): DAT read: 2025-07-18T17:32:52.474Z,1752859972.474 [DAT](INFO): DAT read: $Packet for address 11 2025-07-18T17:32:52.474Z,1752859972.474 [DAT](INFO): received a packet notification 2025-07-18T17:32:52.486Z,1752859972.486 [DAT](INFO): #Rx 28: Read direction message, but no range. 2025-07-18T17:32:52.487Z,1752859972.487 [DAT](INFO): direction in FSK: [-0.250440,-0.850922,0.461749] 2025-07-18T17:33:50.207Z,1752860030.207 [DAT](INFO): DAT read: Rx Time:17:33:48.5215 2025-07-18T17:33:50.208Z,1752860030.208 [DAT](INFO): Rx dataTimestamp_ set to:1752860030.207313 2025-07-18T17:33:50.716Z,1752860030.716 [DAT](INFO): DAT read: 17:33:48.5215 LVL= 29120, 19521, 28178, 28563, AGC= 75, IDX= 352,-0.20,-0.425, 1.035, 1.305, 0.819, PHS=-1.261, 0.291, 0.534, RAW= 262.8, 5.2, CAL= 262.8, 8.2, ROT= 247.2, -8.2 2025-07-18T17:33:50.717Z,1752860030.717 [DAT](INFO): got valid direction response: 17:33:48.5215 LVL= 29120, 19521, 28178, 28563, AGC= 75, IDX= 352,-0.20,-0.425, 1.035, 1.305, 0.819, PHS=-1.261, 0.291, 0.534, RAW= 262.8, 5.2, CAL= 262.8, 8.2, ROT= 247.2, -8.2 2025-07-18T17:33:50.717Z,1752860030.717 [DAT](INFO): DAT read: 2025-07-18T17:33:50.718Z,1752860030.718 [DAT](INFO): DAT read: $Packet for address 21 2025-07-18T17:33:50.718Z,1752860030.718 [DAT](INFO): received a packet notification 2025-07-18T17:33:50.730Z,1752860030.730 [DAT](INFO): #Rx 29: Read direction message, but no range. 2025-07-18T17:33:50.731Z,1752860030.731 [DAT](INFO): direction in FSK: [-0.383554,-0.912438,0.142629] 2025-07-18T17:33:52.223Z,1752860032.223 [DAT](INFO): DAT read: Rx Time:17:33:50.6482 2025-07-18T17:33:52.224Z,1752860032.224 [DAT](INFO): Rx dataTimestamp_ set to:1752860032.223305 2025-07-18T17:33:52.733Z,1752860032.733 [DAT](INFO): DAT read: 17:33:50.6482 LVL= 32752, 21969, 26450, 32755, AGC= 87, IDX= 70,-0.02, 3.051,-1.408,-1.630,-1.673, PHS=-1.576, 0.339, 0.091, RAW= 276.9, 12.7, CAL= 278.1, 22.2, ROT= 231.9, -22.2 2025-07-18T17:33:52.734Z,1752860032.734 [DAT](INFO): got valid direction response: 17:33:50.6482 LVL= 32752, 21969, 26450, 32755, AGC= 87, IDX= 70,-0.02, 3.051,-1.408,-1.630,-1.673, PHS=-1.576, 0.339, 0.091, RAW= 276.9, 12.7, CAL= 278.1, 22.2, ROT= 231.9, -22.2 2025-07-18T17:33:52.735Z,1752860032.735 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:33:52.735Z,1752860032.735 [DAT](INFO): Received a bad header 2025-07-18T17:33:52.746Z,1752860032.746 [DAT](INFO): #Rx 30: Read direction message, but no range. 2025-07-18T17:33:52.747Z,1752860032.747 [DAT](INFO): direction in FSK: [-0.571295,-0.728600,0.377841] 2025-07-18T17:34:50.459Z,1752860090.459 [DAT](INFO): DAT read: Rx Time:17:34:49.0392 2025-07-18T17:34:50.460Z,1752860090.460 [DAT](INFO): Rx dataTimestamp_ set to:1752860090.459299 2025-07-18T17:34:51.221Z,1752860091.221 [DAT](INFO): DAT read: 17:34:49.0392 LVL= 32752, 32753, 32754, 32755, AGC= 87, IDX= 369, 0.08, 1.186, 2.687, 2.524, 2.618, PHS=-1.447, 0.144,-0.045, RAW= 276.3, 17.6, CAL= 278.9, 26.9, ROT= 231.1, -26.9 2025-07-18T17:34:51.222Z,1752860091.222 [DAT](INFO): got valid direction response: 17:34:49.0392 LVL= 32752, 32753, 32754, 32755, AGC= 87, IDX= 369, 0.08, 1.186, 2.687, 2.524, 2.618, PHS=-1.447, 0.144,-0.045, RAW= 276.3, 17.6, CAL= 278.9, 26.9, ROT= 231.1, -26.9 2025-07-18T17:34:51.223Z,1752860091.223 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:34:51.223Z,1752860091.223 [DAT](INFO): Received a bad header 2025-07-18T17:34:51.234Z,1752860091.234 [DAT](INFO): #Rx 31: Read direction message, but no range. 2025-07-18T17:34:51.235Z,1752860091.235 [DAT](INFO): direction in FSK: [-0.560016,-0.694035,0.452435] 2025-07-18T17:35:50.967Z,1752860150.967 [DAT](INFO): DAT read: Rx Time:17:35:49.3101 2025-07-18T17:35:50.968Z,1752860150.968 [DAT](INFO): Rx dataTimestamp_ set to:1752860150.967283 2025-07-18T17:35:51.477Z,1752860151.477 [DAT](INFO): DAT read: 17:35:49.3101 LVL= 32752, 32753, 32754, 32755, AGC= 87, IDX= 180, 0.03,-3.100,-1.198,-2.266,-2.236, PHS=-0.880, 1.113, 0.018, RAW= 303.3, -2.9, CAL= 303.6, -3.8, ROT= 206.4, 3.8 2025-07-18T17:35:51.478Z,1752860151.478 [DAT](INFO): got valid direction response: 17:35:49.3101 LVL= 32752, 32753, 32754, 32755, AGC= 87, IDX= 180, 0.03,-3.100,-1.198,-2.266,-2.236, PHS=-0.880, 1.113, 0.018, RAW= 303.3, -2.9, CAL= 303.6, -3.8, ROT= 206.4, 3.8 2025-07-18T17:35:51.479Z,1752860151.479 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:35:51.479Z,1752860151.479 [DAT](INFO): Received a bad header 2025-07-18T17:35:51.490Z,1752860151.490 [DAT](INFO): #Rx 32: Read direction message, but no range. 2025-07-18T17:35:51.491Z,1752860151.491 [DAT](INFO): direction in FSK: [-0.893743,-0.443658,-0.066274] 2025-07-18T17:37:51.260Z,1752860271.260 [DAT](INFO): DAT read: Rx Time:17:37:49.8319 2025-07-18T17:37:51.261Z,1752860271.261 [DAT](INFO): Rx dataTimestamp_ set to:1752860271.260255 2025-07-18T17:37:52.030Z,1752860272.030 [DAT](INFO): DAT read: 17:37:49.8319 LVL= 32752, 24929, 32754, 32755, AGC= 88, IDX= 188,-0.10, 1.442, 3.124, 1.357, 1.878, PHS=-0.452, 1.321,-0.473, RAW= 330.6, -4.5, CAL= 330.8, -7.1, ROT= 179.2, 7.1 2025-07-18T17:37:52.031Z,1752860272.031 [DAT](INFO): got valid direction response: 17:37:49.8319 LVL= 32752, 24929, 32754, 32755, AGC= 88, IDX= 188,-0.10, 1.442, 3.124, 1.357, 1.878, PHS=-0.452, 1.321,-0.473, RAW= 330.6, -4.5, CAL= 330.8, -7.1, ROT= 179.2, 7.1 2025-07-18T17:37:52.032Z,1752860272.032 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:37:52.032Z,1752860272.032 [DAT](INFO): Received a bad header 2025-07-18T17:37:52.046Z,1752860272.046 [DAT](INFO): #Rx 33: Read direction message, but no range. 2025-07-18T17:37:52.047Z,1752860272.047 [DAT](INFO): direction in FSK: [-0.992235,0.013855,-0.123601] 2025-07-18T17:37:53.535Z,1752860273.535 [DAT](INFO): DAT read: Rx Time:17:37:52.0498 2025-07-18T17:37:53.535Z,1752860273.535 [DAT](INFO): Rx dataTimestamp_ set to:1752860273.535215 2025-07-18T17:37:54.061Z,1752860274.061 [DAT](INFO): DAT read: 17:37:52.0498 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 146,-0.37, 3.142, 2.988, 3.059, 1.326, PHS= 1.800, 1.737, 1.781, RAW= 133.4, -88.3, CAL= 133.8, -88.1, ROT= 16.2, 88.1 2025-07-18T17:37:54.062Z,1752860274.062 [DAT](INFO): got valid direction response: 17:37:52.0498 LVL= 32752, 32753, 32754, 32755, AGC= 90, IDX= 146,-0.37, 3.142, 2.988, 3.059, 1.326, PHS= 1.800, 1.737, 1.781, RAW= 133.4, -88.3, CAL= 133.8, -88.1, ROT= 16.2, 88.1 2025-07-18T17:37:54.063Z,1752860274.063 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:37:54.063Z,1752860274.063 [DAT](INFO): Received a bad header 2025-07-18T17:37:54.074Z,1752860274.074 [DAT](INFO): #Rx 34: Read direction message, but no range. 2025-07-18T17:37:54.075Z,1752860274.075 [DAT](INFO): direction in FSK: [0.031839,0.009250,-0.999450] 2025-07-18T17:38:53.831Z,1752860333.831 [DAT](INFO): DAT read: Rx Time:17:38:52.3932 2025-07-18T17:38:53.832Z,1752860333.832 [DAT](INFO): Rx dataTimestamp_ set to:1752860333.831563 2025-07-18T17:38:54.594Z,1752860334.594 [DAT](INFO): DAT read: 17:38:52.3932 LVL= 32752, 25841, 32466, 32755, AGC= 91, IDX= 427, 0.03,-0.689,-0.028,-0.954,-1.545, PHS= 0.839, 1.591, 0.639, RAW= 341.5, -51.3, CAL= 343.7, -52.5, ROT= 166.3, 52.5 2025-07-18T17:38:54.596Z,1752860334.596 [DAT](INFO): got valid direction response: 17:38:52.3932 LVL= 32752, 25841, 32466, 32755, AGC= 91, IDX= 427, 0.03,-0.689,-0.028,-0.954,-1.545, PHS= 0.839, 1.591, 0.639, RAW= 341.5, -51.3, CAL= 343.7, -52.5, ROT= 166.3, 52.5 2025-07-18T17:38:54.596Z,1752860334.596 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:38:54.597Z,1752860334.597 [DAT](INFO): Received a bad header 2025-07-18T17:38:54.610Z,1752860334.610 [DAT](INFO): #Rx 35: Read direction message, but no range. 2025-07-18T17:38:54.611Z,1752860334.611 [DAT](INFO): direction in FSK: [-0.591442,0.144178,-0.793353] 2025-07-18T17:39:08.339Z,1752860348.339 [keepstation:SurfaceComms] Running Loop=1 2025-07-18T17:39:08.339Z,1752860348.339 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-07-18T17:39:08.339Z,1752860348.339 [keepstation:SurfaceComms:A] Running Loop=1 2025-07-18T17:39:08.340Z,1752860348.340 [keepstation:SurfaceComms:A] Stopped 2025-07-18T17:39:08.340Z,1752860348.340 [keepstation:SurfaceComms:B] Running Loop=1 2025-07-18T17:39:08.340Z,1752860348.340 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-07-18T17:39:08.341Z,1752860348.341 [keepstation:NeedComms] Running Loop=1 2025-07-18T17:39:08.341Z,1752860348.341 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-07-18T17:39:08.341Z,1752860348.341 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-07-18T17:39:08.341Z,1752860348.341 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T17:39:08.342Z,1752860348.342 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-07-18T17:39:08.343Z,1752860348.343 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-07-18T17:39:08.343Z,1752860348.343 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-07-18T17:39:08.343Z,1752860348.343 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-07-18T17:39:08.344Z,1752860348.344 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T17:39:08.344Z,1752860348.344 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T17:39:08.344Z,1752860348.344 [keepstation:NeedComms:A] Running Loop=1 2025-07-18T17:39:08.346Z,1752860348.346 [keepstation:NeedComms:A](INFO): last time_fix was: 1752857647.000000 second since 1970/01/01T00:00:00Z 2025-07-18T17:39:08.346Z,1752860348.346 [keepstation:NeedComms:A] Stopped 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:KeepStation:Dive] Stopped 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:KeepStation:Dive:A] Stopped 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:DiveCmd:StationKeep] Stopped 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-07-18T17:39:08.743Z,1752860348.743 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-07-18T17:39:08.744Z,1752860348.744 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-07-18T17:39:08.744Z,1752860348.744 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-07-18T17:40:57.422Z,1752860457.422 [keepstation:NeedComms:C] Running Loop=1 2025-07-18T17:40:57.966Z,1752860457.966 [Radio_Surface](INFO): Powering up 2025-07-18T17:41:03.911Z,1752860463.911 [DataOverHttps](INFO): Radio surface powered ON. 2025-07-18T17:41:34.030Z,1752860494.030 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:41:52.571Z,1752860512.571 [DAT](INFO): DAT read: Rx Time:17:41:50.9066 2025-07-18T17:41:52.572Z,1752860512.572 [DAT](INFO): Rx dataTimestamp_ set to:1752860512.571408 2025-07-18T17:41:53.081Z,1752860513.081 [DAT](INFO): DAT read: 17:41:50.9066 LVL= 32752, 23985, 27762, 24019, AGC= 91, IDX= 52, 0.24, 3.000, 1.155, 1.484, 1.666, PHS= 1.318,-0.436,-0.134, RAW= 99.3, -9.3, CAL= 100.8, -11.2, ROT= 49.2, 11.2 2025-07-18T17:41:53.082Z,1752860513.082 [DAT](INFO): got valid direction response: 17:41:50.9066 LVL= 32752, 23985, 27762, 24019, AGC= 91, IDX= 52, 0.24, 3.000, 1.155, 1.484, 1.666, PHS= 1.318,-0.436,-0.134, RAW= 99.3, -9.3, CAL= 100.8, -11.2, ROT= 49.2, 11.2 2025-07-18T17:41:53.082Z,1752860513.082 [DAT](INFO): DAT read: $Error in header 2025-07-18T17:41:53.083Z,1752860513.083 [DAT](INFO): Received a bad header 2025-07-18T17:41:53.094Z,1752860513.094 [DAT](INFO): #Rx 36: Read direction message, but no range. 2025-07-18T17:41:53.095Z,1752860513.095 [DAT](INFO): direction in FSK: [0.640976,0.742578,-0.194234] 2025-07-18T17:41:54.587Z,1752860514.587 [DAT](INFO): DAT read: Rx Time:17:41:52.9785 2025-07-18T17:41:54.588Z,1752860514.588 [DAT](INFO): Rx dataTimestamp_ set to:1752860514.587289 2025-07-18T17:41:55.091Z,1752860515.091 [DAT](INFO): DAT read: 2025-07-18T17:41:55.092Z,1752860515.092 [DAT](INFO): DAT read: $Packet for address 11 2025-07-18T17:41:55.092Z,1752860515.092 [DAT](INFO): received a packet notification 2025-07-18T17:42:09.178Z,1752860529.178 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:42:30.329Z,1752860550.329 [NAL9602](INFO): SBD MO Status=2, MOMSN=10194, MT Status=2, MTMSN=0 2025-07-18T17:42:30.329Z,1752860550.329 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:42:44.319Z,1752860564.319 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:42:45.683Z,1752860565.683 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=10194, MT Status=1, MTMSN=1530 2025-07-18T17:42:45.683Z,1752860565.683 [NAL9602](INFO): Data available in MT queue 2025-07-18T17:42:46.183Z,1752860566.183 [NAL9602](INFO): Received command: stop 2025-07-18T17:42:46.251Z,1752860566.251 [CommandExec](IMPORTANT): got command stop 2025-07-18T17:42:46.251Z,1752860566.251 [CommandExec](IMPORTANT): Scheduling is paused 2025-07-18T17:42:46.251Z,1752860566.251 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-07-18T17:42:46.505Z,1752860566.505 [MissionManager](INFO): MissionManager is completed. 2025-07-18T17:42:46.505Z,1752860566.505 [MissionManager](INFO): Uninitializing Mission keepstation 2025-07-18T17:42:46.505Z,1752860566.505 [keepstation] Stopped 2025-07-18T17:42:46.505Z,1752860566.505 [keepstation](DEBUG): Aggregate::uninitialize keepstation 2025-07-18T17:42:46.505Z,1752860566.505 [keepstation:NeedComms] Stopped 2025-07-18T17:42:46.506Z,1752860566.506 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-07-18T17:42:46.506Z,1752860566.506 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-07-18T17:42:46.506Z,1752860566.506 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-07-18T17:42:46.506Z,1752860566.506 [keepstation:NeedComms:C] Stopped 2025-07-18T17:42:46.522Z,1752860566.522 [keepstation:StandardEnvelopes] Stopped 2025-07-18T17:42:46.522Z,1752860566.522 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes 2025-07-18T17:42:46.522Z,1752860566.522 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-07-18T17:42:46.522Z,1752860566.522 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-07-18T17:42:46.522Z,1752860566.522 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-07-18T17:42:46.522Z,1752860566.522 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-07-18T17:42:46.522Z,1752860566.522 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:BackseatDriver] Stopped 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:BackseatDriver](DEBUG): Aggregate::uninitialize keepstation:BackseatDriver 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:BackseatDriver:A.BackseatDriver] Stopped 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:PowerOnly] Stopped 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:PowerOnly](DEBUG): Aggregate::uninitialize keepstation:PowerOnly 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:PowerOnly:E.Wait] Stopped 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:SurfaceComms] Stopped 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-07-18T17:42:46.523Z,1752860566.523 [keepstation:SurfaceComms:B] Stopped 2025-07-18T17:42:46.524Z,1752860566.524 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-07-18T17:42:46.524Z,1752860566.524 [keepstation:DiveCmd] Stopped 2025-07-18T17:42:46.524Z,1752860566.524 [keepstation:DiveCmd](DEBUG): Aggregate::uninitialize keepstation:DiveCmd 2025-07-18T17:42:46.524Z,1752860566.524 [keepstation:KeepStation] Stopped 2025-07-18T17:42:46.524Z,1752860566.524 [keepstation:KeepStation](DEBUG): Aggregate::uninitialize keepstation:KeepStation 2025-07-18T17:42:46.524Z,1752860566.524 [keepstation:KeepStation:B.Wait] Stopped 2025-07-18T17:42:46.524Z,1752860566.524 [keepstation:KeepStation:B.Wait](DEBUG): Uninitialize Wait Component. 2025-07-18T17:42:46.939Z,1752860566.939 [MissionManager](IMPORTANT): Started mission Default 2025-07-18T17:42:46.939Z,1752860566.939 [Default] Running Loop=1 2025-07-18T17:42:46.939Z,1752860566.939 [Default](DEBUG): Aggregate::initialize Default 2025-07-18T17:42:46.939Z,1752860566.939 [Default:B.GoToSurface] Running Loop=1 2025-07-18T17:42:46.939Z,1752860566.939 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-07-18T17:42:46.939Z,1752860566.939 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-07-18T17:42:46.940Z,1752860566.940 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-07-18T17:42:46.940Z,1752860566.940 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-07-18T17:42:46.940Z,1752860566.940 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-07-18T17:42:46.941Z,1752860566.941 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-07-18T17:42:46.941Z,1752860566.941 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-07-18T17:42:46.942Z,1752860566.942 [Default:A.Wait] Running Loop=1 2025-07-18T17:42:46.942Z,1752860566.942 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-07-18T17:42:47.300Z,1752860567.300 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174246.00,A,3647.83532,N,12150.79899,W,0.641,58.54,180725,,,D*45 2025-07-18T17:42:47.303Z,1752860567.303 [NAL9602](INFO): GPS fix at 20250718T174246: (36.797255, -121.846650) 2025-07-18T17:42:54.607Z,1752860574.607 [DAT](INFO): DAT read: Rx Time:17:42:53.0405 2025-07-18T17:42:54.608Z,1752860574.608 [DAT](INFO): Rx dataTimestamp_ set to:1752860574.607453 2025-07-18T17:42:55.116Z,1752860575.116 [DAT](INFO): DAT read: 17:42:53.0405 LVL= 24048, 19009, 23586, 16307, AGC= 88, IDX= 67,-0.22, 2.564, 2.849, 1.227, 2.266, PHS= 0.283, 0.659,-0.991, RAW= 17.4, 0.7, CAL= 17.7, -3.4, ROT= 132.3, 3.4 2025-07-18T17:42:55.117Z,1752860575.117 [DAT](INFO): got valid direction response: 17:42:53.0405 LVL= 24048, 19009, 23586, 16307, AGC= 88, IDX= 67,-0.22, 2.564, 2.849, 1.227, 2.266, PHS= 0.283, 0.659,-0.991, RAW= 17.4, 0.7, CAL= 17.7, -3.4, ROT= 132.3, 3.4 2025-07-18T17:42:55.117Z,1752860575.117 [DAT](INFO): DAT read: 2025-07-18T17:42:55.118Z,1752860575.118 [DAT](INFO): DAT read: $Packet for address 11 2025-07-18T17:42:55.119Z,1752860575.119 [DAT](INFO): received a packet notification 2025-07-18T17:42:55.130Z,1752860575.130 [DAT](INFO): #Rx 37: Read direction message, but no range. 2025-07-18T17:42:55.131Z,1752860575.131 [DAT](INFO): direction in FSK: [-0.671828,0.738329,-0.059306] 2025-07-18T17:43:00.248Z,1752860580.248 [Default:A.Wait](INFO): Done Waiting. 2025-07-18T17:43:00.248Z,1752860580.248 [Default:A.Wait] Stopped 2025-07-18T17:43:00.248Z,1752860580.248 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-07-18T17:43:00.659Z,1752860580.659 [Default:CheckIn] Running Loop=1 2025-07-18T17:43:00.659Z,1752860580.659 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-07-18T17:43:00.660Z,1752860580.660 [Default:CheckIn:Read_GPS] Running Loop=1 2025-07-18T17:43:02.657Z,1752860582.657 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174301.00,A,3647.83639,N,12150.79599,W,0.719,60.71,180725,,,D*42 2025-07-18T17:43:02.659Z,1752860582.659 [NAL9602](INFO): GPS fix at 20250718T174301: (36.797273, -121.846600) 2025-07-18T17:43:02.669Z,1752860582.669 [Default:CheckIn:Read_GPS] Stopped 2025-07-18T17:43:02.669Z,1752860582.669 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-07-18T17:43:19.460Z,1752860599.460 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:43:25.374Z,1752860605.374 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:43:25.375Z,1752860605.375 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:43:54.598Z,1752860634.598 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:44:15.533Z,1752860655.533 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:44:15.533Z,1752860655.533 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:44:29.738Z,1752860669.738 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:45:04.890Z,1752860704.890 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:45:23.041Z,1752860723.041 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:45:23.041Z,1752860723.041 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:45:40.030Z,1752860740.030 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:45:49.349Z,1752860749.349 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:45:49.349Z,1752860749.349 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:46:15.170Z,1752860775.170 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:46:19.278Z,1752860779.278 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:46:19.289Z,1752860779.289 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:46:50.318Z,1752860810.318 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:46:50.867Z,1752860810.867 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:46:50.867Z,1752860810.867 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:47:25.460Z,1752860845.460 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:47:36.954Z,1752860856.954 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=0, MTMSN=0 2025-07-18T17:47:36.954Z,1752860856.954 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:48:00.598Z,1752860880.598 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:48:07.313Z,1752860887.313 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:48:07.313Z,1752860887.313 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:48:24.718Z,1752860904.718 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:48:24.719Z,1752860904.719 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:48:35.742Z,1752860915.742 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:49:05.579Z,1752860945.579 [DataOverHttps](IMPORTANT): SBD MTMSN=20250718T174901 2025-07-18T17:49:05.583Z,1752860945.583 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003151 2025-07-18T17:49:42.285Z,1752860982.285 [NAL9602](INFO): Not Powering down - fast GPS 2025-07-18T17:50:05.855Z,1752861005.855 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.275394 2025-07-18T17:50:36.994Z,1752861036.994 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:51:08.005Z,1752861068.005 [NAL9602](INFO): SBD MO Status=2, MOMSN=10195, MT Status=2, MTMSN=0 2025-07-18T17:51:08.005Z,1752861068.005 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:51:08.119Z,1752861068.119 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:51:39.242Z,1752861099.242 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:51:46.824Z,1752861106.824 [NAL9602](INFO): SBD MO Status=1, MOMSN=10195, MT Status=0, MTMSN=0 2025-07-18T17:51:46.878Z,1752861106.878 [NAL9602](INFO): Sent 85 bytes from file Logs/20250718T135352/Courier0031.lzma 2025-07-18T17:51:46.879Z,1752861106.879 [NAL9602](INFO): Packets left to send: 0 2025-07-18T17:52:10.366Z,1752861130.366 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:52:11.127Z,1752861131.127 [NAL9602](INFO): SBD MO Status=2, MOMSN=10196, MT Status=2, MTMSN=0 2025-07-18T17:52:11.127Z,1752861131.127 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:52:29.765Z,1752861149.765 [NAL9602](INFO): SBD MO Status=1, MOMSN=10196, MT Status=0, MTMSN=0 2025-07-18T17:52:29.814Z,1752861149.814 [NAL9602](INFO): Sent 332 bytes from file Logs/20250718T135352/Express0032.lzma 2025-07-18T17:52:29.815Z,1752861149.815 [NAL9602](INFO): Packets left to send: 1 2025-07-18T17:52:41.510Z,1752861161.510 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-07-18T17:52:47.161Z,1752861167.161 [NAL9602](INFO): SBD MO Status=2, MOMSN=10197, MT Status=2, MTMSN=0 2025-07-18T17:52:47.161Z,1752861167.161 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:53:05.014Z,1752861185.014 [DataOverHttps](INFO): Received command: stop 2025-07-18T17:53:05.104Z,1752861185.104 [CommandExec](IMPORTANT): got command stop 2025-07-18T17:53:07.429Z,1752861187.429 [NAL9602](INFO): SBD MO Status=1, MOMSN=10197, MT Status=0, MTMSN=0 2025-07-18T17:53:07.486Z,1752861187.486 [NAL9602](INFO): Sent 105 bytes from file Logs/20250718T135352/Express0032.lzma 2025-07-18T17:53:07.486Z,1752861187.486 [NAL9602](INFO): Packets left to send: 0 2025-07-18T17:53:13.042Z,1752861193.042 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-07-18T17:53:23.585Z,1752861203.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=10198, MT Status=2, MTMSN=0 2025-07-18T17:53:23.585Z,1752861203.585 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-07-18T17:53:28.603Z,1752861208.603 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2025-07-18T17:53:35.479Z,1752861215.479 [DataOverHttps](IMPORTANT): SBD MTMSN=20250718T175334 2025-07-18T17:53:35.483Z,1752861215.483 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003137 2025-07-18T17:53:43.930Z,1752861223.930 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20250718T135352/Courier0034.lzma 2025-07-18T17:53:43.932Z,1752861223.932 [DataOverHttps](INFO): Received command: restart logs