2025-04-25T15:48:25.926Z,1745596105.926 [Supervisor](DEBUG): Initializing supervisor. 2025-04-25T15:48:25.931Z,1745596105.931 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-04-25T15:48:25.931Z,1745596105.931 [SyncHandler](INFO): Protected caller Thread ID is 6791 2025-04-25T15:48:25.932Z,1745596105.932 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-04-25T15:48:25.933Z,1745596105.933 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-04-25T15:48:25.933Z,1745596105.933 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6792 2025-04-25T15:48:25.937Z,1745596105.937 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-04-25T15:48:25.958Z,1745596105.958 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-04-25T15:48:25.959Z,1745596105.959 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-04-25T15:48:25.960Z,1745596105.960 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6793 2025-04-25T15:48:25.964Z,1745596105.964 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-04-25T15:48:25.965Z,1745596105.965 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-04-25T15:48:25.966Z,1745596105.966 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6794 2025-04-25T15:48:25.968Z,1745596105.968 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-04-25T15:48:25.969Z,1745596105.969 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-04-25T15:48:25.969Z,1745596105.969 [logger ThreadHandler](INFO): Protected caller Thread ID is 6795 2025-04-25T15:48:25.973Z,1745596105.973 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-04-25T15:48:25.974Z,1745596105.974 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-04-25T15:48:25.978Z,1745596105.978 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-04-25T15:48:26.421Z,1745596106.421 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-04-25T15:48:26.423Z,1745596106.423 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-04-25T15:48:26.516Z,1745596106.516 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-04-25T15:48:26.635Z,1745596106.635 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-04-25T15:48:26.637Z,1745596106.637 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-04-25T15:48:26.788Z,1745596106.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-04-25T15:48:26.790Z,1745596106.790 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-04-25T15:48:27.156Z,1745596107.156 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-04-25T15:48:27.157Z,1745596107.157 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-04-25T15:48:27.266Z,1745596107.266 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-04-25T15:48:27.267Z,1745596107.267 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-04-25T15:48:27.706Z,1745596107.706 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-04-25T15:48:27.707Z,1745596107.707 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-04-25T15:48:27.947Z,1745596107.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-04-25T15:48:27.949Z,1745596107.949 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-04-25T15:48:28.044Z,1745596108.044 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-04-25T15:48:28.393Z,1745596108.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-04-25T15:48:28.394Z,1745596108.394 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-04-25T15:48:28.631Z,1745596108.631 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-04-25T15:48:28.633Z,1745596108.633 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-04-25T15:48:29.183Z,1745596109.183 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-04-25T15:48:29.184Z,1745596109.184 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-04-25T15:48:29.394Z,1745596109.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-04-25T15:48:29.395Z,1745596109.395 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-04-25T15:48:29.698Z,1745596109.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-04-25T15:48:29.699Z,1745596109.699 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-04-25T15:48:30.596Z,1745596110.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-04-25T15:48:30.596Z,1745596110.596 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-04-25T15:48:31.188Z,1745596111.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-04-25T15:48:31.190Z,1745596111.190 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/ 2025-04-25T15:48:31.192Z,1745596111.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg 2025-04-25T15:48:31.302Z,1745596111.302 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg 2025-04-25T15:48:31.449Z,1745596111.449 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg 2025-04-25T15:48:31.545Z,1745596111.545 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg 2025-04-25T15:48:31.666Z,1745596111.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg 2025-04-25T15:48:31.767Z,1745596111.767 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg 2025-04-25T15:48:32.043Z,1745596112.043 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-04-25T15:48:32.043Z,1745596112.043 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg 2025-04-25T15:48:32.166Z,1745596112.166 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg 2025-04-25T15:48:32.278Z,1745596112.278 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg 2025-04-25T15:48:32.436Z,1745596112.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg 2025-04-25T15:48:32.533Z,1745596112.533 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-04-25T15:48:32.542Z,1745596112.542 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-04-25T15:48:32.706Z,1745596112.706 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-04-25T15:48:32.706Z,1745596112.706 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-04-25T15:48:32.775Z,1745596112.775 [VerticalControl](DEBUG): Construct VerticalControl. 2025-04-25T15:48:32.838Z,1745596112.838 [VerticalControl] Loaded 2025-04-25T15:48:32.838Z,1745596112.838 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-04-25T15:48:32.841Z,1745596112.841 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-04-25T15:48:32.889Z,1745596112.889 [HorizontalControl] Loaded 2025-04-25T15:48:32.889Z,1745596112.889 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-04-25T15:48:32.892Z,1745596112.892 [SpeedControl](DEBUG): Construct SpeedControl. 2025-04-25T15:48:32.895Z,1745596112.895 [SpeedControl] Loaded 2025-04-25T15:48:32.895Z,1745596112.895 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-04-25T15:48:32.898Z,1745596112.898 [LoopControl](DEBUG): Construct LoopControl. 2025-04-25T15:48:32.899Z,1745596112.899 [LoopControl] Loaded 2025-04-25T15:48:32.899Z,1745596112.899 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-04-25T15:48:32.899Z,1745596112.899 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-04-25T15:48:32.900Z,1745596112.900 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-04-25T15:48:32.981Z,1745596112.981 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-04-25T15:48:32.982Z,1745596112.982 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-04-25T15:48:33.659Z,1745596113.659 [AHRS_M2] Loaded 2025-04-25T15:48:33.659Z,1745596113.659 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-04-25T15:48:33.697Z,1745596113.697 [BackseatComponent](INFO): Found secondary power supply at: /dev/loadC4 2025-04-25T15:48:33.698Z,1745596113.698 [BackseatComponent] Loaded 2025-04-25T15:48:33.698Z,1745596113.698 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-04-25T15:48:33.699Z,1745596113.699 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BA4E0 2025-04-25T15:48:33.700Z,1745596113.700 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 6874 2025-04-25T15:48:33.702Z,1745596113.702 [LcmUniversalReporter] Loaded 2025-04-25T15:48:33.703Z,1745596113.703 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-04-25T15:48:34.507Z,1745596114.507 [BPC1] Loaded 2025-04-25T15:48:34.507Z,1745596114.507 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-04-25T15:48:34.604Z,1745596114.604 [DAT] Loaded 2025-04-25T15:48:34.604Z,1745596114.604 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-04-25T15:48:34.605Z,1745596114.605 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408EA4E0 2025-04-25T15:48:34.606Z,1745596114.606 [DAT ThreadHandler](INFO): Protected caller Thread ID is 6875 2025-04-25T15:48:34.678Z,1745596114.678 [DataOverHttps] Loaded 2025-04-25T15:48:34.678Z,1745596114.678 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-04-25T15:48:34.679Z,1745596114.679 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091A4E0 2025-04-25T15:48:34.680Z,1745596114.680 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6876 2025-04-25T15:48:34.703Z,1745596114.703 [Depth_Keller] Loaded 2025-04-25T15:48:34.703Z,1745596114.703 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-04-25T15:48:34.708Z,1745596114.708 [DropWeight] Loaded 2025-04-25T15:48:34.708Z,1745596114.708 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-04-25T15:48:34.774Z,1745596114.774 [NAL9602] Loaded 2025-04-25T15:48:34.774Z,1745596114.774 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-04-25T15:48:34.804Z,1745596114.804 [Onboard] Loaded 2025-04-25T15:48:34.804Z,1745596114.804 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-04-25T15:48:34.805Z,1745596114.805 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094A4E0 2025-04-25T15:48:34.806Z,1745596114.806 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6877 2025-04-25T15:48:34.820Z,1745596114.820 [Power24vConverter] Loaded 2025-04-25T15:48:34.820Z,1745596114.820 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-04-25T15:48:34.836Z,1745596114.836 [Radio_Surface] Loaded 2025-04-25T15:48:34.837Z,1745596114.837 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-04-25T15:48:34.838Z,1745596114.838 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097A4E0 2025-04-25T15:48:34.838Z,1745596114.838 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6878 2025-04-25T15:48:34.854Z,1745596114.854 [Sonardyne_Nano] Loaded 2025-04-25T15:48:34.854Z,1745596114.854 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-04-25T15:48:34.879Z,1745596114.879 [Waterlinked] Loaded 2025-04-25T15:48:34.879Z,1745596114.879 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread. 2025-04-25T15:48:34.879Z,1745596114.879 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-04-25T15:48:34.880Z,1745596114.880 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-04-25T15:48:34.894Z,1745596114.894 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-04-25T15:48:34.894Z,1745596114.894 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-04-25T15:48:34.936Z,1745596114.936 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-04-25T15:48:34.937Z,1745596114.937 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-04-25T15:48:35.131Z,1745596115.131 [SBIT](DEBUG): Construct Startup Built In Test. 2025-04-25T15:48:35.140Z,1745596115.140 [SBIT] Loaded 2025-04-25T15:48:35.141Z,1745596115.141 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-04-25T15:48:35.143Z,1745596115.143 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-04-25T15:48:35.156Z,1745596115.156 [IBIT] Loaded 2025-04-25T15:48:35.157Z,1745596115.157 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-04-25T15:48:35.162Z,1745596115.162 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-04-25T15:48:35.244Z,1745596115.244 [CBIT] Loaded 2025-04-25T15:48:35.244Z,1745596115.244 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-04-25T15:48:35.277Z,1745596115.277 [GFScanner] Loaded 2025-04-25T15:48:35.278Z,1745596115.278 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-04-25T15:48:35.278Z,1745596115.278 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-04-25T15:48:35.279Z,1745596115.279 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-04-25T15:48:35.683Z,1745596115.683 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-04-25T15:48:35.684Z,1745596115.684 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-04-25T15:48:35.754Z,1745596115.754 [DepthRateCalculator] Loaded 2025-04-25T15:48:35.754Z,1745596115.754 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-04-25T15:48:35.759Z,1745596115.759 [PitchRateCalculator] Loaded 2025-04-25T15:48:35.760Z,1745596115.760 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-04-25T15:48:35.770Z,1745596115.770 [SpeedCalculator] Loaded 2025-04-25T15:48:35.771Z,1745596115.771 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-04-25T15:48:35.775Z,1745596115.775 [YawRateCalculator] Loaded 2025-04-25T15:48:35.775Z,1745596115.775 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-04-25T15:48:35.795Z,1745596115.795 [ElevatorOffsetCalculator] Loaded 2025-04-25T15:48:35.795Z,1745596115.795 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-04-25T15:48:35.796Z,1745596115.796 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-04-25T15:48:35.796Z,1745596115.796 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-04-25T15:48:36.010Z,1745596116.010 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-04-25T15:48:36.011Z,1745596116.011 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-04-25T15:48:36.146Z,1745596116.146 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-04-25T15:48:36.146Z,1745596116.146 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-04-25T15:48:36.160Z,1745596116.160 [NavChart] Loaded 2025-04-25T15:48:36.160Z,1745596116.160 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-04-25T15:48:36.166Z,1745596116.166 [UniversalFixResidualReporter] Loaded 2025-04-25T15:48:36.166Z,1745596116.166 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-04-25T15:48:36.167Z,1745596116.167 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-04-25T15:48:36.167Z,1745596116.167 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-04-25T15:48:36.330Z,1745596116.330 [BuoyancyServo] Loaded 2025-04-25T15:48:36.331Z,1745596116.331 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-04-25T15:48:36.354Z,1745596116.354 [ElevatorServo] Loaded 2025-04-25T15:48:36.354Z,1745596116.354 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-04-25T15:48:36.376Z,1745596116.376 [MassServo] Loaded 2025-04-25T15:48:36.377Z,1745596116.377 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-04-25T15:48:36.399Z,1745596116.399 [RudderServo] Loaded 2025-04-25T15:48:36.399Z,1745596116.399 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-04-25T15:48:36.416Z,1745596116.416 [ThrusterHE] Loaded 2025-04-25T15:48:36.417Z,1745596116.417 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-04-25T15:48:36.417Z,1745596116.417 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-04-25T15:48:36.418Z,1745596116.418 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-04-25T15:48:36.626Z,1745596116.626 [CTD_Seabird] Loaded 2025-04-25T15:48:36.626Z,1745596116.626 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-04-25T15:48:36.627Z,1745596116.627 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C054E0 2025-04-25T15:48:36.628Z,1745596116.628 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6879 2025-04-25T15:48:36.665Z,1745596116.665 [ESPComponent] Loaded 2025-04-25T15:48:36.665Z,1745596116.665 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-04-25T15:48:36.699Z,1745596116.699 [PAR_Licor] Loaded 2025-04-25T15:48:36.699Z,1745596116.699 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-04-25T15:48:36.747Z,1745596116.747 [WetLabsBB2FL] Loaded 2025-04-25T15:48:36.748Z,1745596116.748 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-04-25T15:48:36.749Z,1745596116.749 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0 2025-04-25T15:48:36.749Z,1745596116.749 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6880 2025-04-25T15:48:36.750Z,1745596116.750 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-04-25T15:48:36.794Z,1745596116.794 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-04-25T15:48:36.801Z,1745596116.801 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-04-25T15:48:36.814Z,1745596116.814 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-04-25T15:48:36.815Z,1745596116.815 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C654E0 2025-04-25T15:48:36.816Z,1745596116.816 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6881 2025-04-25T15:48:36.820Z,1745596116.820 [Supervisor](INFO): Main Thread ID is 828 2025-04-25T15:48:36.820Z,1745596116.820 [Supervisor](DEBUG): Running supervisor. 2025-04-25T15:48:36.821Z,1745596116.821 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6882 2025-04-25T15:48:36.821Z,1745596116.821 [CommandExec](INFO): Initializing the command executive. 2025-04-25T15:48:36.823Z,1745596116.823 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6883 2025-04-25T15:48:36.825Z,1745596116.825 [controlThread ThreadHandler](INFO): Handler Thread ID is 6884 2025-04-25T15:48:36.825Z,1745596116.825 [controlThread](DEBUG): Initializing ControlThread 2025-04-25T15:48:36.826Z,1745596116.826 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-04-25T15:48:36.828Z,1745596116.828 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-04-25T15:48:36.828Z,1745596116.828 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-04-25T15:48:36.829Z,1745596116.829 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-04-25T15:48:36.832Z,1745596116.832 [SBIT](INFO): Initialize SBIT Component. 2025-04-25T15:48:36.833Z,1745596116.833 [SBIT](IMPORTANT): git: 2025-04-17_A-2-g3be7fe2f4 2025-04-25T15:48:36.833Z,1745596116.833 [SBIT](INFO): git hash: 3be7fe2f4f797b01e854aad963005adeda34aee5 2025-04-25T15:48:36.833Z,1745596116.833 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-04-25T15:48:36.834Z,1745596116.834 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #1 PREEMPT Tue Nov 28 15:04:22 PST 2023 2025-04-25T15:48:36.835Z,1745596116.835 [SBIT](INFO): Beginning SBIT in 113.000000 seconds. 2025-04-25T15:48:36.836Z,1745596116.836 [IBIT](INFO): Initialize IBIT Component. 2025-04-25T15:48:36.837Z,1745596116.837 [CBIT](DEBUG): Initialize CBIT Component. 2025-04-25T15:48:36.838Z,1745596116.838 [logger ThreadHandler](INFO): Handler Thread ID is 6885 2025-04-25T15:48:36.849Z,1745596116.849 [CBIT](DEBUG): Initialized mux pins. 2025-04-25T15:48:36.849Z,1745596116.849 [CBIT](DEBUG): Initializing the watchdog timer. 2025-04-25T15:48:36.857Z,1745596116.857 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 6886 2025-04-25T15:48:36.873Z,1745596116.873 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-04-25T15:48:36.873Z,1745596116.873 [CBIT](DEBUG): Initializing heartbeat. 2025-04-25T15:48:36.874Z,1745596116.874 [DAT ThreadHandler](INFO): Handler Thread ID is 6887 2025-04-25T15:48:36.875Z,1745596116.875 [DAT](INFO): Powering up 2025-04-25T15:48:36.875Z,1745596116.875 [DAT](DEBUG): Initializing DAT. 2025-04-25T15:48:36.878Z,1745596116.878 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6889 2025-04-25T15:48:36.880Z,1745596116.880 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-04-25T15:48:36.901Z,1745596116.901 [Onboard ThreadHandler](INFO): Handler Thread ID is 6890 2025-04-25T15:48:36.919Z,1745596116.919 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6891 2025-04-25T15:48:36.940Z,1745596116.940 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6892 2025-04-25T15:48:36.941Z,1745596116.941 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-04-25T15:48:36.945Z,1745596116.945 [CBIT](DEBUG): Deactivating emergency mode. 2025-04-25T15:48:36.947Z,1745596116.947 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6894 2025-04-25T15:48:36.949Z,1745596116.949 [WetLabsBB2FL](INFO): Powering up 2025-04-25T15:48:36.951Z,1745596116.951 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6896 2025-04-25T15:48:36.959Z,1745596116.959 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-04-25T15:48:36.959Z,1745596116.959 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-04-25T15:48:36.959Z,1745596116.959 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-04-25T15:48:36.959Z,1745596116.959 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-04-25T15:48:36.960Z,1745596116.960 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-04-25T15:48:36.960Z,1745596116.960 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-04-25T15:48:36.960Z,1745596116.960 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-04-25T15:48:36.960Z,1745596116.960 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-04-25T15:48:36.985Z,1745596116.985 [CBIT](DEBUG): Backplane powered. 2025-04-25T15:48:36.985Z,1745596116.985 [GFScanner](DEBUG): Initializing GFScanner 2025-04-25T15:48:36.985Z,1745596116.985 [GFScanner](DEBUG): Deactivating GF circuits. 2025-04-25T15:48:36.990Z,1745596116.990 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-04-25T15:48:36.990Z,1745596116.990 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-04-25T15:48:36.990Z,1745596116.990 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-04-25T15:48:36.991Z,1745596116.991 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-04-25T15:48:36.991Z,1745596116.991 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-04-25T15:48:36.992Z,1745596116.992 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-04-25T15:48:36.993Z,1745596116.993 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-04-25T15:48:37.006Z,1745596117.006 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-04-25T15:48:37.006Z,1745596117.006 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-04-25T15:48:37.007Z,1745596117.007 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-04-25T15:48:37.010Z,1745596117.010 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-04-25T15:48:37.076Z,1745596117.076 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-04-25T15:48:37.100Z,1745596117.100 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-25T15:48:37.130Z,1745596117.130 [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-04-25T15:48:37.131Z,1745596117.131 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-04-25T15:48:37.131Z,1745596117.131 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-04-25T15:48:37.146Z,1745596117.146 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-04-25T15:48:37.329Z,1745596117.329 [Radio_Surface](INFO): Powering up 2025-04-25T15:48:37.436Z,1745596117.436 [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-04-25T15:48:37.462Z,1745596117.462 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-04-25T15:48:37.463Z,1745596117.463 [Default:A.Wait](DEBUG): Construct Wait. 2025-04-25T15:48:37.465Z,1745596117.465 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-25T15:48:37.518Z,1745596117.518 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-04-25T15:48:37.520Z,1745596117.520 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-04-25T15:48:37.542Z,1745596117.542 [Default:E.Execute](DEBUG): Construct Execute. 2025-04-25T15:48:37.545Z,1745596117.545 [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-04-25T15:48:37.554Z,1745596117.554 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,Waterlinked,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter, 2025-04-25T15:48:37.581Z,1745596117.581 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-04-25T15:48:37.645Z,1745596117.645 [Depth_Keller](INFO): Initializing. 2025-04-25T15:48:37.647Z,1745596117.647 [Power24vConverter](INFO): Powering up. 2025-04-25T15:48:37.647Z,1745596117.647 [Sonardyne_Nano](INFO): Initializing. 2025-04-25T15:48:37.686Z,1745596117.686 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-04-25T15:48:37.712Z,1745596117.712 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-04-25T15:48:37.717Z,1745596117.717 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-04-25T15:48:37.718Z,1745596117.718 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-04-25T15:48:37.725Z,1745596117.725 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-04-25T15:48:37.726Z,1745596117.726 [MassServo](DEBUG): Initializing EZServoServo. 2025-04-25T15:48:37.733Z,1745596117.733 [MassServo](DEBUG): Initializing MassServo. 2025-04-25T15:48:37.734Z,1745596117.734 [RudderServo](DEBUG): Initializing EZServoServo. 2025-04-25T15:48:37.741Z,1745596117.741 [RudderServo](DEBUG): Initializing RudderServo. 2025-04-25T15:48:37.742Z,1745596117.742 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-04-25T15:48:37.749Z,1745596117.749 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-04-25T15:48:39.057Z,1745596119.057 [WetLabsBB2FL](INFO): Powering down 2025-04-25T15:48:39.583Z,1745596119.583 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-04-25T15:48:40.869Z,1745596120.869 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311 2025-04-25T15:48:43.502Z,1745596123.502 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-04-25T15:48:49.222Z,1745596129.222 [DAT](INFO): DAT read: 2025-04-25T15:48:49.223Z,1745596129.223 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-04-25T15:48:50.734Z,1745596130.734 [DAT](INFO): DAT read: MF Frequency Band 2025-04-25T15:48:50.735Z,1745596130.735 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-04-25T15:48:50.736Z,1745596130.736 [DAT](INFO): DAT read: Apr 25 2025 15:48:49 2025-04-25T15:48:51.994Z,1745596131.994 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-04-25T15:48:51.995Z,1745596131.995 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-04-25T15:48:51.996Z,1745596131.996 [DAT](INFO): commRate: 800 2025-04-25T15:48:54.061Z,1745596134.061 [DAT](INFO): entering command mode 2025-04-25T15:48:54.262Z,1745596134.262 [DAT](INFO): DAT read: 2025-04-25T15:48:54.262Z,1745596134.262 [DAT](INFO): DAT read: user:1> 2025-04-25T15:48:54.263Z,1745596134.263 [DAT](INFO): setting verbose to 3 2025-04-25T15:48:54.514Z,1745596134.514 [DAT](INFO): DAT read: user:1> 2025-04-25T15:48:54.515Z,1745596134.515 [DAT](INFO): DAT read: Verbose | 3 2025-04-25T15:48:54.515Z,1745596134.515 [DAT](INFO): set verbose to 3 2025-04-25T15:48:54.515Z,1745596134.515 [DAT](INFO): setting DatVerbose to 27440 2025-04-25T15:48:54.766Z,1745596134.766 [DAT](INFO): DAT read: user:2> 2025-04-25T15:48:54.767Z,1745596134.767 [DAT](INFO): DAT read: DatVerbose | 27440 2025-04-25T15:48:54.767Z,1745596134.767 [DAT](INFO): set DatVerbose to 27440 2025-04-25T15:48:54.767Z,1745596134.767 [DAT](INFO): setting transmit power to 8 2025-04-25T15:48:55.018Z,1745596135.018 [DAT](INFO): DAT read: user:3> 2025-04-25T15:48:55.019Z,1745596135.019 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-04-25T15:48:55.019Z,1745596135.019 [DAT](INFO): set transmit power to 8 2025-04-25T15:48:55.019Z,1745596135.019 [DAT](INFO): setting local address to 1 2025-04-25T15:48:55.270Z,1745596135.270 [DAT](INFO): DAT read: user:4> 2025-04-25T15:48:55.271Z,1745596135.271 [DAT](INFO): DAT read: LocalAddr | 1 2025-04-25T15:48:55.271Z,1745596135.271 [DAT](INFO): set local address to 1 2025-04-25T15:48:55.272Z,1745596135.272 [DAT](INFO): Setting time to: 15:48:55 And date to:4/25/2025 2025-04-25T15:48:55.522Z,1745596135.522 [DAT](INFO): DAT read: user:5> 2025-04-25T15:48:55.523Z,1745596135.523 [DAT](INFO): DAT read: Fri Apr 25, 2025 15:48:55 2025-04-25T15:48:55.523Z,1745596135.523 [DAT](INFO): Local DAT time set to Fri Apr 25, 2025 15:48:55 2025-04-25T15:49:05.100Z,1745596145.100 [NAL9602](INFO): Powering up NAL9602 2025-04-25T15:49:15.145Z,1745596155.145 [Waterlinked](INFO): Powering down 2025-04-25T15:49:16.271Z,1745596156.271 [NAL9602](INFO): NAL9602 initialized 2025-04-25T15:49:44.961Z,1745596184.961 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:49:48.996Z,1745596188.996 [NAL9602](INFO): SBD MO Status=2, MOMSN=24292, MT Status=2, MTMSN=0 2025-04-25T15:49:48.996Z,1745596188.996 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T15:49:59.895Z,1745596199.895 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:50:07.172Z,1745596207.172 [NAL9602](INFO): SBD MO Status=2, MOMSN=24292, MT Status=2, MTMSN=0 2025-04-25T15:50:07.173Z,1745596207.173 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T15:50:14.843Z,1745596214.843 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:50:16.872Z,1745596216.872 [NAL9602](INFO): SBD MO Status=0, MOMSN=24292, MT Status=0, MTMSN=0 2025-04-25T15:50:16.872Z,1745596216.872 [NAL9602](INFO): No messages in MT queue 2025-04-25T15:50:18.080Z,1745596218.080 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155021.00,A,3647.84177,N,12150.83333,W,0.233,303.78,250425,,,A*73 2025-04-25T15:50:18.084Z,1745596218.084 [NAL9602](INFO): GPS fix at 20250425T155021: (36.797363, -121.847222) 2025-04-25T15:50:29.798Z,1745596229.798 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:50:30.249Z,1745596230.249 [SBIT](IMPORTANT): Beginning Startup BIT 2025-04-25T15:50:30.254Z,1745596230.254 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-04-25T15:50:34.790Z,1745596234.790 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.045122 CHAN A1 (24V): 0.082792 CHAN A2 (12V): 0.036791 CHAN A3 (5V): 0.007883 CHAN B0 (3.3V): 0.005292 CHAN B1 (3.15aV): 0.004597 CHAN B2 (3.15bV): 0.004553 CHAN B3 (GND): -0.004827 OPEN: 0.009367 Full Scale: +/- 1 mA 2025-04-25T15:50:45.196Z,1745596245.196 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:50:50.454Z,1745596250.454 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T15:51:24.026Z,1745596284.026 [SBIT](IMPORTANT): SBIT PASSED 2025-04-25T15:51:24.026Z,1745596284.026 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-04-25T15:51:24.027Z,1745596284.027 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=15 count; 2025-04-25T15:51:24.027Z,1745596284.027 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter; 2025-04-25T15:51:24.027Z,1745596284.027 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool; 2025-04-25T15:51:24.028Z,1745596284.028 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=1 ampere_hour; 2025-04-25T15:51:24.028Z,1745596284.028 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=205.765991 cubic_centimeter; 2025-04-25T15:51:24.028Z,1745596284.028 [SBIT](IMPORTANT): VerticalControl.massDefault=23.4804 millimeter; 2025-04-25T15:51:24.418Z,1745596284.418 [MissionManager](IMPORTANT): Started mission Startup 2025-04-25T15:51:24.419Z,1745596284.419 [Startup] Running Loop=1 2025-04-25T15:51:24.419Z,1745596284.419 [Startup](DEBUG): Aggregate::initialize Startup 2025-04-25T15:51:24.419Z,1745596284.419 [Startup:A.GoToSurface] Running Loop=1 2025-04-25T15:51:24.419Z,1745596284.419 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-25T15:51:24.420Z,1745596284.420 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-25T15:51:24.420Z,1745596284.420 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-25T15:51:24.420Z,1745596284.420 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-25T15:51:24.421Z,1745596284.421 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-25T15:51:24.421Z,1745596284.421 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-25T15:51:24.421Z,1745596284.421 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-25T15:51:24.423Z,1745596284.423 [Startup:StartupSatComms] Running Loop=1 2025-04-25T15:51:24.423Z,1745596284.423 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-04-25T15:51:24.423Z,1745596284.423 [Startup:StartupSatComms:A] Running Loop=1 2025-04-25T15:51:24.835Z,1745596284.835 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-04-25T15:51:26.405Z,1745596286.405 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155129.00,A,3647.84351,N,12150.83606,W,0.583,309.76,250425,,,A*77 2025-04-25T15:51:26.407Z,1745596286.407 [NAL9602](INFO): GPS fix at 20250425T155129: (36.797392, -121.847268) 2025-04-25T15:51:26.419Z,1745596286.419 [Startup:StartupSatComms:A] Stopped 2025-04-25T15:51:26.419Z,1745596286.419 [Startup:StartupSatComms:B] Running Loop=1 2025-04-25T15:51:26.839Z,1745596286.839 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-25T15:51:52.721Z,1745596312.721 [NAL9602](INFO): SBD MO Status=2, MOMSN=24293, MT Status=2, MTMSN=0 2025-04-25T15:51:52.721Z,1745596312.721 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T15:52:23.407Z,1745596343.407 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004305 2025-04-25T15:52:26.689Z,1745596346.689 [Startup:StartupSatComms:B](INFO): Timed out from 2025-04-25T15:51:26.4Z 2025-04-25T15:52:26.689Z,1745596346.689 [Startup:StartupSatComms:B] Stopped 2025-04-25T15:52:26.690Z,1745596346.690 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-04-25T15:52:26.690Z,1745596346.690 [Startup:StartupSatComms] Stopped 2025-04-25T15:52:26.690Z,1745596346.690 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-04-25T15:52:26.691Z,1745596346.691 [Startup](INFO): Completed Startup 2025-04-25T15:52:26.691Z,1745596346.691 [MissionManager](INFO): Startup is completed. 2025-04-25T15:52:26.691Z,1745596346.691 [MissionManager](INFO): Uninitializing Mission Startup 2025-04-25T15:52:26.691Z,1745596346.691 [Startup] Stopped 2025-04-25T15:52:26.691Z,1745596346.691 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-04-25T15:52:26.691Z,1745596346.691 [Startup:A.GoToSurface] Stopped 2025-04-25T15:52:26.691Z,1745596346.691 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-25T15:52:27.076Z,1745596347.076 [MissionManager](IMPORTANT): Started mission Default 2025-04-25T15:52:27.076Z,1745596347.076 [Default] Running Loop=1 2025-04-25T15:52:27.076Z,1745596347.076 [Default](DEBUG): Aggregate::initialize Default 2025-04-25T15:52:27.076Z,1745596347.076 [Default:B.GoToSurface] Running Loop=1 2025-04-25T15:52:27.076Z,1745596347.076 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-25T15:52:27.076Z,1745596347.076 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-25T15:52:27.077Z,1745596347.077 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-25T15:52:27.077Z,1745596347.077 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-25T15:52:27.078Z,1745596347.078 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-25T15:52:27.078Z,1745596347.078 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-25T15:52:27.078Z,1745596347.078 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-25T15:52:27.078Z,1745596347.078 [Default:A.Wait] Running Loop=1 2025-04-25T15:52:27.079Z,1745596347.079 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-04-25T15:52:31.841Z,1745596351.841 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250424T184726/Courier0405.lzma 2025-04-25T15:52:33.847Z,1745596353.847 [DataOverHttps](INFO): Moved sent file to Logs/20250424T184726/Courier0405.lzma.bak 2025-04-25T15:52:33.848Z,1745596353.848 [DataOverHttps](INFO): SBD MOMSN=24730442 2025-04-25T15:52:40.467Z,1745596360.467 [Default:A.Wait](INFO): Done Waiting. 2025-04-25T15:52:40.467Z,1745596360.467 [Default:A.Wait] Stopped 2025-04-25T15:52:40.467Z,1745596360.467 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T15:52:40.906Z,1745596360.906 [Default:CheckIn] Running Loop=1 2025-04-25T15:52:40.906Z,1745596360.906 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T15:52:40.906Z,1745596360.906 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T15:52:41.282Z,1745596361.282 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-25T15:52:42.844Z,1745596362.844 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155246.00,A,3647.84551,N,12150.84073,W,0.505,300.73,250425,,,A*7A 2025-04-25T15:52:42.846Z,1745596362.846 [NAL9602](INFO): GPS fix at 20250425T155246: (36.797425, -121.847346) 2025-04-25T15:52:42.941Z,1745596362.941 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T15:52:42.941Z,1745596362.941 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T15:52:43.322Z,1745596363.322 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-25T15:52:52.949Z,1745596372.949 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20250425T154825/Courier0000.lzma 2025-04-25T15:52:53.951Z,1745596373.951 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0000.lzma.bak 2025-04-25T15:52:53.951Z,1745596373.951 [DataOverHttps](INFO): SBD MOMSN=24730444 2025-04-25T15:53:11.849Z,1745596391.849 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0004.lzma 2025-04-25T15:53:12.851Z,1745596392.851 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0004.lzma.bak 2025-04-25T15:53:12.851Z,1745596392.851 [DataOverHttps](INFO): SBD MOMSN=24730448 2025-04-25T15:53:14.993Z,1745596394.993 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:53:16.615Z,1745596396.615 [NAL9602](INFO): SBD MO Status=2, MOMSN=24293, MT Status=2, MTMSN=0 2025-04-25T15:53:16.615Z,1745596396.615 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T15:53:20.649Z,1745596400.649 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:53:29.953Z,1745596409.953 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20250424T184726/Express0403.lzma 2025-04-25T15:53:31.959Z,1745596411.959 [DataOverHttps](INFO): Moved sent file to Logs/20250424T184726/Express0403.lzma.bak 2025-04-25T15:53:31.959Z,1745596411.959 [DataOverHttps](INFO): SBD MOMSN=24730451 2025-04-25T15:53:33.175Z,1745596413.175 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:53:45.293Z,1745596425.293 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:53:47.829Z,1745596427.829 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20250424T184726/Express0406.lzma 2025-04-25T15:53:48.831Z,1745596428.831 [DataOverHttps](INFO): Moved sent file to Logs/20250424T184726/Express0406.lzma.bak 2025-04-25T15:53:48.831Z,1745596428.831 [DataOverHttps](INFO): SBD MOMSN=24730456 2025-04-25T15:53:50.960Z,1745596430.960 [NAL9602](INFO): SBD MO Status=2, MOMSN=24293, MT Status=2, MTMSN=0 2025-04-25T15:53:50.960Z,1745596430.960 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T15:53:57.347Z,1745596437.347 [DataOverHttps](IMPORTANT): SBD MTMSN=20250425T155401 2025-04-25T15:53:57.819Z,1745596437.819 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:54:04.745Z,1745596444.745 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20250424T184726/Express0409.lzma 2025-04-25T15:54:04.756Z,1745596444.756 [DataOverHttps](INFO): Received command: load Transport/keepstation.tl;set keepstation.NeedCommsTime 30 min;set keepstation.Latitude 36.797 degree;set keepstation.Longitude -121.847 degree;run 2025-04-25T15:54:04.872Z,1745596444.872 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl 2025-04-25T15:54:04.873Z,1745596444.873 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl 2025-04-25T15:54:04.873Z,1745596444.873 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl 2025-04-25T15:54:04.875Z,1745596444.875 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl 2025-04-25T15:54:06.151Z,1745596446.151 [DataOverHttps](INFO): Moved sent file to Logs/20250424T184726/Express0409.lzma.bak 2025-04-25T15:54:06.151Z,1745596446.151 [DataOverHttps](INFO): SBD MOMSN=24730466 2025-04-25T15:54:06.185Z,1745596446.185 [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-04-25T15:54:06.194Z,1745596446.194 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h 2025-04-25T15:54:06.197Z,1745596446.197 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min 2025-04-25T15:54:06.200Z,1745596446.200 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg 2025-04-25T15:54:06.203Z,1745596446.203 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg 2025-04-25T15:54:06.226Z,1745596446.226 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m 2025-04-25T15:54:06.235Z,1745596446.235 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m 2025-04-25T15:54:06.238Z,1745596446.238 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m 2025-04-25T15:54:06.254Z,1745596446.254 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s 2025-04-25T15:54:06.256Z,1745596446.256 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m 2025-04-25T15:54:06.263Z,1745596446.263 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool 2025-04-25T15:54:06.278Z,1745596446.278 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m 2025-04-25T15:54:06.281Z,1745596446.281 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min 2025-04-25T15:54:06.316Z,1745596446.316 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m 2025-04-25T15:54:06.327Z,1745596446.327 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km 2025-04-25T15:54:06.335Z,1745596446.335 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count 2025-04-25T15:54:06.354Z,1745596446.354 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count 2025-04-25T15:54:06.359Z,1745596446.359 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count 2025-04-25T15:54:06.368Z,1745596446.368 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count 2025-04-25T15:54:06.372Z,1745596446.372 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count 2025-04-25T15:54:06.384Z,1745596446.384 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool 2025-04-25T15:54:06.384Z,1745596446.384 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2025-04-25T15:54:06.384Z,1745596446.384 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2025-04-25T15:54:06.390Z,1745596446.390 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2025-04-25T15:54:06.851Z,1745596446.851 [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-04-25T15:54:06.868Z,1745596446.868 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h 2025-04-25T15:54:06.875Z,1745596446.875 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min 2025-04-25T15:54:06.882Z,1745596446.882 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg 2025-04-25T15:54:06.889Z,1745596446.889 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s 2025-04-25T15:54:06.892Z,1745596446.892 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s 2025-04-25T15:54:06.899Z,1745596446.899 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s 2025-04-25T15:54:06.906Z,1745596446.906 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min 2025-04-25T15:54:06.938Z,1745596446.938 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min 2025-04-25T15:54:06.952Z,1745596446.952 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-25T15:54:07.017Z,1745596447.017 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-04-25T15:54:07.033Z,1745596447.033 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-04-25T15:54:07.035Z,1745596447.035 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-04-25T15:54:07.247Z,1745596447.247 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 0 200 2000 2025-04-25T15:54:07.256Z,1745596447.256 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m 2025-04-25T15:54:07.263Z,1745596447.263 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 0.000000 m 2025-04-25T15:54:07.267Z,1745596447.267 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m 2025-04-25T15:54:07.276Z,1745596447.276 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-04-25T15:54:07.285Z,1745596447.285 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-04-25T15:54:07.302Z,1745596447.302 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-04-25T15:54:07.319Z,1745596447.319 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-04-25T15:54:07.348Z,1745596447.348 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-04-25T15:54:07.348Z,1745596447.348 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-04-25T15:54:07.365Z,1745596447.365 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-04-25T15:54:07.407Z,1745596447.407 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-04-25T15:54:07.415Z,1745596447.415 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool 2025-04-25T15:54:07.422Z,1745596447.422 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-04-25T15:54:07.449Z,1745596447.449 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-04-25T15:54:07.450Z,1745596447.450 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-04-25T15:54:07.451Z,1745596447.451 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-04-25T15:54:07.740Z,1745596447.740 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-04-25T15:54:07.744Z,1745596447.744 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool 2025-04-25T15:54:07.748Z,1745596447.748 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool 2025-04-25T15:54:07.751Z,1745596447.751 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool 2025-04-25T15:54:07.757Z,1745596447.757 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool 2025-04-25T15:54:07.760Z,1745596447.760 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool 2025-04-25T15:54:07.767Z,1745596447.767 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-04-25T15:54:07.769Z,1745596447.769 [keepstation:H.Pitch](DEBUG): Construct. 2025-04-25T15:54:07.830Z,1745596447.830 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-04-25T15:54:07.837Z,1745596447.837 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct. 2025-04-25T15:54:07.846Z,1745596447.846 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct. 2025-04-25T15:54:07.888Z,1745596447.888 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy. 2025-04-25T15:54:07.934Z,1745596447.934 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct. 2025-04-25T15:54:07.940Z,1745596447.940 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct. 2025-04-25T15:54:07.963Z,1745596447.963 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct. 2025-04-25T15:54:07.988Z,1745596447.988 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation. 2025-04-25T15:54:08.010Z,1745596448.010 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-04-25T15:54:08.042Z,1745596448.042 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait. 2025-04-25T15:54:08.073Z,1745596448.073 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission keepstation { """ Vehicle transits to desired waypoint (or stays put if none is commanded) and stays within the specified radius. """ arguments { MissionTimeout = 4 hour """ Maximum duration of mission """ NeedCommsTime = 45 minute """ How often to surface for communications """ Latitude = NaN degree """ Latitude of waypoint to hold. If NaN, hold the latitude at start of mission. """ Longitude = NaN degree """ Longitude of waypoint to hold. If NaN, hold the longitude at start of mission. """ Depth = 30 meter """ Depth held during drift mode """ ApproachDepth = 15 meter """ Depth for initial approach to station. """ DepthDeadband = 4 meter """ How much vertical drift from the specified depth is allowed in drift mode """ Speed = 0.75 meter_per_second """ Vehicle transit speed. """ Radius = 200 meter """ Radius of circle around waypoint to hold. """ SinkOffSurface = false """ If true, use buoyancy only to decend to SinkDepth before driving to first target depth """ SinkDepth = 10 meter """ Initial depth to decend using only buoyancy before driving """ SinkDepthTimeout = 10 minute """ Max wait time for the vehicle to reach the target depth """ MaxDepth = 45 meter """ Maximum allowable depth during the mission. """ MinOffshore = 2 kilometer """ Minimum distance from the shoreline to maintain """ } output { DiveMode = 0 count """ Mission variable (don't change). The mission sets this variable to switch between dive modes. Initialized to DoingComms. """ DoingComms = 0 count """ Mission variable (don't change). The mission will run in this mode when doing surface comms. """ SurfaceSink = 1 count """ Mission variable (don't change). The mission will run in this mode when sinking from the surface using only buoyancy. """ TransitToStation = 2 count """ Mission variable (don't change). The mission will run in this mode when performing the transit to station """ StationKeep = 3 count """ Mission variable (don't change). The mission will run in this mode when keeping station """ OnStation = false """ Mission variable (don't change). Determines last mode (Transit or StationKeep) to resume after needcomms """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl behavior Guidance:Pitch { run in parallel set massPosition = Control:VerticalControl.massDefault } aggregate SurfaceComms { run when ( called or ( elapsed ( Universal:time_fix ) > NeedCommsTime ) ) assign in sequence DiveMode = DoingComms call 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" 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 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" refId="NeedComms" aggregate KeepStation { run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call 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-04-25T15:54:08.077Z,1745596448.077 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation 2025-04-25T15:54:10.353Z,1745596450.353 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:54:18.428Z,1745596458.428 [NAL9602](INFO): SBD MO Status=1, MOMSN=24293, MT Status=0, MTMSN=0 2025-04-25T15:54:18.428Z,1745596458.428 [NAL9602](INFO): No messages in MT queue 2025-04-25T15:54:20.621Z,1745596460.621 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 30 minute 2025-04-25T15:54:20.622Z,1745596460.622 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.797 degree 2025-04-25T15:54:20.623Z,1745596460.623 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.847 degree 2025-04-25T15:54:20.624Z,1745596460.624 [CommandExec](IMPORTANT): got command run 2025-04-25T15:54:20.626Z,1745596460.626 [CommandExec](IMPORTANT): Running 2025-04-25T15:54:20.878Z,1745596460.878 [Default] Stopped 2025-04-25T15:54:20.878Z,1745596460.878 [Default](DEBUG): Aggregate::uninitialize Default 2025-04-25T15:54:20.878Z,1745596460.878 [Default:B.GoToSurface] Stopped 2025-04-25T15:54:20.878Z,1745596460.878 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-25T15:54:20.878Z,1745596460.878 [Default:CheckIn] Stopped 2025-04-25T15:54:20.879Z,1745596460.879 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T15:54:20.879Z,1745596460.879 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T15:54:20.879Z,1745596460.879 [MissionManager](IMPORTANT): Started mission keepstation 2025-04-25T15:54:20.879Z,1745596460.879 [keepstation] Running Loop=1 2025-04-25T15:54:20.879Z,1745596460.879 [keepstation](DEBUG): Aggregate::initialize keepstation 2025-04-25T15:54:20.879Z,1745596460.879 [keepstation:StandardEnvelopes] Running Loop=1 2025-04-25T15:54:20.879Z,1745596460.879 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes 2025-04-25T15:54:20.879Z,1745596460.879 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-04-25T15:54:20.879Z,1745596460.879 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-04-25T15:54:20.880Z,1745596460.880 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-04-25T15:54:20.880Z,1745596460.880 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-04-25T15:54:20.880Z,1745596460.880 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-04-25T15:54:20.880Z,1745596460.880 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-04-25T15:54:20.880Z,1745596460.880 [keepstation:BackseatDriver] Running Loop=1 2025-04-25T15:54:20.880Z,1745596460.880 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver 2025-04-25T15:54:20.880Z,1745596460.880 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-04-25T15:54:20.881Z,1745596460.881 [keepstation:PowerOnly] Running Loop=1 2025-04-25T15:54:20.881Z,1745596460.881 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly 2025-04-25T15:54:20.881Z,1745596460.881 [keepstation:PowerOnly:A] Running Loop=1 2025-04-25T15:54:20.881Z,1745596460.881 [keepstation:PowerOnly:B] Running Loop=1 2025-04-25T15:54:20.881Z,1745596460.881 [keepstation:PowerOnly:C] Running Loop=1 2025-04-25T15:54:20.881Z,1745596460.881 [keepstation:PowerOnly:D] Running Loop=1 2025-04-25T15:54:20.882Z,1745596460.882 [keepstation:PowerOnly:E.Wait] Running Loop=1 2025-04-25T15:54:20.882Z,1745596460.882 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-04-25T15:54:20.882Z,1745596460.882 [keepstation:H.Pitch] Running Loop=1 2025-04-25T15:54:20.882Z,1745596460.882 [keepstation:H.Pitch](DEBUG): Initialize. 2025-04-25T15:54:20.882Z,1745596460.882 [keepstation:B] Running Loop=1 2025-04-25T15:54:20.883Z,1745596460.883 [keepstation:H.Pitch] Running Loop=1 2025-04-25T15:54:20.883Z,1745596460.883 [keepstation:PowerOnly] Running Loop=1 2025-04-25T15:54:20.884Z,1745596460.884 [keepstation:PowerOnly:D] Stopped 2025-04-25T15:54:20.884Z,1745596460.884 [keepstation:PowerOnly:C] Stopped 2025-04-25T15:54:20.884Z,1745596460.884 [keepstation:PowerOnly:B] Stopped 2025-04-25T15:54:20.884Z,1745596460.884 [keepstation:PowerOnly:A] Stopped 2025-04-25T15:54:20.884Z,1745596460.884 [keepstation:BackseatDriver] Running Loop=1 2025-04-25T15:54:20.884Z,1745596460.884 [keepstation:StandardEnvelopes] Running Loop=1 2025-04-25T15:54:20.884Z,1745596460.884 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-04-25T15:54:20.885Z,1745596460.885 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-04-25T15:54:20.886Z,1745596460.886 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-04-25T15:54:20.886Z,1745596460.886 [keepstation:B] Stopped 2025-04-25T15:54:20.887Z,1745596460.887 [keepstation:D] Running Loop=1 2025-04-25T15:54:21.271Z,1745596461.271 [keepstation:D] Stopped 2025-04-25T15:54:21.271Z,1745596461.271 [keepstation:E] Running Loop=1 2025-04-25T15:54:21.669Z,1745596461.669 [keepstation:E] Stopped 2025-04-25T15:54:21.669Z,1745596461.669 [keepstation:StartingMission] Running Loop=1 2025-04-25T15:54:21.669Z,1745596461.669 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission 2025-04-25T15:54:22.320Z,1745596462.320 [keepstation:SurfaceComms] Running Loop=1 2025-04-25T15:54:22.320Z,1745596462.320 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-04-25T15:54:22.320Z,1745596462.320 [keepstation:SurfaceComms:A] Running Loop=1 2025-04-25T15:54:22.320Z,1745596462.320 [keepstation:SurfaceComms:A] Stopped 2025-04-25T15:54:22.321Z,1745596462.321 [keepstation:SurfaceComms:B] Running Loop=1 2025-04-25T15:54:22.321Z,1745596462.321 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-04-25T15:54:22.558Z,1745596462.558 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:54:22.611Z,1745596462.611 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2025-04-25T15:54:22.611Z,1745596462.611 [keepstation:NeedComms] Running Loop=1 2025-04-25T15:54:22.611Z,1745596462.611 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-04-25T15:54:22.611Z,1745596462.611 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-04-25T15:54:22.611Z,1745596462.611 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-25T15:54:22.612Z,1745596462.612 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-04-25T15:54:22.612Z,1745596462.612 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-04-25T15:54:22.612Z,1745596462.612 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-04-25T15:54:22.613Z,1745596462.613 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-04-25T15:54:22.621Z,1745596462.621 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-25T15:54:22.622Z,1745596462.622 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-25T15:54:22.622Z,1745596462.622 [keepstation:NeedComms:A] Running Loop=1 2025-04-25T15:54:22.623Z,1745596462.623 [keepstation:NeedComms:A](INFO): last time_fix was: 1745596366.000000 second since 1970/01/01T00:00:00Z 2025-04-25T15:54:22.623Z,1745596462.623 [keepstation:NeedComms:A] Stopped 2025-04-25T15:54:22.000Z,1745596463.000 [keepstation:NeedComms:C] Running Loop=1 2025-04-25T15:54:23.396Z,1745596463.396 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-25T15:54:24.968Z,1745596464.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155428.00,A,3647.84848,N,12150.84562,W,0.253,305.31,250425,,,A*73 2025-04-25T15:54:24.970Z,1745596464.970 [NAL9602](INFO): GPS fix at 20250425T155428: (36.797475, -121.847427) 2025-04-25T15:54:25.008Z,1745596465.008 [keepstation:NeedComms:C] Stopped 2025-04-25T15:54:25.008Z,1745596465.008 [keepstation:NeedComms:D] Running Loop=1 2025-04-25T15:54:25.419Z,1745596465.419 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-25T15:54:27.076Z,1745596467.076 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250425T154825/Courier0007.lzma 2025-04-25T15:54:28.079Z,1745596468.079 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0007.lzma.bak 2025-04-25T15:54:28.079Z,1745596468.079 [DataOverHttps](INFO): SBD MOMSN=24730469 2025-04-25T15:54:34.867Z,1745596474.867 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:54:40.503Z,1745596480.503 [DataOverHttps](IMPORTANT): SBD MTMSN=20250425T155444 2025-04-25T15:54:47.413Z,1745596487.413 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:54:49.101Z,1745596489.101 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250425T154825/Courier0010.lzma 2025-04-25T15:54:49.103Z,1745596489.103 [DataOverHttps](INFO): Received command: stop 2025-04-25T15:54:49.142Z,1745596489.142 [CommandExec](IMPORTANT): got command stop 2025-04-25T15:54:49.142Z,1745596489.142 [CommandExec](IMPORTANT): Scheduling is paused 2025-04-25T15:54:49.142Z,1745596489.142 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-04-25T15:54:49.486Z,1745596489.486 [MissionManager](INFO): MissionManager is completed. 2025-04-25T15:54:49.486Z,1745596489.486 [MissionManager](INFO): Uninitializing Mission keepstation 2025-04-25T15:54:49.486Z,1745596489.486 [keepstation] Stopped 2025-04-25T15:54:49.486Z,1745596489.486 [keepstation](DEBUG): Aggregate::uninitialize keepstation 2025-04-25T15:54:49.486Z,1745596489.486 [keepstation:NeedComms] Stopped 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:NeedComms:D] Stopped 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes] Stopped 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-04-25T15:54:49.487Z,1745596489.487 [keepstation:BackseatDriver] Stopped 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:BackseatDriver](DEBUG): Aggregate::uninitialize keepstation:BackseatDriver 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:BackseatDriver:A.BackseatDriver] Stopped 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:PowerOnly] Stopped 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:PowerOnly](DEBUG): Aggregate::uninitialize keepstation:PowerOnly 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:PowerOnly:E.Wait] Stopped 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:H.Pitch] Stopped 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:SurfaceComms] Stopped 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:SurfaceComms:B] Stopped 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-04-25T15:54:49.488Z,1745596489.488 [keepstation:StartingMission] Stopped 2025-04-25T15:54:49.489Z,1745596489.489 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission 2025-04-25T15:54:49.875Z,1745596489.875 [MissionManager](IMPORTANT): Started mission Default 2025-04-25T15:54:49.875Z,1745596489.875 [Default] Running Loop=1 2025-04-25T15:54:49.876Z,1745596489.876 [Default](DEBUG): Aggregate::initialize Default 2025-04-25T15:54:49.876Z,1745596489.876 [Default:B.GoToSurface] Running Loop=1 2025-04-25T15:54:49.876Z,1745596489.876 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-25T15:54:49.876Z,1745596489.876 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-25T15:54:49.876Z,1745596489.876 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-25T15:54:49.877Z,1745596489.877 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-25T15:54:49.877Z,1745596489.877 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-25T15:54:49.877Z,1745596489.877 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-25T15:54:49.878Z,1745596489.878 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-25T15:54:49.878Z,1745596489.878 [Default:A.Wait] Running Loop=1 2025-04-25T15:54:49.878Z,1745596489.878 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-04-25T15:54:50.103Z,1745596490.103 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0010.lzma.bak 2025-04-25T15:54:50.103Z,1745596490.103 [DataOverHttps](INFO): SBD MOMSN=24730472 2025-04-25T15:54:57.515Z,1745596497.515 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T15:54:59.533Z,1745596499.533 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:55:03.190Z,1745596503.190 [Default:A.Wait](INFO): Done Waiting. 2025-04-25T15:55:03.190Z,1745596503.190 [Default:A.Wait] Stopped 2025-04-25T15:55:03.190Z,1745596503.190 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T15:55:03.610Z,1745596503.610 [Default:CheckIn] Running Loop=1 2025-04-25T15:55:03.610Z,1745596503.610 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T15:55:03.611Z,1745596503.611 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T15:55:05.596Z,1745596505.596 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155509.00,A,3647.85025,N,12150.84802,W,0.544,328.99,250425,,,A*74 2025-04-25T15:55:05.605Z,1745596505.605 [NAL9602](INFO): GPS fix at 20250425T155509: (36.797504, -121.847467) 2025-04-25T15:55:05.618Z,1745596505.618 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T15:55:05.618Z,1745596505.618 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T15:55:11.654Z,1745596511.654 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:55:13.280Z,1745596513.280 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0013.lzma 2025-04-25T15:55:14.283Z,1745596514.283 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0013.lzma.bak 2025-04-25T15:55:14.283Z,1745596514.283 [DataOverHttps](INFO): SBD MOMSN=24730478 2025-04-25T15:55:22.759Z,1745596522.759 [DataOverHttps](IMPORTANT): SBD MTMSN=20250425T155526 2025-04-25T15:55:24.197Z,1745596524.197 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T15:55:30.254Z,1745596530.254 [DataOverHttps](INFO): Sending 1081 bytes from file Logs/20250425T154825/Express0001.lzma 2025-04-25T15:55:30.263Z,1745596530.263 [DataOverHttps](INFO): Received command: sched asap "load Transport/keepstation.tl;set keepstation.NeedCommsTime 30 min;set keepstation.Latitude 36.806966 degree;set keepstation.Longitude -121.824326 degree;set keepstation.Depth 10 m;set keepstation.ApproachDepth 10 m" 6s8a 1 2 2025-04-25T15:55:30.335Z,1745596530.335 [CommandExec](IMPORTANT): got command schedule asap "load Transport/keepstation.tl;set keepstation.NeedCommsTime 30 min;set keepstation.Latitude 36.806966 degree;set keepstation.Longitude -121.824326 degree;set keepstation.Depth 10 m;set keepstation.ApproachDepth 10 m" 6s8a 1 2.000000 2025-04-25T15:55:30.336Z,1745596530.336 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=6s8a 2025-04-25T15:55:30.337Z,1745596530.337 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='6s8a'): "load Transport/keepstation.tl;set keepstation.NeedCommsTime 30 min;set keepstation.Latitude 36.806966 degree;set keepstation.Longitude -121.824326 degree;set keepstation.Depth 10 m;set keepstation.ApproachDepth 10 m", ASAP 2025-04-25T15:55:31.425Z,1745596531.425 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0001.lzma.bak 2025-04-25T15:55:31.425Z,1745596531.425 [DataOverHttps](IMPORTANT): SBD MOMSN=24730482, MTMSN=20250425T155535 2025-04-25T15:55:38.869Z,1745596538.869 [DataOverHttps](INFO): Received command: sched asap "set keepstation.MaxDepth 25 m;run" 6s8a 2 2 2025-04-25T15:55:38.908Z,1745596538.908 [CommandExec](IMPORTANT): got command schedule asap "set keepstation.MaxDepth 25 m;run" 6s8a 2 2.000000 2025-04-25T15:55:38.908Z,1745596538.908 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=6s8a 2025-04-25T15:55:38.909Z,1745596538.909 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='6s8a'): "set keepstation.MaxDepth 25 m;run", ASAP 2025-04-25T15:55:39.036Z,1745596539.036 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl 2025-04-25T15:55:39.037Z,1745596539.037 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl 2025-04-25T15:55:39.037Z,1745596539.037 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl 2025-04-25T15:55:39.039Z,1745596539.039 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl 2025-04-25T15:55:39.556Z,1745596539.556 [NAL9602](INFO): SBD MO Status=2, MOMSN=24294, MT Status=2, MTMSN=0 2025-04-25T15:55:39.556Z,1745596539.556 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T15:55:40.423Z,1745596540.423 [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-04-25T15:55:40.451Z,1745596540.451 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h 2025-04-25T15:55:40.453Z,1745596540.453 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min 2025-04-25T15:55:40.455Z,1745596540.455 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg 2025-04-25T15:55:40.457Z,1745596540.457 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg 2025-04-25T15:55:40.459Z,1745596540.459 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m 2025-04-25T15:55:40.462Z,1745596540.462 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m 2025-04-25T15:55:40.464Z,1745596540.464 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m 2025-04-25T15:55:40.466Z,1745596540.466 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s 2025-04-25T15:55:40.468Z,1745596540.468 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m 2025-04-25T15:55:40.470Z,1745596540.470 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool 2025-04-25T15:55:40.473Z,1745596540.473 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m 2025-04-25T15:55:40.475Z,1745596540.475 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min 2025-04-25T15:55:40.510Z,1745596540.510 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m 2025-04-25T15:55:40.512Z,1745596540.512 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km 2025-04-25T15:55:40.526Z,1745596540.526 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count 2025-04-25T15:55:40.528Z,1745596540.528 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count 2025-04-25T15:55:40.536Z,1745596540.536 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count 2025-04-25T15:55:40.548Z,1745596540.548 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count 2025-04-25T15:55:40.555Z,1745596540.555 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count 2025-04-25T15:55:40.561Z,1745596540.561 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool 2025-04-25T15:55:40.562Z,1745596540.562 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2025-04-25T15:55:40.562Z,1745596540.562 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2025-04-25T15:55:40.563Z,1745596540.563 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2025-04-25T15:55:40.881Z,1745596540.881 [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-04-25T15:55:40.886Z,1745596540.886 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h 2025-04-25T15:55:40.888Z,1745596540.888 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min 2025-04-25T15:55:40.890Z,1745596540.890 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg 2025-04-25T15:55:40.892Z,1745596540.892 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s 2025-04-25T15:55:40.894Z,1745596540.894 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s 2025-04-25T15:55:40.897Z,1745596540.897 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s 2025-04-25T15:55:40.899Z,1745596540.899 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min 2025-04-25T15:55:40.921Z,1745596540.921 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min 2025-04-25T15:55:40.932Z,1745596540.932 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-04-25T15:55:40.970Z,1745596540.970 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-04-25T15:55:40.971Z,1745596540.971 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-04-25T15:55:40.972Z,1745596540.972 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-04-25T15:55:41.044Z,1745596541.044 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 0 200 2000 2025-04-25T15:55:41.048Z,1745596541.048 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m 2025-04-25T15:55:41.050Z,1745596541.050 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 0.000000 m 2025-04-25T15:55:41.052Z,1745596541.052 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m 2025-04-25T15:55:41.054Z,1745596541.054 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-04-25T15:55:41.055Z,1745596541.055 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-04-25T15:55:41.085Z,1745596541.085 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-04-25T15:55:41.091Z,1745596541.091 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-04-25T15:55:41.100Z,1745596541.100 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-04-25T15:55:41.100Z,1745596541.100 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-04-25T15:55:41.101Z,1745596541.101 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-04-25T15:55:41.131Z,1745596541.131 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-04-25T15:55:41.135Z,1745596541.135 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool 2025-04-25T15:55:41.137Z,1745596541.137 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-04-25T15:55:41.139Z,1745596541.139 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-04-25T15:55:41.140Z,1745596541.140 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-04-25T15:55:41.141Z,1745596541.141 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-04-25T15:55:41.328Z,1745596541.328 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-04-25T15:55:41.332Z,1745596541.332 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool 2025-04-25T15:55:41.334Z,1745596541.334 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool 2025-04-25T15:55:41.336Z,1745596541.336 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool 2025-04-25T15:55:41.338Z,1745596541.338 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool 2025-04-25T15:55:41.340Z,1745596541.340 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool 2025-04-25T15:55:41.347Z,1745596541.347 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-04-25T15:55:41.348Z,1745596541.348 [keepstation:H.Pitch](DEBUG): Construct. 2025-04-25T15:55:41.368Z,1745596541.368 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-04-25T15:55:41.371Z,1745596541.371 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct. 2025-04-25T15:55:41.398Z,1745596541.398 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct. 2025-04-25T15:55:41.423Z,1745596541.423 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy. 2025-04-25T15:55:41.429Z,1745596541.429 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct. 2025-04-25T15:55:41.433Z,1745596541.433 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct. 2025-04-25T15:55:41.443Z,1745596541.443 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct. 2025-04-25T15:55:41.447Z,1745596541.447 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation. 2025-04-25T15:55:41.454Z,1745596541.454 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-04-25T15:55:41.465Z,1745596541.465 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait. 2025-04-25T15:55:41.490Z,1745596541.490 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission keepstation { """ Vehicle transits to desired waypoint (or stays put if none is commanded) and stays within the specified radius. """ arguments { MissionTimeout = 4 hour """ Maximum duration of mission """ NeedCommsTime = 45 minute """ How often to surface for communications """ Latitude = NaN degree """ Latitude of waypoint to hold. If NaN, hold the latitude at start of mission. """ Longitude = NaN degree """ Longitude of waypoint to hold. If NaN, hold the longitude at start of mission. """ Depth = 30 meter """ Depth held during drift mode """ ApproachDepth = 15 meter """ Depth for initial approach to station. """ DepthDeadband = 4 meter """ How much vertical drift from the specified depth is allowed in drift mode """ Speed = 0.75 meter_per_second """ Vehicle transit speed. """ Radius = 200 meter """ Radius of circle around waypoint to hold. """ SinkOffSurface = false """ If true, use buoyancy only to decend to SinkDepth before driving to first target depth """ SinkDepth = 10 meter """ Initial depth to decend using only buoyancy before driving """ SinkDepthTimeout = 10 minute """ Max wait time for the vehicle to reach the target depth """ MaxDepth = 45 meter """ Maximum allowable depth during the mission. """ MinOffshore = 2 kilometer """ Minimum distance from the shoreline to maintain """ } output { DiveMode = 0 count """ Mission variable (don't change). The mission sets this variable to switch between dive modes. Initialized to DoingComms. """ DoingComms = 0 count """ Mission variable (don't change). The mission will run in this mode when doing surface comms. """ SurfaceSink = 1 count """ Mission variable (don't change). The mission will run in this mode when sinking from the surface using only buoyancy. """ TransitToStation = 2 count """ Mission variable (don't change). The mission will run in this mode when performing the transit to station """ StationKeep = 3 count """ Mission variable (don't change). The mission will run in this mode when keeping station """ OnStation = false """ Mission variable (don't change). Determines last mode (Transit or StationKeep) to resume after needcomms """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl behavior Guidance:Pitch { run in parallel set massPosition = Control:VerticalControl.massDefault } aggregate SurfaceComms { run when ( called or ( elapsed ( Universal:time_fix ) > NeedCommsTime ) ) assign in sequence DiveMode = DoingComms call 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" 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 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" refId="NeedComms" aggregate KeepStation { run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call 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-04-25T15:55:41.491Z,1745596541.491 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation 2025-04-25T15:55:50.909Z,1745596550.909 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250425T154825/Courier0019.lzma 2025-04-25T15:55:51.911Z,1745596551.911 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0019.lzma.bak 2025-04-25T15:55:51.911Z,1745596551.911 [DataOverHttps](INFO): SBD MOMSN=24730504 2025-04-25T15:55:54.908Z,1745596554.908 [NAL9602](INFO): SBD MO Status=1, MOMSN=24294, MT Status=0, MTMSN=0 2025-04-25T15:55:54.908Z,1745596554.908 [NAL9602](INFO): No messages in MT queue 2025-04-25T15:56:03.197Z,1745596563.197 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 30 minute 2025-04-25T15:56:03.198Z,1745596563.198 [CommandExec](IMPORTANT): got command set keepstation.Latitude 36.806966 degree 2025-04-25T15:56:03.199Z,1745596563.199 [CommandExec](IMPORTANT): got command set keepstation.Longitude -121.824326 degree 2025-04-25T15:56:03.200Z,1745596563.200 [CommandExec](IMPORTANT): got command set keepstation.Depth 10 meter 2025-04-25T15:56:03.200Z,1745596563.200 [CommandExec](IMPORTANT): got command set keepstation.ApproachDepth 10 meter 2025-04-25T15:56:06.020Z,1745596566.020 [CommandExec](IMPORTANT): got command set keepstation.MaxDepth 25 meter 2025-04-25T15:56:06.020Z,1745596566.020 [CommandExec](IMPORTANT): got command run 2025-04-25T15:56:06.022Z,1745596566.022 [CommandExec](IMPORTANT): Running 2025-04-25T15:56:06.233Z,1745596566.233 [Default] Stopped 2025-04-25T15:56:06.234Z,1745596566.234 [Default](DEBUG): Aggregate::uninitialize Default 2025-04-25T15:56:06.234Z,1745596566.234 [Default:B.GoToSurface] Stopped 2025-04-25T15:56:06.234Z,1745596566.234 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-25T15:56:06.234Z,1745596566.234 [Default:CheckIn] Stopped 2025-04-25T15:56:06.234Z,1745596566.234 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T15:56:06.234Z,1745596566.234 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T15:56:06.234Z,1745596566.234 [MissionManager](IMPORTANT): Started mission keepstation 2025-04-25T15:56:06.234Z,1745596566.234 [keepstation] Running Loop=1 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation](DEBUG): Aggregate::initialize keepstation 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes] Running Loop=1 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-04-25T15:56:06.235Z,1745596566.235 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:BackseatDriver] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly:A] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly:B] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly:C] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly:D] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly:E.Wait] Running Loop=1 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-04-25T15:56:06.236Z,1745596566.236 [keepstation:H.Pitch] Running Loop=1 2025-04-25T15:56:06.237Z,1745596566.237 [keepstation:H.Pitch](DEBUG): Initialize. 2025-04-25T15:56:06.253Z,1745596566.253 [keepstation:B] Running Loop=1 2025-04-25T15:56:06.254Z,1745596566.254 [keepstation:H.Pitch] Running Loop=1 2025-04-25T15:56:06.254Z,1745596566.254 [keepstation:PowerOnly] Running Loop=1 2025-04-25T15:56:06.254Z,1745596566.254 [keepstation:PowerOnly:D] Stopped 2025-04-25T15:56:06.254Z,1745596566.254 [keepstation:PowerOnly:C] Stopped 2025-04-25T15:56:06.255Z,1745596566.255 [keepstation:PowerOnly:B] Stopped 2025-04-25T15:56:06.255Z,1745596566.255 [keepstation:PowerOnly:A] Stopped 2025-04-25T15:56:06.255Z,1745596566.255 [keepstation:BackseatDriver] Running Loop=1 2025-04-25T15:56:06.255Z,1745596566.255 [keepstation:StandardEnvelopes] Running Loop=1 2025-04-25T15:56:06.255Z,1745596566.255 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-04-25T15:56:06.255Z,1745596566.255 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-04-25T15:56:06.256Z,1745596566.256 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-04-25T15:56:06.256Z,1745596566.256 [keepstation:B] Stopped 2025-04-25T15:56:06.256Z,1745596566.256 [keepstation:D] Running Loop=1 2025-04-25T15:56:06.639Z,1745596566.639 [keepstation:D] Stopped 2025-04-25T15:56:06.639Z,1745596566.639 [keepstation:E] Running Loop=1 2025-04-25T15:56:07.055Z,1745596567.055 [keepstation:E] Stopped 2025-04-25T15:56:07.055Z,1745596567.055 [keepstation:StartingMission] Running Loop=1 2025-04-25T15:56:07.055Z,1745596567.055 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission 2025-04-25T15:56:07.458Z,1745596567.458 [keepstation:SurfaceComms] Running Loop=1 2025-04-25T15:56:07.459Z,1745596567.459 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-04-25T15:56:07.459Z,1745596567.459 [keepstation:SurfaceComms:A] Running Loop=1 2025-04-25T15:56:07.459Z,1745596567.459 [keepstation:SurfaceComms:A] Stopped 2025-04-25T15:56:07.459Z,1745596567.459 [keepstation:SurfaceComms:B] Running Loop=1 2025-04-25T15:56:07.459Z,1745596567.459 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-04-25T15:56:07.875Z,1745596567.875 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2025-04-25T15:56:07.876Z,1745596567.876 [keepstation:NeedComms] Running Loop=1 2025-04-25T15:56:07.876Z,1745596567.876 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-04-25T15:56:07.876Z,1745596567.876 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-04-25T15:56:07.876Z,1745596567.876 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-25T15:56:07.876Z,1745596567.876 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-04-25T15:56:07.877Z,1745596567.877 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-04-25T15:56:07.881Z,1745596567.881 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-04-25T15:56:07.882Z,1745596567.882 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-04-25T15:56:07.882Z,1745596567.882 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-25T15:56:07.882Z,1745596567.882 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-25T15:56:07.883Z,1745596567.883 [keepstation:NeedComms:A] Running Loop=1 2025-04-25T15:56:07.884Z,1745596567.884 [keepstation:NeedComms:A](INFO): last time_fix was: 1745596509.000000 second since 1970/01/01T00:00:00Z 2025-04-25T15:56:07.884Z,1745596567.884 [keepstation:NeedComms:A] Stopped 2025-04-25T15:56:08.272Z,1745596568.272 [keepstation:NeedComms:C] Running Loop=1 2025-04-25T15:56:08.675Z,1745596568.675 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-25T15:56:09.856Z,1745596569.856 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-04-25T15:56:09.857Z,1745596569.857 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-04-25T15:56:09.858Z,1745596569.858 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-04-25T15:56:09.858Z,1745596569.858 [BPC1](INFO): Calculating totals. Valid battery stick count: 44. Valid reserve battery stick count: 5. 2025-04-25T15:56:09.870Z,1745596569.870 [BPC1](INFO): Received data from all battery sticks. 2025-04-25T15:56:10.260Z,1745596570.260 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155613.00,A,3647.85215,N,12150.85204,W,0.505,259.11,250425,,,D*77 2025-04-25T15:56:10.263Z,1745596570.263 [NAL9602](INFO): GPS fix at 20250425T155613: (36.797536, -121.847534) 2025-04-25T15:56:10.312Z,1745596570.312 [keepstation:NeedComms:C] Stopped 2025-04-25T15:56:10.312Z,1745596570.312 [keepstation:NeedComms:D] Running Loop=1 2025-04-25T15:56:10.729Z,1745596570.729 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-04-25T15:56:11.841Z,1745596571.841 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250425T154825/Courier0022.lzma 2025-04-25T15:56:12.844Z,1745596572.844 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0022.lzma.bak 2025-04-25T15:56:12.844Z,1745596572.844 [DataOverHttps](INFO): SBD MOMSN=24730506 2025-04-25T15:56:29.789Z,1745596589.789 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20250425T154825/Courier0025.lzma 2025-04-25T15:56:30.792Z,1745596590.792 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0025.lzma.bak 2025-04-25T15:56:30.792Z,1745596590.792 [DataOverHttps](INFO): SBD MOMSN=24730508 2025-04-25T15:56:42.226Z,1745596602.226 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T15:56:49.577Z,1745596609.577 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20250425T154825/Express0005.lzma 2025-04-25T15:56:50.579Z,1745596610.579 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0005.lzma.bak 2025-04-25T15:56:50.579Z,1745596610.579 [DataOverHttps](INFO): SBD MOMSN=24730513 2025-04-25T15:57:06.606Z,1745596626.606 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20250425T154825/Express0008.lzma 2025-04-25T15:57:07.603Z,1745596627.603 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0008.lzma.bak 2025-04-25T15:57:07.603Z,1745596627.603 [DataOverHttps](INFO): SBD MOMSN=24730516 2025-04-25T15:57:24.965Z,1745596644.965 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20250425T154825/Express0011.lzma 2025-04-25T15:57:28.979Z,1745596648.979 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0011.lzma.bak 2025-04-25T15:57:28.979Z,1745596648.979 [DataOverHttps](INFO): SBD MOMSN=24730522 2025-04-25T15:57:34.806Z,1745596654.806 [DAT](INFO): DAT read: user:6>Rx Time:15:57:34.0362 2025-04-25T15:57:34.807Z,1745596654.807 [DAT](INFO): Rx dataTimestamp_ set to:1745596654.806563 2025-04-25T15:57:34.807Z,1745596654.807 [DAT](INFO): DAT read: 2025-04-25T15:57:34.808Z,1745596654.808 [DAT](INFO): DAT read: $Packet for address 0 2025-04-25T15:57:34.808Z,1745596654.808 [DAT](INFO): received a packet notification 2025-04-25T15:57:44.957Z,1745596664.957 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20250425T154825/Express0014.lzma 2025-04-25T15:57:45.959Z,1745596665.959 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0014.lzma.bak 2025-04-25T15:57:45.959Z,1745596665.959 [DataOverHttps](INFO): SBD MOMSN=24730535 2025-04-25T15:58:05.841Z,1745596685.841 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20250425T154825/Express0017.lzma 2025-04-25T15:58:06.843Z,1745596686.843 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0017.lzma.bak 2025-04-25T15:58:06.843Z,1745596686.843 [DataOverHttps](INFO): SBD MOMSN=24730541 2025-04-25T15:58:22.833Z,1745596702.833 [DataOverHttps](INFO): Sending 311 bytes from file Logs/20250425T154825/Express0020.lzma 2025-04-25T15:58:23.835Z,1745596703.835 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0020.lzma.bak 2025-04-25T15:58:23.835Z,1745596703.835 [DataOverHttps](INFO): SBD MOMSN=24730543 2025-04-25T15:58:42.725Z,1745596722.725 [DataOverHttps](INFO): Sending 283 bytes from file Logs/20250425T154825/Express0023.lzma 2025-04-25T15:58:43.727Z,1745596723.727 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0023.lzma.bak 2025-04-25T15:58:43.727Z,1745596723.727 [DataOverHttps](INFO): SBD MOMSN=24730549 2025-04-25T15:58:59.841Z,1745596739.841 [DataOverHttps](INFO): Sending 316 bytes from file Logs/20250425T154825/Express0026.lzma 2025-04-25T15:59:00.843Z,1745596740.843 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0026.lzma.bak 2025-04-25T15:59:00.843Z,1745596740.843 [DataOverHttps](INFO): SBD MOMSN=24730556 2025-04-25T15:59:02.136Z,1745596742.136 [keepstation:NeedComms:D] Stopped 2025-04-25T15:59:02.137Z,1745596742.137 [keepstation:NeedComms:E] Running Loop=1 2025-04-25T15:59:02.548Z,1745596742.548 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-04-25T15:59:04.140Z,1745596744.140 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155908.00,A,3647.85862,N,12150.86038,W,0.622,355.78,250425,,,D*72 2025-04-25T15:59:04.143Z,1745596744.143 [NAL9602](INFO): GPS fix at 20250425T155908: (36.797644, -121.847673) 2025-04-25T15:59:04.165Z,1745596744.165 [keepstation:NeedComms:E] Stopped 2025-04-25T15:59:04.170Z,1745596744.170 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-04-25T15:59:04.170Z,1745596744.170 [keepstation:NeedComms] Stopped 2025-04-25T15:59:04.170Z,1745596744.170 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-04-25T15:59:04.170Z,1745596744.170 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-04-25T15:59:04.170Z,1745596744.170 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-25T15:59:04.573Z,1745596744.573 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-04-25T15:59:04.574Z,1745596744.574 [keepstation:SurfaceComms:B] Stopped 2025-04-25T15:59:04.574Z,1745596744.574 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-04-25T15:59:04.574Z,1745596744.574 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-04-25T15:59:04.574Z,1745596744.574 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-04-25T15:59:04.574Z,1745596744.574 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-04-25T15:59:04.978Z,1745596744.978 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-04-25T15:59:04.979Z,1745596744.979 [keepstation:SurfaceComms:setTransit](INFO): Completed keepstation:SurfaceComms:setTransit 2025-04-25T15:59:04.979Z,1745596744.979 [keepstation:SurfaceComms:setTransit] Stopped 2025-04-25T15:59:04.979Z,1745596744.979 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-04-25T15:59:04.979Z,1745596744.979 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-04-25T15:59:04.979Z,1745596744.979 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-04-25T15:59:04.979Z,1745596744.979 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-04-25T15:59:05.376Z,1745596745.376 [keepstation:SurfaceComms:setStation] Stopped 2025-04-25T15:59:05.376Z,1745596745.376 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-04-25T15:59:05.376Z,1745596745.376 [keepstation:SurfaceComms:setStation:A] Stopped 2025-04-25T15:59:05.376Z,1745596745.376 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-04-25T15:59:05.376Z,1745596745.376 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-04-25T15:59:05.376Z,1745596745.376 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-04-25T15:59:05.794Z,1745596745.794 [keepstation:SurfaceComms:setSink] Stopped 2025-04-25T15:59:05.794Z,1745596745.794 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-04-25T15:59:05.794Z,1745596745.794 [keepstation:SurfaceComms:setSink:A] Stopped 2025-04-25T15:59:05.794Z,1745596745.794 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-04-25T15:59:05.794Z,1745596745.794 [keepstation:SurfaceComms] Stopped 2025-04-25T15:59:05.794Z,1745596745.794 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:StartingMission] Stopped 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:TransitToStation] Running Loop=1 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:TransitToStation:Dive] Running Loop=1 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-04-25T15:59:06.186Z,1745596746.186 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-04-25T15:59:06.187Z,1745596746.187 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1 2025-04-25T15:59:06.187Z,1745596746.187 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2025-04-25T15:59:06.188Z,1745596746.188 [keepstation:TransitToStation:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.806965,-121.824326 2025-04-25T15:59:06.597Z,1745596746.597 [keepstation:TransitToStation:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326 2025-04-25T15:59:06.601Z,1745596746.601 [keepstation:TransitToStation:Dive] Running Loop=1 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd] Running Loop=1 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd](DEBUG): Aggregate::initialize keepstation:DiveCmd 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-04-25T15:59:06.602Z,1745596746.602 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-04-25T15:59:06.603Z,1745596746.603 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-04-25T15:59:06.604Z,1745596746.604 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:StationKeep] Stopped 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-04-25T15:59:06.610Z,1745596746.610 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-04-25T15:59:06.611Z,1745596746.611 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-04-25T15:59:06.611Z,1745596746.611 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-04-25T15:59:06.611Z,1745596746.611 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-04-25T15:59:06.611Z,1745596746.611 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-04-25T15:59:06.611Z,1745596746.611 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-04-25T15:59:06.611Z,1745596746.611 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-04-25T15:59:06.612Z,1745596746.612 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-04-25T15:59:06.612Z,1745596746.612 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-04-25T15:59:06.612Z,1745596746.612 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-04-25T15:59:06.612Z,1745596746.612 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-04-25T15:59:06.628Z,1745596746.628 [HorizontalControl](DEBUG): kpHeading = 0.400000 2025-04-25T15:59:06.628Z,1745596746.628 [HorizontalControl](DEBUG): kiHeading = 0.001000 2025-04-25T15:59:06.629Z,1745596746.629 [HorizontalControl](DEBUG): kdHeading = 0.050000 2025-04-25T15:59:39.008Z,1745596779.008 [NAL9602](INFO): SBD MO Status=2, MOMSN=24295, MT Status=2, MTMSN=0 2025-04-25T15:59:39.008Z,1745596779.008 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T16:00:08.049Z,1745596808.049 [NAL9602](INFO): SBD MO Status=1, MOMSN=24295, MT Status=0, MTMSN=0 2025-04-25T16:00:08.053Z,1745596808.053 [NAL9602](INFO): No messages in MT queue 2025-04-25T16:00:38.858Z,1745596838.858 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T16:01:33.562Z,1745596893.562 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:01:48.789Z,1745596908.789 [Radio_Surface](INFO): Powering down 2025-04-25T16:02:04.702Z,1745596924.702 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:02:05.703Z,1745596925.703 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-04-25T16:03:45.114Z,1745597025.114 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.747238 2025-04-25T16:29:04.522Z,1745598544.522 [keepstation:SurfaceComms] Running Loop=1 2025-04-25T16:29:04.523Z,1745598544.523 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-04-25T16:29:04.523Z,1745598544.523 [keepstation:SurfaceComms:A] Running Loop=1 2025-04-25T16:29:04.523Z,1745598544.523 [keepstation:SurfaceComms:A] Stopped 2025-04-25T16:29:04.523Z,1745598544.523 [keepstation:SurfaceComms:B] Running Loop=1 2025-04-25T16:29:04.523Z,1745598544.523 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-04-25T16:29:04.891Z,1745598544.891 [keepstation:TransitToStation:Dive] Stopped 2025-04-25T16:29:04.892Z,1745598544.892 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-04-25T16:29:04.892Z,1745598544.892 [keepstation:TransitToStation:Dive:A] Stopped 2025-04-25T16:29:04.892Z,1745598544.892 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-04-25T16:29:04.892Z,1745598544.892 [keepstation:DiveCmd:TransitToStation] Stopped 2025-04-25T16:29:04.892Z,1745598544.892 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-04-25T16:29:04.892Z,1745598544.892 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-04-25T16:29:04.892Z,1745598544.892 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-04-25T16:29:04.893Z,1745598544.893 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-04-25T16:29:04.893Z,1745598544.893 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-04-25T16:29:04.893Z,1745598544.893 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-04-25T16:29:04.893Z,1745598544.893 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-04-25T16:29:04.893Z,1745598544.893 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-04-25T16:29:04.895Z,1745598544.895 [keepstation:NeedComms] Running Loop=1 2025-04-25T16:29:04.895Z,1745598544.895 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-04-25T16:29:04.895Z,1745598544.895 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-04-25T16:29:04.895Z,1745598544.895 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-25T16:29:04.895Z,1745598544.895 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-04-25T16:29:04.896Z,1745598544.896 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-04-25T16:29:04.896Z,1745598544.896 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-04-25T16:29:04.896Z,1745598544.896 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-04-25T16:29:04.897Z,1745598544.897 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-25T16:29:04.897Z,1745598544.897 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-25T16:29:04.898Z,1745598544.898 [keepstation:NeedComms:A] Running Loop=1 2025-04-25T16:29:04.899Z,1745598544.899 [keepstation:NeedComms:A](INFO): last time_fix was: 1745596748.000000 second since 1970/01/01T00:00:00Z 2025-04-25T16:29:04.899Z,1745598544.899 [keepstation:NeedComms:A] Stopped 2025-04-25T16:29:54.837Z,1745598594.837 [keepstation:NeedComms:C] Running Loop=1 2025-04-25T16:29:55.301Z,1745598595.301 [Radio_Surface](INFO): Powering up 2025-04-25T16:29:57.289Z,1745598597.289 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](IMPORTANT): Altitude envelope ACTIVE. Altitude:0.370000m. At depth:0.401566m. 2025-04-25T16:30:00.757Z,1745598600.757 [DataOverHttps](INFO): Radio surface powered ON. 2025-04-25T16:30:21.492Z,1745598621.492 [NAL9602](INFO): SBD MO Status=2, MOMSN=24296, MT Status=2, MTMSN=0 2025-04-25T16:30:21.492Z,1745598621.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T16:30:30.878Z,1745598630.878 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:30:36.444Z,1745598636.444 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=24296, MT Status=1, MTMSN=809 2025-04-25T16:30:36.444Z,1745598636.444 [NAL9602](INFO): Data available in MT queue 2025-04-25T16:30:36.934Z,1745598636.934 [NAL9602](INFO): Received command: stop 2025-04-25T16:30:37.040Z,1745598637.040 [CommandExec](IMPORTANT): got command stop 2025-04-25T16:30:37.040Z,1745598637.040 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-04-25T16:30:37.281Z,1745598637.281 [MissionManager](INFO): MissionManager is completed. 2025-04-25T16:30:37.282Z,1745598637.282 [MissionManager](INFO): Uninitializing Mission keepstation 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation] Stopped 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation](DEBUG): Aggregate::uninitialize keepstation 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:NeedComms] Stopped 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:NeedComms:C] Stopped 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:StandardEnvelopes] Stopped 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-04-25T16:30:37.282Z,1745598637.282 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:BackseatDriver] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:BackseatDriver](DEBUG): Aggregate::uninitialize keepstation:BackseatDriver 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:BackseatDriver:A.BackseatDriver] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:PowerOnly] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:PowerOnly](DEBUG): Aggregate::uninitialize keepstation:PowerOnly 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:PowerOnly:E.Wait] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:H.Pitch] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:SurfaceComms] Stopped 2025-04-25T16:30:37.283Z,1745598637.283 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:SurfaceComms:B] Stopped 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:DiveCmd] Stopped 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:DiveCmd](DEBUG): Aggregate::uninitialize keepstation:DiveCmd 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:TransitToStation] Stopped 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped 2025-04-25T16:30:37.284Z,1745598637.284 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2025-04-25T16:30:37.726Z,1745598637.726 [MissionManager](IMPORTANT): Started mission Default 2025-04-25T16:30:37.726Z,1745598637.726 [Default] Running Loop=1 2025-04-25T16:30:37.727Z,1745598637.727 [Default](DEBUG): Aggregate::initialize Default 2025-04-25T16:30:37.727Z,1745598637.727 [Default:B.GoToSurface] Running Loop=1 2025-04-25T16:30:37.727Z,1745598637.727 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-04-25T16:30:37.727Z,1745598637.727 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-04-25T16:30:37.727Z,1745598637.727 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-04-25T16:30:37.728Z,1745598637.728 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-04-25T16:30:37.728Z,1745598637.728 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-04-25T16:30:37.728Z,1745598637.728 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-04-25T16:30:37.729Z,1745598637.729 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-04-25T16:30:37.733Z,1745598637.733 [Default:A.Wait] Running Loop=1 2025-04-25T16:30:37.733Z,1745598637.733 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-04-25T16:30:38.098Z,1745598638.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163042.00,A,3648.11204,N,12150.28860,W,0.408,49.43,250425,,,D*45 2025-04-25T16:30:38.104Z,1745598638.104 [NAL9602](INFO): GPS fix at 20250425T163042: (36.801867, -121.838143) 2025-04-25T16:30:38.152Z,1745598638.152 [UniversalFixResidualReporter](INFO): Fix residual: 18.8 %DT, over the last 1285.1 m. Residual distance 241.8 m at bearing 72.6 degrees. Fix at (36.8019, -121.8381) with 969.8 m made good. 2025-04-25T16:30:51.016Z,1745598651.016 [Default:A.Wait](INFO): Done Waiting. 2025-04-25T16:30:51.016Z,1745598651.016 [Default:A.Wait] Stopped 2025-04-25T16:30:51.016Z,1745598651.016 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T16:30:51.408Z,1745598651.408 [Default:CheckIn] Running Loop=1 2025-04-25T16:30:51.408Z,1745598651.408 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T16:30:51.408Z,1745598651.408 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T16:30:53.407Z,1745598653.407 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163057.00,A,3648.11286,N,12150.28854,W,0.330,75.08,250425,,,D*40 2025-04-25T16:30:53.410Z,1745598653.410 [NAL9602](INFO): GPS fix at 20250425T163057: (36.801881, -121.838142) 2025-04-25T16:30:53.435Z,1745598653.435 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T16:30:53.435Z,1745598653.435 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T16:31:02.001Z,1745598662.001 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:31:09.303Z,1745598669.303 [NAL9602](INFO): SBD MO Status=1, MOMSN=24297, MT Status=0, MTMSN=0 2025-04-25T16:31:09.354Z,1745598669.354 [NAL9602](INFO): Sent 208 bytes from file Logs/20250425T154825/Courier0028.lzma 2025-04-25T16:31:09.355Z,1745598669.355 [NAL9602](INFO): Packets left to send: 0 2025-04-25T16:31:28.816Z,1745598688.816 [NAL9602](INFO): SBD MO Status=2, MOMSN=24298, MT Status=2, MTMSN=0 2025-04-25T16:31:28.816Z,1745598688.816 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T16:31:33.126Z,1745598693.126 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:31:48.748Z,1745598708.748 [NAL9602](INFO): SBD MO Status=1, MOMSN=24298, MT Status=0, MTMSN=0 2025-04-25T16:31:48.797Z,1745598708.797 [NAL9602](INFO): Sent 332 bytes from file Logs/20250425T154825/Express0029.lzma 2025-04-25T16:31:48.797Z,1745598708.797 [NAL9602](INFO): Packets left to send: 1 2025-04-25T16:31:58.956Z,1745598718.956 [NAL9602](INFO): SBD MO Status=1, MOMSN=24299, MT Status=0, MTMSN=0 2025-04-25T16:31:59.005Z,1745598719.005 [NAL9602](INFO): Sent 252 bytes from file Logs/20250425T154825/Express0029.lzma 2025-04-25T16:31:59.005Z,1745598719.005 [NAL9602](INFO): Packets left to send: 0 2025-04-25T16:32:04.249Z,1745598724.249 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:32:07.479Z,1745598727.479 [NAL9602](INFO): SBD MO Status=0, MOMSN=24300, MT Status=0, MTMSN=0 2025-04-25T16:32:18.117Z,1745598738.117 [NAL9602](INFO): SBD MO Status=1, MOMSN=24301, MT Status=0, MTMSN=0 2025-04-25T16:32:18.165Z,1745598738.165 [NAL9602](INFO): Sent 39 bytes from file Logs/20250425T154825/Courier0031.lzma 2025-04-25T16:32:18.165Z,1745598738.165 [NAL9602](INFO): Packets left to send: 0 2025-04-25T16:32:29.567Z,1745598749.567 [NAL9602](INFO): SBD MO Status=1, MOMSN=24302, MT Status=0, MTMSN=0 2025-04-25T16:32:29.629Z,1745598749.629 [NAL9602](INFO): Sent 75 bytes from file Logs/20250425T154825/Express0032.lzma 2025-04-25T16:32:29.629Z,1745598749.629 [NAL9602](INFO): Packets left to send: 0 2025-04-25T16:32:35.377Z,1745598755.377 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:32:37.649Z,1745598757.649 [NAL9602](INFO): SBD MO Status=0, MOMSN=24303, MT Status=0, MTMSN=0 2025-04-25T16:32:37.751Z,1745598757.751 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T16:32:37.751Z,1745598757.751 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T16:32:37.751Z,1745598757.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T16:33:06.501Z,1745598786.501 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:33:08.348Z,1745598788.348 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T16:33:37.626Z,1745598817.626 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-04-25T16:33:46.355Z,1745598826.355 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006776 2025-04-25T16:37:38.231Z,1745599058.231 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T16:37:38.231Z,1745599058.231 [Default:CheckIn:C.Wait] Stopped 2025-04-25T16:37:38.231Z,1745599058.231 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T16:37:38.232Z,1745599058.232 [Default:CheckIn:D] Running Loop=1 2025-04-25T16:37:38.645Z,1745599058.645 [Default:CheckIn:D] Stopped 2025-04-25T16:37:38.645Z,1745599058.645 [Default:CheckIn:E] Running Loop=1 2025-04-25T16:37:39.054Z,1745599059.054 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.015304 min 2025-04-25T16:37:39.054Z,1745599059.054 [Default:CheckIn:E] Stopped 2025-04-25T16:37:39.054Z,1745599059.054 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T16:37:39.054Z,1745599059.054 [Default:CheckIn] Stopped 2025-04-25T16:37:39.054Z,1745599059.054 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T16:37:39.055Z,1745599059.055 [Default:CheckIn](INFO): Running loop #2 2025-04-25T16:37:39.055Z,1745599059.055 [Default:CheckIn] Running Loop=2 2025-04-25T16:37:39.055Z,1745599059.055 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T16:37:39.055Z,1745599059.055 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T16:37:41.049Z,1745599061.049 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163745.00,A,3648.12792,N,12150.31061,W,0.680,284.59,250425,,,D*77 2025-04-25T16:37:41.051Z,1745599061.051 [NAL9602](INFO): GPS fix at 20250425T163745: (36.802132, -121.838510) 2025-04-25T16:37:41.092Z,1745599061.092 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T16:37:41.092Z,1745599061.092 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T16:37:49.053Z,1745599069.053 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0034.lzma 2025-04-25T16:37:50.055Z,1745599070.055 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0034.lzma.bak 2025-04-25T16:37:50.055Z,1745599070.055 [DataOverHttps](INFO): SBD MOMSN=24730801 2025-04-25T16:37:54.788Z,1745599074.788 [NAL9602](INFO): SBD MO Status=0, MOMSN=24304, MT Status=0, MTMSN=0 2025-04-25T16:37:54.788Z,1745599074.788 [NAL9602](INFO): No messages in MT queue 2025-04-25T16:38:06.949Z,1745599086.949 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250425T154825/Express0035.lzma 2025-04-25T16:38:07.951Z,1745599087.951 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0035.lzma.bak 2025-04-25T16:38:07.951Z,1745599087.951 [DataOverHttps](INFO): SBD MOMSN=24730804 2025-04-25T16:38:09.352Z,1745599089.352 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T16:38:09.352Z,1745599089.352 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T16:38:09.352Z,1745599089.352 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T16:38:25.494Z,1745599105.494 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T16:42:46.917Z,1745599366.917 [Waterlinked](INFO): Powering down 2025-04-25T16:43:09.875Z,1745599389.875 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T16:43:09.875Z,1745599389.875 [Default:CheckIn:C.Wait] Stopped 2025-04-25T16:43:09.875Z,1745599389.875 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T16:43:09.876Z,1745599389.876 [Default:CheckIn:D] Running Loop=1 2025-04-25T16:43:10.269Z,1745599390.269 [Default:CheckIn:D] Stopped 2025-04-25T16:43:10.269Z,1745599390.269 [Default:CheckIn:E] Running Loop=1 2025-04-25T16:43:10.675Z,1745599390.675 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.542371 min 2025-04-25T16:43:10.675Z,1745599390.675 [Default:CheckIn:E] Stopped 2025-04-25T16:43:10.675Z,1745599390.675 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T16:43:10.675Z,1745599390.675 [Default:CheckIn] Stopped 2025-04-25T16:43:10.675Z,1745599390.675 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T16:43:10.675Z,1745599390.675 [Default:CheckIn](INFO): Running loop #3 2025-04-25T16:43:10.675Z,1745599390.675 [Default:CheckIn] Running Loop=3 2025-04-25T16:43:10.676Z,1745599390.676 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T16:43:10.676Z,1745599390.676 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T16:43:12.689Z,1745599392.689 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164317.00,A,3648.13775,N,12150.32669,W,0.175,128.32,250425,,,D*73 2025-04-25T16:43:12.691Z,1745599392.691 [NAL9602](INFO): GPS fix at 20250425T164317: (36.802296, -121.838778) 2025-04-25T16:43:12.702Z,1745599392.702 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T16:43:12.702Z,1745599392.702 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T16:43:20.025Z,1745599400.025 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250425T154825/Courier0037.lzma 2025-04-25T16:43:21.027Z,1745599401.027 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0037.lzma.bak 2025-04-25T16:43:21.027Z,1745599401.027 [DataOverHttps](INFO): SBD MOMSN=24730851 2025-04-25T16:43:36.933Z,1745599416.933 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250425T154825/Express0038.lzma 2025-04-25T16:43:37.935Z,1745599417.935 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0038.lzma.bak 2025-04-25T16:43:37.935Z,1745599417.935 [DataOverHttps](INFO): SBD MOMSN=24730855 2025-04-25T16:43:39.362Z,1745599419.362 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T16:43:39.362Z,1745599419.362 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T16:43:39.362Z,1745599419.362 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T16:44:16.920Z,1745599456.920 [NAL9602](INFO): SBD MO Status=2, MOMSN=24305, MT Status=2, MTMSN=0 2025-04-25T16:44:16.920Z,1745599456.920 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T16:44:52.131Z,1745599492.131 [NAL9602](INFO): SBD MO Status=0, MOMSN=24305, MT Status=0, MTMSN=0 2025-04-25T16:44:52.131Z,1745599492.131 [NAL9602](INFO): No messages in MT queue 2025-04-25T16:45:22.842Z,1745599522.842 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T16:48:40.054Z,1745599720.054 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T16:48:40.054Z,1745599720.054 [Default:CheckIn:C.Wait] Stopped 2025-04-25T16:48:40.054Z,1745599720.054 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T16:48:40.054Z,1745599720.054 [Default:CheckIn:D] Running Loop=1 2025-04-25T16:48:40.460Z,1745599720.460 [Default:CheckIn:D] Stopped 2025-04-25T16:48:40.460Z,1745599720.460 [Default:CheckIn:E] Running Loop=1 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.045563 min 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn:E] Stopped 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn] Stopped 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn](INFO): Running loop #4 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn] Running Loop=4 2025-04-25T16:48:40.859Z,1745599720.859 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T16:48:40.860Z,1745599720.860 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T16:48:42.868Z,1745599722.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164847.00,A,3648.16940,N,12150.28128,W,0.330,47.15,250425,,,D*47 2025-04-25T16:48:42.871Z,1745599722.871 [NAL9602](INFO): GPS fix at 20250425T164847: (36.802823, -121.838021) 2025-04-25T16:48:42.916Z,1745599722.916 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T16:48:42.917Z,1745599722.917 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T16:48:52.609Z,1745599732.609 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250425T154825/Courier0040.lzma 2025-04-25T16:48:54.082Z,1745599734.082 [NAL9602](INFO): SBD MO Status=0, MOMSN=24306, MT Status=0, MTMSN=0 2025-04-25T16:48:54.082Z,1745599734.082 [NAL9602](INFO): No messages in MT queue 2025-04-25T16:48:56.623Z,1745599736.623 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0040.lzma.bak 2025-04-25T16:48:56.623Z,1745599736.623 [DataOverHttps](INFO): SBD MOMSN=24730877 2025-04-25T16:49:14.669Z,1745599754.669 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20250425T154825/Express0041.lzma 2025-04-25T16:49:15.671Z,1745599755.671 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0041.lzma.bak 2025-04-25T16:49:15.672Z,1745599755.672 [DataOverHttps](INFO): SBD MOMSN=24730884 2025-04-25T16:49:17.153Z,1745599757.153 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T16:49:17.153Z,1745599757.153 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T16:49:17.153Z,1745599757.153 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T16:49:24.812Z,1745599764.812 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T16:54:17.761Z,1745600057.761 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T16:54:17.761Z,1745600057.761 [Default:CheckIn:C.Wait] Stopped 2025-04-25T16:54:17.762Z,1745600057.762 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T16:54:17.762Z,1745600057.762 [Default:CheckIn:D] Running Loop=1 2025-04-25T16:54:18.173Z,1745600058.173 [Default:CheckIn:D] Stopped 2025-04-25T16:54:18.173Z,1745600058.173 [Default:CheckIn:E] Running Loop=1 2025-04-25T16:54:18.580Z,1745600058.580 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.674101 min 2025-04-25T16:54:18.581Z,1745600058.581 [Default:CheckIn:E] Stopped 2025-04-25T16:54:18.581Z,1745600058.581 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T16:54:18.581Z,1745600058.581 [Default:CheckIn] Stopped 2025-04-25T16:54:18.581Z,1745600058.581 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T16:54:18.581Z,1745600058.581 [Default:CheckIn](INFO): Running loop #5 2025-04-25T16:54:18.581Z,1745600058.581 [Default:CheckIn] Running Loop=5 2025-04-25T16:54:18.581Z,1745600058.581 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T16:54:18.582Z,1745600058.582 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T16:54:20.580Z,1745600060.580 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165425.00,A,3648.30253,N,12149.99521,W,0.952,22.71,250425,,,D*43 2025-04-25T16:54:20.582Z,1745600060.582 [NAL9602](INFO): GPS fix at 20250425T165425: (36.805042, -121.833253) 2025-04-25T16:54:20.613Z,1745600060.613 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T16:54:20.613Z,1745600060.613 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T16:54:28.213Z,1745600068.213 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0043.lzma 2025-04-25T16:54:29.216Z,1745600069.216 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0043.lzma.bak 2025-04-25T16:54:29.216Z,1745600069.216 [DataOverHttps](INFO): SBD MOMSN=24730908 2025-04-25T16:54:42.009Z,1745600082.009 [NAL9602](INFO): SBD MO Status=0, MOMSN=24307, MT Status=0, MTMSN=0 2025-04-25T16:54:42.009Z,1745600082.009 [NAL9602](INFO): No messages in MT queue 2025-04-25T16:54:47.182Z,1745600087.182 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250425T154825/Express0044.lzma 2025-04-25T16:54:48.200Z,1745600088.200 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0044.lzma.bak 2025-04-25T16:54:48.200Z,1745600088.200 [DataOverHttps](INFO): SBD MOMSN=24730911 2025-04-25T16:54:49.728Z,1745600089.728 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T16:54:49.728Z,1745600089.728 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T16:54:49.728Z,1745600089.728 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T16:55:12.730Z,1745600112.730 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T16:58:54.925Z,1745600334.925 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T16:59:08.257Z,1745600348.257 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T16:59:21.589Z,1745600361.589 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T16:59:34.921Z,1745600374.921 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T16:59:48.658Z,1745600388.658 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T16:59:50.287Z,1745600390.287 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T16:59:50.287Z,1745600390.287 [Default:CheckIn:C.Wait] Stopped 2025-04-25T16:59:50.287Z,1745600390.287 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T16:59:50.288Z,1745600390.288 [Default:CheckIn:D] Running Loop=1 2025-04-25T16:59:50.699Z,1745600390.699 [Default:CheckIn:D] Stopped 2025-04-25T16:59:50.699Z,1745600390.699 [Default:CheckIn:E] Running Loop=1 2025-04-25T16:59:51.111Z,1745600391.111 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.216203 min 2025-04-25T16:59:51.111Z,1745600391.111 [Default:CheckIn:E] Stopped 2025-04-25T16:59:51.112Z,1745600391.112 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T16:59:51.112Z,1745600391.112 [Default:CheckIn] Stopped 2025-04-25T16:59:51.112Z,1745600391.112 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T16:59:51.112Z,1745600391.112 [Default:CheckIn](INFO): Running loop #6 2025-04-25T16:59:51.112Z,1745600391.112 [Default:CheckIn] Running Loop=6 2025-04-25T16:59:51.112Z,1745600391.112 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T16:59:51.112Z,1745600391.112 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T16:59:53.112Z,1745600393.112 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165957.00,A,3648.15491,N,12149.44982,W,26.281,112.05,250425,,,D*41 2025-04-25T16:59:53.115Z,1745600393.115 [NAL9602](INFO): GPS fix at 20250425T165957: (36.802582, -121.824164) 2025-04-25T16:59:53.126Z,1745600393.126 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T16:59:53.126Z,1745600393.126 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:00:01.717Z,1745600401.717 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0046.lzma 2025-04-25T17:00:02.395Z,1745600402.395 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T17:00:02.719Z,1745600402.719 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0046.lzma.bak 2025-04-25T17:00:02.719Z,1745600402.719 [DataOverHttps](INFO): SBD MOMSN=24730938 2025-04-25T17:00:07.248Z,1745600407.248 [NAL9602](INFO): SBD MO Status=0, MOMSN=24308, MT Status=0, MTMSN=0 2025-04-25T17:00:07.248Z,1745600407.248 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:00:16.129Z,1745600416.129 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T17:00:21.523Z,1745600421.523 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250425T154825/Express0047.lzma 2025-04-25T17:00:22.523Z,1745600422.523 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0047.lzma.bak 2025-04-25T17:00:22.523Z,1745600422.523 [DataOverHttps](INFO): SBD MOMSN=24730941 2025-04-25T17:00:23.826Z,1745600423.826 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:00:23.826Z,1745600423.826 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:00:23.826Z,1745600423.826 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:00:30.269Z,1745600430.269 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T17:00:37.954Z,1745600437.954 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:00:44.409Z,1745600444.409 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T17:00:58.550Z,1745600458.550 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T17:03:34.903Z,1745600614.903 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T17:03:34.910Z,1745600614.910 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-04-25T17:03:34.911Z,1745600614.911 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-04-25T17:03:34.912Z,1745600614.912 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-04-25T17:03:34.912Z,1745600614.912 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 5. 2025-04-25T17:03:34.935Z,1745600614.935 [BPC1](INFO): Received data from all battery sticks. 2025-04-25T17:05:24.394Z,1745600724.394 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:05:24.394Z,1745600724.394 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:05:24.394Z,1745600724.394 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:05:24.395Z,1745600724.395 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:05:24.800Z,1745600724.800 [Default:CheckIn:D] Stopped 2025-04-25T17:05:24.801Z,1745600724.801 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:05:25.203Z,1745600725.203 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.784566 min 2025-04-25T17:05:25.203Z,1745600725.203 [Default:CheckIn:E] Stopped 2025-04-25T17:05:25.203Z,1745600725.203 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:05:25.204Z,1745600725.204 [Default:CheckIn] Stopped 2025-04-25T17:05:25.204Z,1745600725.204 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:05:25.204Z,1745600725.204 [Default:CheckIn](INFO): Running loop #7 2025-04-25T17:05:25.204Z,1745600725.204 [Default:CheckIn] Running Loop=7 2025-04-25T17:05:25.204Z,1745600725.204 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:05:25.204Z,1745600725.204 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:05:27.212Z,1745600727.212 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170531.00,A,3648.44329,N,12147.29735,W,4.937,46.56,250425,,,D*4E 2025-04-25T17:05:27.214Z,1745600727.214 [NAL9602](INFO): GPS fix at 20250425T170531: (36.807388, -121.788289) 2025-04-25T17:05:27.226Z,1745600727.226 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:05:27.226Z,1745600727.226 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:05:34.817Z,1745600734.817 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20250425T154825/Courier0049.lzma 2025-04-25T17:05:35.820Z,1745600735.820 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0049.lzma.bak 2025-04-25T17:05:35.820Z,1745600735.820 [DataOverHttps](INFO): SBD MOMSN=24730961 2025-04-25T17:05:48.632Z,1745600748.632 [NAL9602](INFO): SBD MO Status=0, MOMSN=24309, MT Status=0, MTMSN=0 2025-04-25T17:05:48.632Z,1745600748.632 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:05:52.717Z,1745600752.717 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20250425T154825/Express0050.lzma 2025-04-25T17:05:53.719Z,1745600753.719 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0050.lzma.bak 2025-04-25T17:05:53.719Z,1745600753.719 [DataOverHttps](INFO): SBD MOMSN=24730964 2025-04-25T17:05:55.128Z,1745600755.128 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:05:55.128Z,1745600755.128 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:05:55.128Z,1745600755.128 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:06:19.334Z,1745600779.334 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:10:55.685Z,1745601055.685 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:10:55.705Z,1745601055.705 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:10:55.705Z,1745601055.705 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:10:55.705Z,1745601055.705 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:10:56.120Z,1745601056.120 [Default:CheckIn:D] Stopped 2025-04-25T17:10:56.120Z,1745601056.120 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:10:56.491Z,1745601056.491 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.306555 min 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn:E] Stopped 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn] Stopped 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn](INFO): Running loop #8 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn] Running Loop=8 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:10:56.492Z,1745601056.492 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:10:58.500Z,1745601058.500 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171103.00,A,3648.23091,N,12147.14646,W,4.199,195.80,250425,,,D*78 2025-04-25T17:10:58.512Z,1745601058.512 [NAL9602](INFO): GPS fix at 20250425T171103: (36.803849, -121.785774) 2025-04-25T17:10:58.528Z,1745601058.528 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:10:58.528Z,1745601058.528 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:11:05.861Z,1745601065.861 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0052.lzma 2025-04-25T17:11:06.863Z,1745601066.863 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0052.lzma.bak 2025-04-25T17:11:06.863Z,1745601066.863 [DataOverHttps](INFO): SBD MOMSN=24730989 2025-04-25T17:11:22.737Z,1745601082.737 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20250425T154825/Express0053.lzma 2025-04-25T17:11:23.739Z,1745601083.739 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0053.lzma.bak 2025-04-25T17:11:23.739Z,1745601083.739 [DataOverHttps](INFO): SBD MOMSN=24730992 2025-04-25T17:11:25.164Z,1745601085.164 [NAL9602](INFO): SBD MO Status=2, MOMSN=24310, MT Status=2, MTMSN=0 2025-04-25T17:11:25.164Z,1745601085.164 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:11:25.192Z,1745601085.192 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:11:25.192Z,1745601085.192 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:11:25.192Z,1745601085.192 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:11:49.412Z,1745601109.412 [NAL9602](INFO): SBD MO Status=2, MOMSN=24310, MT Status=2, MTMSN=0 2025-04-25T17:11:49.412Z,1745601109.412 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:11:59.104Z,1745601119.104 [NAL9602](INFO): SBD MO Status=0, MOMSN=24310, MT Status=0, MTMSN=0 2025-04-25T17:11:59.104Z,1745601119.104 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:12:29.802Z,1745601149.802 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:16:25.820Z,1745601385.820 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:16:25.820Z,1745601385.820 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:16:25.820Z,1745601385.820 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:16:25.821Z,1745601385.821 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:16:26.216Z,1745601386.216 [Default:CheckIn:D] Stopped 2025-04-25T17:16:26.216Z,1745601386.216 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:16:26.625Z,1745601386.625 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.808167 min 2025-04-25T17:16:26.625Z,1745601386.625 [Default:CheckIn:E] Stopped 2025-04-25T17:16:26.625Z,1745601386.625 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:16:26.625Z,1745601386.625 [Default:CheckIn] Stopped 2025-04-25T17:16:26.625Z,1745601386.625 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:16:26.625Z,1745601386.625 [Default:CheckIn](INFO): Running loop #9 2025-04-25T17:16:26.626Z,1745601386.626 [Default:CheckIn] Running Loop=9 2025-04-25T17:16:26.626Z,1745601386.626 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:16:26.626Z,1745601386.626 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:16:28.631Z,1745601388.631 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171633.00,A,3648.15200,N,12147.22042,W,0.078,196.27,250425,,,D*70 2025-04-25T17:16:28.633Z,1745601388.633 [NAL9602](INFO): GPS fix at 20250425T171633: (36.802533, -121.787007) 2025-04-25T17:16:28.644Z,1745601388.644 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:16:28.644Z,1745601388.644 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:16:36.129Z,1745601396.129 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0055.lzma 2025-04-25T17:16:37.131Z,1745601397.131 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0055.lzma.bak 2025-04-25T17:16:37.131Z,1745601397.131 [DataOverHttps](INFO): SBD MOMSN=24731010 2025-04-25T17:16:41.156Z,1745601401.156 [NAL9602](INFO): SBD MO Status=0, MOMSN=24311, MT Status=0, MTMSN=0 2025-04-25T17:16:41.156Z,1745601401.156 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:16:56.569Z,1745601416.569 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20250425T154825/Express0056.lzma 2025-04-25T17:16:58.575Z,1745601418.575 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0056.lzma.bak 2025-04-25T17:16:58.575Z,1745601418.575 [DataOverHttps](INFO): SBD MOMSN=24731013 2025-04-25T17:17:00.190Z,1745601420.190 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:17:00.190Z,1745601420.190 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:17:00.190Z,1745601420.190 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:17:11.894Z,1745601431.894 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:22:00.766Z,1745601720.766 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:22:00.766Z,1745601720.766 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:22:00.766Z,1745601720.766 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:22:00.767Z,1745601720.767 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:22:01.177Z,1745601721.177 [Default:CheckIn:D] Stopped 2025-04-25T17:22:01.177Z,1745601721.177 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.390849 min 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn:E] Stopped 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn] Stopped 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn](INFO): Running loop #10 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn] Running Loop=10 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:22:01.571Z,1745601721.571 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:22:03.582Z,1745601723.582 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172208.00,A,3648.13976,N,12147.22920,W,0.019,134.23,250425,,,D*75 2025-04-25T17:22:03.584Z,1745601723.584 [NAL9602](INFO): GPS fix at 20250425T172208: (36.802329, -121.787153) 2025-04-25T17:22:03.595Z,1745601723.595 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:22:03.595Z,1745601723.595 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:22:12.501Z,1745601732.501 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250425T154825/Courier0058.lzma 2025-04-25T17:22:13.503Z,1745601733.503 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0058.lzma.bak 2025-04-25T17:22:13.503Z,1745601733.503 [DataOverHttps](INFO): SBD MOMSN=24731038 2025-04-25T17:22:27.816Z,1745601747.816 [NAL9602](INFO): SBD MO Status=0, MOMSN=24312, MT Status=0, MTMSN=0 2025-04-25T17:22:27.816Z,1745601747.816 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:22:29.441Z,1745601749.441 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20250425T154825/Express0059.lzma 2025-04-25T17:22:30.443Z,1745601750.443 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0059.lzma.bak 2025-04-25T17:22:30.443Z,1745601750.443 [DataOverHttps](INFO): SBD MOMSN=24731041 2025-04-25T17:22:31.874Z,1745601751.874 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:22:31.874Z,1745601751.874 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:22:31.875Z,1745601751.875 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:22:58.519Z,1745601778.519 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:27:32.445Z,1745602052.445 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:27:32.445Z,1745602052.445 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:27:32.445Z,1745602052.445 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:27:32.445Z,1745602052.445 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:27:32.849Z,1745602052.849 [Default:CheckIn:D] Stopped 2025-04-25T17:27:32.849Z,1745602052.849 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.918705 min 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn:E] Stopped 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn] Stopped 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn](INFO): Running loop #11 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn] Running Loop=11 2025-04-25T17:27:33.256Z,1745602053.256 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:27:33.257Z,1745602053.257 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:27:35.264Z,1745602055.264 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172739.00,A,3648.13897,N,12147.22715,W,0.019,134.23,250425,,,D*74 2025-04-25T17:27:35.275Z,1745602055.275 [NAL9602](INFO): GPS fix at 20250425T172739: (36.802316, -121.787119) 2025-04-25T17:27:35.286Z,1745602055.286 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:27:35.286Z,1745602055.286 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:27:42.849Z,1745602062.849 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0061.lzma 2025-04-25T17:27:43.851Z,1745602063.851 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0061.lzma.bak 2025-04-25T17:27:43.851Z,1745602063.851 [DataOverHttps](INFO): SBD MOMSN=24731059 2025-04-25T17:27:52.236Z,1745602072.236 [NAL9602](INFO): SBD MO Status=0, MOMSN=24313, MT Status=0, MTMSN=0 2025-04-25T17:27:52.236Z,1745602072.236 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:27:59.801Z,1745602079.801 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250425T154825/Express0062.lzma 2025-04-25T17:28:00.803Z,1745602080.803 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0062.lzma.bak 2025-04-25T17:28:00.803Z,1745602080.803 [DataOverHttps](INFO): SBD MOMSN=24731064 2025-04-25T17:28:02.350Z,1745602082.350 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:28:02.350Z,1745602082.350 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:28:02.350Z,1745602082.350 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:28:22.934Z,1745602102.934 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:33:02.927Z,1745602382.927 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:33:02.927Z,1745602382.927 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:33:02.927Z,1745602382.927 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:33:02.927Z,1745602382.927 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:33:03.322Z,1745602383.322 [Default:CheckIn:D] Stopped 2025-04-25T17:33:03.322Z,1745602383.322 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:33:03.729Z,1745602383.729 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.426587 min 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn:E] Stopped 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn] Stopped 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn](INFO): Running loop #12 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn] Running Loop=12 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:33:03.730Z,1745602383.730 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:33:05.739Z,1745602385.739 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173310.00,A,3648.17608,N,12147.28024,W,0.603,260.22,250425,,,D*77 2025-04-25T17:33:05.741Z,1745602385.741 [NAL9602](INFO): GPS fix at 20250425T173310: (36.802935, -121.788004) 2025-04-25T17:33:05.752Z,1745602385.752 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:33:05.752Z,1745602385.752 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:33:13.153Z,1745602393.153 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0064.lzma 2025-04-25T17:33:14.155Z,1745602394.155 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0064.lzma.bak 2025-04-25T17:33:14.155Z,1745602394.155 [DataOverHttps](INFO): SBD MOMSN=24731088 2025-04-25T17:33:32.105Z,1745602412.105 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20250425T154825/Express0065.lzma 2025-04-25T17:33:37.123Z,1745602417.123 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0065.lzma.bak 2025-04-25T17:33:37.123Z,1745602417.123 [DataOverHttps](INFO): SBD MOMSN=24731094 2025-04-25T17:33:38.502Z,1745602418.502 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:33:38.503Z,1745602418.503 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:33:38.503Z,1745602418.503 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:33:40.488Z,1745602420.488 [NAL9602](INFO): SBD MO Status=2, MOMSN=24314, MT Status=2, MTMSN=0 2025-04-25T17:33:40.488Z,1745602420.488 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:36:34.213Z,1745602594.213 [NAL9602](INFO): SBD MO Status=2, MOMSN=24314, MT Status=2, MTMSN=0 2025-04-25T17:36:34.214Z,1745602594.214 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:36:55.692Z,1745602615.692 [NAL9602](INFO): SBD MO Status=2, MOMSN=24314, MT Status=2, MTMSN=0 2025-04-25T17:36:55.693Z,1745602615.693 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:37:13.446Z,1745602633.446 [DAT](INFO): DAT read: Rx Time:17:37:12.8435 2025-04-25T17:37:13.447Z,1745602633.447 [DAT](INFO): Rx dataTimestamp_ set to:1745602633.446353 2025-04-25T17:37:14.454Z,1745602634.454 [DAT](INFO): DAT read: $Error in header 2025-04-25T17:37:14.454Z,1745602634.454 [DAT](INFO): Received a bad header 2025-04-25T17:37:23.961Z,1745602643.961 [NAL9602](INFO): SBD MO Status=0, MOMSN=24314, MT Status=0, MTMSN=0 2025-04-25T17:37:23.961Z,1745602643.961 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:37:54.670Z,1745602674.670 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:38:39.114Z,1745602719.114 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:38:39.114Z,1745602719.114 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:38:39.114Z,1745602719.114 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:38:39.114Z,1745602719.114 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:38:39.525Z,1745602719.525 [Default:CheckIn:D] Stopped 2025-04-25T17:38:39.525Z,1745602719.525 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.029968 min 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn:E] Stopped 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn] Stopped 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn](INFO): Running loop #13 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn] Running Loop=13 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:38:39.934Z,1745602719.934 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:38:41.932Z,1745602721.932 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173846.00,A,3648.17700,N,12147.27968,W,0.408,312.47,250425,,,D*76 2025-04-25T17:38:41.935Z,1745602721.935 [NAL9602](INFO): GPS fix at 20250425T173846: (36.802950, -121.787995) 2025-04-25T17:38:41.946Z,1745602721.946 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:38:41.946Z,1745602721.946 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:38:53.773Z,1745602733.773 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0067.lzma 2025-04-25T17:38:54.775Z,1745602734.775 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0067.lzma.bak 2025-04-25T17:38:54.775Z,1745602734.775 [DataOverHttps](INFO): SBD MOMSN=24731117 2025-04-25T17:39:04.691Z,1745602744.691 [NAL9602](INFO): SBD MO Status=2, MOMSN=24315, MT Status=2, MTMSN=0 2025-04-25T17:39:04.692Z,1745602744.692 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:39:13.689Z,1745602753.689 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250425T154825/Express0068.lzma 2025-04-25T17:39:14.691Z,1745602754.691 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0068.lzma.bak 2025-04-25T17:39:14.691Z,1745602754.691 [DataOverHttps](INFO): SBD MOMSN=24731123 2025-04-25T17:39:16.043Z,1745602756.043 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:39:16.043Z,1745602756.043 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:39:16.043Z,1745602756.043 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:39:25.717Z,1745602765.717 [NAL9602](INFO): SBD MO Status=0, MOMSN=24315, MT Status=0, MTMSN=0 2025-04-25T17:39:25.717Z,1745602765.717 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:39:56.431Z,1745602796.431 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:44:16.616Z,1745603056.616 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:44:16.617Z,1745603056.617 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:44:16.617Z,1745603056.617 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:44:16.633Z,1745603056.633 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:44:17.017Z,1745603057.017 [Default:CheckIn:D] Stopped 2025-04-25T17:44:17.017Z,1745603057.017 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:44:17.425Z,1745603057.425 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.654834 min 2025-04-25T17:44:17.425Z,1745603057.425 [Default:CheckIn:E] Stopped 2025-04-25T17:44:17.425Z,1745603057.425 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:44:17.425Z,1745603057.425 [Default:CheckIn] Stopped 2025-04-25T17:44:17.425Z,1745603057.425 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:44:17.426Z,1745603057.426 [Default:CheckIn](INFO): Running loop #14 2025-04-25T17:44:17.426Z,1745603057.426 [Default:CheckIn] Running Loop=14 2025-04-25T17:44:17.426Z,1745603057.426 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:44:17.426Z,1745603057.426 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:44:19.440Z,1745603059.440 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174424.00,A,3648.17927,N,12147.27863,W,0.097,312.47,250425,,,A*7F 2025-04-25T17:44:19.442Z,1745603059.442 [NAL9602](INFO): GPS fix at 20250425T174424: (36.802988, -121.787977) 2025-04-25T17:44:19.454Z,1745603059.454 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:44:19.454Z,1745603059.454 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:44:27.441Z,1745603067.441 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250425T154825/Courier0070.lzma 2025-04-25T17:44:28.443Z,1745603068.443 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0070.lzma.bak 2025-04-25T17:44:28.443Z,1745603068.443 [DataOverHttps](INFO): SBD MOMSN=24731147 2025-04-25T17:44:47.865Z,1745603087.865 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250425T154825/Express0071.lzma 2025-04-25T17:44:48.867Z,1745603088.867 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0071.lzma.bak 2025-04-25T17:44:48.867Z,1745603088.867 [DataOverHttps](INFO): SBD MOMSN=24731167 2025-04-25T17:44:50.192Z,1745603090.192 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:44:50.192Z,1745603090.192 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:44:50.192Z,1745603090.192 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:45:28.956Z,1745603128.956 [NAL9602](INFO): SBD MO Status=2, MOMSN=24316, MT Status=2, MTMSN=0 2025-04-25T17:45:28.956Z,1745603128.956 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:45:55.616Z,1745603155.616 [NAL9602](INFO): SBD MO Status=0, MOMSN=24316, MT Status=0, MTMSN=0 2025-04-25T17:45:55.616Z,1745603155.616 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:46:26.318Z,1745603186.318 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:48:43.686Z,1745603323.686 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-04-25T17:48:43.687Z,1745603323.687 [DropWeight] Hardware Fault, FailCount= 1 2025-04-25T17:48:43.687Z,1745603323.687 [DropWeight](ERROR): Hardware Fault 2025-04-25T17:48:43.707Z,1745603323.707 [CommandExec](FAULT): Scheduling is paused 2025-04-25T17:48:43.708Z,1745603323.708 [CBIT](INFO): Critical error at 20250425T174843 2025-04-25T17:48:43.710Z,1745603323.710 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-04-25T17:48:43.711Z,1745603323.711 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-04-25T17:48:44.118Z,1745603324.118 [CBIT](INFO): Critical error at 20250425T174843 2025-04-25T17:49:50.774Z,1745603390.774 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:49:50.774Z,1745603390.774 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:49:50.774Z,1745603390.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:49:50.775Z,1745603390.775 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:49:51.172Z,1745603391.172 [Default:CheckIn:D] Stopped 2025-04-25T17:49:51.172Z,1745603391.172 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:49:51.570Z,1745603391.570 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.224097 min 2025-04-25T17:49:51.570Z,1745603391.570 [Default:CheckIn:E] Stopped 2025-04-25T17:49:51.571Z,1745603391.571 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:49:51.571Z,1745603391.571 [Default:CheckIn] Stopped 2025-04-25T17:49:51.571Z,1745603391.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:49:51.571Z,1745603391.571 [Default:CheckIn](INFO): Running loop #15 2025-04-25T17:49:51.571Z,1745603391.571 [Default:CheckIn] Running Loop=15 2025-04-25T17:49:51.571Z,1745603391.571 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:49:51.571Z,1745603391.571 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:49:53.582Z,1745603393.582 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174958.00,A,3648.17719,N,12147.28010,W,0.117,222.38,250425,,,A*7A 2025-04-25T17:49:53.584Z,1745603393.584 [NAL9602](INFO): GPS fix at 20250425T174958: (36.802953, -121.788002) 2025-04-25T17:49:53.595Z,1745603393.595 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:49:53.595Z,1745603393.595 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:50:02.641Z,1745603402.641 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20250425T154825/Courier0073.lzma 2025-04-25T17:50:03.643Z,1745603403.643 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0073.lzma.bak 2025-04-25T17:50:03.643Z,1745603403.643 [DataOverHttps](INFO): SBD MOMSN=24731195 2025-04-25T17:50:19.509Z,1745603419.509 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20250425T154825/Express0074.lzma 2025-04-25T17:50:20.511Z,1745603420.511 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0074.lzma.bak 2025-04-25T17:50:20.511Z,1745603420.511 [DataOverHttps](INFO): SBD MOMSN=24731209 2025-04-25T17:50:21.918Z,1745603421.918 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:50:21.918Z,1745603421.918 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:50:21.918Z,1745603421.918 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:50:36.445Z,1745603436.445 [NAL9602](INFO): SBD MO Status=2, MOMSN=24317, MT Status=2, MTMSN=0 2025-04-25T17:50:36.445Z,1745603436.445 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:51:01.897Z,1745603461.897 [NAL9602](INFO): SBD MO Status=2, MOMSN=24317, MT Status=2, MTMSN=0 2025-04-25T17:51:01.897Z,1745603461.897 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:51:55.225Z,1745603515.225 [NAL9602](INFO): SBD MO Status=0, MOMSN=24317, MT Status=0, MTMSN=0 2025-04-25T17:51:55.225Z,1745603515.225 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:52:25.934Z,1745603545.934 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T17:55:22.484Z,1745603722.484 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T17:55:22.484Z,1745603722.484 [Default:CheckIn:C.Wait] Stopped 2025-04-25T17:55:22.484Z,1745603722.484 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T17:55:22.485Z,1745603722.485 [Default:CheckIn:D] Running Loop=1 2025-04-25T17:55:22.898Z,1745603722.898 [Default:CheckIn:D] Stopped 2025-04-25T17:55:22.898Z,1745603722.898 [Default:CheckIn:E] Running Loop=1 2025-04-25T17:55:23.307Z,1745603723.307 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.752856 min 2025-04-25T17:55:23.307Z,1745603723.307 [Default:CheckIn:E] Stopped 2025-04-25T17:55:23.307Z,1745603723.307 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T17:55:23.307Z,1745603723.307 [Default:CheckIn] Stopped 2025-04-25T17:55:23.307Z,1745603723.307 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T17:55:23.308Z,1745603723.308 [Default:CheckIn](INFO): Running loop #16 2025-04-25T17:55:23.308Z,1745603723.308 [Default:CheckIn] Running Loop=16 2025-04-25T17:55:23.308Z,1745603723.308 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T17:55:23.308Z,1745603723.308 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T17:55:25.305Z,1745603725.305 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175529.00,A,3648.17612,N,12147.27972,W,0.214,222.38,250425,,,A*79 2025-04-25T17:55:25.307Z,1745603725.307 [NAL9602](INFO): GPS fix at 20250425T175529: (36.802935, -121.787995) 2025-04-25T17:55:25.318Z,1745603725.318 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T17:55:25.319Z,1745603725.319 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T17:55:32.677Z,1745603732.677 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0076.lzma 2025-04-25T17:55:34.683Z,1745603734.683 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0076.lzma.bak 2025-04-25T17:55:34.683Z,1745603734.683 [DataOverHttps](INFO): SBD MOMSN=24731235 2025-04-25T17:55:47.927Z,1745603747.927 [NAL9602](INFO): SBD MO Status=2, MOMSN=24318, MT Status=2, MTMSN=0 2025-04-25T17:55:47.927Z,1745603747.927 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T17:55:57.624Z,1745603757.624 [NAL9602](INFO): SBD MO Status=0, MOMSN=24318, MT Status=0, MTMSN=0 2025-04-25T17:55:57.624Z,1745603757.624 [NAL9602](INFO): No messages in MT queue 2025-04-25T17:56:00.733Z,1745603760.733 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20250425T154825/Express0077.lzma 2025-04-25T17:56:03.743Z,1745603763.743 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0077.lzma.bak 2025-04-25T17:56:03.743Z,1745603763.743 [DataOverHttps](INFO): SBD MOMSN=24731244 2025-04-25T17:56:05.316Z,1745603765.316 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T17:56:05.316Z,1745603765.316 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T17:56:05.316Z,1745603765.316 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T17:56:28.328Z,1745603788.328 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T18:01:05.888Z,1745604065.888 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T18:01:05.888Z,1745604065.888 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:01:05.888Z,1745604065.888 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:01:05.889Z,1745604065.889 [Default:CheckIn:D] Running Loop=1 2025-04-25T18:01:06.298Z,1745604066.298 [Default:CheckIn:D] Stopped 2025-04-25T18:01:06.298Z,1745604066.298 [Default:CheckIn:E] Running Loop=1 2025-04-25T18:01:06.713Z,1745604066.713 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.476188 min 2025-04-25T18:01:06.713Z,1745604066.713 [Default:CheckIn:E] Stopped 2025-04-25T18:01:06.713Z,1745604066.713 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T18:01:06.713Z,1745604066.713 [Default:CheckIn] Stopped 2025-04-25T18:01:06.713Z,1745604066.713 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:01:06.714Z,1745604066.714 [Default:CheckIn](INFO): Running loop #17 2025-04-25T18:01:06.714Z,1745604066.714 [Default:CheckIn] Running Loop=17 2025-04-25T18:01:06.714Z,1745604066.714 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T18:01:06.714Z,1745604066.714 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T18:01:08.704Z,1745604068.704 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180113.00,A,3648.17834,N,12147.28007,W,0.350,182.62,250425,,,A*77 2025-04-25T18:01:08.707Z,1745604068.707 [NAL9602](INFO): GPS fix at 20250425T180113: (36.802972, -121.788001) 2025-04-25T18:01:08.718Z,1745604068.718 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T18:01:08.718Z,1745604068.718 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T18:01:18.915Z,1745604078.915 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250425T154825/Courier0079.lzma 2025-04-25T18:01:23.931Z,1745604083.931 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0079.lzma.bak 2025-04-25T18:01:23.931Z,1745604083.931 [DataOverHttps](INFO): SBD MOMSN=24731304 2025-04-25T18:01:42.957Z,1745604102.957 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250425T154825/Express0080.lzma 2025-04-25T18:01:49.983Z,1745604109.983 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0080.lzma.bak 2025-04-25T18:01:49.983Z,1745604109.983 [DataOverHttps](INFO): SBD MOMSN=24731310 2025-04-25T18:01:51.543Z,1745604111.543 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T18:01:51.543Z,1745604111.543 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T18:01:51.543Z,1745604111.543 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T18:02:00.016Z,1745604120.016 [NAL9602](INFO): SBD MO Status=2, MOMSN=24319, MT Status=2, MTMSN=0 2025-04-25T18:02:00.016Z,1745604120.016 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T18:02:37.598Z,1745604157.598 [NAL9602](INFO): SBD MO Status=0, MOMSN=24319, MT Status=0, MTMSN=0 2025-04-25T18:02:37.598Z,1745604157.598 [NAL9602](INFO): No messages in MT queue 2025-04-25T18:03:08.290Z,1745604188.290 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T18:03:43.874Z,1745604223.874 [CBIT](INFO): Clearing failed state for component DropWeight 2025-04-25T18:03:43.874Z,1745604223.874 [DropWeight] No Fault, FailCount= 1 2025-04-25T18:04:41.609Z,1745604281.609 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:04:54.949Z,1745604294.949 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:05:08.284Z,1745604308.284 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:05:21.613Z,1745604321.613 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:05:35.365Z,1745604335.365 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:05:49.507Z,1745604349.507 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:06:03.241Z,1745604363.241 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:06:17.382Z,1745604377.382 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:06:31.118Z,1745604391.118 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:06:44.859Z,1745604404.859 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:06:52.161Z,1745604412.161 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T18:06:52.161Z,1745604412.161 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:06:52.161Z,1745604412.161 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:06:52.161Z,1745604412.161 [Default:CheckIn:D] Running Loop=1 2025-04-25T18:06:52.577Z,1745604412.577 [Default:CheckIn:D] Stopped 2025-04-25T18:06:52.577Z,1745604412.577 [Default:CheckIn:E] Running Loop=1 2025-04-25T18:06:52.965Z,1745604412.965 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.247510 min 2025-04-25T18:06:52.965Z,1745604412.965 [Default:CheckIn:E] Stopped 2025-04-25T18:06:52.965Z,1745604412.965 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T18:06:52.965Z,1745604412.965 [Default:CheckIn] Stopped 2025-04-25T18:06:52.965Z,1745604412.965 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:06:52.965Z,1745604412.965 [Default:CheckIn](INFO): Running loop #18 2025-04-25T18:06:52.966Z,1745604412.966 [Default:CheckIn] Running Loop=18 2025-04-25T18:06:52.966Z,1745604412.966 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T18:06:52.966Z,1745604412.966 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T18:06:54.967Z,1745604414.967 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180659.00,A,3648.16657,N,12147.28067,W,0.875,289.50,250425,,,A*77 2025-04-25T18:06:54.970Z,1745604414.970 [NAL9602](INFO): GPS fix at 20250425T180659: (36.802776, -121.788011) 2025-04-25T18:06:54.981Z,1745604414.981 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T18:06:54.981Z,1745604414.981 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T18:07:02.721Z,1745604422.721 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0082.lzma 2025-04-25T18:07:03.723Z,1745604423.723 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0082.lzma.bak 2025-04-25T18:07:03.723Z,1745604423.723 [DataOverHttps](INFO): SBD MOMSN=24731334 2025-04-25T18:07:19.637Z,1745604439.637 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20250425T154825/Express0083.lzma 2025-04-25T18:07:20.639Z,1745604440.639 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0083.lzma.bak 2025-04-25T18:07:20.639Z,1745604440.639 [DataOverHttps](INFO): SBD MOMSN=24731337 2025-04-25T18:07:22.043Z,1745604442.043 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T18:07:22.043Z,1745604442.043 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T18:07:22.043Z,1745604442.043 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T18:07:24.452Z,1745604444.452 [NAL9602](INFO): SBD MO Status=2, MOMSN=24320, MT Status=2, MTMSN=0 2025-04-25T18:07:24.452Z,1745604444.452 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T18:09:07.941Z,1745604547.941 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:09:14.341Z,1745604554.341 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:09:29.687Z,1745604569.687 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:09:44.635Z,1745604584.635 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:10:00.800Z,1745604600.800 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:10:15.741Z,1745604615.741 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:10:30.689Z,1745604630.689 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:10:30.690Z,1745604630.690 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2025-04-25T18:10:46.041Z,1745604646.041 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:10:53.780Z,1745604653.780 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2025-04-25T18:11:01.001Z,1745604661.001 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:11:15.936Z,1745604675.936 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-04-25T18:11:30.892Z,1745604690.892 [BPC1](FAULT): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-04-25T18:11:30.893Z,1745604690.893 [BPC1](FAULT): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-04-25T18:11:30.894Z,1745604690.894 [BPC1](FAULT): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-04-25T18:11:30.895Z,1745604690.895 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 5. 2025-04-25T18:11:30.901Z,1745604690.901 [BPC1](INFO): Received data from all battery sticks. 2025-04-25T18:11:57.147Z,1745604717.147 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-25T18:12:22.610Z,1745604742.610 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T18:12:22.610Z,1745604742.610 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:12:22.610Z,1745604742.610 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:12:22.611Z,1745604742.611 [Default:CheckIn:D] Running Loop=1 2025-04-25T18:12:23.014Z,1745604743.014 [Default:CheckIn:D] Stopped 2025-04-25T18:12:23.014Z,1745604743.014 [Default:CheckIn:E] Running Loop=1 2025-04-25T18:12:23.427Z,1745604743.427 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.754793 min 2025-04-25T18:12:23.427Z,1745604743.427 [Default:CheckIn:E] Stopped 2025-04-25T18:12:23.427Z,1745604743.427 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T18:12:23.427Z,1745604743.427 [Default:CheckIn] Stopped 2025-04-25T18:12:23.427Z,1745604743.427 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:12:23.427Z,1745604743.427 [Default:CheckIn](INFO): Running loop #19 2025-04-25T18:12:23.427Z,1745604743.427 [Default:CheckIn] Running Loop=19 2025-04-25T18:12:23.428Z,1745604743.428 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T18:12:23.428Z,1745604743.428 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T18:12:25.432Z,1745604745.432 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181230.00,A,3648.16783,N,12147.26798,W,0.330,306.01,250425,,,A*74 2025-04-25T18:12:25.434Z,1745604745.434 [NAL9602](INFO): GPS fix at 20250425T181230: (36.802797, -121.787800) 2025-04-25T18:12:25.465Z,1745604745.465 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T18:12:25.465Z,1745604745.465 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T18:12:34.025Z,1745604754.025 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20250425T154825/Courier0085.lzma 2025-04-25T18:12:35.027Z,1745604755.027 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0085.lzma.bak 2025-04-25T18:12:35.027Z,1745604755.027 [DataOverHttps](INFO): SBD MOMSN=24731370 2025-04-25T18:12:53.720Z,1745604773.720 [DataOverHttps](INFO): Sending 369 bytes from file Logs/20250425T154825/Express0086.lzma 2025-04-25T18:12:54.715Z,1745604774.715 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0086.lzma.bak 2025-04-25T18:12:54.715Z,1745604774.715 [DataOverHttps](INFO): SBD MOMSN=24731374 2025-04-25T18:12:56.179Z,1745604776.179 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T18:12:56.179Z,1745604776.179 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T18:12:56.179Z,1745604776.179 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T18:12:58.182Z,1745604778.182 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T18:17:56.765Z,1745605076.765 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T18:17:56.765Z,1745605076.765 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:17:56.781Z,1745605076.781 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:17:56.781Z,1745605076.781 [Default:CheckIn:D] Running Loop=1 2025-04-25T18:17:57.161Z,1745605077.161 [Default:CheckIn:D] Stopped 2025-04-25T18:17:57.161Z,1745605077.161 [Default:CheckIn:E] Running Loop=1 2025-04-25T18:17:57.568Z,1745605077.568 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.323910 min 2025-04-25T18:17:57.568Z,1745605077.568 [Default:CheckIn:E] Stopped 2025-04-25T18:17:57.568Z,1745605077.568 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T18:17:57.568Z,1745605077.568 [Default:CheckIn] Stopped 2025-04-25T18:17:57.568Z,1745605077.568 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:17:57.568Z,1745605077.568 [Default:CheckIn](INFO): Running loop #20 2025-04-25T18:17:57.568Z,1745605077.568 [Default:CheckIn] Running Loop=20 2025-04-25T18:17:57.569Z,1745605077.569 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T18:17:57.569Z,1745605077.569 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T18:17:59.584Z,1745605079.584 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181804.00,A,3648.16352,N,12147.27191,W,1.225,188.56,250425,,,A*7D 2025-04-25T18:17:59.598Z,1745605079.598 [NAL9602](INFO): GPS fix at 20250425T181804: (36.802725, -121.787865) 2025-04-25T18:17:59.609Z,1745605079.609 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T18:17:59.609Z,1745605079.609 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T18:18:07.365Z,1745605087.365 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20250425T154825/Courier0088.lzma 2025-04-25T18:18:08.367Z,1745605088.367 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0088.lzma.bak 2025-04-25T18:18:08.367Z,1745605088.367 [DataOverHttps](INFO): SBD MOMSN=24731399 2025-04-25T18:18:24.225Z,1745605104.225 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20250425T154825/Express0089.lzma 2025-04-25T18:18:25.227Z,1745605105.227 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0089.lzma.bak 2025-04-25T18:18:25.227Z,1745605105.227 [DataOverHttps](INFO): SBD MOMSN=24731402 2025-04-25T18:18:26.694Z,1745605106.694 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T18:18:26.694Z,1745605106.694 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T18:18:26.694Z,1745605106.694 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T18:22:48.157Z,1745605368.157 [NAL9602](INFO): SBD MO Status=2, MOMSN=24320, MT Status=2, MTMSN=0 2025-04-25T18:22:48.157Z,1745605368.157 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T18:23:01.895Z,1745605381.895 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-25T18:23:27.356Z,1745605407.356 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T18:23:27.356Z,1745605407.356 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:23:27.356Z,1745605407.356 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:23:27.373Z,1745605407.373 [Default:CheckIn:D] Running Loop=1 2025-04-25T18:23:27.759Z,1745605407.759 [Default:CheckIn:D] Stopped 2025-04-25T18:23:27.759Z,1745605407.759 [Default:CheckIn:E] Running Loop=1 2025-04-25T18:23:28.163Z,1745605408.163 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.833870 min 2025-04-25T18:23:28.163Z,1745605408.163 [Default:CheckIn:E] Stopped 2025-04-25T18:23:28.163Z,1745605408.163 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T18:23:28.163Z,1745605408.163 [Default:CheckIn] Stopped 2025-04-25T18:23:28.163Z,1745605408.163 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:23:28.163Z,1745605408.163 [Default:CheckIn](INFO): Running loop #21 2025-04-25T18:23:28.163Z,1745605408.163 [Default:CheckIn] Running Loop=21 2025-04-25T18:23:28.164Z,1745605408.164 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T18:23:28.164Z,1745605408.164 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T18:23:47.552Z,1745605427.552 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182352.00,A,3648.14695,N,12147.28226,W,3.130,353.80,250425,,,A*70 2025-04-25T18:23:47.554Z,1745605427.554 [NAL9602](INFO): GPS fix at 20250425T182352: (36.802449, -121.788038) 2025-04-25T18:23:47.565Z,1745605427.565 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T18:23:47.565Z,1745605427.565 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T18:23:54.773Z,1745605434.773 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250425T154825/Courier0091.lzma 2025-04-25T18:23:55.776Z,1745605435.776 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0091.lzma.bak 2025-04-25T18:23:55.776Z,1745605435.776 [DataOverHttps](INFO): SBD MOMSN=24731437 2025-04-25T18:24:11.705Z,1745605451.705 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20250425T154825/Express0092.lzma 2025-04-25T18:24:12.707Z,1745605452.707 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0092.lzma.bak 2025-04-25T18:24:12.707Z,1745605452.707 [DataOverHttps](INFO): SBD MOMSN=24731442 2025-04-25T18:24:14.229Z,1745605454.229 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T18:24:14.229Z,1745605454.229 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T18:24:14.229Z,1745605454.229 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T18:24:19.864Z,1745605459.864 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T18:29:14.794Z,1745605754.794 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T18:29:14.794Z,1745605754.794 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:29:14.794Z,1745605754.794 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:29:14.794Z,1745605754.794 [Default:CheckIn:D] Running Loop=1 2025-04-25T18:29:15.204Z,1745605755.204 [Default:CheckIn:D] Stopped 2025-04-25T18:29:15.204Z,1745605755.204 [Default:CheckIn:E] Running Loop=1 2025-04-25T18:29:15.604Z,1745605755.604 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 118.624634 min 2025-04-25T18:29:15.605Z,1745605755.605 [Default:CheckIn:E] Stopped 2025-04-25T18:29:15.605Z,1745605755.605 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T18:29:15.605Z,1745605755.605 [Default:CheckIn] Stopped 2025-04-25T18:29:15.605Z,1745605755.605 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:29:15.605Z,1745605755.605 [Default:CheckIn](INFO): Running loop #22 2025-04-25T18:29:15.605Z,1745605755.605 [Default:CheckIn] Running Loop=22 2025-04-25T18:29:15.605Z,1745605755.605 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T18:29:15.606Z,1745605755.606 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T18:29:17.613Z,1745605757.613 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182922.00,A,3648.16514,N,12147.26321,W,1.380,106.59,250425,,,A*70 2025-04-25T18:29:17.622Z,1745605757.622 [NAL9602](INFO): GPS fix at 20250425T182922: (36.802752, -121.787720) 2025-04-25T18:29:17.633Z,1745605757.633 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T18:29:17.633Z,1745605757.633 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T18:29:24.637Z,1745605764.637 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20250425T154825/Courier0094.lzma 2025-04-25T18:29:25.639Z,1745605765.639 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0094.lzma.bak 2025-04-25T18:29:25.639Z,1745605765.639 [DataOverHttps](INFO): SBD MOMSN=24731546 2025-04-25T18:29:41.469Z,1745605781.469 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20250425T154825/Express0095.lzma 2025-04-25T18:29:42.471Z,1745605782.471 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0095.lzma.bak 2025-04-25T18:29:42.471Z,1745605782.471 [DataOverHttps](INFO): SBD MOMSN=24731549 2025-04-25T18:29:43.894Z,1745605783.894 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T18:29:43.894Z,1745605783.894 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T18:29:43.895Z,1745605783.895 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T18:29:48.323Z,1745605788.323 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-04-25T18:29:48.401Z,1745605788.401 [NAL9602](ERROR): received: +CSQ:0 OK320, 2, 0, 0, 0 OK 2025-04-25T18:33:45.086Z,1745606025.086 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-04-25T18:33:45.086Z,1745606025.086 [DropWeight] Hardware Fault, FailCount= 1 2025-04-25T18:33:45.086Z,1745606025.086 [DropWeight](ERROR): Hardware Fault 2025-04-25T18:33:45.105Z,1745606025.105 [CBIT](INFO): Critical error at 20250425T183345 2025-04-25T18:33:45.107Z,1745606025.107 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-04-25T18:33:45.108Z,1745606025.108 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-04-25T18:33:45.510Z,1745606025.510 [CBIT](INFO): Critical error at 20250425T183345 2025-04-25T18:33:51.547Z,1745606031.547 [NAL9602](INFO): SBD MO Status=2, MOMSN=24320, MT Status=2, MTMSN=0 2025-04-25T18:33:51.548Z,1745606031.548 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-04-25T18:34:19.826Z,1745606059.826 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-04-25T18:34:44.481Z,1745606084.481 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-04-25T18:34:44.481Z,1745606084.481 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:34:44.481Z,1745606084.481 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:34:44.481Z,1745606084.481 [Default:CheckIn:D] Running Loop=1 2025-04-25T18:34:44.888Z,1745606084.888 [Default:CheckIn:D] Stopped 2025-04-25T18:34:44.888Z,1745606084.888 [Default:CheckIn:E] Running Loop=1 2025-04-25T18:34:45.285Z,1745606085.285 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.119352 min 2025-04-25T18:34:45.285Z,1745606085.285 [Default:CheckIn:E] Stopped 2025-04-25T18:34:45.285Z,1745606085.285 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-04-25T18:34:45.285Z,1745606085.285 [Default:CheckIn] Stopped 2025-04-25T18:34:45.286Z,1745606085.286 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:34:45.286Z,1745606085.286 [Default:CheckIn](INFO): Running loop #23 2025-04-25T18:34:45.286Z,1745606085.286 [Default:CheckIn] Running Loop=23 2025-04-25T18:34:45.286Z,1745606085.286 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-04-25T18:34:45.286Z,1745606085.286 [Default:CheckIn:Read_GPS] Running Loop=1 2025-04-25T18:34:47.297Z,1745606087.297 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183452.00,A,3648.16924,N,12147.27715,W,1.438,106.59,250425,,,A*72 2025-04-25T18:34:47.299Z,1745606087.299 [NAL9602](INFO): GPS fix at 20250425T183452: (36.802821, -121.787953) 2025-04-25T18:34:47.311Z,1745606087.311 [Default:CheckIn:Read_GPS] Stopped 2025-04-25T18:34:47.312Z,1745606087.312 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-04-25T18:34:54.881Z,1745606094.881 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20250425T154825/Courier0097.lzma 2025-04-25T18:34:55.883Z,1745606095.883 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Courier0097.lzma.bak 2025-04-25T18:34:55.883Z,1745606095.883 [DataOverHttps](INFO): SBD MOMSN=24731579 2025-04-25T18:35:11.797Z,1745606111.797 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20250425T154825/Express0098.lzma 2025-04-25T18:35:12.799Z,1745606112.799 [DataOverHttps](INFO): Moved sent file to Logs/20250425T154825/Express0098.lzma.bak 2025-04-25T18:35:12.799Z,1745606112.799 [DataOverHttps](INFO): SBD MOMSN=24731584 2025-04-25T18:35:14.376Z,1745606114.376 [Default:CheckIn:Read_Iridium] Stopped 2025-04-25T18:35:14.376Z,1745606114.376 [Default:CheckIn:C.Wait] Running Loop=1 2025-04-25T18:35:14.376Z,1745606114.376 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-04-25T18:35:20.018Z,1745606120.018 [NAL9602](INFO): Not Powering down - fast GPS 2025-04-25T18:37:23.234Z,1745606243.234 [CommandExec](IMPORTANT): got command 2025-04-25T18:37:23.234Z,1745606243.234 [CommandExec](FAULT): Incomplete syntax. Try: help 2025-04-25T18:37:26.558Z,1745606246.558 [CommandExec](IMPORTANT): got command quit 2025-04-25T18:37:27.561Z,1745606247.561 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:27.561Z,1745606247.561 [CommandExec](INFO): Uninitializing the command executive. 2025-04-25T18:37:27.561Z,1745606247.561 [CommandExec](INFO): Uninitializing the command scheduler. 2025-04-25T18:37:27.562Z,1745606247.562 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:27.637Z,1745606247.637 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-04-25T18:37:27.637Z,1745606247.637 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-04-25T18:37:27.637Z,1745606247.637 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:27.638Z,1745606247.638 [NavChartDb](INFO): Join timeout helper Thread ID is 7560 2025-04-25T18:37:27.837Z,1745606247.837 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:27.838Z,1745606247.838 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:27.841Z,1745606247.841 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-04-25T18:37:27.841Z,1745606247.841 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:27.842Z,1745606247.842 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7561 2025-04-25T18:37:28.161Z,1745606248.161 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:28.162Z,1745606248.162 [WetLabsBB2FL](INFO): Powering down 2025-04-25T18:37:28.162Z,1745606248.162 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:28.182Z,1745606248.182 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-04-25T18:37:28.182Z,1745606248.182 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:28.182Z,1745606248.182 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7562 2025-04-25T18:37:28.745Z,1745606248.745 [CTD_Seabird](INFO): Powering down 2025-04-25T18:37:28.757Z,1745606248.757 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:28.757Z,1745606248.757 [CTD_Seabird](INFO): Powering down 2025-04-25T18:37:28.769Z,1745606248.769 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:28.796Z,1745606248.796 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-04-25T18:37:28.796Z,1745606248.796 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:28.796Z,1745606248.796 [Radio_Surface](INFO): Join timeout helper Thread ID is 7563 2025-04-25T18:37:29.081Z,1745606249.081 [Radio_Surface](INFO): Powering down 2025-04-25T18:37:29.082Z,1745606249.082 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:29.082Z,1745606249.082 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:29.085Z,1745606249.085 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-04-25T18:37:29.085Z,1745606249.085 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:29.085Z,1745606249.085 [Onboard](INFO): Join timeout helper Thread ID is 7564 2025-04-25T18:37:29.869Z,1745606249.869 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-04-25T18:37:30.521Z,1745606250.521 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:30.522Z,1745606250.522 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:30.526Z,1745606250.526 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-04-25T18:37:30.526Z,1745606250.526 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:30.527Z,1745606250.527 [DataOverHttps](INFO): Join timeout helper Thread ID is 7565 2025-04-25T18:37:30.873Z,1745606250.873 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:30.874Z,1745606250.874 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:30.894Z,1745606250.894 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-04-25T18:37:30.894Z,1745606250.894 [DAT ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:30.894Z,1745606250.894 [DAT](INFO): Join timeout helper Thread ID is 7566 2025-04-25T18:37:31.030Z,1745606251.030 [DAT](INFO): Powering down 2025-04-25T18:37:31.102Z,1745606251.102 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:31.102Z,1745606251.102 [DAT](INFO): Powering down 2025-04-25T18:37:31.103Z,1745606251.103 [DAT ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.118Z,1745606251.118 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2025-04-25T18:37:31.118Z,1745606251.118 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.118Z,1745606251.118 [BackseatComponent](INFO): Join timeout helper Thread ID is 7567 2025-04-25T18:37:31.241Z,1745606251.241 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:31.242Z,1745606251.242 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.258Z,1745606251.258 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-04-25T18:37:31.258Z,1745606251.258 [logger ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.258Z,1745606251.258 [logger](INFO): Join timeout helper Thread ID is 7568 2025-04-25T18:37:31.289Z,1745606251.289 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:31.290Z,1745606251.290 [logger ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.298Z,1745606251.298 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-04-25T18:37:31.298Z,1745606251.298 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.298Z,1745606251.298 [CommandLine](INFO): Join timeout helper Thread ID is 7569 2025-04-25T18:37:31.322Z,1745606251.322 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:31.323Z,1745606251.323 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.330Z,1745606251.330 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-04-25T18:37:31.330Z,1745606251.330 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.330Z,1745606251.330 [CommandExec](INFO): Join timeout helper Thread ID is 7570 2025-04-25T18:37:31.334Z,1745606251.334 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-04-25T18:37:31.334Z,1745606251.334 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.334Z,1745606251.334 [controlThread](INFO): Join timeout helper Thread ID is 7571 2025-04-25T18:37:31.355Z,1745606251.355 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-04-25T18:37:31.355Z,1745606251.355 [controlThread](DEBUG): Uninitializing ControlThread 2025-04-25T18:37:31.355Z,1745606251.355 [AHRS_M2](INFO): Powering down 2025-04-25T18:37:31.426Z,1745606251.426 [NAL9602](INFO): Powering down 2025-04-25T18:37:31.427Z,1745606251.427 [Sonardyne_Nano](INFO): Powering down 2025-04-25T18:37:31.545Z,1745606251.545 [Waterlinked](INFO): Powering down 2025-04-25T18:37:31.633Z,1745606251.633 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-04-25T18:37:31.634Z,1745606251.634 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-04-25T18:37:31.635Z,1745606251.635 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-04-25T18:37:31.635Z,1745606251.635 [MissionManager](INFO): Uninitializing Mission Default 2025-04-25T18:37:31.635Z,1745606251.635 [Default] Stopped 2025-04-25T18:37:31.635Z,1745606251.635 [Default](DEBUG): Aggregate::uninitialize Default 2025-04-25T18:37:31.635Z,1745606251.635 [Default:B.GoToSurface] Stopped 2025-04-25T18:37:31.635Z,1745606251.635 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-04-25T18:37:31.635Z,1745606251.635 [Default:CheckIn] Stopped 2025-04-25T18:37:31.636Z,1745606251.636 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-04-25T18:37:31.636Z,1745606251.636 [Default:CheckIn:C.Wait] Stopped 2025-04-25T18:37:31.636Z,1745606251.636 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-04-25T18:37:31.639Z,1745606251.639 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-04-25T18:37:31.639Z,1745606251.639 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-04-25T18:37:31.639Z,1745606251.639 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-04-25T18:37:31.640Z,1745606251.640 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-04-25T18:37:31.640Z,1745606251.640 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-04-25T18:37:31.640Z,1745606251.640 [BuoyancyServo](INFO): Powering down 2025-04-25T18:37:31.653Z,1745606251.653 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-04-25T18:37:31.653Z,1745606251.653 [ElevatorServo](INFO): Powering down 2025-04-25T18:37:31.654Z,1745606251.654 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-04-25T18:37:31.654Z,1745606251.654 [MassServo](INFO): Powering down 2025-04-25T18:37:31.655Z,1745606251.655 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-04-25T18:37:31.655Z,1745606251.655 [RudderServo](INFO): Powering down 2025-04-25T18:37:31.656Z,1745606251.656 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-04-25T18:37:31.656Z,1745606251.656 [ThrusterHE](INFO): Powering down 2025-04-25T18:37:31.657Z,1745606251.657 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-04-25T18:37:31.657Z,1745606251.657 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-04-25T18:37:31.658Z,1745606251.658 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-04-25T18:37:31.658Z,1745606251.658 [CBIT](DEBUG): Powering off loads. 2025-04-25T18:37:31.669Z,1745606251.669 [CBIT](DEBUG): Disabling WDT. 2025-04-25T18:37:31.681Z,1745606251.681 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-04-25T18:37:31.681Z,1745606251.681 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-04-25T18:37:31.682Z,1745606251.682 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.720Z,1745606251.720 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.723Z,1745606251.723 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.729Z,1745606251.729 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.736Z,1745606251.736 [DAT ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.779Z,1745606251.779 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.812Z,1745606251.812 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-04-25T18:37:31.812Z,1745606251.812 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-04-25T18:37:31.869Z,1745606251.869 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.875Z,1745606251.875 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.883Z,1745606251.883 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-04-25T18:37:31.963Z,1745606251.963 [logger ThreadHandler](INFO): Thread cancelled.