2025-01-09T22:47:47.085Z,1736462867.085 [Supervisor](DEBUG): Initializing supervisor. 2025-01-09T22:47:47.089Z,1736462867.089 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-01-09T22:47:47.089Z,1736462867.089 [SyncHandler](INFO): Protected caller Thread ID is 840 2025-01-09T22:47:47.090Z,1736462867.090 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-01-09T22:47:47.091Z,1736462867.091 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-01-09T22:47:47.091Z,1736462867.091 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 841 2025-01-09T22:47:47.095Z,1736462867.095 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-01-09T22:47:47.112Z,1736462867.112 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-01-09T22:47:47.113Z,1736462867.113 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-01-09T22:47:47.113Z,1736462867.113 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 842 2025-01-09T22:47:47.117Z,1736462867.117 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-01-09T22:47:47.118Z,1736462867.118 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-01-09T22:47:47.119Z,1736462867.119 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 843 2025-01-09T22:47:47.121Z,1736462867.121 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-01-09T22:47:47.122Z,1736462867.122 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-01-09T22:47:47.122Z,1736462867.122 [logger ThreadHandler](INFO): Protected caller Thread ID is 844 2025-01-09T22:47:47.126Z,1736462867.126 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-01-09T22:47:47.126Z,1736462867.126 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-01-09T22:47:47.130Z,1736462867.130 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-01-09T22:47:47.236Z,1736462867.236 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-01-09T22:47:47.238Z,1736462867.238 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-01-09T22:47:48.005Z,1736462868.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-01-09T22:47:48.007Z,1736462868.007 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-01-09T22:47:48.247Z,1736462868.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-01-09T22:47:48.249Z,1736462868.249 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-01-09T22:47:48.339Z,1736462868.339 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-01-09T22:47:48.508Z,1736462868.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-01-09T22:47:48.509Z,1736462868.509 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-01-09T22:47:48.631Z,1736462868.631 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-01-09T22:47:48.748Z,1736462868.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-01-09T22:47:48.749Z,1736462868.749 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-01-09T22:47:49.162Z,1736462869.162 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-01-09T22:47:49.164Z,1736462869.164 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-01-09T22:47:49.698Z,1736462869.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-01-09T22:47:49.700Z,1736462869.700 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-01-09T22:47:49.926Z,1736462869.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-01-09T22:47:49.928Z,1736462869.928 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-01-09T22:47:50.133Z,1736462870.133 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-01-09T22:47:50.134Z,1736462870.134 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-01-09T22:47:50.688Z,1736462870.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-01-09T22:47:50.689Z,1736462870.689 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-01-09T22:47:51.997Z,1736462871.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-01-09T22:47:51.999Z,1736462871.999 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-01-09T22:47:52.281Z,1736462872.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-01-09T22:47:52.282Z,1736462872.282 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-01-09T22:47:52.666Z,1736462872.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-01-09T22:47:52.666Z,1736462872.666 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-01-09T22:47:53.018Z,1736462873.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-01-09T22:47:53.020Z,1736462873.020 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2025-01-09T22:47:53.022Z,1736462873.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2025-01-09T22:47:53.115Z,1736462873.115 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2025-01-09T22:47:53.291Z,1736462873.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Dock.cfg 2025-01-09T22:47:53.406Z,1736462873.406 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/workSite.cfg 2025-01-09T22:47:53.510Z,1736462873.510 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2025-01-09T22:47:53.626Z,1736462873.626 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2025-01-09T22:47:53.721Z,1736462873.721 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2025-01-09T22:47:53.825Z,1736462873.825 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2025-01-09T22:47:53.946Z,1736462873.946 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2025-01-09T22:47:54.219Z,1736462874.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-01-09T22:47:54.220Z,1736462874.220 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2025-01-09T22:47:54.314Z,1736462874.314 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2025-01-09T22:47:54.417Z,1736462874.417 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2025-01-09T22:47:54.568Z,1736462874.568 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2025-01-09T22:47:54.677Z,1736462874.677 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-01-09T22:47:54.694Z,1736462874.694 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-01-09T22:47:54.864Z,1736462874.864 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-01-09T22:47:54.865Z,1736462874.865 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-01-09T22:47:54.935Z,1736462874.935 [VerticalControl](DEBUG): Construct VerticalControl. 2025-01-09T22:47:54.994Z,1736462874.994 [VerticalControl] Loaded 2025-01-09T22:47:54.994Z,1736462874.994 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-01-09T22:47:54.997Z,1736462874.997 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-01-09T22:47:55.046Z,1736462875.046 [HorizontalControl] Loaded 2025-01-09T22:47:55.046Z,1736462875.046 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-01-09T22:47:55.049Z,1736462875.049 [SpeedControl](DEBUG): Construct SpeedControl. 2025-01-09T22:47:55.052Z,1736462875.052 [SpeedControl] Loaded 2025-01-09T22:47:55.052Z,1736462875.052 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-01-09T22:47:55.055Z,1736462875.055 [LoopControl](DEBUG): Construct LoopControl. 2025-01-09T22:47:55.055Z,1736462875.055 [LoopControl] Loaded 2025-01-09T22:47:55.055Z,1736462875.055 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-01-09T22:47:55.056Z,1736462875.056 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-01-09T22:47:55.056Z,1736462875.056 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-01-09T22:47:55.127Z,1736462875.127 [DepthRateCalculator] Loaded 2025-01-09T22:47:55.127Z,1736462875.127 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-01-09T22:47:55.132Z,1736462875.132 [PitchRateCalculator] Loaded 2025-01-09T22:47:55.132Z,1736462875.132 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-01-09T22:47:55.142Z,1736462875.142 [SpeedCalculator] Loaded 2025-01-09T22:47:55.143Z,1736462875.143 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-01-09T22:47:55.147Z,1736462875.147 [YawRateCalculator] Loaded 2025-01-09T22:47:55.147Z,1736462875.147 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-01-09T22:47:55.165Z,1736462875.165 [ElevatorOffsetCalculator] Loaded 2025-01-09T22:47:55.165Z,1736462875.165 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-01-09T22:47:55.166Z,1736462875.166 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-01-09T22:47:55.168Z,1736462875.168 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-01-09T22:47:55.210Z,1736462875.210 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-01-09T22:47:55.211Z,1736462875.211 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-01-09T22:47:55.297Z,1736462875.297 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-01-09T22:47:55.298Z,1736462875.298 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-01-09T22:47:55.703Z,1736462875.703 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-01-09T22:47:55.705Z,1736462875.705 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-01-09T22:47:56.113Z,1736462876.113 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-01-09T22:47:56.114Z,1736462876.114 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-01-09T22:47:57.421Z,1736462877.421 [AHRS_M2] Loaded 2025-01-09T22:47:57.421Z,1736462877.421 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-01-09T22:47:57.674Z,1736462877.674 [BackseatComponent] Loaded 2025-01-09T22:47:57.674Z,1736462877.674 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-01-09T22:47:57.675Z,1736462877.675 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409E14E0 2025-01-09T22:47:57.676Z,1736462877.676 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 932 2025-01-09T22:47:57.678Z,1736462877.678 [LcmUniversalReporter] Loaded 2025-01-09T22:47:57.679Z,1736462877.679 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-01-09T22:47:58.541Z,1736462878.541 [BPC1] Loaded 2025-01-09T22:47:58.541Z,1736462878.541 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-01-09T22:47:58.637Z,1736462878.637 [DAT] Loaded 2025-01-09T22:47:58.637Z,1736462878.637 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-01-09T22:47:58.638Z,1736462878.638 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A114E0 2025-01-09T22:47:58.639Z,1736462878.639 [DAT ThreadHandler](INFO): Protected caller Thread ID is 934 2025-01-09T22:47:58.787Z,1736462878.787 [DataOverHttps] Loaded 2025-01-09T22:47:58.787Z,1736462878.787 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-01-09T22:47:58.788Z,1736462878.788 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A414E0 2025-01-09T22:47:58.789Z,1736462878.789 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 935 2025-01-09T22:47:58.811Z,1736462878.811 [Depth_Keller] Loaded 2025-01-09T22:47:58.812Z,1736462878.812 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-01-09T22:47:58.817Z,1736462878.817 [DropWeight] Loaded 2025-01-09T22:47:58.817Z,1736462878.817 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-01-09T22:47:58.881Z,1736462878.881 [NAL9602] Loaded 2025-01-09T22:47:58.881Z,1736462878.881 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-01-09T22:47:58.910Z,1736462878.910 [Onboard] Loaded 2025-01-09T22:47:58.911Z,1736462878.911 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-01-09T22:47:58.912Z,1736462878.912 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A714E0 2025-01-09T22:47:58.912Z,1736462878.912 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 936 2025-01-09T22:47:58.926Z,1736462878.926 [Power24vConverter] Loaded 2025-01-09T22:47:58.926Z,1736462878.926 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-01-09T22:47:58.942Z,1736462878.942 [Radio_Surface] Loaded 2025-01-09T22:47:58.942Z,1736462878.942 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-01-09T22:47:58.943Z,1736462878.943 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AA14E0 2025-01-09T22:47:58.943Z,1736462878.943 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 937 2025-01-09T22:47:58.990Z,1736462878.990 [RDI_Pathfinder] Loaded 2025-01-09T22:47:58.990Z,1736462878.990 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2025-01-09T22:47:59.005Z,1736462879.005 [Sonardyne_Nano] Loaded 2025-01-09T22:47:59.005Z,1736462879.005 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-01-09T22:47:59.006Z,1736462879.006 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-01-09T22:47:59.007Z,1736462879.007 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-01-09T22:47:59.143Z,1736462879.143 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-01-09T22:47:59.143Z,1736462879.143 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-01-09T22:47:59.157Z,1736462879.157 [NavChart] Loaded 2025-01-09T22:47:59.157Z,1736462879.157 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-01-09T22:47:59.163Z,1736462879.163 [UniversalFixResidualReporter] Loaded 2025-01-09T22:47:59.163Z,1736462879.163 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-01-09T22:47:59.163Z,1736462879.163 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-01-09T22:47:59.165Z,1736462879.165 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-01-09T22:47:59.335Z,1736462879.335 [SBIT](DEBUG): Construct Startup Built In Test. 2025-01-09T22:47:59.343Z,1736462879.343 [SBIT] Loaded 2025-01-09T22:47:59.344Z,1736462879.344 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-01-09T22:47:59.347Z,1736462879.347 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-01-09T22:47:59.359Z,1736462879.359 [IBIT] Loaded 2025-01-09T22:47:59.359Z,1736462879.359 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-01-09T22:47:59.365Z,1736462879.365 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-01-09T22:47:59.470Z,1736462879.470 [CBIT] Loaded 2025-01-09T22:47:59.470Z,1736462879.470 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-01-09T22:47:59.471Z,1736462879.471 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-01-09T22:47:59.471Z,1736462879.471 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-01-09T22:47:59.635Z,1736462879.635 [BuoyancyServo] Loaded 2025-01-09T22:47:59.636Z,1736462879.636 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-01-09T22:47:59.658Z,1736462879.658 [ElevatorServo] Loaded 2025-01-09T22:47:59.659Z,1736462879.659 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-01-09T22:47:59.689Z,1736462879.689 [DockingStepper] Loaded 2025-01-09T22:47:59.689Z,1736462879.689 [ComponentRegistry](DEBUG): SyncComponent "DockingStepper" handled in the control thread. 2025-01-09T22:47:59.711Z,1736462879.711 [MassServo] Loaded 2025-01-09T22:47:59.711Z,1736462879.711 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-01-09T22:47:59.731Z,1736462879.731 [RudderServo] Loaded 2025-01-09T22:47:59.732Z,1736462879.732 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-01-09T22:47:59.750Z,1736462879.750 [ThrusterServo] Loaded 2025-01-09T22:47:59.750Z,1736462879.750 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2025-01-09T22:47:59.751Z,1736462879.751 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-01-09T22:47:59.751Z,1736462879.751 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-01-09T22:47:59.767Z,1736462879.767 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-01-09T22:47:59.767Z,1736462879.767 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-01-09T22:47:59.994Z,1736462879.994 [CTD_Seabird] Loaded 2025-01-09T22:47:59.995Z,1736462879.995 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-01-09T22:47:59.996Z,1736462879.996 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BEE4E0 2025-01-09T22:47:59.996Z,1736462879.996 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 938 2025-01-09T22:48:00.019Z,1736462880.019 [PAR_Licor] Loaded 2025-01-09T22:48:00.019Z,1736462880.019 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-01-09T22:48:00.063Z,1736462880.063 [WetLabsBB2FL] Loaded 2025-01-09T22:48:00.064Z,1736462880.064 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-01-09T22:48:00.065Z,1736462880.065 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40C1E4E0 2025-01-09T22:48:00.065Z,1736462880.065 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 939 2025-01-09T22:48:00.086Z,1736462880.086 [WetLabsUBAT] Loaded 2025-01-09T22:48:00.086Z,1736462880.086 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2025-01-09T22:48:00.087Z,1736462880.087 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40C4E4E0 2025-01-09T22:48:00.088Z,1736462880.088 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 940 2025-01-09T22:48:00.088Z,1736462880.088 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-01-09T22:48:00.095Z,1736462880.095 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-01-09T22:48:00.097Z,1736462880.097 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-01-09T22:48:00.109Z,1736462880.109 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-01-09T22:48:00.110Z,1736462880.110 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C7E4E0 2025-01-09T22:48:00.110Z,1736462880.110 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 941 2025-01-09T22:48:00.114Z,1736462880.114 [Supervisor](INFO): Main Thread ID is 831 2025-01-09T22:48:00.115Z,1736462880.115 [Supervisor](DEBUG): Running supervisor. 2025-01-09T22:48:00.115Z,1736462880.115 [CommandExec ThreadHandler](INFO): Handler Thread ID is 942 2025-01-09T22:48:00.116Z,1736462880.116 [CommandExec](INFO): Initializing the command executive. 2025-01-09T22:48:00.117Z,1736462880.117 [CommandLine ThreadHandler](INFO): Handler Thread ID is 943 2025-01-09T22:48:00.119Z,1736462880.119 [controlThread ThreadHandler](INFO): Handler Thread ID is 944 2025-01-09T22:48:00.120Z,1736462880.120 [controlThread](DEBUG): Initializing ControlThread 2025-01-09T22:48:00.120Z,1736462880.120 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-01-09T22:48:00.122Z,1736462880.122 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-01-09T22:48:00.123Z,1736462880.123 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-01-09T22:48:00.123Z,1736462880.123 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-01-09T22:48:00.124Z,1736462880.124 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-01-09T22:48:00.124Z,1736462880.124 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-01-09T22:48:00.124Z,1736462880.124 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-01-09T22:48:00.125Z,1736462880.125 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-01-09T22:48:00.125Z,1736462880.125 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-01-09T22:48:00.133Z,1736462880.133 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-01-09T22:48:00.133Z,1736462880.133 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-01-09T22:48:00.133Z,1736462880.133 [SBIT](INFO): Initialize SBIT Component. 2025-01-09T22:48:00.134Z,1736462880.134 [SBIT](IMPORTANT): git: 2025-01-09_B 2025-01-09T22:48:00.134Z,1736462880.134 [SBIT](INFO): git hash: 1f9780a539b09f05de89865a2e326c5f9ffadbdc 2025-01-09T22:48:00.134Z,1736462880.134 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-01-09T22:48:00.135Z,1736462880.135 [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 2025-01-09T22:48:00.136Z,1736462880.136 [SBIT](INFO): Beginning SBIT in 107.000000 seconds. 2025-01-09T22:48:00.137Z,1736462880.137 [IBIT](INFO): Initialize IBIT Component. 2025-01-09T22:48:00.138Z,1736462880.138 [CBIT](DEBUG): Initialize CBIT Component. 2025-01-09T22:48:00.139Z,1736462880.139 [logger ThreadHandler](INFO): Handler Thread ID is 945 2025-01-09T22:48:00.150Z,1736462880.150 [CBIT](DEBUG): Initialized mux pins. 2025-01-09T22:48:00.150Z,1736462880.150 [CBIT](DEBUG): Initializing the watchdog timer. 2025-01-09T22:48:00.158Z,1736462880.158 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 946 2025-01-09T22:48:00.170Z,1736462880.170 [DAT ThreadHandler](INFO): Handler Thread ID is 947 2025-01-09T22:48:00.171Z,1736462880.171 [DAT](INFO): Powering up 2025-01-09T22:48:00.171Z,1736462880.171 [DAT](DEBUG): Initializing DAT. 2025-01-09T22:48:00.174Z,1736462880.174 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-01-09T22:48:00.175Z,1736462880.175 [CBIT](DEBUG): Initializing heartbeat. 2025-01-09T22:48:00.176Z,1736462880.176 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 949 2025-01-09T22:48:00.178Z,1736462880.178 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-01-09T22:48:00.187Z,1736462880.187 [Onboard ThreadHandler](INFO): Handler Thread ID is 950 2025-01-09T22:48:00.204Z,1736462880.204 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 951 2025-01-09T22:48:00.223Z,1736462880.223 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 952 2025-01-09T22:48:00.223Z,1736462880.223 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-01-09T22:48:00.227Z,1736462880.227 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 954 2025-01-09T22:48:00.230Z,1736462880.230 [WetLabsBB2FL](INFO): Powering up 2025-01-09T22:48:00.232Z,1736462880.232 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 956 2025-01-09T22:48:00.234Z,1736462880.234 [WetLabsUBAT](INFO): Powering up 2025-01-09T22:48:00.236Z,1736462880.236 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 958 2025-01-09T22:48:00.244Z,1736462880.244 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-01-09T22:48:00.244Z,1736462880.244 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-01-09T22:48:00.245Z,1736462880.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-01-09T22:48:00.245Z,1736462880.245 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-01-09T22:48:00.245Z,1736462880.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-01-09T22:48:00.245Z,1736462880.245 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-01-09T22:48:00.245Z,1736462880.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-01-09T22:48:00.245Z,1736462880.245 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-01-09T22:48:00.246Z,1736462880.246 [CBIT](DEBUG): Deactivating GF circuits. 2025-01-09T22:48:00.246Z,1736462880.246 [CBIT](DEBUG): Deactivating emergency mode. 2025-01-09T22:48:00.286Z,1736462880.286 [CBIT](DEBUG): Backplane powered. 2025-01-09T22:48:00.291Z,1736462880.291 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-01-09T22:48:00.291Z,1736462880.291 [MissionManager](INFO): Loading Mission from file: Missions/underIce/StartupUnder.tl 2025-01-09T22:48:00.292Z,1736462880.292 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/StartupUnder.tl 2025-01-09T22:48:00.311Z,1736462880.311 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/StartupUnder.tl 2025-01-09T22:48:00.326Z,1736462880.326 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/StartupUnder.tl translated into: 2025-01-09T22:48:00.326Z,1736462880.326 [MissionManager](ERROR): Top node has no child nodes: Mission 2025-01-09T22:48:00.326Z,1736462880.326 [MissionManager](ERROR): Could not load startup mission. 2025-01-09T22:48:00.327Z,1736462880.327 [MissionManager](INFO): Loading Mission from file: Missions/underIce/DefaultWithUndock.tl 2025-01-09T22:48:00.327Z,1736462880.327 [MissionManager](DEBUG): TethyslAPI: loading: Missions/underIce/DefaultWithUndock.tl 2025-01-09T22:48:00.336Z,1736462880.336 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/underIce/DefaultWithUndock.tl 2025-01-09T22:48:00.610Z,1736462880.610 [Radio_Surface](INFO): Powering up 2025-01-09T22:48:00.849Z,1736462880.849 [MissionManager](DEBUG): TethyslAPI: Missions/underIce/DefaultWithUndock.tl translated into: 0 6 10 1 3 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 2025-01-09T22:48:00.874Z,1736462880.874 [MissionManager](INFO): DefineArg DefaultWithUndock.ElapsedSinceDefaultStarted = 0.000000 min 2025-01-09T22:48:00.894Z,1736462880.894 [MissionManager](INFO): DefineArg DefaultWithUndock.DetachTimeout = 6.000000 h 2025-01-09T22:48:00.918Z,1736462880.918 [MissionManager](INFO): DefineArg DefaultWithUndock.TransponderCode = 50 count 2025-01-09T22:48:00.927Z,1736462880.927 [MissionManager](INFO): DefineArg DefaultWithUndock.TrackingUpdatePeriod = 10.000000 s 2025-01-09T22:48:00.931Z,1736462880.931 [MissionManager](INFO): DefineArg DefaultWithUndock.NumberOfPings = 1.000000 count 2025-01-09T22:48:00.954Z,1736462880.954 [MissionManager](INFO): DefineArg DefaultWithUndock.DriftTimeout = 3.000000 min 2025-01-09T22:48:00.956Z,1736462880.956 [DefaultWithUndock:A.Wait](DEBUG): Construct Wait. 2025-01-09T22:48:01.116Z,1736462881.116 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Construct. 2025-01-09T22:48:01.116Z,1736462881.116 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-01-09T22:48:01.161Z,1736462881.161 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-01-09T22:48:01.210Z,1736462881.210 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-01-09T22:48:01.212Z,1736462881.212 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-01-09T22:48:01.235Z,1736462881.235 [DefaultWithUndock:E.Execute](DEBUG): Construct Execute. 2025-01-09T22:48:01.239Z,1736462881.239 [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 = 6 hour """ Maximum time duration for the vehicle to detach form the dock. """ TransponderCode = Dock:Dock.transponderCode """ Dock transponder address. """ TrackingUpdatePeriod = 10 second """ Time duration between acoustic range queries while the mission is detaching from the dock. """ NumberOfPings = 1 count """ Number of pings requested each time. """ DriftTimeout = 3 minute """ How long to allow vehicle to drift away from dock before retrying reverse """ } 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 while ( Universal:depth > Control:VerticalControl.surfaceThreshold ) set contactLabelSetting = TransponderCode set numberOfSamplesSetting = NumberOfPings set updatePeriodSetting = TrackingUpdatePeriod } # Leave the dock behavior Dock:Undock { run in sequence set driftTimeout = DriftTimeout } } 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" } } 2025-01-09T22:48:01.250Z,1736462881.250 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,RDI_Pathfinder,Sonardyne_Nano,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, 2025-01-09T22:48:01.259Z,1736462881.259 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-01-09T22:48:01.412Z,1736462881.412 [Depth_Keller](ERROR): Pressure or depth reading out of range: 824.648376 decibar, 0.000000 m 2025-01-09T22:48:01.413Z,1736462881.413 [Power24vConverter](INFO): Powering up. 2025-01-09T22:48:01.419Z,1736462881.419 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2025-01-09T22:48:01.424Z,1736462881.424 [Sonardyne_Nano](INFO): Initializing. 2025-01-09T22:48:01.502Z,1736462881.502 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-01-09T22:48:01.529Z,1736462881.529 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-01-09T22:48:01.534Z,1736462881.534 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-01-09T22:48:01.535Z,1736462881.535 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-01-09T22:48:01.542Z,1736462881.542 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-01-09T22:48:01.543Z,1736462881.543 [DockingStepper](INFO): Start 2025-01-09T22:48:01.543Z,1736462881.543 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-01-09T22:48:01.550Z,1736462881.550 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-01-09T22:48:01.551Z,1736462881.551 [MassServo](DEBUG): Initializing EZServoServo. 2025-01-09T22:48:01.558Z,1736462881.558 [MassServo](DEBUG): Initializing MassServo. 2025-01-09T22:48:01.559Z,1736462881.559 [RudderServo](DEBUG): Initializing EZServoServo. 2025-01-09T22:48:01.566Z,1736462881.566 [RudderServo](DEBUG): Initializing RudderServo. 2025-01-09T22:48:01.567Z,1736462881.567 [ThrusterServo](DEBUG): Initializing EZServoServo. 2025-01-09T22:48:01.574Z,1736462881.574 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2025-01-09T22:48:01.716Z,1736462881.716 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-01-09T22:48:01.723Z,1736462881.723 [DockingStepper](INFO): Starting 2025-01-09T22:48:02.085Z,1736462882.085 [DockingStepper](INFO): Starting 2025-01-09T22:48:02.618Z,1736462882.618 [DockingStepper](INFO): Starting 2025-01-09T22:48:02.667Z,1736462882.667 [DockingStepper](INFO): Init string: /1z16367aE13561N3m50 2025-01-09T22:48:02.842Z,1736462882.842 [WetLabsBB2FL](INFO): Powering down 2025-01-09T22:48:02.903Z,1736462882.903 [DockingStepper](INFO): Starting 2025-01-09T22:48:03.297Z,1736462883.297 [DockingStepper](INFO): Starting 2025-01-09T22:48:03.685Z,1736462883.685 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-01-09T22:48:03.738Z,1736462883.738 [DockingStepper](INFO): Starting 2025-01-09T22:48:04.162Z,1736462884.162 [DockingStepper](INFO): Starting 2025-01-09T22:48:04.187Z,1736462884.187 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2025-01-09T22:48:04.658Z,1736462884.658 [DockingStepper](INFO): Starting 2025-01-09T22:48:04.935Z,1736462884.935 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2103 2025-01-09T22:48:05.363Z,1736462885.363 [DockingStepper](INFO): Pause 2025-01-09T22:48:05.865Z,1736462885.865 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10 2025-01-09T22:48:05.867Z,1736462885.867 [Radio_Surface](INFO): No local IP found 2025-01-09T22:48:07.254Z,1736462887.254 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2025-01-09T22:48:09.538Z,1736462889.538 [WetLabsUBAT](INFO): Powering down 2025-01-09T22:48:14.535Z,1736462894.535 [DAT](INFO): DAT read: 2025-01-09T22:48:14.536Z,1736462894.536 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-01-09T22:48:23.607Z,1736462903.607 [DAT](INFO): DAT read: MF Frequency Band 2025-01-09T22:48:23.608Z,1736462903.608 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.17.2 2025-01-09T22:48:23.609Z,1736462903.609 [DAT](INFO): DAT read: Jan 9 2025 22:47:01 2025-01-09T22:48:24.627Z,1736462904.627 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-01-09T22:48:24.628Z,1736462904.628 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-01-09T22:48:24.629Z,1736462904.629 [DAT](INFO): commRate: 600 2025-01-09T22:48:26.694Z,1736462906.694 [DAT](INFO): entering command mode 2025-01-09T22:48:26.895Z,1736462906.895 [DAT](INFO): DAT read: 2025-01-09T22:48:26.895Z,1736462906.895 [DAT](INFO): DAT read: user:1> 2025-01-09T22:48:26.896Z,1736462906.896 [DAT](INFO): setting verbose to 3 2025-01-09T22:48:27.147Z,1736462907.147 [DAT](INFO): DAT read: user:1> 2025-01-09T22:48:27.148Z,1736462907.148 [DAT](INFO): DAT read: Verbose | 3 2025-01-09T22:48:27.148Z,1736462907.148 [DAT](INFO): set verbose to 3 2025-01-09T22:48:27.148Z,1736462907.148 [DAT](INFO): setting DatVerbose to 27440 2025-01-09T22:48:27.399Z,1736462907.399 [DAT](INFO): DAT read: user:2> 2025-01-09T22:48:27.400Z,1736462907.400 [DAT](INFO): DAT read: DatVerbose | 27440 2025-01-09T22:48:27.400Z,1736462907.400 [DAT](INFO): set DatVerbose to 27440 2025-01-09T22:48:27.400Z,1736462907.400 [DAT](INFO): setting transmit power to 8 2025-01-09T22:48:27.652Z,1736462907.652 [DAT](INFO): DAT read: user:3> 2025-01-09T22:48:27.653Z,1736462907.653 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-01-09T22:48:27.653Z,1736462907.653 [DAT](INFO): set transmit power to 8 2025-01-09T22:48:27.653Z,1736462907.653 [DAT](INFO): setting local address to 10 2025-01-09T22:48:27.903Z,1736462907.903 [DAT](INFO): DAT read: user:4> 2025-01-09T22:48:27.903Z,1736462907.903 [DAT](INFO): DAT read: LocalAddr | 10 2025-01-09T22:48:27.904Z,1736462907.904 [DAT](INFO): set local address to 10 2025-01-09T22:48:27.905Z,1736462907.905 [DAT](INFO): Setting time to: 22:48:27 And date to:1/9/2025 2025-01-09T22:48:28.155Z,1736462908.155 [DAT](INFO): DAT read: user:5> 2025-01-09T22:48:28.156Z,1736462908.156 [DAT](INFO): DAT read: Thu Jan 9, 2025 22:48:27 2025-01-09T22:48:28.156Z,1736462908.156 [DAT](INFO): Local DAT time set to Thu Jan 9, 2025 22:48:27 2025-01-09T22:48:29.148Z,1736462909.148 [NAL9602](INFO): Powering up NAL9602 2025-01-09T22:48:40.068Z,1736462920.068 [NAL9602](INFO): NAL9602 initialized 2025-01-09T22:48:55.024Z,1736462935.024 [NAL9602](INFO): SBD MO Status=0, MOMSN=46964, MT Status=0, MTMSN=0 2025-01-09T22:48:55.025Z,1736462935.025 [NAL9602](INFO): No messages in MT queue 2025-01-09T22:48:59.453Z,1736462939.453 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224900.00,A,3654.26263,N,12206.49349,W,0.622,0.00,090125,,,A*7B 2025-01-09T22:48:59.457Z,1736462939.457 [NAL9602](INFO): GPS fix at 20250109T224900: (36.904377, -122.108225) 2025-01-09T22:49:31.773Z,1736462971.773 [NAL9602](INFO): Not Powering down - fast GPS 2025-01-09T22:49:47.558Z,1736462987.558 [SBIT](IMPORTANT): Beginning Startup BIT 2025-01-09T22:49:47.563Z,1736462987.563 [CBIT](IMPORTANT): Beginning ground fault scan 2025-01-09T22:49:59.053Z,1736462999.053 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.028419 CHAN A1 (24V): 0.031061 CHAN A2 (12V): 0.019662 CHAN A3 (5V): 0.005782 CHAN B0 (3.3V): 0.004530 CHAN B1 (3.15aV): 0.003989 CHAN B2 (3.15bV): 0.004366 CHAN B3 (GND): -0.000328 OPEN: -0.000200 Full Scale: +/- 1 mA 2025-01-09T22:50:27.356Z,1736463027.356 [SBIT](FAULT): Rudder: EXPECTED:-15.000000 ACTUAL:-14.463218 2025-01-09T22:50:27.356Z,1736463027.356 [SBIT](FAULT): Control surface position failure. 2025-01-09T22:50:41.422Z,1736463041.422 [SBIT](CRITICAL): SBIT FAILED 2025-01-09T22:50:41.422Z,1736463041.422 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-01-09T22:50:41.423Z,1736463041.423 [SBIT](IMPORTANT): CBIT.gf24Offset=173 microampere; 2025-01-09T22:50:41.423Z,1736463041.423 [SBIT](IMPORTANT): DAT.convertPhaseDataToDirection=0 bool; 2025-01-09T22:50:41.423Z,1736463041.423 [SBIT](IMPORTANT): DockingStepper.closedValue=16450 count; 2025-01-09T22:50:41.423Z,1736463041.423 [SBIT](IMPORTANT): DockingStepper.slideValue=10700 count; 2025-01-09T22:50:41.423Z,1736463041.423 [SBIT](IMPORTANT): LineCapture.navigationGain=3 none; 2025-01-09T22:50:41.423Z,1736463041.423 [SBIT](IMPORTANT): LineCapture.openLoopFlyby=0 bool; 2025-01-09T22:50:41.424Z,1736463041.424 [SBIT](IMPORTANT): LineCapture.rolloutSpeed=0 meter_per_second; 2025-01-09T22:50:41.424Z,1736463041.424 [SBIT](IMPORTANT): RudderServo.offsetAngle=0.2 degree; 2025-01-09T22:50:41.424Z,1736463041.424 [SBIT](IMPORTANT): SpeedControl.rollOptimum=1.100000 meter_per_second; 2025-01-09T22:50:41.424Z,1736463041.424 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=401.869368 cubic_centimeter; 2025-01-09T22:50:41.424Z,1736463041.424 [SBIT](IMPORTANT): VerticalControl.massDefault=21.805965 millimeter; 2025-01-09T22:50:41.424Z,1736463041.424 [SBIT](IMPORTANT): VerticalControl.massOnlyForceInt=0 bool; 2025-01-09T22:50:41.426Z,1736463041.426 [CommandExec](FAULT): Scheduling is paused 2025-01-09T22:50:41.430Z,1736463041.430 [CBIT](INFO): Critical error at 20250109T225041 2025-01-09T22:50:41.430Z,1736463041.430 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-01-09T22:50:41.786Z,1736463041.786 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-01-09T22:50:41.787Z,1736463041.787 [DefaultWithUndock] Running Loop=1 2025-01-09T22:50:41.787Z,1736463041.787 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-01-09T22:50:41.787Z,1736463041.787 [DefaultWithUndock:A.Wait] Running Loop=1 2025-01-09T22:50:41.787Z,1736463041.787 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-01-09T22:50:49.963Z,1736463049.963 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:51:12.091Z,1736463072.091 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-01-09T22:51:12.091Z,1736463072.091 [DefaultWithUndock:A.Wait] Stopped 2025-01-09T22:51:12.091Z,1736463072.091 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-01-09T22:51:12.091Z,1736463072.091 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-01-09T22:51:12.091Z,1736463072.091 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-01-09T22:51:12.091Z,1736463072.091 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-01-09T22:51:12.092Z,1736463072.092 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-01-09T22:51:12.092Z,1736463072.092 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-01-09T22:51:12.092Z,1736463072.092 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-01-09T22:51:12.092Z,1736463072.092 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-01-09T22:51:12.478Z,1736463072.478 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-01-09T22:51:12.478Z,1736463072.478 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-01-09T22:51:12.479Z,1736463072.479 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth -0.015243 m. 2025-01-09T22:51:12.480Z,1736463072.480 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-01-09T22:51:12.480Z,1736463072.480 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-01-09T22:51:12.485Z,1736463072.485 [DockingStepper](INFO): Resume 2025-01-09T22:51:12.883Z,1736463072.883 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-01-09T22:51:12.889Z,1736463072.889 [DockingStepper](INFO): Resuming 2025-01-09T22:51:13.319Z,1736463073.319 [DockingStepper](INFO): Start 2025-01-09T22:51:13.319Z,1736463073.319 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-01-09T22:51:13.439Z,1736463073.439 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-01-09T22:51:13.710Z,1736463073.710 [DockingStepper](INFO): Starting 2025-01-09T22:51:14.243Z,1736463074.243 [DockingStepper](INFO): Starting 2025-01-09T22:51:14.543Z,1736463074.543 [DockingStepper](INFO): Starting 2025-01-09T22:51:14.591Z,1736463074.591 [DockingStepper](INFO): Init string: /1z16366aE13561N3m50 2025-01-09T22:51:14.935Z,1736463074.935 [DockingStepper](INFO): Starting 2025-01-09T22:51:15.386Z,1736463075.386 [DockingStepper](INFO): Starting 2025-01-09T22:51:15.747Z,1736463075.747 [DockingStepper](INFO): Starting 2025-01-09T22:51:16.147Z,1736463076.147 [DockingStepper](INFO): Starting 2025-01-09T22:51:16.171Z,1736463076.171 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2025-01-09T22:51:16.547Z,1736463076.547 [DockingStepper](INFO): Starting 2025-01-09T22:51:21.106Z,1736463081.106 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:51:33.099Z,1736463093.099 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning docking module to standby. 2025-01-09T22:51:33.489Z,1736463093.489 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-01-09T22:51:33.885Z,1736463093.885 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:LeaveDock] Stopped 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-01-09T22:51:33.886Z,1736463093.886 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-01-09T22:51:33.887Z,1736463093.887 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-01-09T22:51:33.887Z,1736463093.887 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-01-09T22:51:33.888Z,1736463093.888 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-01-09T22:51:33.888Z,1736463093.888 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-01-09T22:51:33.888Z,1736463093.888 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-01-09T22:51:33.889Z,1736463093.889 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-01-09T22:51:34.295Z,1736463094.295 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-01-09T22:51:34.295Z,1736463094.295 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-01-09T22:51:34.295Z,1736463094.295 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-01-09T22:51:34.439Z,1736463094.439 [DockingStepper](INFO): Pause 2025-01-09T22:51:34.696Z,1736463094.696 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-01-09T22:51:36.371Z,1736463096.371 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225137.00,A,3654.26622,N,12206.47066,W,1.322,69.73,090125,,,A*48 2025-01-09T22:51:36.373Z,1736463096.373 [NAL9602](INFO): GPS fix at 20250109T225137: (36.904437, -122.107844) 2025-01-09T22:51:36.385Z,1736463096.385 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-01-09T22:51:36.385Z,1736463096.385 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-01-09T22:51:36.780Z,1736463096.780 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-01-09T22:51:50.100Z,1736463110.100 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004330 2025-01-09T22:51:59.201Z,1736463119.201 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250109T215503/Courier0018.lzma 2025-01-09T22:52:00.204Z,1736463120.204 [DataOverHttps](INFO): Moved sent file to Logs/20250109T215503/Courier0018.lzma.bak 2025-01-09T22:52:00.204Z,1736463120.204 [DataOverHttps](INFO): SBD MOMSN=23891299 2025-01-09T22:52:03.358Z,1736463123.358 [NAL9602](INFO): SBD MO Status=2, MOMSN=46965, MT Status=2, MTMSN=0 2025-01-09T22:52:03.358Z,1736463123.358 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-01-09T22:52:21.347Z,1736463141.347 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20250109T224747/Courier0000.lzma 2025-01-09T22:52:22.348Z,1736463142.348 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Courier0000.lzma.bak 2025-01-09T22:52:22.348Z,1736463142.348 [DataOverHttps](INFO): SBD MOMSN=23891301 2025-01-09T22:52:34.106Z,1736463154.106 [NAL9602](INFO): Not Powering down - fast GPS 2025-01-09T22:52:43.149Z,1736463163.149 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250109T215503/Express0019.lzma 2025-01-09T22:52:44.152Z,1736463164.152 [DataOverHttps](INFO): Moved sent file to Logs/20250109T215503/Express0019.lzma.bak 2025-01-09T22:52:44.152Z,1736463164.152 [DataOverHttps](INFO): SBD MOMSN=23891306 2025-01-09T22:53:03.232Z,1736463183.232 [DataOverHttps](INFO): Sending 1235 bytes from file Logs/20250109T224747/Express0001.lzma 2025-01-09T22:53:04.232Z,1736463184.232 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Express0001.lzma.bak 2025-01-09T22:53:04.232Z,1736463184.232 [DataOverHttps](INFO): SBD MOMSN=23891308 2025-01-09T22:53:08.075Z,1736463188.075 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped 2025-01-09T22:53:08.075Z,1736463188.075 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1 2025-01-09T22:53:08.075Z,1736463188.075 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-01-09T22:53:28.914Z,1736463208.914 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:53:37.510Z,1736463217.510 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:53:46.242Z,1736463226.242 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:53:54.995Z,1736463234.995 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:54:02.496Z,1736463242.496 [DataOverHttps](IMPORTANT): SBD MTMSN=20250109T225404 2025-01-09T22:54:10.302Z,1736463250.302 [DataOverHttps](INFO): Received command: sched asap "load Maintenance/optimize_roll_speed.tl;set optimize_roll_speed.NeedCommsTime 60 min;set optimize_roll_speed.Latitude 36.8964 degree;set optimize_roll_speed.Longitude -122.11969 degree" 51ea2 1 2 2025-01-09T22:54:10.315Z,1736463250.315 [CommandExec](IMPORTANT): got command schedule asap "load Maintenance/optimize_roll_speed.tl;set optimize_roll_speed.NeedCommsTime 60 min;set optimize_roll_speed.Latitude 36.8964 degree;set optimize_roll_speed.Longitude -122.11969 degree" 51ea2 1 2.000000 2025-01-09T22:54:10.315Z,1736463250.315 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=51ea2 2025-01-09T22:54:10.316Z,1736463250.316 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='51ea2'): "load Maintenance/optimize_roll_speed.tl;set optimize_roll_speed.NeedCommsTime 60 min;set optimize_roll_speed.Latitude 36.8964 degree;set optimize_roll_speed.Longitude -122.11969 degree", ASAP 2025-01-09T22:54:11.304Z,1736463251.304 [DataOverHttps](IMPORTANT): SBD MTMSN=20250109T225413 2025-01-09T22:54:22.455Z,1736463262.455 [DataOverHttps](INFO): Received command: sched asap "set optimize_roll_speed.TargetRollAngle 5 degree;set optimize_roll_speed.RollError 0.5 degree;run" 51ea2 2 2 2025-01-09T22:54:22.473Z,1736463262.473 [CommandExec](IMPORTANT): got command schedule asap "set optimize_roll_speed.TargetRollAngle 5 degree;set optimize_roll_speed.RollError 0.5 degree;run" 51ea2 2 2.000000 2025-01-09T22:54:22.474Z,1736463262.474 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=51ea2 2025-01-09T22:54:22.475Z,1736463262.475 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='51ea2'): "set optimize_roll_speed.TargetRollAngle 5 degree;set optimize_roll_speed.RollError 0.5 degree;run", ASAP 2025-01-09T22:54:22.607Z,1736463262.607 [CommandExec](IMPORTANT): got command load ./Missions/Maintenance/optimize_roll_speed.tl 2025-01-09T22:54:22.608Z,1736463262.608 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/optimize_roll_speed.tl 2025-01-09T22:54:22.608Z,1736463262.608 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Maintenance/optimize_roll_speed.tl 2025-01-09T22:54:22.615Z,1736463262.615 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Maintenance/optimize_roll_speed.tl 2025-01-09T22:54:24.447Z,1736463264.447 [MissionManager](DEBUG): TethyslAPI: ./Missions/Maintenance/optimize_roll_speed.tl translated into: 60 30 NaN NaN 30 0.9 0 2 1.1 0.6 5 0.05 0.025 35 1 7 1 2025-01-09T22:54:24.458Z,1736463264.458 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:54:24.466Z,1736463264.466 [MissionManager](INFO): DefineArg optimize_roll_speed.MissionTimeout = 60.000000 min 2025-01-09T22:54:24.475Z,1736463264.475 [MissionManager](INFO): DefineArg optimize_roll_speed.NeedCommsTime = 30.000000 min 2025-01-09T22:54:24.484Z,1736463264.484 [MissionManager](INFO): DefineArg optimize_roll_speed.Latitude = nan arcdeg 2025-01-09T22:54:24.492Z,1736463264.492 [MissionManager](INFO): DefineArg optimize_roll_speed.Longitude = nan arcdeg 2025-01-09T22:54:24.534Z,1736463264.534 [MissionManager](INFO): DefineArg optimize_roll_speed.Depth = 30.000000 m 2025-01-09T22:54:24.537Z,1736463264.537 [MissionManager](INFO): DefineArg optimize_roll_speed.StartSpeed = 0.900000 m/s 2025-01-09T22:54:24.545Z,1736463264.545 [MissionManager](INFO): DefineArg optimize_roll_speed.TargetRollAngle = 0.000000 arcdeg 2025-01-09T22:54:24.597Z,1736463264.597 [MissionManager](INFO): DefineArg optimize_roll_speed.RollError = 2.000000 arcdeg 2025-01-09T22:54:24.613Z,1736463264.613 [MissionManager](INFO): DefineArg optimize_roll_speed.MaxSpeed = 1.100000 m/s 2025-01-09T22:54:24.657Z,1736463264.657 [MissionManager](INFO): DefineArg optimize_roll_speed.MinSpeed = 0.600000 m/s 2025-01-09T22:54:24.665Z,1736463264.665 [MissionManager](INFO): DefineArg optimize_roll_speed.WindowLen = 5.000000 min 2025-01-09T22:54:24.683Z,1736463264.683 [MissionManager](INFO): DefineArg optimize_roll_speed.InitStep = 0.050000 m/s 2025-01-09T22:54:24.691Z,1736463264.691 [MissionManager](INFO): DefineArg optimize_roll_speed.MinStep = 0.025000 m/s 2025-01-09T22:54:24.701Z,1736463264.701 [MissionManager](INFO): DefineArg optimize_roll_speed.Verbose = 1 bool 2025-01-09T22:54:24.719Z,1736463264.719 [MissionManager](INFO): DefineArg optimize_roll_speed.MaxDepth = 35.000000 m 2025-01-09T22:54:24.745Z,1736463264.745 [MissionManager](INFO): DefineArg optimize_roll_speed.MinOffshore = 1.000000 km 2025-01-09T22:54:24.793Z,1736463264.793 [MissionManager](INFO): DefineArg optimize_roll_speed.MinAltitude = 7.000000 m 2025-01-09T22:54:24.801Z,1736463264.801 [MissionManager](INFO): DefineArg optimize_roll_speed.MassHold = 1 bool 2025-01-09T22:54:24.820Z,1736463264.820 [MissionManager](INFO): DefineArg optimize_roll_speed.BuoyancyHold = 1 bool 2025-01-09T22:54:24.827Z,1736463264.827 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2025-01-09T22:54:24.827Z,1736463264.827 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2025-01-09T22:54:24.831Z,1736463264.831 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2025-01-09T22:54:25.740Z,1736463265.740 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into: 1 10 20 NaN 1 1000 7 30 0 last time_fix was: first GPS update timeout Comms timed out after minutes second GPS update timeout 2025-01-09T22:54:25.749Z,1736463265.749 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.DiveInterval = 1.000000 h 2025-01-09T22:54:25.784Z,1736463265.784 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.WaitForPitchUp = 10.000000 min 2025-01-09T22:54:25.799Z,1736463265.799 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.SurfacePitch = 20.000000 arcdeg 2025-01-09T22:54:25.823Z,1736463265.823 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.SurfaceDepthRate = nan m/s 2025-01-09T22:54:25.825Z,1736463265.825 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.SurfaceSpeed = 1.000000 m/s 2025-01-09T22:54:25.840Z,1736463265.840 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.SurfacingTimeout = 1000.000000 s 2025-01-09T22:54:25.860Z,1736463265.860 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.GPSTimeout = 7.000000 min 2025-01-09T22:54:25.869Z,1736463265.869 [MissionManager](INFO): DefineArg optimize_roll_speed:NeedComms.CommsTimeout = 30.000000 min 2025-01-09T22:54:25.901Z,1736463265.901 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-01-09T22:54:25.986Z,1736463265.986 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-01-09T22:54:25.998Z,1736463265.998 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-01-09T22:54:25.999Z,1736463265.999 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-01-09T22:54:26.208Z,1736463266.208 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 0 200 2000 2025-01-09T22:54:26.224Z,1736463266.224 [MissionManager](INFO): DefineArg optimize_roll_speed:StandardEnvelopes.MinAltitude = 5.000000 m 2025-01-09T22:54:26.238Z,1736463266.238 [MissionManager](INFO): DefineArg optimize_roll_speed:StandardEnvelopes.MaxDepthIgnore = 0.000000 m 2025-01-09T22:54:26.254Z,1736463266.254 [MissionManager](INFO): DefineArg optimize_roll_speed:StandardEnvelopes.MaxDepth = 200.000000 m 2025-01-09T22:54:26.272Z,1736463266.272 [MissionManager](INFO): DefineArg optimize_roll_speed:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-01-09T22:54:26.273Z,1736463266.273 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-01-09T22:54:26.305Z,1736463266.305 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-01-09T22:54:26.352Z,1736463266.352 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-01-09T22:54:26.388Z,1736463266.388 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-01-09T22:54:26.388Z,1736463266.388 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-01-09T22:54:26.389Z,1736463266.389 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-01-09T22:54:26.463Z,1736463266.463 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-01-09T22:54:26.495Z,1736463266.495 [MissionManager](INFO): DefineArg optimize_roll_speed:BackseatDriver.EnableBackseat = 0 bool 2025-01-09T22:54:26.497Z,1736463266.497 [optimize_roll_speed:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-01-09T22:54:26.512Z,1736463266.512 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-01-09T22:54:26.513Z,1736463266.513 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-01-09T22:54:26.530Z,1736463266.530 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-01-09T22:54:26.998Z,1736463266.998 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-01-09T22:54:27.063Z,1736463267.063 [MissionManager](INFO): DefineArg optimize_roll_speed:PowerOnly.SampleAll = 0 bool 2025-01-09T22:54:27.065Z,1736463267.065 [MissionManager](INFO): DefineArg optimize_roll_speed:PowerOnly.SampleLoad1 = 0 bool 2025-01-09T22:54:27.084Z,1736463267.084 [MissionManager](INFO): DefineArg optimize_roll_speed:PowerOnly.SampleLoad2 = 0 bool 2025-01-09T22:54:27.099Z,1736463267.099 [MissionManager](INFO): DefineArg optimize_roll_speed:PowerOnly.SampleLoad3 = 0 bool 2025-01-09T22:54:27.124Z,1736463267.124 [MissionManager](INFO): DefineArg optimize_roll_speed:PowerOnly.EnabledPowerOnly = 0 bool 2025-01-09T22:54:27.172Z,1736463267.172 [optimize_roll_speed:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-01-09T22:54:27.191Z,1736463267.191 [optimize_roll_speed:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-01-09T22:54:27.211Z,1736463267.211 [optimize_roll_speed:MassHold.Pitch](DEBUG): Construct. 2025-01-09T22:54:27.260Z,1736463267.260 [optimize_roll_speed:Transit:A.Pitch](DEBUG): Construct. 2025-01-09T22:54:27.290Z,1736463267.290 [optimize_roll_speed:Transit:B.SetRollSpeed](DEBUG): Construct. 2025-01-09T22:54:27.334Z,1736463267.334 [optimize_roll_speed:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-01-09T22:54:27.425Z,1736463267.425 [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 optimize_roll_speed { """ Vehicle transits to desired waypoint while optimizing speed to achieve a target roll angle. """ arguments { MissionTimeout = 60 minute """ Maximum duration of mission """ NeedCommsTime = 30 minute """ How often to surface for communications """ Latitude = NaN degree """ Latitude of waypoint to seek. If set to NaN, uses latitude at mission initialization. """ Longitude = NaN degree """ Longitude of waypoint to seek. If set to NaN, uses longitude at mission initialization. """ Depth = 30 meter """ Depth of flat and level flight during the mission. """ StartSpeed = 0.9 meter_per_second """ Initial speed for roll optimization. """ TargetRollAngle = 0 degree """ Target roll angle for roll speed optimization. """ RollError = 2 degree """ Error tolerance for roll angle during speed optimization. """ MaxSpeed = 1.1 meter_per_second """ Maximum speed for roll speed optimization. """ MinSpeed = 0.6 meter_per_second """ Minimum speed for roll speed optimization. """ WindowLen = 5 minute """ Time window for roll speed optimization. """ InitStep = 0.05 meter_per_second """ Initial step size for roll speed optimization. """ MinStep = 0.025 meter_per_second """ Minimum step size for roll speed optimization. """ Verbose = true """ Enable verbose logging for roll speed optimization. """ MaxDepth = 35 meter """ Maximum depth for the entire mission. """ MinOffshore = 1 kilometer """ Minimum distance offshore for the entire mission. """ MinAltitude = 7 meter """ Minimum height above the sea floor for the entire mission. """ MassHold = true """ Set to True in order to hold mass at default position, False to allow mass to run on its own. """ BuoyancyHold = true """ Set to True in order to hold buoyancy at neutral position, False to allow buoyancy to run on its own. """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime assign in sequence NeedComms:WaitForPitchUp = 1 second insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MinAltitude = MinAltitude assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl call id="StartingMission" refId="NeedComms" behavior Guidance:Buoyancy id="BuoyancyHold" { run while ( BuoyancyHold ) set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch id="MassHold" { run while ( MassHold ) set massPosition = Control:VerticalControl.massDefault } aggregate Transit { run in sequence behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:SetRollSpeed { run in parallel set targetRoll = TargetRollAngle set rollError = RollError set maxSpeed = MaxSpeed set startSpeed = StartSpeed set minSpeed = MinSpeed set estimationWindow = WindowLen set initStep = InitStep set minStep = MinStep set verbose = Verbose set persistResult = true } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude } call id="PhoneHome" refId="NeedComms" } } 2025-01-09T22:54:27.447Z,1736463267.447 [CommandExec](IMPORTANT): Loaded ./Missions/Maintenance/optimize_roll_speed.tl id=optimize_roll_speed 2025-01-09T22:54:41.966Z,1736463281.966 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:54:48.587Z,1736463288.587 [CommandExec](IMPORTANT): got command set optimize_roll_speed.NeedCommsTime 60 minute 2025-01-09T22:54:48.588Z,1736463288.588 [CommandExec](IMPORTANT): got command set optimize_roll_speed.Latitude 36.8964 degree 2025-01-09T22:54:48.589Z,1736463288.589 [CommandExec](IMPORTANT): got command set optimize_roll_speed.Longitude -122.11969 degree 2025-01-09T22:54:54.462Z,1736463294.462 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:54:55.387Z,1736463295.387 [CommandExec](IMPORTANT): got command set optimize_roll_speed.TargetRollAngle 5 degree 2025-01-09T22:54:55.387Z,1736463295.387 [CommandExec](IMPORTANT): got command set optimize_roll_speed.RollError 0.5 degree 2025-01-09T22:54:55.388Z,1736463295.388 [CommandExec](IMPORTANT): got command run 2025-01-09T22:54:55.394Z,1736463295.394 [CommandExec](IMPORTANT): Running 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock] Stopped 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock:SurfaceDefault] Stopped 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Stopped 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-01-09T22:54:55.696Z,1736463295.696 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped 2025-01-09T22:54:55.697Z,1736463295.697 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-01-09T22:54:55.697Z,1736463295.697 [MissionManager](IMPORTANT): Started mission optimize_roll_speed 2025-01-09T22:54:55.697Z,1736463295.697 [optimize_roll_speed] Running Loop=1 2025-01-09T22:54:55.697Z,1736463295.697 [optimize_roll_speed](DEBUG): Aggregate::initialize optimize_roll_speed 2025-01-09T22:54:55.697Z,1736463295.697 [optimize_roll_speed:StandardEnvelopes] Running Loop=1 2025-01-09T22:54:55.697Z,1736463295.697 [optimize_roll_speed:StandardEnvelopes](DEBUG): Aggregate::initialize optimize_roll_speed:StandardEnvelopes 2025-01-09T22:54:55.697Z,1736463295.697 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-01-09T22:54:55.697Z,1736463295.697 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-01-09T22:54:55.698Z,1736463295.698 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-01-09T22:54:55.698Z,1736463295.698 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-01-09T22:54:55.698Z,1736463295.698 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-01-09T22:54:55.698Z,1736463295.698 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-01-09T22:54:55.698Z,1736463295.698 [optimize_roll_speed:BackseatDriver] Running Loop=1 2025-01-09T22:54:55.698Z,1736463295.698 [optimize_roll_speed:BackseatDriver](DEBUG): Aggregate::initialize optimize_roll_speed:BackseatDriver 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly](DEBUG): Aggregate::initialize optimize_roll_speed:PowerOnly 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly:A] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly:B] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly:C] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly:D] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly:E.Wait] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:BuoyancyHold.Buoyancy] Running Loop=1 2025-01-09T22:54:55.699Z,1736463295.699 [optimize_roll_speed:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-01-09T22:54:55.700Z,1736463295.700 [optimize_roll_speed:MassHold.Pitch] Running Loop=1 2025-01-09T22:54:55.700Z,1736463295.700 [optimize_roll_speed:MassHold.Pitch](DEBUG): Initialize. 2025-01-09T22:54:55.700Z,1736463295.700 [optimize_roll_speed:B] Running Loop=1 2025-01-09T22:54:55.701Z,1736463295.701 [optimize_roll_speed:MassHold.Pitch] Running Loop=1 2025-01-09T22:54:55.701Z,1736463295.701 [optimize_roll_speed:BuoyancyHold.Buoyancy] Running Loop=1 2025-01-09T22:54:55.701Z,1736463295.701 [optimize_roll_speed:PowerOnly] Running Loop=1 2025-01-09T22:54:55.702Z,1736463295.702 [optimize_roll_speed:PowerOnly:D] Stopped 2025-01-09T22:54:55.702Z,1736463295.702 [optimize_roll_speed:PowerOnly:C] Stopped 2025-01-09T22:54:55.702Z,1736463295.702 [optimize_roll_speed:PowerOnly:B] Stopped 2025-01-09T22:54:55.702Z,1736463295.702 [optimize_roll_speed:PowerOnly:A] Stopped 2025-01-09T22:54:55.702Z,1736463295.702 [optimize_roll_speed:BackseatDriver] Running Loop=1 2025-01-09T22:54:55.702Z,1736463295.702 [optimize_roll_speed:StandardEnvelopes] Running Loop=1 2025-01-09T22:54:55.702Z,1736463295.702 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-01-09T22:54:55.703Z,1736463295.703 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-01-09T22:54:55.704Z,1736463295.704 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-01-09T22:54:55.704Z,1736463295.704 [optimize_roll_speed:B] Stopped 2025-01-09T22:54:55.705Z,1736463295.705 [optimize_roll_speed:C] Running Loop=1 2025-01-09T22:54:56.081Z,1736463296.081 [optimize_roll_speed:C] Stopped 2025-01-09T22:54:56.081Z,1736463296.081 [optimize_roll_speed:E] Running Loop=1 2025-01-09T22:54:56.489Z,1736463296.489 [optimize_roll_speed:E] Stopped 2025-01-09T22:54:56.489Z,1736463296.489 [optimize_roll_speed:F] Running Loop=1 2025-01-09T22:54:56.873Z,1736463296.873 [optimize_roll_speed:F] Stopped 2025-01-09T22:54:56.873Z,1736463296.873 [optimize_roll_speed:G] Running Loop=1 2025-01-09T22:54:57.284Z,1736463297.284 [optimize_roll_speed:G] Stopped 2025-01-09T22:54:57.284Z,1736463297.284 [optimize_roll_speed:StartingMission] Running Loop=1 2025-01-09T22:54:57.284Z,1736463297.284 [optimize_roll_speed:StartingMission](DEBUG): Aggregate::initialize optimize_roll_speed:StartingMission 2025-01-09T22:54:57.664Z,1736463297.664 [optimize_roll_speed:NeedComms] Running Loop=1 2025-01-09T22:54:57.664Z,1736463297.664 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::initialize optimize_roll_speed:NeedComms 2025-01-09T22:54:57.664Z,1736463297.664 [optimize_roll_speed:NeedComms:B.GoToSurface] Running Loop=1 2025-01-09T22:54:57.664Z,1736463297.664 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-01-09T22:54:57.664Z,1736463297.664 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-01-09T22:54:57.665Z,1736463297.665 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-01-09T22:54:57.665Z,1736463297.665 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-01-09T22:54:57.666Z,1736463297.666 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-01-09T22:54:57.694Z,1736463297.694 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-01-09T22:54:57.694Z,1736463297.694 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-01-09T22:54:57.695Z,1736463297.695 [optimize_roll_speed:NeedComms:A] Running Loop=1 2025-01-09T22:54:57.696Z,1736463297.696 [optimize_roll_speed:NeedComms:A](INFO): last time_fix was: 1736463097.000000 second since 1970/01/01T00:00:00Z 2025-01-09T22:54:57.696Z,1736463297.696 [optimize_roll_speed:NeedComms:A] Stopped 2025-01-09T22:54:58.074Z,1736463298.074 [optimize_roll_speed:NeedComms:C] Running Loop=1 2025-01-09T22:54:58.477Z,1736463298.477 [optimize_roll_speed:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-01-09T22:55:00.061Z,1736463300.061 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225502.00,A,3654.27104,N,12206.44426,W,0.972,83.49,090125,,,D*4D 2025-01-09T22:55:00.063Z,1736463300.063 [NAL9602](INFO): GPS fix at 20250109T225502: (36.904517, -122.107404) 2025-01-09T22:55:00.101Z,1736463300.101 [optimize_roll_speed:NeedComms:C] Stopped 2025-01-09T22:55:00.102Z,1736463300.102 [optimize_roll_speed:NeedComms:D] Running Loop=1 2025-01-09T22:55:00.504Z,1736463300.504 [optimize_roll_speed:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-01-09T22:55:02.854Z,1736463302.854 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250109T224747/Courier0004.lzma 2025-01-09T22:55:03.860Z,1736463303.860 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Courier0004.lzma.bak 2025-01-09T22:55:03.860Z,1736463303.860 [DataOverHttps](INFO): SBD MOMSN=23891340 2025-01-09T22:55:09.769Z,1736463309.769 [NAL9602](INFO): SBD MO Status=1, MOMSN=46965, MT Status=0, MTMSN=0 2025-01-09T22:55:09.769Z,1736463309.769 [NAL9602](INFO): No messages in MT queue 2025-01-09T22:55:22.817Z,1736463322.817 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250109T224747/Courier0007.lzma 2025-01-09T22:55:23.820Z,1736463323.820 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Courier0007.lzma.bak 2025-01-09T22:55:23.820Z,1736463323.820 [DataOverHttps](INFO): SBD MOMSN=23891343 2025-01-09T22:55:40.467Z,1736463340.467 [NAL9602](INFO): Not Powering down - fast GPS 2025-01-09T22:55:43.227Z,1736463343.227 [DataOverHttps](INFO): Sending 544 bytes from file Logs/20250109T224747/Express0005.lzma 2025-01-09T22:55:44.228Z,1736463344.228 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Express0005.lzma.bak 2025-01-09T22:55:44.228Z,1736463344.228 [DataOverHttps](INFO): SBD MOMSN=23891347 2025-01-09T22:55:57.847Z,1736463357.847 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2025-01-09T22:55:57.851Z,1736463357.851 [BPC1](INFO): Received data from all battery sticks. 2025-01-09T22:56:05.665Z,1736463365.665 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250109T224747/Express0008.lzma 2025-01-09T22:56:06.668Z,1736463366.668 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Express0008.lzma.bak 2025-01-09T22:56:06.668Z,1736463366.668 [DataOverHttps](INFO): SBD MOMSN=23891367 2025-01-09T22:56:13.737Z,1736463373.737 [optimize_roll_speed:NeedComms:D] Stopped 2025-01-09T22:56:13.737Z,1736463373.737 [optimize_roll_speed:NeedComms:E] Running Loop=1 2025-01-09T22:56:14.150Z,1736463374.150 [optimize_roll_speed:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-01-09T22:56:15.705Z,1736463375.705 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225617.00,A,3654.27209,N,12206.43364,W,0.389,92.76,090125,,,D*40 2025-01-09T22:56:15.707Z,1736463375.707 [NAL9602](INFO): GPS fix at 20250109T225617: (36.904535, -122.107227) 2025-01-09T22:56:15.779Z,1736463375.779 [optimize_roll_speed:NeedComms:E] Stopped 2025-01-09T22:56:15.780Z,1736463375.780 [optimize_roll_speed:NeedComms](INFO): Completed optimize_roll_speed:NeedComms 2025-01-09T22:56:15.780Z,1736463375.780 [optimize_roll_speed:NeedComms] Stopped 2025-01-09T22:56:15.780Z,1736463375.780 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::uninitialize optimize_roll_speed:NeedComms 2025-01-09T22:56:15.780Z,1736463375.780 [optimize_roll_speed:NeedComms:B.GoToSurface] Stopped 2025-01-09T22:56:15.780Z,1736463375.780 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:StartingMission](INFO): Completed optimize_roll_speed:StartingMission 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:StartingMission] Stopped 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:StartingMission](DEBUG): Aggregate::uninitialize optimize_roll_speed:StartingMission 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:Transit] Running Loop=1 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:Transit](DEBUG): Aggregate::initialize optimize_roll_speed:Transit 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:Transit:A.Pitch] Running Loop=1 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:Transit:A.Pitch](DEBUG): Initialize. 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:Transit:B.SetRollSpeed] Running Loop=1 2025-01-09T22:56:16.165Z,1736463376.165 [optimize_roll_speed:Transit:B.SetRollSpeed](DEBUG): Initialize. 2025-01-09T22:56:16.211Z,1736463376.211 [optimize_roll_speed:Transit:Wpt1.Waypoint] Running Loop=1 2025-01-09T22:56:16.211Z,1736463376.211 [optimize_roll_speed:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2025-01-09T22:56:16.212Z,1736463376.212 [optimize_roll_speed:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.896400,-122.119690 2025-01-09T22:56:16.553Z,1736463376.553 [optimize_roll_speed:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.896400,-122.119690 2025-01-09T22:56:16.553Z,1736463376.553 [optimize_roll_speed:Transit:B.SetRollSpeed] Running Loop=1 2025-01-09T22:56:16.595Z,1736463376.595 [optimize_roll_speed:Transit:A.Pitch] Running Loop=1 2025-01-09T22:56:16.639Z,1736463376.639 [HorizontalControl](DEBUG): kpHeading = 0.400000 2025-01-09T22:56:16.639Z,1736463376.639 [HorizontalControl](DEBUG): kiHeading = 0.001000 2025-01-09T22:56:16.640Z,1736463376.640 [HorizontalControl](DEBUG): kdHeading = 0.050000 2025-01-09T22:56:33.933Z,1736463393.933 [NAL9602](INFO): SBD MO Status=1, MOMSN=46966, MT Status=0, MTMSN=0 2025-01-09T22:56:33.933Z,1736463393.933 [NAL9602](INFO): No messages in MT queue 2025-01-09T22:56:39.056Z,1736463399.056 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:56:48.678Z,1736463408.678 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:56:57.942Z,1736463417.942 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:57:04.518Z,1736463424.518 [NAL9602](INFO): Not Powering down - fast GPS 2025-01-09T22:57:08.082Z,1736463428.082 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:57:25.150Z,1736463445.150 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:57:34.194Z,1736463454.194 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:57:43.239Z,1736463463.239 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:58:13.366Z,1736463493.366 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T22:58:14.370Z,1736463494.370 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:58:42.487Z,1736463522.487 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.251347 2025-01-09T22:58:43.490Z,1736463523.490 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:58:46.214Z,1736463526.214 [Radio_Surface](INFO): Powering down 2025-01-09T22:59:13.611Z,1736463553.611 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T22:59:14.614Z,1736463554.614 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-01-09T22:59:14.614Z,1736463554.614 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T22:59:44.734Z,1736463584.734 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T22:59:45.738Z,1736463585.738 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:00:15.859Z,1736463615.859 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:00:16.862Z,1736463616.862 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:00:46.999Z,1736463646.999 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:00:48.002Z,1736463648.002 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:01:16.332Z,1736463676.332 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 8.627473 degrees over 722 samples 2025-01-09T23:01:16.333Z,1736463676.333 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Adjusting speed to 0.950000 m/s (avg roll: 8.627473 degrees, target: 5.000000 degrees) 2025-01-09T23:01:18.130Z,1736463678.130 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:01:19.134Z,1736463679.134 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:01:49.254Z,1736463709.254 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:01:50.258Z,1736463710.258 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:02:20.378Z,1736463740.378 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:02:21.391Z,1736463741.391 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:02:51.511Z,1736463771.511 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:02:52.514Z,1736463772.514 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:03:22.654Z,1736463802.654 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:03:23.659Z,1736463803.659 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:03:31.296Z,1736463811.296 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25010915043850,35.0 0.0,1501.8, 0 2025-01-09T23:03:53.778Z,1736463833.778 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:03:54.782Z,1736463834.782 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:04:21.066Z,1736463861.066 [RDI_Pathfinder](ERROR): only read 0 of 4 data items for bottom velocity. Device response is::BS +815, +62,A 2025-01-09T23:04:24.902Z,1736463864.902 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:04:25.906Z,1736463865.906 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:04:56.026Z,1736463896.026 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:04:57.031Z,1736463897.031 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:05:27.150Z,1736463927.150 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:05:28.155Z,1736463928.155 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:05:58.274Z,1736463958.274 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:05:59.279Z,1736463959.279 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:06:16.947Z,1736463976.947 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 6.736600 degrees over 740 samples 2025-01-09T23:06:16.948Z,1736463976.948 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Same direction. New step: 0.100000 m/s 2025-01-09T23:06:16.948Z,1736463976.948 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Adjusting speed to 1.050000 m/s (avg roll: 6.736600 degrees, target: 5.000000 degrees) 2025-01-09T23:06:29.398Z,1736463989.398 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:06:30.402Z,1736463990.402 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:07:00.522Z,1736464020.522 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:07:01.527Z,1736464021.527 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:07:31.646Z,1736464051.646 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:07:32.651Z,1736464052.651 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:08:02.770Z,1736464082.770 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:08:03.774Z,1736464083.774 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:08:21.371Z,1736464101.371 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS35.0, +13.4, 0.0,1501.6, 0 2025-01-09T23:08:33.894Z,1736464113.894 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:08:34.898Z,1736464114.898 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:09:05.028Z,1736464145.028 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:09:06.030Z,1736464146.030 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:09:36.154Z,1736464176.154 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:09:37.158Z,1736464177.158 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:10:07.278Z,1736464207.278 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:10:08.282Z,1736464208.282 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:10:38.407Z,1736464238.407 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:10:39.410Z,1736464239.410 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:11:09.530Z,1736464269.530 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:11:10.537Z,1736464270.537 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:11:17.521Z,1736464277.521 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 5.636612 degrees over 739 samples 2025-01-09T23:11:17.521Z,1736464277.521 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Same direction. New step: 0.200000 m/s 2025-01-09T23:11:17.538Z,1736464277.538 [optimize_roll_speed:Transit:B.SetRollSpeed](FAULT): Cannot achieve target roll 5.000000 degrees. Maximum speed reached: 1.100000 m/s 2025-01-09T23:11:17.539Z,1736464277.539 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Adjusting speed to 1.100000 m/s (avg roll: 5.636612 degrees, target: 5.000000 degrees) 2025-01-09T23:11:17.539Z,1736464277.539 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Persisting best achievable speed 1.100000 m/s for 5.000000 degrees roll to config 2025-01-09T23:11:17.547Z,1736464277.547 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-01-09T23:11:17.547Z,1736464277.547 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): CBIT.gf24Offset=173 microampere; 2025-01-09T23:11:17.548Z,1736464277.548 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): DAT.convertPhaseDataToDirection=0 bool; 2025-01-09T23:11:17.549Z,1736464277.549 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): DockingStepper.closedValue=16450 count; 2025-01-09T23:11:17.550Z,1736464277.550 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): DockingStepper.slideValue=10700 count; 2025-01-09T23:11:17.555Z,1736464277.555 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): LineCapture.navigationGain=3 none; 2025-01-09T23:11:17.555Z,1736464277.555 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): LineCapture.openLoopFlyby=0 bool; 2025-01-09T23:11:17.556Z,1736464277.556 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): LineCapture.rolloutSpeed=0 meter_per_second; 2025-01-09T23:11:17.556Z,1736464277.556 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): RudderServo.offsetAngle=0.2 degree; 2025-01-09T23:11:17.557Z,1736464277.557 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): SpeedControl.rollOptimum=1.100000 meter_per_second; 2025-01-09T23:11:17.566Z,1736464277.566 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): VerticalControl.buoyancyNeutral=401.869368 cubic_centimeter; 2025-01-09T23:11:17.567Z,1736464277.567 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): VerticalControl.massDefault=21.805965 millimeter; 2025-01-09T23:11:17.568Z,1736464277.568 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): VerticalControl.massOnlyForceInt=0 bool; 2025-01-09T23:11:40.660Z,1736464300.660 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:11:41.662Z,1736464301.662 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:12:11.782Z,1736464331.782 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:12:12.786Z,1736464332.786 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:12:42.919Z,1736464362.919 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:12:43.922Z,1736464363.922 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:13:14.042Z,1736464394.042 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:13:15.046Z,1736464395.046 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:13:45.166Z,1736464425.166 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:13:46.170Z,1736464426.170 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:14:16.298Z,1736464456.298 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:14:17.302Z,1736464457.302 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:14:47.430Z,1736464487.430 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:14:48.434Z,1736464488.434 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:15:18.554Z,1736464518.554 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:15:19.559Z,1736464519.559 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:15:49.682Z,1736464549.682 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:15:50.686Z,1736464550.686 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:16:18.099Z,1736464578.099 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 4.649623 degrees over 738 samples 2025-01-09T23:16:20.814Z,1736464580.814 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:16:21.818Z,1736464581.818 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:16:51.938Z,1736464611.938 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:16:52.942Z,1736464612.942 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:17:23.070Z,1736464643.070 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:17:24.074Z,1736464644.074 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:17:54.194Z,1736464674.194 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:17:55.198Z,1736464675.198 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:18:25.318Z,1736464705.318 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:18:26.323Z,1736464706.323 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:18:56.452Z,1736464736.452 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:18:57.454Z,1736464737.454 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:19:27.574Z,1736464767.574 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:19:28.578Z,1736464768.578 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:19:58.698Z,1736464798.698 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:19:59.703Z,1736464799.703 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:20:29.822Z,1736464829.822 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:20:30.826Z,1736464830.826 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:21:00.947Z,1736464860.947 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:21:01.950Z,1736464861.950 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:21:18.680Z,1736464878.680 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 4.717800 degrees over 738 samples 2025-01-09T23:21:32.070Z,1736464892.070 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:21:33.074Z,1736464893.074 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:22:03.194Z,1736464923.194 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:22:04.198Z,1736464924.198 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:22:34.362Z,1736464954.362 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:22:35.367Z,1736464955.367 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:23:05.494Z,1736464985.494 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:23:06.498Z,1736464986.498 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:23:36.618Z,1736465016.618 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:23:37.622Z,1736465017.622 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:24:07.743Z,1736465047.743 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:24:08.746Z,1736465048.746 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:24:38.866Z,1736465078.866 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:24:39.870Z,1736465079.870 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:25:09.998Z,1736465109.998 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:25:11.003Z,1736465111.003 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:25:41.122Z,1736465141.122 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:25:42.126Z,1736465142.126 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:26:12.246Z,1736465172.246 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:26:13.250Z,1736465173.250 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:26:19.280Z,1736465179.280 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 5.103190 degrees over 737 samples 2025-01-09T23:26:43.371Z,1736465203.371 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:26:44.374Z,1736465204.374 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:27:14.494Z,1736465234.494 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:27:15.498Z,1736465235.498 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:27:45.626Z,1736465265.626 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:27:46.630Z,1736465266.630 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:28:16.750Z,1736465296.750 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:28:17.754Z,1736465297.754 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:28:47.878Z,1736465327.878 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:28:48.882Z,1736465328.882 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:29:05.719Z,1736465345.719 [optimize_roll_speed:Transit:Wpt1.Waypoint](IMPORTANT): Reached waypoint: 36.896400,-122.119690 2025-01-09T23:29:05.719Z,1736465345.719 [optimize_roll_speed:Transit:Wpt1.Waypoint] Stopped 2025-01-09T23:29:05.719Z,1736465345.719 [optimize_roll_speed:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2025-01-09T23:29:05.719Z,1736465345.719 [optimize_roll_speed:Transit:PhoneHome] Running Loop=1 2025-01-09T23:29:05.719Z,1736465345.719 [optimize_roll_speed:Transit:PhoneHome](DEBUG): Aggregate::initialize optimize_roll_speed:Transit:PhoneHome 2025-01-09T23:29:06.109Z,1736465346.109 [optimize_roll_speed:NeedComms] Running Loop=1 2025-01-09T23:29:06.109Z,1736465346.109 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::initialize optimize_roll_speed:NeedComms 2025-01-09T23:29:06.109Z,1736465346.109 [optimize_roll_speed:NeedComms:B.GoToSurface] Running Loop=1 2025-01-09T23:29:06.109Z,1736465346.109 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-01-09T23:29:06.109Z,1736465346.109 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-01-09T23:29:06.110Z,1736465346.110 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-01-09T23:29:06.110Z,1736465346.110 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-01-09T23:29:06.111Z,1736465346.111 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-01-09T23:29:06.111Z,1736465346.111 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-01-09T23:29:06.111Z,1736465346.111 [optimize_roll_speed:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-01-09T23:29:06.111Z,1736465346.111 [optimize_roll_speed:NeedComms:A] Running Loop=1 2025-01-09T23:29:06.113Z,1736465346.113 [optimize_roll_speed:NeedComms:A](INFO): last time_fix was: 1736463377.000000 second since 1970/01/01T00:00:00Z 2025-01-09T23:29:06.113Z,1736465346.113 [optimize_roll_speed:NeedComms:A] Stopped 2025-01-09T23:29:19.012Z,1736465359.012 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:29:20.014Z,1736465360.014 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:29:50.142Z,1736465390.142 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:29:51.146Z,1736465391.146 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:30:21.270Z,1736465421.270 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:30:22.274Z,1736465422.274 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:30:52.406Z,1736465452.406 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:30:53.412Z,1736465453.412 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:30:54.877Z,1736465454.877 [optimize_roll_speed:NeedComms:C] Running Loop=1 2025-01-09T23:30:55.386Z,1736465455.386 [Radio_Surface](INFO): Powering up 2025-01-09T23:31:00.642Z,1736465460.642 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10 2025-01-09T23:31:00.644Z,1736465460.644 [Radio_Surface](INFO): Found local IP address 10.89.10.2 for eth0 2025-01-09T23:31:19.923Z,1736465479.923 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 4.756979 degrees over 737 samples 2025-01-09T23:31:23.554Z,1736465483.554 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:31:24.558Z,1736465484.558 [DataOverHttps](INFO): Radio surface powered ON. 2025-01-09T23:31:24.558Z,1736465484.558 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:31:54.694Z,1736465514.694 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:31:55.698Z,1736465515.698 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:31:58.297Z,1736465518.297 [NAL9602](INFO): SBD MO Status=2, MOMSN=46967, MT Status=2, MTMSN=0 2025-01-09T23:31:58.297Z,1736465518.297 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-01-09T23:32:25.818Z,1736465545.818 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:32:26.822Z,1736465546.822 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:32:56.942Z,1736465576.942 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:32:57.946Z,1736465577.946 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:33:05.768Z,1736465585.768 [NAL9602](INFO): SBD MO Status=2, MOMSN=46967, MT Status=2, MTMSN=0 2025-01-09T23:33:05.769Z,1736465585.769 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-01-09T23:33:28.086Z,1736465608.086 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:33:29.090Z,1736465609.090 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:33:59.226Z,1736465639.226 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:34:00.230Z,1736465640.230 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:34:30.350Z,1736465670.350 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:34:31.354Z,1736465671.354 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:01.487Z,1736465701.487 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-01-09T23:35:02.490Z,1736465702.490 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:10.143Z,1736465710.143 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003243 2025-01-09T23:35:11.143Z,1736465711.143 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:19.622Z,1736465719.622 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:28.278Z,1736465728.278 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:35.245Z,1736465735.245 [NAL9602](INFO): SBD MO Status=2, MOMSN=46967, MT Status=2, MTMSN=0 2025-01-09T23:35:35.246Z,1736465735.246 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-01-09T23:35:36.968Z,1736465736.968 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:45.507Z,1736465745.507 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:54.194Z,1736465754.194 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:35:59.483Z,1736465759.483 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-01-09T23:36:02.850Z,1736465762.850 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:36:03.125Z,1736465763.125 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233605.00,A,3653.65889,N,12207.04959,W,1.205,100.72,090125,,,D*7B 2025-01-09T23:36:03.128Z,1736465763.128 [NAL9602](INFO): GPS fix at 20250109T233605: (36.894315, -122.117493) 2025-01-09T23:36:03.177Z,1736465763.177 [UniversalFixResidualReporter](INFO): Fix residual: 11.6 %DT, over the last 1662.3 m. Residual distance 192.6 m at bearing -45.5 degrees. Fix at (36.8943, -122.1175) with 1457.6 m made good. 2025-01-09T23:36:03.180Z,1736465763.180 [optimize_roll_speed:NeedComms:C] Stopped 2025-01-09T23:36:03.180Z,1736465763.180 [optimize_roll_speed:NeedComms:D] Running Loop=1 2025-01-09T23:36:13.790Z,1736465773.790 [DataOverHttps](INFO): Sending 265 bytes from file Logs/20250109T224747/Courier0010.lzma 2025-01-09T23:36:14.792Z,1736465774.792 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Courier0010.lzma.bak 2025-01-09T23:36:14.792Z,1736465774.792 [DataOverHttps](INFO): SBD MOMSN=23891420 2025-01-09T23:36:20.648Z,1736465780.648 [optimize_roll_speed:Transit:B.SetRollSpeed](IMPORTANT): Averaging window complete. Average roll: 12.639697 degrees over 739 samples 2025-01-09T23:36:35.943Z,1736465795.943 [NAL9602](INFO): Not Powering down - fast GPS 2025-01-09T23:36:37.711Z,1736465797.711 [DataOverHttps](INFO): Sending 1072 bytes from file Logs/20250109T224747/Express0011.lzma 2025-01-09T23:36:38.712Z,1736465798.712 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Express0011.lzma.bak 2025-01-09T23:36:38.712Z,1736465798.712 [DataOverHttps](INFO): SBD MOMSN=23891423 2025-01-09T23:36:42.846Z,1736465802.846 [optimize_roll_speed:NeedComms:D] Stopped 2025-01-09T23:36:42.846Z,1736465802.846 [optimize_roll_speed:NeedComms:E] Running Loop=1 2025-01-09T23:36:44.833Z,1736465804.833 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233647.00,A,3653.65720,N,12207.04522,W,0.739,143.49,090125,,,D*75 2025-01-09T23:36:44.835Z,1736465804.835 [NAL9602](INFO): GPS fix at 20250109T233647: (36.894287, -122.117420) 2025-01-09T23:36:44.894Z,1736465804.894 [optimize_roll_speed:NeedComms:E] Stopped 2025-01-09T23:36:44.895Z,1736465804.895 [optimize_roll_speed:NeedComms](INFO): Completed optimize_roll_speed:NeedComms 2025-01-09T23:36:44.896Z,1736465804.896 [optimize_roll_speed:NeedComms] Stopped 2025-01-09T23:36:44.896Z,1736465804.896 [optimize_roll_speed:NeedComms](DEBUG): Aggregate::uninitialize optimize_roll_speed:NeedComms 2025-01-09T23:36:44.896Z,1736465804.896 [optimize_roll_speed:NeedComms:B.GoToSurface] Stopped 2025-01-09T23:36:44.896Z,1736465804.896 [optimize_roll_speed:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-01-09T23:36:45.307Z,1736465805.307 [optimize_roll_speed:Transit:PhoneHome](INFO): Completed optimize_roll_speed:Transit:PhoneHome 2025-01-09T23:36:45.307Z,1736465805.307 [optimize_roll_speed:Transit:PhoneHome] Stopped 2025-01-09T23:36:45.307Z,1736465805.307 [optimize_roll_speed:Transit:PhoneHome](DEBUG): Aggregate::uninitialize optimize_roll_speed:Transit:PhoneHome 2025-01-09T23:36:45.308Z,1736465805.308 [optimize_roll_speed:Transit](INFO): Completed optimize_roll_speed:Transit 2025-01-09T23:36:45.308Z,1736465805.308 [optimize_roll_speed:Transit] Stopped 2025-01-09T23:36:45.308Z,1736465805.308 [optimize_roll_speed:Transit](DEBUG): Aggregate::uninitialize optimize_roll_speed:Transit 2025-01-09T23:36:45.308Z,1736465805.308 [optimize_roll_speed:Transit:A.Pitch] Stopped 2025-01-09T23:36:45.308Z,1736465805.308 [optimize_roll_speed:Transit:B.SetRollSpeed] Stopped 2025-01-09T23:36:45.308Z,1736465805.308 [optimize_roll_speed:Transit:B.SetRollSpeed](DEBUG): Uninitialize. 2025-01-09T23:36:45.314Z,1736465805.314 [optimize_roll_speed](INFO): Completed optimize_roll_speed 2025-01-09T23:36:45.314Z,1736465805.314 [MissionManager](INFO): optimize_roll_speed is completed. 2025-01-09T23:36:45.314Z,1736465805.314 [MissionManager](INFO): Uninitializing Mission optimize_roll_speed 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed] Stopped 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed](DEBUG): Aggregate::uninitialize optimize_roll_speed 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes] Stopped 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes](DEBUG): Aggregate::uninitialize optimize_roll_speed:StandardEnvelopes 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:BackseatDriver] Stopped 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:BackseatDriver](DEBUG): Aggregate::uninitialize optimize_roll_speed:BackseatDriver 2025-01-09T23:36:45.315Z,1736465805.315 [optimize_roll_speed:BackseatDriver:A.BackseatDriver] Stopped 2025-01-09T23:36:45.316Z,1736465805.316 [optimize_roll_speed:PowerOnly] Stopped 2025-01-09T23:36:45.316Z,1736465805.316 [optimize_roll_speed:PowerOnly](DEBUG): Aggregate::uninitialize optimize_roll_speed:PowerOnly 2025-01-09T23:36:45.316Z,1736465805.316 [optimize_roll_speed:PowerOnly:E.Wait] Stopped 2025-01-09T23:36:45.316Z,1736465805.316 [optimize_roll_speed:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-01-09T23:36:45.316Z,1736465805.316 [optimize_roll_speed:BuoyancyHold.Buoyancy] Stopped 2025-01-09T23:36:45.316Z,1736465805.316 [optimize_roll_speed:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-01-09T23:36:45.316Z,1736465805.316 [optimize_roll_speed:MassHold.Pitch] Stopped 2025-01-09T23:36:45.679Z,1736465805.679 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-01-09T23:36:45.680Z,1736465805.680 [DefaultWithUndock] Running Loop=1 2025-01-09T23:36:45.680Z,1736465805.680 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-01-09T23:36:45.680Z,1736465805.680 [DefaultWithUndock:A.Wait] Running Loop=1 2025-01-09T23:36:45.680Z,1736465805.680 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-01-09T23:37:03.178Z,1736465823.178 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:37:11.610Z,1736465831.610 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:37:15.555Z,1736465835.555 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-01-09T23:37:15.639Z,1736465835.639 [NAL9602](ERROR): received: +CSQ:1 OK967, 2, 0, 0, 0 OK 2025-01-09T23:37:15.690Z,1736465835.690 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-01-09T23:37:15.690Z,1736465835.690 [DefaultWithUndock:A.Wait] Stopped 2025-01-09T23:37:15.690Z,1736465835.690 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-01-09T23:37:15.691Z,1736465835.691 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-01-09T23:37:15.691Z,1736465835.691 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-01-09T23:37:15.691Z,1736465835.691 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-01-09T23:37:15.691Z,1736465835.691 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-01-09T23:37:15.691Z,1736465835.691 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-01-09T23:37:15.691Z,1736465835.691 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-01-09T23:37:15.691Z,1736465835.691 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-01-09T23:37:15.994Z,1736465835.994 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-01-09T23:37:15.994Z,1736465835.994 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-01-09T23:37:15.995Z,1736465835.995 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth 0.008595 m. 2025-01-09T23:37:15.996Z,1736465835.996 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-01-09T23:37:15.996Z,1736465835.996 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-01-09T23:37:16.005Z,1736465836.005 [DockingStepper](INFO): Resume 2025-01-09T23:37:16.382Z,1736465836.382 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-01-09T23:37:16.415Z,1736465836.415 [DockingStepper](INFO): Resuming 2025-01-09T23:37:16.800Z,1736465836.800 [DockingStepper](INFO): Start 2025-01-09T23:37:16.800Z,1736465836.800 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-01-09T23:37:16.919Z,1736465836.919 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-01-09T23:37:17.256Z,1736465837.256 [DockingStepper](INFO): Starting 2025-01-09T23:37:17.735Z,1736465837.735 [DockingStepper](INFO): Starting 2025-01-09T23:37:18.023Z,1736465838.023 [DockingStepper](INFO): Starting 2025-01-09T23:37:18.070Z,1736465838.070 [DockingStepper](INFO): Init string: /1z16366aE13561N3m50 2025-01-09T23:37:18.439Z,1736465838.439 [DockingStepper](INFO): Starting 2025-01-09T23:37:18.855Z,1736465838.855 [DockingStepper](INFO): Starting 2025-01-09T23:37:19.267Z,1736465839.267 [DockingStepper](INFO): Starting 2025-01-09T23:37:19.639Z,1736465839.639 [DockingStepper](INFO): Starting 2025-01-09T23:37:19.662Z,1736465839.662 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@ 2025-01-09T23:37:20.055Z,1736465840.055 [DockingStepper](INFO): Starting 2025-01-09T23:37:20.330Z,1736465840.330 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:37:29.282Z,1736465849.282 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:37:35.353Z,1736465855.353 [NAL9602](INFO): SBD MO Status=1, MOMSN=46967, MT Status=0, MTMSN=0 2025-01-09T23:37:35.353Z,1736465855.353 [NAL9602](INFO): No messages in MT queue 2025-01-09T23:37:36.575Z,1736465856.575 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning docking module to standby. 2025-01-09T23:37:37.031Z,1736465857.031 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:LeaveDock] Stopped 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-01-09T23:37:37.403Z,1736465857.403 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-01-09T23:37:37.404Z,1736465857.404 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-01-09T23:37:37.404Z,1736465857.404 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-01-09T23:37:37.404Z,1736465857.404 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-01-09T23:37:37.404Z,1736465857.404 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-01-09T23:37:37.405Z,1736465857.405 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-01-09T23:37:37.405Z,1736465857.405 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-01-09T23:37:37.784Z,1736465857.784 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-01-09T23:37:37.784Z,1736465857.784 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-01-09T23:37:37.784Z,1736465857.784 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-01-09T23:37:37.915Z,1736465857.915 [DockingStepper](INFO): Pause 2025-01-09T23:37:38.162Z,1736465858.162 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:37:39.792Z,1736465859.792 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233741.00,A,3653.65505,N,12207.04018,W,0.058,116.09,090125,,,D*7F 2025-01-09T23:37:39.804Z,1736465859.804 [NAL9602](INFO): GPS fix at 20250109T233741: (36.894251, -122.117336) 2025-01-09T23:37:39.815Z,1736465859.815 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-01-09T23:37:39.815Z,1736465859.815 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-01-09T23:37:45.539Z,1736465865.539 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250109T224747/Courier0013.lzma 2025-01-09T23:37:46.544Z,1736465866.544 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Courier0013.lzma.bak 2025-01-09T23:37:46.544Z,1736465866.544 [DataOverHttps](INFO): SBD MOMSN=23891455 2025-01-09T23:38:05.946Z,1736465885.946 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20250109T224747/Express0014.lzma 2025-01-09T23:38:06.948Z,1736465886.948 [DataOverHttps](INFO): Moved sent file to Logs/20250109T224747/Express0014.lzma.bak 2025-01-09T23:38:06.948Z,1736465886.948 [DataOverHttps](INFO): SBD MOMSN=23891460 2025-01-09T23:38:11.987Z,1736465891.987 [NAL9602](INFO): Not Powering down - fast GPS 2025-01-09T23:38:14.501Z,1736465894.501 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped 2025-01-09T23:38:14.501Z,1736465894.501 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1 2025-01-09T23:38:14.501Z,1736465894.501 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-01-09T23:38:36.818Z,1736465916.818 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:38:45.310Z,1736465925.310 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:38:56.502Z,1736465936.502 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-01-09T23:39:04.063Z,1736465944.063 [DataOverHttps](IMPORTANT): SBD MTMSN=20250109T233905 2025-01-09T23:39:11.598Z,1736465951.598 [DataOverHttps](INFO): Received command: restart logs