2025-11-11T00:27:14.648Z,1762820834.648 [Supervisor](DEBUG): Initializing supervisor. 2025-11-11T00:27:14.653Z,1762820834.653 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-11-11T00:27:14.654Z,1762820834.654 [SyncHandler](INFO): Protected caller Thread ID is 1904 2025-11-11T00:27:14.654Z,1762820834.654 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-11-11T00:27:14.655Z,1762820834.655 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-11-11T00:27:14.655Z,1762820834.655 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1905 2025-11-11T00:27:14.659Z,1762820834.659 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-11-11T00:27:14.678Z,1762820834.678 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-11-11T00:27:14.679Z,1762820834.679 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-11-11T00:27:14.680Z,1762820834.680 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1906 2025-11-11T00:27:14.684Z,1762820834.684 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-11-11T00:27:14.685Z,1762820834.685 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-11-11T00:27:14.685Z,1762820834.685 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1907 2025-11-11T00:27:14.687Z,1762820834.687 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-11-11T00:27:14.688Z,1762820834.688 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-11-11T00:27:14.689Z,1762820834.689 [logger ThreadHandler](INFO): Protected caller Thread ID is 1908 2025-11-11T00:27:14.692Z,1762820834.692 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-11-11T00:27:14.693Z,1762820834.693 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-11-11T00:27:14.694Z,1762820834.694 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-11-11T00:27:15.020Z,1762820835.020 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-11-11T00:27:15.021Z,1762820835.021 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-11-11T00:27:15.121Z,1762820835.121 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-11-11T00:27:15.121Z,1762820835.121 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-11-11T00:27:15.238Z,1762820835.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-11-11T00:27:15.238Z,1762820835.238 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-11-11T00:27:15.377Z,1762820835.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-11-11T00:27:15.378Z,1762820835.378 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-11-11T00:27:15.722Z,1762820835.722 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-11-11T00:27:15.723Z,1762820835.723 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-11-11T00:27:15.829Z,1762820835.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-11-11T00:27:15.829Z,1762820835.829 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-11-11T00:27:16.220Z,1762820836.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-11-11T00:27:16.220Z,1762820836.220 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-11-11T00:27:16.446Z,1762820836.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-11-11T00:27:16.446Z,1762820836.446 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-11-11T00:27:16.536Z,1762820836.536 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-11-11T00:27:16.777Z,1762820836.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-11-11T00:27:16.777Z,1762820836.777 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-11-11T00:27:16.997Z,1762820836.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-11-11T00:27:16.997Z,1762820836.997 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-11-11T00:27:17.530Z,1762820837.530 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-11-11T00:27:17.530Z,1762820837.530 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-11-11T00:27:17.715Z,1762820837.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-11-11T00:27:17.716Z,1762820837.716 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-11-11T00:27:18.006Z,1762820838.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-11-11T00:27:18.007Z,1762820838.007 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-11-11T00:27:18.838Z,1762820838.838 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-11-11T00:27:18.839Z,1762820838.839 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-11-11T00:27:19.383Z,1762820839.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-11-11T00:27:19.385Z,1762820839.385 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/ 2025-11-11T00:27:19.386Z,1762820839.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Control.cfg 2025-11-11T00:27:19.494Z,1762820839.494 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Science.cfg 2025-11-11T00:27:19.634Z,1762820839.634 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/secure.cfg 2025-11-11T00:27:19.727Z,1762820839.727 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Servo.cfg 2025-11-11T00:27:19.843Z,1762820839.843 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/BIT.cfg 2025-11-11T00:27:19.945Z,1762820839.945 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Battery.cfg 2025-11-11T00:27:20.211Z,1762820840.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-11-11T00:27:20.212Z,1762820840.212 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/vehicle.cfg 2025-11-11T00:27:20.330Z,1762820840.330 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/logger.cfg 2025-11-11T00:27:20.436Z,1762820840.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Sensor.cfg 2025-11-11T00:27:20.582Z,1762820840.582 [Supervisor](INFO): Opening Config file at: Config/lrauv-ahi/Simulator.cfg 2025-11-11T00:27:20.679Z,1762820840.679 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-ahi/root/ 2025-11-11T00:27:20.679Z,1762820840.679 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-11-11T00:27:20.688Z,1762820840.688 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-11-11T00:27:20.817Z,1762820840.817 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-11-11T00:27:20.817Z,1762820840.817 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-11-11T00:27:20.869Z,1762820840.869 [VerticalControl](DEBUG): Construct VerticalControl. 2025-11-11T00:27:20.927Z,1762820840.927 [VerticalControl] Loaded 2025-11-11T00:27:20.928Z,1762820840.928 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-11-11T00:27:20.930Z,1762820840.930 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-11-11T00:27:20.976Z,1762820840.976 [HorizontalControl] Loaded 2025-11-11T00:27:20.977Z,1762820840.977 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-11-11T00:27:20.979Z,1762820840.979 [SpeedControl](DEBUG): Construct SpeedControl. 2025-11-11T00:27:20.982Z,1762820840.982 [SpeedControl] Loaded 2025-11-11T00:27:20.982Z,1762820840.982 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-11-11T00:27:20.985Z,1762820840.985 [LoopControl](DEBUG): Construct LoopControl. 2025-11-11T00:27:20.985Z,1762820840.985 [LoopControl] Loaded 2025-11-11T00:27:20.985Z,1762820840.985 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-11-11T00:27:20.986Z,1762820840.986 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-11-11T00:27:20.986Z,1762820840.986 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-11-11T00:27:21.043Z,1762820841.043 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-11-11T00:27:21.044Z,1762820841.044 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-11-11T00:27:21.549Z,1762820841.549 [AHRS_M2] Loaded 2025-11-11T00:27:21.550Z,1762820841.550 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-11-11T00:27:21.588Z,1762820841.588 [BackseatComponent] Loaded 2025-11-11T00:27:21.588Z,1762820841.588 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-11-11T00:27:21.590Z,1762820841.590 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408BE4E0 2025-11-11T00:27:21.590Z,1762820841.590 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1987 2025-11-11T00:27:21.593Z,1762820841.593 [LcmPublisher](INFO): Full slate access is ENABLED. All requested slate values (including non-universals) will be published on LCM. 2025-11-11T00:27:21.593Z,1762820841.593 [LcmPublisher] Loaded 2025-11-11T00:27:21.593Z,1762820841.593 [ComponentRegistry](DEBUG): SyncComponent "LcmPublisher" handled in the control thread. 2025-11-11T00:27:22.394Z,1762820842.394 [BPC1] Loaded 2025-11-11T00:27:22.394Z,1762820842.394 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-11-11T00:27:22.489Z,1762820842.489 [DAT] Loaded 2025-11-11T00:27:22.490Z,1762820842.490 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-11-11T00:27:22.491Z,1762820842.491 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 408EE4E0 2025-11-11T00:27:22.491Z,1762820842.491 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1988 2025-11-11T00:27:22.565Z,1762820842.565 [DataOverHttps] Loaded 2025-11-11T00:27:22.565Z,1762820842.565 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-11-11T00:27:22.566Z,1762820842.566 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4091E4E0 2025-11-11T00:27:22.567Z,1762820842.567 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1989 2025-11-11T00:27:22.589Z,1762820842.589 [Depth_Keller] Loaded 2025-11-11T00:27:22.589Z,1762820842.589 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-11-11T00:27:22.594Z,1762820842.594 [DropWeight] Loaded 2025-11-11T00:27:22.595Z,1762820842.595 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-11-11T00:27:22.658Z,1762820842.658 [NAL9602] Loaded 2025-11-11T00:27:22.658Z,1762820842.658 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-11-11T00:27:22.687Z,1762820842.687 [Onboard] Loaded 2025-11-11T00:27:22.687Z,1762820842.687 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-11-11T00:27:22.688Z,1762820842.688 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4094E4E0 2025-11-11T00:27:22.688Z,1762820842.688 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1990 2025-11-11T00:27:22.702Z,1762820842.702 [Power24vConverter] Loaded 2025-11-11T00:27:22.702Z,1762820842.702 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-11-11T00:27:22.718Z,1762820842.718 [Radio_Surface] Loaded 2025-11-11T00:27:22.718Z,1762820842.718 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-11-11T00:27:22.719Z,1762820842.719 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4097E4E0 2025-11-11T00:27:22.719Z,1762820842.719 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1991 2025-11-11T00:27:22.734Z,1762820842.734 [Sonardyne_Nano] Loaded 2025-11-11T00:27:22.734Z,1762820842.734 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-11-11T00:27:22.735Z,1762820842.735 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-11-11T00:27:22.735Z,1762820842.735 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-11-11T00:27:22.745Z,1762820842.745 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-11-11T00:27:22.746Z,1762820842.746 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-11-11T00:27:22.774Z,1762820842.774 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-11-11T00:27:22.774Z,1762820842.774 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-11-11T00:27:22.926Z,1762820842.926 [SBIT](DEBUG): Construct Startup Built In Test. 2025-11-11T00:27:22.934Z,1762820842.934 [SBIT] Loaded 2025-11-11T00:27:22.935Z,1762820842.935 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-11-11T00:27:22.937Z,1762820842.937 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-11-11T00:27:22.950Z,1762820842.950 [IBIT] Loaded 2025-11-11T00:27:22.950Z,1762820842.950 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-11-11T00:27:22.955Z,1762820842.955 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-11-11T00:27:23.049Z,1762820843.049 [CBIT] Loaded 2025-11-11T00:27:23.049Z,1762820843.049 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-11-11T00:27:23.081Z,1762820843.081 [GFScanner] Loaded 2025-11-11T00:27:23.081Z,1762820843.081 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-11-11T00:27:23.082Z,1762820843.082 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-11-11T00:27:23.082Z,1762820843.082 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-11-11T00:27:23.408Z,1762820843.408 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-11-11T00:27:23.409Z,1762820843.409 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-11-11T00:27:23.457Z,1762820843.457 [DepthRateCalculator] Loaded 2025-11-11T00:27:23.458Z,1762820843.458 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-11-11T00:27:23.462Z,1762820843.462 [PitchRateCalculator] Loaded 2025-11-11T00:27:23.463Z,1762820843.463 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-11-11T00:27:23.473Z,1762820843.473 [SpeedCalculator] Loaded 2025-11-11T00:27:23.473Z,1762820843.473 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-11-11T00:27:23.477Z,1762820843.477 [YawRateCalculator] Loaded 2025-11-11T00:27:23.477Z,1762820843.477 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-11-11T00:27:23.496Z,1762820843.496 [ElevatorOffsetCalculator] Loaded 2025-11-11T00:27:23.496Z,1762820843.496 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-11-11T00:27:23.497Z,1762820843.497 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-11-11T00:27:23.497Z,1762820843.497 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-11-11T00:27:23.666Z,1762820843.666 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-11-11T00:27:23.667Z,1762820843.667 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-11-11T00:27:23.777Z,1762820843.777 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-11-11T00:27:23.777Z,1762820843.777 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-11-11T00:27:23.791Z,1762820843.791 [NavChart] Loaded 2025-11-11T00:27:23.791Z,1762820843.791 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-11-11T00:27:23.796Z,1762820843.796 [UniversalFixResidualReporter] Loaded 2025-11-11T00:27:23.797Z,1762820843.797 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-11-11T00:27:23.797Z,1762820843.797 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-11-11T00:27:23.798Z,1762820843.798 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-11-11T00:27:23.928Z,1762820843.928 [BuoyancyServo] Loaded 2025-11-11T00:27:23.929Z,1762820843.929 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-11-11T00:27:23.951Z,1762820843.951 [ElevatorServo] Loaded 2025-11-11T00:27:23.951Z,1762820843.951 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-11-11T00:27:23.972Z,1762820843.972 [MassServo] Loaded 2025-11-11T00:27:23.973Z,1762820843.973 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-11-11T00:27:23.993Z,1762820843.993 [RudderServo] Loaded 2025-11-11T00:27:23.994Z,1762820843.994 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-11-11T00:27:24.010Z,1762820844.010 [ThrusterHE] Loaded 2025-11-11T00:27:24.010Z,1762820844.010 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-11-11T00:27:24.011Z,1762820844.011 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-11-11T00:27:24.011Z,1762820844.011 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-11-11T00:27:24.178Z,1762820844.178 [CTD_Seabird] Loaded 2025-11-11T00:27:24.178Z,1762820844.178 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-11-11T00:27:24.179Z,1762820844.179 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40C0E4E0 2025-11-11T00:27:24.179Z,1762820844.179 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1992 2025-11-11T00:27:24.215Z,1762820844.215 [ESPComponent] Loaded 2025-11-11T00:27:24.215Z,1762820844.215 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-11-11T00:27:24.237Z,1762820844.237 [PAR_Licor] Loaded 2025-11-11T00:27:24.237Z,1762820844.237 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-11-11T00:27:24.281Z,1762820844.281 [WetLabsBB2FL] Loaded 2025-11-11T00:27:24.281Z,1762820844.281 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-11-11T00:27:24.282Z,1762820844.282 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C3E4E0 2025-11-11T00:27:24.282Z,1762820844.282 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1993 2025-11-11T00:27:24.283Z,1762820844.283 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-11-11T00:27:24.289Z,1762820844.289 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-11-11T00:27:24.293Z,1762820844.293 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-11-11T00:27:24.304Z,1762820844.304 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-11-11T00:27:24.305Z,1762820844.305 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C6E4E0 2025-11-11T00:27:24.305Z,1762820844.305 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1994 2025-11-11T00:27:24.309Z,1762820844.309 [Supervisor](INFO): Main Thread ID is 1470 2025-11-11T00:27:24.309Z,1762820844.309 [Supervisor](DEBUG): Running supervisor. 2025-11-11T00:27:24.310Z,1762820844.310 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1995 2025-11-11T00:27:24.311Z,1762820844.311 [CommandExec](INFO): Initializing the command executive. 2025-11-11T00:27:24.312Z,1762820844.312 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1996 2025-11-11T00:27:24.315Z,1762820844.316 [controlThread ThreadHandler](INFO): Handler Thread ID is 1997 2025-11-11T00:27:24.316Z,1762820844.316 [controlThread](DEBUG): Initializing ControlThread 2025-11-11T00:27:24.317Z,1762820844.317 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-11-11T00:27:24.318Z,1762820844.318 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-11-11T00:27:24.319Z,1762820844.319 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-11-11T00:27:24.320Z,1762820844.320 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-11-11T00:27:24.323Z,1762820844.323 [SBIT](INFO): Initialize SBIT Component. 2025-11-11T00:27:24.323Z,1762820844.323 [SBIT](IMPORTANT): git: 2025-11-06-4-g76494056e 2025-11-11T00:27:24.323Z,1762820844.323 [SBIT](INFO): git hash: 76494056ed9c20a4ea114d534fa322c9d45bc993 2025-11-11T00:27:24.324Z,1762820844.324 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-11-11T00:27:24.325Z,1762820844.325 [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-11T00:27:24.326Z,1762820844.326 [SBIT](INFO): Beginning SBIT in 117.000000 seconds. 2025-11-11T00:27:24.327Z,1762820844.327 [IBIT](INFO): Initialize IBIT Component. 2025-11-11T00:27:24.327Z,1762820844.327 [CBIT](DEBUG): Initialize CBIT Component. 2025-11-11T00:27:24.328Z,1762820844.328 [logger ThreadHandler](INFO): Handler Thread ID is 1998 2025-11-11T00:27:24.340Z,1762820844.340 [CBIT](DEBUG): Initialized mux pins. 2025-11-11T00:27:24.340Z,1762820844.340 [CBIT](DEBUG): Initializing the watchdog timer. 2025-11-11T00:27:24.348Z,1762820844.348 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1999 2025-11-11T00:27:24.364Z,1762820844.364 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-11-11T00:27:24.364Z,1762820844.364 [CBIT](DEBUG): Initializing heartbeat. 2025-11-11T00:27:24.365Z,1762820844.365 [DAT ThreadHandler](INFO): Handler Thread ID is 2000 2025-11-11T00:27:24.366Z,1762820844.366 [DAT](INFO): Powering up 2025-11-11T00:27:24.366Z,1762820844.366 [DAT](DEBUG): Initializing DAT. 2025-11-11T00:27:24.369Z,1762820844.369 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2002 2025-11-11T00:27:24.371Z,1762820844.371 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-11-11T00:27:24.392Z,1762820844.392 [Onboard ThreadHandler](INFO): Handler Thread ID is 2003 2025-11-11T00:27:24.409Z,1762820844.409 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2004 2025-11-11T00:27:24.431Z,1762820844.431 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2005 2025-11-11T00:27:24.432Z,1762820844.432 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-11-11T00:27:24.436Z,1762820844.436 [CBIT](DEBUG): Deactivating emergency mode. 2025-11-11T00:27:24.437Z,1762820844.437 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2007 2025-11-11T00:27:24.440Z,1762820844.440 [WetLabsBB2FL](INFO): Powering up 2025-11-11T00:27:24.442Z,1762820844.442 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2009 2025-11-11T00:27:24.444Z,1762820844.444 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-11-11T00:27:24.444Z,1762820844.444 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-11-11T00:27:24.445Z,1762820844.445 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-11-11T00:27:24.445Z,1762820844.445 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-11-11T00:27:24.445Z,1762820844.445 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-11-11T00:27:24.445Z,1762820844.445 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-11-11T00:27:24.445Z,1762820844.445 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-11-11T00:27:24.446Z,1762820844.446 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-11-11T00:27:24.476Z,1762820844.476 [CBIT](DEBUG): Backplane powered. 2025-11-11T00:27:24.476Z,1762820844.476 [GFScanner](DEBUG): Initializing GFScanner 2025-11-11T00:27:24.476Z,1762820844.476 [GFScanner](DEBUG): Deactivating GF circuits. 2025-11-11T00:27:24.481Z,1762820844.481 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-11-11T00:27:24.481Z,1762820844.481 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-11-11T00:27:24.481Z,1762820844.481 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-11-11T00:27:24.482Z,1762820844.482 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-11-11T00:27:24.482Z,1762820844.482 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-11-11T00:27:24.483Z,1762820844.483 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-11-11T00:27:24.483Z,1762820844.483 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-11-11T00:27:24.496Z,1762820844.496 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-11-11T00:27:24.497Z,1762820844.497 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-11-11T00:27:24.498Z,1762820844.498 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-11-11T00:27:24.499Z,1762820844.499 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-11-11T00:27:24.599Z,1762820844.599 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-11-11T00:27:24.612Z,1762820844.612 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-11-11T00:27:24.673Z,1762820844.673 [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-11T00:27:24.674Z,1762820844.674 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-11-11T00:27:24.674Z,1762820844.674 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-11-11T00:27:24.675Z,1762820844.675 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-11-11T00:27:24.816Z,1762820844.816 [Radio_Surface](INFO): Powering up 2025-11-11T00:27:24.970Z,1762820844.970 [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-11T00:27:24.992Z,1762820844.992 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-11-11T00:27:24.994Z,1762820844.994 [Default:A.Wait](DEBUG): Construct Wait. 2025-11-11T00:27:25.013Z,1762820845.013 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-11-11T00:27:25.050Z,1762820845.050 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-11-11T00:27:25.068Z,1762820845.068 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-11-11T00:27:25.074Z,1762820845.074 [Default:E.Execute](DEBUG): Construct Execute. 2025-11-11T00:27:25.093Z,1762820845.093 [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-11T00:27:25.098Z,1762820845.098 [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-11T00:27:25.122Z,1762820845.122 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-11-11T00:27:25.180Z,1762820845.180 [Depth_Keller](INFO): Initializing. 2025-11-11T00:27:25.182Z,1762820845.182 [Power24vConverter](INFO): Powering up. 2025-11-11T00:27:25.182Z,1762820845.182 [Sonardyne_Nano](INFO): Initializing. 2025-11-11T00:27:25.220Z,1762820845.220 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-11-11T00:27:25.247Z,1762820845.247 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-11-11T00:27:25.264Z,1762820845.264 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-11-11T00:27:25.265Z,1762820845.265 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-11-11T00:27:25.272Z,1762820845.272 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-11-11T00:27:25.273Z,1762820845.273 [MassServo](DEBUG): Initializing EZServoServo. 2025-11-11T00:27:25.280Z,1762820845.280 [MassServo](DEBUG): Initializing MassServo. 2025-11-11T00:27:25.281Z,1762820845.281 [RudderServo](DEBUG): Initializing EZServoServo. 2025-11-11T00:27:25.288Z,1762820845.288 [RudderServo](DEBUG): Initializing RudderServo. 2025-11-11T00:27:25.289Z,1762820845.289 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-11-11T00:27:25.296Z,1762820845.296 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-11-11T00:27:25.545Z,1762820845.545 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-11-11T00:27:25.545Z,1762820845.545 [DropWeight] Hardware Fault, FailCount= 1 2025-11-11T00:27:25.545Z,1762820845.545 [DropWeight](ERROR): Hardware Fault 2025-11-11T00:27:25.601Z,1762820845.601 [CommandExec](FAULT): Scheduling is paused 2025-11-11T00:27:25.601Z,1762820845.601 [CBIT](INFO): Critical error at 20251111T002725 2025-11-11T00:27:25.602Z,1762820845.602 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-11-11T00:27:25.612Z,1762820845.612 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-11-11T00:27:25.613Z,1762820845.613 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-11-11T00:27:25.976Z,1762820845.976 [CBIT](INFO): Critical error at 20251111T002725 2025-11-11T00:27:26.548Z,1762820846.548 [WetLabsBB2FL](INFO): Powering down 2025-11-11T00:27:27.126Z,1762820847.126 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-11-11T00:27:28.412Z,1762820848.412 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2311 2025-11-11T00:27:31.005Z,1762820851.005 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-11-11T00:27:36.713Z,1762820856.713 [DAT](INFO): DAT read: 2025-11-11T00:27:36.714Z,1762820856.714 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-11-11T00:27:38.477Z,1762820858.477 [DAT](INFO): DAT read: MF Frequency Band 2025-11-11T00:27:38.479Z,1762820858.479 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-11-11T00:27:38.479Z,1762820858.479 [DAT](INFO): DAT read: Nov 11 2025 00:27:32 2025-11-11T00:27:39.485Z,1762820859.485 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-11-11T00:27:39.486Z,1762820859.486 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-11-11T00:27:39.487Z,1762820859.487 [DAT](INFO): commRate: 800 2025-11-11T00:27:41.552Z,1762820861.552 [DAT](INFO): entering command mode 2025-11-11T00:27:41.753Z,1762820861.753 [DAT](INFO): DAT read: 2025-11-11T00:27:41.753Z,1762820861.753 [DAT](INFO): DAT read: user:1> 2025-11-11T00:27:41.753Z,1762820861.753 [DAT](INFO): setting verbose to 3 2025-11-11T00:27:42.004Z,1762820862.004 [DAT](INFO): DAT read: user:1> 2025-11-11T00:27:42.005Z,1762820862.005 [DAT](INFO): DAT read: Verbose | 3 2025-11-11T00:27:42.006Z,1762820862.006 [DAT](INFO): set verbose to 3 2025-11-11T00:27:42.006Z,1762820862.006 [DAT](INFO): setting DatVerbose to 27440 2025-11-11T00:27:42.257Z,1762820862.257 [DAT](INFO): DAT read: user:2> 2025-11-11T00:27:42.258Z,1762820862.258 [DAT](INFO): DAT read: DatVerbose | 27440 2025-11-11T00:27:42.258Z,1762820862.258 [DAT](INFO): set DatVerbose to 27440 2025-11-11T00:27:42.258Z,1762820862.258 [DAT](INFO): setting transmit power to 8 2025-11-11T00:27:42.509Z,1762820862.509 [DAT](INFO): DAT read: user:3> 2025-11-11T00:27:42.510Z,1762820862.510 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-11-11T00:27:42.510Z,1762820862.510 [DAT](INFO): set transmit power to 8 2025-11-11T00:27:42.510Z,1762820862.510 [DAT](INFO): setting local address to 1 2025-11-11T00:27:42.761Z,1762820862.761 [DAT](INFO): DAT read: user:4> 2025-11-11T00:27:42.762Z,1762820862.762 [DAT](INFO): DAT read: LocalAddr | 1 2025-11-11T00:27:42.762Z,1762820862.762 [DAT](INFO): set local address to 1 2025-11-11T00:27:42.763Z,1762820862.763 [DAT](INFO): Setting time to: 0:27:42 And date to:11/11/2025 2025-11-11T00:27:43.013Z,1762820863.013 [DAT](INFO): DAT read: user:5> 2025-11-11T00:27:43.013Z,1762820863.013 [DAT](INFO): DAT read: Tue Nov 11, 2025 00:27:42 2025-11-11T00:27:43.014Z,1762820863.014 [DAT](INFO): Local DAT time set to Tue Nov 11, 2025 00:27:42 2025-11-11T00:27:52.989Z,1762820872.989 [NAL9602](INFO): Powering up NAL9602 2025-11-11T00:28:03.905Z,1762820883.905 [NAL9602](INFO): NAL9602 initialized 2025-11-11T00:28:31.365Z,1762820911.365 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:28:46.313Z,1762820926.313 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:29:01.677Z,1762820941.677 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:29:17.433Z,1762820957.433 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:29:21.898Z,1762820961.898 [SBIT](IMPORTANT): Beginning Startup BIT 2025-11-11T00:29:21.904Z,1762820961.904 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-11-11T00:29:26.473Z,1762820966.473 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.000267 CHAN A1 (24V): 0.000556 CHAN A2 (12V): 0.000227 CHAN A3 (5V): -0.001248 CHAN B0 (3.3V): -0.000357 CHAN B1 (3.15aV): 0.000417 CHAN B2 (3.15bV): 0.000481 CHAN B3 (GND): -0.000145 OPEN: 0.007212 Full Scale: +/- 1 mA 2025-11-11T00:29:32.033Z,1762820972.033 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:29:47.443Z,1762820987.443 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:30:03.141Z,1762821003.141 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:30:07.507Z,1762821007.507 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004940 2025-11-11T00:30:15.747Z,1762821015.747 [SBIT](IMPORTANT): SBIT PASSED 2025-11-11T00:30:15.747Z,1762821015.747 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-11-11T00:30:15.748Z,1762821015.748 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=19 count; 2025-11-11T00:30:15.748Z,1762821015.748 [SBIT](IMPORTANT): BackseatComponent.fullSlateAccess=1 bool; 2025-11-11T00:30:15.748Z,1762821015.748 [SBIT](IMPORTANT): DAT.surfaceThreshold=-0.5 meter; 2025-11-11T00:30:15.748Z,1762821015.748 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter; 2025-11-11T00:30:15.749Z,1762821015.749 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_HM_AvgRois 2.000000 count_per_second; 2025-11-11T00:30:15.749Z,1762821015.749 [SBIT](IMPORTANT): Express linearApproximation _.planktivore_LM_AvgRois 100.000000 count_per_second; 2025-11-11T00:30:15.749Z,1762821015.749 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=162.414241 cubic_centimeter; 2025-11-11T00:30:15.749Z,1762821015.749 [SBIT](IMPORTANT): VerticalControl.massDefault=24.263883 millimeter; 2025-11-11T00:30:15.749Z,1762821015.749 [SBIT](IMPORTANT): Waterlinked.loadAtStartup=0 bool; 2025-11-11T00:30:16.146Z,1762821016.146 [MissionManager](IMPORTANT): Started mission Startup 2025-11-11T00:30:16.146Z,1762821016.146 [Startup] Running Loop=1 2025-11-11T00:30:16.146Z,1762821016.146 [Startup](DEBUG): Aggregate::initialize Startup 2025-11-11T00:30:16.146Z,1762821016.146 [Startup:A.GoToSurface] Running Loop=1 2025-11-11T00:30:16.146Z,1762821016.146 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-11-11T00:30:16.147Z,1762821016.147 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-11-11T00:30:16.147Z,1762821016.147 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-11-11T00:30:16.148Z,1762821016.148 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-11-11T00:30:16.148Z,1762821016.148 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-11-11T00:30:16.149Z,1762821016.149 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-11-11T00:30:16.149Z,1762821016.149 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-11-11T00:30:16.151Z,1762821016.151 [Startup:StartupSatComms] Running Loop=1 2025-11-11T00:30:16.151Z,1762821016.151 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-11-11T00:30:16.151Z,1762821016.151 [Startup:StartupSatComms:A] Running Loop=1 2025-11-11T00:30:16.556Z,1762821016.556 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-11-11T00:30:17.725Z,1762821017.725 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7). 2025-11-11T00:30:24.678Z,1762821024.678 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-11-11T00:30:24.678Z,1762821024.678 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:30:24.689Z,1762821024.689 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:30:25.066Z,1762821025.066 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:30:25.066Z,1762821025.066 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-11-11T00:31:16.317Z,1762821076.317 [Startup:StartupSatComms:A](INFO): Timed out from 2025-11-11T00:30:16.2Z 2025-11-11T00:31:16.318Z,1762821076.318 [Startup:StartupSatComms:A] Stopped 2025-11-11T00:31:16.318Z,1762821076.318 [Startup:StartupSatComms:B] Running Loop=1 2025-11-11T00:31:16.720Z,1762821076.720 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-11-11T00:31:27.508Z,1762821087.508 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251111T000850/Courier0007.lzma 2025-11-11T00:31:28.510Z,1762821088.510 [DataOverHttps](INFO): Moved sent file to Logs/20251111T000850/Courier0007.lzma.bak 2025-11-11T00:31:28.510Z,1762821088.510 [DataOverHttps](INFO): SBD MOMSN=26295324 2025-11-11T00:31:45.535Z,1762821105.535 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20251111T002714/Courier0000.lzma 2025-11-11T00:31:46.538Z,1762821106.538 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Courier0000.lzma.bak 2025-11-11T00:31:46.538Z,1762821106.538 [DataOverHttps](INFO): SBD MOMSN=26295326 2025-11-11T00:32:01.271Z,1762821121.271 [DataOverHttps](INFO): Sending 89 bytes from file Logs/20251111T000850/Express0008.lzma 2025-11-11T00:32:02.258Z,1762821122.258 [DataOverHttps](INFO): Moved sent file to Logs/20251111T000850/Express0008.lzma.bak 2025-11-11T00:32:02.258Z,1762821122.258 [DataOverHttps](INFO): SBD MOMSN=26295331 2025-11-11T00:32:16.590Z,1762821136.590 [Startup:StartupSatComms:B](INFO): Timed out from 2025-11-11T00:31:16.3Z 2025-11-11T00:32:16.590Z,1762821136.590 [Startup:StartupSatComms:B] Stopped 2025-11-11T00:32:16.590Z,1762821136.590 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-11-11T00:32:16.590Z,1762821136.590 [Startup:StartupSatComms] Stopped 2025-11-11T00:32:16.590Z,1762821136.590 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-11-11T00:32:16.591Z,1762821136.591 [Startup](INFO): Completed Startup 2025-11-11T00:32:16.591Z,1762821136.591 [MissionManager](INFO): Startup is completed. 2025-11-11T00:32:16.591Z,1762821136.591 [MissionManager](INFO): Uninitializing Mission Startup 2025-11-11T00:32:16.596Z,1762821136.596 [Startup] Stopped 2025-11-11T00:32:16.596Z,1762821136.596 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-11-11T00:32:16.596Z,1762821136.596 [Startup:A.GoToSurface] Stopped 2025-11-11T00:32:16.596Z,1762821136.596 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-11-11T00:32:16.990Z,1762821136.990 [MissionManager](IMPORTANT): Started mission Default 2025-11-11T00:32:16.990Z,1762821136.990 [Default] Running Loop=1 2025-11-11T00:32:16.990Z,1762821136.990 [Default](DEBUG): Aggregate::initialize Default 2025-11-11T00:32:16.990Z,1762821136.990 [Default:B.GoToSurface] Running Loop=1 2025-11-11T00:32:16.990Z,1762821136.990 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-11-11T00:32:16.991Z,1762821136.991 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-11-11T00:32:16.991Z,1762821136.991 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-11-11T00:32:16.991Z,1762821136.991 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-11-11T00:32:16.992Z,1762821136.992 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-11-11T00:32:16.993Z,1762821136.993 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-11-11T00:32:16.993Z,1762821136.993 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-11-11T00:32:16.993Z,1762821136.993 [Default:A.Wait] Running Loop=1 2025-11-11T00:32:16.993Z,1762821136.993 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-11-11T00:32:17.937Z,1762821137.937 [DataOverHttps](INFO): Sending 986 bytes from file Logs/20251111T002714/Express0001.lzma 2025-11-11T00:32:18.938Z,1762821138.938 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Express0001.lzma.bak 2025-11-11T00:32:18.938Z,1762821138.938 [DataOverHttps](INFO): SBD MOMSN=26295334 2025-11-11T00:32:30.314Z,1762821150.314 [Default:A.Wait](INFO): Done Waiting. 2025-11-11T00:32:30.314Z,1762821150.314 [Default:A.Wait] Stopped 2025-11-11T00:32:30.314Z,1762821150.314 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-11-11T00:32:30.738Z,1762821150.738 [Default:CheckIn] Running Loop=1 2025-11-11T00:32:30.738Z,1762821150.738 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-11-11T00:32:30.738Z,1762821150.738 [Default:CheckIn:Read_GPS] Running Loop=1 2025-11-11T00:32:31.202Z,1762821151.202 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-11-11T00:32:36.765Z,1762821156.765 [CommandExec](IMPORTANT): got command load ./Missions/marl_lab.tl 2025-11-11T00:32:36.765Z,1762821156.765 [MissionManager](INFO): Loading Mission from file: ./Missions/marl_lab.tl 2025-11-11T00:32:36.766Z,1762821156.766 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/marl_lab.tl 2025-11-11T00:32:36.767Z,1762821156.767 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/marl_lab.tl 2025-11-11T00:32:37.423Z,1762821157.423 [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-11T00:32:37.438Z,1762821157.438 [MissionManager](INFO): DefineArg marl_lab.MissionTimeout = 1.000000 h 2025-11-11T00:32:37.441Z,1762821157.441 [MissionManager](INFO): DefineArg marl_lab.ContactLabel = 8.000000 count 2025-11-11T00:32:37.452Z,1762821157.452 [MissionManager](INFO): DefineArg marl_lab.SendDataLabel = 10.000000 count 2025-11-11T00:32:37.455Z,1762821157.455 [MissionManager](INFO): DefineArg marl_lab.ContactDepth = nan m 2025-11-11T00:32:37.465Z,1762821157.465 [MissionManager](INFO): DefineArg marl_lab.SendObservationDataInterval = 20.000000 s 2025-11-11T00:32:37.469Z,1762821157.469 [MissionManager](INFO): DefineArg marl_lab.TrackingUpdatePeriod = 10.000000 min 2025-11-11T00:32:37.471Z,1762821157.471 [MissionManager](INFO): DefineArg marl_lab.NumberOfPings = 1.000000 count 2025-11-11T00:32:37.495Z,1762821157.495 [MissionManager](INFO): DefineArg marl_lab.AcousticContactTimeout = 1.000000 h 2025-11-11T00:32:37.505Z,1762821157.505 [MissionManager](INFO): DefineArg marl_lab.MyTempVar = NaN 2025-11-11T00:32:37.512Z,1762821157.512 [MissionManager](INFO): DefineOutput marl_lab.TimeLastSendData = 0.000000 s 2025-11-11T00:32:37.515Z,1762821157.515 [MissionManager](INFO): DefineOutput marl_lab.ElapsedSinceLastSendData = 0.000000 s 2025-11-11T00:32:37.524Z,1762821157.524 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.tl 2025-11-11T00:32:37.524Z,1762821157.524 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/AbortDrift.tl 2025-11-11T00:32:37.525Z,1762821157.525 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/AbortDrift.tl 2025-11-11T00:32:37.737Z,1762821157.737 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/AbortDrift.tl translated into: 96 Insert acoustic timeout set to . stop 2025-11-11T00:32:37.757Z,1762821157.757 [MissionManager](INFO): DefineArg marl_lab:AbortDrift.AcousticTimeout = 96.000000 h 2025-11-11T00:32:37.768Z,1762821157.768 [marl_lab:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift. 2025-11-11T00:32:37.770Z,1762821157.770 [marl_lab:AbortDrift:C.Execute](DEBUG): Construct Execute. 2025-11-11T00:32:37.789Z,1762821157.789 [MissionManager](INFO): RedefineArg marl_lab:AbortDrift.AcousticTimeout = reader:marl_lab.AcousticContactTimeout 2025-11-11T00:32:38.057Z,1762821158.057 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-11-11T00:32:38.058Z,1762821158.058 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-11-11T00:32:38.059Z,1762821158.059 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-11-11T00:32:38.130Z,1762821158.130 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-11-11T00:32:38.145Z,1762821158.145 [MissionManager](INFO): DefineArg marl_lab:BackseatDriver.EnableBackseat = 0 bool 2025-11-11T00:32:38.156Z,1762821158.156 [marl_lab:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-11-11T00:32:38.165Z,1762821158.165 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-11-11T00:32:38.166Z,1762821158.166 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-11-11T00:32:38.167Z,1762821158.167 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-11-11T00:32:38.482Z,1762821158.482 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-11-11T00:32:38.495Z,1762821158.495 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleAll = 0 bool 2025-11-11T00:32:38.502Z,1762821158.502 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad1 = 0 bool 2025-11-11T00:32:38.529Z,1762821158.529 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad2 = 0 bool 2025-11-11T00:32:38.540Z,1762821158.540 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad3 = 0 bool 2025-11-11T00:32:38.543Z,1762821158.543 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.EnabledPowerOnly = 0 bool 2025-11-11T00:32:38.574Z,1762821158.574 [marl_lab:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-11-11T00:32:38.581Z,1762821158.581 [marl_lab:H.Wait](DEBUG): Construct Wait. 2025-11-11T00:32:38.604Z,1762821158.604 [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-11T00:32:38.605Z,1762821158.605 [CommandExec](IMPORTANT): Loaded ./Missions/marl_lab.tl id=marl_lab 2025-11-11T00:32:39.703Z,1762821159.703 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-11-11T00:32:45.664Z,1762821165.664 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:32:58.992Z,1762821178.992 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:33:07.069Z,1762821187.069 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-11-11T00:33:13.122Z,1762821193.122 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:33:25.698Z,1762821205.698 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-11-11T00:33:25.698Z,1762821205.698 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:33:25.749Z,1762821205.749 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:33:26.102Z,1762821206.102 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:33:26.102Z,1762821206.102 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-11-11T00:33:27.261Z,1762821207.261 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:33:40.997Z,1762821220.997 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:33:46.749Z,1762821226.749 [CommandExec](IMPORTANT): got command set marl_lab.SendObservationDataInterval 1 minute 2025-11-11T00:33:54.733Z,1762821234.733 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:34:08.469Z,1762821248.469 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:34:22.609Z,1762821262.609 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:34:36.345Z,1762821276.345 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:34:50.492Z,1762821290.492 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2025-11-11T00:35:05.041Z,1762821305.041 [BPC1](ERROR): Battery stick #17 (s/n: 0084) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0. 2025-11-11T00:35:05.042Z,1762821305.042 [BPC1](ERROR): Battery stick #24 (s/n: 01D3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-11T00:35:05.042Z,1762821305.042 [BPC1](ERROR): Battery stick #29 (s/n: 00A7) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-11-11T00:35:05.043Z,1762821305.043 [BPC1](ERROR): Battery stick #38 (s/n: 01BC) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-11T00:35:05.044Z,1762821305.044 [BPC1](ERROR): Battery stick #50 (s/n: 019C) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-11T00:35:05.045Z,1762821305.045 [BPC1](ERROR): Battery stick #51 (s/n: 01D6) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-11T00:35:05.045Z,1762821305.045 [BPC1](ERROR): Battery stick #57 (s/n: 019F) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-11-11T00:35:05.046Z,1762821305.046 [BPC1](ERROR): Battery stick #59 (s/n: 0184) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x5AD0. 2025-11-11T00:35:05.046Z,1762821305.046 [BPC1](INFO): Calculating totals. Valid battery stick count: 38. Valid reserve battery stick count: 4. 2025-11-11T00:35:05.050Z,1762821305.050 [BPC1](INFO): Received data from all battery sticks. 2025-11-11T00:36:26.664Z,1762821386.664 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2025-11-11T00:36:26.664Z,1762821386.664 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:36:26.683Z,1762821386.683 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:36:27.090Z,1762821387.090 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:36:27.090Z,1762821387.090 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2025-11-11T00:37:30.896Z,1762821450.896 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-11T00:32:30.7Z 2025-11-11T00:37:30.896Z,1762821450.896 [Default:CheckIn:Read_GPS] Stopped 2025-11-11T00:37:30.896Z,1762821450.896 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-11-11T00:37:31.318Z,1762821451.318 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-11-11T00:37:38.475Z,1762821458.475 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20251111T002714/Courier0004.lzma 2025-11-11T00:37:39.478Z,1762821459.478 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Courier0004.lzma.bak 2025-11-11T00:37:39.478Z,1762821459.478 [DataOverHttps](INFO): SBD MOMSN=26295357 2025-11-11T00:37:55.008Z,1762821475.008 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20251111T002714/Express0005.lzma 2025-11-11T00:37:56.017Z,1762821476.017 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Express0005.lzma.bak 2025-11-11T00:37:56.017Z,1762821476.017 [DataOverHttps](INFO): SBD MOMSN=26295359 2025-11-11T00:37:57.555Z,1762821477.555 [Default:CheckIn:Read_Iridium] Stopped 2025-11-11T00:37:57.555Z,1762821477.555 [Default:CheckIn:C.Wait] Running Loop=1 2025-11-11T00:37:57.555Z,1762821477.555 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-11-11T00:38:05.226Z,1762821485.226 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-11-11T00:38:05.226Z,1762821485.226 [NAL9602] Data Fault, FailCount= 1 2025-11-11T00:38:05.226Z,1762821485.226 [NAL9602](ERROR): Data Fault 2025-11-11T00:38:05.243Z,1762821485.243 [CBIT](ERROR): Data Fault in component: NAL9602 2025-11-11T00:38:05.621Z,1762821485.621 [NAL9602](INFO): Powering down 2025-11-11T00:38:06.450Z,1762821486.450 [CBIT](INFO): Clearing failed state for component NAL9602 2025-11-11T00:38:06.450Z,1762821486.450 [NAL9602] No Fault, FailCount= 1 2025-11-11T00:38:35.925Z,1762821515.925 [NAL9602](INFO): Powering up NAL9602 2025-11-11T00:38:46.829Z,1762821526.829 [NAL9602](INFO): NAL9602 initialized 2025-11-11T00:39:27.667Z,1762821567.667 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2025-11-11T00:39:27.667Z,1762821567.667 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:39:27.678Z,1762821567.678 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:39:28.058Z,1762821568.058 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:39:28.058Z,1762821568.058 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2025-11-11T00:39:48.452Z,1762821588.452 [CommandExec](IMPORTANT): got command run 2025-11-11T00:39:48.455Z,1762821588.455 [CommandExec](IMPORTANT): Running 2025-11-11T00:39:48.673Z,1762821588.673 [Default] Stopped 2025-11-11T00:39:48.673Z,1762821588.673 [Default](DEBUG): Aggregate::uninitialize Default 2025-11-11T00:39:48.673Z,1762821588.673 [Default:B.GoToSurface] Stopped 2025-11-11T00:39:48.673Z,1762821588.673 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-11-11T00:39:48.673Z,1762821588.673 [Default:CheckIn] Stopped 2025-11-11T00:39:48.673Z,1762821588.673 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-11-11T00:39:48.673Z,1762821588.673 [Default:CheckIn:C.Wait] Stopped 2025-11-11T00:39:48.674Z,1762821588.674 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-11-11T00:39:48.674Z,1762821588.674 [MissionManager](IMPORTANT): Started mission marl_lab 2025-11-11T00:39:48.674Z,1762821588.674 [marl_lab] Running Loop=1 2025-11-11T00:39:48.674Z,1762821588.674 [marl_lab](DEBUG): Aggregate::initialize marl_lab 2025-11-11T00:39:48.674Z,1762821588.674 [marl_lab:AbortDrift] Running Loop=1 2025-11-11T00:39:48.674Z,1762821588.674 [marl_lab:AbortDrift](DEBUG): Aggregate::initialize marl_lab:AbortDrift 2025-11-11T00:39:48.674Z,1762821588.674 [marl_lab:AbortDrift:A] Running Loop=1 2025-11-11T00:39:48.674Z,1762821588.674 [marl_lab:B.] Running Loop=1 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:B.](INFO): Initializing TrackAcousticContact. 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:BackseatDriver] Running Loop=1 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:BackseatDriver](DEBUG): Aggregate::initialize marl_lab:BackseatDriver 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:PowerOnly] Running Loop=1 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:PowerOnly](DEBUG): Aggregate::initialize marl_lab:PowerOnly 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:PowerOnly:A] Running Loop=1 2025-11-11T00:39:48.675Z,1762821588.675 [marl_lab:PowerOnly:B] Running Loop=1 2025-11-11T00:39:48.676Z,1762821588.676 [marl_lab:PowerOnly:C] Running Loop=1 2025-11-11T00:39:48.676Z,1762821588.676 [marl_lab:PowerOnly:D] Running Loop=1 2025-11-11T00:39:48.676Z,1762821588.676 [marl_lab:PowerOnly:E.Wait] Running Loop=1 2025-11-11T00:39:48.676Z,1762821588.676 [marl_lab:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-11-11T00:39:48.676Z,1762821588.676 [marl_lab:F] Running Loop=1 2025-11-11T00:39:48.677Z,1762821588.677 [marl_lab:PowerOnly] Running Loop=1 2025-11-11T00:39:48.677Z,1762821588.677 [marl_lab:PowerOnly:D] Stopped 2025-11-11T00:39:48.677Z,1762821588.677 [marl_lab:PowerOnly:C] Stopped 2025-11-11T00:39:48.677Z,1762821588.677 [marl_lab:PowerOnly:B] Stopped 2025-11-11T00:39:48.677Z,1762821588.677 [marl_lab:PowerOnly:A] Stopped 2025-11-11T00:39:48.677Z,1762821588.677 [marl_lab:F] Stopped 2025-11-11T00:39:48.677Z,1762821588.677 [marl_lab:H.Wait] Running Loop=1 2025-11-11T00:39:48.678Z,1762821588.678 [marl_lab:H.Wait](DEBUG): Initialize Wait Component. 2025-11-11T00:39:48.678Z,1762821588.678 [marl_lab:BackseatDriver] Running Loop=1 2025-11-11T00:39:48.678Z,1762821588.678 [marl_lab:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat 2025-11-11T00:39:48.699Z,1762821588.699 [marl_lab:SendObservationData] Running Loop=1 2025-11-11T00:39:48.699Z,1762821588.699 [marl_lab:SendObservationData](DEBUG): Aggregate::initialize marl_lab:SendObservationData 2025-11-11T00:39:48.699Z,1762821588.699 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-11T00:39:48.728Z,1762821588.728 [marl_lab:SendObservationData:A] Running Loop=1 2025-11-11T00:39:48.728Z,1762821588.728 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-11T00:39:48.729Z,1762821588.729 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was empty 2025-11-11T00:39:48.729Z,1762821588.729 [marl_lab:SendObservationData:A](ERROR): data element is not active. 2025-11-11T00:39:48.730Z,1762821588.730 [marl_lab:SendObservationData:A](INFO): Got test_good : n/a str and temp var is NaN n/a str 2025-11-11T00:39:48.730Z,1762821588.730 [marl_lab:SendObservationData:A] Stopped 2025-11-11T00:39:48.730Z,1762821588.730 [marl_lab:SendObservationData:B] Running Loop=1 2025-11-11T00:39:48.730Z,1762821588.730 [marl_lab:B.] Running Loop=1 2025-11-11T00:39:48.731Z,1762821588.731 [marl_lab:AbortDrift] Running Loop=1 2025-11-11T00:39:48.731Z,1762821588.731 [marl_lab:AbortDrift:A](INFO): Insert acoustic timeout set to 1.000000 h . 2025-11-11T00:39:48.736Z,1762821588.736 [marl_lab:AbortDrift:A] Stopped 2025-11-11T00:39:48.736Z,1762821588.736 [marl_lab:AbortDrift:B.AbortDrift] Running Loop=1 2025-11-11T00:39:48.736Z,1762821588.736 [marl_lab:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift. 2025-11-11T00:39:48.737Z,1762821588.737 [marl_lab:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 1.00 hours. 2025-11-11T00:39:48.758Z,1762821588.758 [DAT](INFO): modem://10: set _.others_observations string "NaN" 2025-11-11T00:39:48.758Z,1762821588.758 [DAT](INFO): #Outgoing data=1 2025-11-11T00:39:48.758Z,1762821588.758 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:39:49.009Z,1762821589.009 [DAT](INFO): setting remote address to 10 2025-11-11T00:39:49.048Z,1762821589.048 [BackseatComponent](INFO): Powering up 2025-11-11T00:39:49.048Z,1762821589.048 [BackseatComponent](INFO): Subscribing to LCM channels. 2025-11-11T00:39:49.117Z,1762821589.117 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was empty 2025-11-11T00:39:49.117Z,1762821589.117 [marl_lab:SendObservationData:B] Stopped 2025-11-11T00:39:49.117Z,1762821589.117 [marl_lab:SendObservationData:C] Running Loop=1 2025-11-11T00:39:49.261Z,1762821589.261 [DAT](INFO): DAT read: user:6> 2025-11-11T00:39:49.262Z,1762821589.262 [DAT](INFO): DAT read: RemoteAddr | 10 2025-11-11T00:39:49.262Z,1762821589.262 [DAT](INFO): set remote address to 10 2025-11-11T00:39:49.263Z,1762821589.263 [DAT](INFO): entering online mode 2025-11-11T00:39:49.465Z,1762821589.465 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was not empty 2025-11-11T00:39:49.465Z,1762821589.465 [marl_lab:SendObservationData:C] Stopped 2025-11-11T00:39:49.465Z,1762821589.465 [marl_lab:SendObservationData:E] Running Loop=1 2025-11-11T00:39:49.513Z,1762821589.513 [DAT](INFO): DAT read: user:7> 2025-11-11T00:39:49.513Z,1762821589.513 [DAT](INFO): DAT read: 2025-11-11T00:39:49.514Z,1762821589.514 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2025-11-11T00:39:49.515Z,1762821589.515 [DAT](INFO): commRate: 800 2025-11-11T00:39:49.515Z,1762821589.515 [DAT](INFO): online mode acknowledged 2025-11-11T00:39:49.515Z,1762821589.515 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:39:49.876Z,1762821589.876 [marl_lab:SendObservationData:E](INFO): SendData: sent send_observations : n/a str to nearby vehicles. Elapsed time 7.193537 min 2025-11-11T00:39:49.877Z,1762821589.877 [marl_lab:SendObservationData:E] Stopped 2025-11-11T00:39:49.877Z,1762821589.877 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was not empty 2025-11-11T00:39:49.878Z,1762821589.878 [marl_lab:SendObservationData](INFO): Completed marl_lab:SendObservationData 2025-11-11T00:39:49.878Z,1762821589.878 [marl_lab:SendObservationData] Stopped 2025-11-11T00:39:49.878Z,1762821589.878 [marl_lab:SendObservationData](DEBUG): Aggregate::uninitialize marl_lab:SendObservationData 2025-11-11T00:39:49.878Z,1762821589.878 [marl_lab:SendObservationData:D.SendDirect] Stopped 2025-11-11T00:39:52.510Z,1762821592.510 [CTD_Seabird](ERROR): Failed to parse device response: 2025-11-11T00:39:52.789Z,1762821592.789 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:39:51.9707 2025-11-11T00:39:52.789Z,1762821592.789 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:39:53.558Z,1762821593.558 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287970 psu 2025-11-11T00:39:53.560Z,1762821593.560 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:39:54.557Z,1762821594.557 [CTD_Seabird](ERROR): Salinity reading out of range: 0.288025 psu 2025-11-11T00:39:54.558Z,1762821594.558 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:39:55.557Z,1762821595.557 [CTD_Seabird](ERROR): Salinity reading out of range: 0.288024 psu 2025-11-11T00:39:55.558Z,1762821595.558 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:39:56.549Z,1762821596.549 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287975 psu 2025-11-11T00:39:56.550Z,1762821596.550 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:39:57.553Z,1762821597.553 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287970 psu 2025-11-11T00:39:57.554Z,1762821597.554 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:39:58.560Z,1762821598.560 [CTD_Seabird](ERROR): Salinity reading out of range: 0.288025 psu 2025-11-11T00:39:58.562Z,1762821598.562 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:39:59.089Z,1762821599.089 [DAT](INFO): DAT read: Rx Time:00:39:57.7784 2025-11-11T00:39:59.089Z,1762821599.089 [DAT](INFO): Rx dataTimestamp_ set to:1762821599.089003 2025-11-11T00:39:59.560Z,1762821599.560 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287968 psu 2025-11-11T00:39:59.562Z,1762821599.562 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:39:59.865Z,1762821599.865 [DAT](INFO): DAT read: 2025-11-11T00:39:59.865Z,1762821599.865 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:39:59.865Z,1762821599.865 [DAT](INFO): Got DATA 2 2025-11-11T00:39:59.866Z,1762821599.866 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:39:59.866Z,1762821599.866 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:39:59.867Z,1762821599.867 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:39:59.868Z,1762821599.868 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.1 AGC:18 SPD:+0.0 CCERR:013 2025-11-11T00:39:59.868Z,1762821599.868 [DAT](INFO): Got CRC:Pass 2025-11-11T00:39:59.868Z,1762821599.868 [DAT](INFO): Got CRC:Pass 2025-11-11T00:39:59.868Z,1762821599.868 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:39:59.869Z,1762821599.869 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:39:59.869Z,1762821599.869 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:39:59.869Z,1762821599.869 [DAT](INFO): Got ack 2025-11-11T00:39:59.869Z,1762821599.869 [DAT](INFO): DAT read: 2025-11-11T00:39:59.870Z,1762821599.870 [DAT](INFO): DAT read: 2025-11-11T00:39:59.870Z,1762821599.870 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:39:59.870Z,1762821599.870 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:40:00.117Z,1762821600.117 [DAT](INFO): modem://10: set _.others_observations string "NaN" 2025-11-11T00:40:00.117Z,1762821600.117 [DAT](INFO): #Outgoing data=1 2025-11-11T00:40:00.117Z,1762821600.117 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:40:00.369Z,1762821600.369 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:40:00.557Z,1762821600.557 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287969 psu 2025-11-11T00:40:00.558Z,1762821600.558 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:01.550Z,1762821601.550 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287972 psu 2025-11-11T00:40:01.551Z,1762821601.551 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:02.554Z,1762821602.554 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287966 psu 2025-11-11T00:40:02.555Z,1762821602.555 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:03.558Z,1762821603.558 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287964 psu 2025-11-11T00:40:03.559Z,1762821603.559 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:03.645Z,1762821603.645 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:40:02.8208 2025-11-11T00:40:03.646Z,1762821603.646 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:40:04.562Z,1762821604.562 [CTD_Seabird](ERROR): Salinity reading out of range: 0.288018 psu 2025-11-11T00:40:04.563Z,1762821604.563 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:05.566Z,1762821605.566 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287967 psu 2025-11-11T00:40:05.567Z,1762821605.567 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:06.570Z,1762821606.570 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287970 psu 2025-11-11T00:40:06.571Z,1762821606.571 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:07.574Z,1762821607.574 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287968 psu 2025-11-11T00:40:07.575Z,1762821607.575 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:08.578Z,1762821608.578 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287970 psu 2025-11-11T00:40:08.579Z,1762821608.579 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:09.582Z,1762821609.582 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287972 psu 2025-11-11T00:40:09.583Z,1762821609.583 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:09.945Z,1762821609.945 [DAT](INFO): DAT read: Rx Time:00:40:08.6285 2025-11-11T00:40:09.945Z,1762821609.945 [DAT](INFO): Rx dataTimestamp_ set to:1762821609.945039 2025-11-11T00:40:10.586Z,1762821610.586 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287973 psu 2025-11-11T00:40:10.587Z,1762821610.587 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:10.701Z,1762821610.701 [DAT](INFO): DAT read: 2025-11-11T00:40:10.701Z,1762821610.701 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:40:10.702Z,1762821610.702 [DAT](INFO): Got DATA 2 2025-11-11T00:40:10.702Z,1762821610.702 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:40:10.703Z,1762821610.703 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:40:10.703Z,1762821610.703 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:40:10.704Z,1762821610.704 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:19.7 AGC:17 SPD:+0.0 CCERR:013 2025-11-11T00:40:10.704Z,1762821610.704 [DAT](INFO): Got CRC:Pass 2025-11-11T00:40:10.704Z,1762821610.704 [DAT](INFO): Got CRC:Pass 2025-11-11T00:40:10.705Z,1762821610.705 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:40:10.705Z,1762821610.705 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:40:10.705Z,1762821610.705 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:40:10.705Z,1762821610.705 [DAT](INFO): Got ack 2025-11-11T00:40:10.705Z,1762821610.705 [DAT](INFO): DAT read: 2025-11-11T00:40:10.706Z,1762821610.706 [DAT](INFO): DAT read: 2025-11-11T00:40:10.706Z,1762821610.706 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:40:10.707Z,1762821610.707 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:40:10.953Z,1762821610.953 [DAT](INFO): modem://10: set _.others_observations string "NaN" 2025-11-11T00:40:10.953Z,1762821610.953 [DAT](INFO): #Outgoing data=1 2025-11-11T00:40:10.953Z,1762821610.953 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:40:11.204Z,1762821611.204 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:40:11.590Z,1762821611.590 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287918 psu 2025-11-11T00:40:11.591Z,1762821611.591 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:12.594Z,1762821612.594 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287970 psu 2025-11-11T00:40:12.595Z,1762821612.595 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:13.598Z,1762821613.598 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287970 psu 2025-11-11T00:40:13.599Z,1762821613.599 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:14.481Z,1762821614.481 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:40:13.6708 2025-11-11T00:40:14.481Z,1762821614.481 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:40:14.602Z,1762821614.602 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287976 psu 2025-11-11T00:40:14.603Z,1762821614.603 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:15.606Z,1762821615.606 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287976 psu 2025-11-11T00:40:15.607Z,1762821615.607 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:16.610Z,1762821616.610 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287969 psu 2025-11-11T00:40:16.611Z,1762821616.611 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:17.614Z,1762821617.614 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287915 psu 2025-11-11T00:40:17.615Z,1762821617.615 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:18.618Z,1762821618.618 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287916 psu 2025-11-11T00:40:18.619Z,1762821618.619 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:19.622Z,1762821619.622 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287969 psu 2025-11-11T00:40:19.623Z,1762821619.623 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:20.626Z,1762821620.626 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287969 psu 2025-11-11T00:40:20.627Z,1762821620.627 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:20.781Z,1762821620.781 [DAT](INFO): DAT read: Rx Time:00:40:19.5287 2025-11-11T00:40:20.781Z,1762821620.781 [DAT](INFO): Rx dataTimestamp_ set to:1762821620.781010 2025-11-11T00:40:21.537Z,1762821621.537 [DAT](INFO): DAT read: 2025-11-11T00:40:21.538Z,1762821621.538 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:40:21.538Z,1762821621.538 [DAT](INFO): Got DATA 2 2025-11-11T00:40:21.539Z,1762821621.539 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:40:21.539Z,1762821621.539 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:40:21.540Z,1762821621.540 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:40:21.541Z,1762821621.541 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.1 AGC:17 SPD:+0.0 CCERR:013 2025-11-11T00:40:21.542Z,1762821621.542 [DAT](INFO): Got CRC:Pass 2025-11-11T00:40:21.542Z,1762821621.542 [DAT](INFO): Got CRC:Pass 2025-11-11T00:40:21.542Z,1762821621.542 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:40:21.542Z,1762821621.542 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:40:21.543Z,1762821621.543 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:40:21.543Z,1762821621.543 [DAT](INFO): Got ack 2025-11-11T00:40:21.543Z,1762821621.543 [DAT](INFO): DAT read: 2025-11-11T00:40:21.543Z,1762821621.543 [DAT](INFO): DAT read: 2025-11-11T00:40:21.544Z,1762821621.544 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:40:21.545Z,1762821621.545 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:40:21.630Z,1762821621.630 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287967 psu 2025-11-11T00:40:21.631Z,1762821621.631 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:21.790Z,1762821621.790 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:40:21.790Z,1762821621.790 [DAT](INFO): #Outgoing data=1 2025-11-11T00:40:21.790Z,1762821621.790 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:40:22.041Z,1762821622.041 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:40:22.634Z,1762821622.634 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287968 psu 2025-11-11T00:40:22.635Z,1762821622.635 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:23.638Z,1762821623.638 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287968 psu 2025-11-11T00:40:23.639Z,1762821623.639 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:24.642Z,1762821624.642 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287916 psu 2025-11-11T00:40:24.643Z,1762821624.643 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:25.317Z,1762821625.317 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:40:24.4708 2025-11-11T00:40:25.317Z,1762821625.317 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:40:25.646Z,1762821625.646 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287965 psu 2025-11-11T00:40:25.647Z,1762821625.647 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:26.650Z,1762821626.650 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287968 psu 2025-11-11T00:40:26.651Z,1762821626.651 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:27.654Z,1762821627.654 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287969 psu 2025-11-11T00:40:27.655Z,1762821627.655 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:28.658Z,1762821628.658 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287967 psu 2025-11-11T00:40:28.659Z,1762821628.659 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:29.662Z,1762821629.662 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287966 psu 2025-11-11T00:40:29.663Z,1762821629.663 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:30.666Z,1762821630.666 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287917 psu 2025-11-11T00:40:30.667Z,1762821630.667 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:31.365Z,1762821631.365 [DAT](INFO): DAT read: Rx Time:00:40:30.0288 2025-11-11T00:40:31.365Z,1762821631.365 [DAT](INFO): Rx dataTimestamp_ set to:1762821631.365029 2025-11-11T00:40:31.670Z,1762821631.670 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287911 psu 2025-11-11T00:40:31.671Z,1762821631.671 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:32.121Z,1762821632.121 [DAT](INFO): DAT read: 2025-11-11T00:40:32.121Z,1762821632.121 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:40:32.121Z,1762821632.121 [DAT](INFO): Got DATA 2 2025-11-11T00:40:32.122Z,1762821632.122 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:40:32.122Z,1762821632.122 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:40:32.123Z,1762821632.123 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:40:32.124Z,1762821632.124 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.5 AGC:15 SPD:+0.0 CCERR:013 2025-11-11T00:40:32.124Z,1762821632.124 [DAT](INFO): Got CRC:Pass 2025-11-11T00:40:32.124Z,1762821632.124 [DAT](INFO): Got CRC:Pass 2025-11-11T00:40:32.124Z,1762821632.124 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:40:32.125Z,1762821632.125 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=1, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:40:32.125Z,1762821632.125 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:40:32.125Z,1762821632.125 [DAT](INFO): Got ack 2025-11-11T00:40:32.125Z,1762821632.125 [DAT](INFO): DAT read: 2025-11-11T00:40:32.126Z,1762821632.126 [DAT](INFO): DAT read: 2025-11-11T00:40:32.126Z,1762821632.126 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=1, outgoingCommsBuffer_ size=0 2025-11-11T00:40:32.126Z,1762821632.126 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:40:32.674Z,1762821632.674 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287913 psu 2025-11-11T00:40:32.675Z,1762821632.675 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:33.678Z,1762821633.678 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287968 psu 2025-11-11T00:40:33.679Z,1762821633.679 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:34.682Z,1762821634.682 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287965 psu 2025-11-11T00:40:34.683Z,1762821634.683 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:35.686Z,1762821635.686 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287908 psu 2025-11-11T00:40:35.687Z,1762821635.687 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:36.690Z,1762821636.690 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287912 psu 2025-11-11T00:40:36.691Z,1762821636.691 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:37.694Z,1762821637.694 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:40:37.695Z,1762821637.695 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:38.698Z,1762821638.698 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287967 psu 2025-11-11T00:40:38.699Z,1762821638.699 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:39.702Z,1762821639.702 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287913 psu 2025-11-11T00:40:39.703Z,1762821639.703 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:40.706Z,1762821640.706 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287911 psu 2025-11-11T00:40:40.707Z,1762821640.707 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:41.710Z,1762821641.710 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:40:41.711Z,1762821641.711 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:42.714Z,1762821642.714 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:40:42.715Z,1762821642.715 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:43.718Z,1762821643.718 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287913 psu 2025-11-11T00:40:43.719Z,1762821643.719 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:44.722Z,1762821644.722 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287963 psu 2025-11-11T00:40:44.723Z,1762821644.723 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:45.726Z,1762821645.726 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287965 psu 2025-11-11T00:40:45.727Z,1762821645.727 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:46.730Z,1762821646.730 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287967 psu 2025-11-11T00:40:46.731Z,1762821646.731 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:47.734Z,1762821647.734 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287912 psu 2025-11-11T00:40:47.735Z,1762821647.735 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:48.738Z,1762821648.738 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287909 psu 2025-11-11T00:40:48.739Z,1762821648.739 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:49.672Z,1762821649.672 [marl_lab:SendObservationData] Running Loop=1 2025-11-11T00:40:49.672Z,1762821649.672 [marl_lab:SendObservationData](DEBUG): Aggregate::initialize marl_lab:SendObservationData 2025-11-11T00:40:49.672Z,1762821649.672 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-11T00:40:49.673Z,1762821649.673 [marl_lab:SendObservationData:A] Running Loop=1 2025-11-11T00:40:49.674Z,1762821649.674 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was empty 2025-11-11T00:40:49.674Z,1762821649.674 [marl_lab:SendObservationData:A](ERROR): data element is not active. 2025-11-11T00:40:49.675Z,1762821649.675 [marl_lab:SendObservationData:A](INFO): Got test_good : n/a str and temp var is n/a str 2025-11-11T00:40:49.675Z,1762821649.675 [marl_lab:SendObservationData:A] Stopped 2025-11-11T00:40:49.675Z,1762821649.675 [marl_lab:SendObservationData:B] Running Loop=1 2025-11-11T00:40:49.742Z,1762821649.742 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287911 psu 2025-11-11T00:40:49.743Z,1762821649.743 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:49.806Z,1762821649.806 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:40:49.807Z,1762821649.807 [DAT](INFO): #Outgoing data=1 2025-11-11T00:40:49.807Z,1762821649.807 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:40:50.056Z,1762821650.056 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:40:50.101Z,1762821650.101 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was empty 2025-11-11T00:40:50.101Z,1762821650.101 [marl_lab:SendObservationData:B] Stopped 2025-11-11T00:40:50.101Z,1762821650.101 [marl_lab:SendObservationData:C] Running Loop=1 2025-11-11T00:40:50.481Z,1762821650.481 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was not empty 2025-11-11T00:40:50.481Z,1762821650.481 [marl_lab:SendObservationData:C] Stopped 2025-11-11T00:40:50.481Z,1762821650.481 [marl_lab:SendObservationData:E] Running Loop=1 2025-11-11T00:40:50.746Z,1762821650.746 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287909 psu 2025-11-11T00:40:50.747Z,1762821650.747 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:50.873Z,1762821650.872 [marl_lab:SendObservationData:E](INFO): SendData: sent send_observations : n/a str to nearby vehicles. Elapsed time 1.010601 min 2025-11-11T00:40:50.873Z,1762821650.873 [marl_lab:SendObservationData:E] Stopped 2025-11-11T00:40:50.873Z,1762821650.873 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was not empty 2025-11-11T00:40:50.874Z,1762821650.874 [marl_lab:SendObservationData](INFO): Completed marl_lab:SendObservationData 2025-11-11T00:40:50.874Z,1762821650.874 [marl_lab:SendObservationData] Stopped 2025-11-11T00:40:50.874Z,1762821650.874 [marl_lab:SendObservationData](DEBUG): Aggregate::uninitialize marl_lab:SendObservationData 2025-11-11T00:40:50.874Z,1762821650.874 [marl_lab:SendObservationData:D.SendDirect] Stopped 2025-11-11T00:40:51.750Z,1762821651.750 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287963 psu 2025-11-11T00:40:51.751Z,1762821651.751 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:52.755Z,1762821652.755 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:40:52.756Z,1762821652.756 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:53.333Z,1762821653.333 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:40:52.5210 2025-11-11T00:40:53.333Z,1762821653.333 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:40:53.758Z,1762821653.758 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287911 psu 2025-11-11T00:40:53.759Z,1762821653.759 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:54.762Z,1762821654.762 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287909 psu 2025-11-11T00:40:54.763Z,1762821654.763 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:55.766Z,1762821655.766 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:40:55.767Z,1762821655.767 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:56.770Z,1762821656.770 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287908 psu 2025-11-11T00:40:56.771Z,1762821656.771 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:57.774Z,1762821657.774 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287962 psu 2025-11-11T00:40:57.775Z,1762821657.775 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:58.778Z,1762821658.778 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287960 psu 2025-11-11T00:40:58.779Z,1762821658.779 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:40:59.637Z,1762821659.637 [DAT](INFO): DAT read: Rx Time:00:40:58.2291 2025-11-11T00:40:59.637Z,1762821659.637 [DAT](INFO): Rx dataTimestamp_ set to:1762821659.636990 2025-11-11T00:40:59.782Z,1762821659.782 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287958 psu 2025-11-11T00:40:59.783Z,1762821659.783 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:00.397Z,1762821660.397 [DAT](INFO): DAT read: 2025-11-11T00:41:00.397Z,1762821660.397 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:41:00.397Z,1762821660.397 [DAT](INFO): Got DATA 2 2025-11-11T00:41:00.398Z,1762821660.398 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:41:00.398Z,1762821660.398 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:41:00.399Z,1762821660.399 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:41:00.400Z,1762821660.400 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:19.8 AGC:16 SPD:+0.0 CCERR:013 2025-11-11T00:41:00.400Z,1762821660.400 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:00.400Z,1762821660.400 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:00.400Z,1762821660.400 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:41:00.401Z,1762821660.401 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:41:00.401Z,1762821660.401 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:41:00.401Z,1762821660.401 [DAT](INFO): Got ack 2025-11-11T00:41:00.401Z,1762821660.401 [DAT](INFO): DAT read: 2025-11-11T00:41:00.402Z,1762821660.402 [DAT](INFO): DAT read: 2025-11-11T00:41:00.402Z,1762821660.402 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:41:00.402Z,1762821660.402 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:41:00.649Z,1762821660.649 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:41:00.649Z,1762821660.649 [DAT](INFO): #Outgoing data=1 2025-11-11T00:41:00.649Z,1762821660.649 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:41:00.786Z,1762821660.786 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287911 psu 2025-11-11T00:41:00.787Z,1762821660.787 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:00.901Z,1762821660.901 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:41:01.791Z,1762821661.791 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287962 psu 2025-11-11T00:41:01.792Z,1762821661.792 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:02.794Z,1762821662.794 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287958 psu 2025-11-11T00:41:02.795Z,1762821662.795 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:03.798Z,1762821663.798 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287908 psu 2025-11-11T00:41:03.799Z,1762821663.799 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:04.181Z,1762821664.181 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:41:03.3711 2025-11-11T00:41:04.181Z,1762821664.181 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:41:04.802Z,1762821664.802 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287904 psu 2025-11-11T00:41:04.803Z,1762821664.803 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:05.806Z,1762821665.806 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287959 psu 2025-11-11T00:41:05.807Z,1762821665.807 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:06.811Z,1762821666.811 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:06.812Z,1762821666.812 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:07.814Z,1762821667.814 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:41:07.815Z,1762821667.815 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:08.818Z,1762821668.818 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:41:08.819Z,1762821668.819 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:09.822Z,1762821669.822 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287908 psu 2025-11-11T00:41:09.823Z,1762821669.823 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:10.485Z,1762821670.485 [DAT](INFO): DAT read: Rx Time:00:41:09.0792 2025-11-11T00:41:10.485Z,1762821670.485 [DAT](INFO): Rx dataTimestamp_ set to:1762821670.485057 2025-11-11T00:41:10.827Z,1762821670.827 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287908 psu 2025-11-11T00:41:10.833Z,1762821670.833 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:11.241Z,1762821671.241 [DAT](INFO): DAT read: 2025-11-11T00:41:11.241Z,1762821671.241 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:41:11.241Z,1762821671.241 [DAT](INFO): Got DATA 2 2025-11-11T00:41:11.242Z,1762821671.242 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:41:11.242Z,1762821671.242 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:41:11.243Z,1762821671.243 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:41:11.244Z,1762821671.244 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.4 AGC:18 SPD:+0.0 CCERR:013 2025-11-11T00:41:11.244Z,1762821671.244 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:11.244Z,1762821671.244 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:11.244Z,1762821671.244 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:41:11.245Z,1762821671.245 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:41:11.245Z,1762821671.245 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:41:11.245Z,1762821671.245 [DAT](INFO): Got ack 2025-11-11T00:41:11.245Z,1762821671.245 [DAT](INFO): DAT read: 2025-11-11T00:41:11.246Z,1762821671.246 [DAT](INFO): DAT read: 2025-11-11T00:41:11.246Z,1762821671.246 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:41:11.246Z,1762821671.246 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:41:11.493Z,1762821671.493 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:41:11.493Z,1762821671.493 [DAT](INFO): #Outgoing data=1 2025-11-11T00:41:11.493Z,1762821671.493 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:41:11.745Z,1762821671.745 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:41:11.830Z,1762821671.830 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:11.831Z,1762821671.831 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:12.842Z,1762821672.842 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287907 psu 2025-11-11T00:41:12.843Z,1762821672.843 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:13.850Z,1762821673.850 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:13.851Z,1762821673.851 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:14.858Z,1762821674.858 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287854 psu 2025-11-11T00:41:14.859Z,1762821674.859 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:15.025Z,1762821675.025 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:41:14.1711 2025-11-11T00:41:15.025Z,1762821675.025 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:41:15.866Z,1762821675.866 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:15.867Z,1762821675.867 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:16.874Z,1762821676.874 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287904 psu 2025-11-11T00:41:16.876Z,1762821676.876 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:17.882Z,1762821677.882 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287905 psu 2025-11-11T00:41:17.883Z,1762821677.883 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:18.890Z,1762821678.890 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:18.891Z,1762821678.891 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:19.898Z,1762821679.898 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287910 psu 2025-11-11T00:41:19.899Z,1762821679.899 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:20.906Z,1762821680.906 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287908 psu 2025-11-11T00:41:20.907Z,1762821680.907 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:21.325Z,1762821681.325 [DAT](INFO): DAT read: Rx Time:00:41:19.9293 2025-11-11T00:41:21.326Z,1762821681.326 [DAT](INFO): Rx dataTimestamp_ set to:1762821681.324892 2025-11-11T00:41:21.915Z,1762821681.915 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:21.916Z,1762821681.916 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:22.080Z,1762821682.080 [DAT](INFO): DAT read: 2025-11-11T00:41:22.081Z,1762821682.081 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:41:22.081Z,1762821682.081 [DAT](INFO): Got DATA 2 2025-11-11T00:41:22.082Z,1762821682.082 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:41:22.082Z,1762821682.082 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:41:22.083Z,1762821682.083 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:41:22.084Z,1762821682.084 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.1 AGC:15 SPD:+0.0 CCERR:013 2025-11-11T00:41:22.084Z,1762821682.084 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:22.084Z,1762821682.084 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:22.084Z,1762821682.084 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:41:22.085Z,1762821682.085 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:41:22.085Z,1762821682.085 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:41:22.085Z,1762821682.085 [DAT](INFO): Got ack 2025-11-11T00:41:22.085Z,1762821682.085 [DAT](INFO): DAT read: 2025-11-11T00:41:22.086Z,1762821682.086 [DAT](INFO): DAT read: 2025-11-11T00:41:22.086Z,1762821682.086 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:41:22.086Z,1762821682.086 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:41:22.333Z,1762821682.333 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:41:22.333Z,1762821682.333 [DAT](INFO): #Outgoing data=1 2025-11-11T00:41:22.333Z,1762821682.333 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:41:22.585Z,1762821682.585 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:41:22.922Z,1762821682.922 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:22.923Z,1762821682.923 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:23.926Z,1762821683.926 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:23.927Z,1762821683.927 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:24.931Z,1762821684.931 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287904 psu 2025-11-11T00:41:24.932Z,1762821684.932 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:25.861Z,1762821685.861 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:41:25.0212 2025-11-11T00:41:25.862Z,1762821685.862 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:41:25.934Z,1762821685.934 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287904 psu 2025-11-11T00:41:25.935Z,1762821685.935 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:26.938Z,1762821686.938 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287908 psu 2025-11-11T00:41:26.939Z,1762821686.939 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:27.942Z,1762821687.942 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287907 psu 2025-11-11T00:41:27.943Z,1762821687.943 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:28.946Z,1762821688.946 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287960 psu 2025-11-11T00:41:28.947Z,1762821688.947 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:29.950Z,1762821689.950 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287906 psu 2025-11-11T00:41:29.951Z,1762821689.951 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:30.954Z,1762821690.954 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287902 psu 2025-11-11T00:41:30.955Z,1762821690.955 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:31.958Z,1762821691.958 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287909 psu 2025-11-11T00:41:31.959Z,1762821691.959 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:32.185Z,1762821692.185 [DAT](INFO): DAT read: Rx Time:00:41:30.7794 2025-11-11T00:41:32.185Z,1762821692.185 [DAT](INFO): Rx dataTimestamp_ set to:1762821692.185102 2025-11-11T00:41:32.941Z,1762821692.941 [DAT](INFO): DAT read: 2025-11-11T00:41:32.941Z,1762821692.941 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:41:32.941Z,1762821692.941 [DAT](INFO): Got DATA 2 2025-11-11T00:41:32.942Z,1762821692.942 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:41:32.942Z,1762821692.942 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:41:32.943Z,1762821692.943 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:41:32.944Z,1762821692.944 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.1 AGC:15 SPD:+0.0 CCERR:013 2025-11-11T00:41:32.944Z,1762821692.944 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:32.944Z,1762821692.944 [DAT](INFO): Got CRC:Pass 2025-11-11T00:41:32.944Z,1762821692.944 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:41:32.945Z,1762821692.945 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=1, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:41:32.945Z,1762821692.945 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:41:32.945Z,1762821692.945 [DAT](INFO): Got ack 2025-11-11T00:41:32.945Z,1762821692.945 [DAT](INFO): DAT read: 2025-11-11T00:41:32.946Z,1762821692.946 [DAT](INFO): DAT read: 2025-11-11T00:41:32.946Z,1762821692.946 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=1, outgoingCommsBuffer_ size=0 2025-11-11T00:41:32.946Z,1762821692.946 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:41:32.962Z,1762821692.962 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287849 psu 2025-11-11T00:41:32.963Z,1762821692.963 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:33.966Z,1762821693.966 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287851 psu 2025-11-11T00:41:33.967Z,1762821693.967 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:34.970Z,1762821694.970 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287852 psu 2025-11-11T00:41:34.971Z,1762821694.971 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:35.974Z,1762821695.974 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287852 psu 2025-11-11T00:41:35.975Z,1762821695.975 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:36.978Z,1762821696.978 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287851 psu 2025-11-11T00:41:36.979Z,1762821696.979 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:37.983Z,1762821697.983 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287852 psu 2025-11-11T00:41:37.984Z,1762821697.984 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:38.986Z,1762821698.986 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287852 psu 2025-11-11T00:41:38.987Z,1762821698.987 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:39.990Z,1762821699.990 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287850 psu 2025-11-11T00:41:39.991Z,1762821699.991 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:40.994Z,1762821700.994 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287845 psu 2025-11-11T00:41:40.995Z,1762821700.995 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:41.998Z,1762821701.998 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287902 psu 2025-11-11T00:41:41.999Z,1762821701.999 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:43.002Z,1762821703.002 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287849 psu 2025-11-11T00:41:43.003Z,1762821703.003 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:44.007Z,1762821704.007 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287847 psu 2025-11-11T00:41:44.008Z,1762821704.008 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:45.010Z,1762821705.010 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287845 psu 2025-11-11T00:41:45.011Z,1762821705.011 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:46.014Z,1762821706.014 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287956 psu 2025-11-11T00:41:46.015Z,1762821706.015 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:47.018Z,1762821707.018 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287900 psu 2025-11-11T00:41:47.019Z,1762821707.019 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:48.022Z,1762821708.022 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287844 psu 2025-11-11T00:41:48.023Z,1762821708.023 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:49.026Z,1762821709.026 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287847 psu 2025-11-11T00:41:49.027Z,1762821709.027 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:50.030Z,1762821710.030 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287902 psu 2025-11-11T00:41:50.031Z,1762821710.031 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:50.752Z,1762821710.752 [marl_lab:SendObservationData] Running Loop=1 2025-11-11T00:41:50.752Z,1762821710.752 [marl_lab:SendObservationData](DEBUG): Aggregate::initialize marl_lab:SendObservationData 2025-11-11T00:41:50.752Z,1762821710.752 [marl_lab:SendObservationData:D.SendDirect] Running Loop=1 2025-11-11T00:41:50.753Z,1762821710.753 [marl_lab:SendObservationData:A] Running Loop=1 2025-11-11T00:41:50.754Z,1762821710.754 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was empty 2025-11-11T00:41:50.754Z,1762821710.754 [marl_lab:SendObservationData:A](ERROR): data element is not active. 2025-11-11T00:41:50.754Z,1762821710.754 [marl_lab:SendObservationData:A](INFO): Got test_good : n/a str and temp var is n/a str 2025-11-11T00:41:50.755Z,1762821710.755 [marl_lab:SendObservationData:A] Stopped 2025-11-11T00:41:50.755Z,1762821710.755 [marl_lab:SendObservationData:B] Running Loop=1 2025-11-11T00:41:50.833Z,1762821710.833 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:41:50.833Z,1762821710.833 [DAT](INFO): #Outgoing data=1 2025-11-11T00:41:50.833Z,1762821710.833 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:41:51.035Z,1762821711.035 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287845 psu 2025-11-11T00:41:51.036Z,1762821711.036 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:51.092Z,1762821711.092 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:41:51.169Z,1762821711.169 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was empty 2025-11-11T00:41:51.169Z,1762821711.169 [marl_lab:SendObservationData:B] Stopped 2025-11-11T00:41:51.169Z,1762821711.169 [marl_lab:SendObservationData:C] Running Loop=1 2025-11-11T00:41:51.573Z,1762821711.573 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was not empty 2025-11-11T00:41:51.573Z,1762821711.573 [marl_lab:SendObservationData:C] Stopped 2025-11-11T00:41:51.573Z,1762821711.573 [marl_lab:SendObservationData:E] Running Loop=1 2025-11-11T00:41:51.993Z,1762821711.993 [marl_lab:SendObservationData:E](INFO): SendData: sent send_observations : n/a str to nearby vehicles. Elapsed time 1.011466 min 2025-11-11T00:41:51.993Z,1762821711.993 [marl_lab:SendObservationData:E] Stopped 2025-11-11T00:41:51.994Z,1762821711.994 [marl_lab:SendObservationData:D.SendDirect](DEBUG): SendData::Push: Added data for modem://10:_.others_observations, buffer was not empty 2025-11-11T00:41:51.994Z,1762821711.994 [marl_lab:SendObservationData](INFO): Completed marl_lab:SendObservationData 2025-11-11T00:41:51.994Z,1762821711.994 [marl_lab:SendObservationData] Stopped 2025-11-11T00:41:51.994Z,1762821711.994 [marl_lab:SendObservationData](DEBUG): Aggregate::uninitialize marl_lab:SendObservationData 2025-11-11T00:41:51.994Z,1762821711.994 [marl_lab:SendObservationData:D.SendDirect] Stopped 2025-11-11T00:41:52.038Z,1762821712.038 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287846 psu 2025-11-11T00:41:52.039Z,1762821712.039 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:53.042Z,1762821713.042 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287848 psu 2025-11-11T00:41:53.043Z,1762821713.043 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:54.046Z,1762821714.046 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287847 psu 2025-11-11T00:41:54.047Z,1762821714.047 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:54.361Z,1762821714.361 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:41:53.5214 2025-11-11T00:41:54.361Z,1762821714.361 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:41:55.050Z,1762821715.050 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287851 psu 2025-11-11T00:41:55.051Z,1762821715.051 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:56.056Z,1762821716.056 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287845 psu 2025-11-11T00:41:56.057Z,1762821716.057 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:57.058Z,1762821717.058 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287845 psu 2025-11-11T00:41:57.059Z,1762821717.059 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:58.078Z,1762821718.078 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287849 psu 2025-11-11T00:41:58.079Z,1762821718.079 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:41:59.082Z,1762821719.082 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287849 psu 2025-11-11T00:41:59.083Z,1762821719.083 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:00.086Z,1762821720.086 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287847 psu 2025-11-11T00:42:00.089Z,1762821720.089 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:00.661Z,1762821720.661 [DAT](INFO): DAT read: Rx Time:00:41:59.2797 2025-11-11T00:42:00.661Z,1762821720.661 [DAT](INFO): Rx dataTimestamp_ set to:1762821720.660978 2025-11-11T00:42:01.090Z,1762821721.090 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287846 psu 2025-11-11T00:42:01.091Z,1762821721.091 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:01.416Z,1762821721.416 [DAT](INFO): DAT read: 2025-11-11T00:42:01.417Z,1762821721.417 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:42:01.417Z,1762821721.417 [DAT](INFO): Got DATA 2 2025-11-11T00:42:01.418Z,1762821721.418 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:42:01.418Z,1762821721.418 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:42:01.419Z,1762821721.419 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:42:01.420Z,1762821721.420 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.0 AGC:18 SPD:+0.0 CCERR:013 2025-11-11T00:42:01.420Z,1762821721.420 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:01.420Z,1762821721.420 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:01.420Z,1762821721.420 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:42:01.421Z,1762821721.421 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:42:01.421Z,1762821721.421 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:42:01.421Z,1762821721.421 [DAT](INFO): Got ack 2025-11-11T00:42:01.421Z,1762821721.421 [DAT](INFO): DAT read: 2025-11-11T00:42:01.422Z,1762821721.422 [DAT](INFO): DAT read: 2025-11-11T00:42:01.422Z,1762821721.422 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:42:01.422Z,1762821721.422 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:42:01.669Z,1762821721.669 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:42:01.669Z,1762821721.669 [DAT](INFO): #Outgoing data=1 2025-11-11T00:42:01.669Z,1762821721.669 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:42:01.921Z,1762821721.921 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:42:02.094Z,1762821722.094 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287853 psu 2025-11-11T00:42:02.095Z,1762821722.095 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:03.098Z,1762821723.098 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287851 psu 2025-11-11T00:42:03.099Z,1762821723.099 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:04.110Z,1762821724.110 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287853 psu 2025-11-11T00:42:04.111Z,1762821724.111 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:05.114Z,1762821725.114 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287794 psu 2025-11-11T00:42:05.115Z,1762821725.115 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:05.199Z,1762821725.199 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:42:04.3715 2025-11-11T00:42:05.199Z,1762821725.199 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:42:06.118Z,1762821726.118 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287845 psu 2025-11-11T00:42:06.119Z,1762821726.119 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:07.122Z,1762821727.122 [CTD_Seabird](ERROR): Salinity reading out of range: 0.287794 psu 2025-11-11T00:42:07.123Z,1762821727.123 [CTD_Seabird](INFO): some bad data, not updating bins 2025-11-11T00:42:07.253Z,1762821727.253 [CommandExec](IMPORTANT): got command stop 2025-11-11T00:42:07.253Z,1762821727.253 [CommandExec](IMPORTANT): Scheduling is paused 2025-11-11T00:42:07.253Z,1762821727.253 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-11-11T00:42:07.368Z,1762821727.368 [MissionManager](INFO): MissionManager is completed. 2025-11-11T00:42:07.369Z,1762821727.369 [MissionManager](INFO): Uninitializing Mission marl_lab 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab] Stopped 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab](DEBUG): Aggregate::uninitialize marl_lab 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:AbortDrift] Stopped 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:AbortDrift](DEBUG): Aggregate::uninitialize marl_lab:AbortDrift 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:AbortDrift:B.AbortDrift] Stopped 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift. 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:B.] Stopped 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:B.](DEBUG): Uninitializing TrackAcousticContact. 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:BackseatDriver] Stopped 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:BackseatDriver](DEBUG): Aggregate::uninitialize marl_lab:BackseatDriver 2025-11-11T00:42:07.369Z,1762821727.369 [marl_lab:BackseatDriver:A.BackseatDriver] Stopped 2025-11-11T00:42:07.370Z,1762821727.370 [marl_lab:PowerOnly] Stopped 2025-11-11T00:42:07.370Z,1762821727.370 [marl_lab:PowerOnly](DEBUG): Aggregate::uninitialize marl_lab:PowerOnly 2025-11-11T00:42:07.370Z,1762821727.370 [marl_lab:PowerOnly:E.Wait] Stopped 2025-11-11T00:42:07.370Z,1762821727.370 [marl_lab:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-11-11T00:42:07.370Z,1762821727.370 [marl_lab:H.Wait] Stopped 2025-11-11T00:42:07.370Z,1762821727.370 [marl_lab:H.Wait](DEBUG): Uninitialize Wait Component. 2025-11-11T00:42:07.750Z,1762821727.750 [MissionManager](IMPORTANT): Started mission Default 2025-11-11T00:42:07.750Z,1762821727.750 [Default] Running Loop=1 2025-11-11T00:42:07.750Z,1762821727.750 [Default](DEBUG): Aggregate::initialize Default 2025-11-11T00:42:07.750Z,1762821727.750 [Default:B.GoToSurface] Running Loop=1 2025-11-11T00:42:07.750Z,1762821727.750 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-11-11T00:42:07.751Z,1762821727.751 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-11-11T00:42:07.751Z,1762821727.751 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-11-11T00:42:07.751Z,1762821727.751 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-11-11T00:42:07.752Z,1762821727.752 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-11-11T00:42:07.752Z,1762821727.752 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-11-11T00:42:07.752Z,1762821727.752 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-11-11T00:42:07.753Z,1762821727.753 [Default:A.Wait] Running Loop=1 2025-11-11T00:42:07.753Z,1762821727.753 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-11-11T00:42:09.302Z,1762821729.302 [BackseatComponent](INFO): Sent LCM shutdown request. 2025-11-11T00:42:09.302Z,1762821729.302 [BackseatComponent](INFO): Shutdown requested. Waiting (30.00 sec to power down.). 2025-11-11T00:42:11.501Z,1762821731.501 [DAT](INFO): DAT read: Rx Time:00:42:10.1299 2025-11-11T00:42:11.501Z,1762821731.501 [DAT](INFO): Rx dataTimestamp_ set to:1762821731.500994 2025-11-11T00:42:12.257Z,1762821732.257 [DAT](INFO): DAT read: 2025-11-11T00:42:12.257Z,1762821732.257 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:42:12.258Z,1762821732.258 [DAT](INFO): Got DATA 2 2025-11-11T00:42:12.258Z,1762821732.258 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:42:12.259Z,1762821732.259 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:42:12.259Z,1762821732.259 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:42:12.260Z,1762821732.260 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:19.7 AGC:16 SPD:+0.0 CCERR:013 2025-11-11T00:42:12.260Z,1762821732.260 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:12.260Z,1762821732.260 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:12.261Z,1762821732.261 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:42:12.261Z,1762821732.261 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:42:12.261Z,1762821732.261 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:42:12.261Z,1762821732.261 [DAT](INFO): Got ack 2025-11-11T00:42:12.261Z,1762821732.261 [DAT](INFO): DAT read: 2025-11-11T00:42:12.262Z,1762821732.262 [DAT](INFO): DAT read: 2025-11-11T00:42:12.262Z,1762821732.262 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:42:12.262Z,1762821732.262 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:42:12.509Z,1762821732.509 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:42:12.509Z,1762821732.509 [DAT](INFO): #Outgoing data=1 2025-11-11T00:42:12.509Z,1762821732.509 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:42:12.761Z,1762821732.761 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:42:16.037Z,1762821736.037 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:42:15.2215 2025-11-11T00:42:16.037Z,1762821736.037 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:42:21.057Z,1762821741.057 [Default:A.Wait](INFO): Done Waiting. 2025-11-11T00:42:21.057Z,1762821741.057 [Default:A.Wait] Stopped 2025-11-11T00:42:21.058Z,1762821741.058 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-11-11T00:42:21.462Z,1762821741.462 [Default:CheckIn] Running Loop=1 2025-11-11T00:42:21.462Z,1762821741.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-11-11T00:42:21.462Z,1762821741.462 [Default:CheckIn:Read_GPS] Running Loop=1 2025-11-11T00:42:22.341Z,1762821742.341 [DAT](INFO): DAT read: Rx Time:00:42:21.0301 2025-11-11T00:42:22.341Z,1762821742.341 [DAT](INFO): Rx dataTimestamp_ set to:1762821742.341071 2025-11-11T00:42:23.097Z,1762821743.097 [DAT](INFO): DAT read: 2025-11-11T00:42:23.097Z,1762821743.097 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:42:23.098Z,1762821743.098 [DAT](INFO): Got DATA 2 2025-11-11T00:42:23.098Z,1762821743.098 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:42:23.099Z,1762821743.099 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:42:23.099Z,1762821743.099 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:42:23.100Z,1762821743.100 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:20.1 AGC:17 SPD:+0.0 CCERR:013 2025-11-11T00:42:23.100Z,1762821743.100 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:23.100Z,1762821743.100 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:23.100Z,1762821743.100 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:42:23.101Z,1762821743.101 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:42:23.102Z,1762821743.102 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:42:23.102Z,1762821743.102 [DAT](INFO): Got ack 2025-11-11T00:42:23.103Z,1762821743.103 [DAT](INFO): DAT read: 2025-11-11T00:42:23.106Z,1762821743.106 [DAT](INFO): DAT read: 2025-11-11T00:42:23.107Z,1762821743.107 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=0, outgoingCommsBuffer_ size=0 2025-11-11T00:42:23.107Z,1762821743.107 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:42:23.349Z,1762821743.349 [DAT](INFO): modem://10: set _.others_observations string "" 2025-11-11T00:42:23.349Z,1762821743.349 [DAT](INFO): #Outgoing data=1 2025-11-11T00:42:23.349Z,1762821743.349 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-11-11T00:42:23.601Z,1762821743.601 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-11-11T00:42:25.948Z,1762821745.948 [CBIT](INFO): Clearing failed state for component DropWeight 2025-11-11T00:42:25.948Z,1762821745.948 [DropWeight] No Fault, FailCount= 1 2025-11-11T00:42:26.877Z,1762821746.877 [DAT](INFO): DAT read: Forwarding Delay UpTx time:00:42:26.0216 2025-11-11T00:42:26.877Z,1762821746.877 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2025-11-11T00:42:28.732Z,1762821748.732 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2025-11-11T00:42:28.732Z,1762821748.732 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:42:28.772Z,1762821748.772 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:42:29.177Z,1762821749.177 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:42:29.177Z,1762821749.177 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2025-11-11T00:42:33.177Z,1762821753.177 [DAT](INFO): DAT read: Rx Time:00:42:31.8302 2025-11-11T00:42:33.177Z,1762821753.177 [DAT](INFO): Rx dataTimestamp_ set to:1762821753.177110 2025-11-11T00:42:33.933Z,1762821753.933 [DAT](INFO): DAT read: 2025-11-11T00:42:33.933Z,1762821753.933 [DAT](INFO): DAT read: DATA(0002):~~ 2025-11-11T00:42:33.933Z,1762821753.933 [DAT](INFO): Got DATA 2 2025-11-11T00:42:33.934Z,1762821753.934 [DAT](INFO): DAT read: Source:010 Destination:001 2025-11-11T00:42:33.934Z,1762821753.934 [DAT](INFO): Got Src/Dest after DATA 2025-11-11T00:42:33.935Z,1762821753.935 [DAT](INFO): DATA Src=10, Dst=1 2025-11-11T00:42:33.996Z,1762821753.996 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:20.1 AGC:16 SPD:+0.0 CCERR:013 2025-11-11T00:42:33.996Z,1762821753.996 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:33.997Z,1762821753.997 [DAT](INFO): Got CRC:Pass 2025-11-11T00:42:33.997Z,1762821753.997 [DAT](INFO): Incoming data is intended for us 2025-11-11T00:42:33.997Z,1762821753.997 [DAT](DEBUG): parseResponses: Got ACK. Before transition: sendDataBuffer_ isEmpty=1, outgoingCommsBuffer_ size=0, outgoingCommsNow_=NOT NULL 2025-11-11T00:42:33.997Z,1762821753.997 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2025-11-11T00:42:33.997Z,1762821753.997 [DAT](INFO): Got ack 2025-11-11T00:42:33.998Z,1762821753.998 [DAT](INFO): DAT read: 2025-11-11T00:42:33.998Z,1762821753.998 [DAT](INFO): DAT read: 2025-11-11T00:42:33.998Z,1762821753.998 [DAT](DEBUG): sendingVerified: ACK received. sendDataBuffer_ isEmpty=1, outgoingCommsBuffer_ size=0 2025-11-11T00:42:33.999Z,1762821753.999 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-11-11T00:42:39.312Z,1762821759.312 [BackseatComponent](INFO): Powering down and starting shutdown timer (30.00 sec). 2025-11-11T00:42:39.313Z,1762821759.313 [BackseatComponent](INFO): Unsubscribing from LCM channels. 2025-11-11T00:42:39.313Z,1762821759.313 [LcmPublisher](INFO): Deactivating messaging. 2025-11-11T00:45:29.739Z,1762821929.739 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2025-11-11T00:45:29.739Z,1762821929.739 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:45:29.749Z,1762821929.749 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:45:30.137Z,1762821930.137 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:45:30.137Z,1762821930.137 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2025-11-11T00:47:21.637Z,1762822041.637 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-11T00:42:21.5Z 2025-11-11T00:47:21.638Z,1762822041.638 [Default:CheckIn:Read_GPS] Stopped 2025-11-11T00:47:21.638Z,1762822041.638 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-11-11T00:47:28.575Z,1762822048.575 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251111T002714/Courier0007.lzma 2025-11-11T00:47:29.578Z,1762822049.578 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Courier0007.lzma.bak 2025-11-11T00:47:29.578Z,1762822049.578 [DataOverHttps](INFO): SBD MOMSN=26295379 2025-11-11T00:47:45.120Z,1762822065.120 [DataOverHttps](INFO): Sending 273 bytes from file Logs/20251111T002714/Express0008.lzma 2025-11-11T00:47:46.122Z,1762822066.122 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Express0008.lzma.bak 2025-11-11T00:47:46.122Z,1762822066.122 [DataOverHttps](INFO): SBD MOMSN=26295381 2025-11-11T00:47:47.502Z,1762822067.502 [Default:CheckIn:Read_Iridium] Stopped 2025-11-11T00:47:47.502Z,1762822067.502 [Default:CheckIn:C.Wait] Running Loop=1 2025-11-11T00:47:47.502Z,1762822067.502 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-11-11T00:48:30.724Z,1762822110.724 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2025-11-11T00:48:30.724Z,1762822110.724 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:48:30.734Z,1762822110.734 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:48:31.141Z,1762822111.141 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:48:31.141Z,1762822111.141 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2025-11-11T00:48:50.101Z,1762822130.101 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-11-11T00:48:50.101Z,1762822130.101 [NAL9602] Data Fault, FailCount= 2 2025-11-11T00:48:50.101Z,1762822130.101 [NAL9602](ERROR): Data Fault 2025-11-11T00:48:50.155Z,1762822130.155 [CBIT](ERROR): Data Fault in component: NAL9602 2025-11-11T00:48:50.505Z,1762822130.505 [NAL9602](INFO): Powering down 2025-11-11T00:48:51.349Z,1762822131.349 [CBIT](INFO): Clearing failed state for component NAL9602 2025-11-11T00:48:51.349Z,1762822131.349 [NAL9602] No Fault, FailCount= 2 2025-11-11T00:49:20.805Z,1762822160.805 [NAL9602](INFO): Powering up NAL9602 2025-11-11T00:49:31.714Z,1762822171.714 [NAL9602](INFO): NAL9602 initialized 2025-11-11T00:51:31.733Z,1762822291.733 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2025-11-11T00:51:31.733Z,1762822291.733 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:51:31.744Z,1762822291.744 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:51:32.149Z,1762822292.149 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:51:32.149Z,1762822292.149 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2025-11-11T00:52:48.069Z,1762822368.069 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-11-11T00:52:48.069Z,1762822368.069 [Default:CheckIn:C.Wait] Stopped 2025-11-11T00:52:48.069Z,1762822368.069 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-11-11T00:52:48.070Z,1762822368.070 [Default:CheckIn:D] Running Loop=1 2025-11-11T00:52:48.474Z,1762822368.474 [Default:CheckIn:D] Stopped 2025-11-11T00:52:48.474Z,1762822368.474 [Default:CheckIn:E] Running Loop=1 2025-11-11T00:52:48.878Z,1762822368.878 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.678728 min 2025-11-11T00:52:48.878Z,1762822368.878 [Default:CheckIn:E] Stopped 2025-11-11T00:52:48.878Z,1762822368.878 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-11-11T00:52:48.879Z,1762822368.879 [Default:CheckIn] Stopped 2025-11-11T00:52:48.879Z,1762822368.879 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-11-11T00:52:48.879Z,1762822368.879 [Default:CheckIn](INFO): Running loop #2 2025-11-11T00:52:48.879Z,1762822368.879 [Default:CheckIn] Running Loop=2 2025-11-11T00:52:48.879Z,1762822368.879 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-11-11T00:52:48.879Z,1762822368.879 [Default:CheckIn:Read_GPS] Running Loop=1 2025-11-11T00:54:32.728Z,1762822472.728 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2025-11-11T00:54:32.728Z,1762822472.728 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:54:32.739Z,1762822472.739 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:54:33.147Z,1762822473.147 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:54:33.147Z,1762822473.147 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2025-11-11T00:57:33.694Z,1762822653.694 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2025-11-11T00:57:33.694Z,1762822653.694 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T00:57:33.704Z,1762822653.704 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T00:57:34.130Z,1762822654.130 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T00:57:34.130Z,1762822654.130 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2025-11-11T00:57:49.067Z,1762822669.067 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-11T00:52:48.9Z 2025-11-11T00:57:49.067Z,1762822669.067 [Default:CheckIn:Read_GPS] Stopped 2025-11-11T00:57:49.067Z,1762822669.067 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-11-11T00:57:56.455Z,1762822676.455 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20251111T002714/Courier0010.lzma 2025-11-11T00:57:57.458Z,1762822677.458 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Courier0010.lzma.bak 2025-11-11T00:57:57.458Z,1762822677.458 [DataOverHttps](INFO): SBD MOMSN=26295428 2025-11-11T00:58:13.043Z,1762822693.043 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20251111T002714/Express0011.lzma 2025-11-11T00:58:14.046Z,1762822694.046 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Express0011.lzma.bak 2025-11-11T00:58:14.046Z,1762822694.046 [DataOverHttps](INFO): SBD MOMSN=26295430 2025-11-11T00:58:15.313Z,1762822695.313 [Default:CheckIn:Read_Iridium] Stopped 2025-11-11T00:58:15.313Z,1762822695.313 [Default:CheckIn:C.Wait] Running Loop=1 2025-11-11T00:58:15.313Z,1762822695.313 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-11-11T00:59:32.866Z,1762822772.866 [NAL9602](FAULT): GPS failed to acquire within timeout. 2025-11-11T00:59:32.866Z,1762822772.866 [NAL9602] Data Fault, FailCount= 3 2025-11-11T00:59:32.866Z,1762822772.866 [NAL9602](ERROR): Data Fault 2025-11-11T00:59:32.883Z,1762822772.883 [CBIT](ERROR): Data Fault in component: NAL9602 2025-11-11T00:59:33.275Z,1762822773.275 [NAL9602](INFO): Powering down 2025-11-11T00:59:34.098Z,1762822774.098 [CBIT](INFO): Clearing failed state for component NAL9602 2025-11-11T00:59:34.098Z,1762822774.098 [NAL9602] No Fault, FailCount= 3 2025-11-11T01:00:03.579Z,1762822803.579 [NAL9602](INFO): Powering up NAL9602 2025-11-11T01:00:14.481Z,1762822814.481 [NAL9602](INFO): NAL9602 initialized 2025-11-11T01:00:34.682Z,1762822834.682 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2025-11-11T01:00:34.682Z,1762822834.682 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T01:00:34.709Z,1762822834.709 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T01:00:35.116Z,1762822835.116 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T01:00:35.116Z,1762822835.116 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2025-11-11T01:03:15.913Z,1762822995.913 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-11-11T01:03:15.913Z,1762822995.913 [Default:CheckIn:C.Wait] Stopped 2025-11-11T01:03:15.913Z,1762822995.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-11-11T01:03:15.913Z,1762822995.913 [Default:CheckIn:D] Running Loop=1 2025-11-11T01:03:16.306Z,1762822996.306 [Default:CheckIn:D] Stopped 2025-11-11T01:03:16.306Z,1762822996.306 [Default:CheckIn:E] Running Loop=1 2025-11-11T01:03:16.691Z,1762822996.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.142596 min 2025-11-11T01:03:16.691Z,1762822996.691 [Default:CheckIn:E] Stopped 2025-11-11T01:03:16.691Z,1762822996.691 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-11-11T01:03:16.691Z,1762822996.691 [Default:CheckIn] Stopped 2025-11-11T01:03:16.691Z,1762822996.691 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-11-11T01:03:16.692Z,1762822996.692 [Default:CheckIn](INFO): Running loop #3 2025-11-11T01:03:16.692Z,1762822996.692 [Default:CheckIn] Running Loop=3 2025-11-11T01:03:16.692Z,1762822996.692 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-11-11T01:03:16.692Z,1762822996.692 [Default:CheckIn:Read_GPS] Running Loop=1 2025-11-11T01:03:35.681Z,1762823015.681 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2025-11-11T01:03:35.681Z,1762823015.681 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T01:03:35.691Z,1762823015.691 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T01:03:36.097Z,1762823016.097 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T01:03:36.097Z,1762823016.097 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2025-11-11T01:06:36.681Z,1762823196.681 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2025-11-11T01:06:36.681Z,1762823196.681 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T01:06:36.692Z,1762823196.692 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T01:06:37.101Z,1762823197.101 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T01:06:37.101Z,1762823197.101 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2025-11-11T01:08:16.866Z,1762823296.866 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-11-11T01:03:16.7Z 2025-11-11T01:08:16.866Z,1762823296.866 [Default:CheckIn:Read_GPS] Stopped 2025-11-11T01:08:16.867Z,1762823296.867 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-11-11T01:08:23.967Z,1762823303.967 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20251111T002714/Courier0013.lzma 2025-11-11T01:08:24.970Z,1762823304.970 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Courier0013.lzma.bak 2025-11-11T01:08:24.970Z,1762823304.970 [DataOverHttps](INFO): SBD MOMSN=26295440 2025-11-11T01:08:40.515Z,1762823320.515 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20251111T002714/Express0014.lzma 2025-11-11T01:08:41.519Z,1762823321.519 [DataOverHttps](INFO): Moved sent file to Logs/20251111T002714/Express0014.lzma.bak 2025-11-11T01:08:41.519Z,1762823321.519 [DataOverHttps](INFO): SBD MOMSN=26295442 2025-11-11T01:08:42.731Z,1762823322.731 [Default:CheckIn:Read_Iridium] Stopped 2025-11-11T01:08:42.731Z,1762823322.731 [Default:CheckIn:C.Wait] Running Loop=1 2025-11-11T01:08:42.732Z,1762823322.732 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-11-11T01:09:37.664Z,1762823377.664 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2025-11-11T01:09:37.664Z,1762823377.664 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-11-11T01:09:37.675Z,1762823377.675 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-11-11T01:09:38.080Z,1762823378.080 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-11-11T01:09:38.080Z,1762823378.080 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2025-11-11T01:09:46.907Z,1762823386.907 [CommandExec](IMPORTANT): got command load ./Missions/marl_lab.tl 2025-11-11T01:09:46.908Z,1762823386.908 [MissionManager](INFO): Loading Mission from file: ./Missions/marl_lab.tl 2025-11-11T01:09:46.908Z,1762823386.908 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/marl_lab.tl 2025-11-11T01:09:46.909Z,1762823386.909 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/marl_lab.tl 2025-11-11T01:09:47.925Z,1762823387.925 [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-11T01:09:47.934Z,1762823387.934 [MissionManager](INFO): DefineArg marl_lab.MissionTimeout = 1.000000 h 2025-11-11T01:09:47.940Z,1762823387.940 [MissionManager](INFO): DefineArg marl_lab.ContactLabel = 8.000000 count 2025-11-11T01:09:47.942Z,1762823387.942 [MissionManager](INFO): DefineArg marl_lab.SendDataLabel = 10.000000 count 2025-11-11T01:09:47.949Z,1762823387.949 [MissionManager](INFO): DefineArg marl_lab.ContactDepth = nan m 2025-11-11T01:09:47.951Z,1762823387.951 [MissionManager](INFO): DefineArg marl_lab.SendObservationDataInterval = 20.000000 s 2025-11-11T01:09:48.001Z,1762823388.001 [MissionManager](INFO): DefineArg marl_lab.TrackingUpdatePeriod = 10.000000 min 2025-11-11T01:09:48.003Z,1762823388.003 [MissionManager](INFO): DefineArg marl_lab.NumberOfPings = 1.000000 count 2025-11-11T01:09:48.018Z,1762823388.018 [MissionManager](INFO): DefineArg marl_lab.AcousticContactTimeout = 1.000000 h 2025-11-11T01:09:48.029Z,1762823388.029 [MissionManager](INFO): DefineArg marl_lab.MyTempVar = NaN 2025-11-11T01:09:48.056Z,1762823388.056 [MissionManager](INFO): DefineOutput marl_lab.TimeLastSendData = 0.000000 s 2025-11-11T01:09:48.058Z,1762823388.058 [MissionManager](INFO): DefineOutput marl_lab.ElapsedSinceLastSendData = 0.000000 s 2025-11-11T01:09:48.059Z,1762823388.059 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.tl 2025-11-11T01:09:48.059Z,1762823388.059 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/AbortDrift.tl 2025-11-11T01:09:48.072Z,1762823388.072 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/AbortDrift.tl 2025-11-11T01:09:48.241Z,1762823388.241 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/AbortDrift.tl translated into: 96 Insert acoustic timeout set to . stop 2025-11-11T01:09:48.248Z,1762823388.248 [MissionManager](INFO): DefineArg marl_lab:AbortDrift.AcousticTimeout = 96.000000 h 2025-11-11T01:09:48.250Z,1762823388.250 [marl_lab:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift. 2025-11-11T01:09:48.256Z,1762823388.256 [marl_lab:AbortDrift:C.Execute](DEBUG): Construct Execute. 2025-11-11T01:09:48.258Z,1762823388.258 [MissionManager](INFO): RedefineArg marl_lab:AbortDrift.AcousticTimeout = reader:marl_lab.AcousticContactTimeout 2025-11-11T01:09:48.363Z,1762823388.363 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-11-11T01:09:48.363Z,1762823388.363 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-11-11T01:09:48.368Z,1762823388.368 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-11-11T01:09:48.417Z,1762823388.417 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-11-11T01:09:48.419Z,1762823388.419 [MissionManager](INFO): DefineArg marl_lab:BackseatDriver.EnableBackseat = 0 bool 2025-11-11T01:09:48.426Z,1762823388.426 [marl_lab:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-11-11T01:09:48.453Z,1762823388.453 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-11-11T01:09:48.454Z,1762823388.454 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-11-11T01:09:48.455Z,1762823388.455 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-11-11T01:09:48.708Z,1762823388.708 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-11-11T01:09:48.711Z,1762823388.711 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleAll = 0 bool 2025-11-11T01:09:48.717Z,1762823388.717 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad1 = 0 bool 2025-11-11T01:09:48.719Z,1762823388.719 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad2 = 0 bool 2025-11-11T01:09:48.725Z,1762823388.725 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.SampleLoad3 = 0 bool 2025-11-11T01:09:48.727Z,1762823388.727 [MissionManager](INFO): DefineArg marl_lab:PowerOnly.EnabledPowerOnly = 0 bool 2025-11-11T01:09:48.818Z,1762823388.818 [marl_lab:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-11-11T01:09:48.819Z,1762823388.819 [marl_lab:H.Wait](DEBUG): Construct Wait. 2025-11-11T01:09:48.842Z,1762823388.842 [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 while ( 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-11T01:09:48.843Z,1762823388.843 [CommandExec](IMPORTANT): Loaded ./Missions/marl_lab.tl id=marl_lab