2025-11-07T23:56:14.196Z,1762559774.196 [Supervisor](DEBUG): Initializing supervisor. 2025-11-07T23:56:14.201Z,1762559774.201 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-11-07T23:56:14.202Z,1762559774.202 [SyncHandler](INFO): Protected caller Thread ID is 3814 2025-11-07T23:56:14.202Z,1762559774.202 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-11-07T23:56:14.203Z,1762559774.203 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-11-07T23:56:14.203Z,1762559774.203 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3815 2025-11-07T23:56:14.208Z,1762559774.208 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-11-07T23:56:14.227Z,1762559774.227 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-11-07T23:56:14.228Z,1762559774.228 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-11-07T23:56:14.229Z,1762559774.229 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3816 2025-11-07T23:56:14.233Z,1762559774.233 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-11-07T23:56:14.234Z,1762559774.234 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-11-07T23:56:14.234Z,1762559774.234 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3817 2025-11-07T23:56:14.237Z,1762559774.237 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-11-07T23:56:14.237Z,1762559774.237 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-11-07T23:56:14.238Z,1762559774.238 [logger ThreadHandler](INFO): Protected caller Thread ID is 3818 2025-11-07T23:56:14.241Z,1762559774.241 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-11-07T23:56:14.242Z,1762559774.242 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-11-07T23:56:14.244Z,1762559774.244 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-11-07T23:56:14.590Z,1762559774.590 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-11-07T23:56:14.590Z,1762559774.590 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-11-07T23:56:14.693Z,1762559774.693 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-11-07T23:56:14.694Z,1762559774.694 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-11-07T23:56:14.814Z,1762559774.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-11-07T23:56:14.814Z,1762559774.814 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-11-07T23:56:14.958Z,1762559774.958 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-11-07T23:56:14.958Z,1762559774.958 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-11-07T23:56:15.321Z,1762559775.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-11-07T23:56:15.322Z,1762559775.322 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-11-07T23:56:15.430Z,1762559775.430 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-11-07T23:56:15.431Z,1762559775.431 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-11-07T23:56:15.842Z,1762559775.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-11-07T23:56:15.843Z,1762559775.843 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-11-07T23:56:16.079Z,1762559776.079 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-11-07T23:56:16.080Z,1762559776.080 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-11-07T23:56:16.171Z,1762559776.171 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-11-07T23:56:16.425Z,1762559776.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-11-07T23:56:16.425Z,1762559776.425 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-11-07T23:56:16.656Z,1762559776.656 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-11-07T23:56:16.656Z,1762559776.656 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-11-07T23:56:17.220Z,1762559777.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-11-07T23:56:17.220Z,1762559777.220 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-11-07T23:56:17.417Z,1762559777.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-11-07T23:56:17.417Z,1762559777.417 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-11-07T23:56:17.714Z,1762559777.714 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-11-07T23:56:17.715Z,1762559777.715 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-11-07T23:56:18.582Z,1762559778.582 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-11-07T23:56:18.582Z,1762559778.582 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-11-07T23:56:19.174Z,1762559779.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-11-07T23:56:19.176Z,1762559779.176 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/ 2025-11-07T23:56:19.177Z,1762559779.177 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg 2025-11-07T23:56:19.285Z,1762559779.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg 2025-11-07T23:56:19.428Z,1762559779.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg 2025-11-07T23:56:19.524Z,1762559779.524 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg 2025-11-07T23:56:19.643Z,1762559779.643 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg 2025-11-07T23:56:19.749Z,1762559779.749 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg 2025-11-07T23:56:20.019Z,1762559780.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-11-07T23:56:20.019Z,1762559780.019 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg 2025-11-07T23:56:20.142Z,1762559780.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg 2025-11-07T23:56:20.251Z,1762559780.251 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg 2025-11-07T23:56:20.403Z,1762559780.403 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg 2025-11-07T23:56:20.503Z,1762559780.503 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/root/ 2025-11-07T23:56:20.503Z,1762559780.503 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-11-07T23:56:20.513Z,1762559780.513 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-11-07T23:56:20.645Z,1762559780.645 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-11-07T23:56:20.645Z,1762559780.645 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-11-07T23:56:20.698Z,1762559780.698 [VerticalControl](DEBUG): Construct VerticalControl. 2025-11-07T23:56:20.757Z,1762559780.757 [VerticalControl] Loaded 2025-11-07T23:56:20.758Z,1762559780.758 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-11-07T23:56:20.761Z,1762559780.761 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-11-07T23:56:20.807Z,1762559780.807 [HorizontalControl] Loaded 2025-11-07T23:56:20.807Z,1762559780.807 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-11-07T23:56:20.810Z,1762559780.810 [SpeedControl](DEBUG): Construct SpeedControl. 2025-11-07T23:56:20.813Z,1762559780.813 [SpeedControl] Loaded 2025-11-07T23:56:20.813Z,1762559780.813 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-11-07T23:56:20.816Z,1762559780.816 [LoopControl](DEBUG): Construct LoopControl. 2025-11-07T23:56:20.816Z,1762559780.816 [LoopControl] Loaded 2025-11-07T23:56:20.817Z,1762559780.817 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-11-07T23:56:20.817Z,1762559780.817 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-11-07T23:56:20.817Z,1762559780.817 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-11-07T23:56:20.877Z,1762559780.877 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-11-07T23:56:20.878Z,1762559780.878 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-11-07T23:56:21.378Z,1762559781.378 [AHRS_M2] Loaded 2025-11-07T23:56:21.378Z,1762559781.378 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-11-07T23:56:21.417Z,1762559781.417 [BackseatComponent] Loaded 2025-11-07T23:56:21.417Z,1762559781.417 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-11-07T23:56:21.419Z,1762559781.419 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BD4E0 2025-11-07T23:56:21.419Z,1762559781.419 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 3897 2025-11-07T23:56:21.422Z,1762559781.422 [LcmPublisher](INFO): Full slate access is ENABLED. All requested slate values (including non-universals) will be published on LCM. 2025-11-07T23:56:21.422Z,1762559781.422 [LcmPublisher] Loaded 2025-11-07T23:56:21.422Z,1762559781.422 [ComponentRegistry](DEBUG): SyncComponent "LcmPublisher" handled in the control thread. 2025-11-07T23:56:22.229Z,1762559782.229 [BPC1] Loaded 2025-11-07T23:56:22.229Z,1762559782.229 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-11-07T23:56:22.326Z,1762559782.326 [DAT] Loaded 2025-11-07T23:56:22.327Z,1762559782.327 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-11-07T23:56:22.328Z,1762559782.328 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408ED4E0 2025-11-07T23:56:22.328Z,1762559782.328 [DAT ThreadHandler](INFO): Protected caller Thread ID is 3898 2025-11-07T23:56:22.402Z,1762559782.402 [DataOverHttps] Loaded 2025-11-07T23:56:22.402Z,1762559782.402 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-11-07T23:56:22.403Z,1762559782.403 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091D4E0 2025-11-07T23:56:22.404Z,1762559782.404 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3899 2025-11-07T23:56:22.426Z,1762559782.426 [Depth_Keller] Loaded 2025-11-07T23:56:22.427Z,1762559782.427 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-11-07T23:56:22.432Z,1762559782.432 [DropWeight] Loaded 2025-11-07T23:56:22.432Z,1762559782.432 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-11-07T23:56:22.496Z,1762559782.496 [NAL9602] Loaded 2025-11-07T23:56:22.496Z,1762559782.496 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-11-07T23:56:22.525Z,1762559782.525 [Onboard] Loaded 2025-11-07T23:56:22.525Z,1762559782.525 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-11-07T23:56:22.526Z,1762559782.526 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094D4E0 2025-11-07T23:56:22.527Z,1762559782.527 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3900 2025-11-07T23:56:22.540Z,1762559782.540 [Power24vConverter] Loaded 2025-11-07T23:56:22.541Z,1762559782.541 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-11-07T23:56:22.556Z,1762559782.556 [Radio_Surface] Loaded 2025-11-07T23:56:22.557Z,1762559782.557 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-11-07T23:56:22.558Z,1762559782.558 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097D4E0 2025-11-07T23:56:22.558Z,1762559782.558 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3901 2025-11-07T23:56:22.573Z,1762559782.573 [Sonardyne_Nano] Loaded 2025-11-07T23:56:22.573Z,1762559782.573 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-11-07T23:56:22.574Z,1762559782.574 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-11-07T23:56:22.574Z,1762559782.574 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-11-07T23:56:22.585Z,1762559782.585 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-11-07T23:56:22.585Z,1762559782.585 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-11-07T23:56:22.615Z,1762559782.615 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-11-07T23:56:22.616Z,1762559782.616 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-11-07T23:56:22.769Z,1762559782.769 [SBIT](DEBUG): Construct Startup Built In Test. 2025-11-07T23:56:22.778Z,1762559782.778 [SBIT] Loaded 2025-11-07T23:56:22.778Z,1762559782.778 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-11-07T23:56:22.781Z,1762559782.781 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-11-07T23:56:22.794Z,1762559782.794 [IBIT] Loaded 2025-11-07T23:56:22.794Z,1762559782.794 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-11-07T23:56:22.799Z,1762559782.799 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-11-07T23:56:22.878Z,1762559782.878 [CBIT] Loaded 2025-11-07T23:56:22.878Z,1762559782.878 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-11-07T23:56:22.911Z,1762559782.911 [GFScanner] Loaded 2025-11-07T23:56:22.911Z,1762559782.911 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-11-07T23:56:22.911Z,1762559782.911 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-11-07T23:56:22.912Z,1762559782.912 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-11-07T23:56:23.242Z,1762559783.242 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-11-07T23:56:23.242Z,1762559783.242 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-11-07T23:56:23.292Z,1762559783.292 [DepthRateCalculator] Loaded 2025-11-07T23:56:23.293Z,1762559783.293 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-11-07T23:56:23.298Z,1762559783.298 [PitchRateCalculator] Loaded 2025-11-07T23:56:23.298Z,1762559783.298 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-11-07T23:56:23.308Z,1762559783.308 [SpeedCalculator] Loaded 2025-11-07T23:56:23.309Z,1762559783.309 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-11-07T23:56:23.313Z,1762559783.313 [YawRateCalculator] Loaded 2025-11-07T23:56:23.313Z,1762559783.313 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-11-07T23:56:23.332Z,1762559783.332 [ElevatorOffsetCalculator] Loaded 2025-11-07T23:56:23.332Z,1762559783.332 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-11-07T23:56:23.333Z,1762559783.333 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-11-07T23:56:23.333Z,1762559783.333 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-11-07T23:56:23.507Z,1762559783.507 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-11-07T23:56:23.507Z,1762559783.507 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-11-07T23:56:23.620Z,1762559783.620 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-11-07T23:56:23.620Z,1762559783.620 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-11-07T23:56:23.634Z,1762559783.634 [NavChart] Loaded 2025-11-07T23:56:23.634Z,1762559783.634 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-11-07T23:56:23.640Z,1762559783.640 [UniversalFixResidualReporter] Loaded 2025-11-07T23:56:23.640Z,1762559783.640 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-11-07T23:56:23.641Z,1762559783.641 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-11-07T23:56:23.641Z,1762559783.641 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-11-07T23:56:23.790Z,1762559783.790 [BuoyancyServo] Loaded 2025-11-07T23:56:23.790Z,1762559783.790 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-11-07T23:56:23.813Z,1762559783.813 [ElevatorServo] Loaded 2025-11-07T23:56:23.813Z,1762559783.813 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-11-07T23:56:23.835Z,1762559783.835 [MassServo] Loaded 2025-11-07T23:56:23.835Z,1762559783.835 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-11-07T23:56:23.855Z,1762559783.855 [RudderServo] Loaded 2025-11-07T23:56:23.856Z,1762559783.856 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-11-07T23:56:23.873Z,1762559783.873 [ThrusterHE] Loaded 2025-11-07T23:56:23.873Z,1762559783.873 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-11-07T23:56:23.873Z,1762559783.873 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-11-07T23:56:23.874Z,1762559783.874 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-11-07T23:56:24.047Z,1762559784.047 [CTD_Seabird] Loaded 2025-11-07T23:56:24.048Z,1762559784.048 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-11-07T23:56:24.049Z,1762559784.049 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C0D4E0 2025-11-07T23:56:24.049Z,1762559784.049 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3902 2025-11-07T23:56:24.085Z,1762559784.085 [ESPComponent] Loaded 2025-11-07T23:56:24.086Z,1762559784.086 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-11-07T23:56:24.107Z,1762559784.107 [PAR_Licor] Loaded 2025-11-07T23:56:24.107Z,1762559784.107 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-11-07T23:56:24.152Z,1762559784.152 [WetLabsBB2FL] Loaded 2025-11-07T23:56:24.153Z,1762559784.153 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-11-07T23:56:24.153Z,1762559784.153 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C3D4E0 2025-11-07T23:56:24.154Z,1762559784.154 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3903 2025-11-07T23:56:24.155Z,1762559784.155 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-11-07T23:56:24.161Z,1762559784.161 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-11-07T23:56:24.164Z,1762559784.164 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-11-07T23:56:24.175Z,1762559784.175 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-11-07T23:56:24.176Z,1762559784.176 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C6D4E0 2025-11-07T23:56:24.176Z,1762559784.176 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3904 2025-11-07T23:56:24.181Z,1762559784.181 [Supervisor](INFO): Main Thread ID is 3224 2025-11-07T23:56:24.181Z,1762559784.181 [Supervisor](DEBUG): Running supervisor. 2025-11-07T23:56:24.182Z,1762559784.182 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3905 2025-11-07T23:56:24.182Z,1762559784.182 [CommandExec](INFO): Initializing the command executive. 2025-11-07T23:56:24.184Z,1762559784.184 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3906 2025-11-07T23:56:24.187Z,1762559784.187 [controlThread ThreadHandler](INFO): Handler Thread ID is 3907 2025-11-07T23:56:24.188Z,1762559784.188 [controlThread](DEBUG): Initializing ControlThread 2025-11-07T23:56:24.189Z,1762559784.189 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-11-07T23:56:24.190Z,1762559784.190 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-11-07T23:56:24.191Z,1762559784.191 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-11-07T23:56:24.191Z,1762559784.191 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-11-07T23:56:24.194Z,1762559784.194 [SBIT](INFO): Initialize SBIT Component. 2025-11-07T23:56:24.195Z,1762559784.195 [SBIT](IMPORTANT): git: 2025-11-06-4-g76494056e 2025-11-07T23:56:24.195Z,1762559784.195 [SBIT](INFO): git hash: 76494056ed9c20a4ea114d534fa322c9d45bc993 2025-11-07T23:56:24.195Z,1762559784.195 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-11-07T23:56:24.197Z,1762559784.197 [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-11-07T23:56:24.198Z,1762559784.198 [SBIT](INFO): Beginning SBIT in 117.000000 seconds. 2025-11-07T23:56:24.198Z,1762559784.198 [IBIT](INFO): Initialize IBIT Component. 2025-11-07T23:56:24.199Z,1762559784.199 [CBIT](DEBUG): Initialize CBIT Component. 2025-11-07T23:56:24.200Z,1762559784.200 [logger ThreadHandler](INFO): Handler Thread ID is 3908 2025-11-07T23:56:24.212Z,1762559784.212 [CBIT](DEBUG): Initialized mux pins. 2025-11-07T23:56:24.212Z,1762559784.212 [CBIT](DEBUG): Initializing the watchdog timer. 2025-11-07T23:56:24.220Z,1762559784.220 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 3909 2025-11-07T23:56:24.236Z,1762559784.236 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-11-07T23:56:24.236Z,1762559784.236 [CBIT](DEBUG): Initializing heartbeat. 2025-11-07T23:56:24.237Z,1762559784.237 [DAT ThreadHandler](INFO): Handler Thread ID is 3910 2025-11-07T23:56:24.238Z,1762559784.238 [DAT](INFO): Powering up 2025-11-07T23:56:24.238Z,1762559784.238 [DAT](DEBUG): Initializing DAT. 2025-11-07T23:56:24.241Z,1762559784.241 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3912 2025-11-07T23:56:24.243Z,1762559784.243 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-11-07T23:56:24.264Z,1762559784.264 [Onboard ThreadHandler](INFO): Handler Thread ID is 3913 2025-11-07T23:56:24.281Z,1762559784.281 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3914 2025-11-07T23:56:24.302Z,1762559784.302 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3915 2025-11-07T23:56:24.303Z,1762559784.303 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-11-07T23:56:24.308Z,1762559784.308 [CBIT](DEBUG): Deactivating emergency mode. 2025-11-07T23:56:24.309Z,1762559784.309 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3917 2025-11-07T23:56:24.312Z,1762559784.312 [WetLabsBB2FL](INFO): Powering up 2025-11-07T23:56:24.314Z,1762559784.314 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3919 2025-11-07T23:56:24.316Z,1762559784.316 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-11-07T23:56:24.317Z,1762559784.317 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-11-07T23:56:24.317Z,1762559784.317 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-11-07T23:56:24.317Z,1762559784.317 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-11-07T23:56:24.317Z,1762559784.317 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-11-07T23:56:24.317Z,1762559784.317 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-11-07T23:56:24.318Z,1762559784.318 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-11-07T23:56:24.318Z,1762559784.318 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-11-07T23:56:24.348Z,1762559784.348 [CBIT](DEBUG): Backplane powered. 2025-11-07T23:56:24.348Z,1762559784.348 [GFScanner](DEBUG): Initializing GFScanner 2025-11-07T23:56:24.348Z,1762559784.348 [GFScanner](DEBUG): Deactivating GF circuits. 2025-11-07T23:56:24.353Z,1762559784.353 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-11-07T23:56:24.353Z,1762559784.353 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-11-07T23:56:24.353Z,1762559784.353 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-11-07T23:56:24.354Z,1762559784.354 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-11-07T23:56:24.354Z,1762559784.354 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-11-07T23:56:24.355Z,1762559784.355 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-11-07T23:56:24.355Z,1762559784.355 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-11-07T23:56:24.369Z,1762559784.369 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-11-07T23:56:24.372Z,1762559784.372 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-11-07T23:56:24.373Z,1762559784.373 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-11-07T23:56:24.374Z,1762559784.374 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-11-07T23:56:24.473Z,1762559784.473 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-11-07T23:56:24.478Z,1762559784.478 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-11-07T23:56:24.536Z,1762559784.536 [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-11-07T23:56:24.537Z,1762559784.537 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-11-07T23:56:24.537Z,1762559784.537 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-11-07T23:56:24.538Z,1762559784.538 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-11-07T23:56:24.688Z,1762559784.688 [Radio_Surface](INFO): Powering up 2025-11-07T23:56:24.869Z,1762559784.869 [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-11-07T23:56:24.883Z,1762559784.883 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-11-07T23:56:24.892Z,1762559784.892 [Default:A.Wait](DEBUG): Construct Wait. 2025-11-07T23:56:24.895Z,1762559784.895 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-11-07T23:56:24.940Z,1762559784.940 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-11-07T23:56:24.943Z,1762559784.943 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-11-07T23:56:24.965Z,1762559784.965 [Default:E.Execute](DEBUG): Construct Execute. 2025-11-07T23:56:24.968Z,1762559784.968 [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-11-07T23:56:24.980Z,1762559784.980 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmPublisher,Reporter,LogSplitter, 2025-11-07T23:56:24.994Z,1762559784.994 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-11-07T23:56:25.052Z,1762559785.052 [Depth_Keller](INFO): Initializing. 2025-11-07T23:56:25.054Z,1762559785.054 [Power24vConverter](INFO): Powering up. 2025-11-07T23:56:25.054Z,1762559785.054 [Sonardyne_Nano](INFO): Initializing. 2025-11-07T23:56:25.093Z,1762559785.093 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-11-07T23:56:25.136Z,1762559785.136 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-11-07T23:56:25.137Z,1762559785.137 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-11-07T23:56:25.138Z,1762559785.138 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-11-07T23:56:25.144Z,1762559785.144 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-11-07T23:56:25.145Z,1762559785.145 [MassServo](DEBUG): Initializing EZServoServo. 2025-11-07T23:56:25.152Z,1762559785.152 [MassServo](DEBUG): Initializing MassServo. 2025-11-07T23:56:25.153Z,1762559785.153 [RudderServo](DEBUG): Initializing EZServoServo. 2025-11-07T23:56:25.160Z,1762559785.160 [RudderServo](DEBUG): Initializing RudderServo. 2025-11-07T23:56:25.161Z,1762559785.161 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-11-07T23:56:25.168Z,1762559785.168 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-11-07T23:56:25.429Z,1762559785.429 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-11-07T23:56:25.430Z,1762559785.430 [DropWeight] Hardware Fault, FailCount= 1 2025-11-07T23:56:25.430Z,1762559785.430 [DropWeight](ERROR): Hardware Fault 2025-11-07T23:56:25.470Z,1762559785.470 [CommandExec](FAULT): Scheduling is paused 2025-11-07T23:56:25.470Z,1762559785.470 [CBIT](INFO): Critical error at 20251107T235625 2025-11-07T23:56:25.470Z,1762559785.470 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-11-07T23:56:25.481Z,1762559785.481 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-11-07T23:56:25.481Z,1762559785.481 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-11-07T23:56:25.843Z,1762559785.843 [CBIT](INFO): Critical error at 20251107T235625 2025-11-07T23:56:26.420Z,1762559786.420 [WetLabsBB2FL](INFO): Powering down 2025-11-07T23:56:27.014Z,1762559787.014 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-11-07T23:56:28.298Z,1762559788.298 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311 2025-11-07T23:56:30.905Z,1762559790.905 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-11-07T23:56:31.333Z,1762559791.333 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2025-11-07T23:56:36.585Z,1762559796.585 [DAT](INFO): DAT read: 2025-11-07T23:56:36.586Z,1762559796.586 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-11-07T23:56:38.349Z,1762559798.349 [DAT](INFO): DAT read: MF Frequency Band 2025-11-07T23:56:38.350Z,1762559798.350 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-11-07T23:56:38.351Z,1762559798.351 [DAT](INFO): DAT read: Nov 7 2025 23:56:32 2025-11-07T23:56:39.357Z,1762559799.357 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-11-07T23:56:39.358Z,1762559799.358 [DAT](INFO): DAT read: CONNECT 00800 bits/sec Rate 1/2 CC 12.50ms MGP 2025-11-07T23:56:39.359Z,1762559799.359 [DAT](INFO): commRate: 800 2025-11-07T23:56:41.424Z,1762559801.424 [DAT](INFO): entering command mode 2025-11-07T23:56:41.624Z,1762559801.624 [DAT](INFO): DAT read: 2025-11-07T23:56:41.625Z,1762559801.625 [DAT](INFO): DAT read: user:1> 2025-11-07T23:56:41.625Z,1762559801.625 [DAT](INFO): setting verbose to 3 2025-11-07T23:56:41.876Z,1762559801.876 [DAT](INFO): DAT read: user:1> 2025-11-07T23:56:41.878Z,1762559801.878 [DAT](INFO): DAT read: Verbose | 3 2025-11-07T23:56:41.878Z,1762559801.878 [DAT](INFO): set verbose to 3 2025-11-07T23:56:41.878Z,1762559801.878 [DAT](INFO): setting DatVerbose to 27440 2025-11-07T23:56:42.129Z,1762559802.129 [DAT](INFO): DAT read: user:2> 2025-11-07T23:56:42.130Z,1762559802.130 [DAT](INFO): DAT read: DatVerbose | 27440 2025-11-07T23:56:42.131Z,1762559802.131 [DAT](INFO): set DatVerbose to 27440 2025-11-07T23:56:42.131Z,1762559802.131 [DAT](INFO): setting transmit power to 8 2025-11-07T23:56:42.381Z,1762559802.381 [DAT](INFO): DAT read: user:3> 2025-11-07T23:56:42.382Z,1762559802.382 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-11-07T23:56:42.382Z,1762559802.382 [DAT](INFO): set transmit power to 8 2025-11-07T23:56:42.382Z,1762559802.382 [DAT](INFO): setting local address to 1 2025-11-07T23:56:42.633Z,1762559802.633 [DAT](INFO): DAT read: user:4> 2025-11-07T23:56:42.634Z,1762559802.634 [DAT](INFO): DAT read: LocalAddr | 1 2025-11-07T23:56:42.634Z,1762559802.634 [DAT](INFO): set local address to 1 2025-11-07T23:56:42.635Z,1762559802.635 [DAT](INFO): Setting time to: 23:56:42 And date to:11/7/2025 2025-11-07T23:56:42.885Z,1762559802.885 [DAT](INFO): DAT read: user:5> 2025-11-07T23:56:42.886Z,1762559802.886 [DAT](INFO): DAT read: Fri Nov 7, 2025 23:56:42 2025-11-07T23:56:42.886Z,1762559802.886 [DAT](INFO): Local DAT time set to Fri Nov 7, 2025 23:56:42 2025-11-07T23:56:52.877Z,1762559812.877 [NAL9602](INFO): Powering up NAL9602 2025-11-07T23:57:03.778Z,1762559823.778 [NAL9602](INFO): NAL9602 initialized 2025-11-07T23:58:21.771Z,1762559901.771 [SBIT](IMPORTANT): Beginning Startup BIT 2025-11-07T23:58:21.777Z,1762559901.777 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-11-07T23:58:26.284Z,1762559906.284 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.000163 CHAN A1 (24V): 0.000651 CHAN A2 (12V): 0.000006 CHAN A3 (5V): -0.001057 CHAN B0 (3.3V): 0.000143 CHAN B1 (3.15aV): 0.000387 CHAN B2 (3.15bV): 0.000131 CHAN B3 (GND): -0.000395 OPEN: 0.006725 Full Scale: +/- 1 mA 2025-11-07T23:59:06.442Z,1762559946.442 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004651 2025-11-07T23:59:15.498Z,1762559955.498 [SBIT](IMPORTANT): SBIT PASSED 2025-11-07T23:59:15.498Z,1762559955.498 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-11-07T23:59:15.499Z,1762559955.499 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=19 count; 2025-11-07T23:59:15.499Z,1762559955.499 [SBIT](IMPORTANT): BackseatComponent.fullSlateAccess=1 bool; 2025-11-07T23:59:15.499Z,1762559955.499 [SBIT](IMPORTANT): DAT.surfaceThreshold=0.01 meter; 2025-11-07T23:59:15.499Z,1762559955.499 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter; 2025-11-07T23:59:15.499Z,1762559955.499 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 2.000000 count_per_second; 2025-11-07T23:59:15.499Z,1762559955.499 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 100.000000 count_per_second; 2025-11-07T23:59:15.500Z,1762559955.500 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=162.414241 cubic_centimeter; 2025-11-07T23:59:15.500Z,1762559955.500 [SBIT](IMPORTANT): VerticalControl.massDefault=24.263883 millimeter; 2025-11-07T23:59:15.500Z,1762559955.500 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool; 2025-11-07T23:59:15.903Z,1762559955.903 [MissionManager](IMPORTANT): Started mission Startup 2025-11-07T23:59:15.904Z,1762559955.904 [Startup] Running Loop=1 2025-11-07T23:59:15.904Z,1762559955.904 [Startup](DEBUG): Aggregate::initialize Startup 2025-11-07T23:59:15.904Z,1762559955.904 [Startup:A.GoToSurface] Running Loop=1 2025-11-07T23:59:15.904Z,1762559955.904 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-11-07T23:59:15.905Z,1762559955.905 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-11-07T23:59:15.905Z,1762559955.905 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-11-07T23:59:15.906Z,1762559955.906 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-11-07T23:59:15.906Z,1762559955.906 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-11-07T23:59:15.906Z,1762559955.906 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-11-07T23:59:15.907Z,1762559955.907 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-11-07T23:59:15.908Z,1762559955.908 [Startup:StartupSatComms] Running Loop=1 2025-11-07T23:59:15.908Z,1762559955.908 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-11-07T23:59:15.909Z,1762559955.909 [Startup:StartupSatComms:A] Running Loop=1 2025-11-07T23:59:16.302Z,1762559956.302 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-11-07T23:59:20.325Z,1762559960.325 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-07T23:59:24.380Z,1762559964.380 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-11-07T23:59:24.380Z,1762559964.380 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-07T23:59:24.391Z,1762559964.391 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-07T23:59:24.807Z,1762559964.807 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-07T23:59:24.807Z,1762559964.807 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-11-07T23:59:35.284Z,1762559975.284 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-07T23:59:50.625Z,1762559990.625 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-08T00:00:05.573Z,1762560005.573 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-08T00:00:16.094Z,1762560016.094 [Startup:StartupSatComms:A](INFO): Timed out from 2025-11-07T23:59:15.9Z 2025-11-08T00:00:16.094Z,1762560016.094 [Startup:StartupSatComms:A] Stopped 2025-11-08T00:00:16.094Z,1762560016.094 [Startup:StartupSatComms:B] Running Loop=1 2025-11-08T00:00:16.497Z,1762560016.497 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-11-08T00:00:20.925Z,1762560020.925 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-08T00:00:23.859Z,1762560023.859 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251107T194800/Courier0073.lzma 2025-11-08T00:00:24.862Z,1762560024.862 [DataOverHttps](INFO): Moved sent file to Logs/20251107T194800/Courier0073.lzma.bak 2025-11-08T00:00:24.862Z,1762560024.862 [DataOverHttps](INFO): SBD MOMSN=26293528 2025-11-08T00:00:35.939Z,1762560035.939 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-08T00:00:40.404Z,1762560040.404 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20251107T235614/Courier0000.lzma 2025-11-08T00:00:41.407Z,1762560041.407 [DataOverHttps](INFO): Moved sent file to Logs/20251107T235614/Courier0000.lzma.bak 2025-11-08T00:00:41.407Z,1762560041.407 [DataOverHttps](INFO): SBD MOMSN=26293530 2025-11-08T00:00:51.225Z,1762560051.225 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-08T00:00:56.984Z,1762560056.984 [DataOverHttps](INFO): Sending 185 bytes from file Logs/20251107T194800/Express0074.lzma 2025-11-08T00:00:57.986Z,1762560057.986 [DataOverHttps](INFO): Moved sent file to Logs/20251107T194800/Express0074.lzma.bak 2025-11-08T00:00:57.986Z,1762560057.986 [DataOverHttps](INFO): SBD MOMSN=26293536 2025-11-08T00:01:06.245Z,1762560066.245 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-08T00:01:16.374Z,1762560076.374 [Startup:StartupSatComms:B](INFO): Timed out from 2025-11-08T00:00:16.1Z 2025-11-08T00:01:16.374Z,1762560076.374 [Startup:StartupSatComms:B] Stopped 2025-11-08T00:01:16.375Z,1762560076.375 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-11-08T00:01:16.375Z,1762560076.375 [Startup:StartupSatComms] Stopped 2025-11-08T00:01:16.375Z,1762560076.375 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-11-08T00:01:16.400Z,1762560076.400 [Startup](INFO): Completed Startup 2025-11-08T00:01:16.401Z,1762560076.401 [MissionManager](INFO): Startup is completed. 2025-11-08T00:01:16.401Z,1762560076.401 [MissionManager](INFO): Uninitializing Mission Startup 2025-11-08T00:01:16.401Z,1762560076.401 [Startup] Stopped 2025-11-08T00:01:16.401Z,1762560076.401 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-11-08T00:01:16.401Z,1762560076.401 [Startup:A.GoToSurface] Stopped 2025-11-08T00:01:16.401Z,1762560076.401 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-11-08T00:01:16.794Z,1762560076.794 [MissionManager](IMPORTANT): Started mission Default 2025-11-08T00:01:16.794Z,1762560076.794 [Default] Running Loop=1 2025-11-08T00:01:16.794Z,1762560076.794 [Default](DEBUG): Aggregate::initialize Default 2025-11-08T00:01:16.794Z,1762560076.794 [Default:B.GoToSurface] Running Loop=1 2025-11-08T00:01:16.794Z,1762560076.794 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-11-08T00:01:16.795Z,1762560076.795 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-11-08T00:01:16.795Z,1762560076.795 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-11-08T00:01:16.795Z,1762560076.795 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-11-08T00:01:16.796Z,1762560076.796 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-11-08T00:01:16.820Z,1762560076.820 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-11-08T00:01:16.820Z,1762560076.820 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-11-08T00:01:16.821Z,1762560076.821 [Default:A.Wait] Running Loop=1 2025-11-08T00:01:16.821Z,1762560076.821 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-11-08T00:01:18.029Z,1762560078.029 [DataOverHttps](INFO): Sending 992 bytes from file Logs/20251107T235614/Express0001.lzma 2025-11-08T00:01:19.030Z,1762560079.030 [DataOverHttps](INFO): Moved sent file to Logs/20251107T235614/Express0001.lzma.bak 2025-11-08T00:01:19.030Z,1762560079.030 [DataOverHttps](INFO): SBD MOMSN=26293541 2025-11-08T00:01:21.197Z,1762560081.197 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-08T00:01:30.118Z,1762560090.118 [Default:A.Wait](INFO): Done Waiting. 2025-11-08T00:01:30.118Z,1762560090.118 [Default:A.Wait] Stopped 2025-11-08T00:01:30.118Z,1762560090.118 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-11-08T00:01:30.511Z,1762560090.511 [Default:CheckIn] Running Loop=1 2025-11-08T00:01:30.511Z,1762560090.511 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-11-08T00:01:30.511Z,1762560090.511 [Default:CheckIn:Read_GPS] Running Loop=1 2025-11-08T00:01:30.910Z,1762560090.910 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-11-08T00:01:35.741Z,1762560095.741 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2025-11-08T00:01:42.278Z,1762560102.278 [BPC1](ERROR): Battery stick #17 (s/n: 0084) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2025-11-08T00:01:42.279Z,1762560102.279 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-08T00:01:42.280Z,1762560102.280 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-11-08T00:01:42.281Z,1762560102.281 [BPC1](ERROR): Battery stick #50 (s/n: 019C) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-08T00:01:42.282Z,1762560102.282 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-08T00:01:42.282Z,1762560102.282 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-08T00:01:42.283Z,1762560102.283 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x5AD0. 2025-11-08T00:01:42.283Z,1762560102.283 [BPC1](INFO): Calculating totals. Valid battery stick count: 34. Valid reserve battery stick count: 3. 2025-11-08T00:01:42.287Z,1762560102.287 [BPC1](INFO): Received data from all battery sticks. 2025-11-08T00:02:06.857Z,1762560126.857 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-11-08T00:02:25.472Z,1762560145.472 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-11-08T00:02:25.472Z,1762560145.472 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-08T00:02:25.487Z,1762560145.487 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-08T00:02:25.900Z,1762560145.900 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-08T00:02:25.900Z,1762560145.900 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-11-08T00:04:19.099Z,1762560259.099 [CommandExec](IMPORTANT): got command load ./Missions/marl_lab.tl 2025-11-08T00:04:19.099Z,1762560259.099 [MissionManager](INFO): Loading Mission from file: ./Missions/marl_lab.tl 2025-11-08T00:04:19.099Z,1762560259.099 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/marl_lab.tl 2025-11-08T00:04:19.101Z,1762560259.101 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/marl_lab.tl 2025-11-08T00:04:19.581Z,1762560259.581 [MissionManager](DEBUG): TethyslAPI: ./Missions/marl_lab.tl translated into: 1 8 10 NaN 20 10 1 1 NaN 0 0 Got test_good : and temp var is modem _.others_observations none_str SendData: sent send_observations : to nearby vehicles. Elapsed time Upadating ContactLabel 2025-11-08T00:04:19.587Z,1762560259.587 [MissionManager](INFO): DefineArg marl_lab.MissionTimeout = 1.000000 h 2025-11-08T00:04:19.590Z,1762560259.590 [MissionManager](INFO): DefineArg marl_lab.ContactLabel = 8.000000 count 2025-11-08T00:04:19.593Z,1762560259.593 [MissionManager](INFO): DefineArg marl_lab.SendDataLabel = 10.000000 count 2025-11-08T00:04:19.596Z,1762560259.596 [MissionManager](INFO): DefineArg marl_lab.ContactDepth = nan m 2025-11-08T00:04:19.599Z,1762560259.599 [MissionManager](INFO): DefineArg marl_lab.SendObservationDataInterval = 20.000000 s 2025-11-08T00:04:19.602Z,1762560259.602 [MissionManager](INFO): DefineArg marl_lab.TrackingUpdatePeriod = 10.000000 min 2025-11-08T00:04:19.629Z,1762560259.629 [MissionManager](INFO): DefineArg marl_lab.NumberOfPings = 1.000000 count 2025-11-08T00:04:19.631Z,1762560259.631 [MissionManager](INFO): DefineArg marl_lab.AcousticContactTimeout = 1.000000 h 2025-11-08T00:04:19.646Z,1762560259.646 [MissionManager](INFO): DefineArg marl_lab.MyTempVar = NaN 2025-11-08T00:04:19.650Z,1762560259.650 [MissionManager](INFO): DefineOutput marl_lab.TimeLastSendData = 0.000000 s 2025-11-08T00:04:19.682Z,1762560259.682 [MissionManager](INFO): DefineOutput marl_lab.ElapsedSinceLastSendData = 0.000000 s 2025-11-08T00:04:19.701Z,1762560259.701 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.tl 2025-11-08T00:04:19.701Z,1762560259.701 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/AbortDrift.tl 2025-11-08T00:04:19.702Z,1762560259.702 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/AbortDrift.tl 2025-11-08T00:04:19.861Z,1762560259.861 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/AbortDrift.tl translated into: 96 Insert acoustic timeout set to . stop 2025-11-08T00:04:19.879Z,1762560259.879 [MissionManager](INFO): DefineArg marl_lab:AbortDrift.AcousticTimeout = 96.000000 h 2025-11-08T00:04:19.894Z,1762560259.894 [marl_lab:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift. 2025-11-08T00:04:19.900Z,1762560259.900 [marl_lab:AbortDrift:C.Execute](DEBUG): Construct Execute. 2025-11-08T00:04:19.903Z,1762560259.903 [MissionManager](INFO): RedefineArg marl_lab:AbortDrift.AcousticTimeout = reader:marl_lab.AcousticContactTimeout 2025-11-08T00:04:20.084Z,1762560260.084 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-11-08T00:04:20.085Z,1762560260.085 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-11-08T00:04:20.086Z,1762560260.086 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-11-08T00:04:20.124Z,1762560260.124 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-11-08T00:04:20.132Z,1762560260.132 [MissionManager](INFO): DefineArg marl_lab:BackseatDriver.EnableBackseat = 0 bool 2025-11-08T00:04:20.135Z,1762560260.135 [marl_lab:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-11-08T00:04:20.148Z,1762560260.148 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-11-08T00:04:20.148Z,1762560260.148 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-11-08T00:04:20.149Z,1762560260.149 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-11-08T00:04:20.400Z,1762560260.400 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-11-08T00:04:20.412Z,1762560260.412 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleAll = 0 bool 2025-11-08T00:04:20.417Z,1762560260.417 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad1 = 0 bool 2025-11-08T00:04:20.420Z,1762560260.420 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad2 = 0 bool 2025-11-08T00:04:20.423Z,1762560260.423 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad3 = 0 bool 2025-11-08T00:04:20.426Z,1762560260.426 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.EnabledPowerOnly = 0 bool 2025-11-08T00:04:20.447Z,1762560260.447 [marl_lab:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-11-08T00:04:20.461Z,1762560260.461 [marl_lab:H.Wait](DEBUG): Construct Wait. 2025-11-08T00:04:20.484Z,1762560260.484 [MissionManager](DEBUG): mission marl_lab { """ Lab test mission for marl3 acoustic communications. Tests acoustic tracking and send observation data without driving. """ arguments { MissionTimeout = 1 hour """ Maximum duration of mission """ ContactLabel = 8 count """ The acoustic address of the asset to be tracked. tethys = 6 brizo = 11 daphne = 8 galene = 9 makai = 5 pontus = 10 triton = 12 """ SendDataLabel = 10 count """ The acoustic address of the asset to send observation data to. 10 is pontus """ ContactDepth = NaN meter """ The asset's depth to be tracked """ SendObservationDataInterval = 20 second """ How often to send back some a-comms data """ TrackingUpdatePeriod = 10 minute """ How long to wait between acoustic queries """ NumberOfPings = 1 count """ Number of return pings to request with each acoustic query (more than 1 will activate oneway mode) """ AcousticContactTimeout = 1 hour """ If the vehicle does not receive an acoustic signal for more than this length of time, it will surface for communications with shore. """ MyTempVar = NaN none_str """ A custom variable from the backseat driver interface. """ } output { TimeLastSendData = 0 second ElapsedSinceLastSendData = 0 second """ Time elapsed since last Send Data fix. """ } timeout duration=MissionTimeout insert Insert/AbortDrift.tl { redefineArg AcousticTimeout = AcousticContactTimeout } behavior Estimation:TrackAcousticContact { run in parallel set contactDepthSetting = ContactDepth set contactLabelSetting = ContactLabel set numberOfSamplesSetting = NumberOfPings set updatePeriodSetting = TrackingUpdatePeriod } aggregate SendObservationData { run when ( elapsed ( MyTempVar ) >= SendObservationDataInterval ) syslog info "Got test_good : " + customUri "_.send_observations"~none_str + " and temp var is " + MyTempVar~none_str assign in sequence ElapsedSinceLastSendData = elapsed ( MyTempVar ) assign in sequence MyTempVar = customUri "_.send_observations" behavior Sensor:SendDirect { run in parallel set destType = "modem" set destId = SendDataLabel set destName = "_.others_observations" set value = MyTempVar set unit = "none_str" } syslog info "SendData: sent send_observations : " + MyTempVar~none_str + " to nearby vehicles. Elapsed time " + ElapsedSinceLastSendData~minute } aggregate UpdateContactLabel { run when ( elapsed ( customUri "_.contactLabelSetting" ) < ( elapsed ( ContactLabel ) ) ) assign in sequence ContactLabel = abs ( customUri "_.contactLabelSetting" ) syslog info "Upadating ContactLabel " + customUri "_.contactLabelSetting"~count } insert Insert/BackseatDriver.tl assign in sequence BackseatDriver:EnableBackseat = true insert Insert/PowerOnly.tl behavior Guidance:Wait { run in sequence set duration = MissionTimeout } } 2025-11-08T00:04:20.485Z,1762560260.485 [CommandExec](IMPORTANT): Loaded ./Missions/marl_lab.tl id=marl_lab 2025-11-08T00:05:26.469Z,1762560326.469 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-11-08T00:05:26.469Z,1762560326.469 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-08T00:05:26.510Z,1762560326.510 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-08T00:05:26.881Z,1762560326.881 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-08T00:05:26.881Z,1762560326.881 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-11-08T00:06:01.513Z,1762560361.513 [CommandExec](IMPORTANT): got command set marl_lab.AcousticContactTimeout 2 hour 2025-11-08T00:06:07.572Z,1762560367.572 [CommandExec](IMPORTANT): got command get marl_lab.AcousticContactTimeout 2025-11-08T00:06:07.573Z,1762560367.573 [CommandExec](IMPORTANT): marl_lab.AcousticContactTimeout 2.000000 h 2025-11-08T00:06:30.698Z,1762560390.698 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-08T00:01:30.5Z 2025-11-08T00:06:30.698Z,1762560390.698 [Default:CheckIn:Read_GPS] Stopped 2025-11-08T00:06:30.699Z,1762560390.699 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-11-08T00:06:31.086Z,1762560391.086 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-11-08T00:06:39.220Z,1762560399.220 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251107T235614/Courier0004.lzma 2025-11-08T00:06:40.222Z,1762560400.222 [DataOverHttps](INFO): Moved sent file to Logs/20251107T235614/Courier0004.lzma.bak 2025-11-08T00:06:40.222Z,1762560400.222 [DataOverHttps](INFO): SBD MOMSN=26293564 2025-11-08T00:06:55.884Z,1762560415.884 [DataOverHttps](INFO): Sending 302 bytes from file Logs/20251107T235614/Express0005.lzma 2025-11-08T00:06:56.886Z,1762560416.886 [DataOverHttps](INFO): Moved sent file to Logs/20251107T235614/Express0005.lzma.bak 2025-11-08T00:06:56.886Z,1762560416.886 [DataOverHttps](INFO): SBD MOMSN=26293566 2025-11-08T00:06:58.162Z,1762560418.162 [Default:CheckIn:Read_Iridium] Stopped 2025-11-08T00:06:58.163Z,1762560418.163 [Default:CheckIn:C.Wait] Running Loop=1 2025-11-08T00:06:58.163Z,1762560418.163 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-11-08T00:07:01.292Z,1762560421.292 [CommandExec](IMPORTANT): got command run 2025-11-08T00:07:01.295Z,1762560421.295 [CommandExec](IMPORTANT): Running 2025-11-08T00:07:01.401Z,1762560421.401 [Default] Stopped 2025-11-08T00:07:01.401Z,1762560421.401 [Default](DEBUG): Aggregate::uninitialize Default 2025-11-08T00:07:01.401Z,1762560421.401 [Default:B.GoToSurface] Stopped 2025-11-08T00:07:01.401Z,1762560421.401 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-11-08T00:07:01.401Z,1762560421.401 [Default:CheckIn] Stopped 2025-11-08T00:07:01.401Z,1762560421.401 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-11-08T00:07:01.402Z,1762560421.402 [Default:CheckIn:C.Wait] Stopped 2025-11-08T00:07:01.402Z,1762560421.402 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-11-08T00:07:01.402Z,1762560421.402 [MissionManager](IMPORTANT): Started mission marl_lab 2025-11-08T00:07:01.402Z,1762560421.402 [marl_lab] Running Loop=1 2025-11-08T00:07:01.402Z,1762560421.402 [marl_lab](DEBUG): Aggregate::initialize marl_lab 2025-11-08T00:07:01.402Z,1762560421.402 [marl_lab:AbortDrift] Running Loop=1 2025-11-08T00:07:01.402Z,1762560421.402 [marl_lab:AbortDrift](DEBUG): Aggregate::initialize marl_lab:AbortDrift 2025-11-08T00:07:01.402Z,1762560421.402 [marl_lab:AbortDrift:A] Running Loop=1 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:B.] Running Loop=1 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:B.](INFO): Initializing TrackAcousticContact. 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:BackseatDriver] Running Loop=1 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:BackseatDriver](DEBUG): Aggregate::initialize marl_lab:BackseatDriver 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:PowerOnly] Running Loop=1 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:PowerOnly](DEBUG): Aggregate::initialize marl_lab:PowerOnly 2025-11-08T00:07:01.403Z,1762560421.403 [marl_lab:PowerOnly:A] Running Loop=1 2025-11-08T00:07:01.404Z,1762560421.404 [marl_lab:PowerOnly:B] Running Loop=1 2025-11-08T00:07:01.408Z,1762560421.408 [marl_lab:PowerOnly:C] Running Loop=1 2025-11-08T00:07:01.408Z,1762560421.408 [marl_lab:PowerOnly:D] Running Loop=1 2025-11-08T00:07:01.408Z,1762560421.408 [marl_lab:PowerOnly:E.Wait] Running Loop=1 2025-11-08T00:07:01.408Z,1762560421.408 [marl_lab:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-11-08T00:07:01.408Z,1762560421.408 [marl_lab:F] Running Loop=1 2025-11-08T00:07:01.409Z,1762560421.409 [marl_lab:PowerOnly] Running Loop=1 2025-11-08T00:07:01.409Z,1762560421.409 [marl_lab:PowerOnly:D] Stopped 2025-11-08T00:07:01.409Z,1762560421.409 [marl_lab:PowerOnly:C] Stopped 2025-11-08T00:07:01.409Z,1762560421.409 [marl_lab:PowerOnly:B] Stopped 2025-11-08T00:07:01.409Z,1762560421.409 [marl_lab:PowerOnly:A] Stopped 2025-11-08T00:07:01.409Z,1762560421.409 [marl_lab:F] Stopped 2025-11-08T00:07:01.410Z,1762560421.410 [marl_lab:H.Wait] Running Loop=1 2025-11-08T00:07:01.410Z,1762560421.410 [marl_lab:H.Wait](DEBUG): Initialize Wait Component. 2025-11-08T00:07:01.410Z,1762560421.410 [marl_lab:BackseatDriver] Running Loop=1 2025-11-08T00:07:01.410Z,1762560421.410 [marl_lab:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat 2025-11-08T00:07:01.502Z,1762560421.502 [marl_lab:SendObservationData] Running Loop=1 2025-11-08T00:07:01.502Z,1762560421.502 [marl_lab:SendObservationData](DEBUG): Aggregate::initialize marl_lab:SendObservationData 2025-11-08T00:07:01.502Z,1762560421.502 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-08T00:07:01.503Z,1762560421.503 [marl_lab:SendObservationData:A] Running Loop=1 2025-11-08T00:07:01.503Z,1762560421.503 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-08T00:07:01.512Z,1762560421.512 [marl_lab:SendObservationData:A](ERROR): data element is not active. 2025-11-08T00:07:01.512Z,1762560421.512 [marl_lab:SendObservationData:A](INFO): Got test_good : n/a str and temp var is NaN n/a str 2025-11-08T00:07:01.512Z,1762560421.512 [marl_lab:SendObservationData:A] Stopped 2025-11-08T00:07:01.513Z,1762560421.513 [marl_lab:SendObservationData:B] Running Loop=1 2025-11-08T00:07:01.513Z,1762560421.513 [marl_lab:B.] Running Loop=1 2025-11-08T00:07:01.513Z,1762560421.513 [marl_lab:AbortDrift] Running Loop=1 2025-11-08T00:07:01.514Z,1762560421.514 [marl_lab:AbortDrift:A](INFO): Insert acoustic timeout set to 2.000000 h . 2025-11-08T00:07:01.514Z,1762560421.514 [marl_lab:AbortDrift:A] Stopped 2025-11-08T00:07:01.514Z,1762560421.514 [marl_lab:AbortDrift:B.AbortDrift] Running Loop=1 2025-11-08T00:07:01.514Z,1762560421.514 [marl_lab:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift. 2025-11-08T00:07:01.515Z,1762560421.515 [marl_lab:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 2.00 hours. 2025-11-08T00:07:01.776Z,1762560421.776 [BackseatComponent](INFO): Powering up 2025-11-08T00:07:01.776Z,1762560421.776 [BackseatComponent](INFO): Subscribing to LCM channels. 2025-11-08T00:07:01.856Z,1762560421.856 [marl_lab:SendObservationData:B] Stopped 2025-11-08T00:07:01.857Z,1762560421.857 [marl_lab:SendObservationData:C] Running Loop=1 2025-11-08T00:07:02.224Z,1762560422.224 [marl_lab:SendObservationData:C] Stopped 2025-11-08T00:07:02.225Z,1762560422.225 [marl_lab:SendObservationData:E] Running Loop=1 2025-11-08T00:07:02.625Z,1762560422.625 [marl_lab:SendObservationData:E](INFO): SendData: sent send_observations : n/a str to nearby vehicles. Elapsed time 2.703506 min 2025-11-08T00:07:02.625Z,1762560422.625 [marl_lab:SendObservationData:E] Stopped 2025-11-08T00:07:02.625Z,1762560422.625 [marl_lab:SendObservationData](INFO): Completed marl_lab:SendObservationData 2025-11-08T00:07:02.625Z,1762560422.625 [marl_lab:SendObservationData] Stopped 2025-11-08T00:07:02.625Z,1762560422.625 [marl_lab:SendObservationData](DEBUG): Aggregate::uninitialize marl_lab:SendObservationData 2025-11-08T00:07:02.625Z,1762560422.625 [marl_lab:SendObservationData:D.SendDirect] Stopped 2025-11-08T00:07:04.949Z,1762560424.949 [CTD_Seabird](ERROR): Failed to parse device response: 2025-11-08T00:07:05.822Z,1762560425.822 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-11-08T00:07:05.822Z,1762560425.822 [NAL9602] Data Fault, FailCount= 1 2025-11-08T00:07:05.822Z,1762560425.822 [NAL9602](ERROR): Data Fault 2025-11-08T00:07:05.873Z,1762560425.873 [CBIT](ERROR): Data Fault in component: NAL9602 2025-11-08T00:07:06.221Z,1762560426.221 [NAL9602](INFO): Powering down 2025-11-08T00:07:06.959Z,1762560426.959 [CTD_Seabird](ERROR): Salinity reading out of range: 1.900830 psu 2025-11-08T00:07:06.961Z,1762560426.961 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:07.052Z,1762560427.052 [CBIT](INFO): Clearing failed state for component NAL9602 2025-11-08T00:07:07.053Z,1762560427.053 [NAL9602] No Fault, FailCount= 1 2025-11-08T00:07:07.962Z,1762560427.962 [CTD_Seabird](ERROR): Salinity reading out of range: 1.893121 psu 2025-11-08T00:07:07.963Z,1762560427.963 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:08.966Z,1762560428.966 [CTD_Seabird](ERROR): Salinity reading out of range: 1.905028 psu 2025-11-08T00:07:08.967Z,1762560428.967 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:09.970Z,1762560429.970 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892524 psu 2025-11-08T00:07:09.971Z,1762560429.971 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:10.974Z,1762560430.974 [CTD_Seabird](ERROR): Salinity reading out of range: 1.893130 psu 2025-11-08T00:07:10.975Z,1762560430.975 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:11.978Z,1762560431.978 [CTD_Seabird](ERROR): Salinity reading out of range: 1.886539 psu 2025-11-08T00:07:11.979Z,1762560431.979 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:12.698Z,1762560432.698 [marl_lab:BackseatDriver:A.BackseatDriver](INFO): Created data writer for _.send_observations with code: 2007 2025-11-08T00:07:12.982Z,1762560432.982 [CTD_Seabird](ERROR): Salinity reading out of range: 1.901878 psu 2025-11-08T00:07:12.983Z,1762560432.983 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:13.986Z,1762560433.986 [CTD_Seabird](ERROR): Salinity reading out of range: 1.899208 psu 2025-11-08T00:07:13.987Z,1762560433.987 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:14.990Z,1762560434.990 [CTD_Seabird](ERROR): Salinity reading out of range: 1.891335 psu 2025-11-08T00:07:14.991Z,1762560434.991 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:15.994Z,1762560435.994 [CTD_Seabird](ERROR): Salinity reading out of range: 1.897131 psu 2025-11-08T00:07:15.995Z,1762560435.995 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:16.998Z,1762560436.998 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892066 psu 2025-11-08T00:07:16.999Z,1762560436.999 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:18.003Z,1762560438.003 [CTD_Seabird](ERROR): Salinity reading out of range: 1.889769 psu 2025-11-08T00:07:18.004Z,1762560438.004 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:19.006Z,1762560439.006 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892299 psu 2025-11-08T00:07:19.007Z,1762560439.007 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:20.010Z,1762560440.010 [CTD_Seabird](ERROR): Salinity reading out of range: 1.889198 psu 2025-11-08T00:07:20.011Z,1762560440.011 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:21.014Z,1762560441.014 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892792 psu 2025-11-08T00:07:21.015Z,1762560441.015 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:22.018Z,1762560442.018 [CTD_Seabird](ERROR): Salinity reading out of range: 1.888502 psu 2025-11-08T00:07:22.019Z,1762560442.019 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:22.396Z,1762560442.396 [marl_lab:SendObservationData] Running Loop=1 2025-11-08T00:07:22.396Z,1762560442.396 [marl_lab:SendObservationData](DEBUG): Aggregate::initialize marl_lab:SendObservationData 2025-11-08T00:07:22.396Z,1762560442.396 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-08T00:07:22.397Z,1762560442.397 [marl_lab:SendObservationData:A] Running Loop=1 2025-11-08T00:07:22.398Z,1762560442.398 [marl_lab:SendObservationData:A](INFO): Got test_good : test_msg_4 n/a str and temp var is n/a str 2025-11-08T00:07:22.398Z,1762560442.398 [marl_lab:SendObservationData:A] Stopped 2025-11-08T00:07:22.398Z,1762560442.398 [marl_lab:SendObservationData:B] Running Loop=1 2025-11-08T00:07:22.809Z,1762560442.809 [marl_lab:SendObservationData:B] Stopped 2025-11-08T00:07:22.809Z,1762560442.809 [marl_lab:SendObservationData:C] Running Loop=1 2025-11-08T00:07:23.022Z,1762560443.022 [CTD_Seabird](ERROR): Salinity reading out of range: 1.890366 psu 2025-11-08T00:07:23.023Z,1762560443.023 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:23.204Z,1762560443.204 [marl_lab:SendObservationData:C] Stopped 2025-11-08T00:07:23.205Z,1762560443.205 [marl_lab:SendObservationData:E] Running Loop=1 2025-11-08T00:07:23.605Z,1762560443.605 [marl_lab:SendObservationData:E](INFO): SendData: sent send_observations : test_msg_5 n/a str to nearby vehicles. Elapsed time 0.343067 min 2025-11-08T00:07:23.605Z,1762560443.605 [marl_lab:SendObservationData:E] Stopped 2025-11-08T00:07:23.605Z,1762560443.605 [marl_lab:SendObservationData](INFO): Completed marl_lab:SendObservationData 2025-11-08T00:07:23.605Z,1762560443.605 [marl_lab:SendObservationData] Stopped 2025-11-08T00:07:23.605Z,1762560443.605 [marl_lab:SendObservationData](DEBUG): Aggregate::uninitialize marl_lab:SendObservationData 2025-11-08T00:07:23.606Z,1762560443.606 [marl_lab:SendObservationData:D.SendDirect] Stopped 2025-11-08T00:07:24.026Z,1762560444.026 [CTD_Seabird](ERROR): Salinity reading out of range: 1.891261 psu 2025-11-08T00:07:24.027Z,1762560444.027 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:25.030Z,1762560445.030 [CTD_Seabird](ERROR): Salinity reading out of range: 1.886206 psu 2025-11-08T00:07:25.031Z,1762560445.031 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:26.034Z,1762560446.034 [CTD_Seabird](ERROR): Salinity reading out of range: 1.894588 psu 2025-11-08T00:07:26.035Z,1762560446.035 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:27.038Z,1762560447.038 [CTD_Seabird](ERROR): Salinity reading out of range: 1.893926 psu 2025-11-08T00:07:27.039Z,1762560447.039 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:28.042Z,1762560448.042 [CTD_Seabird](ERROR): Salinity reading out of range: 1.897689 psu 2025-11-08T00:07:28.043Z,1762560448.043 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:29.046Z,1762560449.046 [CTD_Seabird](ERROR): Salinity reading out of range: 1.895613 psu 2025-11-08T00:07:29.047Z,1762560449.047 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:30.050Z,1762560450.050 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892598 psu 2025-11-08T00:07:30.051Z,1762560450.051 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:31.054Z,1762560451.054 [CTD_Seabird](ERROR): Salinity reading out of range: 1.890902 psu 2025-11-08T00:07:31.055Z,1762560451.055 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:32.017Z,1762560452.017 [BackseatComponent](IMPORTANT): netra: running backseat application. 2025-11-08T00:07:32.094Z,1762560452.094 [CTD_Seabird](ERROR): Salinity reading out of range: 1.897036 psu 2025-11-08T00:07:32.095Z,1762560452.095 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:32.425Z,1762560452.425 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:32.425Z,1762560452.425 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:32.630Z,1762560452.630 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:32.630Z,1762560452.630 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:33.037Z,1762560453.037 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:33.037Z,1762560453.037 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:33.098Z,1762560453.098 [CTD_Seabird](ERROR): Salinity reading out of range: 1.894133 psu 2025-11-08T00:07:33.100Z,1762560453.100 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:33.241Z,1762560453.241 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:33.241Z,1762560453.241 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:33.649Z,1762560453.649 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:33.649Z,1762560453.649 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:33.853Z,1762560453.853 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:33.853Z,1762560453.853 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:34.102Z,1762560454.102 [CTD_Seabird](ERROR): Salinity reading out of range: 1.896538 psu 2025-11-08T00:07:34.103Z,1762560454.103 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:34.261Z,1762560454.261 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:34.261Z,1762560454.261 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:34.465Z,1762560454.465 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:34.465Z,1762560454.465 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:34.873Z,1762560454.873 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:34.873Z,1762560454.873 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:35.078Z,1762560455.078 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:35.078Z,1762560455.078 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:35.106Z,1762560455.106 [CTD_Seabird](ERROR): Salinity reading out of range: 1.895375 psu 2025-11-08T00:07:35.107Z,1762560455.107 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:36.110Z,1762560456.110 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892187 psu 2025-11-08T00:07:36.111Z,1762560456.111 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:36.525Z,1762560456.525 [NAL9602](INFO): Powering up NAL9602 2025-11-08T00:07:37.114Z,1762560457.114 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892529 psu 2025-11-08T00:07:37.115Z,1762560457.115 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:37.517Z,1762560457.517 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:37.517Z,1762560457.517 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:38.118Z,1762560458.118 [CTD_Seabird](ERROR): Salinity reading out of range: 1.889756 psu 2025-11-08T00:07:38.119Z,1762560458.119 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:39.122Z,1762560459.122 [CTD_Seabird](ERROR): Salinity reading out of range: 1.888113 psu 2025-11-08T00:07:39.123Z,1762560459.123 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:40.028Z,1762560460.028 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:40.029Z,1762560460.029 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:40.126Z,1762560460.126 [CTD_Seabird](ERROR): Salinity reading out of range: 1.887555 psu 2025-11-08T00:07:40.127Z,1762560460.127 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:41.130Z,1762560461.130 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892844 psu 2025-11-08T00:07:41.132Z,1762560461.132 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:42.134Z,1762560462.134 [CTD_Seabird](ERROR): Salinity reading out of range: 1.895461 psu 2025-11-08T00:07:42.135Z,1762560462.135 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:42.734Z,1762560462.734 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:42.734Z,1762560462.734 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:43.138Z,1762560463.138 [CTD_Seabird](ERROR): Salinity reading out of range: 1.889475 psu 2025-11-08T00:07:43.139Z,1762560463.139 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:43.404Z,1762560463.404 [marl_lab:SendObservationData] Running Loop=1 2025-11-08T00:07:43.404Z,1762560463.404 [marl_lab:SendObservationData](DEBUG): Aggregate::initialize marl_lab:SendObservationData 2025-11-08T00:07:43.404Z,1762560463.404 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-08T00:07:43.405Z,1762560463.405 [marl_lab:SendObservationData:A] Running Loop=1 2025-11-08T00:07:43.406Z,1762560463.406 [marl_lab:SendObservationData:A](INFO): Got test_good : test_msg_13 n/a str and temp var is test_msg_5 n/a str 2025-11-08T00:07:43.406Z,1762560463.406 [marl_lab:SendObservationData:A] Stopped 2025-11-08T00:07:43.406Z,1762560463.406 [marl_lab:SendObservationData:B] Running Loop=1 2025-11-08T00:07:43.808Z,1762560463.808 [marl_lab:SendObservationData:B] Stopped 2025-11-08T00:07:43.808Z,1762560463.808 [marl_lab:SendObservationData:C] Running Loop=1 2025-11-08T00:07:44.142Z,1762560464.142 [CTD_Seabird](ERROR): Salinity reading out of range: 1.894112 psu 2025-11-08T00:07:44.143Z,1762560464.143 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:44.245Z,1762560464.245 [marl_lab:SendObservationData:C] Stopped 2025-11-08T00:07:44.245Z,1762560464.245 [marl_lab:SendObservationData:E] Running Loop=1 2025-11-08T00:07:44.629Z,1762560464.629 [marl_lab:SendObservationData:E](INFO): SendData: sent send_observations : test_msg_13 n/a str to nearby vehicles. Elapsed time 0.343399 min 2025-11-08T00:07:44.629Z,1762560464.629 [marl_lab:SendObservationData:E] Stopped 2025-11-08T00:07:44.629Z,1762560464.629 [marl_lab:SendObservationData](INFO): Completed marl_lab:SendObservationData 2025-11-08T00:07:44.630Z,1762560464.630 [marl_lab:SendObservationData] Stopped 2025-11-08T00:07:44.630Z,1762560464.630 [marl_lab:SendObservationData](DEBUG): Aggregate::uninitialize marl_lab:SendObservationData 2025-11-08T00:07:44.630Z,1762560464.630 [marl_lab:SendObservationData:D.SendDirect] Stopped 2025-11-08T00:07:45.062Z,1762560465.062 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:45.062Z,1762560465.062 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:45.146Z,1762560465.146 [CTD_Seabird](ERROR): Salinity reading out of range: 1.895470 psu 2025-11-08T00:07:45.147Z,1762560465.147 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:46.150Z,1762560466.150 [CTD_Seabird](ERROR): Salinity reading out of range: 1.891850 psu 2025-11-08T00:07:46.151Z,1762560466.151 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:47.154Z,1762560467.154 [CTD_Seabird](ERROR): Salinity reading out of range: 1.892494 psu 2025-11-08T00:07:47.155Z,1762560467.155 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:47.434Z,1762560467.434 [NAL9602](INFO): NAL9602 initialized 2025-11-08T00:07:47.765Z,1762560467.765 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:47.765Z,1762560467.765 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:48.162Z,1762560468.162 [CTD_Seabird](ERROR): Salinity reading out of range: 1.883870 psu 2025-11-08T00:07:48.163Z,1762560468.163 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:49.162Z,1762560469.162 [CTD_Seabird](ERROR): Salinity reading out of range: 1.893653 psu 2025-11-08T00:07:49.163Z,1762560469.163 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:50.080Z,1762560470.080 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:50.081Z,1762560470.081 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:50.166Z,1762560470.166 [CTD_Seabird](ERROR): Salinity reading out of range: 1.890872 psu 2025-11-08T00:07:50.167Z,1762560470.167 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:51.171Z,1762560471.171 [CTD_Seabird](ERROR): Salinity reading out of range: 1.888753 psu 2025-11-08T00:07:51.172Z,1762560471.172 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:52.174Z,1762560472.174 [CTD_Seabird](ERROR): Salinity reading out of range: 1.881419 psu 2025-11-08T00:07:52.175Z,1762560472.175 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:52.786Z,1762560472.786 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:52.786Z,1762560472.786 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:53.178Z,1762560473.178 [CTD_Seabird](ERROR): Salinity reading out of range: 1.886582 psu 2025-11-08T00:07:53.179Z,1762560473.179 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:54.182Z,1762560474.182 [CTD_Seabird](ERROR): Salinity reading out of range: 1.886759 psu 2025-11-08T00:07:54.183Z,1762560474.183 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:55.117Z,1762560475.117 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:55.118Z,1762560475.118 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:55.186Z,1762560475.186 [CTD_Seabird](ERROR): Salinity reading out of range: 1.886945 psu 2025-11-08T00:07:55.187Z,1762560475.187 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:56.190Z,1762560476.190 [CTD_Seabird](ERROR): Salinity reading out of range: 1.885250 psu 2025-11-08T00:07:56.191Z,1762560476.191 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:57.194Z,1762560477.194 [CTD_Seabird](ERROR): Salinity reading out of range: 1.885825 psu 2025-11-08T00:07:57.195Z,1762560477.195 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:57.821Z,1762560477.821 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:07:57.821Z,1762560477.821 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:07:58.198Z,1762560478.198 [CTD_Seabird](ERROR): Salinity reading out of range: 1.884917 psu 2025-11-08T00:07:58.199Z,1762560478.199 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:07:59.202Z,1762560479.202 [CTD_Seabird](ERROR): Salinity reading out of range: 1.884735 psu 2025-11-08T00:07:59.203Z,1762560479.203 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:08:00.150Z,1762560480.150 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:08:00.150Z,1762560480.150 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:08:00.206Z,1762560480.206 [CTD_Seabird](ERROR): Salinity reading out of range: 1.884964 psu 2025-11-08T00:08:00.207Z,1762560480.207 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:08:01.223Z,1762560481.223 [CTD_Seabird](ERROR): Salinity reading out of range: 1.884614 psu 2025-11-08T00:08:01.224Z,1762560481.224 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:08:02.226Z,1762560482.226 [CTD_Seabird](ERROR): Salinity reading out of range: 1.884951 psu 2025-11-08T00:08:02.227Z,1762560482.227 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:08:02.857Z,1762560482.857 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:08:02.857Z,1762560482.857 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:08:03.230Z,1762560483.230 [CTD_Seabird](ERROR): Salinity reading out of range: 1.884528 psu 2025-11-08T00:08:03.231Z,1762560483.231 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:08:04.234Z,1762560484.234 [CTD_Seabird](ERROR): Salinity reading out of range: 1.884294 psu 2025-11-08T00:08:04.235Z,1762560484.235 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-08T00:08:04.452Z,1762560484.452 [marl_lab:SendObservationData] Running Loop=1 2025-11-08T00:08:04.452Z,1762560484.452 [marl_lab:SendObservationData](DEBUG): Aggregate::initialize marl_lab:SendObservationData 2025-11-08T00:08:04.452Z,1762560484.452 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-08T00:08:04.453Z,1762560484.453 [marl_lab:SendObservationData:A] Running Loop=1 2025-11-08T00:08:04.454Z,1762560484.454 [marl_lab:SendObservationData:A](INFO): Got test_good : test_msg_21 n/a str and temp var is test_msg_13 n/a str 2025-11-08T00:08:04.454Z,1762560484.454 [marl_lab:SendObservationData:A] Stopped 2025-11-08T00:08:04.454Z,1762560484.454 [marl_lab:SendObservationData:B] Running Loop=1 2025-11-08T00:08:04.633Z,1762560484.633 [CommandExec](IMPORTANT): got command stop 2025-11-08T00:08:04.633Z,1762560484.633 [CommandExec](IMPORTANT): Scheduling is paused 2025-11-08T00:08:04.633Z,1762560484.633 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-11-08T00:08:04.841Z,1762560484.841 [marl_lab:SendObservationData:B] Stopped 2025-11-08T00:08:04.841Z,1762560484.841 [marl_lab:SendObservationData:C] Running Loop=1 2025-11-08T00:08:04.841Z,1762560484.841 [MissionManager](INFO): MissionManager is completed. 2025-11-08T00:08:04.841Z,1762560484.841 [MissionManager](INFO): Uninitializing Mission marl_lab 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab] Stopped 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab](DEBUG): Aggregate::uninitialize marl_lab 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:AbortDrift] Stopped 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:AbortDrift](DEBUG): Aggregate::uninitialize marl_lab:AbortDrift 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:AbortDrift:B.AbortDrift] Stopped 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift. 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:B.] Stopped 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:B.](DEBUG): Uninitializing TrackAcousticContact. 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:SendObservationData] Stopped 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:SendObservationData](DEBUG): Aggregate::uninitialize marl_lab:SendObservationData 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:SendObservationData:C] Stopped 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:SendObservationData:D.SendDirect] Stopped 2025-11-08T00:08:04.842Z,1762560484.842 [marl_lab:BackseatDriver] Stopped 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:BackseatDriver](DEBUG): Aggregate::uninitialize marl_lab:BackseatDriver 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:BackseatDriver:A.BackseatDriver] Stopped 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:PowerOnly] Stopped 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:PowerOnly](DEBUG): Aggregate::uninitialize marl_lab:PowerOnly 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:PowerOnly:E.Wait] Stopped 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:H.Wait] Stopped 2025-11-08T00:08:04.843Z,1762560484.843 [marl_lab:H.Wait](DEBUG): Uninitialize Wait Component. 2025-11-08T00:08:05.184Z,1762560485.184 [BackseatComponent](FAULT): Failed to create a data reader. _.others_observations is unknown. 2025-11-08T00:08:05.184Z,1762560485.184 [BackseatComponent](ERROR): Failed to request data from _.others_observations. 2025-11-08T00:08:05.189Z,1762560485.189 [BackseatComponent](INFO): Sent LCM shutdown request. 2025-11-08T00:08:05.190Z,1762560485.190 [BackseatComponent](INFO): Shutdown requested. Waiting (30.00 sec to power down.). 2025-11-08T00:08:05.281Z,1762560485.281 [MissionManager](IMPORTANT): Started mission Default 2025-11-08T00:08:05.282Z,1762560485.282 [Default] Running Loop=1 2025-11-08T00:08:05.282Z,1762560485.282 [Default](DEBUG): Aggregate::initialize Default 2025-11-08T00:08:05.282Z,1762560485.282 [Default:B.GoToSurface] Running Loop=1 2025-11-08T00:08:05.282Z,1762560485.282 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-11-08T00:08:05.282Z,1762560485.282 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-11-08T00:08:05.282Z,1762560485.282 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-11-08T00:08:05.283Z,1762560485.283 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-11-08T00:08:05.283Z,1762560485.283 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-11-08T00:08:05.283Z,1762560485.283 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-11-08T00:08:05.296Z,1762560485.296 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-11-08T00:08:05.296Z,1762560485.296 [Default:A.Wait] Running Loop=1 2025-11-08T00:08:05.296Z,1762560485.296 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-11-08T00:08:18.567Z,1762560498.567 [Default:A.Wait](INFO): Done Waiting. 2025-11-08T00:08:18.567Z,1762560498.567 [Default:A.Wait] Stopped 2025-11-08T00:08:18.567Z,1762560498.567 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-11-08T00:08:18.974Z,1762560498.974 [Default:CheckIn] Running Loop=1 2025-11-08T00:08:18.975Z,1762560498.975 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-11-08T00:08:18.975Z,1762560498.975 [Default:CheckIn:Read_GPS] Running Loop=1 2025-11-08T00:08:27.449Z,1762560507.449 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-11-08T00:08:27.449Z,1762560507.449 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-08T00:08:27.460Z,1762560507.460 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-08T00:08:27.874Z,1762560507.874 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-08T00:08:27.874Z,1762560507.874 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-11-08T00:08:35.204Z,1762560515.204 [BackseatComponent](INFO): Powering down and starting shutdown timer (30.00 sec). 2025-11-08T00:08:35.205Z,1762560515.205 [BackseatComponent](INFO): Unsubscribing from LCM channels. 2025-11-08T00:08:35.205Z,1762560515.205 [LcmPublisher](INFO): Deactivating messaging. 2025-11-08T00:09:05.596Z,1762560545.596 [CommandExec](IMPORTANT): got command get depth 2025-11-08T00:09:05.597Z,1762560545.597 [CommandExec](IMPORTANT): depth -0.024674 m 2025-11-08T00:09:31.782Z,1762560571.782 [CommandExec](IMPORTANT): got command configSet DAT.surfaceThreshold -0.5 meter persist 2025-11-08T00:09:31.838Z,1762560571.838 [DAT](INFO): modem://10: set _.others_observations string "NaN" 2025-11-08T00:09:31.838Z,1762560571.838 [DAT](INFO): #Outgoing data=1 2025-11-08T00:09:31.838Z,1762560571.838 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:09:32.089Z,1762560572.089 [DAT](INFO): setting remote address to 10 2025-11-08T00:09:32.341Z,1762560572.341 [DAT](INFO): DAT read: user:6> 2025-11-08T00:09:32.342Z,1762560572.342 [DAT](INFO): DAT read: RemoteAddr | 10 2025-11-08T00:09:32.342Z,1762560572.342 [DAT](INFO): set remote address to 10 2025-11-08T00:09:32.343Z,1762560572.343 [DAT](INFO): entering online mode 2025-11-08T00:09:32.593Z,1762560572.593 [DAT](INFO): DAT read: user:7> 2025-11-08T00:09:32.593Z,1762560572.593 [DAT](INFO): DAT read: 2025-11-08T00:09:32.594Z,1762560572.594 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-11-08T00:09:32.595Z,1762560572.595 [DAT](INFO): commRate: 800 2025-11-08T00:09:32.595Z,1762560572.595 [DAT](INFO): online mode acknowledged 2025-11-08T00:09:32.595Z,1762560572.595 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:09:35.869Z,1762560575.869 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:09:35.1630 2025-11-08T00:09:35.870Z,1762560575.870 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:09:42.933Z,1762560582.933 [DAT](INFO): DAT read: Rx Time:00:09:41.6467 2025-11-08T00:09:42.933Z,1762560582.933 [DAT](INFO): Rx dataTimestamp_ set to:1762560582.933144 2025-11-08T00:09:43.689Z,1762560583.689 [DAT](INFO): DAT read: 2025-11-08T00:09:43.689Z,1762560583.689 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:09:43.690Z,1762560583.690 [DAT](INFO): Got DATA 2 2025-11-08T00:09:43.690Z,1762560583.690 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:09:43.690Z,1762560583.690 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:09:43.691Z,1762560583.691 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:09:43.692Z,1762560583.692 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:19.7 AGC:19 SPD:+0.0 CCERR:013 2025-11-08T00:09:43.692Z,1762560583.692 [DAT](INFO): Got CRC:Pass 2025-11-08T00:09:43.692Z,1762560583.692 [DAT](INFO): Got CRC:Pass 2025-11-08T00:09:43.692Z,1762560583.692 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:09:43.693Z,1762560583.693 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:09:43.693Z,1762560583.693 [DAT](INFO): Got ack 2025-11-08T00:09:43.693Z,1762560583.693 [DAT](INFO): DAT read: 2025-11-08T00:09:43.693Z,1762560583.693 [DAT](INFO): DAT read: 2025-11-08T00:09:43.694Z,1762560583.694 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:09:43.941Z,1762560583.941 [DAT](INFO): modem://10: set _.others_observations string "NaN" 2025-11-08T00:09:43.941Z,1762560583.941 [DAT](INFO): #Outgoing data=1 2025-11-08T00:09:43.941Z,1762560583.941 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:09:44.193Z,1762560584.193 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:09:47.482Z,1762560587.482 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:09:46.7630 2025-11-08T00:09:47.483Z,1762560587.483 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:09:53.789Z,1762560593.789 [DAT](INFO): DAT read: Rx Time:00:09:52.4968 2025-11-08T00:09:53.789Z,1762560593.789 [DAT](INFO): Rx dataTimestamp_ set to:1762560593.789021 2025-11-08T00:09:54.544Z,1762560594.544 [DAT](INFO): DAT read: 2025-11-08T00:09:54.545Z,1762560594.545 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:09:54.545Z,1762560594.545 [DAT](INFO): Got DATA 2 2025-11-08T00:09:54.546Z,1762560594.546 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:09:54.546Z,1762560594.546 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:09:54.547Z,1762560594.547 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:09:54.548Z,1762560594.548 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.4 AGC:16 SPD:+0.0 CCERR:013 2025-11-08T00:09:54.548Z,1762560594.548 [DAT](INFO): Got CRC:Pass 2025-11-08T00:09:54.548Z,1762560594.548 [DAT](INFO): Got CRC:Pass 2025-11-08T00:09:54.548Z,1762560594.548 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:09:54.548Z,1762560594.548 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:09:54.549Z,1762560594.549 [DAT](INFO): Got ack 2025-11-08T00:09:54.549Z,1762560594.549 [DAT](INFO): DAT read: 2025-11-08T00:09:54.549Z,1762560594.549 [DAT](INFO): DAT read: 2025-11-08T00:09:54.550Z,1762560594.550 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:09:54.797Z,1762560594.797 [DAT](INFO): modem://10: set _.others_observations string "NaN" 2025-11-08T00:09:54.797Z,1762560594.797 [DAT](INFO): #Outgoing data=1 2025-11-08T00:09:54.798Z,1762560594.798 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:09:55.049Z,1762560595.049 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:09:58.325Z,1762560598.325 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:09:57.6131 2025-11-08T00:09:58.326Z,1762560598.326 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:10:04.628Z,1762560604.628 [DAT](INFO): DAT read: Rx Time:00:10:03.3470 2025-11-08T00:10:04.630Z,1762560604.630 [DAT](INFO): Rx dataTimestamp_ set to:1762560604.628817 2025-11-08T00:10:05.381Z,1762560605.381 [DAT](INFO): DAT read: 2025-11-08T00:10:05.382Z,1762560605.382 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:10:05.382Z,1762560605.382 [DAT](INFO): Got DATA 2 2025-11-08T00:10:05.383Z,1762560605.383 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:10:05.383Z,1762560605.383 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:10:05.383Z,1762560605.383 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:10:05.385Z,1762560605.385 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.2 AGC:17 SPD:+0.0 CCERR:013 2025-11-08T00:10:05.385Z,1762560605.385 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:05.385Z,1762560605.385 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:05.385Z,1762560605.385 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:10:05.385Z,1762560605.385 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:10:05.385Z,1762560605.385 [DAT](INFO): Got ack 2025-11-08T00:10:05.385Z,1762560605.385 [DAT](INFO): DAT read: 2025-11-08T00:10:05.386Z,1762560605.386 [DAT](INFO): DAT read: 2025-11-08T00:10:05.386Z,1762560605.386 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:10:05.633Z,1762560605.633 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-08T00:10:05.633Z,1762560605.633 [DAT](INFO): #Outgoing data=1 2025-11-08T00:10:05.634Z,1762560605.634 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:10:05.885Z,1762560605.885 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:10:09.161Z,1762560609.161 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:08.4632 2025-11-08T00:10:09.161Z,1762560609.161 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:10:15.461Z,1762560615.461 [DAT](INFO): DAT read: Rx Time:00:10:14.1970 2025-11-08T00:10:15.461Z,1762560615.461 [DAT](INFO): Rx dataTimestamp_ set to:1762560615.461099 2025-11-08T00:10:16.217Z,1762560616.217 [DAT](INFO): DAT read: 2025-11-08T00:10:16.217Z,1762560616.217 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:10:16.218Z,1762560616.218 [DAT](INFO): Got DATA 2 2025-11-08T00:10:16.218Z,1762560616.218 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:10:16.218Z,1762560616.218 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:10:16.219Z,1762560616.219 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:10:16.220Z,1762560616.220 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.1 AGC:17 SPD:+0.0 CCERR:013 2025-11-08T00:10:16.221Z,1762560616.221 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:16.221Z,1762560616.221 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:16.221Z,1762560616.221 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:10:16.221Z,1762560616.221 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:10:16.221Z,1762560616.221 [DAT](INFO): Got ack 2025-11-08T00:10:16.221Z,1762560616.221 [DAT](INFO): DAT read: 2025-11-08T00:10:16.222Z,1762560616.222 [DAT](INFO): DAT read: 2025-11-08T00:10:16.222Z,1762560616.222 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:10:16.469Z,1762560616.469 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-08T00:10:16.469Z,1762560616.469 [DAT](INFO): #Outgoing data=1 2025-11-08T00:10:16.469Z,1762560616.469 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:10:16.721Z,1762560616.721 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:10:19.997Z,1762560619.997 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:19.3133 2025-11-08T00:10:19.998Z,1762560619.998 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:10:26.297Z,1762560626.297 [DAT](INFO): DAT read: Rx Time:00:10:25.0472 2025-11-08T00:10:26.297Z,1762560626.297 [DAT](INFO): Rx dataTimestamp_ set to:1762560626.297049 2025-11-08T00:10:27.053Z,1762560627.053 [DAT](INFO): DAT read: 2025-11-08T00:10:27.053Z,1762560627.053 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:10:27.054Z,1762560627.054 [DAT](INFO): Got DATA 2 2025-11-08T00:10:27.054Z,1762560627.054 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:10:27.055Z,1762560627.055 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:10:27.055Z,1762560627.055 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:10:27.056Z,1762560627.056 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.2 AGC:16 SPD:+0.0 CCERR:013 2025-11-08T00:10:27.056Z,1762560627.056 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:27.056Z,1762560627.056 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:27.057Z,1762560627.057 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:10:27.057Z,1762560627.057 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:10:27.057Z,1762560627.057 [DAT](INFO): Got ack 2025-11-08T00:10:27.057Z,1762560627.057 [DAT](INFO): DAT read: 2025-11-08T00:10:27.057Z,1762560627.057 [DAT](INFO): DAT read: 2025-11-08T00:10:27.058Z,1762560627.058 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:10:27.305Z,1762560627.305 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-08T00:10:27.305Z,1762560627.305 [DAT](INFO): #Outgoing data=1 2025-11-08T00:10:27.306Z,1762560627.306 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:10:27.557Z,1762560627.557 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:10:30.833Z,1762560630.833 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:30.1133 2025-11-08T00:10:30.834Z,1762560630.834 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:10:37.133Z,1762560637.133 [DAT](INFO): DAT read: Rx Time:00:10:35.8973 2025-11-08T00:10:37.133Z,1762560637.133 [DAT](INFO): Rx dataTimestamp_ set to:1762560637.133126 2025-11-08T00:10:37.889Z,1762560637.889 [DAT](INFO): DAT read: 2025-11-08T00:10:37.889Z,1762560637.889 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:10:37.889Z,1762560637.889 [DAT](INFO): Got DATA 2 2025-11-08T00:10:37.890Z,1762560637.890 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:10:37.890Z,1762560637.890 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:10:37.891Z,1762560637.891 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:10:37.892Z,1762560637.892 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.4 AGC:17 SPD:+0.0 CCERR:013 2025-11-08T00:10:37.892Z,1762560637.892 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:37.892Z,1762560637.892 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:37.892Z,1762560637.892 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:10:37.892Z,1762560637.892 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:10:37.893Z,1762560637.893 [DAT](INFO): Got ack 2025-11-08T00:10:37.893Z,1762560637.893 [DAT](INFO): DAT read: 2025-11-08T00:10:37.893Z,1762560637.893 [DAT](INFO): DAT read: 2025-11-08T00:10:37.894Z,1762560637.894 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:10:38.143Z,1762560638.143 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-08T00:10:38.143Z,1762560638.143 [DAT](INFO): #Outgoing data=1 2025-11-08T00:10:38.143Z,1762560638.143 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:10:38.393Z,1762560638.393 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:10:41.669Z,1762560641.669 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:40.9634 2025-11-08T00:10:41.669Z,1762560641.669 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:10:47.969Z,1762560647.969 [DAT](INFO): DAT read: Rx Time:00:10:46.6975 2025-11-08T00:10:47.969Z,1762560647.969 [DAT](INFO): Rx dataTimestamp_ set to:1762560647.969080 2025-11-08T00:10:48.725Z,1762560648.725 [DAT](INFO): DAT read: 2025-11-08T00:10:48.726Z,1762560648.726 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:10:48.726Z,1762560648.726 [DAT](INFO): Got DATA 2 2025-11-08T00:10:48.727Z,1762560648.727 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:10:48.727Z,1762560648.727 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:10:48.727Z,1762560648.727 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:10:48.728Z,1762560648.728 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.2 AGC:18 SPD:+0.0 CCERR:013 2025-11-08T00:10:48.728Z,1762560648.728 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:48.729Z,1762560648.729 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:48.729Z,1762560648.729 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:10:48.729Z,1762560648.729 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:10:48.729Z,1762560648.729 [DAT](INFO): Got ack 2025-11-08T00:10:48.729Z,1762560648.729 [DAT](INFO): DAT read: 2025-11-08T00:10:48.730Z,1762560648.730 [DAT](INFO): DAT read: 2025-11-08T00:10:48.730Z,1762560648.730 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:10:48.977Z,1762560648.977 [DAT](INFO): modem://10: set _.others_observations string "test_msg_5" 2025-11-08T00:10:48.977Z,1762560648.977 [DAT](INFO): #Outgoing data=1 2025-11-08T00:10:48.977Z,1762560648.977 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:10:49.229Z,1762560649.229 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:10:52.505Z,1762560652.505 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:10:51.8135 2025-11-08T00:10:52.505Z,1762560652.505 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:10:58.805Z,1762560658.805 [DAT](INFO): DAT read: Rx Time:00:10:57.5475 2025-11-08T00:10:58.806Z,1762560658.806 [DAT](INFO): Rx dataTimestamp_ set to:1762560658.805314 2025-11-08T00:10:59.561Z,1762560659.561 [DAT](INFO): DAT read: 2025-11-08T00:10:59.561Z,1762560659.561 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:10:59.562Z,1762560659.562 [DAT](INFO): Got DATA 2 2025-11-08T00:10:59.563Z,1762560659.563 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:10:59.563Z,1762560659.563 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:10:59.563Z,1762560659.563 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:10:59.564Z,1762560659.564 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.2 AGC:18 SPD:+0.0 CCERR:013 2025-11-08T00:10:59.564Z,1762560659.564 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:59.565Z,1762560659.565 [DAT](INFO): Got CRC:Pass 2025-11-08T00:10:59.565Z,1762560659.565 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:10:59.565Z,1762560659.565 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:10:59.565Z,1762560659.565 [DAT](INFO): Got ack 2025-11-08T00:10:59.565Z,1762560659.565 [DAT](INFO): DAT read: 2025-11-08T00:10:59.566Z,1762560659.566 [DAT](INFO): DAT read: 2025-11-08T00:10:59.566Z,1762560659.566 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:10:59.821Z,1762560659.821 [DAT](INFO): modem://10: set _.others_observations string "test_msg_5" 2025-11-08T00:10:59.821Z,1762560659.821 [DAT](INFO): #Outgoing data=1 2025-11-08T00:10:59.821Z,1762560659.821 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:11:00.073Z,1762560660.073 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:11:03.367Z,1762560663.367 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:02.6636 2025-11-08T00:11:03.367Z,1762560663.367 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:11:09.669Z,1762560669.669 [DAT](INFO): DAT read: Rx Time:00:11:08.3977 2025-11-08T00:11:09.670Z,1762560669.670 [DAT](INFO): Rx dataTimestamp_ set to:1762560669.669222 2025-11-08T00:11:10.425Z,1762560670.425 [DAT](INFO): DAT read: 2025-11-08T00:11:10.425Z,1762560670.425 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:11:10.426Z,1762560670.426 [DAT](INFO): Got DATA 2 2025-11-08T00:11:10.426Z,1762560670.426 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:11:10.427Z,1762560670.427 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:11:10.427Z,1762560670.427 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:11:10.429Z,1762560670.429 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.2 AGC:17 SPD:+0.0 CCERR:013 2025-11-08T00:11:10.429Z,1762560670.429 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:10.429Z,1762560670.429 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:10.429Z,1762560670.429 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:11:10.429Z,1762560670.429 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:11:10.429Z,1762560670.429 [DAT](INFO): Got ack 2025-11-08T00:11:10.429Z,1762560670.429 [DAT](INFO): DAT read: 2025-11-08T00:11:10.430Z,1762560670.430 [DAT](INFO): DAT read: 2025-11-08T00:11:10.430Z,1762560670.430 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:11:10.677Z,1762560670.677 [DAT](INFO): modem://10: set _.others_observations string "test_msg_5" 2025-11-08T00:11:10.677Z,1762560670.677 [DAT](INFO): #Outgoing data=1 2025-11-08T00:11:10.677Z,1762560670.677 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:11:10.929Z,1762560670.929 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:11:14.206Z,1762560674.206 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:13.5136 2025-11-08T00:11:14.206Z,1762560674.206 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:11:20.505Z,1762560680.505 [DAT](INFO): DAT read: Rx Time:00:11:19.2478 2025-11-08T00:11:20.505Z,1762560680.505 [DAT](INFO): Rx dataTimestamp_ set to:1762560680.505032 2025-11-08T00:11:21.261Z,1762560681.261 [DAT](INFO): DAT read: 2025-11-08T00:11:21.261Z,1762560681.261 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:11:21.261Z,1762560681.261 [DAT](INFO): Got DATA 2 2025-11-08T00:11:21.262Z,1762560681.262 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:11:21.262Z,1762560681.262 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:11:21.263Z,1762560681.263 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:11:21.265Z,1762560681.265 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.2 AGC:17 SPD:+0.0 CCERR:013 2025-11-08T00:11:21.265Z,1762560681.265 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:21.265Z,1762560681.265 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:21.265Z,1762560681.265 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:11:21.265Z,1762560681.265 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:11:21.265Z,1762560681.265 [DAT](INFO): Got ack 2025-11-08T00:11:21.265Z,1762560681.265 [DAT](INFO): DAT read: 2025-11-08T00:11:21.266Z,1762560681.266 [DAT](INFO): DAT read: 2025-11-08T00:11:21.266Z,1762560681.266 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:11:21.513Z,1762560681.513 [DAT](INFO): modem://10: set _.others_observations string "test_msg_5" 2025-11-08T00:11:21.513Z,1762560681.513 [DAT](INFO): #Outgoing data=1 2025-11-08T00:11:21.513Z,1762560681.513 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:11:21.765Z,1762560681.765 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:11:25.045Z,1762560685.045 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:24.3137 2025-11-08T00:11:25.046Z,1762560685.046 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:11:25.635Z,1762560685.635 [CBIT](INFO): Clearing failed state for component DropWeight 2025-11-08T00:11:25.635Z,1762560685.635 [DropWeight] No Fault, FailCount= 1 2025-11-08T00:11:28.459Z,1762560688.459 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-11-08T00:11:28.459Z,1762560688.459 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-08T00:11:28.470Z,1762560688.470 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-08T00:11:28.843Z,1762560688.843 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-08T00:11:28.843Z,1762560688.843 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-11-08T00:11:31.345Z,1762560691.345 [DAT](INFO): DAT read: Rx Time:00:11:30.0980 2025-11-08T00:11:31.345Z,1762560691.345 [DAT](INFO): Rx dataTimestamp_ set to:1762560691.345002 2025-11-08T00:11:32.101Z,1762560692.101 [DAT](INFO): DAT read: 2025-11-08T00:11:32.102Z,1762560692.102 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:11:32.102Z,1762560692.102 [DAT](INFO): Got DATA 2 2025-11-08T00:11:32.103Z,1762560692.103 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:11:32.103Z,1762560692.103 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:11:32.103Z,1762560692.103 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:11:32.105Z,1762560692.105 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.1 AGC:17 SPD:+0.0 CCERR:013 2025-11-08T00:11:32.105Z,1762560692.105 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:32.105Z,1762560692.105 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:32.105Z,1762560692.105 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:11:32.105Z,1762560692.105 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:11:32.105Z,1762560692.105 [DAT](INFO): Got ack 2025-11-08T00:11:32.106Z,1762560692.106 [DAT](INFO): DAT read: 2025-11-08T00:11:32.106Z,1762560692.106 [DAT](INFO): DAT read: 2025-11-08T00:11:32.106Z,1762560692.106 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:11:32.353Z,1762560692.353 [DAT](INFO): modem://10: set _.others_observations string "test_msg_13" 2025-11-08T00:11:32.353Z,1762560692.353 [DAT](INFO): #Outgoing data=1 2025-11-08T00:11:32.353Z,1762560692.353 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:11:32.605Z,1762560692.605 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:11:35.881Z,1762560695.881 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:35.1638 2025-11-08T00:11:35.882Z,1762560695.882 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:11:42.181Z,1762560702.181 [DAT](INFO): DAT read: Rx Time:00:11:40.9481 2025-11-08T00:11:42.181Z,1762560702.181 [DAT](INFO): Rx dataTimestamp_ set to:1762560702.181179 2025-11-08T00:11:42.937Z,1762560702.937 [DAT](INFO): DAT read: 2025-11-08T00:11:42.937Z,1762560702.937 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:11:42.938Z,1762560702.938 [DAT](INFO): Got DATA 2 2025-11-08T00:11:42.938Z,1762560702.938 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:11:42.939Z,1762560702.939 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:11:42.939Z,1762560702.939 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:11:42.941Z,1762560702.941 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.1 AGC:16 SPD:+0.0 CCERR:013 2025-11-08T00:11:42.941Z,1762560702.941 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:42.941Z,1762560702.941 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:42.941Z,1762560702.941 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:11:42.941Z,1762560702.941 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:11:42.941Z,1762560702.941 [DAT](INFO): Got ack 2025-11-08T00:11:42.941Z,1762560702.941 [DAT](INFO): DAT read: 2025-11-08T00:11:42.942Z,1762560702.942 [DAT](INFO): DAT read: 2025-11-08T00:11:42.942Z,1762560702.942 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:11:43.189Z,1762560703.189 [DAT](INFO): modem://10: set _.others_observations string "test_msg_13" 2025-11-08T00:11:43.189Z,1762560703.189 [DAT](INFO): #Outgoing data=1 2025-11-08T00:11:43.189Z,1762560703.189 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:11:43.441Z,1762560703.441 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:11:46.717Z,1762560706.717 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:46.0139 2025-11-08T00:11:46.718Z,1762560706.718 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:11:53.017Z,1762560713.017 [DAT](INFO): DAT read: Rx Time:00:11:51.7982 2025-11-08T00:11:53.017Z,1762560713.017 [DAT](INFO): Rx dataTimestamp_ set to:1762560713.016969 2025-11-08T00:11:53.773Z,1762560713.773 [DAT](INFO): DAT read: 2025-11-08T00:11:53.773Z,1762560713.773 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:11:53.774Z,1762560713.774 [DAT](INFO): Got DATA 2 2025-11-08T00:11:53.774Z,1762560713.774 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:11:53.775Z,1762560713.775 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:11:53.775Z,1762560713.775 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:11:53.776Z,1762560713.776 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.5 AGC:16 SPD:+0.0 CCERR:013 2025-11-08T00:11:53.776Z,1762560713.776 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:53.777Z,1762560713.777 [DAT](INFO): Got CRC:Pass 2025-11-08T00:11:53.777Z,1762560713.777 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:11:53.777Z,1762560713.777 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:11:53.777Z,1762560713.777 [DAT](INFO): Got ack 2025-11-08T00:11:53.777Z,1762560713.777 [DAT](INFO): DAT read: 2025-11-08T00:11:53.777Z,1762560713.777 [DAT](INFO): DAT read: 2025-11-08T00:11:53.778Z,1762560713.778 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:11:54.025Z,1762560714.025 [DAT](INFO): modem://10: set _.others_observations string "test_msg_13" 2025-11-08T00:11:54.025Z,1762560714.025 [DAT](INFO): #Outgoing data=1 2025-11-08T00:11:54.025Z,1762560714.025 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-08T00:11:54.277Z,1762560714.277 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-08T00:11:57.553Z,1762560717.553 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:11:56.8639 2025-11-08T00:11:57.553Z,1762560717.553 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-08T00:12:03.857Z,1762560723.857 [DAT](INFO): DAT read: Rx Time:00:12:02.6484 2025-11-08T00:12:03.857Z,1762560723.857 [DAT](INFO): Rx dataTimestamp_ set to:1762560723.857013 2025-11-08T00:12:04.612Z,1762560724.612 [DAT](INFO): DAT read: 2025-11-08T00:12:04.613Z,1762560724.613 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-08T00:12:04.613Z,1762560724.613 [DAT](INFO): Got DATA 2 2025-11-08T00:12:04.614Z,1762560724.614 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-08T00:12:04.614Z,1762560724.614 [DAT](INFO): Got Src/Dest after DATA 2025-11-08T00:12:04.615Z,1762560724.615 [DAT](INFO): DATA Src=10, Dst=1 2025-11-08T00:12:04.616Z,1762560724.616 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.2 AGC:17 SPD:+0.0 CCERR:013 2025-11-08T00:12:04.616Z,1762560724.616 [DAT](INFO): Got CRC:Pass 2025-11-08T00:12:04.616Z,1762560724.616 [DAT](INFO): Got CRC:Pass 2025-11-08T00:12:04.616Z,1762560724.616 [DAT](INFO): Incoming data is intended for us 2025-11-08T00:12:04.616Z,1762560724.616 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-08T00:12:04.617Z,1762560724.617 [DAT](INFO): Got ack 2025-11-08T00:12:04.617Z,1762560724.617 [DAT](INFO): DAT read: 2025-11-08T00:12:04.617Z,1762560724.617 [DAT](INFO): DAT read: 2025-11-08T00:12:04.618Z,1762560724.618 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-08T00:13:19.135Z,1762560799.135 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-08T00:08:18.0Z 2025-11-08T00:13:19.135Z,1762560799.135 [Default:CheckIn:Read_GPS] Stopped 2025-11-08T00:13:19.135Z,1762560799.135 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-11-08T00:13:26.015Z,1762560806.015 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251107T235614/Courier0007.lzma 2025-11-08T00:13:27.018Z,1762560807.018 [DataOverHttps](INFO): Moved sent file to Logs/20251107T235614/Courier0007.lzma.bak 2025-11-08T00:13:27.018Z,1762560807.018 [DataOverHttps](INFO): SBD MOMSN=26293575 2025-11-08T00:13:41.648Z,1762560821.648 [DataOverHttps](INFO): Sending 525 bytes from file Logs/20251107T235614/Express0008.lzma 2025-11-08T00:13:42.650Z,1762560822.650 [DataOverHttps](INFO): Moved sent file to Logs/20251107T235614/Express0008.lzma.bak 2025-11-08T00:13:42.650Z,1762560822.650 [DataOverHttps](INFO): SBD MOMSN=26293577 2025-11-08T00:13:44.182Z,1762560824.182 [Default:CheckIn:Read_Iridium] Stopped 2025-11-08T00:13:44.182Z,1762560824.182 [Default:CheckIn:C.Wait] Running Loop=1 2025-11-08T00:13:44.182Z,1762560824.182 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-11-08T00:14:24.137Z,1762560864.137 [CommandExec](IMPORTANT): got command quit 2025-11-08T00:14:25.140Z,1762560865.140 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:25.140Z,1762560865.140 [CommandExec](INFO): Uninitializing the command executive. 2025-11-08T00:14:25.140Z,1762560865.140 [CommandExec](INFO): Uninitializing the command scheduler. 2025-11-08T00:14:25.141Z,1762560865.141 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.156Z,1762560865.156 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-11-08T00:14:25.156Z,1762560865.156 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-11-08T00:14:25.156Z,1762560865.156 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.156Z,1762560865.156 [NavChartDb](INFO): Join timeout helper Thread ID is 3969 2025-11-08T00:14:25.272Z,1762560865.272 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:25.273Z,1762560865.273 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.278Z,1762560865.278 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-11-08T00:14:25.278Z,1762560865.278 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.278Z,1762560865.278 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3970 2025-11-08T00:14:25.332Z,1762560865.332 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:25.332Z,1762560865.332 [WetLabsBB2FL](INFO): Powering down 2025-11-08T00:14:25.333Z,1762560865.333 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.348Z,1762560865.348 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-11-08T00:14:25.348Z,1762560865.348 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.348Z,1762560865.348 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3971 2025-11-08T00:14:25.808Z,1762560865.808 [CTD_Seabird](INFO): Powering down 2025-11-08T00:14:25.820Z,1762560865.820 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:25.820Z,1762560865.820 [CTD_Seabird](INFO): Powering down 2025-11-08T00:14:25.832Z,1762560865.832 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.840Z,1762560865.840 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-11-08T00:14:25.840Z,1762560865.840 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.840Z,1762560865.840 [Radio_Surface](INFO): Join timeout helper Thread ID is 3972 2025-11-08T00:14:25.928Z,1762560865.928 [Radio_Surface](INFO): Powering down 2025-11-08T00:14:25.929Z,1762560865.929 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:25.929Z,1762560865.929 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.936Z,1762560865.936 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-11-08T00:14:25.936Z,1762560865.936 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:25.936Z,1762560865.936 [Onboard](INFO): Join timeout helper Thread ID is 3973 2025-11-08T00:14:26.248Z,1762560866.248 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-11-08T00:14:29.421Z,1762560869.421 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-11-08T00:14:29.421Z,1762560869.421 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-08T00:14:29.431Z,1762560869.431 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-08T00:14:29.842Z,1762560869.842 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-08T00:14:29.842Z,1762560869.842 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-11-08T00:14:30.192Z,1762560870.192 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:30.192Z,1762560870.192 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.197Z,1762560870.197 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-11-08T00:14:30.197Z,1762560870.197 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.197Z,1762560870.197 [DataOverHttps](INFO): Join timeout helper Thread ID is 3974 2025-11-08T00:14:30.264Z,1762560870.264 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:30.265Z,1762560870.265 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.285Z,1762560870.285 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-11-08T00:14:30.285Z,1762560870.285 [DAT ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.285Z,1762560870.285 [DAT](INFO): Join timeout helper Thread ID is 3975 2025-11-08T00:14:30.380Z,1762560870.380 [DAT](INFO): Powering down 2025-11-08T00:14:30.453Z,1762560870.453 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:30.453Z,1762560870.453 [DAT](INFO): Powering down 2025-11-08T00:14:30.454Z,1762560870.454 [DAT ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.461Z,1762560870.461 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2025-11-08T00:14:30.461Z,1762560870.461 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.461Z,1762560870.461 [BackseatComponent](INFO): Join timeout helper Thread ID is 3976 2025-11-08T00:14:30.492Z,1762560870.492 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:30.493Z,1762560870.493 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.505Z,1762560870.505 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-11-08T00:14:30.505Z,1762560870.505 [logger ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.505Z,1762560870.505 [logger](INFO): Join timeout helper Thread ID is 3977 2025-11-08T00:14:30.533Z,1762560870.533 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:30.534Z,1762560870.534 [logger ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.553Z,1762560870.553 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-11-08T00:14:30.553Z,1762560870.553 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.553Z,1762560870.553 [CommandLine](INFO): Join timeout helper Thread ID is 3978 2025-11-08T00:14:30.556Z,1762560870.556 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:30.556Z,1762560870.556 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.573Z,1762560870.573 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-11-08T00:14:30.573Z,1762560870.573 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.573Z,1762560870.573 [CommandExec](INFO): Join timeout helper Thread ID is 3979 2025-11-08T00:14:30.574Z,1762560870.574 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-11-08T00:14:30.574Z,1762560870.574 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.575Z,1762560870.575 [controlThread](INFO): Join timeout helper Thread ID is 3980 2025-11-08T00:14:30.612Z,1762560870.612 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-11-08T00:14:30.612Z,1762560870.612 [controlThread](DEBUG): Uninitializing ControlThread 2025-11-08T00:14:30.613Z,1762560870.613 [AHRS_M2](INFO): Powering down 2025-11-08T00:14:30.692Z,1762560870.692 [NAL9602](INFO): Powering down 2025-11-08T00:14:30.694Z,1762560870.694 [Sonardyne_Nano](INFO): Powering down 2025-11-08T00:14:30.896Z,1762560870.896 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-11-08T00:14:30.897Z,1762560870.897 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-11-08T00:14:30.897Z,1762560870.897 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-11-08T00:14:30.898Z,1762560870.898 [MissionManager](INFO): Uninitializing Mission Default 2025-11-08T00:14:30.898Z,1762560870.898 [Default] Stopped 2025-11-08T00:14:30.898Z,1762560870.898 [Default](DEBUG): Aggregate::uninitialize Default 2025-11-08T00:14:30.898Z,1762560870.898 [Default:B.GoToSurface] Stopped 2025-11-08T00:14:30.898Z,1762560870.898 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-11-08T00:14:30.898Z,1762560870.898 [Default:CheckIn] Stopped 2025-11-08T00:14:30.898Z,1762560870.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-11-08T00:14:30.899Z,1762560870.899 [Default:CheckIn:C.Wait] Stopped 2025-11-08T00:14:30.899Z,1762560870.899 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-11-08T00:14:30.902Z,1762560870.902 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-11-08T00:14:30.902Z,1762560870.902 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-11-08T00:14:30.902Z,1762560870.902 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-11-08T00:14:30.903Z,1762560870.903 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-11-08T00:14:30.903Z,1762560870.903 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-11-08T00:14:30.903Z,1762560870.903 [BuoyancyServo](INFO): Powering down 2025-11-08T00:14:30.916Z,1762560870.916 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-11-08T00:14:30.916Z,1762560870.916 [ElevatorServo](INFO): Powering down 2025-11-08T00:14:30.917Z,1762560870.917 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-11-08T00:14:30.917Z,1762560870.917 [MassServo](INFO): Powering down 2025-11-08T00:14:30.918Z,1762560870.918 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-11-08T00:14:30.918Z,1762560870.918 [RudderServo](INFO): Powering down 2025-11-08T00:14:30.919Z,1762560870.919 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-11-08T00:14:30.919Z,1762560870.919 [ThrusterHE](INFO): Powering down 2025-11-08T00:14:30.920Z,1762560870.920 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-11-08T00:14:30.920Z,1762560870.920 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-11-08T00:14:30.921Z,1762560870.921 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-11-08T00:14:30.921Z,1762560870.921 [CBIT](DEBUG): Powering off loads. 2025-11-08T00:14:30.932Z,1762560870.932 [CBIT](DEBUG): Disabling WDT. 2025-11-08T00:14:30.944Z,1762560870.944 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-11-08T00:14:30.944Z,1762560870.944 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-11-08T00:14:30.945Z,1762560870.945 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.983Z,1762560870.983 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.986Z,1762560870.986 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.992Z,1762560870.992 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:30.998Z,1762560870.998 [DAT ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:31.041Z,1762560871.041 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:31.075Z,1762560871.075 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-11-08T00:14:31.075Z,1762560871.075 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-11-08T00:14:31.130Z,1762560871.130 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:31.137Z,1762560871.137 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:31.145Z,1762560871.145 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-11-08T00:14:31.210Z,1762560871.210 [logger ThreadHandler](INFO): Thread cancelled.