2025-06-03T19:09:39.011Z,1748977779.011 [Supervisor](DEBUG): Initializing supervisor. 2025-06-03T19:09:39.016Z,1748977779.016 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-06-03T19:09:39.016Z,1748977779.016 [SyncHandler](INFO): Protected caller Thread ID is 829 2025-06-03T19:09:39.017Z,1748977779.017 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-06-03T19:09:39.018Z,1748977779.018 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-06-03T19:09:39.018Z,1748977779.018 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 830 2025-06-03T19:09:39.022Z,1748977779.022 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-06-03T19:09:39.042Z,1748977779.042 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-06-03T19:09:39.043Z,1748977779.043 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-06-03T19:09:39.044Z,1748977779.044 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 831 2025-06-03T19:09:39.048Z,1748977779.048 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-06-03T19:09:39.049Z,1748977779.049 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-06-03T19:09:39.050Z,1748977779.050 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 832 2025-06-03T19:09:39.052Z,1748977779.052 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-06-03T19:09:39.053Z,1748977779.053 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-06-03T19:09:39.053Z,1748977779.053 [logger ThreadHandler](INFO): Protected caller Thread ID is 833 2025-06-03T19:09:39.057Z,1748977779.057 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-06-03T19:09:39.058Z,1748977779.058 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-06-03T19:09:39.063Z,1748977779.063 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-06-03T19:09:39.169Z,1748977779.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-06-03T19:09:39.171Z,1748977779.171 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-06-03T19:09:39.405Z,1748977779.405 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-06-03T19:09:39.407Z,1748977779.407 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-06-03T19:09:39.681Z,1748977779.681 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-06-03T19:09:39.683Z,1748977779.683 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-06-03T19:09:39.799Z,1748977779.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-06-03T19:09:39.801Z,1748977779.801 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-06-03T19:09:40.576Z,1748977780.576 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-06-03T19:09:40.577Z,1748977780.577 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-06-03T19:09:41.107Z,1748977781.107 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-06-03T19:09:41.108Z,1748977781.108 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-06-03T19:09:41.673Z,1748977781.673 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-06-03T19:09:41.674Z,1748977781.674 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-06-03T19:09:42.210Z,1748977782.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-06-03T19:09:42.357Z,1748977782.357 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-06-03T19:09:42.948Z,1748977782.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-06-03T19:09:42.948Z,1748977782.948 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-06-03T19:09:43.345Z,1748977783.345 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-06-03T19:09:43.346Z,1748977783.346 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-06-03T19:09:43.583Z,1748977783.583 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-06-03T19:09:43.585Z,1748977783.585 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-06-03T19:09:43.738Z,1748977783.738 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-06-03T19:09:43.740Z,1748977783.740 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-06-03T19:09:43.842Z,1748977783.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-06-03T19:09:43.843Z,1748977783.843 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-06-03T19:09:43.933Z,1748977783.933 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-06-03T19:09:44.131Z,1748977784.131 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-06-03T19:09:44.132Z,1748977784.132 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-06-03T19:09:44.392Z,1748977784.392 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-06-03T19:09:44.394Z,1748977784.394 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2025-06-03T19:09:44.398Z,1748977784.398 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2025-06-03T19:09:44.491Z,1748977784.491 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2025-06-03T19:09:44.772Z,1748977784.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-06-03T19:09:44.773Z,1748977784.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2025-06-03T19:09:44.867Z,1748977784.867 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2025-06-03T19:09:45.049Z,1748977785.049 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2025-06-03T19:09:45.160Z,1748977785.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2025-06-03T19:09:45.281Z,1748977785.281 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2025-06-03T19:09:45.405Z,1748977785.405 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2025-06-03T19:09:45.510Z,1748977785.510 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2025-06-03T19:09:45.683Z,1748977785.683 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2025-06-03T19:09:45.790Z,1748977785.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg 2025-06-03T19:09:45.887Z,1748977785.887 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2025-06-03T19:09:45.995Z,1748977785.995 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2025-06-03T19:09:46.092Z,1748977786.092 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-06-03T19:09:46.105Z,1748977786.105 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-06-03T19:09:46.342Z,1748977786.342 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-06-03T19:09:46.342Z,1748977786.342 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-06-03T19:09:46.547Z,1748977786.547 [BuoyancyServo] Loaded 2025-06-03T19:09:46.547Z,1748977786.547 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-06-03T19:09:46.571Z,1748977786.571 [ElevatorServo] Loaded 2025-06-03T19:09:46.571Z,1748977786.571 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-06-03T19:09:46.595Z,1748977786.595 [MassServo] Loaded 2025-06-03T19:09:46.595Z,1748977786.595 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-06-03T19:09:46.618Z,1748977786.618 [RudderServo] Loaded 2025-06-03T19:09:46.618Z,1748977786.618 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-06-03T19:09:46.637Z,1748977786.637 [ThrusterHE] Loaded 2025-06-03T19:09:46.637Z,1748977786.637 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-06-03T19:09:46.637Z,1748977786.637 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-06-03T19:09:46.639Z,1748977786.639 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-06-03T19:09:46.856Z,1748977786.856 [SBIT](DEBUG): Construct Startup Built In Test. 2025-06-03T19:09:46.872Z,1748977786.872 [SBIT] Loaded 2025-06-03T19:09:46.872Z,1748977786.872 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-06-03T19:09:46.875Z,1748977786.875 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-06-03T19:09:46.897Z,1748977786.897 [IBIT] Loaded 2025-06-03T19:09:46.897Z,1748977786.897 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-06-03T19:09:46.902Z,1748977786.902 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-06-03T19:09:47.102Z,1748977787.102 [CBIT] Loaded 2025-06-03T19:09:47.102Z,1748977787.102 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-06-03T19:09:47.134Z,1748977787.134 [GFScanner] Loaded 2025-06-03T19:09:47.135Z,1748977787.135 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-06-03T19:09:47.135Z,1748977787.135 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-06-03T19:09:47.136Z,1748977787.136 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-06-03T19:09:47.398Z,1748977787.398 [CTD_Seabird] Loaded 2025-06-03T19:09:47.400Z,1748977787.400 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-06-03T19:09:47.417Z,1748977787.417 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406864E0 2025-06-03T19:09:47.417Z,1748977787.417 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 921 2025-06-03T19:09:47.578Z,1748977787.578 [ESPComponent] Loaded 2025-06-03T19:09:47.579Z,1748977787.579 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-06-03T19:09:47.609Z,1748977787.609 [PAR_Licor] Loaded 2025-06-03T19:09:47.609Z,1748977787.609 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-06-03T19:09:47.656Z,1748977787.656 [WetLabsBB2FL] Loaded 2025-06-03T19:09:47.657Z,1748977787.657 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-06-03T19:09:47.658Z,1748977787.658 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0 2025-06-03T19:09:47.658Z,1748977787.658 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 922 2025-06-03T19:09:47.659Z,1748977787.659 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-06-03T19:09:47.659Z,1748977787.659 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-06-03T19:09:47.981Z,1748977787.981 [DepthRateCalculator] Loaded 2025-06-03T19:09:47.981Z,1748977787.981 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-06-03T19:09:47.987Z,1748977787.987 [PitchRateCalculator] Loaded 2025-06-03T19:09:47.987Z,1748977787.987 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-06-03T19:09:47.998Z,1748977787.998 [SpeedCalculator] Loaded 2025-06-03T19:09:47.998Z,1748977787.998 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-06-03T19:09:48.003Z,1748977788.003 [YawRateCalculator] Loaded 2025-06-03T19:09:48.003Z,1748977788.003 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-06-03T19:09:48.023Z,1748977788.023 [ElevatorOffsetCalculator] Loaded 2025-06-03T19:09:48.024Z,1748977788.024 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-06-03T19:09:48.024Z,1748977788.024 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-06-03T19:09:48.025Z,1748977788.025 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-06-03T19:09:48.208Z,1748977788.208 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-06-03T19:09:48.209Z,1748977788.209 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-06-03T19:09:48.259Z,1748977788.259 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-06-03T19:09:48.259Z,1748977788.259 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-06-03T19:09:48.406Z,1748977788.406 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-06-03T19:09:48.406Z,1748977788.406 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-06-03T19:09:48.420Z,1748977788.420 [NavChart] Loaded 2025-06-03T19:09:48.421Z,1748977788.421 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-06-03T19:09:48.427Z,1748977788.427 [UniversalFixResidualReporter] Loaded 2025-06-03T19:09:48.427Z,1748977788.427 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-06-03T19:09:48.427Z,1748977788.427 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-06-03T19:09:48.428Z,1748977788.428 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-06-03T19:09:49.350Z,1748977789.350 [AHRS_M2] Loaded 2025-06-03T19:09:49.351Z,1748977789.351 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-06-03T19:09:49.605Z,1748977789.605 [BackseatComponent] Loaded 2025-06-03T19:09:49.605Z,1748977789.605 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-06-03T19:09:49.606Z,1748977789.606 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A824E0 2025-06-03T19:09:49.606Z,1748977789.606 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923 2025-06-03T19:09:49.609Z,1748977789.609 [LcmUniversalReporter] Loaded 2025-06-03T19:09:49.610Z,1748977789.610 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-06-03T19:09:50.370Z,1748977790.370 [BPC1] Loaded 2025-06-03T19:09:50.370Z,1748977790.370 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-06-03T19:09:50.474Z,1748977790.474 [DAT] Loaded 2025-06-03T19:09:50.475Z,1748977790.475 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-06-03T19:09:50.476Z,1748977790.476 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB24E0 2025-06-03T19:09:50.476Z,1748977790.476 [DAT ThreadHandler](INFO): Protected caller Thread ID is 924 2025-06-03T19:09:50.618Z,1748977790.618 [DataOverHttps] Loaded 2025-06-03T19:09:50.618Z,1748977790.618 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-06-03T19:09:50.619Z,1748977790.619 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE24E0 2025-06-03T19:09:50.620Z,1748977790.620 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925 2025-06-03T19:09:50.644Z,1748977790.644 [Depth_Keller] Loaded 2025-06-03T19:09:50.644Z,1748977790.644 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-06-03T19:09:50.650Z,1748977790.650 [DropWeight] Loaded 2025-06-03T19:09:50.650Z,1748977790.650 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-06-03T19:09:50.715Z,1748977790.715 [NAL9602] Loaded 2025-06-03T19:09:50.715Z,1748977790.715 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-06-03T19:09:50.742Z,1748977790.742 [Onboard] Loaded 2025-06-03T19:09:50.742Z,1748977790.742 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-06-03T19:09:50.743Z,1748977790.743 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B124E0 2025-06-03T19:09:50.744Z,1748977790.744 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926 2025-06-03T19:09:50.750Z,1748977790.750 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1 2025-06-03T19:09:50.764Z,1748977790.764 [PowerOnly] Loaded 2025-06-03T19:09:50.765Z,1748977790.765 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2025-06-03T19:09:50.779Z,1748977790.779 [Power24vConverter] Loaded 2025-06-03T19:09:50.779Z,1748977790.779 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-06-03T19:09:50.796Z,1748977790.796 [Radio_Surface] Loaded 2025-06-03T19:09:50.797Z,1748977790.797 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-06-03T19:09:50.798Z,1748977790.798 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B424E0 2025-06-03T19:09:50.798Z,1748977790.798 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927 2025-06-03T19:09:50.814Z,1748977790.814 [Sonardyne_Nano] Loaded 2025-06-03T19:09:50.815Z,1748977790.815 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-06-03T19:09:50.815Z,1748977790.815 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-06-03T19:09:50.816Z,1748977790.816 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-06-03T19:09:50.908Z,1748977790.908 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-06-03T19:09:50.909Z,1748977790.909 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-06-03T19:09:50.987Z,1748977790.987 [VerticalControl](DEBUG): Construct VerticalControl. 2025-06-03T19:09:51.042Z,1748977791.042 [VerticalControl] Loaded 2025-06-03T19:09:51.042Z,1748977791.042 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-06-03T19:09:51.045Z,1748977791.045 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-06-03T19:09:51.091Z,1748977791.091 [HorizontalControl] Loaded 2025-06-03T19:09:51.092Z,1748977791.092 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-06-03T19:09:51.094Z,1748977791.094 [SpeedControl](DEBUG): Construct SpeedControl. 2025-06-03T19:09:51.096Z,1748977791.096 [SpeedControl] Loaded 2025-06-03T19:09:51.096Z,1748977791.096 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-06-03T19:09:51.099Z,1748977791.099 [LoopControl](DEBUG): Construct LoopControl. 2025-06-03T19:09:51.100Z,1748977791.100 [LoopControl] Loaded 2025-06-03T19:09:51.100Z,1748977791.100 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-06-03T19:09:51.100Z,1748977791.100 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-06-03T19:09:51.101Z,1748977791.101 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-06-03T19:09:51.117Z,1748977791.117 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-06-03T19:09:51.118Z,1748977791.118 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-06-03T19:09:51.566Z,1748977791.566 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-06-03T19:09:51.572Z,1748977791.572 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-06-03T19:09:51.575Z,1748977791.575 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-06-03T19:09:51.587Z,1748977791.587 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-06-03T19:09:51.588Z,1748977791.588 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C684E0 2025-06-03T19:09:51.588Z,1748977791.588 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928 2025-06-03T19:09:51.592Z,1748977791.592 [Supervisor](INFO): Main Thread ID is 822 2025-06-03T19:09:51.593Z,1748977791.593 [Supervisor](DEBUG): Running supervisor. 2025-06-03T19:09:51.593Z,1748977791.593 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929 2025-06-03T19:09:51.594Z,1748977791.594 [CommandExec](INFO): Initializing the command executive. 2025-06-03T19:09:51.595Z,1748977791.595 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930 2025-06-03T19:09:51.598Z,1748977791.598 [controlThread ThreadHandler](INFO): Handler Thread ID is 931 2025-06-03T19:09:51.598Z,1748977791.598 [controlThread](DEBUG): Initializing ControlThread 2025-06-03T19:09:51.600Z,1748977791.600 [SBIT](INFO): Initialize SBIT Component. 2025-06-03T19:09:51.600Z,1748977791.600 [SBIT](IMPORTANT): git: 2025-05-29 2025-06-03T19:09:51.600Z,1748977791.600 [SBIT](INFO): git hash: c78c975c7bb2a66b27244d2837f68dff299fa024 2025-06-03T19:09:51.601Z,1748977791.601 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-06-03T19:09:51.602Z,1748977791.602 [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-06-03T19:09:51.603Z,1748977791.603 [SBIT](INFO): Beginning SBIT in 145.000000 seconds. 2025-06-03T19:09:51.604Z,1748977791.604 [IBIT](INFO): Initialize IBIT Component. 2025-06-03T19:09:51.605Z,1748977791.605 [CBIT](DEBUG): Initialize CBIT Component. 2025-06-03T19:09:51.606Z,1748977791.606 [logger ThreadHandler](INFO): Handler Thread ID is 932 2025-06-03T19:09:51.616Z,1748977791.616 [CBIT](DEBUG): Initialized mux pins. 2025-06-03T19:09:51.617Z,1748977791.617 [CBIT](DEBUG): Initializing the watchdog timer. 2025-06-03T19:09:51.625Z,1748977791.625 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 933 2025-06-03T19:09:51.626Z,1748977791.626 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-06-03T19:09:51.630Z,1748977791.630 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935 2025-06-03T19:09:51.633Z,1748977791.633 [WetLabsBB2FL](INFO): Powering up 2025-06-03T19:09:51.634Z,1748977791.634 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2025-06-03T19:09:51.641Z,1748977791.641 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-06-03T19:09:51.641Z,1748977791.641 [CBIT](DEBUG): Initializing heartbeat. 2025-06-03T19:09:51.642Z,1748977791.642 [DAT ThreadHandler](INFO): Handler Thread ID is 938 2025-06-03T19:09:51.643Z,1748977791.643 [DAT](INFO): Powering up 2025-06-03T19:09:51.643Z,1748977791.643 [DAT](DEBUG): Initializing DAT. 2025-06-03T19:09:51.646Z,1748977791.646 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 940 2025-06-03T19:09:51.647Z,1748977791.647 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-06-03T19:09:51.657Z,1748977791.657 [Onboard ThreadHandler](INFO): Handler Thread ID is 941 2025-06-03T19:09:51.675Z,1748977791.675 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 942 2025-06-03T19:09:51.693Z,1748977791.693 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2025-06-03T19:09:51.702Z,1748977791.702 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-06-03T19:09:51.702Z,1748977791.702 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-06-03T19:09:51.702Z,1748977791.702 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-06-03T19:09:51.702Z,1748977791.702 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-06-03T19:09:51.703Z,1748977791.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-06-03T19:09:51.703Z,1748977791.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-06-03T19:09:51.703Z,1748977791.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-06-03T19:09:51.703Z,1748977791.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-06-03T19:09:51.713Z,1748977791.713 [CBIT](DEBUG): Deactivating emergency mode. 2025-06-03T19:09:51.753Z,1748977791.753 [CBIT](DEBUG): Backplane powered. 2025-06-03T19:09:51.753Z,1748977791.753 [GFScanner](DEBUG): Initializing GFScanner 2025-06-03T19:09:51.753Z,1748977791.753 [GFScanner](DEBUG): Deactivating GF circuits. 2025-06-03T19:09:51.761Z,1748977791.761 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-06-03T19:09:51.761Z,1748977791.761 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-06-03T19:09:51.762Z,1748977791.762 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-06-03T19:09:51.762Z,1748977791.762 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-06-03T19:09:51.762Z,1748977791.762 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-06-03T19:09:51.763Z,1748977791.763 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-06-03T19:09:51.764Z,1748977791.764 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-06-03T19:09:51.767Z,1748977791.767 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-06-03T19:09:51.773Z,1748977791.773 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-06-03T19:09:51.774Z,1748977791.774 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-06-03T19:09:51.774Z,1748977791.774 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-06-03T19:09:51.775Z,1748977791.775 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-06-03T19:09:51.776Z,1748977791.776 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-06-03T19:09:51.776Z,1748977791.776 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-06-03T19:09:51.797Z,1748977791.797 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-06-03T19:09:51.856Z,1748977791.856 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-06-03T19:09:51.881Z,1748977791.881 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-06-03T19:09:51.917Z,1748977791.917 [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-06-03T19:09:51.917Z,1748977791.917 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-06-03T19:09:51.918Z,1748977791.918 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-06-03T19:09:51.921Z,1748977791.921 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-06-03T19:09:52.081Z,1748977792.081 [Radio_Surface](INFO): Powering up 2025-06-03T19:09:52.211Z,1748977792.211 [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-06-03T19:09:52.237Z,1748977792.237 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-06-03T19:09:52.238Z,1748977792.238 [Default:A.Wait](DEBUG): Construct Wait. 2025-06-03T19:09:52.240Z,1748977792.240 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-06-03T19:09:52.286Z,1748977792.286 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-06-03T19:09:52.304Z,1748977792.304 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-06-03T19:09:52.315Z,1748977792.315 [Default:E.Execute](DEBUG): Construct Execute. 2025-06-03T19:09:52.330Z,1748977792.330 [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-06-03T19:09:52.335Z,1748977792.335 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,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-06-03T19:09:52.360Z,1748977792.360 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-06-03T19:09:52.505Z,1748977792.505 [Depth_Keller](INFO): Initializing. 2025-06-03T19:09:52.507Z,1748977792.507 [PowerOnly](INFO): Powering up loadControl 2025-06-03T19:09:52.525Z,1748977792.525 [Power24vConverter](INFO): Powering up. 2025-06-03T19:09:52.526Z,1748977792.526 [Sonardyne_Nano](INFO): Initializing. 2025-06-03T19:09:52.553Z,1748977792.553 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-06-03T19:09:52.599Z,1748977792.599 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-06-03T19:09:52.605Z,1748977792.605 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-06-03T19:09:52.606Z,1748977792.606 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-06-03T19:09:52.613Z,1748977792.613 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-06-03T19:09:52.614Z,1748977792.614 [MassServo](DEBUG): Initializing EZServoServo. 2025-06-03T19:09:52.621Z,1748977792.621 [MassServo](DEBUG): Initializing MassServo. 2025-06-03T19:09:52.622Z,1748977792.622 [RudderServo](DEBUG): Initializing EZServoServo. 2025-06-03T19:09:52.629Z,1748977792.629 [RudderServo](DEBUG): Initializing RudderServo. 2025-06-03T19:09:52.630Z,1748977792.630 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-06-03T19:09:52.637Z,1748977792.637 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-06-03T19:09:52.812Z,1748977792.812 [Depth_Keller](ERROR): Pressure or depth reading out of range: 947.322021 decibar, 0.000000 m 2025-06-03T19:09:52.819Z,1748977792.819 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-06-03T19:09:54.245Z,1748977794.245 [WetLabsBB2FL](INFO): Powering down 2025-06-03T19:09:54.788Z,1748977794.788 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-06-03T19:09:56.022Z,1748977796.022 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213 2025-06-03T19:09:58.353Z,1748977798.353 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-06-03T19:10:03.741Z,1748977803.741 [DAT](INFO): DAT read: 2025-06-03T19:10:03.743Z,1748977803.743 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-06-03T19:10:05.507Z,1748977805.507 [DAT](INFO): DAT read: MF Frequency Band 2025-06-03T19:10:05.508Z,1748977805.508 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-06-03T19:10:05.509Z,1748977805.509 [DAT](INFO): DAT read: Jun 3 2025 19:09:59 2025-06-03T19:10:06.766Z,1748977806.766 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-06-03T19:10:06.767Z,1748977806.767 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-06-03T19:10:06.767Z,1748977806.767 [DAT](INFO): commRate: 1200 2025-06-03T19:10:08.833Z,1748977808.833 [DAT](INFO): entering command mode 2025-06-03T19:10:09.033Z,1748977809.033 [DAT](INFO): DAT read: 2025-06-03T19:10:09.034Z,1748977809.034 [DAT](INFO): DAT read: user:1> 2025-06-03T19:10:09.034Z,1748977809.034 [DAT](INFO): setting verbose to 3 2025-06-03T19:10:09.285Z,1748977809.285 [DAT](INFO): DAT read: user:1> 2025-06-03T19:10:09.286Z,1748977809.286 [DAT](INFO): DAT read: Verbose | 3 2025-06-03T19:10:09.287Z,1748977809.287 [DAT](INFO): set verbose to 3 2025-06-03T19:10:09.287Z,1748977809.287 [DAT](INFO): setting DatVerbose to 27440 2025-06-03T19:10:09.538Z,1748977809.538 [DAT](INFO): DAT read: user:2> 2025-06-03T19:10:09.539Z,1748977809.539 [DAT](INFO): DAT read: DatVerbose | 27440 2025-06-03T19:10:09.539Z,1748977809.539 [DAT](INFO): set DatVerbose to 27440 2025-06-03T19:10:09.539Z,1748977809.539 [DAT](INFO): setting transmit power to 8 2025-06-03T19:10:09.789Z,1748977809.789 [DAT](INFO): DAT read: user:3> 2025-06-03T19:10:09.791Z,1748977809.791 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-06-03T19:10:09.791Z,1748977809.791 [DAT](INFO): set transmit power to 8 2025-06-03T19:10:09.791Z,1748977809.791 [DAT](INFO): setting local address to 5 2025-06-03T19:10:10.041Z,1748977810.041 [DAT](INFO): DAT read: user:4> 2025-06-03T19:10:10.042Z,1748977810.042 [DAT](INFO): DAT read: LocalAddr | 5 2025-06-03T19:10:10.043Z,1748977810.043 [DAT](INFO): set local address to 5 2025-06-03T19:10:10.044Z,1748977810.044 [DAT](INFO): Setting time to: 19:10:10 And date to:6/3/2025 2025-06-03T19:10:10.293Z,1748977810.293 [DAT](INFO): DAT read: user:5> 2025-06-03T19:10:10.294Z,1748977810.294 [DAT](INFO): DAT read: Tue Jun 3, 2025 19:10:10 2025-06-03T19:10:10.295Z,1748977810.295 [DAT](INFO): Local DAT time set to Tue Jun 3, 2025 19:10:10 2025-06-03T19:10:21.074Z,1748977821.074 [NAL9602](INFO): Powering up NAL9602 2025-06-03T19:10:31.967Z,1748977831.967 [NAL9602](INFO): NAL9602 initialized 2025-06-03T19:11:06.309Z,1748977866.309 [NAL9602](INFO): SBD MO Status=2, MOMSN=20944, MT Status=2, MTMSN=0 2025-06-03T19:11:06.309Z,1748977866.309 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T19:11:32.569Z,1748977892.569 [NAL9602](INFO): SBD MO Status=0, MOMSN=20944, MT Status=0, MTMSN=0 2025-06-03T19:11:32.569Z,1748977892.569 [NAL9602](INFO): No messages in MT queue 2025-06-03T19:11:51.959Z,1748977911.959 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-06-03T19:11:52.451Z,1748977912.451 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004770 2025-06-03T19:12:17.033Z,1748977937.033 [SBIT](IMPORTANT): Beginning Startup BIT 2025-06-03T19:12:17.038Z,1748977937.038 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-06-03T19:12:21.921Z,1748977941.921 [GFScanner](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.007832 CHAN A1 (24V): 0.000145 CHAN A2 (12V): -0.005631 CHAN A3 (5V): -0.002849 CHAN B0 (3.3V): -0.001122 CHAN B1 (3.15aV): -0.001017 CHAN B2 (3.15bV): -0.001170 CHAN B3 (GND): -0.000100 OPEN: 0.006865 Full Scale: +/- 1 mA 2025-06-03T19:12:27.250Z,1748977947.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191223.00,A,3648.15024,N,12147.22786,W,0.058,1.84,030625,,,A*77 2025-06-03T19:12:27.253Z,1748977947.253 [NAL9602](INFO): GPS fix at 20250603T191223: (36.802504, -121.787131) 2025-06-03T19:12:59.605Z,1748977979.605 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T19:13:10.928Z,1748977990.928 [SBIT](IMPORTANT): SBIT PASSED 2025-06-03T19:13:10.929Z,1748977990.929 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-06-03T19:13:10.929Z,1748977990.929 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count; 2025-06-03T19:13:10.930Z,1748977990.930 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=1 bool; 2025-06-03T19:13:10.930Z,1748977990.930 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2025-06-03T19:13:10.930Z,1748977990.930 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere; 2025-06-03T19:13:10.930Z,1748977990.930 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=245.649598 cubic_centimeter; 2025-06-03T19:13:10.930Z,1748977990.930 [SBIT](IMPORTANT): VerticalControl.massDefault=31.276186 millimeter; 2025-06-03T19:13:11.335Z,1748977991.335 [MissionManager](IMPORTANT): Started mission Startup 2025-06-03T19:13:11.336Z,1748977991.336 [Startup] Running Loop=1 2025-06-03T19:13:11.336Z,1748977991.336 [Startup](DEBUG): Aggregate::initialize Startup 2025-06-03T19:13:11.336Z,1748977991.336 [Startup:A.GoToSurface] Running Loop=1 2025-06-03T19:13:11.336Z,1748977991.336 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-06-03T19:13:11.337Z,1748977991.337 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-06-03T19:13:11.337Z,1748977991.337 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-06-03T19:13:11.337Z,1748977991.337 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-06-03T19:13:11.338Z,1748977991.338 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-06-03T19:13:11.338Z,1748977991.338 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-06-03T19:13:11.339Z,1748977991.339 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-06-03T19:13:11.342Z,1748977991.342 [Startup:StartupSatComms] Running Loop=1 2025-06-03T19:13:11.342Z,1748977991.342 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-06-03T19:13:11.342Z,1748977991.342 [Startup:StartupSatComms:A] Running Loop=1 2025-06-03T19:13:11.746Z,1748977991.746 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-06-03T19:13:13.478Z,1748977993.478 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191309.00,A,3648.15067,N,12147.22688,W,0.058,1.84,030625,,,A*76 2025-06-03T19:13:13.480Z,1748977993.480 [NAL9602](INFO): GPS fix at 20250603T191309: (36.802511, -121.787115) 2025-06-03T19:13:13.491Z,1748977993.491 [Startup:StartupSatComms:A] Stopped 2025-06-03T19:13:13.491Z,1748977993.491 [Startup:StartupSatComms:B] Running Loop=1 2025-06-03T19:13:13.806Z,1748977993.806 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-06-03T19:13:21.152Z,1748978001.152 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250603T185326/Courier0010.lzma 2025-06-03T19:13:22.155Z,1748978002.155 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Courier0010.lzma.bak 2025-06-03T19:13:22.155Z,1748978002.155 [DataOverHttps](INFO): SBD MOMSN=25086016 2025-06-03T19:13:25.095Z,1748978005.095 [NAL9602](INFO): SBD MO Status=0, MOMSN=20945, MT Status=0, MTMSN=0 2025-06-03T19:13:25.095Z,1748978005.095 [NAL9602](INFO): No messages in MT queue 2025-06-03T19:13:39.053Z,1748978019.053 [DataOverHttps](INFO): Sending 271 bytes from file Logs/20250603T190938/Courier0000.lzma 2025-06-03T19:13:40.054Z,1748978020.054 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Courier0000.lzma.bak 2025-06-03T19:13:40.055Z,1748978020.055 [DataOverHttps](INFO): SBD MOMSN=25086019 2025-06-03T19:13:55.790Z,1748978035.790 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T19:13:56.464Z,1748978036.464 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250603T185326/Express0012.lzma 2025-06-03T19:13:57.467Z,1748978037.467 [DataOverHttps](INFO): Moved sent file to Logs/20250603T185326/Express0012.lzma.bak 2025-06-03T19:13:57.467Z,1748978037.467 [DataOverHttps](INFO): SBD MOMSN=25086023 2025-06-03T19:14:13.507Z,1748978053.507 [DataOverHttps](INFO): Sending 1117 bytes from file Logs/20250603T190938/Express0001.lzma 2025-06-03T19:14:13.739Z,1748978053.739 [Startup:StartupSatComms:B](INFO): Timed out from 2025-06-03T19:13:13.5Z 2025-06-03T19:14:13.739Z,1748978053.739 [Startup:StartupSatComms:B] Stopped 2025-06-03T19:14:13.740Z,1748978053.740 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-06-03T19:14:13.740Z,1748978053.740 [Startup:StartupSatComms] Stopped 2025-06-03T19:14:13.740Z,1748978053.740 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-06-03T19:14:13.755Z,1748978053.755 [Startup](INFO): Completed Startup 2025-06-03T19:14:13.756Z,1748978053.756 [MissionManager](INFO): Startup is completed. 2025-06-03T19:14:13.774Z,1748978053.774 [MissionManager](INFO): Uninitializing Mission Startup 2025-06-03T19:14:13.774Z,1748978053.774 [Startup] Stopped 2025-06-03T19:14:13.774Z,1748978053.774 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-06-03T19:14:13.774Z,1748978053.774 [Startup:A.GoToSurface] Stopped 2025-06-03T19:14:13.774Z,1748978053.774 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-06-03T19:14:13.979Z,1748978053.979 [MissionManager](IMPORTANT): Started mission Default 2025-06-03T19:14:13.980Z,1748978053.980 [Default] Running Loop=1 2025-06-03T19:14:13.980Z,1748978053.980 [Default](DEBUG): Aggregate::initialize Default 2025-06-03T19:14:13.980Z,1748978053.980 [Default:B.GoToSurface] Running Loop=1 2025-06-03T19:14:13.980Z,1748978053.980 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-06-03T19:14:13.980Z,1748978053.980 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-06-03T19:14:13.981Z,1748978053.981 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-06-03T19:14:13.981Z,1748978053.981 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-06-03T19:14:13.981Z,1748978053.981 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-06-03T19:14:13.982Z,1748978053.982 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-06-03T19:14:13.982Z,1748978053.982 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-06-03T19:14:13.982Z,1748978053.982 [Default:A.Wait] Running Loop=1 2025-06-03T19:14:13.982Z,1748978053.982 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-06-03T19:14:14.506Z,1748978054.506 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Express0001.lzma.bak 2025-06-03T19:14:14.507Z,1748978054.507 [DataOverHttps](INFO): SBD MOMSN=25086026 2025-06-03T19:14:27.311Z,1748978067.311 [Default:A.Wait](INFO): Done Waiting. 2025-06-03T19:14:27.311Z,1748978067.311 [Default:A.Wait] Stopped 2025-06-03T19:14:27.311Z,1748978067.311 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T19:14:27.719Z,1748978067.719 [Default:CheckIn] Running Loop=1 2025-06-03T19:14:27.719Z,1748978067.719 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-03T19:14:27.719Z,1748978067.719 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-03T19:14:28.121Z,1748978068.121 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-06-03T19:14:29.735Z,1748978069.735 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191428.00,A,3648.15038,N,12147.22683,W,0.039,1.84,030625,,,A*74 2025-06-03T19:14:29.737Z,1748978069.737 [NAL9602](INFO): GPS fix at 20250603T191428: (36.802506, -121.787114) 2025-06-03T19:14:29.747Z,1748978069.747 [Default:CheckIn:Read_GPS] Stopped 2025-06-03T19:14:29.747Z,1748978069.747 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-03T19:14:30.165Z,1748978070.165 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-06-03T19:14:39.236Z,1748978079.236 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250603T190938/Courier0004.lzma 2025-06-03T19:14:40.239Z,1748978080.239 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Courier0004.lzma.bak 2025-06-03T19:14:40.239Z,1748978080.239 [DataOverHttps](INFO): SBD MOMSN=25086046 2025-06-03T19:14:50.755Z,1748978090.755 [NAL9602](INFO): SBD MO Status=0, MOMSN=20946, MT Status=0, MTMSN=0 2025-06-03T19:14:50.756Z,1748978090.756 [NAL9602](INFO): No messages in MT queue 2025-06-03T19:14:56.445Z,1748978096.445 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20250603T190938/Express0005.lzma 2025-06-03T19:14:57.446Z,1748978097.446 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Express0005.lzma.bak 2025-06-03T19:14:57.447Z,1748978097.447 [DataOverHttps](INFO): SBD MOMSN=25086049 2025-06-03T19:14:58.858Z,1748978098.858 [Default:CheckIn:Read_Iridium] Stopped 2025-06-03T19:14:58.858Z,1748978098.858 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-03T19:14:58.858Z,1748978098.858 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-03T19:15:21.457Z,1748978121.457 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T19:16:20.917Z,1748978180.917 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-06-03T19:16:20.918Z,1748978180.918 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-06-03T19:16:20.922Z,1748978180.922 [BPC1](INFO): Received data from all battery sticks. 2025-06-03T19:19:59.439Z,1748978399.439 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-03T19:19:59.439Z,1748978399.439 [Default:CheckIn:C.Wait] Stopped 2025-06-03T19:19:59.439Z,1748978399.439 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T19:19:59.439Z,1748978399.439 [Default:CheckIn:D] Running Loop=1 2025-06-03T19:19:59.847Z,1748978399.847 [Default:CheckIn:D] Stopped 2025-06-03T19:19:59.847Z,1748978399.847 [Default:CheckIn:E] Running Loop=1 2025-06-03T19:20:00.257Z,1748978400.257 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.764461 min 2025-06-03T19:20:00.257Z,1748978400.257 [Default:CheckIn:E] Stopped 2025-06-03T19:20:00.257Z,1748978400.257 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-03T19:20:00.257Z,1748978400.257 [Default:CheckIn] Stopped 2025-06-03T19:20:00.257Z,1748978400.257 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-03T19:20:00.257Z,1748978400.257 [Default:CheckIn](INFO): Running loop #2 2025-06-03T19:20:00.258Z,1748978400.258 [Default:CheckIn] Running Loop=2 2025-06-03T19:20:00.258Z,1748978400.258 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-03T19:20:00.258Z,1748978400.258 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-03T19:20:02.262Z,1748978402.262 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192001.00,A,3648.14879,N,12147.22637,W,0.039,1.84,030625,,,D*7E 2025-06-03T19:20:02.264Z,1748978402.264 [NAL9602](INFO): GPS fix at 20250603T192001: (36.802480, -121.787106) 2025-06-03T19:20:02.286Z,1748978402.286 [Default:CheckIn:Read_GPS] Stopped 2025-06-03T19:20:02.286Z,1748978402.286 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-03T19:20:10.017Z,1748978410.017 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20250603T190938/Courier0007.lzma 2025-06-03T19:20:11.018Z,1748978411.018 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Courier0007.lzma.bak 2025-06-03T19:20:11.019Z,1748978411.019 [DataOverHttps](INFO): SBD MOMSN=25086114 2025-06-03T19:20:26.857Z,1748978426.857 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20250603T190938/Express0008.lzma 2025-06-03T19:20:27.858Z,1748978427.858 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Express0008.lzma.bak 2025-06-03T19:20:27.859Z,1748978427.859 [DataOverHttps](INFO): SBD MOMSN=25086117 2025-06-03T19:20:29.336Z,1748978429.336 [Default:CheckIn:Read_Iridium] Stopped 2025-06-03T19:20:29.336Z,1748978429.336 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-03T19:20:29.336Z,1748978429.336 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-03T19:20:36.629Z,1748978436.629 [NAL9602](INFO): SBD MO Status=2, MOMSN=20947, MT Status=2, MTMSN=0 2025-06-03T19:20:36.629Z,1748978436.629 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T19:21:11.773Z,1748978471.773 [NAL9602](INFO): SBD MO Status=2, MOMSN=20947, MT Status=2, MTMSN=0 2025-06-03T19:21:11.774Z,1748978471.774 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T19:21:27.551Z,1748978487.551 [NAL9602](INFO): SBD MO Status=0, MOMSN=20947, MT Status=0, MTMSN=0 2025-06-03T19:21:27.551Z,1748978487.551 [NAL9602](INFO): No messages in MT queue 2025-06-03T19:21:58.244Z,1748978518.244 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T19:25:29.956Z,1748978729.956 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-03T19:25:29.956Z,1748978729.956 [Default:CheckIn:C.Wait] Stopped 2025-06-03T19:25:29.956Z,1748978729.956 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T19:25:29.957Z,1748978729.957 [Default:CheckIn:D] Running Loop=1 2025-06-03T19:25:30.365Z,1748978730.365 [Default:CheckIn:D] Stopped 2025-06-03T19:25:30.365Z,1748978730.365 [Default:CheckIn:E] Running Loop=1 2025-06-03T19:25:30.763Z,1748978730.763 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.273078 min 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn:E] Stopped 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn] Stopped 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn](INFO): Running loop #3 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn] Running Loop=3 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-03T19:25:30.764Z,1748978730.764 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-03T19:25:32.770Z,1748978732.770 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192531.00,A,3648.17497,N,12147.27863,W,0.330,296.85,030625,,,D*7A 2025-06-03T19:25:32.772Z,1748978732.772 [NAL9602](INFO): GPS fix at 20250603T192531: (36.802916, -121.787977) 2025-06-03T19:25:32.796Z,1748978732.796 [Default:CheckIn:Read_GPS] Stopped 2025-06-03T19:25:32.796Z,1748978732.796 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-03T19:25:34.500Z,1748978734.500 [NAL9602](FAULT): LCB fault: Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated. 2025-06-03T19:25:34.500Z,1748978734.500 [NAL9602] Hardware Fault, FailCount= 1 2025-06-03T19:25:34.501Z,1748978734.501 [NAL9602](ERROR): Hardware Fault 2025-06-03T19:25:34.594Z,1748978734.594 [CBIT](ERROR): Hardware Fault in component: NAL9602 2025-06-03T19:25:34.907Z,1748978734.907 [NAL9602](INFO): Powering down 2025-06-03T19:25:35.770Z,1748978735.770 [CBIT](INFO): Clearing failed state for component NAL9602 2025-06-03T19:25:35.770Z,1748978735.770 [NAL9602] No Fault, FailCount= 1 2025-06-03T19:25:40.188Z,1748978740.188 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250603T190938/Courier0010.lzma 2025-06-03T19:25:41.190Z,1748978741.190 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Courier0010.lzma.bak 2025-06-03T19:25:41.191Z,1748978741.191 [DataOverHttps](INFO): SBD MOMSN=25086134 2025-06-03T19:25:58.917Z,1748978758.917 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20250603T190938/Express0011.lzma 2025-06-03T19:25:59.918Z,1748978759.918 [DataOverHttps](INFO): Moved sent file to Logs/20250603T190938/Express0011.lzma.bak 2025-06-03T19:25:59.919Z,1748978759.919 [DataOverHttps](INFO): SBD MOMSN=25086137 2025-06-03T19:26:01.191Z,1748978761.191 [Default:CheckIn:Read_Iridium] Stopped 2025-06-03T19:26:01.191Z,1748978761.191 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-03T19:26:01.191Z,1748978761.191 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-03T19:26:05.223Z,1748978765.223 [NAL9602](INFO): Powering up NAL9602 2025-06-03T19:26:16.129Z,1748978776.129 [NAL9602](INFO): NAL9602 initialized 2025-06-03T19:26:47.233Z,1748978807.233 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T19:31:01.792Z,1748979061.792 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-03T19:31:01.792Z,1748979061.792 [Default:CheckIn:C.Wait] Stopped 2025-06-03T19:31:01.792Z,1748979061.792 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T19:31:01.792Z,1748979061.792 [Default:CheckIn:D] Running Loop=1 2025-06-03T19:31:02.210Z,1748979062.210 [Default:CheckIn:D] Stopped 2025-06-03T19:31:02.210Z,1748979062.210 [Default:CheckIn:E] Running Loop=1 2025-06-03T19:31:02.594Z,1748979062.594 [Default:CheckIn:E](IMPO