2024-05-24T20:47:40.760Z,1716583660.760 [Supervisor](DEBUG): Initializing supervisor. 2024-05-24T20:47:40.765Z,1716583660.765 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-05-24T20:47:40.766Z,1716583660.766 [SyncHandler](INFO): Protected caller Thread ID is 3290 2024-05-24T20:47:40.766Z,1716583660.766 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-05-24T20:47:40.767Z,1716583660.767 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-05-24T20:47:40.768Z,1716583660.768 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3291 2024-05-24T20:47:40.772Z,1716583660.772 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-05-24T20:47:40.789Z,1716583660.789 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-05-24T20:47:40.790Z,1716583660.790 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-05-24T20:47:40.790Z,1716583660.790 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3292 2024-05-24T20:47:40.794Z,1716583660.794 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-05-24T20:47:40.795Z,1716583660.795 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-05-24T20:47:40.796Z,1716583660.796 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3293 2024-05-24T20:47:40.798Z,1716583660.798 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-05-24T20:47:40.799Z,1716583660.799 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-05-24T20:47:40.799Z,1716583660.799 [logger ThreadHandler](INFO): Protected caller Thread ID is 3294 2024-05-24T20:47:40.803Z,1716583660.803 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-05-24T20:47:40.803Z,1716583660.803 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-05-24T20:47:40.805Z,1716583660.805 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-05-24T20:47:40.913Z,1716583660.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-05-24T20:47:40.914Z,1716583660.914 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-05-24T20:47:41.689Z,1716583661.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-05-24T20:47:41.689Z,1716583661.689 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-05-24T20:47:41.935Z,1716583661.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-05-24T20:47:41.936Z,1716583661.936 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-05-24T20:47:42.026Z,1716583662.026 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-05-24T20:47:42.170Z,1716583662.170 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-05-24T20:47:42.170Z,1716583662.170 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-05-24T20:47:42.263Z,1716583662.263 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-05-24T20:47:42.384Z,1716583662.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-05-24T20:47:42.385Z,1716583662.385 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-05-24T20:47:42.794Z,1716583662.794 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-05-24T20:47:42.795Z,1716583662.795 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-05-24T20:47:43.347Z,1716583663.347 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-05-24T20:47:43.348Z,1716583663.348 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-05-24T20:47:43.582Z,1716583663.582 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-05-24T20:47:43.582Z,1716583663.582 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-05-24T20:47:43.783Z,1716583663.783 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-05-24T20:47:43.784Z,1716583663.784 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-05-24T20:47:44.336Z,1716583664.336 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-05-24T20:47:44.337Z,1716583664.337 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-05-24T20:47:44.642Z,1716583664.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-05-24T20:47:44.643Z,1716583664.643 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-05-24T20:47:44.888Z,1716583664.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-05-24T20:47:44.888Z,1716583664.888 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-05-24T20:47:45.286Z,1716583665.286 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-05-24T20:47:45.287Z,1716583665.287 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-05-24T20:47:46.186Z,1716583666.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-05-24T20:47:46.188Z,1716583666.188 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2024-05-24T20:47:46.189Z,1716583666.189 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2024-05-24T20:47:46.286Z,1716583666.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2024-05-24T20:47:46.463Z,1716583666.463 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/workSite.cfg 2024-05-24T20:47:46.571Z,1716583666.571 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2024-05-24T20:47:46.691Z,1716583666.691 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2024-05-24T20:47:46.790Z,1716583666.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2024-05-24T20:47:46.899Z,1716583666.899 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2024-05-24T20:47:47.024Z,1716583667.024 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2024-05-24T20:47:47.298Z,1716583667.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-05-24T20:47:47.298Z,1716583667.298 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2024-05-24T20:47:47.406Z,1716583667.406 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2024-05-24T20:47:47.511Z,1716583667.511 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2024-05-24T20:47:47.666Z,1716583667.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2024-05-24T20:47:47.779Z,1716583667.779 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2024-05-24T20:47:47.779Z,1716583667.779 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2024-05-24T20:47:47.789Z,1716583667.789 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-05-24T20:47:47.897Z,1716583667.897 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-05-24T20:47:47.898Z,1716583667.898 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-05-24T20:47:47.949Z,1716583667.949 [VerticalControl](DEBUG): Construct VerticalControl. 2024-05-24T20:47:48.007Z,1716583668.007 [VerticalControl] Loaded 2024-05-24T20:47:48.007Z,1716583668.007 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-05-24T20:47:48.010Z,1716583668.010 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-05-24T20:47:48.057Z,1716583668.057 [HorizontalControl] Loaded 2024-05-24T20:47:48.057Z,1716583668.057 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-05-24T20:47:48.059Z,1716583668.059 [SpeedControl](DEBUG): Construct SpeedControl. 2024-05-24T20:47:48.062Z,1716583668.062 [SpeedControl] Loaded 2024-05-24T20:47:48.062Z,1716583668.062 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-05-24T20:47:48.065Z,1716583668.065 [LoopControl](DEBUG): Construct LoopControl. 2024-05-24T20:47:48.065Z,1716583668.065 [LoopControl] Loaded 2024-05-24T20:47:48.066Z,1716583668.066 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-05-24T20:47:48.066Z,1716583668.066 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-05-24T20:47:48.067Z,1716583668.067 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-05-24T20:47:48.115Z,1716583668.115 [DepthRateCalculator] Loaded 2024-05-24T20:47:48.115Z,1716583668.115 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-05-24T20:47:48.120Z,1716583668.120 [PitchRateCalculator] Loaded 2024-05-24T20:47:48.120Z,1716583668.120 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-05-24T20:47:48.130Z,1716583668.130 [SpeedCalculator] Loaded 2024-05-24T20:47:48.130Z,1716583668.130 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-05-24T20:47:48.134Z,1716583668.134 [YawRateCalculator] Loaded 2024-05-24T20:47:48.135Z,1716583668.135 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-05-24T20:47:48.152Z,1716583668.152 [ElevatorOffsetCalculator] Loaded 2024-05-24T20:47:48.153Z,1716583668.153 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-05-24T20:47:48.153Z,1716583668.153 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-05-24T20:47:48.154Z,1716583668.154 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-05-24T20:47:48.179Z,1716583668.179 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-05-24T20:47:48.180Z,1716583668.180 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-05-24T20:47:48.234Z,1716583668.234 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-05-24T20:47:48.234Z,1716583668.234 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-05-24T20:47:48.557Z,1716583668.557 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-05-24T20:47:48.558Z,1716583668.558 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-05-24T20:47:48.723Z,1716583668.723 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-05-24T20:47:48.724Z,1716583668.724 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-05-24T20:47:49.166Z,1716583669.166 [AHRS_M2] Loaded 2024-05-24T20:47:49.166Z,1716583669.166 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-05-24T20:47:49.205Z,1716583669.205 [BackseatComponent] Loaded 2024-05-24T20:47:49.205Z,1716583669.205 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2024-05-24T20:47:49.206Z,1716583669.206 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409C34E0 2024-05-24T20:47:49.206Z,1716583669.206 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 3379 2024-05-24T20:47:49.209Z,1716583669.209 [LcmUniversalReporter] Loaded 2024-05-24T20:47:49.209Z,1716583669.209 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2024-05-24T20:47:50.018Z,1716583670.018 [BPC1] Loaded 2024-05-24T20:47:50.018Z,1716583670.018 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-05-24T20:47:50.091Z,1716583670.091 [DataOverHttps] Loaded 2024-05-24T20:47:50.092Z,1716583670.092 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-05-24T20:47:50.093Z,1716583670.093 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409F34E0 2024-05-24T20:47:50.093Z,1716583670.093 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3380 2024-05-24T20:47:50.116Z,1716583670.116 [Depth_Keller] Loaded 2024-05-24T20:47:50.116Z,1716583670.116 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-05-24T20:47:50.121Z,1716583670.121 [DropWeight] Loaded 2024-05-24T20:47:50.121Z,1716583670.121 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-05-24T20:47:50.184Z,1716583670.184 [NAL9602] Loaded 2024-05-24T20:47:50.184Z,1716583670.184 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-05-24T20:47:50.214Z,1716583670.214 [Onboard] Loaded 2024-05-24T20:47:50.214Z,1716583670.214 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-05-24T20:47:50.215Z,1716583670.215 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A234E0 2024-05-24T20:47:50.215Z,1716583670.215 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3381 2024-05-24T20:47:50.229Z,1716583670.229 [Power24vConverter] Loaded 2024-05-24T20:47:50.229Z,1716583670.229 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-05-24T20:47:50.244Z,1716583670.244 [Radio_Surface] Loaded 2024-05-24T20:47:50.245Z,1716583670.245 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-05-24T20:47:50.245Z,1716583670.245 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A534E0 2024-05-24T20:47:50.246Z,1716583670.246 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3382 2024-05-24T20:47:50.292Z,1716583670.292 [RDI_Pathfinder] Loaded 2024-05-24T20:47:50.292Z,1716583670.292 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2024-05-24T20:47:50.386Z,1716583670.386 [DAT] Loaded 2024-05-24T20:47:50.386Z,1716583670.386 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-05-24T20:47:50.387Z,1716583670.387 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A834E0 2024-05-24T20:47:50.387Z,1716583670.387 [DAT ThreadHandler](INFO): Protected caller Thread ID is 3383 2024-05-24T20:47:50.388Z,1716583670.388 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-05-24T20:47:50.389Z,1716583670.389 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-05-24T20:47:50.838Z,1716583670.838 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-05-24T20:47:50.838Z,1716583670.838 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-05-24T20:47:50.852Z,1716583670.852 [NavChart] Loaded 2024-05-24T20:47:50.852Z,1716583670.852 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-05-24T20:47:50.858Z,1716583670.858 [UniversalFixResidualReporter] Loaded 2024-05-24T20:47:50.858Z,1716583670.858 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-05-24T20:47:50.859Z,1716583670.859 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-05-24T20:47:50.859Z,1716583670.859 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-05-24T20:47:51.139Z,1716583671.139 [SBIT](DEBUG): Construct Startup Built In Test. 2024-05-24T20:47:51.148Z,1716583671.148 [SBIT] Loaded 2024-05-24T20:47:51.148Z,1716583671.148 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-05-24T20:47:51.151Z,1716583671.151 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-05-24T20:47:51.164Z,1716583671.164 [IBIT] Loaded 2024-05-24T20:47:51.164Z,1716583671.164 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-05-24T20:47:51.170Z,1716583671.170 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-05-24T20:47:51.273Z,1716583671.273 [CBIT] Loaded 2024-05-24T20:47:51.273Z,1716583671.273 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-05-24T20:47:51.274Z,1716583671.274 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-05-24T20:47:51.274Z,1716583671.274 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-05-24T20:47:51.408Z,1716583671.408 [BuoyancyServo] Loaded 2024-05-24T20:47:51.408Z,1716583671.408 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-05-24T20:47:51.431Z,1716583671.431 [ElevatorServo] Loaded 2024-05-24T20:47:51.431Z,1716583671.431 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-05-24T20:47:51.461Z,1716583671.461 [DockingStepper] Loaded 2024-05-24T20:47:51.461Z,1716583671.461 [ComponentRegistry](DEBUG): SyncComponent "DockingStepper" handled in the control thread. 2024-05-24T20:47:51.482Z,1716583671.482 [MassServo] Loaded 2024-05-24T20:47:51.482Z,1716583671.482 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-05-24T20:47:51.502Z,1716583671.502 [RudderServo] Loaded 2024-05-24T20:47:51.503Z,1716583671.503 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-05-24T20:47:51.521Z,1716583671.521 [ThrusterServo] Loaded 2024-05-24T20:47:51.521Z,1716583671.521 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2024-05-24T20:47:51.522Z,1716583671.522 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-05-24T20:47:51.522Z,1716583671.522 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-05-24T20:47:51.532Z,1716583671.532 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-05-24T20:47:51.533Z,1716583671.533 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-05-24T20:47:51.707Z,1716583671.707 [CTD_Seabird] Loaded 2024-05-24T20:47:51.707Z,1716583671.707 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-05-24T20:47:51.708Z,1716583671.708 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BD74E0 2024-05-24T20:47:51.709Z,1716583671.709 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3384 2024-05-24T20:47:51.731Z,1716583671.731 [PAR_Licor] Loaded 2024-05-24T20:47:51.731Z,1716583671.731 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-05-24T20:47:51.774Z,1716583671.774 [WetLabsBB2FL] Loaded 2024-05-24T20:47:51.775Z,1716583671.775 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-05-24T20:47:51.776Z,1716583671.776 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C074E0 2024-05-24T20:47:51.776Z,1716583671.776 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3385 2024-05-24T20:47:51.797Z,1716583671.797 [WetLabsUBAT] Loaded 2024-05-24T20:47:51.797Z,1716583671.797 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2024-05-24T20:47:51.798Z,1716583671.798 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40C374E0 2024-05-24T20:47:51.798Z,1716583671.798 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 3386 2024-05-24T20:47:51.799Z,1716583671.799 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-05-24T20:47:51.805Z,1716583671.805 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-05-24T20:47:51.808Z,1716583671.808 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-05-24T20:47:51.819Z,1716583671.819 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-05-24T20:47:51.820Z,1716583671.820 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C674E0 2024-05-24T20:47:51.821Z,1716583671.821 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3387 2024-05-24T20:47:51.825Z,1716583671.825 [Supervisor](INFO): Main Thread ID is 2822 2024-05-24T20:47:51.825Z,1716583671.825 [Supervisor](DEBUG): Running supervisor. 2024-05-24T20:47:51.826Z,1716583671.826 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3388 2024-05-24T20:47:51.826Z,1716583671.826 [CommandExec](INFO): Initializing the command executive. 2024-05-24T20:47:51.828Z,1716583671.828 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3389 2024-05-24T20:47:51.830Z,1716583671.830 [controlThread ThreadHandler](INFO): Handler Thread ID is 3390 2024-05-24T20:47:51.830Z,1716583671.830 [controlThread](DEBUG): Initializing ControlThread 2024-05-24T20:47:51.831Z,1716583671.831 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-05-24T20:47:51.833Z,1716583671.833 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-05-24T20:47:51.834Z,1716583671.834 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-05-24T20:47:51.834Z,1716583671.834 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-05-24T20:47:51.834Z,1716583671.834 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-05-24T20:47:51.835Z,1716583671.835 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-05-24T20:47:51.835Z,1716583671.835 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-05-24T20:47:51.835Z,1716583671.835 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-05-24T20:47:51.836Z,1716583671.836 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-05-24T20:47:51.843Z,1716583671.843 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-05-24T20:47:51.843Z,1716583671.843 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-05-24T20:47:51.843Z,1716583671.843 [SBIT](INFO): Initialize SBIT Component. 2024-05-24T20:47:51.844Z,1716583671.844 [SBIT](IMPORTANT): git: 2024-05-22-2-gd2983461b 2024-05-24T20:47:51.844Z,1716583671.844 [SBIT](INFO): git hash: d2983461b0afca1bb4c5ae8a9b5bc51c90c2e86f 2024-05-24T20:47:51.844Z,1716583671.844 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-05-24T20:47:51.845Z,1716583671.845 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2024-05-24T20:47:51.846Z,1716583671.846 [SBIT](INFO): Beginning SBIT in 139.000000 seconds. 2024-05-24T20:47:51.847Z,1716583671.847 [IBIT](INFO): Initialize IBIT Component. 2024-05-24T20:47:51.848Z,1716583671.848 [CBIT](DEBUG): Initialize CBIT Component. 2024-05-24T20:47:51.849Z,1716583671.849 [logger ThreadHandler](INFO): Handler Thread ID is 3391 2024-05-24T20:47:51.860Z,1716583671.860 [CBIT](DEBUG): Initialized mux pins. 2024-05-24T20:47:51.860Z,1716583671.860 [CBIT](DEBUG): Initializing the watchdog timer. 2024-05-24T20:47:51.869Z,1716583671.869 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 3392 2024-05-24T20:47:51.881Z,1716583671.881 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3393 2024-05-24T20:47:51.882Z,1716583671.882 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-05-24T20:47:51.884Z,1716583671.884 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-05-24T20:47:51.885Z,1716583671.885 [CBIT](DEBUG): Initializing heartbeat. 2024-05-24T20:47:51.893Z,1716583671.893 [Onboard ThreadHandler](INFO): Handler Thread ID is 3394 2024-05-24T20:47:51.909Z,1716583671.909 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3395 2024-05-24T20:47:51.929Z,1716583671.929 [DAT ThreadHandler](INFO): Handler Thread ID is 3396 2024-05-24T20:47:51.930Z,1716583671.930 [DAT](INFO): Powering up 2024-05-24T20:47:51.930Z,1716583671.930 [DAT](DEBUG): Initializing DAT. 2024-05-24T20:47:51.934Z,1716583671.934 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3398 2024-05-24T20:47:51.934Z,1716583671.934 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-05-24T20:47:51.937Z,1716583671.937 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3400 2024-05-24T20:47:51.941Z,1716583671.941 [WetLabsBB2FL](INFO): Powering up 2024-05-24T20:47:51.942Z,1716583671.942 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 3402 2024-05-24T20:47:51.945Z,1716583671.945 [WetLabsUBAT](INFO): Powering up 2024-05-24T20:47:51.946Z,1716583671.946 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3404 2024-05-24T20:47:51.949Z,1716583671.949 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-05-24T20:47:51.950Z,1716583671.950 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-05-24T20:47:51.950Z,1716583671.950 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-05-24T20:47:51.950Z,1716583671.950 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-05-24T20:47:51.950Z,1716583671.950 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-05-24T20:47:51.950Z,1716583671.950 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-05-24T20:47:51.950Z,1716583671.950 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-05-24T20:47:51.950Z,1716583671.950 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-05-24T20:47:51.957Z,1716583671.957 [CBIT](DEBUG): Deactivating GF circuits. 2024-05-24T20:47:51.957Z,1716583671.957 [CBIT](DEBUG): Deactivating emergency mode. 2024-05-24T20:47:51.996Z,1716583671.996 [CBIT](DEBUG): Backplane powered. 2024-05-24T20:47:52.001Z,1716583672.001 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-05-24T20:47:52.002Z,1716583672.002 [MissionManager](INFO): Loading Mission from file: Missions/underIce/StartupUnder.tl 2024-05-24T20:47:52.002Z,1716583672.002 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/StartupUnder.tl 2024-05-24T20:47:52.003Z,1716583672.003 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/StartupUnder.tl 2024-05-24T20:47:52.016Z,1716583672.016 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/StartupUnder.tl translated into: 2024-05-24T20:47:52.016Z,1716583672.016 [MissionManager](ERROR): Top node has no child nodes: Mission 2024-05-24T20:47:52.017Z,1716583672.017 [MissionManager](ERROR): Could not load startup mission. 2024-05-24T20:47:52.017Z,1716583672.017 [MissionManager](INFO): Loading Mission from file: Missions/underIce/DefaultWithUndock.tl 2024-05-24T20:47:52.017Z,1716583672.017 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/DefaultWithUndock.tl 2024-05-24T20:47:52.018Z,1716583672.018 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/DefaultWithUndock.tl 2024-05-24T20:47:52.316Z,1716583672.316 [Radio_Surface](INFO): Powering up 2024-05-24T20:47:52.546Z,1716583672.546 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/DefaultWithUndock.tl translated into: 0 30 2.5 1 30 Timed out while trying to detach from dock at current depth of . Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2024-05-24T20:47:52.565Z,1716583672.565 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min 2024-05-24T20:47:52.569Z,1716583672.569 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min 2024-05-24T20:47:52.601Z,1716583672.601 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 201 count 2024-05-24T20:47:52.605Z,1716583672.605 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s 2024-05-24T20:47:52.609Z,1716583672.609 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count 2024-05-24T20:47:52.610Z,1716583672.610 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait. 2024-05-24T20:47:52.752Z,1716583672.752 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct. 2024-05-24T20:47:52.752Z,1716583672.752 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2024-05-24T20:47:52.816Z,1716583672.816 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-05-24T20:47:52.849Z,1716583672.849 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-05-24T20:47:52.851Z,1716583672.851 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-05-24T20:47:52.870Z,1716583672.870 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute. 2024-05-24T20:47:52.886Z,1716583672.886 [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 DefaultWithUndock { arguments { ElapsedSinceDefaultStarted = 0 minute DetachTimeout = 30 minute """ Maximum time duration for the vehicle to detach form the dock. """ TransponderCode = Dock:Dock.transponderCode """ Dock transponder address. """ TrackingUpdatePeriod = 2.5 second """ Time duration between acoustic range queries while the mission is detaching from the dock. """ NumberOfPings = 1 count """ Number of pings requested each time. """ } 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 = 30 second } aggregate LeaveDock { run in sequence timeout duration=DetachTimeout { syslog important "Timed out while trying to detach from dock at current depth of " + Universal:depth~meter + "." } # Acoustic tracking directives behavior Estimation:TrackAcousticContact { run in parallel set contactLabelSetting = TransponderCode set numberOfSamplesSetting = NumberOfPings set updatePeriodSetting = TrackingUpdatePeriod } # Leave the dock behavior Dock:Undock { run in sequence } } aggregate SurfaceDefault { run in sequence # This mission assumes open water so from here on it's the same old default that's always used 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=P2H { 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" } } 2024-05-24T20:47:52.892Z,1716583672.892 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,DockingStepper,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-05-24T20:47:52.912Z,1716583672.912 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-05-24T20:47:52.978Z,1716583672.978 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993022 m 2024-05-24T20:47:52.979Z,1716583672.979 [Power24vConverter](INFO): Powering up. 2024-05-24T20:47:52.980Z,1716583672.980 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2024-05-24T20:47:53.010Z,1716583673.010 [DepthRateCalculator](ERROR): Depth measurement is not active 2024-05-24T20:47:53.049Z,1716583673.049 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-05-24T20:47:53.056Z,1716583673.056 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-05-24T20:47:53.058Z,1716583673.058 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-05-24T20:47:53.065Z,1716583673.065 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-05-24T20:47:53.065Z,1716583673.065 [DockingStepper](INFO): Start 2024-05-24T20:47:53.066Z,1716583673.066 [DockingStepper](DEBUG): Initializing EZServoServo. 2024-05-24T20:47:53.073Z,1716583673.073 [DockingStepper](DEBUG): Initializing DockingStepper. 2024-05-24T20:47:53.074Z,1716583673.074 [MassServo](DEBUG): Initializing EZServoServo. 2024-05-24T20:47:53.080Z,1716583673.080 [MassServo](DEBUG): Initializing MassServo. 2024-05-24T20:47:53.081Z,1716583673.081 [RudderServo](DEBUG): Initializing EZServoServo. 2024-05-24T20:47:53.089Z,1716583673.089 [RudderServo](DEBUG): Initializing RudderServo. 2024-05-24T20:47:53.089Z,1716583673.089 [ThrusterServo](DEBUG): Initializing EZServoServo. 2024-05-24T20:47:53.096Z,1716583673.096 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2024-05-24T20:47:53.373Z,1716583673.373 [DockingStepper](INFO): Starting 2024-05-24T20:47:53.724Z,1716583673.724 [DockingStepper](INFO): Starting 2024-05-24T20:47:54.248Z,1716583674.248 [DockingStepper](INFO): Starting 2024-05-24T20:47:54.297Z,1716583674.297 [DockingStepper](INFO): Init string: /1z16368aE13561N3m50 2024-05-24T20:47:54.548Z,1716583674.548 [WetLabsBB2FL](INFO): Powering down 2024-05-24T20:47:54.550Z,1716583674.550 [DockingStepper](INFO): Starting 2024-05-24T20:47:54.949Z,1716583674.949 [DockingStepper](INFO): Starting 2024-05-24T20:47:55.340Z,1716583675.340 [DockingStepper](INFO): Starting 2024-05-24T20:47:55.793Z,1716583675.793 [DockingStepper](INFO): Starting 2024-05-24T20:47:55.817Z,1716583675.817 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2024-05-24T20:47:56.246Z,1716583676.246 [DockingStepper](INFO): Starting 2024-05-24T20:47:56.676Z,1716583676.676 [DockingStepper](INFO): Commanding negative:9032 2024-05-24T20:47:57.982Z,1716583677.982 [DockingStepper](INFO): Pause 2024-05-24T20:48:01.208Z,1716583681.208 [WetLabsUBAT](INFO): Powering down 2024-05-24T20:48:04.534Z,1716583684.534 [DAT](INFO): DAT read: 2024-05-24T20:48:04.540Z,1716583684.540 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-05-24T20:48:06.297Z,1716583686.297 [DAT](INFO): DAT read: MF Frequency Band 2024-05-24T20:48:06.298Z,1716583686.298 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.17.2 2024-05-24T20:48:06.299Z,1716583686.299 [DAT](INFO): DAT read: May 24 2024 20:48:00 2024-05-24T20:48:07.305Z,1716583687.305 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-05-24T20:48:07.306Z,1716583687.306 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2024-05-24T20:48:07.307Z,1716583687.307 [DAT](INFO): commRate: 800 2024-05-24T20:48:09.373Z,1716583689.373 [DAT](INFO): entering command mode 2024-05-24T20:48:09.573Z,1716583689.573 [DAT](INFO): DAT read: 2024-05-24T20:48:09.573Z,1716583689.573 [DAT](INFO): DAT read: user:1> 2024-05-24T20:48:09.574Z,1716583689.574 [DAT](INFO): setting verbose to 3 2024-05-24T20:48:09.825Z,1716583689.825 [DAT](INFO): DAT read: user:1> 2024-05-24T20:48:09.826Z,1716583689.826 [DAT](INFO): DAT read: Verbose | 3 2024-05-24T20:48:09.826Z,1716583689.826 [DAT](INFO): set verbose to 3 2024-05-24T20:48:09.826Z,1716583689.826 [DAT](INFO): setting DatVerbose to 27440 2024-05-24T20:48:10.077Z,1716583690.077 [DAT](INFO): DAT read: user:2> 2024-05-24T20:48:10.078Z,1716583690.078 [DAT](INFO): DAT read: DatVerbose | 27440 2024-05-24T20:48:10.078Z,1716583690.078 [DAT](INFO): set DatVerbose to 27440 2024-05-24T20:48:10.079Z,1716583690.079 [DAT](INFO): setting transmit power to 8 2024-05-24T20:48:10.329Z,1716583690.329 [DAT](INFO): DAT read: user:3> 2024-05-24T20:48:10.330Z,1716583690.330 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-05-24T20:48:10.330Z,1716583690.330 [DAT](INFO): set transmit power to 8 2024-05-24T20:48:10.331Z,1716583690.331 [DAT](INFO): setting local address to 10 2024-05-24T20:48:10.581Z,1716583690.581 [DAT](INFO): DAT read: user:4> 2024-05-24T20:48:10.582Z,1716583690.582 [DAT](INFO): DAT read: LocalAddr | 10 2024-05-24T20:48:10.582Z,1716583690.582 [DAT](INFO): set local address to 10 2024-05-24T20:48:10.583Z,1716583690.583 [DAT](INFO): Setting time to: 20:48:10 And date to:5/24/2024 2024-05-24T20:48:10.833Z,1716583690.833 [DAT](INFO): DAT read: user:5> 2024-05-24T20:48:10.834Z,1716583690.834 [DAT](INFO): DAT read: Fri May 24, 2024 20:48:10 2024-05-24T20:48:10.834Z,1716583690.834 [DAT](INFO): Local DAT time set to Fri May 24, 2024 20:48:10 2024-05-24T20:48:20.530Z,1716583700.530 [NAL9602](INFO): Powering up NAL9602 2024-05-24T20:48:21.529Z,1716583701.529 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:48:21.529Z,1716583701.529 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:48:22.143Z,1716583702.143 [DockingStepper](INFO): Resume 2024-05-24T20:48:22.634Z,1716583702.634 [DockingStepper](INFO): Resuming 2024-05-24T20:48:22.957Z,1716583702.957 [DockingStepper](INFO): Start 2024-05-24T20:48:22.957Z,1716583702.957 [DockingStepper](DEBUG): Initializing EZServoServo. 2024-05-24T20:48:23.073Z,1716583703.073 [DockingStepper](DEBUG): Initializing DockingStepper. 2024-05-24T20:48:23.370Z,1716583703.370 [DockingStepper](INFO): Starting 2024-05-24T20:48:23.782Z,1716583703.782 [DockingStepper](INFO): Starting 2024-05-24T20:48:24.186Z,1716583704.186 [DockingStepper](INFO): Starting 2024-05-24T20:48:24.234Z,1716583704.234 [DockingStepper](INFO): Init string: /1z14960aE13561N3m50 2024-05-24T20:48:24.629Z,1716583704.629 [DockingStepper](INFO): Starting 2024-05-24T20:48:24.991Z,1716583704.991 [DockingStepper](INFO): Starting 2024-05-24T20:48:25.390Z,1716583705.390 [DockingStepper](INFO): Starting 2024-05-24T20:48:25.803Z,1716583705.803 [DockingStepper](INFO): Starting 2024-05-24T20:48:25.825Z,1716583705.825 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2024-05-24T20:48:26.194Z,1716583706.194 [DockingStepper](INFO): Starting 2024-05-24T20:48:26.647Z,1716583706.647 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:48:26.648Z,1716583706.648 [DockingStepper](INFO): Armed mode. 2024-05-24T20:48:26.716Z,1716583706.716 [DockingStepper](INFO): Commanding negative:45837 2024-05-24T20:48:31.518Z,1716583711.518 [NAL9602](INFO): NAL9602 initialized 2024-05-24T20:48:32.791Z,1716583712.791 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:48:32.791Z,1716583712.791 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:48:32.855Z,1716583712.855 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:48:32.855Z,1716583712.855 [DockingStepper](INFO): Standby mode. 2024-05-24T20:48:32.913Z,1716583712.913 [DockingStepper](INFO): Commanding positive:54900 2024-05-24T20:48:41.641Z,1716583721.641 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:48:41.642Z,1716583721.642 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:48:41.974Z,1716583721.974 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:48:41.974Z,1716583721.974 [DockingStepper](INFO): Armed mode. 2024-05-24T20:48:42.033Z,1716583722.033 [DockingStepper](INFO): Commanding negative:54500 2024-05-24T20:48:47.373Z,1716583727.373 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:48:47.374Z,1716583727.374 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:48:47.438Z,1716583727.438 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:48:47.438Z,1716583727.438 [DockingStepper](INFO): Standby mode. 2024-05-24T20:48:47.896Z,1716583727.896 [DockingStepper](INFO): Commanding positive:54512 2024-05-24T20:48:55.173Z,1716583735.173 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:48:55.173Z,1716583735.173 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:48:55.384Z,1716583735.384 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:48:55.385Z,1716583735.385 [DockingStepper](INFO): Armed mode. 2024-05-24T20:48:55.444Z,1716583735.444 [DockingStepper](INFO): Commanding negative:54500 2024-05-24T20:49:04.745Z,1716583744.745 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:49:04.746Z,1716583744.746 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:49:04.813Z,1716583744.813 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:49:04.813Z,1716583744.813 [DockingStepper](INFO): Standby mode. 2024-05-24T20:49:04.872Z,1716583744.872 [DockingStepper](INFO): Commanding positive:54500 2024-05-24T20:49:05.958Z,1716583745.958 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-05-24T20:49:13.594Z,1716583753.594 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:49:13.594Z,1716583753.594 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:49:13.909Z,1716583753.909 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:49:13.909Z,1716583753.909 [DockingStepper](INFO): Armed mode. 2024-05-24T20:49:13.968Z,1716583753.968 [DockingStepper](INFO): Commanding negative:54500 2024-05-24T20:49:22.122Z,1716583762.122 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:49:22.122Z,1716583762.122 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:49:22.508Z,1716583762.508 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:49:22.509Z,1716583762.509 [DockingStepper](INFO): Standby mode. 2024-05-24T20:49:22.569Z,1716583762.569 [DockingStepper](INFO): Commanding positive:54506 2024-05-24T20:49:30.243Z,1716583770.243 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:49:30.243Z,1716583770.243 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:49:30.347Z,1716583770.347 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:49:30.347Z,1716583770.347 [DockingStepper](INFO): Armed mode. 2024-05-24T20:49:30.416Z,1716583770.416 [DockingStepper](INFO): Commanding negative:54500 2024-05-24T20:49:39.394Z,1716583779.394 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:49:39.394Z,1716583779.394 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:49:39.522Z,1716583779.522 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:49:39.523Z,1716583779.523 [DockingStepper](INFO): Standby mode. 2024-05-24T20:49:39.584Z,1716583779.584 [DockingStepper](INFO): Commanding positive:54500 2024-05-24T20:49:45.765Z,1716583785.765 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:49:45.766Z,1716583785.766 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:49:45.813Z,1716583785.813 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:49:45.813Z,1716583785.813 [DockingStepper](INFO): Armed mode. 2024-05-24T20:49:45.869Z,1716583785.869 [DockingStepper](INFO): Commanding negative:54500 2024-05-24T20:49:47.854Z,1716583787.854 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:49:47.854Z,1716583787.854 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:49:48.200Z,1716583788.200 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:49:48.200Z,1716583788.200 [DockingStepper](INFO): Standby mode. 2024-05-24T20:49:51.560Z,1716583791.560 [DockingStepper](INFO): Commanding positive:54494 2024-05-24T20:49:52.222Z,1716583792.222 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:49:52.222Z,1716583792.222 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:49:52.314Z,1716583792.314 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:49:52.315Z,1716583792.315 [DockingStepper](INFO): Armed mode. 2024-05-24T20:49:57.280Z,1716583797.280 [DockingStepper](INFO): Commanding negative:54494 2024-05-24T20:50:03.046Z,1716583803.046 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:50:03.046Z,1716583803.046 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:50:03.390Z,1716583803.390 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:50:03.390Z,1716583803.390 [DockingStepper](INFO): Standby mode. 2024-05-24T20:50:03.452Z,1716583803.452 [DockingStepper](INFO): Commanding positive:54494 2024-05-24T20:50:11.282Z,1716583811.282 [SBIT](IMPORTANT): Beginning Startup BIT 2024-05-24T20:50:11.287Z,1716583811.287 [CBIT](IMPORTANT): Beginning ground fault scan 2024-05-24T20:50:13.562Z,1716583813.562 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:50:13.562Z,1716583813.562 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:50:13.618Z,1716583813.618 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:50:13.619Z,1716583813.619 [DockingStepper](INFO): Armed mode. 2024-05-24T20:50:13.684Z,1716583813.684 [DockingStepper](INFO): Commanding negative:54494 2024-05-24T20:50:22.320Z,1716583822.320 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005611 CHAN A1 (24V): 0.006577 CHAN A2 (12V): -0.005543 CHAN A3 (5V): -0.001572 CHAN B0 (3.3V): 0.000393 CHAN B1 (3.15aV): -0.000494 CHAN B2 (3.15bV): -0.000102 CHAN B3 (GND): 0.001812 OPEN: 0.004888 Full Scale: +/- 1 mA 2024-05-24T20:50:23.657Z,1716583823.657 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:50:23.657Z,1716583823.657 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:50:23.737Z,1716583823.737 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:50:23.738Z,1716583823.738 [DockingStepper](INFO): Standby mode. 2024-05-24T20:50:23.800Z,1716583823.800 [DockingStepper](INFO): Commanding positive:54500 2024-05-24T20:50:35.113Z,1716583835.113 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:50:35.113Z,1716583835.113 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:50:35.253Z,1716583835.253 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:50:35.253Z,1716583835.253 [DockingStepper](INFO): Armed mode. 2024-05-24T20:50:35.312Z,1716583835.312 [DockingStepper](INFO): Commanding negative:54494 2024-05-24T20:50:48.326Z,1716583848.326 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:50:48.326Z,1716583848.326 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:50:48.575Z,1716583848.575 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:50:48.580Z,1716583848.580 [DockingStepper](INFO): Standby mode. 2024-05-24T20:50:48.648Z,1716583848.648 [DockingStepper](INFO): Commanding positive:54512 2024-05-24T20:50:52.027Z,1716583852.027 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-05-24T20:50:52.027Z,1716583852.027 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-24T20:50:52.257Z,1716583852.257 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-24T20:50:52.587Z,1716583852.587 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-24T20:50:52.587Z,1716583852.587 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-05-24T20:50:55.579Z,1716583855.579 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004815 2024-05-24T20:50:56.877Z,1716583856.877 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:50:56.877Z,1716583856.877 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:50:57.151Z,1716583857.151 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:50:57.151Z,1716583857.151 [DockingStepper](INFO): Armed mode. 2024-05-24T20:50:57.216Z,1716583857.216 [DockingStepper](INFO): Commanding negative:54525 2024-05-24T20:51:00.522Z,1716583860.522 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:51:00.522Z,1716583860.522 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:51:00.926Z,1716583860.926 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:51:00.926Z,1716583860.926 [DockingStepper](INFO): Standby mode. 2024-05-24T20:51:02.752Z,1716583862.752 [DockingStepper](INFO): Commanding positive:54506 2024-05-24T20:51:05.074Z,1716583865.074 [SBIT](IMPORTANT): SBIT PASSED 2024-05-24T20:51:05.074Z,1716583865.074 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-05-24T20:51:05.075Z,1716583865.075 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2024-05-24T20:51:05.075Z,1716583865.075 [SBIT](IMPORTANT): Docked.detachTimeout=8 hour; 2024-05-24T20:51:05.075Z,1716583865.075 [SBIT](IMPORTANT): DockingStepper.closedValue=16500 count; 2024-05-24T20:51:05.075Z,1716583865.075 [SBIT](IMPORTANT): DockingStepper.loadAtStartup=1 bool; 2024-05-24T20:51:05.075Z,1716583865.075 [SBIT](IMPORTANT): DockingStepper.openValue=7500 count; 2024-05-24T20:51:05.076Z,1716583865.076 [SBIT](IMPORTANT): DockingStepper.simulateHardware=0 bool; 2024-05-24T20:51:05.076Z,1716583865.076 [SBIT](IMPORTANT): DockingStepper.slideValue=12000 count; 2024-05-24T20:51:05.076Z,1716583865.076 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2024-05-24T20:51:05.076Z,1716583865.076 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool; 2024-05-24T20:51:05.076Z,1716583865.076 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=300 cubic_centimeter; 2024-05-24T20:51:05.076Z,1716583865.076 [SBIT](IMPORTANT): VerticalControl.massDefault=30 millimeter; 2024-05-24T20:51:05.277Z,1716583865.277 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2024-05-24T20:51:05.278Z,1716583865.278 [DefaultWithUndock] Running Loop=1 2024-05-24T20:51:05.278Z,1716583865.278 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2024-05-24T20:51:05.278Z,1716583865.278 [DefaultWithUndock:A.Wait] Running Loop=1 2024-05-24T20:51:05.278Z,1716583865.278 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2024-05-24T20:51:10.758Z,1716583870.758 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:51:10.758Z,1716583870.758 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:51:11.175Z,1716583871.175 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:51:11.175Z,1716583871.175 [DockingStepper](INFO): Armed mode. 2024-05-24T20:51:11.236Z,1716583871.236 [DockingStepper](INFO): Commanding negative:54494 2024-05-24T20:51:18.665Z,1716583878.665 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:51:18.666Z,1716583878.666 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:51:18.854Z,1716583878.854 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:51:18.854Z,1716583878.854 [DockingStepper](INFO): Standby mode. 2024-05-24T20:51:18.916Z,1716583878.917 [DockingStepper](INFO): Commanding positive:54500 2024-05-24T20:51:30.346Z,1716583890.346 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:51:30.346Z,1716583890.346 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:51:30.521Z,1716583890.521 [DockingStepper](INFO): Changing to mode: 2 2024-05-24T20:51:30.521Z,1716583890.521 [DockingStepper](INFO): Armed mode. 2024-05-24T20:51:30.585Z,1716583890.585 [DockingStepper](INFO): Commanding negative:54500 2024-05-24T20:51:35.435Z,1716583895.435 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2024-05-24T20:51:35.435Z,1716583895.435 [DefaultWithUndock:A.Wait] Stopped 2024-05-24T20:51:35.435Z,1716583895.435 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2024-05-24T20:51:35.435Z,1716583895.435 [DefaultWithUndock:LeaveDock] Running Loop=1 2024-05-24T20:51:35.435Z,1716583895.435 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2024-05-24T20:51:35.435Z,1716583895.435 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2024-05-24T20:51:35.435Z,1716583895.435 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2024-05-24T20:51:35.436Z,1716583895.436 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2024-05-24T20:51:35.436Z,1716583895.436 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2024-05-24T20:51:35.436Z,1716583895.436 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2024-05-24T20:51:35.675Z,1716583895.675 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2024-05-24T20:51:35.710Z,1716583895.710 [DockingStepper](INFO): Changing to mode: 3 2024-05-24T20:51:35.711Z,1716583895.711 [DockingStepper](INFO): Detach mode. 2024-05-24T20:51:36.506Z,1716583896.506 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock. 2024-05-24T20:51:36.926Z,1716583896.926 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2024-05-24T20:51:37.221Z,1716583897.221 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:51:37.222Z,1716583897.222 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:51:37.329Z,1716583897.329 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:51:37.329Z,1716583897.329 [DockingStepper](INFO): Standby mode. 2024-05-24T20:51:37.392Z,1716583897.392 [DockingStepper](INFO): Commanding positive:54488 2024-05-24T20:51:38.121Z,1716583898.121 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:38.361Z,1716583898.361 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:38.361Z,1716583898.361 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:38.361Z,1716583898.361 [DAT](INFO): setting remote address to 0 2024-05-24T20:51:38.619Z,1716583898.619 [DAT](INFO): DAT read: user:6> 2024-05-24T20:51:38.622Z,1716583898.622 [DAT](INFO): DAT read: RemoteAddr | 0 2024-05-24T20:51:38.623Z,1716583898.623 [DAT](INFO): set remote address to 0 2024-05-24T20:51:38.624Z,1716583898.624 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:38.624Z,1716583898.624 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:38.625Z,1716583898.625 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:38.869Z,1716583898.869 [DAT](INFO): DAT read: user:7> 2024-05-24T20:51:38.870Z,1716583898.870 [DAT](INFO): DAT read: Tx time:20:51:38.1146 2024-05-24T20:51:38.870Z,1716583898.870 [DAT](INFO): Ping request sent. 2024-05-24T20:51:38.870Z,1716583898.870 [DAT](INFO): transmitted an acoustic signal 2024-05-24T20:51:38.871Z,1716583898.871 [DAT](INFO): publishing transmit ping time 2024-05-24T20:51:38.871Z,1716583898.871 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000952 2024-05-24T20:51:39.121Z,1716583899.121 [DAT](INFO): DAT read: TxSync time:20:51:38.1138 2024-05-24T20:51:39.122Z,1716583899.122 [DAT](INFO): unknown deviceResponse_: TxSync time:20:51:38.1138 2024-05-24T20:51:39.122Z,1716583899.122 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252013 2024-05-24T20:51:39.373Z,1716583899.373 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503123 2024-05-24T20:51:39.625Z,1716583899.625 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755070 2024-05-24T20:51:39.877Z,1716583899.877 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006975 2024-05-24T20:51:40.129Z,1716583900.129 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258636 2024-05-24T20:51:40.382Z,1716583900.382 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511821 2024-05-24T20:51:40.638Z,1716583900.638 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.765115 2024-05-24T20:51:40.885Z,1716583900.885 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014987 2024-05-24T20:51:41.017Z,1716583901.017 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:41.137Z,1716583901.137 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.267040 2024-05-24T20:51:41.389Z,1716583901.389 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518846 2024-05-24T20:51:41.642Z,1716583901.642 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771260 2024-05-24T20:51:41.893Z,1716583901.893 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022985 2024-05-24T20:51:42.146Z,1716583902.146 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275266 2024-05-24T20:51:42.398Z,1716583902.398 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.527531 2024-05-24T20:51:42.649Z,1716583902.649 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778949 2024-05-24T20:51:42.901Z,1716583902.901 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.031045 2024-05-24T20:51:43.153Z,1716583903.153 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282696 2024-05-24T20:51:43.405Z,1716583903.405 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534791 2024-05-24T20:51:43.578Z,1716583903.578 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:51:43.578Z,1716583903.578 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:51:43.661Z,1716583903.661 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.791063 2024-05-24T20:51:43.891Z,1716583903.891 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:43.913Z,1716583903.913 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.042920 2024-05-24T20:51:43.941Z,1716583903.941 [DockingStepper](INFO): Changing to mode: 3 2024-05-24T20:51:43.942Z,1716583903.942 [DockingStepper](INFO): Detach mode. 2024-05-24T20:51:44.004Z,1716583904.004 [DockingStepper](INFO): Commanding negative:54488 2024-05-24T20:51:44.165Z,1716583904.165 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.294753 2024-05-24T20:51:44.417Z,1716583904.417 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.547160 2024-05-24T20:51:44.669Z,1716583904.669 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.798768 2024-05-24T20:51:44.921Z,1716583904.921 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.050894 2024-05-24T20:51:45.173Z,1716583905.173 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.303032 2024-05-24T20:51:45.425Z,1716583905.425 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.555022 2024-05-24T20:51:45.677Z,1716583905.677 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.806914 2024-05-24T20:51:45.930Z,1716583905.930 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.059352 2024-05-24T20:51:46.181Z,1716583906.181 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.311047 2024-05-24T20:51:46.433Z,1716583906.433 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.562978 2024-05-24T20:51:46.510Z,1716583906.510 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:46.688Z,1716583906.688 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.818128 2024-05-24T20:51:46.937Z,1716583906.937 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.067065 2024-05-24T20:51:47.190Z,1716583907.190 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.319324 2024-05-24T20:51:47.441Z,1716583907.441 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.571041 2024-05-24T20:51:47.694Z,1716583907.694 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.823671 2024-05-24T20:51:47.945Z,1716583907.945 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.074793 2024-05-24T20:51:48.197Z,1716583908.197 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.326714 2024-05-24T20:51:48.449Z,1716583908.449 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.578996 2024-05-24T20:51:48.701Z,1716583908.701 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.830884 2024-05-24T20:51:48.953Z,1716583908.953 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:48.953Z,1716583908.953 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:48.953Z,1716583908.953 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:49.051Z,1716583909.051 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:49.206Z,1716583909.206 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:49.206Z,1716583909.206 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:49.206Z,1716583909.206 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:49.457Z,1716583909.457 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:49.457Z,1716583909.457 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:49.457Z,1716583909.457 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:49.709Z,1716583909.709 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:49.709Z,1716583909.709 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:49.709Z,1716583909.709 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:49.961Z,1716583909.961 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:49.961Z,1716583909.961 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:49.961Z,1716583909.961 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:50.004Z,1716583910.004 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock. 2024-05-24T20:51:50.213Z,1716583910.213 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:50.213Z,1716583910.213 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:50.213Z,1716583910.213 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:50.393Z,1716583910.393 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2024-05-24T20:51:50.465Z,1716583910.465 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:50.465Z,1716583910.465 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:50.466Z,1716583910.466 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:50.717Z,1716583910.717 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:50.717Z,1716583910.717 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:50.717Z,1716583910.717 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:50.969Z,1716583910.969 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:51:50.969Z,1716583910.969 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:51:50.970Z,1716583910.970 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:51:51.073Z,1716583911.073 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:51:51.073Z,1716583911.073 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:51:51.221Z,1716583911.221 [DAT](INFO): DAT read: Response Not Received 2024-05-24T20:51:51.221Z,1716583911.221 [DAT](INFO): response not received 2024-05-24T20:51:51.222Z,1716583911.222 [DAT](INFO): DAT read: user:8> 2024-05-24T20:51:51.223Z,1716583911.223 [DAT](INFO): DAT read: Tx time:20:51:50.5647 2024-05-24T20:51:51.223Z,1716583911.223 [DAT](INFO): Ping request sent. 2024-05-24T20:51:51.223Z,1716583911.223 [DAT](INFO): transmitted an acoustic signal 2024-05-24T20:51:51.223Z,1716583911.223 [DAT](INFO): publishing transmit ping time 2024-05-24T20:51:51.224Z,1716583911.224 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000706 2024-05-24T20:51:51.245Z,1716583911.245 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:51:51.245Z,1716583911.245 [DockingStepper](INFO): Standby mode. 2024-05-24T20:51:51.308Z,1716583911.308 [DockingStepper](INFO): Commanding positive:54488 2024-05-24T20:51:51.473Z,1716583911.473 [DAT](INFO): DAT read: TxSync time:20:51:50.5639 2024-05-24T20:51:51.474Z,1716583911.474 [DAT](INFO): unknown deviceResponse_: TxSync time:20:51:50.5639 2024-05-24T20:51:51.474Z,1716583911.474 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251275 2024-05-24T20:51:51.581Z,1716583911.581 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:51.726Z,1716583911.726 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502772 2024-05-24T20:51:51.977Z,1716583911.977 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754546 2024-05-24T20:51:52.229Z,1716583912.229 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006367 2024-05-24T20:51:52.481Z,1716583912.481 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258206 2024-05-24T20:51:52.733Z,1716583912.733 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510070 2024-05-24T20:51:52.985Z,1716583912.985 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762276 2024-05-24T20:51:53.237Z,1716583913.237 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014190 2024-05-24T20:51:53.489Z,1716583913.489 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266088 2024-05-24T20:51:53.745Z,1716583913.745 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.522533 2024-05-24T20:51:53.993Z,1716583913.993 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770241 2024-05-24T20:51:54.245Z,1716583914.245 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022281 2024-05-24T20:51:54.419Z,1716583914.419 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:54.498Z,1716583914.498 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274879 2024-05-24T20:51:54.749Z,1716583914.749 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526130 2024-05-24T20:51:55.001Z,1716583915.001 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778088 2024-05-24T20:51:55.253Z,1716583915.253 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.029977 2024-05-24T20:51:55.505Z,1716583915.505 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282128 2024-05-24T20:51:55.759Z,1716583915.759 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.536460 2024-05-24T20:51:56.009Z,1716583916.009 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786370 2024-05-24T20:51:56.262Z,1716583916.262 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038472 2024-05-24T20:51:56.513Z,1716583916.513 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290069 2024-05-24T20:51:56.765Z,1716583916.765 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542081 2024-05-24T20:51:57.017Z,1716583917.017 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794241 2024-05-24T20:51:57.028Z,1716583917.028 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:57.269Z,1716583917.269 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046293 2024-05-24T20:51:57.522Z,1716583917.522 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298593 2024-05-24T20:51:57.773Z,1716583917.773 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550140 2024-05-24T20:51:57.866Z,1716583917.866 [DockingStepper](INFO): Changing to mode: 3 2024-05-24T20:51:57.866Z,1716583917.866 [DockingStepper](INFO): Detach mode. 2024-05-24T20:51:57.932Z,1716583917.932 [DockingStepper](INFO): Commanding negative:54494 2024-05-24T20:51:58.025Z,1716583918.025 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802178 2024-05-24T20:51:58.278Z,1716583918.278 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.055119 2024-05-24T20:51:58.529Z,1716583918.529 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306112 2024-05-24T20:51:58.781Z,1716583918.781 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558197 2024-05-24T20:51:59.033Z,1716583919.033 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810418 2024-05-24T20:51:59.286Z,1716583919.286 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062854 2024-05-24T20:51:59.537Z,1716583919.537 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314037 2024-05-24T20:51:59.562Z,1716583919.562 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:51:59.790Z,1716583919.790 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.567043 2024-05-24T20:52:00.041Z,1716583920.041 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818241 2024-05-24T20:52:00.293Z,1716583920.293 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070029 2024-05-24T20:52:00.545Z,1716583920.545 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.322408 2024-05-24T20:52:00.798Z,1716583920.798 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.575373 2024-05-24T20:52:01.049Z,1716583921.049 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826217 2024-05-24T20:52:01.061Z,1716583921.061 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-24T20:52:01.303Z,1716583921.303 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:01.304Z,1716583921.304 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:01.304Z,1716583921.304 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:01.554Z,1716583921.554 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:01.554Z,1716583921.554 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:01.554Z,1716583921.554 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:01.805Z,1716583921.805 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:01.805Z,1716583921.805 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:01.805Z,1716583921.805 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:02.057Z,1716583922.057 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:02.057Z,1716583922.057 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:02.057Z,1716583922.057 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:02.140Z,1716583922.140 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:02.310Z,1716583922.310 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:02.310Z,1716583922.310 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:02.310Z,1716583922.310 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:02.561Z,1716583922.561 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:02.561Z,1716583922.561 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:02.562Z,1716583922.562 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:02.813Z,1716583922.813 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:02.813Z,1716583922.813 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:02.813Z,1716583922.813 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:03.065Z,1716583923.065 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:03.065Z,1716583923.065 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:03.065Z,1716583923.065 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:03.181Z,1716583923.181 [CommandExec](IMPORTANT): got command docking arm 2024-05-24T20:52:03.182Z,1716583923.182 [CommandExec](IMPORTANT): Switching docking moudle to ARM. 2024-05-24T20:52:03.317Z,1716583923.317 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:03.317Z,1716583923.317 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:03.318Z,1716583923.318 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:03.569Z,1716583923.569 [DAT](INFO): DAT read: Response Not Received 2024-05-24T20:52:03.570Z,1716583923.570 [DAT](INFO): response not received 2024-05-24T20:52:03.570Z,1716583923.570 [DAT](INFO): DAT read: user:9> 2024-05-24T20:52:03.570Z,1716583923.570 [DAT](ERROR): No response from remote modem. 2024-05-24T20:52:03.571Z,1716583923.571 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:03.571Z,1716583923.571 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:03.571Z,1716583923.571 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:03.822Z,1716583923.822 [DAT](INFO): DAT read: Tx time:20:52:03.0149 2024-05-24T20:52:03.823Z,1716583923.823 [DAT](INFO): Ping request sent. 2024-05-24T20:52:03.823Z,1716583923.823 [DAT](INFO): transmitted an acoustic signal 2024-05-24T20:52:03.824Z,1716583923.824 [DAT](INFO): DAT read: TxSync time:20:52:03.0141 2024-05-24T20:52:03.824Z,1716583923.824 [DAT](INFO): unknown deviceResponse_: TxSync time:20:52:03.0141 2024-05-24T20:52:03.825Z,1716583923.825 [DAT](INFO): publishing transmit ping time 2024-05-24T20:52:03.825Z,1716583923.825 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.002338 2024-05-24T20:52:04.073Z,1716583924.073 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249936 2024-05-24T20:52:04.123Z,1716583924.123 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock. 2024-05-24T20:52:04.325Z,1716583924.325 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502140 2024-05-24T20:52:04.502Z,1716583924.502 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2024-05-24T20:52:04.577Z,1716583924.577 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754523 2024-05-24T20:52:04.829Z,1716583924.829 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006114 2024-05-24T20:52:04.912Z,1716583924.912 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:05.082Z,1716583925.082 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258701 2024-05-24T20:52:05.335Z,1716583925.335 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511761 2024-05-24T20:52:05.585Z,1716583925.585 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762033 2024-05-24T20:52:05.837Z,1716583925.837 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014296 2024-05-24T20:52:06.089Z,1716583926.089 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266072 2024-05-24T20:52:06.341Z,1716583926.341 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518145 2024-05-24T20:52:06.513Z,1716583926.513 [CommandExec](IMPORTANT): got command docking standby 2024-05-24T20:52:06.514Z,1716583926.514 [CommandExec](IMPORTANT): Switching docking moudle to STANDBY. 2024-05-24T20:52:06.566Z,1716583926.566 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:52:06.566Z,1716583926.566 [DockingStepper](INFO): Standby mode. 2024-05-24T20:52:06.596Z,1716583926.596 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772283 2024-05-24T20:52:06.625Z,1716583926.625 [DockingStepper](INFO): Commanding positive:54506 2024-05-24T20:52:06.845Z,1716583926.845 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022229 2024-05-24T20:52:07.097Z,1716583927.097 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.273999 2024-05-24T20:52:07.350Z,1716583927.350 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526564 2024-05-24T20:52:07.507Z,1716583927.507 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:07.605Z,1716583927.605 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.781006 2024-05-24T20:52:07.853Z,1716583927.853 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030247 2024-05-24T20:52:08.105Z,1716583928.105 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.281998 2024-05-24T20:52:08.357Z,1716583928.357 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.533978 2024-05-24T20:52:08.611Z,1716583928.611 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.787613 2024-05-24T20:52:08.861Z,1716583928.861 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038032 2024-05-24T20:52:09.113Z,1716583929.113 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290073 2024-05-24T20:52:09.365Z,1716583929.365 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542225 2024-05-24T20:52:09.617Z,1716583929.617 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794450 2024-05-24T20:52:09.869Z,1716583929.869 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046210 2024-05-24T20:52:10.091Z,1716583930.091 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:10.122Z,1716583930.122 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298658 2024-05-24T20:52:10.374Z,1716583930.374 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.551132 2024-05-24T20:52:10.628Z,1716583930.628 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.804303 2024-05-24T20:52:10.877Z,1716583930.877 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054167 2024-05-24T20:52:11.129Z,1716583931.129 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.305999 2024-05-24T20:52:11.381Z,1716583931.381 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558410 2024-05-24T20:52:11.633Z,1716583931.633 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810028 2024-05-24T20:52:11.885Z,1716583931.885 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062248 2024-05-24T20:52:12.137Z,1716583932.137 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314209 2024-05-24T20:52:12.389Z,1716583932.389 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.566011 2024-05-24T20:52:12.643Z,1716583932.643 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.819715 2024-05-24T20:52:12.893Z,1716583932.893 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070234 2024-05-24T20:52:12.942Z,1716583932.942 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:12.974Z,1716583932.974 [DockingStepper](INFO): Changing to mode: 3 2024-05-24T20:52:12.974Z,1716583932.974 [DockingStepper](INFO): Detach mode. 2024-05-24T20:52:13.036Z,1716583933.036 [DockingStepper](INFO): Commanding negative:54494 2024-05-24T20:52:13.145Z,1716583933.145 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.322400 2024-05-24T20:52:13.398Z,1716583933.398 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574609 2024-05-24T20:52:13.649Z,1716583933.649 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826119 2024-05-24T20:52:13.901Z,1716583933.901 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:13.901Z,1716583933.901 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:13.902Z,1716583933.902 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:14.109Z,1716583934.109 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-24T20:52:14.153Z,1716583934.153 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:14.153Z,1716583934.153 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:14.153Z,1716583934.153 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:14.405Z,1716583934.405 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:14.405Z,1716583934.405 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:14.406Z,1716583934.406 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:14.659Z,1716583934.659 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:14.659Z,1716583934.659 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:14.660Z,1716583934.660 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:14.909Z,1716583934.909 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:14.909Z,1716583934.909 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:14.909Z,1716583934.909 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:15.162Z,1716583935.162 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:15.162Z,1716583935.162 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:15.162Z,1716583935.162 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:15.413Z,1716583935.413 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:15.413Z,1716583935.413 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:15.413Z,1716583935.413 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:15.478Z,1716583935.478 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:15.665Z,1716583935.665 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:15.665Z,1716583935.665 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:15.665Z,1716583935.665 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:15.919Z,1716583935.919 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:15.920Z,1716583935.920 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:15.920Z,1716583935.920 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:16.169Z,1716583936.169 [DAT](INFO): DAT read: Response Not Received 2024-05-24T20:52:16.169Z,1716583936.169 [DAT](INFO): response not received 2024-05-24T20:52:16.170Z,1716583936.170 [DAT](INFO): DAT read: user:10> 2024-05-24T20:52:16.170Z,1716583936.170 [DAT](INFO): DAT read: Tx time:20:52:15.4650 2024-05-24T20:52:16.171Z,1716583936.171 [DAT](INFO): Ping request sent. 2024-05-24T20:52:16.171Z,1716583936.171 [DAT](INFO): transmitted an acoustic signal 2024-05-24T20:52:16.171Z,1716583936.171 [DAT](INFO): publishing transmit ping time 2024-05-24T20:52:16.172Z,1716583936.172 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000699 2024-05-24T20:52:16.422Z,1716583936.422 [DAT](INFO): DAT read: TxSync time:20:52:15.4642 2024-05-24T20:52:16.422Z,1716583936.422 [DAT](INFO): unknown deviceResponse_: TxSync time:20:52:15.4642 2024-05-24T20:52:16.423Z,1716583936.423 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252073 2024-05-24T20:52:16.673Z,1716583936.673 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502276 2024-05-24T20:52:16.925Z,1716583936.925 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754106 2024-05-24T20:52:17.178Z,1716583937.178 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007632 2024-05-24T20:52:17.429Z,1716583937.429 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258285 2024-05-24T20:52:17.682Z,1716583937.682 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510421 2024-05-24T20:52:17.938Z,1716583937.938 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.766951 2024-05-24T20:52:18.189Z,1716583938.189 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.018269 2024-05-24T20:52:18.306Z,1716583938.306 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:18.442Z,1716583938.442 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.270890 2024-05-24T20:52:18.693Z,1716583938.693 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.522303 2024-05-24T20:52:18.946Z,1716583938.946 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.774519 2024-05-24T20:52:19.106Z,1716583939.106 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock. 2024-05-24T20:52:19.197Z,1716583939.197 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.026216 2024-05-24T20:52:19.449Z,1716583939.449 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.278210 2024-05-24T20:52:19.509Z,1716583939.509 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2024-05-24T20:52:19.702Z,1716583939.702 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.530878 2024-05-24T20:52:19.953Z,1716583939.953 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.782202 2024-05-24T20:52:20.205Z,1716583940.205 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.034443 2024-05-24T20:52:20.458Z,1716583940.458 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.286550 2024-05-24T20:52:20.709Z,1716583940.709 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.538200 2024-05-24T20:52:20.961Z,1716583940.961 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.790241 2024-05-24T20:52:21.124Z,1716583941.124 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:21.214Z,1716583941.214 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.042582 2024-05-24T20:52:21.465Z,1716583941.465 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.294118 2024-05-24T20:52:21.718Z,1716583941.718 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.547112 2024-05-24T20:52:21.970Z,1716583941.970 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.798713 2024-05-24T20:52:22.221Z,1716583942.221 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.050149 2024-05-24T20:52:22.474Z,1716583942.474 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.302938 2024-05-24T20:52:22.725Z,1716583942.725 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.554275 2024-05-24T20:52:22.977Z,1716583942.977 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.806350 2024-05-24T20:52:23.229Z,1716583943.229 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.058579 2024-05-24T20:52:23.481Z,1716583943.481 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.310243 2024-05-24T20:52:23.733Z,1716583943.733 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.562220 2024-05-24T20:52:23.954Z,1716583943.954 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:23.985Z,1716583943.985 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.814461 2024-05-24T20:52:24.237Z,1716583944.237 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.066228 2024-05-24T20:52:24.490Z,1716583944.490 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.318474 2024-05-24T20:52:24.741Z,1716583944.741 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.570551 2024-05-24T20:52:24.993Z,1716583944.993 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.822245 2024-05-24T20:52:25.246Z,1716583945.246 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.075138 2024-05-24T20:52:25.497Z,1716583945.497 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.326452 2024-05-24T20:52:25.750Z,1716583945.750 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.579159 2024-05-24T20:52:26.001Z,1716583946.001 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.830435 2024-05-24T20:52:26.253Z,1716583946.253 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:26.253Z,1716583946.253 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:26.253Z,1716583946.253 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:26.505Z,1716583946.505 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:26.505Z,1716583946.505 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:26.506Z,1716583946.506 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:26.757Z,1716583946.757 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:26.757Z,1716583946.757 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:26.757Z,1716583946.757 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:26.834Z,1716583946.834 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:27.009Z,1716583947.009 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:27.009Z,1716583947.009 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:27.009Z,1716583947.009 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:27.262Z,1716583947.262 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:27.262Z,1716583947.262 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:27.262Z,1716583947.262 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:27.513Z,1716583947.513 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:27.513Z,1716583947.513 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:27.513Z,1716583947.513 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:27.573Z,1716583947.573 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-24T20:52:27.768Z,1716583947.768 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:27.768Z,1716583947.768 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:27.770Z,1716583947.770 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:28.017Z,1716583948.017 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:28.017Z,1716583948.017 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:28.017Z,1716583948.017 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:28.269Z,1716583948.269 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:28.269Z,1716583948.269 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:28.269Z,1716583948.269 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:28.521Z,1716583948.521 [DAT](INFO): DAT read: Response Not Received 2024-05-24T20:52:28.521Z,1716583948.521 [DAT](INFO): response not received 2024-05-24T20:52:28.522Z,1716583948.522 [DAT](INFO): DAT read: user:11> 2024-05-24T20:52:28.522Z,1716583948.522 [DAT](INFO): DAT read: Tx time:20:52:27.9152 2024-05-24T20:52:28.523Z,1716583948.523 [DAT](INFO): Ping request sent. 2024-05-24T20:52:28.523Z,1716583948.523 [DAT](INFO): transmitted an acoustic signal 2024-05-24T20:52:28.523Z,1716583948.523 [DAT](INFO): publishing transmit ping time 2024-05-24T20:52:28.524Z,1716583948.524 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000953 2024-05-24T20:52:28.773Z,1716583948.773 [DAT](INFO): DAT read: TxSync time:20:52:27.9144 2024-05-24T20:52:28.774Z,1716583948.774 [DAT](INFO): unknown deviceResponse_: TxSync time:20:52:27.9144 2024-05-24T20:52:28.774Z,1716583948.774 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251202 2024-05-24T20:52:29.025Z,1716583949.025 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502429 2024-05-24T20:52:29.278Z,1716583949.278 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755156 2024-05-24T20:52:29.529Z,1716583949.529 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006220 2024-05-24T20:52:29.610Z,1716583949.610 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:29.781Z,1716583949.781 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258248 2024-05-24T20:52:30.033Z,1716583950.033 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510405 2024-05-24T20:52:30.285Z,1716583950.285 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762140 2024-05-24T20:52:30.538Z,1716583950.538 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014877 2024-05-24T20:52:30.789Z,1716583950.789 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266253 2024-05-24T20:52:31.041Z,1716583951.041 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518215 2024-05-24T20:52:31.294Z,1716583951.294 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770663 2024-05-24T20:52:31.545Z,1716583951.545 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022302 2024-05-24T20:52:31.798Z,1716583951.798 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274897 2024-05-24T20:52:32.049Z,1716583952.049 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526063 2024-05-24T20:52:32.301Z,1716583952.301 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778164 2024-05-24T20:52:32.461Z,1716583952.461 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:32.554Z,1716583952.554 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.031117 2024-05-24T20:52:32.805Z,1716583952.805 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282189 2024-05-24T20:52:33.057Z,1716583953.057 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534306 2024-05-24T20:52:33.309Z,1716583953.309 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786342 2024-05-24T20:52:33.561Z,1716583953.561 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038118 2024-05-24T20:52:33.813Z,1716583953.813 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290117 2024-05-24T20:52:34.065Z,1716583954.065 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542174 2024-05-24T20:52:34.317Z,1716583954.317 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794134 2024-05-24T20:52:34.569Z,1716583954.569 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046424 2024-05-24T20:52:34.821Z,1716583954.821 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298161 2024-05-24T20:52:34.989Z,1716583954.989 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:35.074Z,1716583955.074 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550656 2024-05-24T20:52:35.325Z,1716583955.325 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802173 2024-05-24T20:52:35.579Z,1716583955.579 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.055887 2024-05-24T20:52:35.830Z,1716583955.830 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306482 2024-05-24T20:52:36.081Z,1716583956.081 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558252 2024-05-24T20:52:36.333Z,1716583956.333 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810317 2024-05-24T20:52:36.587Z,1716583956.587 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.063845 2024-05-24T20:52:36.837Z,1716583956.837 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314260 2024-05-24T20:52:37.089Z,1716583957.089 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.566332 2024-05-24T20:52:37.273Z,1716583957.273 [CommandExec](IMPORTANT): got command restart application 2024-05-24T20:52:37.341Z,1716583957.341 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818229 2024-05-24T20:52:37.593Z,1716583957.593 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070474 2024-05-24T20:52:37.706Z,1716583957.706 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:37.847Z,1716583957.847 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.323503 2024-05-24T20:52:38.097Z,1716583958.097 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574263 2024-05-24T20:52:38.276Z,1716583958.276 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2024-05-24T20:52:38.277Z,1716583958.277 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:38.277Z,1716583958.277 [CommandExec](INFO): Uninitializing the command executive. 2024-05-24T20:52:38.277Z,1716583958.277 [CommandExec](INFO): Uninitializing the command scheduler. 2024-05-24T20:52:38.278Z,1716583958.278 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.324Z,1716583958.324 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-05-24T20:52:38.324Z,1716583958.324 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-05-24T20:52:38.325Z,1716583958.325 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.325Z,1716583958.325 [NavChartDb](INFO): Join timeout helper Thread ID is 3430 2024-05-24T20:52:38.349Z,1716583958.349 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826504 2024-05-24T20:52:38.435Z,1716583958.435 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:38.436Z,1716583958.436 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.444Z,1716583958.444 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2024-05-24T20:52:38.444Z,1716583958.444 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.445Z,1716583958.445 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 3431 2024-05-24T20:52:38.606Z,1716583958.606 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:38.606Z,1716583958.606 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:38.607Z,1716583958.607 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:38.773Z,1716583958.773 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:38.773Z,1716583958.773 [WetLabsUBAT](INFO): Powering down 2024-05-24T20:52:38.774Z,1716583958.774 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.774Z,1716583958.774 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2024-05-24T20:52:38.774Z,1716583958.774 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.775Z,1716583958.775 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3432 2024-05-24T20:52:38.820Z,1716583958.820 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:38.821Z,1716583958.821 [WetLabsBB2FL](INFO): Powering down 2024-05-24T20:52:38.821Z,1716583958.821 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.824Z,1716583958.824 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2024-05-24T20:52:38.824Z,1716583958.824 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:38.826Z,1716583958.826 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3433 2024-05-24T20:52:38.857Z,1716583958.857 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:38.857Z,1716583958.857 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:38.857Z,1716583958.857 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:39.110Z,1716583959.110 [DAT](INFO): ****** received valid address query ****** 2024-05-24T20:52:39.110Z,1716583959.110 [DAT](INFO): ****** received valid ping request ****** 2024-05-24T20:52:39.110Z,1716583959.110 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-24T20:52:39.129Z,1716583959.129 [CTD_Seabird](INFO): Powering down 2024-05-24T20:52:39.140Z,1716583959.140 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:39.140Z,1716583959.140 [CTD_Seabird](INFO): Powering down 2024-05-24T20:52:39.152Z,1716583959.152 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:39.172Z,1716583959.172 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2024-05-24T20:52:39.172Z,1716583959.172 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:39.173Z,1716583959.173 [DAT](INFO): Join timeout helper Thread ID is 3434 2024-05-24T20:52:39.361Z,1716583959.361 [DAT](INFO): Powering down 2024-05-24T20:52:39.433Z,1716583959.433 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:39.433Z,1716583959.433 [DAT](INFO): Powering down 2024-05-24T20:52:39.434Z,1716583959.434 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:39.441Z,1716583959.441 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2024-05-24T20:52:39.441Z,1716583959.441 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:39.442Z,1716583959.442 [Radio_Surface](INFO): Join timeout helper Thread ID is 3435 2024-05-24T20:52:39.672Z,1716583959.672 [Radio_Surface](INFO): Powering down 2024-05-24T20:52:39.673Z,1716583959.673 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:39.673Z,1716583959.673 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:39.681Z,1716583959.681 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2024-05-24T20:52:39.681Z,1716583959.681 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:39.681Z,1716583959.681 [Onboard](INFO): Join timeout helper Thread ID is 3436 2024-05-24T20:52:39.784Z,1716583959.784 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning docking module to standby. 2024-05-24T20:52:40.197Z,1716583960.197 [DockingStepper](INFO): Changing to mode: 1 2024-05-24T20:52:40.197Z,1716583960.197 [DockingStepper](INFO): Standby mode. 2024-05-24T20:52:40.264Z,1716583960.264 [DockingStepper](INFO): Commanding positive:54500 2024-05-24T20:52:40.502Z,1716583960.502 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-24T20:52:40.519Z,1716583960.519 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-24T20:52:42.124Z,1716583962.124 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:42.125Z,1716583962.125 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:42.141Z,1716583962.141 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2024-05-24T20:52:42.141Z,1716583962.141 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:42.141Z,1716583962.141 [DataOverHttps](INFO): Join timeout helper Thread ID is 3437 2024-05-24T20:52:43.008Z,1716583963.008 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:43.011Z,1716583963.011 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.013Z,1716583963.013 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2024-05-24T20:52:43.013Z,1716583963.013 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.014Z,1716583963.014 [BackseatComponent](INFO): Join timeout helper Thread ID is 3438 2024-05-24T20:52:43.049Z,1716583963.049 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:43.049Z,1716583963.049 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.065Z,1716583963.065 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2024-05-24T20:52:43.065Z,1716583963.065 [logger ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.066Z,1716583963.066 [logger](INFO): Join timeout helper Thread ID is 3439 2024-05-24T20:52:43.091Z,1716583963.091 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:43.092Z,1716583963.092 [logger ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.101Z,1716583963.101 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2024-05-24T20:52:43.101Z,1716583963.101 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.102Z,1716583963.102 [CommandLine](INFO): Join timeout helper Thread ID is 3440 2024-05-24T20:52:43.197Z,1716583963.197 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:43.197Z,1716583963.197 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.201Z,1716583963.201 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2024-05-24T20:52:43.201Z,1716583963.201 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.202Z,1716583963.202 [CommandExec](INFO): Join timeout helper Thread ID is 3441 2024-05-24T20:52:43.203Z,1716583963.203 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2024-05-24T20:52:43.203Z,1716583963.203 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.203Z,1716583963.203 [controlThread](INFO): Join timeout helper Thread ID is 3442 2024-05-24T20:52:43.485Z,1716583963.485 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-24T20:52:43.486Z,1716583963.486 [controlThread](DEBUG): Uninitializing ControlThread 2024-05-24T20:52:43.486Z,1716583963.486 [AHRS_M2](INFO): Powering down 2024-05-24T20:52:43.558Z,1716583963.558 [NAL9602](INFO): Powering down 2024-05-24T20:52:43.628Z,1716583963.628 [RDI_Pathfinder](INFO): Powering down 2024-05-24T20:52:43.630Z,1716583963.630 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2024-05-24T20:52:43.631Z,1716583963.631 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2024-05-24T20:52:43.631Z,1716583963.631 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2024-05-24T20:52:43.631Z,1716583963.631 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock 2024-05-24T20:52:43.632Z,1716583963.632 [DefaultWithUndock] Stopped 2024-05-24T20:52:43.632Z,1716583963.632 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock 2024-05-24T20:52:43.632Z,1716583963.632 [DefaultWithUndock:LeaveDock] Stopped 2024-05-24T20:52:43.632Z,1716583963.632 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2024-05-24T20:52:43.632Z,1716583963.632 [DefaultWithUndock:LeaveDock:A.] Stopped 2024-05-24T20:52:43.632Z,1716583963.632 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2024-05-24T20:52:43.632Z,1716583963.632 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2024-05-24T20:52:43.639Z,1716583963.639 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2024-05-24T20:52:43.639Z,1716583963.639 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2024-05-24T20:52:43.640Z,1716583963.640 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2024-05-24T20:52:43.640Z,1716583963.640 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2024-05-24T20:52:43.641Z,1716583963.641 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2024-05-24T20:52:43.641Z,1716583963.641 [BuoyancyServo](INFO): Powering down 2024-05-24T20:52:43.772Z,1716583963.772 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2024-05-24T20:52:43.772Z,1716583963.772 [ElevatorServo](INFO): Powering down 2024-05-24T20:52:43.773Z,1716583963.773 [DockingStepper](DEBUG): Uninitialize Docking Stepper. 2024-05-24T20:52:43.773Z,1716583963.773 [DockingStepper](INFO): Powering down 2024-05-24T20:52:43.774Z,1716583963.774 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-05-24T20:52:43.774Z,1716583963.774 [MassServo](INFO): Powering down 2024-05-24T20:52:43.775Z,1716583963.775 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2024-05-24T20:52:43.775Z,1716583963.775 [RudderServo](INFO): Powering down 2024-05-24T20:52:43.776Z,1716583963.776 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2024-05-24T20:52:43.776Z,1716583963.776 [ThrusterServo](INFO): Powering down 2024-05-24T20:52:43.777Z,1716583963.777 [SBIT](DEBUG): Uninitialize SBIT Component. 2024-05-24T20:52:43.777Z,1716583963.777 [IBIT](DEBUG): Uninitialize IBIT Component. 2024-05-24T20:52:43.778Z,1716583963.778 [CBIT](DEBUG): Uninitialize CBIT Component. 2024-05-24T20:52:43.778Z,1716583963.778 [CBIT](DEBUG): Powering off loads. 2024-05-24T20:52:43.788Z,1716583963.788 [CBIT](DEBUG): Disabling WDT. 2024-05-24T20:52:43.800Z,1716583963.800 [CBIT](DEBUG): Opening all GF detection circuits. 2024-05-24T20:52:43.801Z,1716583963.801 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.866Z,1716583963.866 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.873Z,1716583963.873 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.875Z,1716583963.875 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.880Z,1716583963.880 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:43.923Z,1716583963.923 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:44.218Z,1716583964.218 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:44.220Z,1716583964.220 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:44.225Z,1716583964.225 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:44.233Z,1716583964.233 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-24T20:52:44.297Z,1716583964.297 [logger ThreadHandler](INFO): Thread cancelled.