2024-05-29T15:35:16.302Z,1716996916.302 [Supervisor](DEBUG): Initializing supervisor. 2024-05-29T15:35:16.307Z,1716996916.307 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-05-29T15:35:16.308Z,1716996916.308 [SyncHandler](INFO): Protected caller Thread ID is 840 2024-05-29T15:35:16.308Z,1716996916.308 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-05-29T15:35:16.311Z,1716996916.311 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-05-29T15:35:16.311Z,1716996916.311 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 841 2024-05-29T15:35:16.320Z,1716996916.320 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-05-29T15:35:16.358Z,1716996916.358 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-05-29T15:35:16.360Z,1716996916.360 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-05-29T15:35:16.361Z,1716996916.361 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 842 2024-05-29T15:35:16.370Z,1716996916.370 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-05-29T15:35:16.372Z,1716996916.372 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-05-29T15:35:16.373Z,1716996916.373 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 843 2024-05-29T15:35:16.377Z,1716996916.377 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-05-29T15:35:16.379Z,1716996916.379 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-05-29T15:35:16.380Z,1716996916.380 [logger ThreadHandler](INFO): Protected caller Thread ID is 844 2024-05-29T15:35:16.388Z,1716996916.388 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-05-29T15:35:16.389Z,1716996916.389 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-05-29T15:35:16.394Z,1716996916.394 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-05-29T15:35:16.598Z,1716996916.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-05-29T15:35:16.600Z,1716996916.600 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-05-29T15:35:17.769Z,1716996917.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-05-29T15:35:17.869Z,1716996917.869 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-05-29T15:35:18.216Z,1716996918.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-05-29T15:35:18.217Z,1716996918.217 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-05-29T15:35:18.308Z,1716996918.308 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-05-29T15:35:18.451Z,1716996918.451 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-05-29T15:35:18.451Z,1716996918.451 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-05-29T15:35:18.544Z,1716996918.544 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-05-29T15:35:18.663Z,1716996918.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-05-29T15:35:18.665Z,1716996918.665 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-05-29T15:35:19.075Z,1716996919.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-05-29T15:35:19.077Z,1716996919.077 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-05-29T15:35:19.628Z,1716996919.628 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-05-29T15:35:19.630Z,1716996919.630 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-05-29T15:35:19.863Z,1716996919.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-05-29T15:35:19.865Z,1716996919.865 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-05-29T15:35:20.064Z,1716996920.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-05-29T15:35:20.065Z,1716996920.065 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-05-29T15:35:20.616Z,1716996920.616 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-05-29T15:35:20.617Z,1716996920.617 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-05-29T15:35:20.923Z,1716996920.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-05-29T15:35:20.925Z,1716996920.925 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-05-29T15:35:21.169Z,1716996921.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-05-29T15:35:21.170Z,1716996921.170 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-05-29T15:35:21.561Z,1716996921.561 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-05-29T15:35:21.563Z,1716996921.563 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-05-29T15:35:21.927Z,1716996921.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-05-29T15:35:21.929Z,1716996921.929 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2024-05-29T15:35:21.931Z,1716996921.931 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2024-05-29T15:35:22.027Z,1716996922.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2024-05-29T15:35:22.203Z,1716996922.203 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/workSite.cfg 2024-05-29T15:35:22.311Z,1716996922.311 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2024-05-29T15:35:22.430Z,1716996922.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2024-05-29T15:35:22.635Z,1716996922.635 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2024-05-29T15:35:22.742Z,1716996922.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2024-05-29T15:35:22.876Z,1716996922.876 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2024-05-29T15:35:23.617Z,1716996923.617 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-05-29T15:35:23.618Z,1716996923.618 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2024-05-29T15:35:23.724Z,1716996923.724 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2024-05-29T15:35:23.828Z,1716996923.828 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2024-05-29T15:35:23.981Z,1716996923.981 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2024-05-29T15:35:24.099Z,1716996924.099 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2024-05-29T15:35:24.114Z,1716996924.114 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-05-29T15:35:24.253Z,1716996924.253 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-05-29T15:35:24.253Z,1716996924.253 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-05-29T15:35:24.323Z,1716996924.323 [VerticalControl](DEBUG): Construct VerticalControl. 2024-05-29T15:35:24.384Z,1716996924.384 [VerticalControl] Loaded 2024-05-29T15:35:24.385Z,1716996924.385 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-05-29T15:35:24.387Z,1716996924.387 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-05-29T15:35:24.435Z,1716996924.435 [HorizontalControl] Loaded 2024-05-29T15:35:24.435Z,1716996924.435 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-05-29T15:35:24.438Z,1716996924.438 [SpeedControl](DEBUG): Construct SpeedControl. 2024-05-29T15:35:24.441Z,1716996924.441 [SpeedControl] Loaded 2024-05-29T15:35:24.441Z,1716996924.441 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-05-29T15:35:24.444Z,1716996924.444 [LoopControl](DEBUG): Construct LoopControl. 2024-05-29T15:35:24.444Z,1716996924.444 [LoopControl] Loaded 2024-05-29T15:35:24.444Z,1716996924.444 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-05-29T15:35:24.445Z,1716996924.445 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-05-29T15:35:24.445Z,1716996924.445 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-05-29T15:35:24.514Z,1716996924.514 [DepthRateCalculator] Loaded 2024-05-29T15:35:24.514Z,1716996924.514 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-05-29T15:35:24.519Z,1716996924.519 [PitchRateCalculator] Loaded 2024-05-29T15:35:24.519Z,1716996924.519 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-05-29T15:35:24.529Z,1716996924.529 [SpeedCalculator] Loaded 2024-05-29T15:35:24.529Z,1716996924.529 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-05-29T15:35:24.533Z,1716996924.533 [YawRateCalculator] Loaded 2024-05-29T15:35:24.534Z,1716996924.534 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-05-29T15:35:24.552Z,1716996924.552 [ElevatorOffsetCalculator] Loaded 2024-05-29T15:35:24.552Z,1716996924.552 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-05-29T15:35:24.553Z,1716996924.553 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-05-29T15:35:24.553Z,1716996924.553 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-05-29T15:35:24.596Z,1716996924.596 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-05-29T15:35:24.596Z,1716996924.596 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-05-29T15:35:24.677Z,1716996924.677 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-05-29T15:35:24.678Z,1716996924.678 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-05-29T15:35:25.065Z,1716996925.065 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-05-29T15:35:25.066Z,1716996925.066 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-05-29T15:35:25.273Z,1716996925.273 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-05-29T15:35:25.274Z,1716996925.274 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-05-29T15:35:26.048Z,1716996926.048 [AHRS_M2] Loaded 2024-05-29T15:35:26.048Z,1716996926.048 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-05-29T15:35:26.301Z,1716996926.301 [BackseatComponent] Loaded 2024-05-29T15:35:26.301Z,1716996926.301 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2024-05-29T15:35:26.302Z,1716996926.302 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409C34E0 2024-05-29T15:35:26.302Z,1716996926.302 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 929 2024-05-29T15:35:26.305Z,1716996926.305 [LcmUniversalReporter] Loaded 2024-05-29T15:35:26.306Z,1716996926.306 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2024-05-29T15:35:27.113Z,1716996927.113 [BPC1] Loaded 2024-05-29T15:35:27.113Z,1716996927.113 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-05-29T15:35:27.255Z,1716996927.255 [DataOverHttps] Loaded 2024-05-29T15:35:27.255Z,1716996927.255 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-05-29T15:35:27.256Z,1716996927.256 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409F34E0 2024-05-29T15:35:27.256Z,1716996927.256 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 930 2024-05-29T15:35:27.280Z,1716996927.280 [Depth_Keller] Loaded 2024-05-29T15:35:27.280Z,1716996927.280 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-05-29T15:35:27.285Z,1716996927.285 [DropWeight] Loaded 2024-05-29T15:35:27.285Z,1716996927.285 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-05-29T15:35:27.348Z,1716996927.348 [NAL9602] Loaded 2024-05-29T15:35:27.348Z,1716996927.348 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-05-29T15:35:27.378Z,1716996927.378 [Onboard] Loaded 2024-05-29T15:35:27.378Z,1716996927.378 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-05-29T15:35:27.379Z,1716996927.379 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A234E0 2024-05-29T15:35:27.380Z,1716996927.380 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 931 2024-05-29T15:35:27.394Z,1716996927.394 [Power24vConverter] Loaded 2024-05-29T15:35:27.394Z,1716996927.394 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-05-29T15:35:27.409Z,1716996927.409 [Radio_Surface] Loaded 2024-05-29T15:35:27.409Z,1716996927.409 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-05-29T15:35:27.410Z,1716996927.410 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A534E0 2024-05-29T15:35:27.411Z,1716996927.411 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 932 2024-05-29T15:35:27.457Z,1716996927.457 [RDI_Pathfinder] Loaded 2024-05-29T15:35:27.457Z,1716996927.457 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2024-05-29T15:35:27.551Z,1716996927.551 [DAT] Loaded 2024-05-29T15:35:27.552Z,1716996927.552 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-05-29T15:35:27.553Z,1716996927.553 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A834E0 2024-05-29T15:35:27.553Z,1716996927.553 [DAT ThreadHandler](INFO): Protected caller Thread ID is 933 2024-05-29T15:35:27.554Z,1716996927.554 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-05-29T15:35:27.554Z,1716996927.554 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-05-29T15:35:27.689Z,1716996927.689 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-05-29T15:35:27.690Z,1716996927.690 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-05-29T15:35:27.703Z,1716996927.703 [NavChart] Loaded 2024-05-29T15:35:27.704Z,1716996927.704 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-05-29T15:35:27.709Z,1716996927.709 [UniversalFixResidualReporter] Loaded 2024-05-29T15:35:27.709Z,1716996927.709 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-05-29T15:35:27.710Z,1716996927.710 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-05-29T15:35:27.712Z,1716996927.712 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-05-29T15:35:27.877Z,1716996927.877 [SBIT](DEBUG): Construct Startup Built In Test. 2024-05-29T15:35:27.886Z,1716996927.886 [SBIT] Loaded 2024-05-29T15:35:27.887Z,1716996927.887 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-05-29T15:35:27.890Z,1716996927.890 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-05-29T15:35:27.902Z,1716996927.902 [IBIT] Loaded 2024-05-29T15:35:27.903Z,1716996927.903 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-05-29T15:35:27.908Z,1716996927.908 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-05-29T15:35:28.013Z,1716996928.013 [CBIT] Loaded 2024-05-29T15:35:28.013Z,1716996928.013 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-05-29T15:35:28.014Z,1716996928.014 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-05-29T15:35:28.014Z,1716996928.014 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-05-29T15:35:28.534Z,1716996928.534 [BuoyancyServo] Loaded 2024-05-29T15:35:28.534Z,1716996928.534 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-05-29T15:35:28.557Z,1716996928.557 [ElevatorServo] Loaded 2024-05-29T15:35:28.557Z,1716996928.557 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-05-29T15:35:28.589Z,1716996928.589 [DockingStepper] Loaded 2024-05-29T15:35:28.589Z,1716996928.589 [ComponentRegistry](DEBUG): SyncComponent "DockingStepper" handled in the control thread. 2024-05-29T15:35:28.611Z,1716996928.611 [MassServo] Loaded 2024-05-29T15:35:28.612Z,1716996928.612 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-05-29T15:35:28.632Z,1716996928.632 [RudderServo] Loaded 2024-05-29T15:35:28.632Z,1716996928.632 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-05-29T15:35:28.651Z,1716996928.651 [ThrusterServo] Loaded 2024-05-29T15:35:28.651Z,1716996928.651 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2024-05-29T15:35:28.652Z,1716996928.652 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-05-29T15:35:28.652Z,1716996928.652 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-05-29T15:35:28.667Z,1716996928.667 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-05-29T15:35:28.668Z,1716996928.668 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-05-29T15:35:28.892Z,1716996928.892 [CTD_Seabird] Loaded 2024-05-29T15:35:28.893Z,1716996928.893 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-05-29T15:35:28.894Z,1716996928.894 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BD74E0 2024-05-29T15:35:28.894Z,1716996928.894 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 934 2024-05-29T15:35:28.917Z,1716996928.917 [PAR_Licor] Loaded 2024-05-29T15:35:28.917Z,1716996928.917 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-05-29T15:35:28.961Z,1716996928.961 [WetLabsBB2FL] Loaded 2024-05-29T15:35:28.961Z,1716996928.961 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-05-29T15:35:28.962Z,1716996928.962 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C074E0 2024-05-29T15:35:28.963Z,1716996928.963 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 935 2024-05-29T15:35:28.984Z,1716996928.984 [WetLabsUBAT] Loaded 2024-05-29T15:35:28.984Z,1716996928.984 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2024-05-29T15:35:28.985Z,1716996928.985 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40C374E0 2024-05-29T15:35:28.985Z,1716996928.985 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 936 2024-05-29T15:35:28.986Z,1716996928.986 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-05-29T15:35:28.992Z,1716996928.992 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-05-29T15:35:28.995Z,1716996928.995 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-05-29T15:35:29.006Z,1716996929.006 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-05-29T15:35:29.007Z,1716996929.007 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C674E0 2024-05-29T15:35:29.008Z,1716996929.008 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 937 2024-05-29T15:35:29.012Z,1716996929.012 [Supervisor](INFO): Main Thread ID is 831 2024-05-29T15:35:29.012Z,1716996929.012 [Supervisor](DEBUG): Running supervisor. 2024-05-29T15:35:29.013Z,1716996929.013 [CommandExec ThreadHandler](INFO): Handler Thread ID is 938 2024-05-29T15:35:29.013Z,1716996929.013 [CommandExec](INFO): Initializing the command executive. 2024-05-29T15:35:29.015Z,1716996929.015 [CommandLine ThreadHandler](INFO): Handler Thread ID is 939 2024-05-29T15:35:29.017Z,1716996929.017 [controlThread ThreadHandler](INFO): Handler Thread ID is 940 2024-05-29T15:35:29.017Z,1716996929.017 [controlThread](DEBUG): Initializing ControlThread 2024-05-29T15:35:29.018Z,1716996929.018 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-05-29T15:35:29.020Z,1716996929.020 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-05-29T15:35:29.020Z,1716996929.020 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-05-29T15:35:29.021Z,1716996929.021 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-05-29T15:35:29.021Z,1716996929.021 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-05-29T15:35:29.022Z,1716996929.022 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-05-29T15:35:29.022Z,1716996929.022 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-05-29T15:35:29.022Z,1716996929.022 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-05-29T15:35:29.022Z,1716996929.022 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-05-29T15:35:29.028Z,1716996929.028 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-05-29T15:35:29.028Z,1716996929.028 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-05-29T15:35:29.029Z,1716996929.029 [SBIT](INFO): Initialize SBIT Component. 2024-05-29T15:35:29.029Z,1716996929.029 [SBIT](IMPORTANT): git: 2024-05-22-2-gd2983461b 2024-05-29T15:35:29.029Z,1716996929.029 [SBIT](INFO): git hash: d2983461b0afca1bb4c5ae8a9b5bc51c90c2e86f 2024-05-29T15:35:29.030Z,1716996929.030 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-05-29T15:35:29.031Z,1716996929.031 [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-29T15:35:29.032Z,1716996929.032 [SBIT](INFO): Beginning SBIT in 139.000000 seconds. 2024-05-29T15:35:29.032Z,1716996929.032 [IBIT](INFO): Initialize IBIT Component. 2024-05-29T15:35:29.033Z,1716996929.033 [CBIT](DEBUG): Initialize CBIT Component. 2024-05-29T15:35:29.034Z,1716996929.034 [logger ThreadHandler](INFO): Handler Thread ID is 941 2024-05-29T15:35:29.046Z,1716996929.046 [CBIT](DEBUG): Initialized mux pins. 2024-05-29T15:35:29.046Z,1716996929.046 [CBIT](DEBUG): Initializing the watchdog timer. 2024-05-29T15:35:29.054Z,1716996929.054 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 942 2024-05-29T15:35:29.066Z,1716996929.066 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 943 2024-05-29T15:35:29.068Z,1716996929.068 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-05-29T15:35:29.070Z,1716996929.070 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-05-29T15:35:29.070Z,1716996929.070 [CBIT](DEBUG): Initializing heartbeat. 2024-05-29T15:35:29.078Z,1716996929.078 [Onboard ThreadHandler](INFO): Handler Thread ID is 944 2024-05-29T15:35:29.095Z,1716996929.095 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 945 2024-05-29T15:35:29.114Z,1716996929.114 [DAT ThreadHandler](INFO): Handler Thread ID is 946 2024-05-29T15:35:29.115Z,1716996929.115 [DAT](INFO): Powering up 2024-05-29T15:35:29.115Z,1716996929.115 [DAT](DEBUG): Initializing DAT. 2024-05-29T15:35:29.119Z,1716996929.119 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 948 2024-05-29T15:35:29.120Z,1716996929.120 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-05-29T15:35:29.123Z,1716996929.123 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 950 2024-05-29T15:35:29.126Z,1716996929.126 [WetLabsBB2FL](INFO): Powering up 2024-05-29T15:35:29.127Z,1716996929.127 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 952 2024-05-29T15:35:29.130Z,1716996929.130 [WetLabsUBAT](INFO): Powering up 2024-05-29T15:35:29.132Z,1716996929.132 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 954 2024-05-29T15:35:29.140Z,1716996929.140 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-05-29T15:35:29.140Z,1716996929.140 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-05-29T15:35:29.140Z,1716996929.140 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-05-29T15:35:29.140Z,1716996929.140 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-05-29T15:35:29.141Z,1716996929.141 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-05-29T15:35:29.141Z,1716996929.141 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-05-29T15:35:29.141Z,1716996929.141 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-05-29T15:35:29.141Z,1716996929.141 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-05-29T15:35:29.142Z,1716996929.142 [CBIT](DEBUG): Deactivating GF circuits. 2024-05-29T15:35:29.142Z,1716996929.142 [CBIT](DEBUG): Deactivating emergency mode. 2024-05-29T15:35:29.182Z,1716996929.182 [CBIT](DEBUG): Backplane powered. 2024-05-29T15:35:29.186Z,1716996929.186 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-05-29T15:35:29.187Z,1716996929.187 [MissionManager](INFO): Loading Mission from file: Missions/underIce/StartupUnder.tl 2024-05-29T15:35:29.187Z,1716996929.187 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/StartupUnder.tl 2024-05-29T15:35:29.196Z,1716996929.196 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/StartupUnder.tl 2024-05-29T15:35:29.214Z,1716996929.214 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/StartupUnder.tl translated into: 2024-05-29T15:35:29.215Z,1716996929.215 [MissionManager](ERROR): Top node has no child nodes: Mission 2024-05-29T15:35:29.215Z,1716996929.215 [MissionManager](ERROR): Could not load startup mission. 2024-05-29T15:35:29.215Z,1716996929.215 [MissionManager](INFO): Loading Mission from file: Missions/underIce/DefaultWithUndock.tl 2024-05-29T15:35:29.215Z,1716996929.215 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/DefaultWithUndock.tl 2024-05-29T15:35:29.219Z,1716996929.219 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/DefaultWithUndock.tl 2024-05-29T15:35:29.506Z,1716996929.506 [Radio_Surface](INFO): Powering up 2024-05-29T15:35:29.706Z,1716996929.706 [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-29T15:35:29.713Z,1716996929.713 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min 2024-05-29T15:35:29.733Z,1716996929.733 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 30.000000 min 2024-05-29T15:35:29.737Z,1716996929.737 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 201 count 2024-05-29T15:35:29.756Z,1716996929.756 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 2.500000 s 2024-05-29T15:35:29.760Z,1716996929.760 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count 2024-05-29T15:35:29.761Z,1716996929.761 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait. 2024-05-29T15:35:29.930Z,1716996929.930 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct. 2024-05-29T15:35:29.930Z,1716996929.930 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2024-05-29T15:35:29.962Z,1716996929.962 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-05-29T15:35:30.007Z,1716996930.007 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-05-29T15:35:30.009Z,1716996930.009 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-05-29T15:35:30.031Z,1716996930.031 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute. 2024-05-29T15:35:30.035Z,1716996930.035 [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-29T15:35:30.054Z,1716996930.054 [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-29T15:35:30.061Z,1716996930.061 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-05-29T15:35:30.223Z,1716996930.223 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993022 m 2024-05-29T15:35:30.224Z,1716996930.224 [Power24vConverter](INFO): Powering up. 2024-05-29T15:35:30.225Z,1716996930.225 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2024-05-29T15:35:30.233Z,1716996930.233 [DepthRateCalculator](ERROR): Depth measurement is not active 2024-05-29T15:35:30.259Z,1716996930.259 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-05-29T15:35:30.266Z,1716996930.266 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-05-29T15:35:30.267Z,1716996930.267 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-05-29T15:35:30.274Z,1716996930.274 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-05-29T15:35:30.275Z,1716996930.275 [DockingStepper](INFO): Start 2024-05-29T15:35:30.275Z,1716996930.275 [DockingStepper](DEBUG): Initializing EZServoServo. 2024-05-29T15:35:30.282Z,1716996930.282 [DockingStepper](DEBUG): Initializing DockingStepper. 2024-05-29T15:35:30.283Z,1716996930.283 [MassServo](DEBUG): Initializing EZServoServo. 2024-05-29T15:35:30.290Z,1716996930.290 [MassServo](DEBUG): Initializing MassServo. 2024-05-29T15:35:30.291Z,1716996930.291 [RudderServo](DEBUG): Initializing EZServoServo. 2024-05-29T15:35:30.298Z,1716996930.298 [RudderServo](DEBUG): Initializing RudderServo. 2024-05-29T15:35:30.299Z,1716996930.299 [ThrusterServo](DEBUG): Initializing EZServoServo. 2024-05-29T15:35:30.306Z,1716996930.306 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2024-05-29T15:35:30.534Z,1716996930.534 [DockingStepper](INFO): Starting 2024-05-29T15:35:30.890Z,1716996930.890 [DockingStepper](INFO): Starting 2024-05-29T15:35:31.434Z,1716996931.434 [DockingStepper](INFO): Starting 2024-05-29T15:35:31.482Z,1716996931.482 [DockingStepper](INFO): Init string: /1z14847aE13561N3m50 2024-05-29T15:35:31.739Z,1716996931.739 [DockingStepper](INFO): Starting 2024-05-29T15:35:31.770Z,1716996931.770 [WetLabsBB2FL](INFO): Powering down 2024-05-29T15:35:32.122Z,1716996932.122 [DockingStepper](INFO): Starting 2024-05-29T15:35:32.525Z,1716996932.525 [DockingStepper](INFO): Starting 2024-05-29T15:35:32.978Z,1716996932.978 [DockingStepper](INFO): Starting 2024-05-29T15:35:33.002Z,1716996933.002 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2024-05-29T15:35:33.442Z,1716996933.442 [DockingStepper](INFO): Starting 2024-05-29T15:35:34.209Z,1716996934.209 [DockingStepper](INFO): Pause 2024-05-29T15:35:36.150Z,1716996936.150 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2024-05-29T15:35:38.446Z,1716996938.446 [WetLabsUBAT](INFO): Powering down 2024-05-29T15:35:43.226Z,1716996943.226 [DAT](INFO): DAT read: 2024-05-29T15:35:43.227Z,1716996943.227 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-05-29T15:35:44.740Z,1716996944.740 [DAT](INFO): DAT read: MF Frequency Band 2024-05-29T15:35:44.743Z,1716996944.743 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.17.2 2024-05-29T15:35:44.744Z,1716996944.744 [DAT](INFO): DAT read: May 29 2024 15:29:10 2024-05-29T15:35:45.999Z,1716996945.999 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-05-29T15:35:46.001Z,1716996946.001 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2024-05-29T15:35:46.001Z,1716996946.001 [DAT](INFO): commRate: 800 2024-05-29T15:35:48.066Z,1716996948.066 [DAT](INFO): entering command mode 2024-05-29T15:35:48.266Z,1716996948.266 [DAT](INFO): DAT read: 2024-05-29T15:35:48.267Z,1716996948.267 [DAT](INFO): DAT read: user:1> 2024-05-29T15:35:48.267Z,1716996948.267 [DAT](INFO): setting verbose to 3 2024-05-29T15:35:48.518Z,1716996948.518 [DAT](INFO): DAT read: user:1> 2024-05-29T15:35:48.519Z,1716996948.519 [DAT](INFO): DAT read: Verbose | 3 2024-05-29T15:35:48.520Z,1716996948.520 [DAT](INFO): set verbose to 3 2024-05-29T15:35:48.520Z,1716996948.520 [DAT](INFO): setting DatVerbose to 27440 2024-05-29T15:35:48.771Z,1716996948.771 [DAT](INFO): DAT read: user:2> 2024-05-29T15:35:48.772Z,1716996948.772 [DAT](INFO): DAT read: DatVerbose | 27440 2024-05-29T15:35:48.772Z,1716996948.772 [DAT](INFO): set DatVerbose to 27440 2024-05-29T15:35:48.773Z,1716996948.773 [DAT](INFO): setting transmit power to 8 2024-05-29T15:35:49.022Z,1716996949.022 [DAT](INFO): DAT read: user:3> 2024-05-29T15:35:49.023Z,1716996949.023 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-05-29T15:35:49.024Z,1716996949.024 [DAT](INFO): set transmit power to 8 2024-05-29T15:35:49.024Z,1716996949.024 [DAT](INFO): setting local address to 10 2024-05-29T15:35:49.274Z,1716996949.274 [DAT](INFO): DAT read: user:4> 2024-05-29T15:35:49.275Z,1716996949.275 [DAT](INFO): DAT read: LocalAddr | 10 2024-05-29T15:35:49.275Z,1716996949.275 [DAT](INFO): set local address to 10 2024-05-29T15:35:49.277Z,1716996949.277 [DAT](INFO): Setting time to: 15:35:49 And date to:5/29/2024 2024-05-29T15:35:49.526Z,1716996949.526 [DAT](INFO): DAT read: user:5> 2024-05-29T15:35:49.527Z,1716996949.527 [DAT](INFO): DAT read: Wed May 29, 2024 15:35:49 2024-05-29T15:35:49.528Z,1716996949.528 [DAT](INFO): Local DAT time set to Wed May 29, 2024 15:35:49 2024-05-29T15:35:57.575Z,1716996957.575 [NAL9602](INFO): Powering up NAL9602 2024-05-29T15:36:08.483Z,1716996968.483 [NAL9602](INFO): NAL9602 initialized 2024-05-29T15:37:48.718Z,1716997068.718 [SBIT](IMPORTANT): Beginning Startup BIT 2024-05-29T15:37:48.722Z,1716997068.722 [CBIT](IMPORTANT): Beginning ground fault scan 2024-05-29T15:37:56.752Z,1716997076.752 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:37:59.635Z,1716997079.635 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.014643 CHAN A1 (24V): 0.004061 CHAN A2 (12V): -0.006108 CHAN A3 (5V): -0.001487 CHAN B0 (3.3V): 0.001100 CHAN B1 (3.15aV): -0.000528 CHAN B2 (3.15bV): -0.000023 CHAN B3 (GND): 0.001170 OPEN: -0.003914 Full Scale: +/- 1 mA 2024-05-29T15:38:10.078Z,1716997090.078 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:38:10.364Z,1716997090.364 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004694 2024-05-29T15:38:23.411Z,1716997103.411 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:38:29.082Z,1716997109.082 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-05-29T15:38:29.082Z,1716997109.082 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-05-29T15:38:29.092Z,1716997109.092 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-05-29T15:38:29.500Z,1716997109.500 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-05-29T15:38:29.501Z,1716997109.501 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-05-29T15:38:36.743Z,1716997116.743 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:38:42.845Z,1716997122.845 [SBIT](IMPORTANT): SBIT PASSED 2024-05-29T15:38:42.845Z,1716997122.845 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-05-29T15:38:42.847Z,1716997122.847 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2024-05-29T15:38:42.847Z,1716997122.847 [SBIT](IMPORTANT): Docked.detachTimeout=8 hour; 2024-05-29T15:38:42.847Z,1716997122.847 [SBIT](IMPORTANT): DockingStepper.closedValue=16500 count; 2024-05-29T15:38:42.847Z,1716997122.847 [SBIT](IMPORTANT): DockingStepper.loadAtStartup=1 bool; 2024-05-29T15:38:42.847Z,1716997122.847 [SBIT](IMPORTANT): DockingStepper.openValue=7500 count; 2024-05-29T15:38:42.850Z,1716997122.850 [SBIT](IMPORTANT): DockingStepper.simulateHardware=0 bool; 2024-05-29T15:38:42.850Z,1716997122.850 [SBIT](IMPORTANT): DockingStepper.slideValue=12000 count; 2024-05-29T15:38:42.850Z,1716997122.850 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2024-05-29T15:38:42.850Z,1716997122.850 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool; 2024-05-29T15:38:42.850Z,1716997122.850 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=300 cubic_centimeter; 2024-05-29T15:38:42.851Z,1716997122.851 [SBIT](IMPORTANT): VerticalControl.massDefault=30 millimeter; 2024-05-29T15:38:43.260Z,1716997123.260 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2024-05-29T15:38:43.260Z,1716997123.260 [DefaultWithUndock] Running Loop=1 2024-05-29T15:38:43.260Z,1716997123.260 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2024-05-29T15:38:43.261Z,1716997123.261 [DefaultWithUndock:A.Wait] Running Loop=1 2024-05-29T15:38:43.261Z,1716997123.261 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2024-05-29T15:38:49.278Z,1716997129.278 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:39:01.793Z,1716997141.793 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:39:13.559Z,1716997153.559 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2024-05-29T15:39:13.559Z,1716997153.559 [DefaultWithUndock:A.Wait] Stopped 2024-05-29T15:39:13.559Z,1716997153.559 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2024-05-29T15:39:13.559Z,1716997153.559 [DefaultWithUndock:LeaveDock] Running Loop=1 2024-05-29T15:39:13.559Z,1716997153.559 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2024-05-29T15:39:13.559Z,1716997153.559 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2024-05-29T15:39:13.559Z,1716997153.559 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2024-05-29T15:39:13.560Z,1716997153.560 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2024-05-29T15:39:13.560Z,1716997153.560 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2024-05-29T15:39:13.560Z,1716997153.560 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2024-05-29T15:39:13.988Z,1716997153.988 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2024-05-29T15:39:14.008Z,1716997154.008 [DockingStepper](INFO): Resume 2024-05-29T15:39:14.315Z,1716997154.315 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:39:14.382Z,1716997154.382 [DockingStepper](INFO): Resuming 2024-05-29T15:39:14.752Z,1716997154.752 [DockingStepper](INFO): Start 2024-05-29T15:39:14.752Z,1716997154.752 [DockingStepper](DEBUG): Initializing EZServoServo. 2024-05-29T15:39:14.866Z,1716997154.866 [DockingStepper](DEBUG): Initializing DockingStepper. 2024-05-29T15:39:15.160Z,1716997155.160 [DockingStepper](INFO): Starting 2024-05-29T15:39:15.587Z,1716997155.587 [DockingStepper](INFO): Starting 2024-05-29T15:39:16.015Z,1716997156.015 [DockingStepper](INFO): Starting 2024-05-29T15:39:16.066Z,1716997156.066 [DockingStepper](INFO): Init string: /1z14832aE13561N3m50 2024-05-29T15:39:16.351Z,1716997156.351 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:16.371Z,1716997156.371 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:16.371Z,1716997156.371 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:16.372Z,1716997156.372 [DAT](INFO): setting remote address to 0 2024-05-29T15:39:16.382Z,1716997156.382 [DockingStepper](INFO): Starting 2024-05-29T15:39:16.622Z,1716997156.622 [DAT](INFO): DAT read: user:6> 2024-05-29T15:39:16.623Z,1716997156.623 [DAT](INFO): DAT read: RemoteAddr | 0 2024-05-29T15:39:16.623Z,1716997156.623 [DAT](INFO): set remote address to 0 2024-05-29T15:39:16.623Z,1716997156.623 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:16.624Z,1716997156.624 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:16.624Z,1716997156.624 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:16.798Z,1716997156.798 [DockingStepper](INFO): Starting 2024-05-29T15:39:16.874Z,1716997156.874 [DAT](INFO): DAT read: user:7> 2024-05-29T15:39:16.875Z,1716997156.875 [DAT](INFO): DAT read: Tx time:15:39:16.9328 2024-05-29T15:39:16.875Z,1716997156.875 [DAT](INFO): Ping request sent. 2024-05-29T15:39:16.875Z,1716997156.875 [DAT](INFO): transmitted an acoustic signal 2024-05-29T15:39:16.875Z,1716997156.875 [DAT](INFO): publishing transmit ping time 2024-05-29T15:39:16.876Z,1716997156.876 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000903 2024-05-29T15:39:17.126Z,1716997157.126 [DAT](INFO): DAT read: TxSync time:15:39:16.9320 2024-05-29T15:39:17.127Z,1716997157.127 [DAT](INFO): unknown deviceResponse_: TxSync time:15:39:16.9320 2024-05-29T15:39:17.127Z,1716997157.127 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252036 2024-05-29T15:39:17.190Z,1716997157.190 [DockingStepper](INFO): Starting 2024-05-29T15:39:17.380Z,1716997157.380 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504730 2024-05-29T15:39:17.630Z,1716997157.630 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755084 2024-05-29T15:39:17.675Z,1716997157.675 [DockingStepper](INFO): Starting 2024-05-29T15:39:17.701Z,1716997157.701 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2024-05-29T15:39:17.882Z,1716997157.882 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006990 2024-05-29T15:39:17.998Z,1716997157.998 [DockingStepper](INFO): Starting 2024-05-29T15:39:18.134Z,1716997158.134 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259309 2024-05-29T15:39:18.386Z,1716997158.386 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510866 2024-05-29T15:39:18.442Z,1716997158.442 [DockingStepper](INFO): Changing to mode: 3 2024-05-29T15:39:18.443Z,1716997158.443 [DockingStepper](INFO): Detach mode. 2024-05-29T15:39:18.505Z,1716997158.505 [DockingStepper](INFO): Commanding negative:45136 2024-05-29T15:39:18.639Z,1716997158.639 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763295 2024-05-29T15:39:18.894Z,1716997158.894 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.017739 2024-05-29T15:39:19.142Z,1716997159.142 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266967 2024-05-29T15:39:19.194Z,1716997159.194 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:19.396Z,1716997159.396 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.520812 2024-05-29T15:39:19.647Z,1716997159.647 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771196 2024-05-29T15:39:19.898Z,1716997159.898 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022951 2024-05-29T15:39:20.150Z,1716997160.150 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274966 2024-05-29T15:39:20.402Z,1716997160.402 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526939 2024-05-29T15:39:20.655Z,1716997160.655 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.779769 2024-05-29T15:39:20.906Z,1716997160.906 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030955 2024-05-29T15:39:21.158Z,1716997161.158 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282963 2024-05-29T15:39:21.414Z,1716997161.414 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.538389 2024-05-29T15:39:21.662Z,1716997161.662 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.787069 2024-05-29T15:39:21.745Z,1716997161.745 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:21.914Z,1716997161.914 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038990 2024-05-29T15:39:22.166Z,1716997162.166 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.291250 2024-05-29T15:39:22.418Z,1716997162.418 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542939 2024-05-29T15:39:22.670Z,1716997162.670 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.795303 2024-05-29T15:39:22.922Z,1716997162.922 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.047226 2024-05-29T15:39:23.175Z,1716997163.175 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.299839 2024-05-29T15:39:23.428Z,1716997163.428 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.552782 2024-05-29T15:39:23.517Z,1716997163.517 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock. 2024-05-29T15:39:23.678Z,1716997163.678 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.803279 2024-05-29T15:39:23.892Z,1716997163.892 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2024-05-29T15:39:23.932Z,1716997163.932 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.056582 2024-05-29T15:39:24.182Z,1716997164.182 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306943 2024-05-29T15:39:24.304Z,1716997164.304 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:24.435Z,1716997164.435 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.559690 2024-05-29T15:39:24.690Z,1716997164.690 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.815396 2024-05-29T15:39:24.943Z,1716997164.943 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.067204 2024-05-29T15:39:25.195Z,1716997165.195 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.319524 2024-05-29T15:39:25.448Z,1716997165.448 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.572901 2024-05-29T15:39:25.699Z,1716997165.699 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.823415 2024-05-29T15:39:25.953Z,1716997165.953 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.077685 2024-05-29T15:39:26.202Z,1716997166.202 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.327008 2024-05-29T15:39:26.455Z,1716997166.455 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.579683 2024-05-29T15:39:26.706Z,1716997166.706 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.831234 2024-05-29T15:39:26.958Z,1716997166.958 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:26.958Z,1716997166.958 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:26.958Z,1716997166.958 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:27.094Z,1716997167.094 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:39:27.111Z,1716997167.111 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:27.213Z,1716997167.213 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:27.213Z,1716997167.213 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:27.214Z,1716997167.214 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:27.463Z,1716997167.463 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:27.464Z,1716997167.464 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:27.464Z,1716997167.464 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:27.714Z,1716997167.714 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:27.714Z,1716997167.714 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:27.714Z,1716997167.714 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:27.966Z,1716997167.966 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:27.966Z,1716997167.966 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:27.966Z,1716997167.966 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:28.218Z,1716997168.218 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:28.218Z,1716997168.218 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:28.218Z,1716997168.218 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:28.473Z,1716997168.473 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:28.474Z,1716997168.474 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:28.474Z,1716997168.474 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:28.722Z,1716997168.722 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:28.722Z,1716997168.722 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:28.722Z,1716997168.722 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:28.974Z,1716997168.974 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:28.974Z,1716997168.974 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:28.974Z,1716997168.974 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:29.227Z,1716997169.227 [DAT](INFO): DAT read: Response Not Received 2024-05-29T15:39:29.227Z,1716997169.227 [DAT](INFO): response not received 2024-05-29T15:39:29.227Z,1716997169.227 [DAT](INFO): DAT read: user:8> 2024-05-29T15:39:29.228Z,1716997169.228 [DAT](INFO): DAT read: Tx time:15:39:29.3829 2024-05-29T15:39:29.229Z,1716997169.229 [DAT](INFO): Ping request sent. 2024-05-29T15:39:29.229Z,1716997169.229 [DAT](INFO): transmitted an acoustic signal 2024-05-29T15:39:29.229Z,1716997169.229 [DAT](INFO): publishing transmit ping time 2024-05-29T15:39:29.230Z,1716997169.230 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001076 2024-05-29T15:39:29.478Z,1716997169.478 [DAT](INFO): DAT read: TxSync time:15:39:29.3821 2024-05-29T15:39:29.479Z,1716997169.479 [DAT](INFO): unknown deviceResponse_: TxSync time:15:39:29.3821 2024-05-29T15:39:29.479Z,1716997169.479 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250236 2024-05-29T15:39:29.734Z,1716997169.734 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504754 2024-05-29T15:39:29.964Z,1716997169.964 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:29.983Z,1716997169.983 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753701 2024-05-29T15:39:30.234Z,1716997170.234 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005200 2024-05-29T15:39:30.486Z,1716997170.486 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257472 2024-05-29T15:39:30.739Z,1716997170.739 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510486 2024-05-29T15:39:30.990Z,1716997170.990 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761172 2024-05-29T15:39:31.244Z,1716997171.244 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015185 2024-05-29T15:39:31.494Z,1716997171.494 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265222 2024-05-29T15:39:31.747Z,1716997171.747 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517439 2024-05-29T15:39:31.999Z,1716997171.999 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770524 2024-05-29T15:39:32.250Z,1716997172.250 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.021257 2024-05-29T15:39:32.502Z,1716997172.502 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.273143 2024-05-29T15:39:32.754Z,1716997172.754 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.525519 2024-05-29T15:39:32.771Z,1716997172.771 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:33.006Z,1716997173.006 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.777282 2024-05-29T15:39:33.258Z,1716997173.258 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.029250 2024-05-29T15:39:33.510Z,1716997173.510 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.281196 2024-05-29T15:39:33.762Z,1716997173.762 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.533655 2024-05-29T15:39:34.014Z,1716997174.014 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.785274 2024-05-29T15:39:34.266Z,1716997174.266 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.037471 2024-05-29T15:39:34.519Z,1716997174.519 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290174 2024-05-29T15:39:34.770Z,1716997174.770 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.541300 2024-05-29T15:39:35.022Z,1716997175.022 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.793486 2024-05-29T15:39:35.274Z,1716997175.274 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.045558 2024-05-29T15:39:35.526Z,1716997175.526 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.297308 2024-05-29T15:39:35.634Z,1716997175.634 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:35.782Z,1716997175.782 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.552613 2024-05-29T15:39:36.030Z,1716997176.030 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.801366 2024-05-29T15:39:36.282Z,1716997176.282 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.053192 2024-05-29T15:39:36.535Z,1716997176.535 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.305963 2024-05-29T15:39:36.786Z,1716997176.786 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.557406 2024-05-29T15:39:37.038Z,1716997177.038 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.809192 2024-05-29T15:39:37.290Z,1716997177.290 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.061156 2024-05-29T15:39:37.542Z,1716997177.542 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.313267 2024-05-29T15:39:37.794Z,1716997177.794 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.565143 2024-05-29T15:39:38.046Z,1716997178.046 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.817200 2024-05-29T15:39:38.298Z,1716997178.298 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.069267 2024-05-29T15:39:38.424Z,1716997178.424 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:38.550Z,1716997178.550 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.321178 2024-05-29T15:39:38.803Z,1716997178.803 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.573762 2024-05-29T15:39:39.055Z,1716997179.055 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.825828 2024-05-29T15:39:39.307Z,1716997179.307 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:39.307Z,1716997179.307 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:39.308Z,1716997179.308 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:39.558Z,1716997179.558 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:39.558Z,1716997179.558 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:39.558Z,1716997179.558 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:39.811Z,1716997179.811 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:39.811Z,1716997179.811 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:39.811Z,1716997179.811 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:40.062Z,1716997180.062 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:40.062Z,1716997180.062 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:40.062Z,1716997180.062 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:40.314Z,1716997180.314 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:40.314Z,1716997180.314 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:40.314Z,1716997180.314 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:40.566Z,1716997180.566 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:40.566Z,1716997180.566 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:40.567Z,1716997180.567 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:40.818Z,1716997180.818 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:40.818Z,1716997180.818 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:40.818Z,1716997180.818 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:40.830Z,1716997180.830 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:39:41.070Z,1716997181.070 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:41.070Z,1716997181.070 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:41.071Z,1716997181.071 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:41.271Z,1716997181.271 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:41.322Z,1716997181.322 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:41.322Z,1716997181.322 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:41.323Z,1716997181.323 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:41.574Z,1716997181.574 [DAT](INFO): DAT read: Response Not Received 2024-05-29T15:39:41.574Z,1716997181.574 [DAT](INFO): response not received 2024-05-29T15:39:41.575Z,1716997181.575 [DAT](INFO): DAT read: user:9> 2024-05-29T15:39:41.575Z,1716997181.575 [DAT](ERROR): No response from remote modem. 2024-05-29T15:39:41.575Z,1716997181.575 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:41.575Z,1716997181.575 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:41.576Z,1716997181.576 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:41.831Z,1716997181.831 [DAT](INFO): DAT read: Tx time:15:39:41.8331 2024-05-29T15:39:41.831Z,1716997181.831 [DAT](INFO): Ping request sent. 2024-05-29T15:39:41.831Z,1716997181.831 [DAT](INFO): transmitted an acoustic signal 2024-05-29T15:39:41.832Z,1716997181.832 [DAT](INFO): DAT read: TxSync time:15:39:41.8323 2024-05-29T15:39:41.832Z,1716997181.832 [DAT](INFO): unknown deviceResponse_: TxSync time:15:39:41.8323 2024-05-29T15:39:41.832Z,1716997181.832 [DAT](INFO): publishing transmit ping time 2024-05-29T15:39:41.833Z,1716997181.833 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001666 2024-05-29T15:39:42.079Z,1716997182.079 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.247721 2024-05-29T15:39:42.330Z,1716997182.330 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.498949 2024-05-29T15:39:42.584Z,1716997182.584 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753466 2024-05-29T15:39:42.834Z,1716997182.834 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.003013 2024-05-29T15:39:43.087Z,1716997183.087 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.255657 2024-05-29T15:39:43.338Z,1716997183.338 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.507091 2024-05-29T15:39:43.590Z,1716997183.590 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.759119 2024-05-29T15:39:43.843Z,1716997183.843 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.011378 2024-05-29T15:39:44.090Z,1716997184.090 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning docking module to standby. 2024-05-29T15:39:44.091Z,1716997184.091 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:44.094Z,1716997184.094 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.263365 2024-05-29T15:39:44.346Z,1716997184.346 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.515225 2024-05-29T15:39:44.539Z,1716997184.539 [DockingStepper](INFO): Changing to mode: 1 2024-05-29T15:39:44.539Z,1716997184.539 [DockingStepper](INFO): Standby mode. 2024-05-29T15:39:44.598Z,1716997184.598 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.767056 2024-05-29T15:39:44.601Z,1716997184.601 [DockingStepper](INFO): Commanding positive:54993 2024-05-29T15:39:44.850Z,1716997184.850 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.019310 2024-05-29T15:39:45.103Z,1716997185.103 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.271653 2024-05-29T15:39:45.354Z,1716997185.354 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.523098 2024-05-29T15:39:45.606Z,1716997185.606 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.775038 2024-05-29T15:39:45.859Z,1716997185.859 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.027725 2024-05-29T15:39:46.110Z,1716997186.110 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.279122 2024-05-29T15:39:46.363Z,1716997186.363 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.531982 2024-05-29T15:39:46.614Z,1716997186.614 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.783206 2024-05-29T15:39:46.866Z,1716997186.866 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.035089 2024-05-29T15:39:46.939Z,1716997186.939 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:47.118Z,1716997187.118 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.287114 2024-05-29T15:39:47.371Z,1716997187.371 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.539812 2024-05-29T15:39:47.622Z,1716997187.622 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.791049 2024-05-29T15:39:47.874Z,1716997187.874 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.043059 2024-05-29T15:39:48.130Z,1716997188.130 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298977 2024-05-29T15:39:48.386Z,1716997188.386 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.553977 2024-05-29T15:39:48.635Z,1716997188.635 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.803799 2024-05-29T15:39:48.887Z,1716997188.887 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.055545 2024-05-29T15:39:49.138Z,1716997189.138 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306990 2024-05-29T15:39:49.390Z,1716997189.390 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.559157 2024-05-29T15:39:49.642Z,1716997189.642 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.811038 2024-05-29T15:39:49.774Z,1716997189.774 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2024-05-29T15:39:49.895Z,1716997189.895 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.063254 2024-05-29T15:39:50.146Z,1716997190.146 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314961 2024-05-29T15:39:50.398Z,1716997190.398 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.567044 2024-05-29T15:39:50.564Z,1716997190.564 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2024-05-29T15:39:50.650Z,1716997190.650 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.819392 2024-05-29T15:39:50.903Z,1716997190.903 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.071778 2024-05-29T15:39:50.975Z,1716997190.975 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:LeaveDock] Stopped 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:LeaveDock:A.] Stopped 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2024-05-29T15:39:50.976Z,1716997190.976 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2024-05-29T15:39:50.977Z,1716997190.977 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2024-05-29T15:39:50.977Z,1716997190.977 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-05-29T15:39:50.977Z,1716997190.977 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-05-29T15:39:50.978Z,1716997190.978 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-05-29T15:39:50.978Z,1716997190.978 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-05-29T15:39:50.978Z,1716997190.978 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-05-29T15:39:50.979Z,1716997190.979 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-05-29T15:39:50.979Z,1716997190.979 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-05-29T15:39:51.154Z,1716997191.154 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.323069 2024-05-29T15:39:51.412Z,1716997191.412 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.577829 2024-05-29T15:39:51.454Z,1716997191.454 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2024-05-29T15:39:51.454Z,1716997191.454 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2024-05-29T15:39:51.454Z,1716997191.454 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2024-05-29T15:39:51.530Z,1716997191.530 [DockingStepper](INFO): Pause 2024-05-29T15:39:51.659Z,1716997191.659 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.827697 2024-05-29T15:39:51.790Z,1716997191.790 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-05-29T15:39:51.910Z,1716997191.910 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:51.910Z,1716997191.910 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:51.910Z,1716997191.910 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:52.162Z,1716997192.162 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:52.162Z,1716997192.162 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:52.162Z,1716997192.162 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:52.414Z,1716997192.414 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:52.414Z,1716997192.414 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:52.414Z,1716997192.414 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:52.666Z,1716997192.666 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:52.666Z,1716997192.666 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:52.667Z,1716997192.667 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:52.918Z,1716997192.918 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:52.918Z,1716997192.918 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:52.918Z,1716997192.918 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:53.170Z,1716997193.170 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:53.170Z,1716997193.170 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:53.170Z,1716997193.170 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:53.424Z,1716997193.424 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:53.424Z,1716997193.424 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:53.425Z,1716997193.425 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:53.674Z,1716997193.674 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:53.674Z,1716997193.674 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:53.674Z,1716997193.674 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:53.758Z,1716997193.758 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:39:53.926Z,1716997193.926 [DAT](INFO): ****** received valid address query ****** 2024-05-29T15:39:53.926Z,1716997193.926 [DAT](INFO): ****** received valid ping request ****** 2024-05-29T15:39:53.926Z,1716997193.926 [DAT](INFO): Querying Benthos address 201 with one ping in standard two-way mode. 2024-05-29T15:39:54.178Z,1716997194.178 [DAT](INFO): DAT read: Response Not Received 2024-05-29T15:39:54.178Z,1716997194.178 [DAT](INFO): response not received 2024-05-29T15:39:54.179Z,1716997194.179 [DAT](INFO): DAT read: user:10> 2024-05-29T15:39:54.179Z,1716997194.179 [DAT](INFO): DAT read: Tx time:15:39:54.2832 2024-05-29T15:39:54.180Z,1716997194.180 [DAT](INFO): Ping request sent. 2024-05-29T15:39:54.180Z,1716997194.180 [DAT](INFO): transmitted an acoustic signal 2024-05-29T15:39:54.180Z,1716997194.180 [DAT](INFO): publishing transmit ping time 2024-05-29T15:39:54.181Z,1716997194.181 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000692 2024-05-29T15:39:54.430Z,1716997194.430 [DAT](INFO): DAT read: TxSync time:15:39:54.2824 2024-05-29T15:39:54.431Z,1716997194.431 [DAT](INFO): unknown deviceResponse_: TxSync time:15:39:54.2824 2024-05-29T15:39:54.431Z,1716997194.431 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251228 2024-05-29T15:39:54.682Z,1716997194.682 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502134 2024-05-29T15:39:54.934Z,1716997194.934 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754162 2024-05-29T15:39:55.186Z,1716997195.186 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006102 2024-05-29T15:39:55.440Z,1716997195.440 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259602 2024-05-29T15:39:55.690Z,1716997195.690 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510162 2024-05-29T15:39:55.942Z,1716997195.942 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762103 2024-05-29T15:39:56.194Z,1716997196.194 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014331 2024-05-29T15:39:56.446Z,1716997196.446 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266149 2024-05-29T15:39:56.698Z,1716997196.698 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518107 2024-05-29T15:39:56.950Z,1716997196.950 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770108 2024-05-29T15:39:57.202Z,1716997197.202 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022167 2024-05-29T15:39:57.456Z,1716997197.456 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275823 2024-05-29T15:39:57.706Z,1716997197.706 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526114 2024-05-29T15:39:57.958Z,1716997197.958 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778098 2024-05-29T15:39:58.210Z,1716997198.210 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030016 2024-05-29T15:39:58.462Z,1716997198.462 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282372 2024-05-29T15:39:58.714Z,1716997198.714 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534179 2024-05-29T15:39:58.968Z,1716997198.968 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.787683 2024-05-29T15:39:59.218Z,1716997199.218 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038122 2024-05-29T15:39:59.470Z,1716997199.470 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290253 2024-05-29T15:39:59.722Z,1716997199.722 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542101 2024-05-29T15:39:59.974Z,1716997199.974 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794276 2024-05-29T15:40:00.226Z,1716997200.226 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046328 2024-05-29T15:40:00.478Z,1716997200.478 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298144 2024-05-29T15:40:00.730Z,1716997200.730 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550425 2024-05-29T15:40:00.982Z,1716997200.982 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802218 2024-05-29T15:40:01.234Z,1716997201.234 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054096 2024-05-29T15:40:01.486Z,1716997201.486 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306184 2024-05-29T15:40:01.738Z,1716997201.738 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558130 2024-05-29T15:40:01.990Z,1716997201.990 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810126 2024-05-29T15:40:02.242Z,1716997202.242 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062297 2024-05-29T15:40:02.494Z,1716997202.494 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314175 2024-05-29T15:40:02.746Z,1716997202.746 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.566135 2024-05-29T15:40:02.998Z,1716997202.998 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818123 2024-05-29T15:40:03.250Z,1716997203.250 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070162 2024-05-29T15:40:03.502Z,1716997203.502 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.322000 2024-05-29T15:40:03.754Z,1716997203.754 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574083 2024-05-29T15:40:04.006Z,1716997204.006 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826185 2024-05-29T15:40:06.526Z,1716997206.526 [DAT](INFO): DAT read: Response Not Received 2024-05-29T15:40:06.526Z,1716997206.526 [DAT](INFO): response not received 2024-05-29T15:40:06.527Z,1716997206.527 [DAT](INFO): DAT read: user:11> 2024-05-29T15:40:06.527Z,1716997206.527 [DAT](INFO): DAT read: Tx time:15:40:06.7333 2024-05-29T15:40:06.528Z,1716997206.528 [DAT](INFO): Ping request sent. 2024-05-29T15:40:06.528Z,1716997206.528 [DAT](INFO): transmitted an acoustic signal 2024-05-29T15:40:06.528Z,1716997206.528 [DAT](INFO): publishing transmit ping time 2024-05-29T15:40:06.529Z,1716997206.529 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000695 2024-05-29T15:40:06.778Z,1716997206.778 [DAT](INFO): DAT read: TxSync time:15:40:06.7325 2024-05-29T15:40:06.778Z,1716997206.778 [DAT](INFO): unknown deviceResponse_: TxSync time:15:40:06.7325 2024-05-29T15:40:06.779Z,1716997206.779 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251087 2024-05-29T15:40:07.030Z,1716997207.030 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502393 2024-05-29T15:40:07.090Z,1716997207.090 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2024-05-29T15:40:07.282Z,1716997207.282 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754228 2024-05-29T15:40:07.534Z,1716997207.534 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006271 2024-05-29T15:40:07.786Z,1716997207.786 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258185 2024-05-29T15:40:08.038Z,1716997208.038 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510232 2024-05-29T15:40:08.290Z,1716997208.290 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762154 2024-05-29T15:40:08.542Z,1716997208.542 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014195 2024-05-29T15:40:08.794Z,1716997208.794 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266418 2024-05-29T15:40:09.046Z,1716997209.046 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518085 2024-05-29T15:40:09.298Z,1716997209.298 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770494 2024-05-29T15:40:09.550Z,1716997209.550 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022351 2024-05-29T15:40:09.802Z,1716997209.802 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274185 2024-05-29T15:40:10.054Z,1716997210.054 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526205 2024-05-29T15:40:10.306Z,1716997210.306 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778197 2024-05-29T15:40:10.558Z,1716997210.558 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030154 2024-05-29T15:40:10.810Z,1716997210.810 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282377 2024-05-29T15:40:11.062Z,1716997211.062 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534253 2024-05-29T15:40:11.314Z,1716997211.314 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786165 2024-05-29T15:40:11.568Z,1716997211.568 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.039802 2024-05-29T15:40:11.818Z,1716997211.818 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290241 2024-05-29T15:40:12.070Z,1716997212.070 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542202 2024-05-29T15:40:12.322Z,1716997212.322 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794191 2024-05-29T15:40:12.574Z,1716997212.574 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046160 2024-05-29T15:40:12.826Z,1716997212.826 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298339 2024-05-29T15:40:13.078Z,1716997213.078 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550399 2024-05-29T15:40:13.330Z,1716997213.330 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802206 2024-05-29T15:40:13.582Z,1716997213.582 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054263 2024-05-29T15:40:13.834Z,1716997213.834 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306182 2024-05-29T15:40:14.086Z,1716997214.086 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558262 2024-05-29T15:40:14.338Z,1716997214.338 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810189 2024-05-29T15:40:14.590Z,1716997214.590 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062184 2024-05-29T15:40:14.842Z,1716997214.842 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314227 2024-05-29T15:40:15.094Z,1716997215.094 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.566100 2024-05-29T15:40:15.346Z,1716997215.346 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818551 2024-05-29T15:40:15.598Z,1716997215.598 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070292 2024-05-29T15:40:15.850Z,1716997215.850 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.322169 2024-05-29T15:40:16.102Z,1716997216.102 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574342 2024-05-29T15:40:16.355Z,1716997216.355 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826804 2024-05-29T15:40:19.126Z,1716997219.126 [DAT](INFO): DAT read: Response Not Received 2024-05-29T15:40:19.126Z,1716997219.126 [DAT](INFO): response not received 2024-05-29T15:40:19.127Z,1716997219.127 [DAT](INFO): DAT read: user:12> 2024-05-29T15:40:19.128Z,1716997219.128 [DAT](INFO): DAT read: Tx time:15:40:19.1833 2024-05-29T15:40:19.128Z,1716997219.128 [DAT](INFO): Ping request sent. 2024-05-29T15:40:19.128Z,1716997219.128 [DAT](INFO): transmitted an acoustic signal 2024-05-29T15:40:19.128Z,1716997219.128 [DAT](INFO): publishing transmit ping time 2024-05-29T15:40:19.129Z,1716997219.129 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000704 2024-05-29T15:40:19.380Z,1716997219.380 [DAT](INFO): DAT read: TxSync time:15:40:19.1826 2024-05-29T15:40:19.381Z,1716997219.381 [DAT](INFO): unknown deviceResponse_: TxSync time:15:40:19.1826 2024-05-29T15:40:19.382Z,1716997219.382 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.253582 2024-05-29T15:40:19.630Z,1716997219.630 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501936 2024-05-29T15:40:19.882Z,1716997219.882 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753941 2024-05-29T15:40:20.134Z,1716997220.134 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006170 2024-05-29T15:40:20.386Z,1716997220.386 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258110 2024-05-29T15:40:20.638Z,1716997220.638 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510143 2024-05-29T15:40:20.890Z,1716997220.890 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762200 2024-05-29T15:40:21.142Z,1716997221.142 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014034 2024-05-29T15:40:21.397Z,1716997221.397 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.268264 2024-05-29T15:40:21.652Z,1716997221.652 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.524134 2024-05-29T15:40:21.906Z,1716997221.906 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.778131 2024-05-29T15:40:22.158Z,1716997222.158 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.030156 2024-05-29T15:40:22.410Z,1716997222.410 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.282021 2024-05-29T15:40:22.662Z,1716997222.662 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.534531 2024-05-29T15:40:22.914Z,1716997222.914 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.786174 2024-05-29T15:40:23.166Z,1716997223.166 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.038113 2024-05-29T15:40:23.420Z,1716997223.420 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.291626 2024-05-29T15:40:23.670Z,1716997223.670 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.542144 2024-05-29T15:40:23.923Z,1716997223.923 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.794785 2024-05-29T15:40:24.174Z,1716997224.174 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.046006 2024-05-29T15:40:24.426Z,1716997224.426 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.298075 2024-05-29T15:40:24.678Z,1716997224.678 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.550122 2024-05-29T15:40:24.930Z,1716997224.930 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.802090 2024-05-29T15:40:25.182Z,1716997225.182 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.054056 2024-05-29T15:40:25.437Z,1716997225.437 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.308297 2024-05-29T15:40:25.686Z,1716997225.686 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.558129 2024-05-29T15:40:25.938Z,1716997225.938 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.810007 2024-05-29T15:40:26.190Z,1716997226.190 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.062138 2024-05-29T15:40:26.442Z,1716997226.442 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.314059 2024-05-29T15:40:26.694Z,1716997226.694 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.566053 2024-05-29T15:40:26.946Z,1716997226.946 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.818528 2024-05-29T15:40:27.199Z,1716997227.199 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.070677 2024-05-29T15:40:27.453Z,1716997227.453 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.324447 2024-05-29T15:40:27.702Z,1716997227.702 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.574240 2024-05-29T15:40:27.954Z,1716997227.954 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.826016 2024-05-29T15:40:28.206Z,1716997228.206 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.078062 2024-05-29T15:40:28.458Z,1716997228.458 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.330091 2024-05-29T15:40:28.710Z,1716997228.710 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.582424 2024-05-29T15:40:28.962Z,1716997228.962 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.834157 2024-05-29T15:40:31.482Z,1716997231.482 [DAT](INFO): DAT read: Response Not Received 2024-05-29T15:40:31.482Z,1716997231.482 [DAT](INFO): response not received 2024-05-29T15:40:31.483Z,1716997231.483 [DAT](INFO): DAT read: user:13> 2024-05-29T15:40:31.484Z,1716997231.484 [DAT](INFO): DAT read: Tx time:15:40:31.6334 2024-05-29T15:40:31.484Z,1716997231.484 [DAT](INFO): Ping request sent. 2024-05-29T15:40:31.484Z,1716997231.484 [DAT](INFO): transmitted an acoustic signal 2024-05-29T15:40:31.484Z,1716997231.484 [DAT](INFO): publishing transmit ping time 2024-05-29T15:40:31.485Z,1716997231.485 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000698 2024-05-29T15:40:31.734Z,1716997231.734 [DAT](INFO): DAT read: TxSync time:15:40:31.6327 2024-05-29T15:40:31.735Z,1716997231.735 [DAT](INFO): unknown deviceResponse_: TxSync time:15:40:31.6327 2024-05-29T15:40:31.735Z,1716997231.735 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251158 2024-05-29T15:40:31.986Z,1716997231.986 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502043 2024-05-29T15:40:32.238Z,1716997232.238 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754244 2024-05-29T15:40:32.490Z,1716997232.490 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006108 2024-05-29T15:40:32.742Z,1716997232.742 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258103 2024-05-29T15:40:32.994Z,1716997232.994 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510517 2024-05-29T15:40:33.246Z,1716997233.246 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762013 2024-05-29T15:40:33.498Z,1716997233.498 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014290 2024-05-29T15:40:33.750Z,1716997233.750 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266211 2024-05-29T15:40:34.002Z,1716997234.002 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518060 2024-05-29T15:40:34.254Z,1716997234.254 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770042 2024-05-29T15:40:34.506Z,1716997234.506 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022435 2024-05-29T15:40:34.758Z,1716997234.758 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274084 2024-05-29T15:40:35.010Z,1716997235.010 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526132 2024-05-29T15:40:35.262Z,1716997235.262 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778158 2024-05-29T15:40:35.514Z,1716997235.514 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030077 2024-05-29T15:40:35.766Z,1716997235.766 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282034 2024-05-29T15:40:36.018Z,1716997236.018 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534126 2024-05-29T15:40:36.270Z,1716997236.270 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786086 2024-05-29T15:40:36.522Z,1716997236.522 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038081 2024-05-29T15:40:36.774Z,1716997236.774 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290159 2024-05-29T15:40:37.026Z,1716997237.026 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542228 2024-05-29T15:40:37.278Z,1716997237.278 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794089 2024-05-29T15:40:37.530Z,1716997237.530 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046162 2024-05-29T15:40:37.782Z,1716997237.782 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298044 2024-05-29T15:40:38.034Z,1716997238.034 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550189 2024-05-29T15:40:38.286Z,1716997238.286 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802127 2024-05-29T15:40:38.538Z,1716997238.538 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054069 2024-05-29T15:40:38.790Z,1716997238.790 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306089 2024-05-29T15:40:39.043Z,1716997239.043 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.559056 2024-05-29T15:40:39.294Z,1716997239.294 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.809978 2024-05-29T15:40:39.547Z,1716997239.547 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062733 2024-05-29T15:40:39.798Z,1716997239.798 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314134 2024-05-29T15:40:40.050Z,1716997240.050 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.566058 2024-05-29T15:40:40.302Z,1716997240.302 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818081 2024-05-29T15:40:40.554Z,1716997240.554 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070376 2024-05-29T15:40:40.806Z,1716997240.806 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.322058 2024-05-29T15:40:41.058Z,1716997241.058 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574091 2024-05-29T15:40:41.310Z,1716997241.310 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826176 2024-05-29T15:40:41.698Z,1716997241.698 [CommandExec](IMPORTANT): got command quit 2024-05-29T15:40:42.701Z,1716997242.701 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2024-05-29T15:40:42.701Z,1716997242.701 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:42.702Z,1716997242.702 [CommandExec](INFO): Uninitializing the command executive. 2024-05-29T15:40:42.702Z,1716997242.702 [CommandExec](INFO): Uninitializing the command scheduler. 2024-05-29T15:40:42.702Z,1716997242.702 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:42.702Z,1716997242.702 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-05-29T15:40:42.703Z,1716997242.703 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-05-29T15:40:42.703Z,1716997242.703 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:42.703Z,1716997242.703 [NavChartDb](INFO): Join timeout helper Thread ID is 987 2024-05-29T15:40:42.941Z,1716997242.941 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:42.942Z,1716997242.942 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:42.945Z,1716997242.945 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2024-05-29T15:40:42.945Z,1716997242.945 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:42.946Z,1716997242.946 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 988 2024-05-29T15:40:42.973Z,1716997242.973 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:42.974Z,1716997242.974 [WetLabsUBAT](INFO): Powering down 2024-05-29T15:40:42.974Z,1716997242.974 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:42.991Z,1716997242.991 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2024-05-29T15:40:42.991Z,1716997242.991 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:42.991Z,1716997242.991 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 989 2024-05-29T15:40:43.342Z,1716997243.342 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:43.342Z,1716997243.342 [WetLabsBB2FL](INFO): Powering down 2024-05-29T15:40:43.343Z,1716997243.343 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:43.359Z,1716997243.359 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2024-05-29T15:40:43.359Z,1716997243.359 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:43.360Z,1716997243.360 [CTD_Seabird](INFO): Join timeout helper Thread ID is 990 2024-05-29T15:40:43.830Z,1716997243.830 [DAT](INFO): DAT read: Response Not Received 2024-05-29T15:40:43.830Z,1716997243.830 [DAT](INFO): response not received 2024-05-29T15:40:43.831Z,1716997243.831 [DAT](INFO): DAT read: user:14> 2024-05-29T15:40:43.831Z,1716997243.831 [DAT](ERROR): No response from remote modem. 2024-05-29T15:40:44.022Z,1716997244.022 [CTD_Seabird](INFO): Powering down 2024-05-29T15:40:44.033Z,1716997244.033 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:44.033Z,1716997244.033 [CTD_Seabird](INFO): Powering down 2024-05-29T15:40:44.045Z,1716997244.045 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:44.057Z,1716997244.057 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2024-05-29T15:40:44.057Z,1716997244.057 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:44.058Z,1716997244.058 [DAT](INFO): Join timeout helper Thread ID is 991 2024-05-29T15:40:44.081Z,1716997244.081 [DAT](INFO): Powering down 2024-05-29T15:40:44.154Z,1716997244.154 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:44.154Z,1716997244.154 [DAT](INFO): Powering down 2024-05-29T15:40:44.155Z,1716997244.155 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:44.162Z,1716997244.162 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2024-05-29T15:40:44.162Z,1716997244.162 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:44.163Z,1716997244.163 [Radio_Surface](INFO): Join timeout helper Thread ID is 992 2024-05-29T15:40:44.230Z,1716997244.230 [Radio_Surface](INFO): Powering down 2024-05-29T15:40:44.231Z,1716997244.231 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:44.231Z,1716997244.231 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:44.250Z,1716997244.250 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2024-05-29T15:40:44.250Z,1716997244.250 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:44.250Z,1716997244.250 [Onboard](INFO): Join timeout helper Thread ID is 993 2024-05-29T15:40:44.721Z,1716997244.721 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2024-05-29T15:40:48.929Z,1716997248.929 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:48.930Z,1716997248.930 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:48.946Z,1716997248.946 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2024-05-29T15:40:48.946Z,1716997248.946 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:48.946Z,1716997248.946 [DataOverHttps](INFO): Join timeout helper Thread ID is 994 2024-05-29T15:40:49.742Z,1716997249.742 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:49.742Z,1716997249.742 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:49.762Z,1716997249.762 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2024-05-29T15:40:49.762Z,1716997249.762 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:49.762Z,1716997249.762 [BackseatComponent](INFO): Join timeout helper Thread ID is 995 2024-05-29T15:40:49.957Z,1716997249.957 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:49.958Z,1716997249.958 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:49.962Z,1716997249.962 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2024-05-29T15:40:49.962Z,1716997249.962 [logger ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:49.962Z,1716997249.962 [logger](INFO): Join timeout helper Thread ID is 996 2024-05-29T15:40:50.000Z,1716997250.000 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:50.001Z,1716997250.001 [logger ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.010Z,1716997250.010 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2024-05-29T15:40:50.010Z,1716997250.010 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.010Z,1716997250.010 [CommandLine](INFO): Join timeout helper Thread ID is 997 2024-05-29T15:40:50.089Z,1716997250.089 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:50.090Z,1716997250.090 [CommandLine ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.096Z,1716997250.096 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2024-05-29T15:40:50.097Z,1716997250.097 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.097Z,1716997250.097 [CommandExec](INFO): Join timeout helper Thread ID is 998 2024-05-29T15:40:50.099Z,1716997250.099 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2024-05-29T15:40:50.099Z,1716997250.099 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.099Z,1716997250.099 [controlThread](INFO): Join timeout helper Thread ID is 999 2024-05-29T15:40:50.309Z,1716997250.309 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2024-05-29T15:40:50.310Z,1716997250.310 [controlThread](DEBUG): Uninitializing ControlThread 2024-05-29T15:40:50.310Z,1716997250.310 [AHRS_M2](INFO): Powering down 2024-05-29T15:40:50.382Z,1716997250.382 [NAL9602](INFO): Powering down 2024-05-29T15:40:50.453Z,1716997250.453 [RDI_Pathfinder](INFO): Powering down 2024-05-29T15:40:50.455Z,1716997250.455 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2024-05-29T15:40:50.455Z,1716997250.455 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2024-05-29T15:40:50.456Z,1716997250.456 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2024-05-29T15:40:50.456Z,1716997250.456 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock 2024-05-29T15:40:50.456Z,1716997250.456 [DefaultWithUndock] Stopped 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock:SurfaceDefault] Stopped 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Stopped 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn 2024-05-29T15:40:50.457Z,1716997250.457 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2024-05-29T15:40:50.464Z,1716997250.464 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2024-05-29T15:40:50.465Z,1716997250.465 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2024-05-29T15:40:50.465Z,1716997250.465 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2024-05-29T15:40:50.466Z,1716997250.466 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2024-05-29T15:40:50.466Z,1716997250.466 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2024-05-29T15:40:50.466Z,1716997250.466 [BuoyancyServo](INFO): Powering down 2024-05-29T15:40:50.477Z,1716997250.477 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2024-05-29T15:40:50.477Z,1716997250.477 [ElevatorServo](INFO): Powering down 2024-05-29T15:40:50.478Z,1716997250.478 [DockingStepper](DEBUG): Uninitialize Docking Stepper. 2024-05-29T15:40:50.478Z,1716997250.478 [DockingStepper](INFO): Powering down 2024-05-29T15:40:50.479Z,1716997250.479 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-05-29T15:40:50.479Z,1716997250.479 [MassServo](INFO): Powering down 2024-05-29T15:40:50.480Z,1716997250.480 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2024-05-29T15:40:50.480Z,1716997250.480 [RudderServo](INFO): Powering down 2024-05-29T15:40:50.481Z,1716997250.481 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2024-05-29T15:40:50.481Z,1716997250.481 [ThrusterServo](INFO): Powering down 2024-05-29T15:40:50.482Z,1716997250.482 [SBIT](DEBUG): Uninitialize SBIT Component. 2024-05-29T15:40:50.482Z,1716997250.482 [IBIT](DEBUG): Uninitialize IBIT Component. 2024-05-29T15:40:50.483Z,1716997250.483 [CBIT](DEBUG): Uninitialize CBIT Component. 2024-05-29T15:40:50.483Z,1716997250.483 [CBIT](DEBUG): Powering off loads. 2024-05-29T15:40:50.493Z,1716997250.493 [CBIT](DEBUG): Disabling WDT. 2024-05-29T15:40:50.505Z,1716997250.505 [CBIT](DEBUG): Opening all GF detection circuits. 2024-05-29T15:40:50.506Z,1716997250.506 [controlThread ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.567Z,1716997250.567 [DAT ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.574Z,1716997250.574 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.576Z,1716997250.576 [Onboard ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.581Z,1716997250.581 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.624Z,1716997250.624 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.684Z,1716997250.684 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.686Z,1716997250.686 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.690Z,1716997250.690 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.698Z,1716997250.698 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-05-29T15:40:50.763Z,1716997250.763 [logger ThreadHandler](INFO): Thread cancelled.