2024-04-26T16:04:14.171Z,1714147454.171 [Supervisor](DEBUG): Initializing supervisor. 2024-04-26T16:04:14.175Z,1714147454.175 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-04-26T16:04:14.176Z,1714147454.176 [SyncHandler](INFO): Protected caller Thread ID is 835 2024-04-26T16:04:14.176Z,1714147454.176 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-04-26T16:04:14.177Z,1714147454.177 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-04-26T16:04:14.177Z,1714147454.177 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836 2024-04-26T16:04:14.181Z,1714147454.181 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-04-26T16:04:14.199Z,1714147454.199 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-04-26T16:04:14.200Z,1714147454.200 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-04-26T16:04:14.201Z,1714147454.201 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837 2024-04-26T16:04:14.205Z,1714147454.205 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-04-26T16:04:14.206Z,1714147454.206 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-04-26T16:04:14.206Z,1714147454.206 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838 2024-04-26T16:04:14.209Z,1714147454.209 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-04-26T16:04:14.210Z,1714147454.210 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-04-26T16:04:14.210Z,1714147454.210 [logger ThreadHandler](INFO): Protected caller Thread ID is 839 2024-04-26T16:04:14.214Z,1714147454.214 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-04-26T16:04:14.214Z,1714147454.214 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-04-26T16:04:14.218Z,1714147454.218 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-04-26T16:04:14.627Z,1714147454.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-04-26T16:04:14.629Z,1714147454.629 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-04-26T16:04:15.412Z,1714147455.412 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-04-26T16:04:15.414Z,1714147455.414 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-04-26T16:04:15.533Z,1714147455.533 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-04-26T16:04:15.535Z,1714147455.535 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-04-26T16:04:16.100Z,1714147456.100 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-04-26T16:04:16.101Z,1714147456.101 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-04-26T16:04:16.209Z,1714147456.209 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-04-26T16:04:16.211Z,1714147456.211 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-04-26T16:04:16.304Z,1714147456.304 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-04-26T16:04:16.739Z,1714147456.739 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-04-26T16:04:17.141Z,1714147457.141 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-04-26T16:04:17.410Z,1714147457.410 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-04-26T16:04:17.413Z,1714147457.413 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-04-26T16:04:17.562Z,1714147457.562 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-04-26T16:04:17.564Z,1714147457.564 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-04-26T16:04:17.823Z,1714147457.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-04-26T16:04:17.825Z,1714147457.825 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-04-26T16:04:18.395Z,1714147458.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-04-26T16:04:18.395Z,1714147458.395 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-04-26T16:04:18.810Z,1714147458.810 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-04-26T16:04:18.811Z,1714147458.811 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-04-26T16:04:18.902Z,1714147458.902 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-04-26T16:04:19.118Z,1714147459.118 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-04-26T16:04:19.120Z,1714147459.120 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-04-26T16:04:19.370Z,1714147459.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-04-26T16:04:19.371Z,1714147459.371 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-04-26T16:04:19.687Z,1714147459.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-04-26T16:04:19.689Z,1714147459.689 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2024-04-26T16:04:19.693Z,1714147459.693 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2024-04-26T16:04:19.813Z,1714147459.813 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2024-04-26T16:04:19.977Z,1714147459.977 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2024-04-26T16:04:20.075Z,1714147460.075 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2024-04-26T16:04:20.171Z,1714147460.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2024-04-26T16:04:20.293Z,1714147460.293 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2024-04-26T16:04:20.411Z,1714147460.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2024-04-26T16:04:20.686Z,1714147460.686 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-04-26T16:04:20.687Z,1714147460.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2024-04-26T16:04:20.834Z,1714147460.834 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2024-04-26T16:04:20.938Z,1714147460.938 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2024-04-26T16:04:21.042Z,1714147461.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2024-04-26T16:04:21.157Z,1714147461.157 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2024-04-26T16:04:21.171Z,1714147461.171 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-04-26T16:04:21.321Z,1714147461.321 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-04-26T16:04:21.323Z,1714147461.323 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-04-26T16:04:21.338Z,1714147461.338 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-04-26T16:04:21.340Z,1714147461.340 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-04-26T16:04:21.412Z,1714147461.412 [DepthRateCalculator] Loaded 2024-04-26T16:04:21.412Z,1714147461.412 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-04-26T16:04:21.418Z,1714147461.418 [PitchRateCalculator] Loaded 2024-04-26T16:04:21.418Z,1714147461.418 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-04-26T16:04:21.428Z,1714147461.428 [SpeedCalculator] Loaded 2024-04-26T16:04:21.429Z,1714147461.429 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-04-26T16:04:21.433Z,1714147461.433 [YawRateCalculator] Loaded 2024-04-26T16:04:21.434Z,1714147461.434 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-04-26T16:04:21.455Z,1714147461.455 [ElevatorOffsetCalculator] Loaded 2024-04-26T16:04:21.455Z,1714147461.455 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-04-26T16:04:21.456Z,1714147461.456 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-04-26T16:04:21.458Z,1714147461.458 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-04-26T16:04:21.528Z,1714147461.528 [VerticalControl](DEBUG): Construct VerticalControl. 2024-04-26T16:04:21.585Z,1714147461.585 [VerticalControl] Loaded 2024-04-26T16:04:21.585Z,1714147461.585 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-04-26T16:04:21.588Z,1714147461.588 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-04-26T16:04:21.635Z,1714147461.635 [HorizontalControl] Loaded 2024-04-26T16:04:21.635Z,1714147461.635 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-04-26T16:04:21.638Z,1714147461.638 [SpeedControl](DEBUG): Construct SpeedControl. 2024-04-26T16:04:21.640Z,1714147461.640 [SpeedControl] Loaded 2024-04-26T16:04:21.641Z,1714147461.641 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-04-26T16:04:21.643Z,1714147461.643 [LoopControl](DEBUG): Construct LoopControl. 2024-04-26T16:04:21.644Z,1714147461.644 [LoopControl] Loaded 2024-04-26T16:04:21.644Z,1714147461.644 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-04-26T16:04:21.645Z,1714147461.645 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-04-26T16:04:21.645Z,1714147461.645 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-04-26T16:04:21.783Z,1714147461.783 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-04-26T16:04:21.783Z,1714147461.783 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-04-26T16:04:21.797Z,1714147461.797 [NavChart] Loaded 2024-04-26T16:04:21.798Z,1714147461.798 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-04-26T16:04:21.803Z,1714147461.803 [UniversalFixResidualReporter] Loaded 2024-04-26T16:04:21.804Z,1714147461.804 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-04-26T16:04:21.804Z,1714147461.804 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-04-26T16:04:21.805Z,1714147461.805 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-04-26T16:04:22.754Z,1714147462.754 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-04-26T16:04:22.754Z,1714147462.754 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-04-26T16:04:23.542Z,1714147463.542 [AHRS_M2] Loaded 2024-04-26T16:04:23.543Z,1714147463.543 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-04-26T16:04:23.921Z,1714147463.921 [BackseatComponent] Loaded 2024-04-26T16:04:23.921Z,1714147463.921 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2024-04-26T16:04:23.933Z,1714147463.933 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409224E0 2024-04-26T16:04:23.933Z,1714147463.933 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 922 2024-04-26T16:04:24.009Z,1714147464.009 [LcmUniversalReporter] Loaded 2024-04-26T16:04:24.010Z,1714147464.010 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2024-04-26T16:04:25.144Z,1714147465.144 [BPC1] Loaded 2024-04-26T16:04:25.145Z,1714147465.145 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-04-26T16:04:25.295Z,1714147465.295 [DataOverHttps] Loaded 2024-04-26T16:04:25.295Z,1714147465.295 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-04-26T16:04:25.296Z,1714147465.296 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409524E0 2024-04-26T16:04:25.297Z,1714147465.297 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 923 2024-04-26T16:04:25.317Z,1714147465.317 [Depth_Keller] Loaded 2024-04-26T16:04:25.318Z,1714147465.318 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-04-26T16:04:25.355Z,1714147465.355 [DVL_micro] Loaded 2024-04-26T16:04:25.356Z,1714147465.356 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2024-04-26T16:04:25.417Z,1714147465.417 [NAL9602] Loaded 2024-04-26T16:04:25.418Z,1714147465.418 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-04-26T16:04:25.447Z,1714147465.447 [Onboard] Loaded 2024-04-26T16:04:25.448Z,1714147465.448 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-04-26T16:04:25.449Z,1714147465.449 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409824E0 2024-04-26T16:04:25.449Z,1714147465.449 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 924 2024-04-26T16:04:25.461Z,1714147465.461 [Power24vConverter] Loaded 2024-04-26T16:04:25.461Z,1714147465.461 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-04-26T16:04:25.475Z,1714147465.475 [Radio_Surface] Loaded 2024-04-26T16:04:25.475Z,1714147465.475 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-04-26T16:04:25.476Z,1714147465.476 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409B24E0 2024-04-26T16:04:25.476Z,1714147465.476 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 925 2024-04-26T16:04:25.490Z,1714147465.490 [Sonardyne_Nano] Loaded 2024-04-26T16:04:25.490Z,1714147465.490 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2024-04-26T16:04:25.583Z,1714147465.583 [DAT] Loaded 2024-04-26T16:04:25.584Z,1714147465.584 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-04-26T16:04:25.585Z,1714147465.585 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409E24E0 2024-04-26T16:04:25.585Z,1714147465.585 [DAT ThreadHandler](INFO): Protected caller Thread ID is 926 2024-04-26T16:04:25.586Z,1714147465.586 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-04-26T16:04:25.586Z,1714147465.586 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-04-26T16:04:25.749Z,1714147465.749 [BuoyancyServo] Loaded 2024-04-26T16:04:25.750Z,1714147465.750 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-04-26T16:04:25.770Z,1714147465.770 [ElevatorServo] Loaded 2024-04-26T16:04:25.771Z,1714147465.771 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-04-26T16:04:25.790Z,1714147465.790 [MassServo] Loaded 2024-04-26T16:04:25.791Z,1714147465.791 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-04-26T16:04:25.810Z,1714147465.810 [RudderServo] Loaded 2024-04-26T16:04:25.810Z,1714147465.810 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-04-26T16:04:25.825Z,1714147465.825 [ThrusterHE] Loaded 2024-04-26T16:04:25.825Z,1714147465.825 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-04-26T16:04:25.826Z,1714147465.826 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-04-26T16:04:25.826Z,1714147465.826 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-04-26T16:04:25.910Z,1714147465.910 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-04-26T16:04:25.910Z,1714147465.910 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-04-26T16:04:25.954Z,1714147465.954 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-04-26T16:04:25.955Z,1714147465.955 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-04-26T16:04:26.362Z,1714147466.362 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-04-26T16:04:26.363Z,1714147466.363 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-04-26T16:04:26.600Z,1714147466.600 [CTD_Seabird] Loaded 2024-04-26T16:04:26.600Z,1714147466.600 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-04-26T16:04:26.601Z,1714147466.601 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B984E0 2024-04-26T16:04:26.601Z,1714147466.601 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 927 2024-04-26T16:04:26.635Z,1714147466.635 [ESPComponent] Loaded 2024-04-26T16:04:26.635Z,1714147466.635 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2024-04-26T16:04:26.655Z,1714147466.655 [PAR_Licor] Loaded 2024-04-26T16:04:26.655Z,1714147466.655 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-04-26T16:04:26.699Z,1714147466.699 [WetLabsBB2FL] Loaded 2024-04-26T16:04:26.699Z,1714147466.699 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-04-26T16:04:26.701Z,1714147466.701 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BC84E0 2024-04-26T16:04:26.701Z,1714147466.701 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 928 2024-04-26T16:04:26.702Z,1714147466.702 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-04-26T16:04:26.704Z,1714147466.704 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-04-26T16:04:26.879Z,1714147466.879 [SBIT](DEBUG): Construct Startup Built In Test. 2024-04-26T16:04:26.888Z,1714147466.888 [SBIT] Loaded 2024-04-26T16:04:26.889Z,1714147466.889 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-04-26T16:04:26.892Z,1714147466.892 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-04-26T16:04:26.905Z,1714147466.905 [IBIT] Loaded 2024-04-26T16:04:26.905Z,1714147466.905 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-04-26T16:04:26.911Z,1714147466.911 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-04-26T16:04:27.018Z,1714147467.018 [CBIT] Loaded 2024-04-26T16:04:27.018Z,1714147467.018 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-04-26T16:04:27.019Z,1714147467.019 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-04-26T16:04:27.025Z,1714147467.025 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-04-26T16:04:27.029Z,1714147467.029 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-04-26T16:04:27.040Z,1714147467.040 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-04-26T16:04:27.041Z,1714147467.041 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C374E0 2024-04-26T16:04:27.041Z,1714147467.041 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929 2024-04-26T16:04:27.046Z,1714147467.046 [Supervisor](INFO): Main Thread ID is 828 2024-04-26T16:04:27.046Z,1714147467.046 [Supervisor](DEBUG): Running supervisor. 2024-04-26T16:04:27.047Z,1714147467.047 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930 2024-04-26T16:04:27.047Z,1714147467.047 [CommandExec](INFO): Initializing the command executive. 2024-04-26T16:04:27.049Z,1714147467.049 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931 2024-04-26T16:04:27.051Z,1714147467.051 [controlThread ThreadHandler](INFO): Handler Thread ID is 932 2024-04-26T16:04:27.051Z,1714147467.051 [controlThread](DEBUG): Initializing ControlThread 2024-04-26T16:04:27.052Z,1714147467.052 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-04-26T16:04:27.052Z,1714147467.052 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-04-26T16:04:27.053Z,1714147467.053 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-04-26T16:04:27.053Z,1714147467.053 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-04-26T16:04:27.053Z,1714147467.053 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-04-26T16:04:27.054Z,1714147467.054 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-04-26T16:04:27.056Z,1714147467.056 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-04-26T16:04:27.056Z,1714147467.056 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-04-26T16:04:27.057Z,1714147467.057 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-04-26T16:04:27.058Z,1714147467.058 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-04-26T16:04:27.058Z,1714147467.058 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-04-26T16:04:27.064Z,1714147467.064 [SBIT](INFO): Initialize SBIT Component. 2024-04-26T16:04:27.064Z,1714147467.064 [SBIT](IMPORTANT): git: 2024-04-26 2024-04-26T16:04:27.065Z,1714147467.065 [SBIT](INFO): git hash: d18504f3d5b55cf8c5e2786258a0a6e68a845ccf 2024-04-26T16:04:27.065Z,1714147467.065 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-04-26T16:04:27.066Z,1714147467.066 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2024-04-26T16:04:27.067Z,1714147467.067 [SBIT](INFO): Beginning SBIT in 69.000000 seconds. 2024-04-26T16:04:27.068Z,1714147467.068 [IBIT](INFO): Initialize IBIT Component. 2024-04-26T16:04:27.069Z,1714147467.069 [CBIT](DEBUG): Initialize CBIT Component. 2024-04-26T16:04:27.070Z,1714147467.070 [logger ThreadHandler](INFO): Handler Thread ID is 933 2024-04-26T16:04:27.080Z,1714147467.080 [CBIT](DEBUG): Initialized mux pins. 2024-04-26T16:04:27.080Z,1714147467.080 [CBIT](DEBUG): Initializing the watchdog timer. 2024-04-26T16:04:27.088Z,1714147467.088 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 934 2024-04-26T16:04:27.100Z,1714147467.100 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 935 2024-04-26T16:04:27.102Z,1714147467.102 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-04-26T16:04:27.104Z,1714147467.104 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-04-26T16:04:27.104Z,1714147467.104 [CBIT](DEBUG): Initializing heartbeat. 2024-04-26T16:04:27.112Z,1714147467.112 [Onboard ThreadHandler](INFO): Handler Thread ID is 936 2024-04-26T16:04:27.130Z,1714147467.130 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 937 2024-04-26T16:04:27.152Z,1714147467.152 [DAT ThreadHandler](INFO): Handler Thread ID is 938 2024-04-26T16:04:27.153Z,1714147467.153 [DAT](INFO): Powering up 2024-04-26T16:04:27.153Z,1714147467.153 [DAT](DEBUG): Initializing DAT. 2024-04-26T16:04:27.157Z,1714147467.157 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 940 2024-04-26T16:04:27.158Z,1714147467.158 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-04-26T16:04:27.161Z,1714147467.161 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 942 2024-04-26T16:04:27.164Z,1714147467.164 [WetLabsBB2FL](INFO): Powering up 2024-04-26T16:04:27.166Z,1714147467.166 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 944 2024-04-26T16:04:27.174Z,1714147467.174 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-04-26T16:04:27.174Z,1714147467.174 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-04-26T16:04:27.174Z,1714147467.174 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-04-26T16:04:27.174Z,1714147467.174 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-04-26T16:04:27.174Z,1714147467.174 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-04-26T16:04:27.175Z,1714147467.175 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-04-26T16:04:27.175Z,1714147467.175 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-04-26T16:04:27.175Z,1714147467.175 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-04-26T16:04:27.176Z,1714147467.176 [CBIT](DEBUG): Deactivating GF circuits. 2024-04-26T16:04:27.176Z,1714147467.176 [CBIT](DEBUG): Deactivating emergency mode. 2024-04-26T16:04:27.216Z,1714147467.216 [CBIT](DEBUG): Backplane powered. 2024-04-26T16:04:27.216Z,1714147467.216 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-04-26T16:04:27.217Z,1714147467.217 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-04-26T16:04:27.217Z,1714147467.217 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2024-04-26T16:04:27.232Z,1714147467.232 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2024-04-26T16:04:27.284Z,1714147467.284 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2024-04-26T16:04:27.308Z,1714147467.308 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-26T16:04:27.336Z,1714147467.336 [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 } } } 2024-04-26T16:04:27.337Z,1714147467.337 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-04-26T16:04:27.337Z,1714147467.337 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2024-04-26T16:04:27.344Z,1714147467.344 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2024-04-26T16:04:27.536Z,1714147467.536 [Radio_Surface](INFO): Powering up 2024-04-26T16:04:27.644Z,1714147467.644 [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 2024-04-26T16:04:27.666Z,1714147467.666 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-04-26T16:04:27.667Z,1714147467.667 [Default:A.Wait](DEBUG): Construct Wait. 2024-04-26T16:04:27.686Z,1714147467.686 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-26T16:04:27.715Z,1714147467.715 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-04-26T16:04:27.717Z,1714147467.717 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-04-26T16:04:27.747Z,1714147467.747 [Default:E.Execute](DEBUG): Construct Execute. 2024-04-26T16:04:27.758Z,1714147467.758 [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" } } 2024-04-26T16:04:27.763Z,1714147467.763 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-04-26T16:04:27.816Z,1714147467.816 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-04-26T16:04:28.049Z,1714147468.049 [Power24vConverter](INFO): Powering up. 2024-04-26T16:04:28.050Z,1714147468.050 [Sonardyne_Nano](INFO): Initializing. 2024-04-26T16:04:28.110Z,1714147468.110 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-04-26T16:04:28.116Z,1714147468.116 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-04-26T16:04:28.117Z,1714147468.117 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-04-26T16:04:28.124Z,1714147468.124 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-04-26T16:04:28.125Z,1714147468.125 [MassServo](DEBUG): Initializing EZServoServo. 2024-04-26T16:04:28.132Z,1714147468.132 [MassServo](DEBUG): Initializing MassServo. 2024-04-26T16:04:28.133Z,1714147468.133 [RudderServo](DEBUG): Initializing EZServoServo. 2024-04-26T16:04:28.140Z,1714147468.140 [RudderServo](DEBUG): Initializing RudderServo. 2024-04-26T16:04:28.141Z,1714147468.141 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-26T16:04:28.152Z,1714147468.152 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-26T16:04:29.776Z,1714147469.776 [WetLabsBB2FL](INFO): Powering down 2024-04-26T16:04:30.194Z,1714147470.194 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-04-26T16:04:31.437Z,1714147471.437 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2207 2024-04-26T16:04:31.852Z,1714147471.852 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2024-04-26T16:04:33.672Z,1714147473.672 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-04-26T16:04:34.224Z,1714147474.224 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2024-04-26T16:04:39.252Z,1714147479.252 [DAT](INFO): DAT read: 2024-04-26T16:04:39.254Z,1714147479.254 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-04-26T16:04:40.766Z,1714147480.766 [DAT](INFO): DAT read: MF Frequency Band 2024-04-26T16:04:40.767Z,1714147480.767 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2024-04-26T16:04:40.768Z,1714147480.768 [DAT](INFO): DAT read: Apr 26 2024 16:04:35 2024-04-26T16:04:42.025Z,1714147482.025 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-04-26T16:04:42.026Z,1714147482.026 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2024-04-26T16:04:42.026Z,1714147482.026 [DAT](INFO): commRate: 800 2024-04-26T16:04:44.092Z,1714147484.092 [DAT](INFO): entering command mode 2024-04-26T16:04:44.292Z,1714147484.292 [DAT](INFO): DAT read: 2024-04-26T16:04:44.293Z,1714147484.293 [DAT](INFO): DAT read: user:1> 2024-04-26T16:04:44.293Z,1714147484.293 [DAT](INFO): setting verbose to 3 2024-04-26T16:04:44.544Z,1714147484.544 [DAT](INFO): DAT read: user:1> 2024-04-26T16:04:44.546Z,1714147484.546 [DAT](INFO): DAT read: Verbose | 3 2024-04-26T16:04:44.546Z,1714147484.546 [DAT](INFO): set verbose to 3 2024-04-26T16:04:44.546Z,1714147484.546 [DAT](INFO): setting DatVerbose to 27440 2024-04-26T16:04:44.797Z,1714147484.797 [DAT](INFO): DAT read: user:2> 2024-04-26T16:04:44.798Z,1714147484.798 [DAT](INFO): DAT read: DatVerbose | 27440 2024-04-26T16:04:44.798Z,1714147484.798 [DAT](INFO): set DatVerbose to 27440 2024-04-26T16:04:44.798Z,1714147484.798 [DAT](INFO): setting transmit power to 8 2024-04-26T16:04:45.049Z,1714147485.049 [DAT](INFO): DAT read: user:3> 2024-04-26T16:04:45.049Z,1714147485.049 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-04-26T16:04:45.050Z,1714147485.050 [DAT](INFO): set transmit power to 8 2024-04-26T16:04:45.050Z,1714147485.050 [DAT](INFO): setting local address to 11 2024-04-26T16:04:45.301Z,1714147485.301 [DAT](INFO): DAT read: user:4> 2024-04-26T16:04:45.301Z,1714147485.301 [DAT](INFO): DAT read: LocalAddr | 11 2024-04-26T16:04:45.302Z,1714147485.302 [DAT](INFO): set local address to 11 2024-04-26T16:04:45.303Z,1714147485.303 [DAT](INFO): Setting time to: 16:4:45 And date to:4/26/2024 2024-04-26T16:04:45.552Z,1714147485.552 [DAT](INFO): DAT read: user:5> 2024-04-26T16:04:45.553Z,1714147485.553 [DAT](INFO): DAT read: Fri Apr 26, 2024 16:04:45 2024-04-26T16:04:45.554Z,1714147485.554 [DAT](INFO): Local DAT time set to Fri Apr 26, 2024 16:04:45 2024-04-26T16:04:55.650Z,1714147495.650 [NAL9602](INFO): Powering up NAL9602 2024-04-26T16:05:06.562Z,1714147506.562 [NAL9602](INFO): NAL9602 initialized 2024-04-26T16:05:34.033Z,1714147534.033 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:05:36.875Z,1714147536.875 [SBIT](IMPORTANT): Beginning Startup BIT 2024-04-26T16:05:36.895Z,1714147536.895 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-26T16:05:47.917Z,1714147547.917 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.017730 CHAN A1 (24V): 0.028411 CHAN A2 (12V): 0.002353 CHAN A3 (5V): -0.009282 CHAN B0 (3.3V): -0.007767 CHAN B1 (3.15aV): -0.006252 CHAN B2 (3.15bV): -0.004888 CHAN B3 (GND): -0.008600 OPEN: -0.002378 Full Scale: +/- 1 mA 2024-04-26T16:05:48.974Z,1714147548.974 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:06:00.723Z,1714147560.723 [NAL9602](INFO): SBD MO Status=2, MOMSN=19636, MT Status=2, MTMSN=0 2024-04-26T16:06:00.723Z,1714147560.723 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-26T16:06:03.922Z,1714147563.922 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:06:10.394Z,1714147570.394 [NAL9602](INFO): SBD MO Status=0, MOMSN=19636, MT Status=0, MTMSN=0 2024-04-26T16:06:10.394Z,1714147570.394 [NAL9602](INFO): No messages in MT queue 2024-04-26T16:06:11.607Z,1714147571.607 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160608.00,A,3648.15212,N,12147.22156,W,0.233,0.00,260424,,,A*7E 2024-04-26T16:06:11.611Z,1714147571.611 [NAL9602](INFO): GPS fix at 20240426T160608: (36.802535, -121.787026) 2024-04-26T16:06:18.471Z,1714147578.471 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:06:31.040Z,1714147591.040 [SBIT](IMPORTANT): SBIT PASSED 2024-04-26T16:06:31.040Z,1714147591.040 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2024-04-26T16:06:31.041Z,1714147591.041 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=1 bool; 2024-04-26T16:06:31.041Z,1714147591.041 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=12 count; 2024-04-26T16:06:31.041Z,1714147591.041 [SBIT](IMPORTANT): DVL_micro.baud=19200 bit_per_second; 2024-04-26T16:06:31.042Z,1714147591.042 [SBIT](IMPORTANT): Depth_Keller.offset=3.6 decibar; 2024-04-26T16:06:31.042Z,1714147591.042 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2024-04-26T16:06:31.042Z,1714147591.042 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=3 minute; 2024-04-26T16:06:31.042Z,1714147591.042 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool; 2024-04-26T16:06:31.042Z,1714147591.042 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=150 cubic_centimeter; 2024-04-26T16:06:31.042Z,1714147591.042 [SBIT](IMPORTANT): VerticalControl.massDefault=12.406871 millimeter; 2024-04-26T16:06:31.421Z,1714147591.421 [MissionManager](IMPORTANT): Started mission Startup 2024-04-26T16:06:31.421Z,1714147591.421 [Startup] Running Loop=1 2024-04-26T16:06:31.421Z,1714147591.421 [Startup](DEBUG): Aggregate::initialize Startup 2024-04-26T16:06:31.421Z,1714147591.421 [Startup:A.GoToSurface] Running Loop=1 2024-04-26T16:06:31.421Z,1714147591.421 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-26T16:06:31.422Z,1714147591.422 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-26T16:06:31.422Z,1714147591.422 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-26T16:06:31.423Z,1714147591.423 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-26T16:06:31.423Z,1714147591.423 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-26T16:06:31.423Z,1714147591.423 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-26T16:06:31.425Z,1714147591.425 [Startup:StartupSatComms] Running Loop=1 2024-04-26T16:06:31.425Z,1714147591.425 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-04-26T16:06:31.425Z,1714147591.425 [Startup:StartupSatComms:A] Running Loop=1 2024-04-26T16:06:31.818Z,1714147591.818 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-04-26T16:06:33.422Z,1714147593.422 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:06:33.433Z,1714147593.433 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160630.00,A,3648.15127,N,12147.22208,W,0.039,0.00,260424,,,A*70 2024-04-26T16:06:33.435Z,1714147593.435 [NAL9602](INFO): GPS fix at 20240426T160630: (36.802521, -121.787035) 2024-04-26T16:06:33.446Z,1714147593.446 [Startup:StartupSatComms:A] Stopped 2024-04-26T16:06:33.446Z,1714147593.446 [Startup:StartupSatComms:B] Running Loop=1 2024-04-26T16:06:33.873Z,1714147593.873 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-26T16:06:48.048Z,1714147608.048 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:07:02.998Z,1714147622.998 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:07:04.623Z,1714147624.623 [NAL9602](INFO): SBD MO Status=2, MOMSN=19637, MT Status=2, MTMSN=0 2024-04-26T16:07:04.623Z,1714147624.623 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-26T16:07:17.485Z,1714147637.485 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:07:24.347Z,1714147644.347 [NAL9602](INFO): SBD MO Status=1, MOMSN=19637, MT Status=0, MTMSN=0 2024-04-26T16:07:24.400Z,1714147644.400 [NAL9602](INFO): Sent 39 bytes from file Logs/20240425T213440/Courier0595.lzma 2024-04-26T16:07:24.400Z,1714147644.400 [NAL9602](INFO): Packets left to send: 0 2024-04-26T16:07:33.709Z,1714147653.709 [Startup:StartupSatComms:B](INFO): Timed out from 2024-04-26T16:06:33.4Z 2024-04-26T16:07:33.710Z,1714147653.710 [Startup:StartupSatComms:B] Stopped 2024-04-26T16:07:33.710Z,1714147653.710 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-04-26T16:07:33.710Z,1714147653.710 [Startup:StartupSatComms] Stopped 2024-04-26T16:07:33.710Z,1714147653.710 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-04-26T16:07:33.711Z,1714147653.711 [Startup](INFO): Completed Startup 2024-04-26T16:07:33.711Z,1714147653.711 [MissionManager](INFO): Startup is completed. 2024-04-26T16:07:33.711Z,1714147653.711 [MissionManager](INFO): Uninitializing Mission Startup 2024-04-26T16:07:33.711Z,1714147653.711 [Startup] Stopped 2024-04-26T16:07:33.711Z,1714147653.711 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-04-26T16:07:33.711Z,1714147653.711 [Startup:A.GoToSurface] Stopped 2024-04-26T16:07:33.711Z,1714147653.711 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-04-26T16:07:33.993Z,1714147653.993 [MissionManager](IMPORTANT): Started mission Default 2024-04-26T16:07:33.993Z,1714147653.993 [Default] Running Loop=1 2024-04-26T16:07:33.993Z,1714147653.993 [Default](DEBUG): Aggregate::initialize Default 2024-04-26T16:07:33.993Z,1714147653.993 [Default:B.GoToSurface] Running Loop=1 2024-04-26T16:07:33.993Z,1714147653.993 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-26T16:07:33.994Z,1714147653.994 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-26T16:07:33.994Z,1714147653.994 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-26T16:07:33.994Z,1714147653.994 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-26T16:07:33.995Z,1714147653.995 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-26T16:07:33.995Z,1714147653.995 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-26T16:07:33.995Z,1714147653.995 [Default:A.Wait] Running Loop=1 2024-04-26T16:07:33.995Z,1714147653.995 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-04-26T16:07:37.207Z,1714147657.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=19638, MT Status=2, MTMSN=0 2024-04-26T16:07:37.207Z,1714147657.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-26T16:07:47.334Z,1714147667.334 [Default:A.Wait](INFO): Done Waiting. 2024-04-26T16:07:47.334Z,1714147667.334 [Default:A.Wait] Stopped 2024-04-26T16:07:47.334Z,1714147667.334 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-04-26T16:07:47.727Z,1714147667.727 [Default:CheckIn] Running Loop=1 2024-04-26T16:07:47.727Z,1714147667.727 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-26T16:07:47.727Z,1714147667.727 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-26T16:07:48.132Z,1714147668.132 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-04-26T16:07:49.746Z,1714147669.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160746.00,A,3648.15010,N,12147.22246,W,0.039,0.00,260424,,,D*7A 2024-04-26T16:07:49.749Z,1714147669.749 [NAL9602](INFO): GPS fix at 20240426T160746: (36.802502, -121.787041) 2024-04-26T16:07:49.760Z,1714147669.760 [Default:CheckIn:Read_GPS] Stopped 2024-04-26T16:07:49.760Z,1714147669.760 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-26T16:07:50.173Z,1714147670.173 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-26T16:08:05.446Z,1714147685.446 [NAL9602](INFO): SBD MO Status=1, MOMSN=19638, MT Status=0, MTMSN=0 2024-04-26T16:08:05.500Z,1714147685.500 [NAL9602](INFO): Sent 268 bytes from file Logs/20240426T160414/Courier0000.lzma 2024-04-26T16:08:05.500Z,1714147685.500 [NAL9602](INFO): Packets left to send: 0 2024-04-26T16:08:21.431Z,1714147701.431 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004464 2024-04-26T16:08:28.859Z,1714147708.859 [NAL9602](INFO): SBD MO Status=2, MOMSN=19639, MT Status=2, MTMSN=0 2024-04-26T16:08:28.859Z,1714147708.859 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2024-04-26T16:08:59.570Z,1714147739.570 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-26T16:14:53.776Z,1714148093.776 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:14:59.029Z,1714148099.029 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:15:13.983Z,1714148113.983 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:15:28.364Z,1714148128.364 [CommandExec](IMPORTANT): got command failComponent 2024-04-26T16:15:28.365Z,1714148128.365 [CommandExec](IMPORTANT): Failed components: 2024-04-26T16:15:28.365Z,1714148128.365 [CommandExec](IMPORTANT): No failed Components. 2024-04-26T16:15:29.008Z,1714148129.008 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:15:29.933Z,1714148129.933 [CommandExec](IMPORTANT): got command ibit 2024-04-26T16:15:30.259Z,1714148130.259 [IBIT](IMPORTANT): Beginning Initiated BIT 2024-04-26T16:15:30.259Z,1714148130.259 [IBIT](IMPORTANT): Beginning control surface checks. 2024-04-26T16:15:30.262Z,1714148130.262 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-26T16:15:31.831Z,1714148131.831 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161531.00,A,3648.14861,N,12147.22055,W,0.058,0.00,260424,,,D*71 2024-04-26T16:15:31.834Z,1714148131.834 [NAL9602](INFO): GPS fix at 20240426T161531: (36.802477, -121.787009) 2024-04-26T16:15:41.218Z,1714148141.218 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.017271 CHAN A1 (24V): 0.027051 CHAN A2 (12V): 0.001794 CHAN A3 (5V): -0.009068 CHAN B0 (3.3V): -0.007547 CHAN B1 (3.15aV): -0.006144 CHAN B2 (3.15bV): -0.004900 CHAN B3 (GND): -0.008830 OPEN: 0.004776 Full Scale: +/- 1 mA 2024-04-26T16:15:44.347Z,1714148144.347 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:15:59.344Z,1714148159.344 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:16:01.807Z,1714148161.807 [NAL9602](INFO): SBD MO Status=1, MOMSN=19639, MT Status=0, MTMSN=0 2024-04-26T16:16:01.820Z,1714148161.820 [NAL9602](INFO): No messages in MT queue 2024-04-26T16:16:02.993Z,1714148162.993 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161602.00,A,3648.14854,N,12147.21946,W,0.097,0.00,260424,,,D*7F 2024-04-26T16:16:02.995Z,1714148162.995 [NAL9602](INFO): GPS fix at 20240426T161602: (36.802476, -121.786991) 2024-04-26T16:16:05.813Z,1714148165.813 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161605.00,A,3648.14852,N,12147.21934,W,0.039,0.00,260424,,,D*7F 2024-04-26T16:16:05.815Z,1714148165.815 [NAL9602](INFO): GPS fix at 20240426T161605: (36.802475, -121.786989) 2024-04-26T16:16:09.047Z,1714148169.047 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161608.00,A,3648.14848,N,12147.21929,W,0.058,0.00,260424,,,D*72 2024-04-26T16:16:09.049Z,1714148169.049 [NAL9602](INFO): GPS fix at 20240426T161608: (36.802475, -121.786988) 2024-04-26T16:16:11.873Z,1714148171.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161611.00,A,3648.14843,N,12147.21926,W,0.019,0.00,260424,,,D*7B 2024-04-26T16:16:11.875Z,1714148171.875 [NAL9602](INFO): GPS fix at 20240426T161611: (36.802474, -121.786988) 2024-04-26T16:16:14.296Z,1714148174.296 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:16:15.149Z,1714148175.149 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161614.00,A,3648.14833,N,12147.21936,W,0.039,0.00,260424,,,D*7A 2024-04-26T16:16:15.151Z,1714148175.151 [NAL9602](INFO): GPS fix at 20240426T161614: (36.802472, -121.786989) 2024-04-26T16:16:16.783Z,1714148176.783 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 3 Latitude: 36.802471 Longitude: -121.786987 2024-04-26T16:16:17.170Z,1714148177.170 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active. 2024-04-26T16:16:17.628Z,1714148177.628 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2024-04-26T16:16:17.629Z,1714148177.629 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2024-04-26T16:16:17.629Z,1714148177.629 [IBIT](IMPORTANT): Pressure:9.858236 PSI 2024-04-26T16:16:17.629Z,1714148177.629 [IBIT](IMPORTANT): Humidity:22.048590 % 2024-04-26T16:16:18.007Z,1714148178.007 [IBIT](IMPORTANT): Vehicle Pitch:1.218027 degrees 2024-04-26T16:16:18.007Z,1714148178.007 [IBIT](IMPORTANT): Vehicle Roll:-8.148192 degrees 2024-04-26T16:16:18.007Z,1714148178.007 [IBIT](IMPORTANT): Vehicle Heading:199.612946 degrees 2024-04-26T16:16:18.393Z,1714148178.393 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2024-04-26T16:16:18.394Z,1714148178.394 [IBIT](IMPORTANT): buoyancyNeutral: 150.000000 cc 2024-04-26T16:16:18.394Z,1714148178.394 [IBIT](IMPORTANT): massDefault: 1.240687 cm 2024-04-26T16:16:18.394Z,1714148178.394 [IBIT](IMPORTANT): stopDepth: 275.000000 m 2024-04-26T16:16:18.395Z,1714148178.395 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2024-04-26T16:16:18.395Z,1714148178.395 [IBIT](IMPORTANT): IBIT PASSED 2024-04-26T16:16:24.440Z,1714148184.440 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20240426T160414/Courier0004.lzma 2024-04-26T16:16:25.444Z,1714148185.444 [DataOverHttps](INFO): Moved sent file to Logs/20240426T160414/Courier0004.lzma.bak 2024-04-26T16:16:25.444Z,1714148185.444 [DataOverHttps](INFO): SBD MOMSN=19595952 2024-04-26T16:16:29.296Z,1714148189.296 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:16:39.003Z,1714148199.003 [CommandLine](INFO): End of History 2024-04-26T16:16:39.441Z,1714148199.441 [CommandLine](INFO): End of History 2024-04-26T16:16:39.442Z,1714148199.442 [CommandLine](INFO): End of History 2024-04-26T16:16:39.443Z,1714148199.443 [CommandLine](INFO): End of History 2024-04-26T16:16:39.525Z,1714148199.525 [CommandLine](INFO): End of History 2024-04-26T16:16:39.526Z,1714148199.526 [CommandLine](INFO): End of History 2024-04-26T16:16:39.526Z,1714148199.526 [CommandLine](INFO): End of History 2024-04-26T16:16:39.645Z,1714148199.645 [CommandLine](INFO): End of History 2024-04-26T16:16:39.646Z,1714148199.646 [CommandLine](INFO): End of History 2024-04-26T16:16:39.646Z,1714148199.646 [CommandLine](INFO): End of History 2024-04-26T16:16:44.241Z,1714148204.241 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:16:46.241Z,1714148206.241 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20240425T213440/Express0596.lzma 2024-04-26T16:16:47.242Z,1714148207.242 [DataOverHttps](INFO): Moved sent file to Logs/20240425T213440/Express0596.lzma.bak 2024-04-26T16:16:47.242Z,1714148207.242 [DataOverHttps](INFO): SBD MOMSN=19595955 2024-04-26T16:16:47.477Z,1714148207.477 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-26T16:16:58.783Z,1714148218.783 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:17:05.926Z,1714148225.926 [DataOverHttps](INFO): Sending 994 bytes from file Logs/20240426T160414/Express0001.lzma 2024-04-26T16:17:06.926Z,1714148226.926 [DataOverHttps](INFO): Moved sent file to Logs/20240426T160414/Express0001.lzma.bak 2024-04-26T16:17:06.926Z,1714148226.926 [DataOverHttps](INFO): SBD MOMSN=19595958 2024-04-26T16:17:13.804Z,1714148233.804 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-26T16:17:26.995Z,1714148246.995 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20240426T160414/Express0005.lzma 2024-04-26T16:17:27.998Z,1714148247.998 [DataOverHttps](INFO): Moved sent file to Logs/20240426T160414/Express0005.lzma.bak 2024-04-26T16:17:27.998Z,1714148247.998 [DataOverHttps](INFO): SBD MOMSN=19595980 2024-04-26T16:17:31.533Z,1714148251.533 [Default:CheckIn:Read_Iridium] Stopped 2024-04-26T16:17:31.533Z,1714148251.533 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-26T16:17:31.534Z,1714148251.534 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-26T16:18:47.265Z,1714148327.265 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2024-04-26T16:18:49.274Z,1714148329.274 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.784657 2024-04-26T16:19:16.820Z,1714148356.820 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002919 2024-04-26T16:22:32.164Z,1714148552.164 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-26T16:22:32.165Z,1714148552.165 [Default:CheckIn:C.Wait] Stopped 2024-04-26T16:22:32.165Z,1714148552.165 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-26T16:22:32.165Z,1714148552.165 [Default:CheckIn:D] Running Loop=1 2024-04-26T16:22:32.576Z,1714148552.576 [Default:CheckIn:D] Stopped 2024-04-26T16:22:32.576Z,1714148552.576 [Default:CheckIn:E] Running Loop=1 2024-04-26T16:22:32.973Z,1714148552.973 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.976376 min 2024-04-26T16:22:32.973Z,1714148552.973 [Default:CheckIn:E] Stopped 2024-04-26T16:22:32.974Z,1714148552.974 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-26T16:22:32.974Z,1714148552.974 [Default:CheckIn] Stopped 2024-04-26T16:22:32.974Z,1714148552.974 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-26T16:22:32.974Z,1714148552.974 [Default:CheckIn](INFO): Running loop #2 2024-04-26T16:22:32.974Z,1714148552.974 [Default:CheckIn] Running Loop=2 2024-04-26T16:22:32.974Z,1714148552.974 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-26T16:22:32.974Z,1714148552.974 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-26T16:22:34.995Z,1714148554.995 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162234.00,A,3648.14960,N,12147.22178,W,0.097,0.00,260424,,,D*7D 2024-04-26T16:22:34.998Z,1714148554.998 [NAL9602](INFO): GPS fix at 20240426T162234: (36.802493, -121.787030) 2024-04-26T16:22:35.010Z,1714148555.010 [Default:CheckIn:Read_GPS] Stopped 2024-04-26T16:22:35.010Z,1714148555.010 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-26T16:22:43.799Z,1714148563.799 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20240426T160414/Courier0007.lzma 2024-04-26T16:22:44.802Z,1714148564.802 [DataOverHttps](INFO): Moved sent file to Logs/20240426T160414/Courier0007.lzma.bak 2024-04-26T16:22:44.802Z,1714148564.802 [DataOverHttps](INFO): SBD MOMSN=19595994