2025-08-15T23:27:29.856Z,1755300449.856 [Supervisor](DEBUG): Initializing supervisor. 2025-08-15T23:27:29.860Z,1755300449.860 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-08-15T23:27:29.860Z,1755300449.860 [SyncHandler](INFO): Protected caller Thread ID is 2760 2025-08-15T23:27:29.861Z,1755300449.861 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-08-15T23:27:29.862Z,1755300449.862 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-08-15T23:27:29.862Z,1755300449.862 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2761 2025-08-15T23:27:29.866Z,1755300449.866 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-08-15T23:27:29.886Z,1755300449.886 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-08-15T23:27:29.887Z,1755300449.887 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-08-15T23:27:29.887Z,1755300449.887 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2762 2025-08-15T23:27:29.892Z,1755300449.892 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-08-15T23:27:29.893Z,1755300449.893 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-08-15T23:27:29.893Z,1755300449.893 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2763 2025-08-15T23:27:29.896Z,1755300449.896 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-08-15T23:27:29.897Z,1755300449.897 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-08-15T23:27:29.897Z,1755300449.897 [logger ThreadHandler](INFO): Protected caller Thread ID is 2764 2025-08-15T23:27:29.901Z,1755300449.901 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-08-15T23:27:29.901Z,1755300449.901 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-08-15T23:27:29.903Z,1755300449.903 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-08-15T23:27:30.010Z,1755300450.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-08-15T23:27:30.010Z,1755300450.010 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-08-15T23:27:30.250Z,1755300450.250 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-08-15T23:27:30.251Z,1755300450.251 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-08-15T23:27:30.522Z,1755300450.522 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-08-15T23:27:30.523Z,1755300450.523 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-08-15T23:27:30.641Z,1755300450.641 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-08-15T23:27:30.641Z,1755300450.641 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-08-15T23:27:31.404Z,1755300451.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-08-15T23:27:31.405Z,1755300451.405 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-08-15T23:27:32.466Z,1755300452.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-08-15T23:27:32.467Z,1755300452.467 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-08-15T23:27:33.897Z,1755300453.897 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-08-15T23:27:33.897Z,1755300453.897 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-08-15T23:27:34.579Z,1755300454.579 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-08-15T23:27:34.580Z,1755300454.580 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-08-15T23:27:34.937Z,1755300454.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-08-15T23:27:34.937Z,1755300454.937 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-08-15T23:27:35.335Z,1755300455.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-08-15T23:27:35.335Z,1755300455.335 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-08-15T23:27:35.572Z,1755300455.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-08-15T23:27:35.573Z,1755300455.573 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-08-15T23:27:35.728Z,1755300455.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-08-15T23:27:35.728Z,1755300455.728 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-08-15T23:27:35.831Z,1755300455.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-08-15T23:27:35.831Z,1755300455.831 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-08-15T23:27:35.922Z,1755300455.922 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-08-15T23:27:36.115Z,1755300456.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-08-15T23:27:36.116Z,1755300456.116 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-08-15T23:27:36.373Z,1755300456.373 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-08-15T23:27:36.374Z,1755300456.374 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2025-08-15T23:27:36.375Z,1755300456.375 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2025-08-15T23:27:36.472Z,1755300456.472 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2025-08-15T23:27:36.755Z,1755300456.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-08-15T23:27:36.755Z,1755300456.755 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2025-08-15T23:27:36.851Z,1755300456.851 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2025-08-15T23:27:37.030Z,1755300457.030 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2025-08-15T23:27:37.142Z,1755300457.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2025-08-15T23:27:37.262Z,1755300457.262 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2025-08-15T23:27:37.417Z,1755300457.417 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2025-08-15T23:27:37.550Z,1755300457.550 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2025-08-15T23:27:38.009Z,1755300458.009 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2025-08-15T23:27:38.146Z,1755300458.146 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg 2025-08-15T23:27:38.245Z,1755300458.245 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2025-08-15T23:27:38.353Z,1755300458.353 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2025-08-15T23:27:38.452Z,1755300458.452 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2025-08-15T23:27:38.453Z,1755300458.453 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-08-15T23:27:38.460Z,1755300458.460 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-08-15T23:27:38.646Z,1755300458.646 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-08-15T23:27:38.646Z,1755300458.646 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-08-15T23:27:38.814Z,1755300458.814 [BuoyancyServo] Loaded 2025-08-15T23:27:38.814Z,1755300458.814 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-08-15T23:27:38.838Z,1755300458.838 [ElevatorServo] Loaded 2025-08-15T23:27:38.838Z,1755300458.838 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-08-15T23:27:38.861Z,1755300458.861 [MassServo] Loaded 2025-08-15T23:27:38.861Z,1755300458.861 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-08-15T23:27:38.883Z,1755300458.883 [RudderServo] Loaded 2025-08-15T23:27:38.884Z,1755300458.884 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-08-15T23:27:38.902Z,1755300458.902 [ThrusterHE] Loaded 2025-08-15T23:27:38.902Z,1755300458.902 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-08-15T23:27:38.902Z,1755300458.902 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-08-15T23:27:38.903Z,1755300458.903 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-08-15T23:27:39.072Z,1755300459.072 [SBIT](DEBUG): Construct Startup Built In Test. 2025-08-15T23:27:39.087Z,1755300459.087 [SBIT] Loaded 2025-08-15T23:27:39.087Z,1755300459.087 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-08-15T23:27:39.090Z,1755300459.090 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-08-15T23:27:39.111Z,1755300459.111 [IBIT] Loaded 2025-08-15T23:27:39.112Z,1755300459.112 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-08-15T23:27:39.117Z,1755300459.117 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-08-15T23:27:39.318Z,1755300459.318 [CBIT] Loaded 2025-08-15T23:27:39.319Z,1755300459.319 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-08-15T23:27:39.351Z,1755300459.351 [GFScanner] Loaded 2025-08-15T23:27:39.351Z,1755300459.351 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-08-15T23:27:39.352Z,1755300459.352 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-08-15T23:27:39.352Z,1755300459.352 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-08-15T23:27:39.525Z,1755300459.525 [CTD_Seabird] Loaded 2025-08-15T23:27:39.526Z,1755300459.526 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-08-15T23:27:39.527Z,1755300459.527 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406874E0 2025-08-15T23:27:39.527Z,1755300459.527 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2852 2025-08-15T23:27:39.563Z,1755300459.563 [ESPComponent] Loaded 2025-08-15T23:27:39.563Z,1755300459.563 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-08-15T23:27:39.585Z,1755300459.585 [PAR_Licor] Loaded 2025-08-15T23:27:39.586Z,1755300459.586 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-08-15T23:27:39.631Z,1755300459.631 [WetLabsBB2FL] Loaded 2025-08-15T23:27:39.631Z,1755300459.631 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-08-15T23:27:39.632Z,1755300459.632 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B74E0 2025-08-15T23:27:39.632Z,1755300459.632 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2853 2025-08-15T23:27:39.633Z,1755300459.633 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-08-15T23:27:39.634Z,1755300459.634 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-08-15T23:27:39.686Z,1755300459.686 [DepthRateCalculator] Loaded 2025-08-15T23:27:39.686Z,1755300459.686 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-08-15T23:27:39.692Z,1755300459.692 [PitchRateCalculator] Loaded 2025-08-15T23:27:39.692Z,1755300459.692 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-08-15T23:27:39.702Z,1755300459.702 [SpeedCalculator] Loaded 2025-08-15T23:27:39.703Z,1755300459.703 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-08-15T23:27:39.707Z,1755300459.707 [YawRateCalculator] Loaded 2025-08-15T23:27:39.708Z,1755300459.708 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-08-15T23:27:39.728Z,1755300459.728 [ElevatorOffsetCalculator] Loaded 2025-08-15T23:27:39.728Z,1755300459.728 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-08-15T23:27:39.729Z,1755300459.729 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-08-15T23:27:39.729Z,1755300459.729 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-08-15T23:27:39.869Z,1755300459.869 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-08-15T23:27:39.869Z,1755300459.869 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-08-15T23:27:39.899Z,1755300459.899 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-08-15T23:27:39.900Z,1755300459.900 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-08-15T23:27:40.016Z,1755300460.016 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-08-15T23:27:40.016Z,1755300460.016 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-08-15T23:27:40.031Z,1755300460.031 [NavChart] Loaded 2025-08-15T23:27:40.031Z,1755300460.031 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-08-15T23:27:40.037Z,1755300460.037 [UniversalFixResidualReporter] Loaded 2025-08-15T23:27:40.037Z,1755300460.037 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-08-15T23:27:40.038Z,1755300460.038 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-08-15T23:27:40.038Z,1755300460.038 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-08-15T23:27:40.530Z,1755300460.530 [AHRS_M2] Loaded 2025-08-15T23:27:40.530Z,1755300460.530 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-08-15T23:27:40.570Z,1755300460.570 [BackseatComponent] Loaded 2025-08-15T23:27:40.570Z,1755300460.570 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-08-15T23:27:40.571Z,1755300460.571 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A834E0 2025-08-15T23:27:40.571Z,1755300460.571 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2854 2025-08-15T23:27:40.574Z,1755300460.574 [LcmUniversalReporter] Loaded 2025-08-15T23:27:40.575Z,1755300460.575 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-08-15T23:27:41.342Z,1755300461.342 [BPC1] Loaded 2025-08-15T23:27:41.342Z,1755300461.342 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-08-15T23:27:41.445Z,1755300461.445 [DAT] Loaded 2025-08-15T23:27:41.446Z,1755300461.446 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-08-15T23:27:41.447Z,1755300461.447 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB34E0 2025-08-15T23:27:41.447Z,1755300461.447 [DAT ThreadHandler](INFO): Protected caller Thread ID is 2855 2025-08-15T23:27:41.523Z,1755300461.523 [DataOverHttps] Loaded 2025-08-15T23:27:41.523Z,1755300461.523 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-08-15T23:27:41.524Z,1755300461.524 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE34E0 2025-08-15T23:27:41.524Z,1755300461.524 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2856 2025-08-15T23:27:41.549Z,1755300461.549 [Depth_Keller] Loaded 2025-08-15T23:27:41.549Z,1755300461.549 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-08-15T23:27:41.554Z,1755300461.554 [DropWeight] Loaded 2025-08-15T23:27:41.554Z,1755300461.554 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-08-15T23:27:41.596Z,1755300461.596 [DVL_micro] Loaded 2025-08-15T23:27:41.597Z,1755300461.597 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2025-08-15T23:27:41.661Z,1755300461.661 [NAL9602] Loaded 2025-08-15T23:27:41.661Z,1755300461.661 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-08-15T23:27:41.689Z,1755300461.689 [Onboard] Loaded 2025-08-15T23:27:41.689Z,1755300461.689 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-08-15T23:27:41.690Z,1755300461.690 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B134E0 2025-08-15T23:27:41.690Z,1755300461.690 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2857 2025-08-15T23:27:41.705Z,1755300461.705 [Power24vConverter] Loaded 2025-08-15T23:27:41.705Z,1755300461.705 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-08-15T23:27:41.722Z,1755300461.722 [Radio_Surface] Loaded 2025-08-15T23:27:41.722Z,1755300461.722 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-08-15T23:27:41.723Z,1755300461.723 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B434E0 2025-08-15T23:27:41.723Z,1755300461.723 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2858 2025-08-15T23:27:41.739Z,1755300461.739 [Sonardyne_Nano] Loaded 2025-08-15T23:27:41.739Z,1755300461.739 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-08-15T23:27:41.740Z,1755300461.740 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-08-15T23:27:41.741Z,1755300461.741 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-08-15T23:27:41.801Z,1755300461.801 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-08-15T23:27:41.801Z,1755300461.801 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-08-15T23:27:41.857Z,1755300461.857 [VerticalControl](DEBUG): Construct VerticalControl. 2025-08-15T23:27:41.910Z,1755300461.910 [VerticalControl] Loaded 2025-08-15T23:27:41.910Z,1755300461.910 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-08-15T23:27:41.913Z,1755300461.913 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-08-15T23:27:41.958Z,1755300461.958 [HorizontalControl] Loaded 2025-08-15T23:27:41.959Z,1755300461.959 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-08-15T23:27:41.961Z,1755300461.961 [SpeedControl](DEBUG): Construct SpeedControl. 2025-08-15T23:27:41.963Z,1755300461.963 [SpeedControl] Loaded 2025-08-15T23:27:41.963Z,1755300461.963 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-08-15T23:27:41.966Z,1755300461.966 [LoopControl](DEBUG): Construct LoopControl. 2025-08-15T23:27:41.966Z,1755300461.966 [LoopControl] Loaded 2025-08-15T23:27:41.967Z,1755300461.967 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-08-15T23:27:41.967Z,1755300461.967 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-08-15T23:27:41.968Z,1755300461.968 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-08-15T23:27:41.978Z,1755300461.978 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-08-15T23:27:41.979Z,1755300461.979 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-08-15T23:27:42.338Z,1755300462.338 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-08-15T23:27:42.345Z,1755300462.345 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-08-15T23:27:42.347Z,1755300462.347 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-08-15T23:27:42.359Z,1755300462.359 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-08-15T23:27:42.360Z,1755300462.360 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C6A4E0 2025-08-15T23:27:42.361Z,1755300462.361 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2859 2025-08-15T23:27:42.365Z,1755300462.365 [Supervisor](INFO): Main Thread ID is 822 2025-08-15T23:27:42.365Z,1755300462.365 [Supervisor](DEBUG): Running supervisor. 2025-08-15T23:27:42.366Z,1755300462.366 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2860 2025-08-15T23:27:42.366Z,1755300462.366 [CommandExec](INFO): Initializing the command executive. 2025-08-15T23:27:42.368Z,1755300462.368 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2861 2025-08-15T23:27:42.371Z,1755300462.371 [controlThread ThreadHandler](INFO): Handler Thread ID is 2862 2025-08-15T23:27:42.371Z,1755300462.371 [controlThread](DEBUG): Initializing ControlThread 2025-08-15T23:27:42.373Z,1755300462.373 [SBIT](INFO): Initialize SBIT Component. 2025-08-15T23:27:42.374Z,1755300462.374 [SBIT](IMPORTANT): git: 2025-08-15 2025-08-15T23:27:42.374Z,1755300462.374 [SBIT](INFO): git hash: aa1cd939c0bb5080a316c7313ffe69d6279cb338 2025-08-15T23:27:42.374Z,1755300462.374 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-08-15T23:27:42.376Z,1755300462.376 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2025-08-15T23:27:42.377Z,1755300462.377 [SBIT](INFO): Beginning SBIT in 147.000000 seconds. 2025-08-15T23:27:42.377Z,1755300462.377 [IBIT](INFO): Initialize IBIT Component. 2025-08-15T23:27:42.378Z,1755300462.378 [CBIT](DEBUG): Initialize CBIT Component. 2025-08-15T23:27:42.379Z,1755300462.379 [logger ThreadHandler](INFO): Handler Thread ID is 2863 2025-08-15T23:27:42.392Z,1755300462.392 [CBIT](DEBUG): Initialized mux pins. 2025-08-15T23:27:42.392Z,1755300462.392 [CBIT](DEBUG): Initializing the watchdog timer. 2025-08-15T23:27:42.404Z,1755300462.404 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2864 2025-08-15T23:27:42.405Z,1755300462.405 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-08-15T23:27:42.409Z,1755300462.409 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2866 2025-08-15T23:27:42.412Z,1755300462.412 [WetLabsBB2FL](INFO): Powering up 2025-08-15T23:27:42.414Z,1755300462.414 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2868 2025-08-15T23:27:42.416Z,1755300462.416 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-08-15T23:27:42.416Z,1755300462.416 [CBIT](DEBUG): Initializing heartbeat. 2025-08-15T23:27:42.431Z,1755300462.431 [DAT ThreadHandler](INFO): Handler Thread ID is 2869 2025-08-15T23:27:42.431Z,1755300462.431 [DAT](INFO): Powering up 2025-08-15T23:27:42.432Z,1755300462.432 [DAT](DEBUG): Initializing DAT. 2025-08-15T23:27:42.440Z,1755300462.440 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2871 2025-08-15T23:27:42.442Z,1755300462.442 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-08-15T23:27:42.452Z,1755300462.452 [Onboard ThreadHandler](INFO): Handler Thread ID is 2872 2025-08-15T23:27:42.476Z,1755300462.476 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2873 2025-08-15T23:27:42.481Z,1755300462.481 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2874 2025-08-15T23:27:42.483Z,1755300462.483 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-08-15T23:27:42.484Z,1755300462.484 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-08-15T23:27:42.484Z,1755300462.484 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-08-15T23:27:42.484Z,1755300462.484 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-08-15T23:27:42.484Z,1755300462.484 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-08-15T23:27:42.484Z,1755300462.484 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-08-15T23:27:42.485Z,1755300462.485 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-08-15T23:27:42.485Z,1755300462.485 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-08-15T23:27:42.496Z,1755300462.496 [CBIT](DEBUG): Deactivating emergency mode. 2025-08-15T23:27:42.536Z,1755300462.536 [CBIT](DEBUG): Backplane powered. 2025-08-15T23:27:42.536Z,1755300462.536 [GFScanner](DEBUG): Initializing GFScanner 2025-08-15T23:27:42.536Z,1755300462.536 [GFScanner](DEBUG): Deactivating GF circuits. 2025-08-15T23:27:42.544Z,1755300462.544 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-08-15T23:27:42.545Z,1755300462.545 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-08-15T23:27:42.545Z,1755300462.545 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-08-15T23:27:42.545Z,1755300462.545 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-08-15T23:27:42.546Z,1755300462.546 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-08-15T23:27:42.547Z,1755300462.547 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-08-15T23:27:42.547Z,1755300462.547 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-08-15T23:27:42.557Z,1755300462.557 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-08-15T23:27:42.559Z,1755300462.559 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-08-15T23:27:42.559Z,1755300462.559 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-08-15T23:27:42.560Z,1755300462.560 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-08-15T23:27:42.561Z,1755300462.561 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-08-15T23:27:42.562Z,1755300462.562 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-08-15T23:27:42.562Z,1755300462.562 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-08-15T23:27:42.563Z,1755300462.563 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-08-15T23:27:42.676Z,1755300462.676 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-08-15T23:27:42.681Z,1755300462.681 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-08-15T23:27:42.715Z,1755300462.715 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2025-08-15T23:27:42.742Z,1755300462.742 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-08-15T23:27:42.743Z,1755300462.743 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-08-15T23:27:42.765Z,1755300462.765 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-08-15T23:27:42.880Z,1755300462.880 [Radio_Surface](INFO): Powering up 2025-08-15T23:27:43.116Z,1755300463.116 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2025-08-15T23:27:43.122Z,1755300463.122 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-08-15T23:27:43.123Z,1755300463.123 [Default:A.Wait](DEBUG): Construct Wait. 2025-08-15T23:27:43.145Z,1755300463.145 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-08-15T23:27:43.170Z,1755300463.170 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-08-15T23:27:43.198Z,1755300463.198 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-08-15T23:27:43.203Z,1755300463.203 [Default:E.Execute](DEBUG): Construct Execute. 2025-08-15T23:27:43.223Z,1755300463.223 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2025-08-15T23:27:43.228Z,1755300463.228 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter, 2025-08-15T23:27:43.242Z,1755300463.242 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-08-15T23:27:43.308Z,1755300463.308 [Depth_Keller](INFO): Initializing. 2025-08-15T23:27:43.311Z,1755300463.311 [Power24vConverter](INFO): Powering up. 2025-08-15T23:27:43.312Z,1755300463.312 [Sonardyne_Nano](INFO): Initializing. 2025-08-15T23:27:43.340Z,1755300463.340 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-08-15T23:27:43.362Z,1755300463.362 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-08-15T23:27:43.368Z,1755300463.368 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-08-15T23:27:43.369Z,1755300463.369 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-08-15T23:27:43.377Z,1755300463.377 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-08-15T23:27:43.377Z,1755300463.377 [MassServo](DEBUG): Initializing EZServoServo. 2025-08-15T23:27:43.384Z,1755300463.384 [MassServo](DEBUG): Initializing MassServo. 2025-08-15T23:27:43.385Z,1755300463.385 [RudderServo](DEBUG): Initializing EZServoServo. 2025-08-15T23:27:43.392Z,1755300463.392 [RudderServo](DEBUG): Initializing RudderServo. 2025-08-15T23:27:43.393Z,1755300463.393 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-08-15T23:27:43.400Z,1755300463.400 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-08-15T23:27:45.024Z,1755300465.024 [WetLabsBB2FL](INFO): Powering down 2025-08-15T23:27:45.262Z,1755300465.262 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-08-15T23:27:46.552Z,1755300466.552 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213 2025-08-15T23:27:54.529Z,1755300474.529 [DAT](INFO): DAT read: 2025-08-15T23:27:54.530Z,1755300474.530 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-08-15T23:27:56.293Z,1755300476.293 [DAT](INFO): DAT read: MF Frequency Band 2025-08-15T23:27:56.294Z,1755300476.294 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-08-15T23:27:56.295Z,1755300476.295 [DAT](INFO): DAT read: Aug 15 2025 23:27:51 2025-08-15T23:27:57.553Z,1755300477.553 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-08-15T23:27:57.554Z,1755300477.554 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-08-15T23:27:57.554Z,1755300477.554 [DAT](INFO): commRate: 1200 2025-08-15T23:27:59.620Z,1755300479.620 [DAT](INFO): entering command mode 2025-08-15T23:27:59.821Z,1755300479.821 [DAT](INFO): DAT read: 2025-08-15T23:27:59.821Z,1755300479.821 [DAT](INFO): DAT read: user:1> 2025-08-15T23:27:59.822Z,1755300479.822 [DAT](INFO): setting verbose to 3 2025-08-15T23:28:00.073Z,1755300480.073 [DAT](INFO): DAT read: user:1> 2025-08-15T23:28:00.074Z,1755300480.074 [DAT](INFO): DAT read: Verbose | 3 2025-08-15T23:28:00.074Z,1755300480.074 [DAT](INFO): set verbose to 3 2025-08-15T23:28:00.074Z,1755300480.074 [DAT](INFO): setting DatVerbose to 27440 2025-08-15T23:28:00.325Z,1755300480.325 [DAT](INFO): DAT read: user:2> 2025-08-15T23:28:00.326Z,1755300480.326 [DAT](INFO): DAT read: DatVerbose | 27440 2025-08-15T23:28:00.327Z,1755300480.327 [DAT](INFO): set DatVerbose to 27440 2025-08-15T23:28:00.327Z,1755300480.327 [DAT](INFO): setting transmit power to 8 2025-08-15T23:28:00.577Z,1755300480.577 [DAT](INFO): DAT read: user:3> 2025-08-15T23:28:00.577Z,1755300480.577 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-08-15T23:28:00.578Z,1755300480.578 [DAT](INFO): set transmit power to 8 2025-08-15T23:28:00.578Z,1755300480.578 [DAT](INFO): setting local address to 5 2025-08-15T23:28:00.829Z,1755300480.829 [DAT](INFO): DAT read: user:4> 2025-08-15T23:28:00.830Z,1755300480.830 [DAT](INFO): DAT read: LocalAddr | 5 2025-08-15T23:28:00.830Z,1755300480.830 [DAT](INFO): set local address to 5 2025-08-15T23:28:00.831Z,1755300480.831 [DAT](INFO): Setting time to: 23:28:0 And date to:8/15/2025 2025-08-15T23:28:01.081Z,1755300481.081 [DAT](INFO): DAT read: user:5> 2025-08-15T23:28:01.083Z,1755300481.083 [DAT](INFO): DAT read: Fri Aug 15, 2025 23:28:00 2025-08-15T23:28:01.083Z,1755300481.083 [DAT](INFO): Local DAT time set to Fri Aug 15, 2025 23:28:00 2025-08-15T23:28:12.003Z,1755300492.003 [NAL9602](INFO): Powering up NAL9602 2025-08-15T23:28:22.904Z,1755300502.904 [NAL9602](INFO): NAL9602 initialized 2025-08-15T23:29:53.330Z,1755300593.330 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004326 2025-08-15T23:30:10.039Z,1755300610.039 [SBIT](IMPORTANT): Beginning Startup BIT 2025-08-15T23:30:10.043Z,1755300610.043 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-08-15T23:30:14.485Z,1755300614.485 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.005865 CHAN A1 (24V): 0.002885 CHAN A2 (12V): -0.004607 CHAN A3 (5V): -0.002887 CHAN B0 (3.3V): -0.001063 CHAN B1 (3.15aV): -0.001849 CHAN B2 (3.15bV): -0.001444 CHAN B3 (GND): -0.000135 OPEN: 0.006974 Full Scale: +/- 1 mA 2025-08-15T23:30:23.066Z,1755300623.066 [SBIT](FAULT): Rudder: EXPECTED:15.000000 ACTUAL:14.725096 2025-08-15T23:30:42.704Z,1755300642.704 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-08-15T23:30:42.704Z,1755300642.704 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-08-15T23:30:42.852Z,1755300642.852 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-08-15T23:30:43.239Z,1755300643.239 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-08-15T23:30:43.240Z,1755300643.240 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-08-15T23:31:03.905Z,1755300663.905 [SBIT](CRITICAL): SBIT FAILED 2025-08-15T23:31:03.905Z,1755300663.905 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-08-15T23:31:03.906Z,1755300663.906 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count; 2025-08-15T23:31:03.906Z,1755300663.906 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=0 bool; 2025-08-15T23:31:03.906Z,1755300663.906 [SBIT](IMPORTANT): ElevatorServo.currLimit=50 percent; 2025-08-15T23:31:03.906Z,1755300663.906 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree; 2025-08-15T23:31:03.906Z,1755300663.906 [SBIT](IMPORTANT): ThrusterHE.bestEffortMode=1 bool; 2025-08-15T23:31:03.906Z,1755300663.906 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=264.941384 cubic_centimeter; 2025-08-15T23:31:03.906Z,1755300663.906 [SBIT](IMPORTANT): VerticalControl.massDefault=31.919755 millimeter; 2025-08-15T23:31:03.908Z,1755300663.908 [CommandExec](FAULT): Scheduling is paused 2025-08-15T23:31:03.908Z,1755300663.908 [CBIT](INFO): Critical error at 20250815T233103 2025-08-15T23:31:03.908Z,1755300663.908 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-08-15T23:31:04.120Z,1755300664.120 [MissionManager](IMPORTANT): Started mission Startup 2025-08-15T23:31:04.121Z,1755300664.121 [Startup] Running Loop=1 2025-08-15T23:31:04.121Z,1755300664.121 [Startup](DEBUG): Aggregate::initialize Startup 2025-08-15T23:31:04.121Z,1755300664.121 [Startup:A.GoToSurface] Running Loop=1 2025-08-15T23:31:04.121Z,1755300664.121 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:31:04.122Z,1755300664.122 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-15T23:31:04.122Z,1755300664.122 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-15T23:31:04.122Z,1755300664.122 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-15T23:31:04.123Z,1755300664.123 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-15T23:31:04.123Z,1755300664.123 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:31:04.123Z,1755300664.123 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:31:04.125Z,1755300664.125 [Startup:StartupSatComms] Running Loop=1 2025-08-15T23:31:04.125Z,1755300664.125 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-08-15T23:31:04.125Z,1755300664.125 [Startup:StartupSatComms:A] Running Loop=1 2025-08-15T23:31:04.534Z,1755300664.534 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-08-15T23:32:04.321Z,1755300724.321 [Startup:StartupSatComms:A](INFO): Timed out from 2025-08-15T23:31:04.1Z 2025-08-15T23:32:04.322Z,1755300724.322 [Startup:StartupSatComms:A] Stopped 2025-08-15T23:32:04.322Z,1755300724.322 [Startup:StartupSatComms:B] Running Loop=1 2025-08-15T23:32:04.723Z,1755300724.723 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-08-15T23:32:12.013Z,1755300732.013 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250815T223525/Courier0031.lzma 2025-08-15T23:32:13.014Z,1755300733.014 [DataOverHttps](INFO): Moved sent file to Logs/20250815T223525/Courier0031.lzma.bak 2025-08-15T23:32:13.014Z,1755300733.014 [DataOverHttps](INFO): SBD MOMSN=25854167 2025-08-15T23:32:34.260Z,1755300754.260 [DataOverHttps](INFO): Sending 185 bytes from file Logs/20250815T232729/Courier0000.lzma 2025-08-15T23:32:35.262Z,1755300755.262 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0000.lzma.bak 2025-08-15T23:32:35.262Z,1755300755.262 [DataOverHttps](INFO): SBD MOMSN=25854169 2025-08-15T23:32:41.973Z,1755300761.973 [NAL9602](INFO): SBD MO Status=2, MOMSN=21844, MT Status=2, MTMSN=0 2025-08-15T23:32:41.973Z,1755300761.973 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-15T23:32:52.445Z,1755300772.445 [DVL_micro](ERROR): Failed to parse: :WI,+00001,+01424,+01036,+00000,A 2025-08-15T23:32:59.584Z,1755300779.584 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20250815T223525/Express0032.lzma 2025-08-15T23:33:00.586Z,1755300780.586 [DataOverHttps](INFO): Moved sent file to Logs/20250815T223525/Express0032.lzma.bak 2025-08-15T23:33:00.586Z,1755300780.586 [DataOverHttps](INFO): SBD MOMSN=25854173 2025-08-15T23:33:04.594Z,1755300784.594 [Startup:StartupSatComms:B](INFO): Timed out from 2025-08-15T23:32:04.3Z 2025-08-15T23:33:04.594Z,1755300784.594 [Startup:StartupSatComms:B] Stopped 2025-08-15T23:33:04.594Z,1755300784.594 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-08-15T23:33:04.594Z,1755300784.594 [Startup:StartupSatComms] Stopped 2025-08-15T23:33:04.594Z,1755300784.594 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-08-15T23:33:04.595Z,1755300784.595 [Startup](INFO): Completed Startup 2025-08-15T23:33:04.595Z,1755300784.595 [MissionManager](INFO): Startup is completed. 2025-08-15T23:33:04.595Z,1755300784.595 [MissionManager](INFO): Uninitializing Mission Startup 2025-08-15T23:33:04.595Z,1755300784.595 [Startup] Stopped 2025-08-15T23:33:04.595Z,1755300784.595 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-08-15T23:33:04.596Z,1755300784.596 [Startup:A.GoToSurface] Stopped 2025-08-15T23:33:04.596Z,1755300784.596 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-15T23:33:04.982Z,1755300784.982 [MissionManager](IMPORTANT): Started mission Default 2025-08-15T23:33:04.983Z,1755300784.983 [Default] Running Loop=1 2025-08-15T23:33:04.983Z,1755300784.983 [Default](DEBUG): Aggregate::initialize Default 2025-08-15T23:33:04.983Z,1755300784.983 [Default:B.GoToSurface] Running Loop=1 2025-08-15T23:33:04.983Z,1755300784.983 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:33:04.983Z,1755300784.983 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-15T23:33:04.984Z,1755300784.984 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-15T23:33:04.988Z,1755300784.988 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-15T23:33:04.988Z,1755300784.988 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-15T23:33:04.989Z,1755300784.989 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:33:04.989Z,1755300784.989 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:33:04.989Z,1755300784.989 [Default:A.Wait] Running Loop=1 2025-08-15T23:33:04.989Z,1755300784.989 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-08-15T23:33:07.803Z,1755300787.803 [NAL9602](INFO): SBD MO Status=2, MOMSN=21844, MT Status=2, MTMSN=0 2025-08-15T23:33:07.803Z,1755300787.803 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-15T23:33:18.336Z,1755300798.336 [Default:A.Wait](INFO): Done Waiting. 2025-08-15T23:33:18.336Z,1755300798.336 [Default:A.Wait] Stopped 2025-08-15T23:33:18.336Z,1755300798.336 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-08-15T23:33:18.716Z,1755300798.716 [Default:CheckIn] Running Loop=1 2025-08-15T23:33:18.716Z,1755300798.716 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-15T23:33:18.716Z,1755300798.716 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-15T23:33:19.115Z,1755300799.115 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-15T23:33:19.402Z,1755300799.402 [DataOverHttps](INFO): Sending 934 bytes from file Logs/20250815T232729/Express0001.lzma 2025-08-15T23:33:20.402Z,1755300800.402 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0001.lzma.bak 2025-08-15T23:33:20.402Z,1755300800.402 [DataOverHttps](INFO): SBD MOMSN=25854177 2025-08-15T23:33:26.375Z,1755300806.375 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-15T23:33:27.593Z,1755300807.593 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233324.00,A,3648.16310,N,12147.27942,W,0.117,315.17,150825,,,A*71 2025-08-15T23:33:27.597Z,1755300807.597 [NAL9602](INFO): GPS fix at 20250815T233324: (36.802718, -121.787990) 2025-08-15T23:33:27.607Z,1755300807.607 [Default:CheckIn:Read_GPS] Stopped 2025-08-15T23:33:27.607Z,1755300807.607 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-15T23:33:28.036Z,1755300808.036 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-08-15T23:33:45.388Z,1755300825.388 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250815T232729/Courier0004.lzma 2025-08-15T23:33:46.390Z,1755300826.390 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0004.lzma.bak 2025-08-15T23:33:46.390Z,1755300826.390 [DataOverHttps](INFO): SBD MOMSN=25854198 2025-08-15T23:34:00.022Z,1755300840.022 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-15T23:34:05.690Z,1755300845.690 [DataOverHttps](INFO): Sending 411 bytes from file Logs/20250815T232729/Express0005.lzma 2025-08-15T23:34:06.690Z,1755300846.690 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0005.lzma.bak 2025-08-15T23:34:06.690Z,1755300846.690 [DataOverHttps](INFO): SBD MOMSN=25854201 2025-08-15T23:34:09.308Z,1755300849.308 [Default:CheckIn:Read_Iridium] Stopped 2025-08-15T23:34:09.308Z,1755300849.308 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-15T23:34:09.308Z,1755300849.308 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-15T23:34:17.458Z,1755300857.458 [DataOverHttps](IMPORTANT): SBD MTMSN=20250815T233416 2025-08-15T23:34:25.388Z,1755300865.388 [DataOverHttps](INFO): Received command: sched asap "load Transport/keepstation.tl;set keepstation.NeedCommsTime 4 min;set keepstation.Depth 0.01 m;set keepstation.Speed 0 m/s;set keepstation.MinOffshore 0.00001 km;set keepstation:NeedComms.GPSTimeout 2 min" tlh1 1 2 2025-08-15T23:34:25.465Z,1755300865.465 [CommandExec](IMPORTANT): got command schedule asap "load Transport/keepstation.tl;set keepstation.NeedCommsTime 4 min;set keepstation.Depth 0.01 m;set keepstation.Speed 0 m/s;set keepstation.MinOffshore 0.00001 km;set keepstation:NeedComms.GPSTimeout 2 min" tlh1 1 2.000000 2025-08-15T23:34:25.465Z,1755300865.465 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=tlh1 2025-08-15T23:34:25.466Z,1755300865.466 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='tlh1'): "load Transport/keepstation.tl;set keepstation.NeedCommsTime 4 min;set keepstation.Depth 0.01 m;set keepstation.Speed 0 m/s;set keepstation.MinOffshore 0.00001 km;set keepstation:NeedComms.GPSTimeout 2 min", ASAP 2025-08-15T23:34:26.390Z,1755300866.390 [DataOverHttps](IMPORTANT): SBD MTMSN=20250815T233425 2025-08-15T23:34:34.312Z,1755300874.312 [DataOverHttps](INFO): Received command: sched asap "set keepstation:NeedComms.CommsTimeout 0.5 min;set keepstation:BackseatDriver.EnableBackseat 1 bool;run" tlh1 2 2 2025-08-15T23:34:34.411Z,1755300874.411 [CommandExec](IMPORTANT): got command schedule asap "set keepstation:NeedComms.CommsTimeout 0.5 min;set keepstation:BackseatDriver.EnableBackseat 1 bool;run" tlh1 2 2.000000 2025-08-15T23:34:34.412Z,1755300874.412 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=tlh1 2025-08-15T23:34:34.413Z,1755300874.413 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='tlh1'): "set keepstation:NeedComms.CommsTimeout 0.5 min;set keepstation:BackseatDriver.EnableBackseat 1 bool;run", ASAP 2025-08-15T23:34:34.534Z,1755300874.534 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl 2025-08-15T23:34:34.535Z,1755300874.535 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl 2025-08-15T23:34:34.535Z,1755300874.535 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl 2025-08-15T23:34:34.537Z,1755300874.537 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl 2025-08-15T23:34:35.800Z,1755300875.800 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/keepstation.tl translated into: 4 45 NaN NaN 30 15 4 0.75 200 10 10 45 2 0 0 1 2 3 NaN 0 Sinking to Timed out while trying to reach target sink depth at current depth of 2025-08-15T23:34:35.809Z,1755300875.809 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h 2025-08-15T23:34:35.811Z,1755300875.811 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min 2025-08-15T23:34:35.863Z,1755300875.863 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg 2025-08-15T23:34:35.875Z,1755300875.875 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg 2025-08-15T23:34:35.883Z,1755300875.883 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m 2025-08-15T23:34:35.886Z,1755300875.886 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m 2025-08-15T23:34:35.889Z,1755300875.889 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m 2025-08-15T23:34:35.893Z,1755300875.893 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s 2025-08-15T23:34:35.896Z,1755300875.896 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m 2025-08-15T23:34:35.899Z,1755300875.899 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool 2025-08-15T23:34:35.902Z,1755300875.902 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m 2025-08-15T23:34:35.906Z,1755300875.906 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min 2025-08-15T23:34:35.909Z,1755300875.909 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m 2025-08-15T23:34:35.912Z,1755300875.912 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km 2025-08-15T23:34:35.915Z,1755300875.915 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count 2025-08-15T23:34:35.978Z,1755300875.978 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count 2025-08-15T23:34:35.990Z,1755300875.990 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count 2025-08-15T23:34:36.002Z,1755300876.002 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count 2025-08-15T23:34:36.025Z,1755300876.025 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count 2025-08-15T23:34:36.036Z,1755300876.036 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool 2025-08-15T23:34:36.037Z,1755300876.037 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2025-08-15T23:34:36.037Z,1755300876.037 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2025-08-15T23:34:36.038Z,1755300876.038 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2025-08-15T23:34:36.590Z,1755300876.590 [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-08-15T23:34:36.596Z,1755300876.596 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h 2025-08-15T23:34:36.599Z,1755300876.599 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min 2025-08-15T23:34:36.602Z,1755300876.602 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg 2025-08-15T23:34:36.605Z,1755300876.605 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s 2025-08-15T23:34:36.609Z,1755300876.609 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s 2025-08-15T23:34:36.612Z,1755300876.612 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s 2025-08-15T23:34:36.615Z,1755300876.615 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min 2025-08-15T23:34:36.618Z,1755300876.618 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min 2025-08-15T23:34:36.625Z,1755300876.625 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-08-15T23:34:36.801Z,1755300876.801 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-08-15T23:34:36.801Z,1755300876.801 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-08-15T23:34:36.803Z,1755300876.803 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-08-15T23:34:37.136Z,1755300877.136 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 1.5 200 2000 2025-08-15T23:34:37.141Z,1755300877.141 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m 2025-08-15T23:34:37.181Z,1755300877.181 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 1.500000 m 2025-08-15T23:34:37.196Z,1755300877.196 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m 2025-08-15T23:34:37.202Z,1755300877.202 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-08-15T23:34:37.203Z,1755300877.203 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-08-15T23:34:37.277Z,1755300877.277 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-08-15T23:34:37.307Z,1755300877.307 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-08-15T23:34:37.397Z,1755300877.397 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-08-15T23:34:37.398Z,1755300877.398 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-08-15T23:34:37.399Z,1755300877.399 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-08-15T23:34:37.500Z,1755300877.500 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-08-15T23:34:37.516Z,1755300877.516 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool 2025-08-15T23:34:37.519Z,1755300877.519 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-08-15T23:34:37.538Z,1755300877.538 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-08-15T23:34:37.538Z,1755300877.538 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-08-15T23:34:37.539Z,1755300877.539 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-08-15T23:34:38.206Z,1755300878.206 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-08-15T23:34:38.300Z,1755300878.300 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool 2025-08-15T23:34:38.303Z,1755300878.303 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool 2025-08-15T23:34:38.310Z,1755300878.310 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool 2025-08-15T23:34:38.336Z,1755300878.336 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool 2025-08-15T23:34:38.360Z,1755300878.360 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool 2025-08-15T23:34:38.436Z,1755300878.436 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-08-15T23:34:38.438Z,1755300878.438 [keepstation:H.Pitch](DEBUG): Construct. 2025-08-15T23:34:38.536Z,1755300878.536 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-08-15T23:34:38.539Z,1755300878.539 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct. 2025-08-15T23:34:38.560Z,1755300878.560 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct. 2025-08-15T23:34:38.601Z,1755300878.601 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy. 2025-08-15T23:34:38.613Z,1755300878.613 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct. 2025-08-15T23:34:38.619Z,1755300878.619 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct. 2025-08-15T23:34:38.635Z,1755300878.635 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct. 2025-08-15T23:34:38.680Z,1755300878.680 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation. 2025-08-15T23:34:38.698Z,1755300878.698 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-08-15T23:34:38.737Z,1755300878.737 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait. 2025-08-15T23:34:38.780Z,1755300878.780 [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 keepstation { """ Vehicle transits to desired waypoint (or stays put if none is commanded) and stays within the specified radius. """ arguments { MissionTimeout = 4 hour """ Maximum duration of mission """ NeedCommsTime = 45 minute """ How often to surface for communications """ Latitude = NaN degree """ Latitude of waypoint to hold. If NaN, hold the latitude at start of mission. """ Longitude = NaN degree """ Longitude of waypoint to hold. If NaN, hold the longitude at start of mission. """ Depth = 30 meter """ Depth held during drift mode """ ApproachDepth = 15 meter """ Depth for initial approach to station. """ DepthDeadband = 4 meter """ How much vertical drift from the specified depth is allowed in drift mode """ Speed = 0.75 meter_per_second """ Vehicle transit speed. """ Radius = 200 meter """ Radius of circle around waypoint to hold. """ SinkOffSurface = false """ If true, use buoyancy only to decend to SinkDepth before driving to first target depth """ SinkDepth = 10 meter """ Initial depth to decend using only buoyancy before driving """ SinkDepthTimeout = 10 minute """ Max wait time for the vehicle to reach the target depth """ MaxDepth = 45 meter """ Maximum allowable depth during the mission. """ MinOffshore = 2 kilometer """ Minimum distance from the shoreline to maintain """ } output { DiveMode = 0 count """ Mission variable (don't change). The mission sets this variable to switch between dive modes. Initialized to DoingComms. """ DoingComms = 0 count """ Mission variable (don't change). The mission will run in this mode when doing surface comms. """ SurfaceSink = 1 count """ Mission variable (don't change). The mission will run in this mode when sinking from the surface using only buoyancy. """ TransitToStation = 2 count """ Mission variable (don't change). The mission will run in this mode when performing the transit to station """ StationKeep = 3 count """ Mission variable (don't change). The mission will run in this mode when keeping station """ OnStation = false """ Mission variable (don't change). Determines last mode (Transit or StationKeep) to resume after needcomms """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl behavior Guidance:Pitch { run in parallel set massPosition = Control:VerticalControl.massDefault } aggregate SurfaceComms { run when ( called or ( elapsed ( Universal:time_fix ) > NeedCommsTime ) ) assign in sequence DiveMode = DoingComms call priorityHere=false refId="NeedComms" aggregate setTransit { run in sequence break if ( SinkOffSurface or OnStation ) assign in sequence DiveMode = TransitToStation } aggregate setStation { run in sequence break if ( SinkOffSurface or not OnStation ) assign in sequence DiveMode = StationKeep } aggregate setSink { run in sequence break if ( not SinkOffSurface ) assign in sequence DiveMode = SurfaceSink } } call id="StartingMission" priorityHere=false refId="SurfaceComms" aggregate DiveCmd { run when ( called ) aggregate SurfaceSink { run while ( DiveMode == SurfaceSink ) aggregate sink { run in sequence behavior Guidance:Buoyancy id="BuoyancyHold" { run in parallel set position = NaN cc } behavior Guidance:SetSpeed { run in parallel set speed = 0 m/s } syslog info "Sinking to " + SinkDepth~meter behavior Guidance:Pitch { run in sequence timeout duration=SinkDepthTimeout { syslog important "Timed out while trying to reach target sink depth at current depth of " + Universal:depth~meter } set depth = SinkDepth } # Once we've sunk, either resume transit or station keeping depths and speeds aggregate sinkToTransit { run in sequence break if ( OnStation ) assign in sequence DiveMode = TransitToStation } aggregate sinkToStation { run in sequence break if ( not OnStation ) assign in sequence DiveMode = StationKeep } } } aggregate TransitToStation { run while ( DiveMode == TransitToStation ) aggregate dive { run in sequence behavior Guidance:Buoyancy { run in parallel set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch { run in parallel set depth = ApproachDepth } behavior Guidance:SetSpeed { run in parallel set speed = Speed } } } aggregate StationKeep { run while ( DiveMode == StationKeep ) assign in parallel Control:VerticalControl.depthDeadband = DepthDeadband behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:KeepStation { run in parallel set latitude = Latitude set longitude = Longitude set radius = Radius set speed = Speed } } } aggregate TransitToStation { """ Need a separate aggregate for transit if we want to specify a different depth for the approach. """ run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call priorityHere=false refId="DiveCmd" } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude } assign in sequence DiveMode = StationKeep assign in sequence OnStation = true } call id="OnStation" priorityHere=false refId="NeedComms" aggregate KeepStation { run in sequence aggregate Dive { run while ( not ( DiveMode == DoingComms ) ) call priorityHere=false refId="DiveCmd" } behavior Guidance:Wait { """ Due to the way the KeepStation behavior is currently implemented, we must run it in parallel and use a Wait to keep from completing the mission before the timeout expires. However, this new version of the mission uses a top-level timeout so that the entire mission will not run for longer then MissionTimeout. """ run in sequence set duration = MissionTimeout } } } 2025-08-15T23:34:38.780Z,1755300878.780 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation 2025-08-15T23:34:55.570Z,1755300895.570 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 4 minute 2025-08-15T23:34:55.571Z,1755300895.571 [CommandExec](IMPORTANT): got command set keepstation.Depth 0.01 meter 2025-08-15T23:34:55.572Z,1755300895.572 [CommandExec](IMPORTANT): got command set keepstation.Speed 0 meter_per_second 2025-08-15T23:34:55.573Z,1755300895.573 [CommandExec](IMPORTANT): got command set keepstation.MinOffshore 0.00001 kilometer 2025-08-15T23:34:55.574Z,1755300895.574 [CommandExec](IMPORTANT): got command set keepstation:NeedComms.GPSTimeout 2 minute 2025-08-15T23:35:08.938Z,1755300908.938 [DataOverHttps](IMPORTANT): SBD MTMSN=20250815T233508 2025-08-15T23:35:10.598Z,1755300910.598 [CommandExec](IMPORTANT): got command set keepstation:NeedComms.CommsTimeout 0.5 minute 2025-08-15T23:35:10.599Z,1755300910.599 [CommandExec](IMPORTANT): got command set keepstation:BackseatDriver.EnableBackseat 1 bool 2025-08-15T23:35:10.599Z,1755300910.599 [CommandExec](IMPORTANT): got command run 2025-08-15T23:35:10.602Z,1755300910.602 [CommandExec](IMPORTANT): Running 2025-08-15T23:35:10.742Z,1755300910.742 [Default] Stopped 2025-08-15T23:35:10.742Z,1755300910.742 [Default](DEBUG): Aggregate::uninitialize Default 2025-08-15T23:35:10.742Z,1755300910.742 [Default:B.GoToSurface] Stopped 2025-08-15T23:35:10.742Z,1755300910.742 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-15T23:35:10.742Z,1755300910.742 [Default:CheckIn] Stopped 2025-08-15T23:35:10.742Z,1755300910.742 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-15T23:35:10.742Z,1755300910.742 [Default:CheckIn:C.Wait] Stopped 2025-08-15T23:35:10.742Z,1755300910.742 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-15T23:35:10.742Z,1755300910.742 [MissionManager](IMPORTANT): Started mission keepstation 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation] Running Loop=1 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation](DEBUG): Aggregate::initialize keepstation 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation:StandardEnvelopes] Running Loop=1 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-08-15T23:35:10.743Z,1755300910.743 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-08-15T23:35:10.744Z,1755300910.744 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-08-15T23:35:10.744Z,1755300910.744 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-08-15T23:35:10.744Z,1755300910.744 [keepstation:BackseatDriver] Running Loop=1 2025-08-15T23:35:10.744Z,1755300910.744 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver 2025-08-15T23:35:10.744Z,1755300910.744 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-08-15T23:35:10.744Z,1755300910.744 [keepstation:PowerOnly] Running Loop=1 2025-08-15T23:35:10.745Z,1755300910.745 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly 2025-08-15T23:35:10.745Z,1755300910.745 [keepstation:PowerOnly:A] Running Loop=1 2025-08-15T23:35:10.745Z,1755300910.745 [keepstation:PowerOnly:B] Running Loop=1 2025-08-15T23:35:10.745Z,1755300910.745 [keepstation:PowerOnly:C] Running Loop=1 2025-08-15T23:35:10.745Z,1755300910.745 [keepstation:PowerOnly:D] Running Loop=1 2025-08-15T23:35:10.745Z,1755300910.745 [keepstation:PowerOnly:E.Wait] Running Loop=1 2025-08-15T23:35:10.745Z,1755300910.745 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-08-15T23:35:10.746Z,1755300910.746 [keepstation:H.Pitch] Running Loop=1 2025-08-15T23:35:10.746Z,1755300910.746 [keepstation:H.Pitch](DEBUG): Initialize. 2025-08-15T23:35:10.746Z,1755300910.746 [keepstation:B] Running Loop=1 2025-08-15T23:35:10.747Z,1755300910.747 [keepstation:H.Pitch] Running Loop=1 2025-08-15T23:35:10.747Z,1755300910.747 [keepstation:PowerOnly] Running Loop=1 2025-08-15T23:35:10.747Z,1755300910.747 [keepstation:PowerOnly:D] Stopped 2025-08-15T23:35:10.747Z,1755300910.747 [keepstation:PowerOnly:C] Stopped 2025-08-15T23:35:10.752Z,1755300910.752 [keepstation:PowerOnly:B] Stopped 2025-08-15T23:35:10.752Z,1755300910.752 [keepstation:PowerOnly:A] Stopped 2025-08-15T23:35:10.752Z,1755300910.752 [keepstation:BackseatDriver] Running Loop=1 2025-08-15T23:35:10.752Z,1755300910.752 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat 2025-08-15T23:35:10.800Z,1755300910.800 [keepstation:StandardEnvelopes] Running Loop=1 2025-08-15T23:35:10.800Z,1755300910.800 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-08-15T23:35:10.801Z,1755300910.801 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](IMPORTANT): Offshore envelope ACTIVE 2025-08-15T23:35:10.829Z,1755300910.829 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-08-15T23:35:10.830Z,1755300910.830 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-08-15T23:35:10.831Z,1755300910.831 [keepstation:B] Stopped 2025-08-15T23:35:10.831Z,1755300910.831 [keepstation:D] Running Loop=1 2025-08-15T23:35:10.839Z,1755300910.839 [HorizontalControl](DEBUG): kpHeading = 0.400000 2025-08-15T23:35:10.840Z,1755300910.840 [HorizontalControl](DEBUG): kiHeading = 0.001000 2025-08-15T23:35:10.844Z,1755300910.844 [HorizontalControl](DEBUG): kdHeading = 0.050000 2025-08-15T23:35:11.012Z,1755300911.012 [BackseatComponent](INFO): Powering up 2025-08-15T23:35:11.013Z,1755300911.013 [BackseatComponent](INFO): Subscribing to LCM channels. 2025-08-15T23:35:11.144Z,1755300911.144 [keepstation:D] Stopped 2025-08-15T23:35:11.144Z,1755300911.144 [keepstation:E] Running Loop=1 2025-08-15T23:35:11.544Z,1755300911.544 [keepstation:E] Stopped 2025-08-15T23:35:11.544Z,1755300911.544 [keepstation:StartingMission] Running Loop=1 2025-08-15T23:35:11.544Z,1755300911.544 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission 2025-08-15T23:35:11.929Z,1755300911.929 [keepstation:SurfaceComms] Running Loop=1 2025-08-15T23:35:11.929Z,1755300911.929 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-15T23:35:11.929Z,1755300911.929 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-15T23:35:11.930Z,1755300911.930 [keepstation:SurfaceComms:A] Stopped 2025-08-15T23:35:11.930Z,1755300911.930 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-15T23:35:11.930Z,1755300911.930 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-15T23:35:12.413Z,1755300912.413 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active. 2025-08-15T23:35:12.413Z,1755300912.413 [keepstation:NeedComms] Running Loop=1 2025-08-15T23:35:12.413Z,1755300912.413 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-15T23:35:12.413Z,1755300912.413 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-15T23:35:12.413Z,1755300912.413 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:35:12.413Z,1755300912.413 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-15T23:35:12.414Z,1755300912.414 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-15T23:35:12.414Z,1755300912.414 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-15T23:35:12.414Z,1755300912.414 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-15T23:35:12.415Z,1755300912.415 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:35:12.415Z,1755300912.415 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:35:12.415Z,1755300912.415 [keepstation:NeedComms:A] Running Loop=1 2025-08-15T23:35:12.417Z,1755300912.417 [keepstation:NeedComms:A](INFO): last time_fix was: 1755300804.000000 second since 1970/01/01T00:00:00Z 2025-08-15T23:35:12.417Z,1755300912.417 [keepstation:NeedComms:A] Stopped 2025-08-15T23:35:12.765Z,1755300912.765 [keepstation:NeedComms:C] Running Loop=1 2025-08-15T23:35:13.165Z,1755300913.165 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-15T23:35:14.743Z,1755300914.743 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233511.00,A,3648.16284,N,12147.27815,W,0.058,315.17,150825,,,A*74 2025-08-15T23:35:14.746Z,1755300914.746 [NAL9602](INFO): GPS fix at 20250815T233511: (36.802714, -121.787969) 2025-08-15T23:35:14.797Z,1755300914.797 [keepstation:NeedComms:C] Stopped 2025-08-15T23:35:14.797Z,1755300914.797 [keepstation:NeedComms:D] Running Loop=1 2025-08-15T23:35:15.225Z,1755300915.225 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-08-15T23:35:17.223Z,1755300917.223 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250815T232729/Courier0007.lzma 2025-08-15T23:35:17.226Z,1755300917.226 [DataOverHttps](INFO): Received command: sched 20250815T2345 "set keepstation:backseatdriver.enablebackseat 0 bool" 2025-08-15T23:35:17.271Z,1755300917.271 [CommandExec](IMPORTANT): got command schedule 20250815T234500 "set keepstation:backseatdriver.enablebackseat 0 bool" 2025-08-15T23:35:17.273Z,1755300917.273 [CommandExec](IMPORTANT): Scheduled #3: "set keepstation:backseatdriver.enablebackseat 0 bool", AT TIME: 2025-08-15T23:45:00Z 2025-08-15T23:35:17.273Z,1755300917.273 [CommandExec](FAULT): Scheduling was paused by an error at 2025-08-15T23:31:03Z 2025-08-15T23:35:17.641Z,1755300917.641 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0007.lzma.bak 2025-08-15T23:35:17.642Z,1755300917.642 [DataOverHttps](IMPORTANT): SBD MOMSN=25854211, MTMSN=20250815T233517 2025-08-15T23:35:18.311Z,1755300918.311 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-15T23:35:18.332Z,1755300918.332 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-08-15T23:35:18.335Z,1755300918.335 [BPC1](INFO): Received data from all battery sticks. 2025-08-15T23:35:26.492Z,1755300926.492 [DataOverHttps](INFO): Received command: sched 20250815T2350 "set keepstation:backseatdriver.enablebackseat 1 bool" 2025-08-15T23:35:26.498Z,1755300926.498 [CommandExec](IMPORTANT): got command schedule 20250815T235000 "set keepstation:backseatdriver.enablebackseat 1 bool" 2025-08-15T23:35:26.499Z,1755300926.499 [CommandExec](IMPORTANT): Scheduled #4: "set keepstation:backseatdriver.enablebackseat 1 bool", AT TIME: 2025-08-15T23:50:00Z 2025-08-15T23:35:26.499Z,1755300926.499 [CommandExec](FAULT): Scheduling was paused by an error at 2025-08-15T23:31:03Z 2025-08-15T23:35:27.771Z,1755300927.771 [DataOverHttps](IMPORTANT): SBD MTMSN=20250815T233526 2025-08-15T23:35:35.325Z,1755300935.325 [DataOverHttps](INFO): Sending 677 bytes from file Logs/20250815T232729/Express0008.lzma 2025-08-15T23:35:35.329Z,1755300935.329 [DataOverHttps](INFO): Received command: sched 20250816T00 "set keepstation:backseatdriver.enablebackseat 0 bool" 2025-08-15T23:35:35.349Z,1755300935.349 [CommandExec](IMPORTANT): got command schedule 20250816T000000 "set keepstation:backseatdriver.enablebackseat 0 bool" 2025-08-15T23:35:35.349Z,1755300935.349 [CommandExec](IMPORTANT): Scheduled #5: "set keepstation:backseatdriver.enablebackseat 0 bool", AT TIME: 2025-08-16T00:00:00Z 2025-08-15T23:35:35.350Z,1755300935.350 [CommandExec](FAULT): Scheduling was paused by an error at 2025-08-15T23:31:03Z 2025-08-15T23:35:36.620Z,1755300936.620 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0008.lzma.bak 2025-08-15T23:35:36.620Z,1755300936.620 [DataOverHttps](IMPORTANT): SBD MOMSN=25854217, MTMSN=20250815T233535 2025-08-15T23:35:44.031Z,1755300944.031 [DataOverHttps](INFO): Received command: sched 20250816T0005 "set keepstation:backseatdriver.enablebackseat 1 bool" 2025-08-15T23:35:44.085Z,1755300944.085 [CommandExec](IMPORTANT): got command schedule 20250816T000500 "set keepstation:backseatdriver.enablebackseat 1 bool" 2025-08-15T23:35:44.087Z,1755300944.087 [CommandExec](IMPORTANT): Scheduled #6: "set keepstation:backseatdriver.enablebackseat 1 bool", AT TIME: 2025-08-16T00:05:00Z 2025-08-15T23:35:44.087Z,1755300944.087 [CommandExec](FAULT): Scheduling was paused by an error at 2025-08-15T23:31:03Z 2025-08-15T23:35:44.957Z,1755300944.957 [keepstation:NeedComms:D](INFO): Timed out from 2025-08-15T23:35:14.8Z 2025-08-15T23:35:44.957Z,1755300944.957 [keepstation:NeedComms:D:A_Timeout] Running Loop=1 2025-08-15T23:35:44.957Z,1755300944.957 [keepstation:NeedComms:D:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:D:A_Timeout 2025-08-15T23:35:44.958Z,1755300944.958 [keepstation:NeedComms:D:A_Timeout:A] Running Loop=1 2025-08-15T23:35:44.958Z,1755300944.958 [keepstation:NeedComms:D:A_Timeout:A](IMPORTANT): Comms timed out after 0.500000 min minutes 2025-08-15T23:35:44.958Z,1755300944.958 [keepstation:NeedComms:D:A_Timeout:A] Stopped 2025-08-15T23:35:44.958Z,1755300944.958 [keepstation:NeedComms:D:A_Timeout](INFO): Completed keepstation:NeedComms:D:A_Timeout 2025-08-15T23:35:44.958Z,1755300944.958 [keepstation:NeedComms:D] Stopped 2025-08-15T23:35:44.959Z,1755300944.959 [keepstation:NeedComms:E] Running Loop=1 2025-08-15T23:35:45.030Z,1755300945.030 [DataOverHttps](IMPORTANT): SBD MTMSN=20250815T233544 2025-08-15T23:35:45.337Z,1755300945.337 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-15T23:35:45.412Z,1755300945.412 [NAL9602](ERROR): received: +CSQ:0 OK844, 2, 0, 0, 0 OK 2025-08-15T23:35:45.434Z,1755300945.434 [keepstation:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-15T23:35:49.703Z,1755300949.703 [BackseatComponent](IMPORTANT): piscivore: running backseat_app backseat application. 2025-08-15T23:35:57.160Z,1755300957.160 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250815T232729/Courier0016.lzma 2025-08-15T23:35:57.162Z,1755300957.162 [DataOverHttps](INFO): Received command: sched 20250816T0015 "restart sys" 2025-08-15T23:35:57.187Z,1755300957.187 [CommandExec](IMPORTANT): got command schedule 20250816T001500 "restart sys" 2025-08-15T23:35:57.188Z,1755300957.188 [CommandExec](IMPORTANT): Scheduled #7: "restart sys", AT TIME: 2025-08-16T00:15:00Z 2025-08-15T23:35:57.189Z,1755300957.189 [CommandExec](FAULT): Scheduling was paused by an error at 2025-08-15T23:31:03Z 2025-08-15T23:35:58.162Z,1755300958.162 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0016.lzma.bak 2025-08-15T23:35:58.162Z,1755300958.162 [DataOverHttps](IMPORTANT): SBD MOMSN=25854245, MTMSN=20250815T233557 2025-08-15T23:36:05.919Z,1755300965.919 [DataOverHttps](INFO): Received command: schedule resume 2025-08-15T23:36:05.936Z,1755300965.936 [CommandExec](IMPORTANT): got command schedule resume 2025-08-15T23:36:05.936Z,1755300965.936 [CommandExec](IMPORTANT): Scheduling is resumed 2025-08-15T23:36:58.859Z,1755301018.859 [NAL9602](INFO): SBD MO Status=2, MOMSN=21844, MT Status=2, MTMSN=0 2025-08-15T23:36:58.859Z,1755301018.859 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-15T23:37:45.337Z,1755301065.337 [keepstation:NeedComms:E](INFO): Timed out from 2025-08-15T23:35:44.0Z 2025-08-15T23:37:45.337Z,1755301065.337 [keepstation:NeedComms:E:A_Timeout] Running Loop=1 2025-08-15T23:37:45.337Z,1755301065.337 [keepstation:NeedComms:E:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:E:A_Timeout 2025-08-15T23:37:45.338Z,1755301065.338 [keepstation:NeedComms:E:A_Timeout:A] Running Loop=1 2025-08-15T23:37:45.338Z,1755301065.338 [keepstation:NeedComms:E:A_Timeout:A](IMPORTANT): second GPS update timeout 2025-08-15T23:37:45.338Z,1755301065.338 [keepstation:NeedComms:E:A_Timeout:A] Stopped 2025-08-15T23:37:45.338Z,1755301065.338 [keepstation:NeedComms:E:A_Timeout](INFO): Completed keepstation:NeedComms:E:A_Timeout 2025-08-15T23:37:45.338Z,1755301065.338 [keepstation:NeedComms:E] Stopped 2025-08-15T23:37:45.339Z,1755301065.339 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-15T23:37:45.339Z,1755301065.339 [keepstation:NeedComms] Stopped 2025-08-15T23:37:45.339Z,1755301065.339 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-15T23:37:45.339Z,1755301065.339 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-15T23:37:45.339Z,1755301065.339 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-15T23:37:45.754Z,1755301065.754 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-15T23:37:45.754Z,1755301065.754 [keepstation:SurfaceComms:B] Stopped 2025-08-15T23:37:45.754Z,1755301065.754 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-15T23:37:45.754Z,1755301065.754 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-15T23:37:45.754Z,1755301065.754 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-15T23:37:45.755Z,1755301065.755 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-15T23:37:46.166Z,1755301066.166 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-15T23:37:46.166Z,1755301066.166 [keepstation:SurfaceComms:setTransit](INFO): Completed keepstation:SurfaceComms:setTransit 2025-08-15T23:37:46.166Z,1755301066.166 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-15T23:37:46.167Z,1755301066.167 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-15T23:37:46.167Z,1755301066.167 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-15T23:37:46.167Z,1755301066.167 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-15T23:37:46.167Z,1755301066.167 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-15T23:37:46.543Z,1755301066.543 [keepstation:SurfaceComms:setStation] Stopped 2025-08-15T23:37:46.543Z,1755301066.543 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-15T23:37:46.543Z,1755301066.543 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-15T23:37:46.543Z,1755301066.543 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-15T23:37:46.543Z,1755301066.543 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-15T23:37:46.543Z,1755301066.543 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-15T23:37:46.969Z,1755301066.969 [keepstation:SurfaceComms:setSink] Stopped 2025-08-15T23:37:46.969Z,1755301066.969 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-15T23:37:46.969Z,1755301066.969 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-15T23:37:46.969Z,1755301066.969 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-15T23:37:46.969Z,1755301066.969 [keepstation:SurfaceComms] Stopped 2025-08-15T23:37:46.969Z,1755301066.969 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-15T23:37:47.356Z,1755301067.356 [keepstation:StartingMission](INFO): Completed keepstation:StartingMission 2025-08-15T23:37:47.356Z,1755301067.356 [keepstation:StartingMission] Stopped 2025-08-15T23:37:47.356Z,1755301067.356 [keepstation:StartingMission](DEBUG): Aggregate::uninitialize keepstation:StartingMission 2025-08-15T23:37:47.356Z,1755301067.356 [keepstation:TransitToStation] Running Loop=1 2025-08-15T23:37:47.356Z,1755301067.356 [keepstation:TransitToStation](DEBUG): Aggregate::initialize keepstation:TransitToStation 2025-08-15T23:37:47.356Z,1755301067.356 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-15T23:37:47.357Z,1755301067.357 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-08-15T23:37:47.357Z,1755301067.357 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-08-15T23:37:47.357Z,1755301067.357 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-08-15T23:37:47.357Z,1755301067.357 [keepstation:TransitToStation:Wpt1.Waypoint] Running Loop=1 2025-08-15T23:37:47.357Z,1755301067.357 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2025-08-15T23:37:47.770Z,1755301067.770 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-15T23:37:47.770Z,1755301067.770 [keepstation:DiveCmd] Running Loop=1 2025-08-15T23:37:47.770Z,1755301067.770 [keepstation:DiveCmd](DEBUG): Aggregate::initialize keepstation:DiveCmd 2025-08-15T23:37:47.770Z,1755301067.770 [keepstation:DiveCmd:SurfaceSink] Running Loop=1 2025-08-15T23:37:47.770Z,1755301067.770 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink 2025-08-15T23:37:47.770Z,1755301067.770 [keepstation:DiveCmd:SurfaceSink:sink] Running Loop=1 2025-08-15T23:37:47.770Z,1755301067.770 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::initialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Running Loop=1 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Initialize. 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:SurfaceSink:sink:C] Running Loop=1 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:TransitToStation:dive] Running Loop=1 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::initialize keepstation:DiveCmd:TransitToStation:dive 2025-08-15T23:37:47.771Z,1755301067.771 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-15T23:37:47.772Z,1755301067.772 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-15T23:37:47.772Z,1755301067.772 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-15T23:37:47.772Z,1755301067.772 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Initialize. 2025-08-15T23:37:47.772Z,1755301067.772 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-15T23:37:47.772Z,1755301067.772 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Initialize. 2025-08-15T23:37:47.772Z,1755301067.772 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-15T23:37:47.772Z,1755301067.772 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-15T23:37:47.773Z,1755301067.773 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-15T23:37:47.773Z,1755301067.773 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-15T23:37:47.773Z,1755301067.773 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-15T23:37:47.773Z,1755301067.773 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-15T23:37:47.773Z,1755301067.773 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:TransitToStation] Running Loop=1 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Running Loop=1 2025-08-15T23:37:47.774Z,1755301067.774 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Running Loop=1 2025-08-15T23:37:47.775Z,1755301067.775 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Running Loop=1 2025-08-15T23:37:47.775Z,1755301067.775 [keepstation:DiveCmd:SurfaceSink] Stopped 2025-08-15T23:37:47.775Z,1755301067.775 [keepstation:DiveCmd:SurfaceSink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink 2025-08-15T23:37:47.775Z,1755301067.775 [keepstation:DiveCmd:SurfaceSink:sink] Stopped 2025-08-15T23:37:47.775Z,1755301067.775 [keepstation:DiveCmd:SurfaceSink:sink](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:SurfaceSink:sink 2025-08-15T23:37:47.775Z,1755301067.775 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy] Stopped 2025-08-15T23:37:47.776Z,1755301067.776 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-15T23:37:47.776Z,1755301067.776 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed] Stopped 2025-08-15T23:37:47.776Z,1755301067.776 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Uninitialize. 2025-08-15T23:37:47.776Z,1755301067.776 [keepstation:DiveCmd:SurfaceSink:sink:C] Stopped 2025-08-15T23:38:31.048Z,1755301111.048 [DVL_micro](ERROR): DVL uart error: serial timeout 2025-08-15T23:38:31.048Z,1755301111.048 [DVL_micro] Communications Fault, FailCount= 1 2025-08-15T23:38:31.048Z,1755301111.048 [DVL_micro](ERROR): Communications Fault 2025-08-15T23:38:31.048Z,1755301111.048 [DVL_micro](ERROR): Failed to parse: 2025-08-15T23:38:31.280Z,1755301111.280 [CBIT](ERROR): Communications Fault in component: DVL_micro 2025-08-15T23:38:31.512Z,1755301111.512 [DVL_micro](INFO): Powering down 2025-08-15T23:38:32.424Z,1755301112.424 [CBIT](INFO): Clearing failed state for component DVL_micro 2025-08-15T23:38:32.424Z,1755301112.424 [DVL_micro] No Fault, FailCount= 1 2025-08-15T23:39:15.022Z,1755301155.022 [keepstation:SurfaceComms] Running Loop=1 2025-08-15T23:39:15.022Z,1755301155.022 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-15T23:39:15.023Z,1755301155.023 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-15T23:39:15.023Z,1755301155.023 [keepstation:SurfaceComms:A] Stopped 2025-08-15T23:39:15.023Z,1755301155.023 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-15T23:39:15.023Z,1755301155.023 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-15T23:39:15.428Z,1755301155.428 [keepstation:TransitToStation:Dive] Stopped 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:TransitToStation:Dive:A] Stopped 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:DiveCmd:TransitToStation] Stopped 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:DiveCmd:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:DiveCmd:TransitToStation:dive] Stopped 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:DiveCmd:TransitToStation:dive](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:TransitToStation:dive 2025-08-15T23:39:15.429Z,1755301155.429 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy] Stopped 2025-08-15T23:39:15.430Z,1755301155.430 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-15T23:39:15.430Z,1755301155.430 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch] Stopped 2025-08-15T23:39:15.430Z,1755301155.430 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed] Stopped 2025-08-15T23:39:15.430Z,1755301155.430 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Uninitialize. 2025-08-15T23:39:15.433Z,1755301155.433 [keepstation:NeedComms] Running Loop=1 2025-08-15T23:39:15.433Z,1755301155.433 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-15T23:39:15.433Z,1755301155.433 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-15T23:39:15.433Z,1755301155.433 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:39:15.433Z,1755301155.433 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-15T23:39:15.434Z,1755301155.434 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-15T23:39:15.434Z,1755301155.434 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-15T23:39:15.434Z,1755301155.434 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-15T23:39:15.435Z,1755301155.435 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:39:15.435Z,1755301155.435 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:39:15.435Z,1755301155.435 [keepstation:NeedComms:A] Running Loop=1 2025-08-15T23:39:15.436Z,1755301155.436 [keepstation:NeedComms:A](INFO): last time_fix was: 1755300911.000000 second since 1970/01/01T00:00:00Z 2025-08-15T23:39:15.436Z,1755301155.436 [keepstation:NeedComms:A] Stopped 2025-08-15T23:39:15.837Z,1755301155.837 [keepstation:NeedComms:C] Running Loop=1 2025-08-15T23:40:16.829Z,1755301216.829 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-15T23:40:26.527Z,1755301226.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234023.00,A,3648.16413,N,12147.27692,W,0.156,7.83,150825,,,A*7C 2025-08-15T23:40:26.539Z,1755301226.539 [NAL9602](INFO): GPS fix at 20250815T234023: (36.802735, -121.787949) 2025-08-15T23:40:26.549Z,1755301226.549 [keepstation:TransitToStation:Wpt1.Waypoint] Stopped 2025-08-15T23:40:26.549Z,1755301226.549 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2025-08-15T23:40:26.549Z,1755301226.549 [keepstation:TransitToStation:C] Running Loop=1 2025-08-15T23:40:26.557Z,1755301226.557 [keepstation:NeedComms:C] Stopped 2025-08-15T23:40:26.558Z,1755301226.558 [keepstation:NeedComms:D] Running Loop=1 2025-08-15T23:40:26.967Z,1755301226.967 [keepstation:TransitToStation:C] Stopped 2025-08-15T23:40:26.967Z,1755301226.967 [keepstation:TransitToStation:D] Running Loop=1 2025-08-15T23:40:26.967Z,1755301226.967 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-15T23:40:26.968Z,1755301226.968 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-15T23:40:26.968Z,1755301226.968 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-15T23:40:26.968Z,1755301226.968 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-15T23:40:26.968Z,1755301226.968 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-15T23:40:26.968Z,1755301226.968 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-15T23:40:26.968Z,1755301226.968 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-15T23:40:26.969Z,1755301226.969 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-15T23:40:26.969Z,1755301226.969 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-15T23:40:26.969Z,1755301226.969 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-15T23:40:26.970Z,1755301226.970 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-15T23:40:27.399Z,1755301227.399 [keepstation:TransitToStation:D] Stopped 2025-08-15T23:40:27.399Z,1755301227.399 [keepstation:TransitToStation:Dive] Running Loop=1 2025-08-15T23:40:27.399Z,1755301227.399 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive 2025-08-15T23:40:27.399Z,1755301227.399 [keepstation:TransitToStation:Dive:A] Running Loop=1 2025-08-15T23:40:27.399Z,1755301227.399 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::initialize keepstation:TransitToStation:Dive:A 2025-08-15T23:40:27.404Z,1755301227.404 [keepstation:TransitToStation](INFO): Completed keepstation:TransitToStation 2025-08-15T23:40:27.404Z,1755301227.404 [keepstation:TransitToStation] Stopped 2025-08-15T23:40:27.404Z,1755301227.404 [keepstation:TransitToStation](DEBUG): Aggregate::uninitialize keepstation:TransitToStation 2025-08-15T23:40:27.404Z,1755301227.404 [keepstation:TransitToStation:Dive] Stopped 2025-08-15T23:40:27.404Z,1755301227.404 [keepstation:TransitToStation:Dive](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive 2025-08-15T23:40:27.404Z,1755301227.404 [keepstation:TransitToStation:Dive:A] Stopped 2025-08-15T23:40:27.404Z,1755301227.404 [keepstation:TransitToStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:TransitToStation:Dive:A 2025-08-15T23:40:27.405Z,1755301227.405 [keepstation:OnStation] Running Loop=1 2025-08-15T23:40:27.405Z,1755301227.405 [keepstation:OnStation](DEBUG): Aggregate::initialize keepstation:OnStation 2025-08-15T23:40:35.115Z,1755301235.115 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250815T232729/Courier0019.lzma 2025-08-15T23:40:36.118Z,1755301236.118 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0019.lzma.bak 2025-08-15T23:40:36.118Z,1755301236.118 [DataOverHttps](INFO): SBD MOMSN=25854249 2025-08-15T23:40:51.611Z,1755301251.611 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250815T232729/Courier0022.lzma 2025-08-15T23:40:52.624Z,1755301252.624 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0022.lzma.bak 2025-08-15T23:40:52.624Z,1755301252.624 [DataOverHttps](INFO): SBD MOMSN=25854251 2025-08-15T23:40:56.865Z,1755301256.865 [keepstation:NeedComms:D](INFO): Timed out from 2025-08-15T23:40:26.6Z 2025-08-15T23:40:56.865Z,1755301256.865 [keepstation:NeedComms:D:A_Timeout] Running Loop=1 2025-08-15T23:40:56.865Z,1755301256.865 [keepstation:NeedComms:D:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:D:A_Timeout 2025-08-15T23:40:56.866Z,1755301256.866 [keepstation:NeedComms:D:A_Timeout:A] Running Loop=1 2025-08-15T23:40:56.866Z,1755301256.866 [keepstation:NeedComms:D:A_Timeout:A](IMPORTANT): Comms timed out after 0.500000 min minutes 2025-08-15T23:40:56.866Z,1755301256.866 [keepstation:NeedComms:D:A_Timeout:A] Stopped 2025-08-15T23:40:56.866Z,1755301256.866 [keepstation:NeedComms:D:A_Timeout](INFO): Completed keepstation:NeedComms:D:A_Timeout 2025-08-15T23:40:56.866Z,1755301256.866 [keepstation:NeedComms:D] Stopped 2025-08-15T23:40:56.867Z,1755301256.867 [keepstation:NeedComms:E] Running Loop=1 2025-08-15T23:40:58.867Z,1755301258.867 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234055.00,A,3648.16407,N,12147.28235,W,1.788,290.41,150825,,,A*78 2025-08-15T23:40:58.870Z,1755301258.870 [NAL9602](INFO): GPS fix at 20250815T234055: (36.802734, -121.788039) 2025-08-15T23:40:58.954Z,1755301258.954 [keepstation:NeedComms:E] Stopped 2025-08-15T23:40:58.955Z,1755301258.955 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-15T23:40:58.955Z,1755301258.955 [keepstation:NeedComms] Stopped 2025-08-15T23:40:58.955Z,1755301258.955 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-15T23:40:58.955Z,1755301258.955 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-15T23:40:58.955Z,1755301258.955 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-15T23:40:59.331Z,1755301259.331 [keepstation:OnStation](INFO): Completed keepstation:OnStation 2025-08-15T23:40:59.331Z,1755301259.331 [keepstation:OnStation] Stopped 2025-08-15T23:40:59.331Z,1755301259.331 [keepstation:OnStation](DEBUG): Aggregate::uninitialize keepstation:OnStation 2025-08-15T23:40:59.331Z,1755301259.331 [keepstation:KeepStation] Running Loop=1 2025-08-15T23:40:59.331Z,1755301259.331 [keepstation:KeepStation](DEBUG): Aggregate::initialize keepstation:KeepStation 2025-08-15T23:40:59.331Z,1755301259.331 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-15T23:40:59.331Z,1755301259.331 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-15T23:40:59.336Z,1755301259.336 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-15T23:40:59.336Z,1755301259.336 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-15T23:40:59.336Z,1755301259.336 [keepstation:KeepStation:B.Wait] Running Loop=1 2025-08-15T23:40:59.336Z,1755301259.336 [keepstation:KeepStation:B.Wait](DEBUG): Initialize Wait Component. 2025-08-15T23:40:59.338Z,1755301259.338 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-15T23:40:59.338Z,1755301259.338 [keepstation:SurfaceComms:B] Stopped 2025-08-15T23:40:59.338Z,1755301259.338 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-15T23:40:59.338Z,1755301259.338 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-15T23:40:59.338Z,1755301259.338 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-15T23:40:59.338Z,1755301259.338 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-15T23:40:59.715Z,1755301259.715 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-15T23:40:59.721Z,1755301259.721 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-15T23:40:59.721Z,1755301259.721 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-15T23:40:59.721Z,1755301259.721 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-15T23:40:59.721Z,1755301259.721 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-15T23:40:59.721Z,1755301259.721 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-15T23:40:59.721Z,1755301259.721 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-15T23:41:00.176Z,1755301260.176 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-15T23:41:00.177Z,1755301260.177 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation 2025-08-15T23:41:00.177Z,1755301260.177 [keepstation:SurfaceComms:setStation] Stopped 2025-08-15T23:41:00.177Z,1755301260.177 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-15T23:41:00.177Z,1755301260.177 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-15T23:41:00.177Z,1755301260.177 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-15T23:41:00.177Z,1755301260.177 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-15T23:41:00.525Z,1755301260.525 [keepstation:SurfaceComms:setSink] Stopped 2025-08-15T23:41:00.525Z,1755301260.525 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-15T23:41:00.525Z,1755301260.525 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-15T23:41:00.525Z,1755301260.525 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-15T23:41:00.525Z,1755301260.525 [keepstation:SurfaceComms] Stopped 2025-08-15T23:41:00.525Z,1755301260.525 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-15T23:41:12.847Z,1755301272.847 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20250815T232729/Express0011.lzma 2025-08-15T23:41:13.850Z,1755301273.850 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0011.lzma.bak 2025-08-15T23:41:13.850Z,1755301273.850 [DataOverHttps](INFO): SBD MOMSN=25854254 2025-08-15T23:41:31.202Z,1755301291.202 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-15T23:44:59.270Z,1755301499.270 [keepstation:SurfaceComms] Running Loop=1 2025-08-15T23:44:59.270Z,1755301499.270 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-15T23:44:59.271Z,1755301499.271 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-15T23:44:59.272Z,1755301499.272 [keepstation:SurfaceComms:A] Stopped 2025-08-15T23:44:59.272Z,1755301499.272 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-15T23:44:59.272Z,1755301499.272 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-15T23:44:59.671Z,1755301499.671 [keepstation:KeepStation:Dive] Stopped 2025-08-15T23:44:59.671Z,1755301499.671 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-08-15T23:44:59.671Z,1755301499.671 [keepstation:KeepStation:Dive:A] Stopped 2025-08-15T23:44:59.671Z,1755301499.671 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-08-15T23:44:59.692Z,1755301499.692 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-15T23:44:59.692Z,1755301499.692 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-15T23:44:59.692Z,1755301499.692 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-15T23:44:59.692Z,1755301499.692 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-15T23:44:59.692Z,1755301499.692 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-15T23:44:59.692Z,1755301499.692 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-15T23:44:59.697Z,1755301499.697 [keepstation:NeedComms] Running Loop=1 2025-08-15T23:44:59.697Z,1755301499.697 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-15T23:44:59.697Z,1755301499.697 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-15T23:44:59.697Z,1755301499.697 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:44:59.697Z,1755301499.697 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-15T23:44:59.698Z,1755301499.698 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-15T23:44:59.698Z,1755301499.698 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-15T23:44:59.698Z,1755301499.698 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-15T23:44:59.699Z,1755301499.699 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:44:59.699Z,1755301499.699 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:44:59.699Z,1755301499.699 [keepstation:NeedComms:A] Running Loop=1 2025-08-15T23:44:59.701Z,1755301499.701 [keepstation:NeedComms:A](INFO): last time_fix was: 1755301255.000000 second since 1970/01/01T00:00:00Z 2025-08-15T23:44:59.701Z,1755301499.701 [keepstation:NeedComms:A] Stopped 2025-08-15T23:45:00.081Z,1755301500.081 [keepstation:NeedComms:C] Running Loop=1 2025-08-15T23:45:02.087Z,1755301502.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234501.00,A,3648.16629,N,12147.28142,W,0.078,274.64,150825,,,D*70 2025-08-15T23:45:02.094Z,1755301502.094 [NAL9602](INFO): GPS fix at 20250815T234501: (36.802771, -121.788024) 2025-08-15T23:45:02.145Z,1755301502.145 [keepstation:NeedComms:C] Stopped 2025-08-15T23:45:02.145Z,1755301502.145 [keepstation:NeedComms:D] Running Loop=1 2025-08-15T23:45:07.034Z,1755301507.034 [CommandExec](IMPORTANT): got command set keepstation:BackseatDriver.EnableBackseat 0 bool 2025-08-15T23:45:07.073Z,1755301507.073 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Uninitializing backseat 2025-08-15T23:45:08.027Z,1755301508.027 [BackseatComponent](INFO): Sent LCM shutdown request. 2025-08-15T23:45:08.030Z,1755301508.030 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.). 2025-08-15T23:45:09.051Z,1755301509.051 [DVL_micro](ERROR): only read 1 of 4 data items for beam range. Device response is::RD,+99 2025-08-15T23:45:09.051Z,1755301509.051 [DVL_micro](ERROR): Failed to parse: :RD,+99 2025-08-15T23:45:11.627Z,1755301511.627 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250815T232729/Courier0025.lzma 2025-08-15T23:45:12.630Z,1755301512.630 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0025.lzma.bak 2025-08-15T23:45:12.630Z,1755301512.630 [DataOverHttps](INFO): SBD MOMSN=25854256 2025-08-15T23:45:26.200Z,1755301526.200 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec). 2025-08-15T23:45:26.201Z,1755301526.201 [BackseatComponent](INFO): Unsubscribing from LCM channels. 2025-08-15T23:45:26.201Z,1755301526.201 [LcmUniversalReporter](INFO): Deactivating messaging. 2025-08-15T23:45:30.336Z,1755301530.336 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20250815T232729/Express0014.lzma 2025-08-15T23:45:31.338Z,1755301531.338 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0014.lzma.bak 2025-08-15T23:45:31.338Z,1755301531.338 [DataOverHttps](INFO): SBD MOMSN=25854259 2025-08-15T23:45:32.175Z,1755301532.175 [keepstation:NeedComms:D](INFO): Timed out from 2025-08-15T23:45:02.1Z 2025-08-15T23:45:32.175Z,1755301532.175 [keepstation:NeedComms:D:A_Timeout] Running Loop=1 2025-08-15T23:45:32.175Z,1755301532.175 [keepstation:NeedComms:D:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:D:A_Timeout 2025-08-15T23:45:33.449Z,1755301533.449 [keepstation:NeedComms:D:A_Timeout:A] Running Loop=1 2025-08-15T23:45:33.449Z,1755301533.449 [keepstation:NeedComms:D:A_Timeout:A](IMPORTANT): Comms timed out after 0.500000 min minutes 2025-08-15T23:45:33.449Z,1755301533.449 [keepstation:NeedComms:D:A_Timeout:A] Stopped 2025-08-15T23:45:33.449Z,1755301533.449 [keepstation:NeedComms:D:A_Timeout](INFO): Completed keepstation:NeedComms:D:A_Timeout 2025-08-15T23:45:33.449Z,1755301533.449 [keepstation:NeedComms:D] Stopped 2025-08-15T23:45:33.450Z,1755301533.450 [keepstation:NeedComms:E] Running Loop=1 2025-08-15T23:45:33.633Z,1755301533.633 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-15T23:45:33.716Z,1755301533.716 [NAL9602](ERROR): received: +CSQ:0 OK844, 2, 0, 0, 0 OK 2025-08-15T23:45:52.094Z,1755301552.094 [NAL9602](INFO): SBD MO Status=2, MOMSN=21844, MT Status=2, MTMSN=0 2025-08-15T23:45:52.094Z,1755301552.094 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-15T23:46:13.084Z,1755301573.084 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20250815T232729/Express0017.lzma 2025-08-15T23:46:14.086Z,1755301574.086 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0017.lzma.bak 2025-08-15T23:46:14.086Z,1755301574.086 [DataOverHttps](INFO): SBD MOMSN=25854264 2025-08-15T23:46:20.386Z,1755301580.386 [NAL9602](INFO): SBD MO Status=2, MOMSN=21844, MT Status=2, MTMSN=0 2025-08-15T23:46:20.387Z,1755301580.387 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-15T23:47:33.522Z,1755301653.522 [keepstation:NeedComms:E](INFO): Timed out from 2025-08-15T23:45:33.4Z 2025-08-15T23:47:33.523Z,1755301653.523 [keepstation:NeedComms:E:A_Timeout] Running Loop=1 2025-08-15T23:47:33.523Z,1755301653.523 [keepstation:NeedComms:E:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:E:A_Timeout 2025-08-15T23:47:33.523Z,1755301653.523 [keepstation:NeedComms:E:A_Timeout:A] Running Loop=1 2025-08-15T23:47:33.523Z,1755301653.523 [keepstation:NeedComms:E:A_Timeout:A](IMPORTANT): second GPS update timeout 2025-08-15T23:47:33.523Z,1755301653.523 [keepstation:NeedComms:E:A_Timeout:A] Stopped 2025-08-15T23:47:33.523Z,1755301653.523 [keepstation:NeedComms:E:A_Timeout](INFO): Completed keepstation:NeedComms:E:A_Timeout 2025-08-15T23:47:33.523Z,1755301653.523 [keepstation:NeedComms:E] Stopped 2025-08-15T23:47:33.524Z,1755301653.524 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-15T23:47:33.525Z,1755301653.525 [keepstation:NeedComms] Stopped 2025-08-15T23:47:33.525Z,1755301653.525 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-15T23:47:33.525Z,1755301653.525 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-15T23:47:33.525Z,1755301653.525 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-15T23:47:33.925Z,1755301653.925 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-15T23:47:33.925Z,1755301653.925 [keepstation:SurfaceComms:B] Stopped 2025-08-15T23:47:33.925Z,1755301653.925 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-15T23:47:33.926Z,1755301653.926 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-15T23:47:33.926Z,1755301653.926 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-15T23:47:33.926Z,1755301653.926 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-15T23:47:34.341Z,1755301654.341 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-15T23:47:34.341Z,1755301654.341 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-15T23:47:34.341Z,1755301654.341 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-15T23:47:34.341Z,1755301654.341 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-15T23:47:34.341Z,1755301654.341 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-15T23:47:34.341Z,1755301654.341 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-15T23:47:34.743Z,1755301654.743 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-15T23:47:34.743Z,1755301654.743 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation 2025-08-15T23:47:34.743Z,1755301654.743 [keepstation:SurfaceComms:setStation] Stopped 2025-08-15T23:47:34.743Z,1755301654.743 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-15T23:47:34.743Z,1755301654.743 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-15T23:47:34.743Z,1755301654.743 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-15T23:47:34.748Z,1755301654.748 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-15T23:47:35.134Z,1755301655.134 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-15T23:47:35.134Z,1755301655.134 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-15T23:47:35.134Z,1755301655.134 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-15T23:47:35.134Z,1755301655.134 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-15T23:47:35.135Z,1755301655.135 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-15T23:47:35.135Z,1755301655.135 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-15T23:47:35.135Z,1755301655.135 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-15T23:47:35.135Z,1755301655.135 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-15T23:47:35.135Z,1755301655.135 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-15T23:47:35.135Z,1755301655.135 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-15T23:47:35.135Z,1755301655.135 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-15T23:47:35.137Z,1755301655.137 [keepstation:SurfaceComms:setSink] Stopped 2025-08-15T23:47:35.137Z,1755301655.137 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-15T23:47:35.137Z,1755301655.137 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-15T23:47:35.138Z,1755301655.138 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-15T23:47:35.138Z,1755301655.138 [keepstation:SurfaceComms] Stopped 2025-08-15T23:47:35.138Z,1755301655.138 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-15T23:49:02.412Z,1755301742.412 [keepstation:SurfaceComms] Running Loop=1 2025-08-15T23:49:02.413Z,1755301742.413 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-15T23:49:02.413Z,1755301742.413 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-15T23:49:02.413Z,1755301742.413 [keepstation:SurfaceComms:A] Stopped 2025-08-15T23:49:02.413Z,1755301742.413 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-15T23:49:02.413Z,1755301742.413 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-15T23:49:02.822Z,1755301742.822 [keepstation:KeepStation:Dive] Stopped 2025-08-15T23:49:02.822Z,1755301742.822 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:KeepStation:Dive:A] Stopped 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-15T23:49:02.823Z,1755301742.823 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-15T23:49:02.825Z,1755301742.825 [keepstation:NeedComms] Running Loop=1 2025-08-15T23:49:02.825Z,1755301742.825 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-15T23:49:02.825Z,1755301742.825 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-15T23:49:02.826Z,1755301742.826 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:49:02.826Z,1755301742.826 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-15T23:49:02.826Z,1755301742.826 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-15T23:49:02.827Z,1755301742.827 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-15T23:49:02.827Z,1755301742.827 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-15T23:49:02.827Z,1755301742.827 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:49:02.828Z,1755301742.828 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:49:02.828Z,1755301742.828 [keepstation:NeedComms:A] Running Loop=1 2025-08-15T23:49:02.829Z,1755301742.829 [keepstation:NeedComms:A](INFO): last time_fix was: 1755301501.000000 second since 1970/01/01T00:00:00Z 2025-08-15T23:49:02.829Z,1755301742.829 [keepstation:NeedComms:A] Stopped 2025-08-15T23:49:03.231Z,1755301743.231 [keepstation:NeedComms:C] Running Loop=1 2025-08-15T23:50:04.198Z,1755301804.198 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-15T23:50:05.568Z,1755301805.568 [CommandExec](IMPORTANT): got command set keepstation:BackseatDriver.EnableBackseat 1 bool 2025-08-15T23:50:05.824Z,1755301805.824 [keepstation:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat 2025-08-15T23:50:06.132Z,1755301806.132 [BackseatComponent](INFO): Powering up 2025-08-15T23:50:06.132Z,1755301806.132 [BackseatComponent](INFO): Subscribing to LCM channels. 2025-08-15T23:50:10.672Z,1755301810.672 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235010.00,A,3648.16449,N,12147.28028,W,0.175,274.64,150825,,,A*74 2025-08-15T23:50:10.674Z,1755301810.674 [NAL9602](INFO): GPS fix at 20250815T235010: (36.802742, -121.788005) 2025-08-15T23:50:10.689Z,1755301810.689 [keepstation:NeedComms:C] Stopped 2025-08-15T23:50:10.689Z,1755301810.689 [keepstation:NeedComms:D] Running Loop=1 2025-08-15T23:50:17.687Z,1755301817.687 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250815T232729/Courier0031.lzma 2025-08-15T23:50:18.690Z,1755301818.690 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0031.lzma.bak 2025-08-15T23:50:18.690Z,1755301818.690 [DataOverHttps](INFO): SBD MOMSN=25854270 2025-08-15T23:50:37.452Z,1755301837.452 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20250815T232729/Express0020.lzma 2025-08-15T23:50:38.454Z,1755301838.454 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0020.lzma.bak 2025-08-15T23:50:38.454Z,1755301838.454 [DataOverHttps](INFO): SBD MOMSN=25854273 2025-08-15T23:50:40.989Z,1755301840.989 [keepstation:NeedComms:D](INFO): Timed out from 2025-08-15T23:50:10.7Z 2025-08-15T23:50:40.989Z,1755301840.989 [keepstation:NeedComms:D:A_Timeout] Running Loop=1 2025-08-15T23:50:40.989Z,1755301840.989 [keepstation:NeedComms:D:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:D:A_Timeout 2025-08-15T23:50:40.990Z,1755301840.990 [keepstation:NeedComms:D:A_Timeout:A] Running Loop=1 2025-08-15T23:50:40.990Z,1755301840.990 [keepstation:NeedComms:D:A_Timeout:A](IMPORTANT): Comms timed out after 0.500000 min minutes 2025-08-15T23:50:40.990Z,1755301840.990 [keepstation:NeedComms:D:A_Timeout:A] Stopped 2025-08-15T23:50:40.990Z,1755301840.990 [keepstation:NeedComms:D:A_Timeout](INFO): Completed keepstation:NeedComms:D:A_Timeout 2025-08-15T23:50:40.990Z,1755301840.990 [keepstation:NeedComms:D] Stopped 2025-08-15T23:50:40.991Z,1755301840.991 [keepstation:NeedComms:E] Running Loop=1 2025-08-15T23:50:42.980Z,1755301842.980 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235042.00,A,3648.16520,N,12147.28384,W,0.233,274.64,150825,,,A*79 2025-08-15T23:50:42.982Z,1755301842.982 [NAL9602](INFO): GPS fix at 20250815T235042: (36.802753, -121.788064) 2025-08-15T23:50:43.005Z,1755301843.005 [keepstation:NeedComms:E] Stopped 2025-08-15T23:50:43.006Z,1755301843.006 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-15T23:50:43.006Z,1755301843.006 [keepstation:NeedComms] Stopped 2025-08-15T23:50:43.006Z,1755301843.006 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-15T23:50:43.006Z,1755301843.006 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-15T23:50:43.006Z,1755301843.006 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-15T23:50:43.442Z,1755301843.442 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-15T23:50:43.442Z,1755301843.442 [keepstation:SurfaceComms:B] Stopped 2025-08-15T23:50:43.442Z,1755301843.442 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-15T23:50:43.442Z,1755301843.442 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-15T23:50:43.443Z,1755301843.443 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-15T23:50:43.443Z,1755301843.443 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-15T23:50:43.817Z,1755301843.817 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-15T23:50:43.817Z,1755301843.817 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-15T23:50:43.817Z,1755301843.817 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-15T23:50:43.817Z,1755301843.817 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-15T23:50:43.817Z,1755301843.817 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-15T23:50:43.817Z,1755301843.817 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-15T23:50:44.227Z,1755301844.227 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-15T23:50:44.227Z,1755301844.227 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation 2025-08-15T23:50:44.227Z,1755301844.227 [keepstation:SurfaceComms:setStation] Stopped 2025-08-15T23:50:44.232Z,1755301844.232 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-15T23:50:44.232Z,1755301844.232 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-15T23:50:44.232Z,1755301844.232 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-15T23:50:44.232Z,1755301844.232 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-15T23:50:44.620Z,1755301844.620 [BackseatComponent](IMPORTANT): piscivore: running backseat_app backseat application. 2025-08-15T23:50:44.699Z,1755301844.699 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-15T23:50:44.699Z,1755301844.699 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-15T23:50:44.699Z,1755301844.699 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-15T23:50:44.699Z,1755301844.699 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-15T23:50:44.704Z,1755301844.704 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-15T23:50:44.704Z,1755301844.704 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-15T23:50:44.704Z,1755301844.704 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-15T23:50:44.704Z,1755301844.704 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-15T23:50:44.704Z,1755301844.704 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-15T23:50:44.704Z,1755301844.704 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-15T23:50:44.704Z,1755301844.704 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-15T23:50:44.706Z,1755301844.706 [keepstation:SurfaceComms:setSink] Stopped 2025-08-15T23:50:44.706Z,1755301844.706 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-15T23:50:44.706Z,1755301844.706 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-15T23:50:44.706Z,1755301844.706 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-15T23:50:44.706Z,1755301844.706 [keepstation:SurfaceComms] Stopped 2025-08-15T23:50:44.706Z,1755301844.706 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-15T23:50:59.473Z,1755301859.473 [DataOverHttps](INFO): Sending 622 bytes from file Logs/20250815T232729/Express0023.lzma 2025-08-15T23:51:00.475Z,1755301860.475 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0023.lzma.bak 2025-08-15T23:51:00.475Z,1755301860.475 [DataOverHttps](INFO): SBD MOMSN=25854279 2025-08-15T23:51:15.301Z,1755301875.301 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-15T23:54:43.033Z,1755302083.033 [keepstation:SurfaceComms] Running Loop=1 2025-08-15T23:54:43.033Z,1755302083.033 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms 2025-08-15T23:54:43.033Z,1755302083.033 [keepstation:SurfaceComms:A] Running Loop=1 2025-08-15T23:54:43.033Z,1755302083.033 [keepstation:SurfaceComms:A] Stopped 2025-08-15T23:54:43.033Z,1755302083.033 [keepstation:SurfaceComms:B] Running Loop=1 2025-08-15T23:54:43.034Z,1755302083.034 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B 2025-08-15T23:54:43.417Z,1755302083.417 [keepstation:KeepStation:Dive] Stopped 2025-08-15T23:54:43.417Z,1755302083.417 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-08-15T23:54:43.417Z,1755302083.417 [keepstation:KeepStation:Dive:A] Stopped 2025-08-15T23:54:43.417Z,1755302083.417 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-08-15T23:54:43.418Z,1755302083.418 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-15T23:54:43.418Z,1755302083.418 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-15T23:54:43.418Z,1755302083.418 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-15T23:54:43.418Z,1755302083.418 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-15T23:54:43.418Z,1755302083.418 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-15T23:54:43.418Z,1755302083.418 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-15T23:54:43.421Z,1755302083.421 [keepstation:NeedComms] Running Loop=1 2025-08-15T23:54:43.421Z,1755302083.421 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms 2025-08-15T23:54:43.421Z,1755302083.421 [keepstation:NeedComms:B.GoToSurface] Running Loop=1 2025-08-15T23:54:43.421Z,1755302083.421 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:54:43.421Z,1755302083.421 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-15T23:54:43.422Z,1755302083.422 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-15T23:54:43.422Z,1755302083.422 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-15T23:54:43.422Z,1755302083.422 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-15T23:54:43.423Z,1755302083.423 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:54:43.423Z,1755302083.423 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:54:43.423Z,1755302083.423 [keepstation:NeedComms:A] Running Loop=1 2025-08-15T23:54:43.425Z,1755302083.425 [keepstation:NeedComms:A](INFO): last time_fix was: 1755301842.000000 second since 1970/01/01T00:00:00Z 2025-08-15T23:54:43.425Z,1755302083.425 [keepstation:NeedComms:A] Stopped 2025-08-15T23:54:43.853Z,1755302083.853 [keepstation:NeedComms:C] Running Loop=1 2025-08-15T23:54:45.834Z,1755302085.834 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235445.00,A,3648.16454,N,12147.28838,W,0.311,274.64,150825,,,A*75 2025-08-15T23:54:45.847Z,1755302085.847 [NAL9602](INFO): GPS fix at 20250815T235445: (36.802742, -121.788140) 2025-08-15T23:54:45.861Z,1755302085.861 [keepstation:NeedComms:C] Stopped 2025-08-15T23:54:45.861Z,1755302085.861 [keepstation:NeedComms:D] Running Loop=1 2025-08-15T23:54:53.487Z,1755302093.487 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250815T232729/Courier0034.lzma 2025-08-15T23:54:54.490Z,1755302094.490 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0034.lzma.bak 2025-08-15T23:54:54.490Z,1755302094.490 [DataOverHttps](INFO): SBD MOMSN=25854296 2025-08-15T23:55:12.132Z,1755302112.132 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20250815T232729/Express0027.lzma 2025-08-15T23:55:13.134Z,1755302113.134 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0027.lzma.bak 2025-08-15T23:55:13.134Z,1755302113.134 [DataOverHttps](INFO): SBD MOMSN=25854299 2025-08-15T23:55:16.145Z,1755302116.145 [keepstation:NeedComms:D](INFO): Timed out from 2025-08-15T23:54:45.9Z 2025-08-15T23:55:16.145Z,1755302116.145 [keepstation:NeedComms:D:A_Timeout] Running Loop=1 2025-08-15T23:55:16.145Z,1755302116.145 [keepstation:NeedComms:D:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:D:A_Timeout 2025-08-15T23:55:16.145Z,1755302116.145 [keepstation:NeedComms:D:A_Timeout:A] Running Loop=1 2025-08-15T23:55:16.147Z,1755302116.147 [keepstation:NeedComms:D:A_Timeout:A](IMPORTANT): Comms timed out after 0.500000 min minutes 2025-08-15T23:55:16.147Z,1755302116.147 [keepstation:NeedComms:D:A_Timeout:A] Stopped 2025-08-15T23:55:16.148Z,1755302116.148 [keepstation:NeedComms:D:A_Timeout](INFO): Completed keepstation:NeedComms:D:A_Timeout 2025-08-15T23:55:16.149Z,1755302116.149 [keepstation:NeedComms:D] Stopped 2025-08-15T23:55:16.149Z,1755302116.149 [keepstation:NeedComms:E] Running Loop=1 2025-08-15T23:55:16.539Z,1755302116.539 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-15T23:55:16.620Z,1755302116.620 [NAL9602](ERROR): received: +CSQ:0 OK844, 2, 0, 0, 0 OK 2025-08-15T23:55:33.100Z,1755302133.100 [DataOverHttps](INFO): Sending 314 bytes from file Logs/20250815T232729/Express0032.lzma 2025-08-15T23:55:34.102Z,1755302134.102 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0032.lzma.bak 2025-08-15T23:55:34.102Z,1755302134.102 [DataOverHttps](INFO): SBD MOMSN=25854304 2025-08-15T23:57:16.185Z,1755302236.185 [keepstation:NeedComms:E](INFO): Timed out from 2025-08-15T23:55:16.1Z 2025-08-15T23:57:16.185Z,1755302236.185 [keepstation:NeedComms:E:A_Timeout] Running Loop=1 2025-08-15T23:57:16.185Z,1755302236.185 [keepstation:NeedComms:E:A_Timeout](DEBUG): Aggregate::initialize keepstation:NeedComms:E:A_Timeout 2025-08-15T23:57:16.186Z,1755302236.186 [keepstation:NeedComms:E:A_Timeout:A] Running Loop=1 2025-08-15T23:57:16.186Z,1755302236.186 [keepstation:NeedComms:E:A_Timeout:A](IMPORTANT): second GPS update timeout 2025-08-15T23:57:16.186Z,1755302236.186 [keepstation:NeedComms:E:A_Timeout:A] Stopped 2025-08-15T23:57:16.186Z,1755302236.186 [keepstation:NeedComms:E:A_Timeout](INFO): Completed keepstation:NeedComms:E:A_Timeout 2025-08-15T23:57:16.186Z,1755302236.186 [keepstation:NeedComms:E] Stopped 2025-08-15T23:57:16.187Z,1755302236.187 [keepstation:NeedComms](INFO): Completed keepstation:NeedComms 2025-08-15T23:57:16.187Z,1755302236.187 [keepstation:NeedComms] Stopped 2025-08-15T23:57:16.187Z,1755302236.187 [keepstation:NeedComms](DEBUG): Aggregate::uninitialize keepstation:NeedComms 2025-08-15T23:57:16.187Z,1755302236.187 [keepstation:NeedComms:B.GoToSurface] Stopped 2025-08-15T23:57:16.187Z,1755302236.187 [keepstation:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-15T23:57:16.573Z,1755302236.573 [keepstation:SurfaceComms:B](INFO): Completed keepstation:SurfaceComms:B 2025-08-15T23:57:16.573Z,1755302236.573 [keepstation:SurfaceComms:B] Stopped 2025-08-15T23:57:16.574Z,1755302236.574 [keepstation:SurfaceComms:B](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:B 2025-08-15T23:57:16.574Z,1755302236.574 [keepstation:SurfaceComms:setTransit] Running Loop=1 2025-08-15T23:57:16.574Z,1755302236.574 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setTransit 2025-08-15T23:57:16.574Z,1755302236.574 [keepstation:SurfaceComms:setTransit:A] Running Loop=1 2025-08-15T23:57:16.943Z,1755302236.943 [keepstation:SurfaceComms:setTransit] Stopped 2025-08-15T23:57:16.943Z,1755302236.943 [keepstation:SurfaceComms:setTransit](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setTransit 2025-08-15T23:57:16.962Z,1755302236.962 [keepstation:SurfaceComms:setTransit:A] Stopped 2025-08-15T23:57:16.962Z,1755302236.962 [keepstation:SurfaceComms:setStation] Running Loop=1 2025-08-15T23:57:16.963Z,1755302236.963 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setStation 2025-08-15T23:57:16.963Z,1755302236.963 [keepstation:SurfaceComms:setStation:A] Running Loop=1 2025-08-15T23:57:17.352Z,1755302237.352 [keepstation:SurfaceComms:setStation:A] Stopped 2025-08-15T23:57:17.352Z,1755302237.352 [keepstation:SurfaceComms:setStation](INFO): Completed keepstation:SurfaceComms:setStation 2025-08-15T23:57:17.352Z,1755302237.352 [keepstation:SurfaceComms:setStation] Stopped 2025-08-15T23:57:17.352Z,1755302237.352 [keepstation:SurfaceComms:setStation](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setStation 2025-08-15T23:57:17.352Z,1755302237.352 [keepstation:SurfaceComms:setSink] Running Loop=1 2025-08-15T23:57:17.353Z,1755302237.353 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::initialize keepstation:SurfaceComms:setSink 2025-08-15T23:57:17.353Z,1755302237.353 [keepstation:SurfaceComms:setSink:A] Running Loop=1 2025-08-15T23:57:17.755Z,1755302237.755 [keepstation:KeepStation:Dive] Running Loop=1 2025-08-15T23:57:17.756Z,1755302237.756 [keepstation:KeepStation:Dive](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive 2025-08-15T23:57:17.756Z,1755302237.756 [keepstation:KeepStation:Dive:A] Running Loop=1 2025-08-15T23:57:17.756Z,1755302237.756 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::initialize keepstation:KeepStation:Dive:A 2025-08-15T23:57:17.757Z,1755302237.757 [keepstation:DiveCmd:StationKeep] Running Loop=1 2025-08-15T23:57:17.757Z,1755302237.757 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::initialize keepstation:DiveCmd:StationKeep 2025-08-15T23:57:17.757Z,1755302237.757 [keepstation:DiveCmd:StationKeep:A] Running Loop=1 2025-08-15T23:57:17.757Z,1755302237.757 [keepstation:DiveCmd:StationKeep:B.Pitch] Running Loop=1 2025-08-15T23:57:17.757Z,1755302237.757 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Initialize. 2025-08-15T23:57:17.757Z,1755302237.757 [keepstation:DiveCmd:StationKeep:C.KeepStation] Running Loop=1 2025-08-15T23:57:17.757Z,1755302237.757 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Initialize KeepStationComponent. 2025-08-15T23:57:17.759Z,1755302237.759 [keepstation:SurfaceComms:setSink] Stopped 2025-08-15T23:57:17.759Z,1755302237.759 [keepstation:SurfaceComms:setSink](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms:setSink 2025-08-15T23:57:17.759Z,1755302237.759 [keepstation:SurfaceComms:setSink:A] Stopped 2025-08-15T23:57:17.759Z,1755302237.759 [keepstation:SurfaceComms](INFO): Completed keepstation:SurfaceComms 2025-08-15T23:57:17.759Z,1755302237.759 [keepstation:SurfaceComms] Stopped 2025-08-15T23:57:17.759Z,1755302237.759 [keepstation:SurfaceComms](DEBUG): Aggregate::uninitialize keepstation:SurfaceComms 2025-08-15T23:57:45.214Z,1755302265.214 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-08-15T23:57:45.214Z,1755302265.214 [DropWeight] Hardware Fault, FailCount= 1 2025-08-15T23:57:45.214Z,1755302265.214 [DropWeight](ERROR): Hardware Fault 2025-08-15T23:57:45.398Z,1755302265.398 [CommandExec](FAULT): Scheduling is paused for 3 commands 2025-08-15T23:57:45.399Z,1755302265.399 [CBIT](INFO): Critical error at 20250815T235745 2025-08-15T23:57:45.399Z,1755302265.399 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-08-15T23:57:45.401Z,1755302265.401 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-08-15T23:57:45.402Z,1755302265.402 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-08-15T23:57:45.637Z,1755302265.637 [MissionManager](INFO): MissionManager is completed. 2025-08-15T23:57:45.637Z,1755302265.637 [MissionManager](INFO): Uninitializing Mission keepstation 2025-08-15T23:57:45.637Z,1755302265.637 [keepstation] Stopped 2025-08-15T23:57:45.637Z,1755302265.637 [keepstation](DEBUG): Aggregate::uninitialize keepstation 2025-08-15T23:57:45.637Z,1755302265.637 [keepstation:StandardEnvelopes] Stopped 2025-08-15T23:57:45.637Z,1755302265.637 [keepstation:StandardEnvelopes](DEBUG): Aggregate::uninitialize keepstation:StandardEnvelopes 2025-08-15T23:57:45.637Z,1755302265.637 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-08-15T23:57:45.637Z,1755302265.637 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:BackseatDriver] Stopped 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:BackseatDriver](DEBUG): Aggregate::uninitialize keepstation:BackseatDriver 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:BackseatDriver:A.BackseatDriver] Stopped 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:PowerOnly] Stopped 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:PowerOnly](DEBUG): Aggregate::uninitialize keepstation:PowerOnly 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:PowerOnly:E.Wait] Stopped 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:H.Pitch] Stopped 2025-08-15T23:57:45.638Z,1755302265.638 [keepstation:DiveCmd] Stopped 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:DiveCmd](DEBUG): Aggregate::uninitialize keepstation:DiveCmd 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:DiveCmd:StationKeep] Stopped 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:DiveCmd:StationKeep](DEBUG): Aggregate::uninitialize keepstation:DiveCmd:StationKeep 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:DiveCmd:StationKeep:A] Stopped 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:DiveCmd:StationKeep:B.Pitch] Stopped 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:DiveCmd:StationKeep:C.KeepStation] Stopped 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Uninitialize KeepStationComponent. 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:KeepStation] Stopped 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:KeepStation](DEBUG): Aggregate::uninitialize keepstation:KeepStation 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:KeepStation:Dive] Stopped 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:KeepStation:Dive](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive 2025-08-15T23:57:45.639Z,1755302265.639 [keepstation:KeepStation:Dive:A] Stopped 2025-08-15T23:57:45.656Z,1755302265.656 [keepstation:KeepStation:Dive:A](DEBUG): Aggregate::uninitialize keepstation:KeepStation:Dive:A 2025-08-15T23:57:45.656Z,1755302265.656 [keepstation:KeepStation:B.Wait] Stopped 2025-08-15T23:57:45.656Z,1755302265.656 [keepstation:KeepStation:B.Wait](DEBUG): Uninitialize Wait Component. 2025-08-15T23:57:45.887Z,1755302265.887 [CBIT](INFO): Critical error at 20250815T235745 2025-08-15T23:57:46.028Z,1755302266.028 [MissionManager](IMPORTANT): Started mission Default 2025-08-15T23:57:46.028Z,1755302266.028 [Default] Running Loop=1 2025-08-15T23:57:46.028Z,1755302266.028 [Default](DEBUG): Aggregate::initialize Default 2025-08-15T23:57:46.028Z,1755302266.028 [Default:B.GoToSurface] Running Loop=1 2025-08-15T23:57:46.028Z,1755302266.028 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-15T23:57:46.029Z,1755302266.029 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-15T23:57:46.029Z,1755302266.029 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-15T23:57:46.029Z,1755302266.029 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-15T23:57:46.029Z,1755302266.029 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-15T23:57:46.030Z,1755302266.030 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-15T23:57:46.030Z,1755302266.030 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-15T23:57:46.030Z,1755302266.030 [Default:A.Wait] Running Loop=1 2025-08-15T23:57:46.030Z,1755302266.030 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-08-15T23:57:47.654Z,1755302267.654 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-15T23:57:47.763Z,1755302267.763 [BackseatComponent](INFO): Sent LCM shutdown request. 2025-08-15T23:57:47.763Z,1755302267.763 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.). 2025-08-15T23:57:59.392Z,1755302279.392 [Default:A.Wait](INFO): Done Waiting. 2025-08-15T23:57:59.392Z,1755302279.392 [Default:A.Wait] Stopped 2025-08-15T23:57:59.392Z,1755302279.392 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-08-15T23:57:59.772Z,1755302279.772 [Default:CheckIn] Running Loop=1 2025-08-15T23:57:59.773Z,1755302279.773 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-15T23:57:59.773Z,1755302279.773 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-15T23:58:05.940Z,1755302285.940 [BackseatComponent](INFO): Powering down and starting shutdown timer (18.00 sec). 2025-08-15T23:58:05.941Z,1755302285.941 [BackseatComponent](INFO): Unsubscribing from LCM channels. 2025-08-15T23:58:05.941Z,1755302285.941 [LcmUniversalReporter](INFO): Deactivating messaging. 2025-08-15T23:59:48.034Z,1755302388.034 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-15T23:59:52.484Z,1755302392.484 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235952.00,A,3648.16436,N,12147.28839,W,0.719,226.45,150825,,,A*73 2025-08-15T23:59:52.487Z,1755302392.487 [NAL9602](INFO): GPS fix at 20250815T235952: (36.802739, -121.788140) 2025-08-15T23:59:52.496Z,1755302392.496 [Default:CheckIn:Read_GPS] Stopped 2025-08-15T23:59:52.497Z,1755302392.497 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-16T00:00:00.064Z,1755302400.064 [CommandExec](FAULT): Schedule is paused. Ignoring time-scheduled command: set keepstation:backseatdriver.enablebackseat 0 bool 2025-08-16T00:00:00.592Z,1755302400.592 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20250815T232729/Courier0037.lzma 2025-08-16T00:00:01.594Z,1755302401.594 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0037.lzma.bak 2025-08-16T00:00:01.594Z,1755302401.594 [DataOverHttps](INFO): SBD MOMSN=25854311 2025-08-16T00:00:18.716Z,1755302418.716 [DataOverHttps](INFO): Sending 217 bytes from file Logs/20250815T232729/Express0035.lzma 2025-08-16T00:00:19.718Z,1755302419.718 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0035.lzma.bak 2025-08-16T00:00:19.718Z,1755302419.718 [DataOverHttps](INFO): SBD MOMSN=25854316 2025-08-16T00:00:25.201Z,1755302425.201 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-16T00:00:38.510Z,1755302438.510 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20250815T232729/Express0038.lzma 2025-08-16T00:00:39.522Z,1755302439.522 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0038.lzma.bak 2025-08-16T00:00:39.522Z,1755302439.522 [DataOverHttps](INFO): SBD MOMSN=25854322 2025-08-16T00:00:42.199Z,1755302442.199 [Default:CheckIn:Read_Iridium] Stopped 2025-08-16T00:00:42.204Z,1755302442.204 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-16T00:00:42.204Z,1755302442.204 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-16T00:04:38.665Z,1755302678.665 [CommandExec](IMPORTANT): got command strobe off 2025-08-16T00:04:38.665Z,1755302678.665 [CommandExec](IMPORTANT): Deactivating strobe 2025-08-16T00:05:00.020Z,1755302700.020 [CommandExec](FAULT): Schedule is paused. Ignoring time-scheduled command: set keepstation:backseatdriver.enablebackseat 1 bool 2025-08-16T00:05:42.804Z,1755302742.804 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-16T00:05:42.804Z,1755302742.804 [Default:CheckIn:C.Wait] Stopped 2025-08-16T00:05:42.804Z,1755302742.804 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-16T00:05:42.805Z,1755302742.805 [Default:CheckIn:D] Running Loop=1 2025-08-16T00:05:43.214Z,1755302743.214 [Default:CheckIn:D] Stopped 2025-08-16T00:05:43.214Z,1755302743.214 [Default:CheckIn:E] Running Loop=1 2025-08-16T00:05:43.614Z,1755302743.614 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.953104 min 2025-08-16T00:05:43.614Z,1755302743.614 [Default:CheckIn:E] Stopped 2025-08-16T00:05:43.615Z,1755302743.615 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-16T00:05:43.615Z,1755302743.615 [Default:CheckIn] Stopped 2025-08-16T00:05:43.615Z,1755302743.615 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-16T00:05:43.615Z,1755302743.615 [Default:CheckIn](INFO): Running loop #2 2025-08-16T00:05:43.615Z,1755302743.615 [Default:CheckIn] Running Loop=2 2025-08-16T00:05:43.615Z,1755302743.615 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-16T00:05:43.615Z,1755302743.615 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-16T00:05:45.622Z,1755302745.622 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,000545.00,A,3648.16638,N,12147.28001,W,0.194,226.45,160825,,,A*72 2025-08-16T00:05:45.625Z,1755302745.625 [NAL9602](INFO): GPS fix at 20250816T000545: (36.802773, -121.788000) 2025-08-16T00:05:45.635Z,1755302745.635 [Default:CheckIn:Read_GPS] Stopped 2025-08-16T00:05:45.635Z,1755302745.635 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-16T00:05:53.451Z,1755302753.451 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250815T232729/Courier0040.lzma 2025-08-16T00:05:54.454Z,1755302754.454 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0040.lzma.bak 2025-08-16T00:05:54.454Z,1755302754.454 [DataOverHttps](INFO): SBD MOMSN=25854329 2025-08-16T00:06:02.998Z,1755302762.998 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00000:WI,-00668,-00073,+01548,+00000,A 2025-08-16T00:06:02.998Z,1755302762.998 [DVL_micro](ERROR): Failed to parse: :TS,00000:WI,-00668,-00073,+01548,+00000,A 2025-08-16T00:06:11.900Z,1755302771.900 [DataOverHttps](INFO): Sending 318 bytes from file Logs/20250815T232729/Express0041.lzma 2025-08-16T00:06:12.902Z,1755302772.902 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0041.lzma.bak 2025-08-16T00:06:12.902Z,1755302772.902 [DataOverHttps](INFO): SBD MOMSN=25854332 2025-08-16T00:06:15.547Z,1755302775.547 [Default:CheckIn:Read_Iridium] Stopped 2025-08-16T00:06:15.547Z,1755302775.547 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-16T00:06:15.547Z,1755302775.547 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-16T00:06:16.325Z,1755302776.325 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-16T00:06:16.408Z,1755302776.408 [NAL9602](ERROR): received: +CSQ:0 OK844, 2, 0, 0, 0 OK 2025-08-16T00:10:06.217Z,1755303006.217 [DVL_micro](ERROR): Failed to parse: :SA,-01.38,+03.42,252.3 2025-08-16T00:10:47.846Z,1755303047.846 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-16T00:11:16.130Z,1755303076.130 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-16T00:11:16.130Z,1755303076.130 [Default:CheckIn:C.Wait] Stopped 2025-08-16T00:11:16.130Z,1755303076.130 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-16T00:11:16.131Z,1755303076.131 [Default:CheckIn:D] Running Loop=1 2025-08-16T00:11:16.539Z,1755303076.539 [Default:CheckIn:D] Stopped 2025-08-16T00:11:16.539Z,1755303076.539 [Default:CheckIn:E] Running Loop=1 2025-08-16T00:11:16.947Z,1755303076.947 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.508511 min 2025-08-16T00:11:16.947Z,1755303076.947 [Default:CheckIn:E] Stopped 2025-08-16T00:11:16.947Z,1755303076.947 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-16T00:11:16.948Z,1755303076.948 [Default:CheckIn] Stopped 2025-08-16T00:11:16.948Z,1755303076.948 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-16T00:11:16.948Z,1755303076.948 [Default:CheckIn](INFO): Running loop #3 2025-08-16T00:11:16.948Z,1755303076.948 [Default:CheckIn] Running Loop=3 2025-08-16T00:11:16.948Z,1755303076.948 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-16T00:11:16.948Z,1755303076.948 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-16T00:11:18.950Z,1755303078.950 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001118.00,A,3648.16733,N,12147.28194,W,0.292,0.00,160825,,,A*7A 2025-08-16T00:11:18.952Z,1755303078.952 [NAL9602](INFO): GPS fix at 20250816T001118: (36.802789, -121.788032) 2025-08-16T00:11:18.962Z,1755303078.962 [Default:CheckIn:Read_GPS] Stopped 2025-08-16T00:11:18.962Z,1755303078.962 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-16T00:11:28.527Z,1755303088.527 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250815T232729/Courier0043.lzma 2025-08-16T00:11:29.534Z,1755303089.534 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0043.lzma.bak 2025-08-16T00:11:29.534Z,1755303089.534 [DataOverHttps](INFO): SBD MOMSN=25854339 2025-08-16T00:11:47.040Z,1755303107.040 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20250815T232729/Express0044.lzma 2025-08-16T00:11:48.042Z,1755303108.042 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0044.lzma.bak 2025-08-16T00:11:48.042Z,1755303108.042 [DataOverHttps](INFO): SBD MOMSN=25854342 2025-08-16T00:11:50.581Z,1755303110.581 [Default:CheckIn:Read_Iridium] Stopped 2025-08-16T00:11:50.581Z,1755303110.581 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-16T00:11:50.581Z,1755303110.581 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-16T00:11:50.983Z,1755303110.983 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-16T00:12:45.527Z,1755303165.527 [CBIT](INFO): Clearing failed state for component DropWeight 2025-08-16T00:12:45.527Z,1755303165.527 [DropWeight] No Fault, FailCount= 1 2025-08-16T00:15:00.029Z,1755303300.029 [CommandExec](FAULT): Schedule is paused. Ignoring time-scheduled command: restart sys 2025-08-16T00:16:51.200Z,1755303411.200 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-16T00:16:51.201Z,1755303411.201 [Default:CheckIn:C.Wait] Stopped 2025-08-16T00:16:51.201Z,1755303411.201 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-16T00:16:51.201Z,1755303411.201 [Default:CheckIn:D] Running Loop=1 2025-08-16T00:16:51.618Z,1755303411.618 [Default:CheckIn:D] Stopped 2025-08-16T00:16:51.618Z,1755303411.618 [Default:CheckIn:E] Running Loop=1 2025-08-16T00:16:52.001Z,1755303412.001 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.093164 min 2025-08-16T00:16:52.001Z,1755303412.001 [Default:CheckIn:E] Stopped 2025-08-16T00:16:52.001Z,1755303412.001 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-16T00:16:52.001Z,1755303412.001 [Default:CheckIn] Stopped 2025-08-16T00:16:52.001Z,1755303412.001 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-16T00:16:52.001Z,1755303412.001 [Default:CheckIn](INFO): Running loop #4 2025-08-16T00:16:52.001Z,1755303412.001 [Default:CheckIn] Running Loop=4 2025-08-16T00:16:52.002Z,1755303412.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-16T00:16:52.002Z,1755303412.002 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-16T00:16:54.012Z,1755303414.012 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,001653.00,A,3648.16869,N,12147.28442,W,0.214,0.00,160825,,,A*72 2025-08-16T00:16:54.014Z,1755303414.014 [NAL9602](INFO): GPS fix at 20250816T001653: (36.802811, -121.788074) 2025-08-16T00:16:54.025Z,1755303414.025 [Default:CheckIn:Read_GPS] Stopped 2025-08-16T00:16:54.025Z,1755303414.025 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-16T00:17:01.919Z,1755303421.919 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250815T232729/Courier0046.lzma 2025-08-16T00:17:02.922Z,1755303422.922 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0046.lzma.bak 2025-08-16T00:17:02.922Z,1755303422.922 [DataOverHttps](INFO): SBD MOMSN=25854346 2025-08-16T00:17:22.524Z,1755303442.524 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20250815T232729/Express0047.lzma 2025-08-16T00:17:23.526Z,1755303443.526 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0047.lzma.bak 2025-08-16T00:17:23.526Z,1755303443.526 [DataOverHttps](INFO): SBD MOMSN=25854349 2025-08-16T00:17:24.706Z,1755303444.706 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-16T00:17:24.780Z,1755303444.780 [NAL9602](ERROR): received: +CSQ:0 OK844, 2, 0, 0, 0 OK 2025-08-16T00:17:25.992Z,1755303445.992 [Default:CheckIn:Read_Iridium] Stopped 2025-08-16T00:17:25.993Z,1755303445.993 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-16T00:17:25.993Z,1755303445.993 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-16T00:21:56.217Z,1755303716.217 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-16T00:22:26.598Z,1755303746.598 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-16T00:22:26.598Z,1755303746.598 [Default:CheckIn:C.Wait] Stopped 2025-08-16T00:22:26.598Z,1755303746.598 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-16T00:22:26.598Z,1755303746.598 [Default:CheckIn:D] Running Loop=1 2025-08-16T00:22:26.958Z,1755303746.958 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-16T00:22:27.101Z,1755303747.101 [Default:CheckIn:D] Stopped 2025-08-16T00:22:27.101Z,1755303747.101 [Default:CheckIn:E] Running Loop=1 2025-08-16T00:22:27.366Z,1755303747.366 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.684554 min 2025-08-16T00:22:27.366Z,1755303747.366 [Default:CheckIn:E] Stopped 2025-08-16T00:22:27.366Z,1755303747.366 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-16T00:22:27.366Z,1755303747.366 [Default:CheckIn] Stopped 2025-08-16T00:22:27.366Z,1755303747.366 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-16T00:22:27.366Z,1755303747.366 [Default:CheckIn](INFO): Running loop #5 2025-08-16T00:22:27.366Z,1755303747.366 [Default:CheckIn] Running Loop=5 2025-08-16T00:22:27.367Z,1755303747.367 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-16T00:22:27.367Z,1755303747.367 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-16T00:22:29.407Z,1755303749.407 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002229.00,A,3648.17486,N,12147.28616,W,0.253,199.91,160825,,,A*7D 2025-08-16T00:22:29.430Z,1755303749.430 [NAL9602](INFO): GPS fix at 20250816T002229: (36.802914, -121.788103) 2025-08-16T00:22:29.469Z,1755303749.469 [Default:CheckIn:Read_GPS] Stopped 2025-08-16T00:22:29.469Z,1755303749.469 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-16T00:22:42.331Z,1755303762.331 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250815T232729/Courier0049.lzma 2025-08-16T00:22:43.334Z,1755303763.334 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0049.lzma.bak 2025-08-16T00:22:43.334Z,1755303763.334 [DataOverHttps](INFO): SBD MOMSN=25854353 2025-08-16T00:23:00.078Z,1755303780.078 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-16T00:23:00.160Z,1755303780.160 [NAL9602](ERROR): received: +CSQ:0 OK844, 2, 0, 0, 0 OK 2025-08-16T00:23:04.108Z,1755303784.108 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20250815T232729/Express0050.lzma 2025-08-16T00:23:05.110Z,1755303785.110 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Express0050.lzma.bak 2025-08-16T00:23:05.111Z,1755303785.111 [DataOverHttps](INFO): SBD MOMSN=25854356 2025-08-16T00:23:07.801Z,1755303787.801 [Default:CheckIn:Read_Iridium] Stopped 2025-08-16T00:23:07.802Z,1755303787.802 [Default:CheckIn:C.Wait] Running Loop=1 2025-08-16T00:23:07.802Z,1755303787.802 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-16T00:27:32.002Z,1755304052.002 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-16T00:28:02.694Z,1755304082.694 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-16T00:28:08.371Z,1755304088.371 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-08-16T00:28:08.371Z,1755304088.371 [Default:CheckIn:C.Wait] Stopped 2025-08-16T00:28:08.371Z,1755304088.371 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-16T00:28:08.371Z,1755304088.371 [Default:CheckIn:D] Running Loop=1 2025-08-16T00:28:08.763Z,1755304088.763 [Default:CheckIn:D] Stopped 2025-08-16T00:28:08.763Z,1755304088.763 [Default:CheckIn:E] Running Loop=1 2025-08-16T00:28:09.177Z,1755304089.177 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.378914 min 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn:E] Stopped 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn] Stopped 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn](INFO): Running loop #6 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn] Running Loop=6 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-08-16T00:28:09.178Z,1755304089.178 [Default:CheckIn:Read_GPS] Running Loop=1 2025-08-16T00:28:11.181Z,1755304091.181 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,002810.00,A,3648.16290,N,12147.28302,W,0.933,215.16,160825,,,A*78 2025-08-16T00:28:11.183Z,1755304091.183 [NAL9602](INFO): GPS fix at 20250816T002810: (36.802715, -121.788050) 2025-08-16T00:28:11.193Z,1755304091.193 [Default:CheckIn:Read_GPS] Stopped 2025-08-16T00:28:11.193Z,1755304091.193 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-08-16T00:28:18.875Z,1755304098.875 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250815T232729/Courier0052.lzma 2025-08-16T00:28:19.879Z,1755304099.879 [DataOverHttps](INFO): Moved sent file to Logs/20250815T232729/Courier0052.lzma.bak 2025-08-16T00:28:19.879Z,1755304099.879 [DataOverHttps](IMPORTANT): SBD MOMSN=25854361, MTMSN=20250816T002819 2025-08-16T00:28:30.068Z,1755304110.068 [DataOverHttps](INFO): Received command: configset dropweight.loadatstartup 0 bool persist;restart app 2025-08-16T00:28:30.587Z,1755304110.587 [CommandExec](IMPORTANT): got command configSet DropWeight.loadAtStartup 0 bool persist 2025-08-16T00:28:30.587Z,1755304110.587 [CommandExec](IMPORTANT): configSet DropWeight.loadAtStartup requires a restart to take effect. 2025-08-16T00:28:30.598Z,1755304110.598 [CommandExec](IMPORTANT): got command restart application 2025-08-16T00:28:31.600Z,1755304111.600 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:31.600Z,1755304111.600 [CommandExec](INFO): Uninitializing the command executive. 2025-08-16T00:28:31.600Z,1755304111.600 [CommandExec](INFO): Uninitializing the command scheduler. 2025-08-16T00:28:31.600Z,1755304111.600 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:31.748Z,1755304111.748 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-08-16T00:28:31.748Z,1755304111.748 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-08-16T00:28:31.748Z,1755304111.748 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:31.748Z,1755304111.748 [NavChartDb](INFO): Join timeout helper Thread ID is 2952 2025-08-16T00:28:31.908Z,1755304111.908 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:31.908Z,1755304111.908 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:31.912Z,1755304111.912 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-08-16T00:28:31.912Z,1755304111.912 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:31.912Z,1755304111.912 [Radio_Surface](INFO): Join timeout helper Thread ID is 2953 2025-08-16T00:28:31.924Z,1755304111.924 [Radio_Surface](INFO): Powering down 2025-08-16T00:28:31.925Z,1755304111.925 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:31.925Z,1755304111.925 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:31.932Z,1755304111.932 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-08-16T00:28:31.932Z,1755304111.932 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:31.932Z,1755304111.932 [Onboard](INFO): Join timeout helper Thread ID is 2954 2025-08-16T00:28:32.072Z,1755304112.072 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-16T00:28:35.524Z,1755304115.524 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:35.525Z,1755304115.525 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:35.528Z,1755304115.528 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-08-16T00:28:35.528Z,1755304115.528 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:35.529Z,1755304115.529 [DataOverHttps](INFO): Join timeout helper Thread ID is 2955 2025-08-16T00:28:36.088Z,1755304116.088 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:36.088Z,1755304116.088 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:36.092Z,1755304116.092 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-08-16T00:28:36.092Z,1755304116.092 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:36.092Z,1755304116.092 [DAT](INFO): Join timeout helper Thread ID is 2956 2025-08-16T00:28:36.329Z,1755304116.329 [DAT](INFO): Powering down 2025-08-16T00:28:36.400Z,1755304116.400 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:36.401Z,1755304116.401 [DAT](INFO): Powering down 2025-08-16T00:28:36.401Z,1755304116.401 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:36.417Z,1755304116.417 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2025-08-16T00:28:36.417Z,1755304116.417 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:36.417Z,1755304116.417 [BackseatComponent](INFO): Join timeout helper Thread ID is 2957 2025-08-16T00:28:36.532Z,1755304116.532 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:36.532Z,1755304116.532 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:36.549Z,1755304116.549 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-08-16T00:28:36.549Z,1755304116.549 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:36.549Z,1755304116.549 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2958 2025-08-16T00:28:36.988Z,1755304116.988 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:36.988Z,1755304116.988 [WetLabsBB2FL](INFO): Powering down 2025-08-16T00:28:36.989Z,1755304116.989 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.016Z,1755304117.016 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-08-16T00:28:37.016Z,1755304117.016 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.020Z,1755304117.020 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2959 2025-08-16T00:28:37.804Z,1755304117.804 [CTD_Seabird](INFO): Powering down 2025-08-16T00:28:37.816Z,1755304117.816 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:37.824Z,1755304117.824 [CTD_Seabird](INFO): Powering down 2025-08-16T00:28:37.836Z,1755304117.836 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.837Z,1755304117.837 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-08-16T00:28:37.837Z,1755304117.837 [logger ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.838Z,1755304117.838 [logger](INFO): Join timeout helper Thread ID is 2960 2025-08-16T00:28:37.844Z,1755304117.844 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:37.844Z,1755304117.844 [logger ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.857Z,1755304117.857 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-08-16T00:28:37.857Z,1755304117.857 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.857Z,1755304117.857 [CommandLine](INFO): Join timeout helper Thread ID is 2961 2025-08-16T00:28:37.924Z,1755304117.924 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:37.924Z,1755304117.924 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.941Z,1755304117.941 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-08-16T00:28:37.941Z,1755304117.941 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.941Z,1755304117.941 [CommandExec](INFO): Join timeout helper Thread ID is 2962 2025-08-16T00:28:37.942Z,1755304117.942 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-08-16T00:28:37.942Z,1755304117.942 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:37.943Z,1755304117.943 [controlThread](INFO): Join timeout helper Thread ID is 2963 2025-08-16T00:28:38.220Z,1755304118.220 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-16T00:28:38.220Z,1755304118.220 [controlThread](DEBUG): Uninitializing ControlThread 2025-08-16T00:28:38.221Z,1755304118.221 [AHRS_M2](INFO): Powering down 2025-08-16T00:28:38.396Z,1755304118.396 [DVL_micro](INFO): Powering down 2025-08-16T00:28:38.397Z,1755304118.397 [NAL9602](INFO): Powering down 2025-08-16T00:28:38.398Z,1755304118.398 [Sonardyne_Nano](INFO): Powering down 2025-08-16T00:28:38.604Z,1755304118.604 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-08-16T00:28:38.605Z,1755304118.605 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-08-16T00:28:38.605Z,1755304118.605 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-08-16T00:28:38.606Z,1755304118.606 [MissionManager](INFO): Uninitializing Mission Default 2025-08-16T00:28:38.606Z,1755304118.606 [Default] Stopped 2025-08-16T00:28:38.606Z,1755304118.606 [Default](DEBUG): Aggregate::uninitialize Default 2025-08-16T00:28:38.606Z,1755304118.606 [Default:B.GoToSurface] Stopped 2025-08-16T00:28:38.606Z,1755304118.606 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-16T00:28:38.606Z,1755304118.606 [Default:CheckIn] Stopped 2025-08-16T00:28:38.606Z,1755304118.606 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-08-16T00:28:38.606Z,1755304118.606 [Default:CheckIn:Read_Iridium] Stopped 2025-08-16T00:28:38.609Z,1755304118.609 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-08-16T00:28:38.610Z,1755304118.610 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-08-16T00:28:38.610Z,1755304118.610 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-08-16T00:28:38.610Z,1755304118.610 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-08-16T00:28:38.611Z,1755304118.611 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-08-16T00:28:38.611Z,1755304118.611 [BuoyancyServo](INFO): Powering down 2025-08-16T00:28:38.624Z,1755304118.624 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-08-16T00:28:38.624Z,1755304118.624 [ElevatorServo](INFO): Powering down 2025-08-16T00:28:38.625Z,1755304118.625 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-08-16T00:28:38.625Z,1755304118.625 [MassServo](INFO): Powering down 2025-08-16T00:28:38.626Z,1755304118.626 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-08-16T00:28:38.626Z,1755304118.626 [RudderServo](INFO): Powering down 2025-08-16T00:28:38.627Z,1755304118.627 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-08-16T00:28:38.627Z,1755304118.627 [ThrusterHE](INFO): Powering down 2025-08-16T00:28:38.628Z,1755304118.628 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-08-16T00:28:38.628Z,1755304118.628 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-08-16T00:28:38.628Z,1755304118.628 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-08-16T00:28:38.629Z,1755304118.629 [CBIT](DEBUG): Powering off loads. 2025-08-16T00:28:38.640Z,1755304118.640 [CBIT](DEBUG): Disabling WDT. 2025-08-16T00:28:38.652Z,1755304118.652 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-08-16T00:28:38.652Z,1755304118.652 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-08-16T00:28:38.653Z,1755304118.653 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.689Z,1755304118.689 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-08-16T00:28:38.689Z,1755304118.689 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-08-16T00:28:38.704Z,1755304118.704 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.710Z,1755304118.710 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.742Z,1755304118.742 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.744Z,1755304118.744 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.751Z,1755304118.751 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.758Z,1755304118.758 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.800Z,1755304118.800 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.854Z,1755304118.854 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-16T00:28:38.927Z,1755304118.927 [logger ThreadHandler](INFO): Thread cancelled.