2025-06-03T18:34:13.827Z,1748975653.827 [Supervisor](DEBUG): Initializing supervisor. 2025-06-03T18:34:13.831Z,1748975653.831 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-06-03T18:34:13.831Z,1748975653.831 [SyncHandler](INFO): Protected caller Thread ID is 829 2025-06-03T18:34:13.832Z,1748975653.832 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-06-03T18:34:13.833Z,1748975653.833 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-06-03T18:34:13.833Z,1748975653.833 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 830 2025-06-03T18:34:13.838Z,1748975653.838 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-06-03T18:34:13.858Z,1748975653.858 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-06-03T18:34:13.859Z,1748975653.859 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-06-03T18:34:13.860Z,1748975653.860 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 831 2025-06-03T18:34:13.864Z,1748975653.864 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-06-03T18:34:13.865Z,1748975653.865 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-06-03T18:34:13.865Z,1748975653.865 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 832 2025-06-03T18:34:13.868Z,1748975653.868 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-06-03T18:34:13.869Z,1748975653.869 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-06-03T18:34:13.869Z,1748975653.869 [logger ThreadHandler](INFO): Protected caller Thread ID is 833 2025-06-03T18:34:13.873Z,1748975653.873 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-06-03T18:34:13.873Z,1748975653.873 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-06-03T18:34:13.879Z,1748975653.879 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-06-03T18:34:13.985Z,1748975653.985 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-06-03T18:34:13.987Z,1748975653.987 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-06-03T18:34:14.225Z,1748975654.225 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-06-03T18:34:14.227Z,1748975654.227 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-06-03T18:34:14.513Z,1748975654.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-06-03T18:34:14.515Z,1748975654.515 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-06-03T18:34:14.632Z,1748975654.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-06-03T18:34:14.635Z,1748975654.635 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-06-03T18:34:15.422Z,1748975655.422 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-06-03T18:34:15.422Z,1748975655.422 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-06-03T18:34:15.958Z,1748975655.958 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-06-03T18:34:15.959Z,1748975655.959 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-06-03T18:34:16.532Z,1748975656.532 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-06-03T18:34:16.532Z,1748975656.532 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-06-03T18:34:16.982Z,1748975656.982 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-06-03T18:34:17.240Z,1748975657.240 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-06-03T18:34:17.845Z,1748975657.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-06-03T18:34:17.846Z,1748975657.846 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-06-03T18:34:18.244Z,1748975658.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-06-03T18:34:18.245Z,1748975658.245 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-06-03T18:34:18.485Z,1748975658.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-06-03T18:34:18.487Z,1748975658.487 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-06-03T18:34:18.640Z,1748975658.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-06-03T18:34:18.642Z,1748975658.642 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-06-03T18:34:18.745Z,1748975658.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance 2025-06-03T18:34:18.746Z,1748975658.746 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-06-03T18:34:18.837Z,1748975658.837 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-06-03T18:34:19.040Z,1748975659.040 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-06-03T18:34:19.040Z,1748975659.040 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-06-03T18:34:19.304Z,1748975659.304 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-06-03T18:34:19.306Z,1748975659.306 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2025-06-03T18:34:19.310Z,1748975659.310 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2025-06-03T18:34:19.403Z,1748975659.403 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2025-06-03T18:34:19.683Z,1748975659.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-06-03T18:34:19.684Z,1748975659.684 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2025-06-03T18:34:19.779Z,1748975659.779 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2025-06-03T18:34:19.965Z,1748975659.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2025-06-03T18:34:20.077Z,1748975660.077 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2025-06-03T18:34:20.201Z,1748975660.201 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2025-06-03T18:34:20.326Z,1748975660.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2025-06-03T18:34:20.431Z,1748975660.431 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2025-06-03T18:34:20.608Z,1748975660.608 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2025-06-03T18:34:20.717Z,1748975660.717 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg 2025-06-03T18:34:20.814Z,1748975660.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2025-06-03T18:34:20.924Z,1748975660.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2025-06-03T18:34:21.023Z,1748975661.023 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-06-03T18:34:21.027Z,1748975661.027 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-06-03T18:34:21.258Z,1748975661.258 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-06-03T18:34:21.259Z,1748975661.259 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-06-03T18:34:21.459Z,1748975661.459 [BuoyancyServo] Loaded 2025-06-03T18:34:21.459Z,1748975661.459 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-06-03T18:34:21.483Z,1748975661.483 [ElevatorServo] Loaded 2025-06-03T18:34:21.483Z,1748975661.483 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-06-03T18:34:21.506Z,1748975661.506 [MassServo] Loaded 2025-06-03T18:34:21.507Z,1748975661.507 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-06-03T18:34:21.529Z,1748975661.529 [RudderServo] Loaded 2025-06-03T18:34:21.530Z,1748975661.530 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-06-03T18:34:21.548Z,1748975661.548 [ThrusterHE] Loaded 2025-06-03T18:34:21.548Z,1748975661.548 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-06-03T18:34:21.549Z,1748975661.549 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-06-03T18:34:21.551Z,1748975661.551 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-06-03T18:34:21.760Z,1748975661.760 [SBIT](DEBUG): Construct Startup Built In Test. 2025-06-03T18:34:21.775Z,1748975661.775 [SBIT] Loaded 2025-06-03T18:34:21.776Z,1748975661.776 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-06-03T18:34:21.778Z,1748975661.778 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-06-03T18:34:21.800Z,1748975661.800 [IBIT] Loaded 2025-06-03T18:34:21.800Z,1748975661.800 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-06-03T18:34:21.806Z,1748975661.806 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-06-03T18:34:22.004Z,1748975662.004 [CBIT] Loaded 2025-06-03T18:34:22.004Z,1748975662.004 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-06-03T18:34:22.036Z,1748975662.036 [GFScanner] Loaded 2025-06-03T18:34:22.036Z,1748975662.036 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-06-03T18:34:22.036Z,1748975662.036 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-06-03T18:34:22.037Z,1748975662.037 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-06-03T18:34:22.851Z,1748975662.851 [CTD_Seabird] Loaded 2025-06-03T18:34:22.851Z,1748975662.851 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-06-03T18:34:22.852Z,1748975662.852 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406864E0 2025-06-03T18:34:22.852Z,1748975662.852 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 921 2025-06-03T18:34:22.888Z,1748975662.888 [ESPComponent] Loaded 2025-06-03T18:34:22.888Z,1748975662.888 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2025-06-03T18:34:22.911Z,1748975662.911 [PAR_Licor] Loaded 2025-06-03T18:34:22.911Z,1748975662.911 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-06-03T18:34:22.957Z,1748975662.957 [WetLabsBB2FL] Loaded 2025-06-03T18:34:22.958Z,1748975662.958 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-06-03T18:34:22.959Z,1748975662.959 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0 2025-06-03T18:34:22.959Z,1748975662.959 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 922 2025-06-03T18:34:22.960Z,1748975662.960 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-06-03T18:34:22.960Z,1748975662.960 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-06-03T18:34:23.035Z,1748975663.035 [DepthRateCalculator] Loaded 2025-06-03T18:34:23.035Z,1748975663.035 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-06-03T18:34:23.040Z,1748975663.040 [PitchRateCalculator] Loaded 2025-06-03T18:34:23.041Z,1748975663.041 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-06-03T18:34:23.052Z,1748975663.052 [SpeedCalculator] Loaded 2025-06-03T18:34:23.052Z,1748975663.052 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-06-03T18:34:23.057Z,1748975663.057 [YawRateCalculator] Loaded 2025-06-03T18:34:23.057Z,1748975663.057 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-06-03T18:34:23.077Z,1748975663.077 [ElevatorOffsetCalculator] Loaded 2025-06-03T18:34:23.077Z,1748975663.077 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-06-03T18:34:23.078Z,1748975663.078 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-06-03T18:34:23.079Z,1748975663.079 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-06-03T18:34:23.253Z,1748975663.253 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-06-03T18:34:23.254Z,1748975663.254 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-06-03T18:34:23.303Z,1748975663.303 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-06-03T18:34:23.304Z,1748975663.304 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-06-03T18:34:23.447Z,1748975663.447 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-06-03T18:34:23.448Z,1748975663.448 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-06-03T18:34:23.462Z,1748975663.462 [NavChart] Loaded 2025-06-03T18:34:23.462Z,1748975663.462 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-06-03T18:34:23.468Z,1748975663.468 [UniversalFixResidualReporter] Loaded 2025-06-03T18:34:23.468Z,1748975663.468 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-06-03T18:34:23.469Z,1748975663.469 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-06-03T18:34:23.470Z,1748975663.470 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-06-03T18:34:24.374Z,1748975664.374 [AHRS_M2] Loaded 2025-06-03T18:34:24.375Z,1748975664.375 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-06-03T18:34:24.628Z,1748975664.628 [BackseatComponent] Loaded 2025-06-03T18:34:24.628Z,1748975664.628 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-06-03T18:34:24.629Z,1748975664.629 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A824E0 2025-06-03T18:34:24.630Z,1748975664.630 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923 2025-06-03T18:34:24.633Z,1748975664.633 [LcmUniversalReporter] Loaded 2025-06-03T18:34:24.633Z,1748975664.633 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-06-03T18:34:25.385Z,1748975665.385 [BPC1] Loaded 2025-06-03T18:34:25.386Z,1748975665.386 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-06-03T18:34:25.488Z,1748975665.488 [DAT] Loaded 2025-06-03T18:34:25.488Z,1748975665.488 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2025-06-03T18:34:25.489Z,1748975665.489 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB24E0 2025-06-03T18:34:25.490Z,1748975665.490 [DAT ThreadHandler](INFO): Protected caller Thread ID is 924 2025-06-03T18:34:25.634Z,1748975665.634 [DataOverHttps] Loaded 2025-06-03T18:34:25.634Z,1748975665.634 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-06-03T18:34:25.635Z,1748975665.635 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE24E0 2025-06-03T18:34:25.635Z,1748975665.635 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925 2025-06-03T18:34:25.659Z,1748975665.659 [Depth_Keller] Loaded 2025-06-03T18:34:25.660Z,1748975665.660 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-06-03T18:34:25.665Z,1748975665.665 [DropWeight] Loaded 2025-06-03T18:34:25.665Z,1748975665.665 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-06-03T18:34:25.708Z,1748975665.708 [DVL_micro] Loaded 2025-06-03T18:34:25.708Z,1748975665.708 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2025-06-03T18:34:25.772Z,1748975665.772 [NAL9602] Loaded 2025-06-03T18:34:25.773Z,1748975665.773 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-06-03T18:34:25.799Z,1748975665.799 [Onboard] Loaded 2025-06-03T18:34:25.800Z,1748975665.800 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-06-03T18:34:25.801Z,1748975665.801 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B124E0 2025-06-03T18:34:25.801Z,1748975665.801 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926 2025-06-03T18:34:25.807Z,1748975665.807 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1 2025-06-03T18:34:25.822Z,1748975665.822 [PowerOnly] Loaded 2025-06-03T18:34:25.822Z,1748975665.822 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2025-06-03T18:34:25.836Z,1748975665.836 [Power24vConverter] Loaded 2025-06-03T18:34:25.836Z,1748975665.836 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-06-03T18:34:25.854Z,1748975665.854 [Radio_Surface] Loaded 2025-06-03T18:34:25.854Z,1748975665.854 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-06-03T18:34:25.855Z,1748975665.855 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B424E0 2025-06-03T18:34:25.855Z,1748975665.855 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927 2025-06-03T18:34:25.871Z,1748975665.871 [Sonardyne_Nano] Loaded 2025-06-03T18:34:25.872Z,1748975665.872 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2025-06-03T18:34:25.872Z,1748975665.872 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-06-03T18:34:25.873Z,1748975665.873 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-06-03T18:34:25.963Z,1748975665.963 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-06-03T18:34:25.963Z,1748975665.963 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-06-03T18:34:26.039Z,1748975666.039 [VerticalControl](DEBUG): Construct VerticalControl. 2025-06-03T18:34:26.093Z,1748975666.093 [VerticalControl] Loaded 2025-06-03T18:34:26.094Z,1748975666.094 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-06-03T18:34:26.097Z,1748975666.097 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-06-03T18:34:26.143Z,1748975666.143 [HorizontalControl] Loaded 2025-06-03T18:34:26.143Z,1748975666.143 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-06-03T18:34:26.146Z,1748975666.146 [SpeedControl](DEBUG): Construct SpeedControl. 2025-06-03T18:34:26.147Z,1748975666.147 [SpeedControl] Loaded 2025-06-03T18:34:26.148Z,1748975666.148 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-06-03T18:34:26.151Z,1748975666.151 [LoopControl](DEBUG): Construct LoopControl. 2025-06-03T18:34:26.151Z,1748975666.151 [LoopControl] Loaded 2025-06-03T18:34:26.151Z,1748975666.151 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-06-03T18:34:26.152Z,1748975666.152 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-06-03T18:34:26.152Z,1748975666.152 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-06-03T18:34:26.169Z,1748975666.169 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-06-03T18:34:26.169Z,1748975666.169 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-06-03T18:34:26.601Z,1748975666.601 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-06-03T18:34:26.607Z,1748975666.607 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-06-03T18:34:26.610Z,1748975666.610 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-06-03T18:34:26.622Z,1748975666.622 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-06-03T18:34:26.623Z,1748975666.623 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C684E0 2025-06-03T18:34:26.623Z,1748975666.623 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928 2025-06-03T18:34:26.628Z,1748975666.628 [Supervisor](INFO): Main Thread ID is 822 2025-06-03T18:34:26.628Z,1748975666.628 [Supervisor](DEBUG): Running supervisor. 2025-06-03T18:34:26.629Z,1748975666.629 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929 2025-06-03T18:34:26.629Z,1748975666.629 [CommandExec](INFO): Initializing the command executive. 2025-06-03T18:34:26.631Z,1748975666.631 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930 2025-06-03T18:34:26.633Z,1748975666.633 [controlThread ThreadHandler](INFO): Handler Thread ID is 931 2025-06-03T18:34:26.634Z,1748975666.634 [controlThread](DEBUG): Initializing ControlThread 2025-06-03T18:34:26.635Z,1748975666.635 [SBIT](INFO): Initialize SBIT Component. 2025-06-03T18:34:26.636Z,1748975666.636 [SBIT](IMPORTANT): git: 2025-05-29 2025-06-03T18:34:26.636Z,1748975666.636 [SBIT](INFO): git hash: c78c975c7bb2a66b27244d2837f68dff299fa024 2025-06-03T18:34:26.636Z,1748975666.636 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-06-03T18:34:26.638Z,1748975666.638 [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-03T18:34:26.639Z,1748975666.639 [SBIT](INFO): Beginning SBIT in 107.000000 seconds. 2025-06-03T18:34:26.639Z,1748975666.639 [IBIT](INFO): Initialize IBIT Component. 2025-06-03T18:34:26.640Z,1748975666.640 [CBIT](DEBUG): Initialize CBIT Component. 2025-06-03T18:34:26.641Z,1748975666.641 [logger ThreadHandler](INFO): Handler Thread ID is 932 2025-06-03T18:34:26.653Z,1748975666.653 [CBIT](DEBUG): Initialized mux pins. 2025-06-03T18:34:26.653Z,1748975666.653 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2025-06-03T18:34:26.653Z,1748975666.653 [CBIT](DEBUG): Initializing the watchdog timer. 2025-06-03T18:34:26.661Z,1748975666.661 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 933 2025-06-03T18:34:26.662Z,1748975666.662 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-06-03T18:34:26.667Z,1748975666.667 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935 2025-06-03T18:34:26.669Z,1748975666.669 [WetLabsBB2FL](INFO): Powering up 2025-06-03T18:34:26.671Z,1748975666.671 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2025-06-03T18:34:26.677Z,1748975666.677 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2025-06-03T18:34:26.677Z,1748975666.677 [CBIT](DEBUG): Initializing heartbeat. 2025-06-03T18:34:26.679Z,1748975666.679 [DAT ThreadHandler](INFO): Handler Thread ID is 938 2025-06-03T18:34:26.679Z,1748975666.679 [DAT](INFO): Powering up 2025-06-03T18:34:26.679Z,1748975666.679 [DAT](DEBUG): Initializing DAT. 2025-06-03T18:34:26.682Z,1748975666.682 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 940 2025-06-03T18:34:26.684Z,1748975666.684 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-06-03T18:34:26.705Z,1748975666.705 [Onboard ThreadHandler](INFO): Handler Thread ID is 941 2025-06-03T18:34:26.723Z,1748975666.723 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 942 2025-06-03T18:34:26.744Z,1748975666.744 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2025-06-03T18:34:26.749Z,1748975666.749 [CBIT](DEBUG): Deactivating emergency mode. 2025-06-03T18:34:26.754Z,1748975666.754 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-06-03T18:34:26.754Z,1748975666.754 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-06-03T18:34:26.754Z,1748975666.754 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-06-03T18:34:26.754Z,1748975666.754 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-06-03T18:34:26.755Z,1748975666.755 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-06-03T18:34:26.755Z,1748975666.755 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-06-03T18:34:26.755Z,1748975666.755 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-06-03T18:34:26.755Z,1748975666.755 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-06-03T18:34:26.789Z,1748975666.789 [CBIT](DEBUG): Backplane powered. 2025-06-03T18:34:26.789Z,1748975666.789 [GFScanner](DEBUG): Initializing GFScanner 2025-06-03T18:34:26.789Z,1748975666.789 [GFScanner](DEBUG): Deactivating GF circuits. 2025-06-03T18:34:26.795Z,1748975666.795 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-06-03T18:34:26.795Z,1748975666.795 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-06-03T18:34:26.795Z,1748975666.795 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-06-03T18:34:26.796Z,1748975666.796 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-06-03T18:34:26.796Z,1748975666.796 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-06-03T18:34:26.798Z,1748975666.798 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-06-03T18:34:26.798Z,1748975666.798 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-06-03T18:34:26.818Z,1748975666.818 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-06-03T18:34:26.820Z,1748975666.820 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-06-03T18:34:26.821Z,1748975666.821 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-06-03T18:34:26.829Z,1748975666.829 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-06-03T18:34:26.830Z,1748975666.830 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-06-03T18:34:26.831Z,1748975666.831 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-06-03T18:34:26.831Z,1748975666.831 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-06-03T18:34:26.840Z,1748975666.840 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-06-03T18:34:26.917Z,1748975666.917 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-06-03T18:34:26.935Z,1748975666.935 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-06-03T18:34:26.961Z,1748975666.961 [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-03T18:34:26.982Z,1748975666.982 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-06-03T18:34:26.982Z,1748975666.982 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-06-03T18:34:26.984Z,1748975666.984 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-06-03T18:34:27.129Z,1748975667.129 [Radio_Surface](INFO): Powering up 2025-06-03T18:34:27.307Z,1748975667.307 [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-03T18:34:27.329Z,1748975667.329 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-06-03T18:34:27.330Z,1748975667.330 [Default:A.Wait](DEBUG): Construct Wait. 2025-06-03T18:34:27.333Z,1748975667.333 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-06-03T18:34:27.367Z,1748975667.367 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-06-03T18:34:27.394Z,1748975667.394 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-06-03T18:34:27.399Z,1748975667.399 [Default:E.Execute](DEBUG): Construct Execute. 2025-06-03T18:34:27.419Z,1748975667.419 [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-03T18:34:27.424Z,1748975667.424 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,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-03T18:34:27.457Z,1748975667.457 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-06-03T18:34:27.566Z,1748975667.566 [Depth_Keller](INFO): Initializing. 2025-06-03T18:34:27.575Z,1748975667.575 [PowerOnly](INFO): Powering up loadControl 2025-06-03T18:34:27.594Z,1748975667.594 [Power24vConverter](INFO): Powering up. 2025-06-03T18:34:27.594Z,1748975667.594 [Sonardyne_Nano](INFO): Initializing. 2025-06-03T18:34:27.621Z,1748975667.621 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-06-03T18:34:27.687Z,1748975667.687 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:34:27.693Z,1748975667.693 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-06-03T18:34:27.694Z,1748975667.694 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:34:27.701Z,1748975667.701 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-06-03T18:34:27.702Z,1748975667.702 [MassServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:34:27.709Z,1748975667.709 [MassServo](DEBUG): Initializing MassServo. 2025-06-03T18:34:27.710Z,1748975667.710 [RudderServo](DEBUG): Initializing EZServoServo. 2025-06-03T18:34:27.717Z,1748975667.717 [RudderServo](DEBUG): Initializing RudderServo. 2025-06-03T18:34:27.718Z,1748975667.718 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-06-03T18:34:27.725Z,1748975667.725 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-06-03T18:34:27.727Z,1748975667.727 [CommandExec](FAULT): Scheduling is paused 2025-06-03T18:34:27.728Z,1748975667.728 [CBIT](INFO): Critical error at 20250603T183426 2025-06-03T18:34:27.728Z,1748975667.728 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-06-03T18:34:27.890Z,1748975667.890 [Depth_Keller](ERROR): Pressure or depth reading out of range: 947.322021 decibar, 0.000000 m 2025-06-03T18:34:27.901Z,1748975667.901 [DepthRateCalculator](ERROR): Depth measurement is not active 2025-06-03T18:34:29.281Z,1748975669.281 [WetLabsBB2FL](INFO): Powering down 2025-06-03T18:34:29.864Z,1748975669.864 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2025-06-03T18:34:31.098Z,1748975671.098 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213 2025-06-03T18:34:33.342Z,1748975673.342 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-06-03T18:34:38.778Z,1748975678.778 [DAT](INFO): DAT read: 2025-06-03T18:34:38.779Z,1748975678.779 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-06-03T18:34:40.543Z,1748975680.543 [DAT](INFO): DAT read: MF Frequency Band 2025-06-03T18:34:40.544Z,1748975680.544 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-06-03T18:34:40.545Z,1748975680.545 [DAT](INFO): DAT read: Jun 3 2025 18:34:34 2025-06-03T18:34:41.802Z,1748975681.802 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-06-03T18:34:41.803Z,1748975681.803 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2025-06-03T18:34:41.804Z,1748975681.804 [DAT](INFO): commRate: 1200 2025-06-03T18:34:43.869Z,1748975683.869 [DAT](INFO): entering command mode 2025-06-03T18:34:44.070Z,1748975684.070 [DAT](INFO): DAT read: 2025-06-03T18:34:44.070Z,1748975684.070 [DAT](INFO): DAT read: user:1> 2025-06-03T18:34:44.071Z,1748975684.071 [DAT](INFO): setting verbose to 3 2025-06-03T18:34:44.322Z,1748975684.322 [DAT](INFO): DAT read: user:1> 2025-06-03T18:34:44.323Z,1748975684.323 [DAT](INFO): DAT read: Verbose | 3 2025-06-03T18:34:44.323Z,1748975684.323 [DAT](INFO): set verbose to 3 2025-06-03T18:34:44.323Z,1748975684.323 [DAT](INFO): setting DatVerbose to 27440 2025-06-03T18:34:44.574Z,1748975684.574 [DAT](INFO): DAT read: user:2> 2025-06-03T18:34:44.575Z,1748975684.575 [DAT](INFO): DAT read: DatVerbose | 27440 2025-06-03T18:34:44.575Z,1748975684.575 [DAT](INFO): set DatVerbose to 27440 2025-06-03T18:34:44.575Z,1748975684.575 [DAT](INFO): setting transmit power to 8 2025-06-03T18:34:44.826Z,1748975684.826 [DAT](INFO): DAT read: user:3> 2025-06-03T18:34:44.827Z,1748975684.827 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-06-03T18:34:44.827Z,1748975684.827 [DAT](INFO): set transmit power to 8 2025-06-03T18:34:44.827Z,1748975684.827 [DAT](INFO): setting local address to 5 2025-06-03T18:34:45.078Z,1748975685.078 [DAT](INFO): DAT read: user:4> 2025-06-03T18:34:45.079Z,1748975685.079 [DAT](INFO): DAT read: LocalAddr | 5 2025-06-03T18:34:45.079Z,1748975685.079 [DAT](INFO): set local address to 5 2025-06-03T18:34:45.080Z,1748975685.080 [DAT](INFO): Setting time to: 18:34:45 And date to:6/3/2025 2025-06-03T18:34:45.331Z,1748975685.331 [DAT](INFO): DAT read: user:5> 2025-06-03T18:34:45.332Z,1748975685.332 [DAT](INFO): DAT read: Tue Jun 3, 2025 18:34:45 2025-06-03T18:34:45.333Z,1748975685.333 [DAT](INFO): Local DAT time set to Tue Jun 3, 2025 18:34:45 2025-06-03T18:34:56.127Z,1748975696.127 [NAL9602](INFO): Powering up NAL9602 2025-06-03T18:35:07.032Z,1748975707.032 [NAL9602](INFO): NAL9602 initialized 2025-06-03T18:35:37.345Z,1748975737.345 [NAL9602](INFO): SBD MO Status=2, MOMSN=20936, MT Status=2, MTMSN=0 2025-06-03T18:35:37.345Z,1748975737.345 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T18:36:14.135Z,1748975774.135 [SBIT](IMPORTANT): Beginning Startup BIT 2025-06-03T18:36:14.140Z,1748975774.140 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-06-03T18:36:18.761Z,1748975778.761 [GFScanner](IMPORTANT): Low side ground fault detected mA: CHAN A0 (Batt): 0.856074 CHAN A1 (24V): 0.806997 CHAN A2 (12V): 0.865818 CHAN A3 (5V): 0.329405 CHAN B0 (3.3V): 0.200687 CHAN B1 (3.15aV): 0.235458 CHAN B2 (3.15bV): 0.234802 CHAN B3 (GND): -0.066693 OPEN: 0.020084 Full Scale: +/- 1 mA 2025-06-03T18:36:28.911Z,1748975788.911 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004710 2025-06-03T18:36:40.116Z,1748975800.116 [NAL9602](INFO): SBD MO Status=2, MOMSN=20936, MT Status=2, MTMSN=0 2025-06-03T18:36:40.116Z,1748975800.116 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T18:37:04.290Z,1748975824.290 [NAL9602](INFO): SBD MO Status=2, MOMSN=20936, MT Status=2, MTMSN=0 2025-06-03T18:37:04.290Z,1748975824.290 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T18:37:07.956Z,1748975827.956 [SBIT](IMPORTANT): SBIT PASSED 2025-06-03T18:37:07.956Z,1748975827.956 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2025-06-03T18:37:08.343Z,1748975828.343 [MissionManager](IMPORTANT): Started mission Startup 2025-06-03T18:37:08.343Z,1748975828.343 [Startup] Running Loop=1 2025-06-03T18:37:08.344Z,1748975828.344 [Startup](DEBUG): Aggregate::initialize Startup 2025-06-03T18:37:08.344Z,1748975828.344 [Startup:A.GoToSurface] Running Loop=1 2025-06-03T18:37:08.344Z,1748975828.344 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-06-03T18:37:08.344Z,1748975828.344 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-06-03T18:37:08.345Z,1748975828.345 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-06-03T18:37:08.345Z,1748975828.345 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-06-03T18:37:08.346Z,1748975828.346 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-06-03T18:37:08.346Z,1748975828.346 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-06-03T18:37:08.346Z,1748975828.346 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-06-03T18:37:08.348Z,1748975828.348 [Startup:StartupSatComms] Running Loop=1 2025-06-03T18:37:08.348Z,1748975828.348 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-06-03T18:37:08.348Z,1748975828.348 [Startup:StartupSatComms:A] Running Loop=1 2025-06-03T18:37:08.771Z,1748975828.771 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-06-03T18:37:26.954Z,1748975846.954 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-06-03T18:37:26.954Z,1748975846.954 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-06-03T18:37:27.004Z,1748975847.004 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-06-03T18:37:27.374Z,1748975847.374 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-06-03T18:37:27.375Z,1748975847.375 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-06-03T18:37:56.821Z,1748975876.821 [NAL9602](INFO): SBD MO Status=2, MOMSN=20936, MT Status=2, MTMSN=0 2025-06-03T18:37:56.825Z,1748975876.825 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T18:38:08.546Z,1748975888.546 [Startup:StartupSatComms:A](INFO): Timed out from 2025-06-03T18:37:08.3Z 2025-06-03T18:38:08.546Z,1748975888.546 [Startup:StartupSatComms:A] Stopped 2025-06-03T18:38:08.546Z,1748975888.546 [Startup:StartupSatComms:B] Running Loop=1 2025-06-03T18:38:08.965Z,1748975888.965 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-06-03T18:38:13.383Z,1748975893.383 [NAL9602](INFO): SBD MO Status=0, MOMSN=20936, MT Status=0, MTMSN=0 2025-06-03T18:38:13.383Z,1748975893.383 [NAL9602](INFO): No messages in MT queue 2025-06-03T18:38:14.597Z,1748975894.597 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183813.00,A,3649.11145,N,12152.36205,W,0.505,203.85,030625,,,A*7D 2025-06-03T18:38:14.600Z,1748975894.600 [NAL9602](INFO): GPS fix at 20250603T183813: (36.818524, -121.872701) 2025-06-03T18:38:16.655Z,1748975896.655 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250603T182202/Courier0007.lzma 2025-06-03T18:38:17.655Z,1748975897.655 [DataOverHttps](INFO): Moved sent file to Logs/20250603T182202/Courier0007.lzma.bak 2025-06-03T18:38:17.655Z,1748975897.655 [DataOverHttps](INFO): SBD MOMSN=25085650 2025-06-03T18:38:37.909Z,1748975917.909 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20250603T183413/Courier0000.lzma 2025-06-03T18:38:38.911Z,1748975918.911 [DataOverHttps](INFO): Moved sent file to Logs/20250603T183413/Courier0000.lzma.bak 2025-06-03T18:38:38.911Z,1748975918.911 [DataOverHttps](INFO): SBD MOMSN=25085652 2025-06-03T18:38:46.952Z,1748975926.952 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T18:38:55.412Z,1748975935.412 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20250603T182202/Express0008.lzma 2025-06-03T18:38:56.415Z,1748975936.415 [DataOverHttps](INFO): Moved sent file to Logs/20250603T182202/Express0008.lzma.bak 2025-06-03T18:38:56.415Z,1748975936.415 [DataOverHttps](INFO): SBD MOMSN=25085656 2025-06-03T18:39:08.782Z,1748975948.782 [Startup:StartupSatComms:B](INFO): Timed out from 2025-06-03T18:38:08.5Z 2025-06-03T18:39:08.782Z,1748975948.782 [Startup:StartupSatComms:B] Stopped 2025-06-03T18:39:08.782Z,1748975948.782 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-06-03T18:39:08.782Z,1748975948.782 [Startup:StartupSatComms] Stopped 2025-06-03T18:39:08.783Z,1748975948.783 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-06-03T18:39:08.784Z,1748975948.784 [Startup](INFO): Completed Startup 2025-06-03T18:39:08.784Z,1748975948.784 [MissionManager](INFO): Startup is completed. 2025-06-03T18:39:08.784Z,1748975948.784 [MissionManager](INFO): Uninitializing Mission Startup 2025-06-03T18:39:08.784Z,1748975948.784 [Startup] Stopped 2025-06-03T18:39:08.784Z,1748975948.784 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-06-03T18:39:08.784Z,1748975948.784 [Startup:A.GoToSurface] Stopped 2025-06-03T18:39:08.784Z,1748975948.784 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-06-03T18:39:09.168Z,1748975949.168 [MissionManager](IMPORTANT): Started mission Default 2025-06-03T18:39:09.168Z,1748975949.168 [Default] Running Loop=1 2025-06-03T18:39:09.168Z,1748975949.168 [Default](DEBUG): Aggregate::initialize Default 2025-06-03T18:39:09.168Z,1748975949.168 [Default:B.GoToSurface] Running Loop=1 2025-06-03T18:39:09.168Z,1748975949.168 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-06-03T18:39:09.169Z,1748975949.169 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-06-03T18:39:09.173Z,1748975949.173 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-06-03T18:39:09.174Z,1748975949.174 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-06-03T18:39:09.174Z,1748975949.174 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-06-03T18:39:09.174Z,1748975949.174 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-06-03T18:39:09.174Z,1748975949.174 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-06-03T18:39:09.175Z,1748975949.175 [Default:A.Wait] Running Loop=1 2025-06-03T18:39:09.175Z,1748975949.175 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-06-03T18:39:13.083Z,1748975953.083 [DataOverHttps](INFO): Sending 751 bytes from file Logs/20250603T183413/Express0001.lzma 2025-06-03T18:39:14.083Z,1748975954.083 [DataOverHttps](INFO): Moved sent file to Logs/20250603T183413/Express0001.lzma.bak 2025-06-03T18:39:14.083Z,1748975954.083 [DataOverHttps](INFO): SBD MOMSN=25085658 2025-06-03T18:39:22.531Z,1748975962.531 [Default:A.Wait](INFO): Done Waiting. 2025-06-03T18:39:22.531Z,1748975962.531 [Default:A.Wait] Stopped 2025-06-03T18:39:22.531Z,1748975962.531 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T18:39:22.890Z,1748975962.890 [Default:CheckIn] Running Loop=1 2025-06-03T18:39:22.891Z,1748975962.891 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-03T18:39:22.891Z,1748975962.891 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-03T18:39:23.296Z,1748975963.296 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-06-03T18:39:24.916Z,1748975964.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183923.00,A,3649.11077,N,12152.36426,W,0.253,241.83,030625,,,A*7C 2025-06-03T18:39:24.919Z,1748975964.919 [NAL9602](INFO): GPS fix at 20250603T183923: (36.818513, -121.872738) 2025-06-03T18:39:24.929Z,1748975964.929 [Default:CheckIn:Read_GPS] Stopped 2025-06-03T18:39:24.929Z,1748975964.929 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-03T18:39:25.350Z,1748975965.350 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-06-03T18:39:32.433Z,1748975972.433 [DataOverHttps](INFO): Sending 228 bytes from file Logs/20250603T183413/Courier0004.lzma 2025-06-03T18:39:32.628Z,1748975972.628 [NAL9602](INFO): SBD MO Status=0, MOMSN=20937, MT Status=0, MTMSN=0 2025-06-03T18:39:32.628Z,1748975972.628 [NAL9602](INFO): No messages in MT queue 2025-06-03T18:39:33.431Z,1748975973.431 [DataOverHttps](INFO): Moved sent file to Logs/20250603T183413/Courier0004.lzma.bak 2025-06-03T18:39:33.431Z,1748975973.431 [DataOverHttps](INFO): SBD MOMSN=25085676 2025-06-03T18:39:49.878Z,1748975989.878 [DataOverHttps](INFO): Sending 352 bytes from file Logs/20250603T183413/Express0005.lzma 2025-06-03T18:39:50.879Z,1748975990.879 [DataOverHttps](INFO): Moved sent file to Logs/20250603T183413/Express0005.lzma.bak 2025-06-03T18:39:50.879Z,1748975990.879 [DataOverHttps](INFO): SBD MOMSN=25085685 2025-06-03T18:39:52.060Z,1748975992.060 [Default:CheckIn:Read_Iridium] Stopped 2025-06-03T18:39:52.060Z,1748975992.060 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-03T18:39:52.060Z,1748975992.060 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-03T18:40:03.308Z,1748976003.308 [NAL9602](INFO): Not Powering down - fast GPS 2025-06-03T18:40:41.700Z,1748976041.700 [BPC1](ERROR): BPC1A: No match for serial number FFBD in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2025-06-03T18:40:57.862Z,1748976057.862 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-06-03T18:40:57.863Z,1748976057.863 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6. 2025-06-03T18:40:57.867Z,1748976057.867 [BPC1](INFO): Received data from all battery sticks. 2025-06-03T18:44:52.617Z,1748976292.617 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2025-06-03T18:44:52.618Z,1748976292.618 [Default:CheckIn:C.Wait] Stopped 2025-06-03T18:44:52.618Z,1748976292.618 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-06-03T18:44:52.618Z,1748976292.618 [Default:CheckIn:D] Running Loop=1 2025-06-03T18:44:53.016Z,1748976293.016 [Default:CheckIn:D] Stopped 2025-06-03T18:44:53.016Z,1748976293.016 [Default:CheckIn:E] Running Loop=1 2025-06-03T18:44:53.420Z,1748976293.420 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.730795 min 2025-06-03T18:44:53.420Z,1748976293.420 [Default:CheckIn:E] Stopped 2025-06-03T18:44:53.420Z,1748976293.420 [Default:CheckIn](INFO): Completed Default:CheckIn 2025-06-03T18:44:53.420Z,1748976293.420 [Default:CheckIn] Stopped 2025-06-03T18:44:53.420Z,1748976293.420 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-06-03T18:44:53.420Z,1748976293.420 [Default:CheckIn](INFO): Running loop #2 2025-06-03T18:44:53.420Z,1748976293.420 [Default:CheckIn] Running Loop=2 2025-06-03T18:44:53.421Z,1748976293.421 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-06-03T18:44:53.421Z,1748976293.421 [Default:CheckIn:Read_GPS] Running Loop=1 2025-06-03T18:44:55.430Z,1748976295.430 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184454.00,A,3649.10545,N,12152.35957,W,0.641,201.37,030625,,,A*77 2025-06-03T18:44:55.432Z,1748976295.432 [NAL9602](INFO): GPS fix at 20250603T184454: (36.818424, -121.872659) 2025-06-03T18:44:55.463Z,1748976295.463 [Default:CheckIn:Read_GPS] Stopped 2025-06-03T18:44:55.463Z,1748976295.463 [Default:CheckIn:Read_Iridium] Running Loop=1 2025-06-03T18:45:03.481Z,1748976303.481 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20250603T183413/Courier0007.lzma 2025-06-03T18:45:04.483Z,1748976304.483 [DataOverHttps](INFO): Moved sent file to Logs/20250603T183413/Courier0007.lzma.bak 2025-06-03T18:45:04.483Z,1748976304.483 [DataOverHttps](INFO): SBD MOMSN=25085695 2025-06-03T18:45:18.458Z,1748976318.458 [NAL9602](INFO): SBD MO Status=2, MOMSN=20938, MT Status=2, MTMSN=0 2025-06-03T18:45:18.459Z,1748976318.459 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T18:45:20.621Z,1748976320.621 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250603T183413/Express0008.lzma 2025-06-03T18:45:21.623Z,1748976321.623 [DataOverHttps](INFO): Moved sent file to Logs/20250603T183413/Express0008.lzma.bak 2025-06-03T18:45:21.623Z,1748976321.623 [DataOverHttps](INFO): SBD MOMSN=25085707 2025-06-03T18:45:22.907Z,1748976322.907 [Default:CheckIn:Read_Iridium] Stopped 2025-06-03T18:45:22.907Z,1748976322.907 [Default:CheckIn:C.Wait] Running Loop=1 2025-06-03T18:45:22.907Z,1748976322.907 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-06-03T18:45:35.427Z,1748976335.427 [NAL9602](INFO): SBD MO Status=2, MOMSN=20938, MT Status=2, MTMSN=0 2025-06-03T18:45:35.427Z,1748976335.427 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T18:46:17.023Z,1748976377.023 [NAL9602](INFO): SBD MO Status=2, MOMSN=20938, MT Status=2, MTMSN=0 2025-06-03T18:46:17.023Z,1748976377.023 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-06-03T18:46:31.530Z,1748976391.530 [DataOverHttps](IMPORTANT): SBD MTMSN=20250603T184630 2025-06-03T18:46:39.525Z,1748976399.525 [DataOverHttps](INFO): Received command: gfscan 2025-06-03T18:46:39.590Z,1748976399.590 [CommandExec](IMPORTANT): got command gfscan 2025-06-03T18:46:39.698Z,1748976399.698 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-06-03T18:46:40.526Z,1748976400.526 [DataOverHttps](IMPORTANT): SBD MTMSN=20250603T184639 2025-06-03T18:46:44.138Z,1748976404.138 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.028458 CHAN A1 (24V): 0.024228 CHAN A2 (12V): -0.036966 CHAN A3 (5V): -0.063744 CHAN B0 (3.3V): -0.023632 CHAN B1 (3.15aV): -0.010489 CHAN B2 (3.15bV): -0.005099 CHAN B3 (GND): -0.026265 OPEN: 0.010555 Full Scale: +/- 1 mA 2025-06-03T18:46:48.205Z,1748976408.205 [DataOverHttps](INFO): Received command: restart logs