2025-03-07T01:09:42.392Z,1741309782.392 [Supervisor](DEBUG): Initializing supervisor. 2025-03-07T01:09:42.396Z,1741309782.396 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2025-03-07T01:09:42.396Z,1741309782.396 [SyncHandler](INFO): Protected caller Thread ID is 838 2025-03-07T01:09:42.397Z,1741309782.397 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2025-03-07T01:09:42.398Z,1741309782.398 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2025-03-07T01:09:42.398Z,1741309782.398 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 839 2025-03-07T01:09:42.402Z,1741309782.402 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2025-03-07T01:09:42.421Z,1741309782.421 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2025-03-07T01:09:42.422Z,1741309782.422 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2025-03-07T01:09:42.423Z,1741309782.423 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 840 2025-03-07T01:09:42.427Z,1741309782.427 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2025-03-07T01:09:42.428Z,1741309782.428 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2025-03-07T01:09:42.428Z,1741309782.428 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 841 2025-03-07T01:09:42.430Z,1741309782.430 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2025-03-07T01:09:42.431Z,1741309782.431 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2025-03-07T01:09:42.432Z,1741309782.432 [logger ThreadHandler](INFO): Protected caller Thread ID is 842 2025-03-07T01:09:42.436Z,1741309782.436 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2025-03-07T01:09:42.436Z,1741309782.436 [Supervisor](INFO): Looking for Config files in directory: Config/ 2025-03-07T01:09:42.440Z,1741309782.440 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2025-03-07T01:09:42.666Z,1741309782.666 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2025-03-07T01:09:42.667Z,1741309782.667 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2025-03-07T01:09:42.783Z,1741309782.783 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2025-03-07T01:09:42.785Z,1741309782.785 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2025-03-07T01:09:42.892Z,1741309782.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2025-03-07T01:09:42.893Z,1741309782.893 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2025-03-07T01:09:43.417Z,1741309783.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2025-03-07T01:09:43.419Z,1741309783.419 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2025-03-07T01:09:43.786Z,1741309783.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2025-03-07T01:09:43.787Z,1741309783.787 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2025-03-07T01:09:44.149Z,1741309784.149 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2025-03-07T01:09:44.150Z,1741309784.150 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2025-03-07T01:09:44.352Z,1741309784.352 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2025-03-07T01:09:44.353Z,1741309784.353 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2025-03-07T01:09:44.443Z,1741309784.443 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2025-03-07T01:09:44.535Z,1741309784.535 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2025-03-07T01:09:44.965Z,1741309784.965 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2025-03-07T01:09:44.966Z,1741309784.966 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2025-03-07T01:09:45.280Z,1741309785.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2025-03-07T01:09:45.280Z,1741309785.280 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2025-03-07T01:09:45.862Z,1741309785.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2025-03-07T01:09:46.031Z,1741309786.031 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2025-03-07T01:09:46.538Z,1741309786.538 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2025-03-07T01:09:46.539Z,1741309786.539 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2025-03-07T01:09:46.847Z,1741309786.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2025-03-07T01:09:46.848Z,1741309786.848 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2025-03-07T01:09:46.999Z,1741309786.999 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2025-03-07T01:09:46.999Z,1741309786.999 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2025-03-07T01:09:47.906Z,1741309787.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2025-03-07T01:09:47.908Z,1741309787.908 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/ 2025-03-07T01:09:47.911Z,1741309787.911 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg 2025-03-07T01:09:48.007Z,1741309788.007 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg 2025-03-07T01:09:48.148Z,1741309788.148 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg 2025-03-07T01:09:48.424Z,1741309788.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2025-03-07T01:09:48.426Z,1741309788.426 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg 2025-03-07T01:09:48.562Z,1741309788.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg 2025-03-07T01:09:48.671Z,1741309788.671 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg 2025-03-07T01:09:48.775Z,1741309788.775 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg 2025-03-07T01:09:48.903Z,1741309788.903 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg 2025-03-07T01:09:48.997Z,1741309788.997 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg 2025-03-07T01:09:49.094Z,1741309789.094 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg 2025-03-07T01:09:49.198Z,1741309789.198 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg 2025-03-07T01:09:49.377Z,1741309789.377 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg 2025-03-07T01:09:49.395Z,1741309789.395 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2025-03-07T01:09:49.468Z,1741309789.468 [DepthRateCalculator] Loaded 2025-03-07T01:09:49.468Z,1741309789.468 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2025-03-07T01:09:49.474Z,1741309789.474 [PitchRateCalculator] Loaded 2025-03-07T01:09:49.474Z,1741309789.474 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2025-03-07T01:09:49.484Z,1741309789.484 [SpeedCalculator] Loaded 2025-03-07T01:09:49.485Z,1741309789.485 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2025-03-07T01:09:49.490Z,1741309789.490 [YawRateCalculator] Loaded 2025-03-07T01:09:49.490Z,1741309789.490 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2025-03-07T01:09:49.512Z,1741309789.512 [ElevatorOffsetCalculator] Loaded 2025-03-07T01:09:49.512Z,1741309789.512 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2025-03-07T01:09:49.513Z,1741309789.513 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2025-03-07T01:09:49.514Z,1741309789.514 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2025-03-07T01:09:49.562Z,1741309789.562 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2025-03-07T01:09:49.563Z,1741309789.563 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2025-03-07T01:09:49.579Z,1741309789.579 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2025-03-07T01:09:49.580Z,1741309789.580 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2025-03-07T01:09:50.481Z,1741309790.481 [AHRS_M2] Loaded 2025-03-07T01:09:50.481Z,1741309790.481 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2025-03-07T01:09:50.734Z,1741309790.734 [BackseatComponent] Loaded 2025-03-07T01:09:50.734Z,1741309790.734 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2025-03-07T01:09:50.735Z,1741309790.735 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408754E0 2025-03-07T01:09:50.736Z,1741309790.736 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925 2025-03-07T01:09:50.738Z,1741309790.738 [LcmUniversalReporter] Loaded 2025-03-07T01:09:50.739Z,1741309790.739 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2025-03-07T01:09:51.872Z,1741309791.872 [BPC1] Loaded 2025-03-07T01:09:51.872Z,1741309791.872 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2025-03-07T01:09:52.075Z,1741309792.075 [DataOverHttps] Loaded 2025-03-07T01:09:52.075Z,1741309792.075 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2025-03-07T01:09:52.076Z,1741309792.076 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408A54E0 2025-03-07T01:09:52.076Z,1741309792.076 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 927 2025-03-07T01:09:52.099Z,1741309792.099 [Depth_Keller] Loaded 2025-03-07T01:09:52.099Z,1741309792.099 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2025-03-07T01:09:52.104Z,1741309792.104 [DropWeight] Loaded 2025-03-07T01:09:52.104Z,1741309792.104 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2025-03-07T01:09:52.125Z,1741309792.125 [MultiRay] Loaded 2025-03-07T01:09:52.126Z,1741309792.126 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2025-03-07T01:09:52.194Z,1741309792.194 [NAL9602] Loaded 2025-03-07T01:09:52.194Z,1741309792.194 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2025-03-07T01:09:52.224Z,1741309792.224 [Onboard] Loaded 2025-03-07T01:09:52.224Z,1741309792.224 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2025-03-07T01:09:52.225Z,1741309792.225 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408D54E0 2025-03-07T01:09:52.226Z,1741309792.226 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 928 2025-03-07T01:09:52.232Z,1741309792.232 [PowerOnly] Loaded 2025-03-07T01:09:52.232Z,1741309792.232 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2025-03-07T01:09:52.246Z,1741309792.246 [Power24vConverter] Loaded 2025-03-07T01:09:52.246Z,1741309792.246 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2025-03-07T01:09:52.264Z,1741309792.264 [Radio_Surface] Loaded 2025-03-07T01:09:52.264Z,1741309792.264 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2025-03-07T01:09:52.265Z,1741309792.265 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409054E0 2025-03-07T01:09:52.266Z,1741309792.266 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 929 2025-03-07T01:09:52.291Z,1741309792.291 [Waterlinked] Loaded 2025-03-07T01:09:52.291Z,1741309792.291 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread. 2025-03-07T01:09:52.292Z,1741309792.292 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2025-03-07T01:09:52.293Z,1741309792.293 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2025-03-07T01:09:52.431Z,1741309792.431 [DeadReckonUsingMultipleVelocitySources] Loaded 2025-03-07T01:09:52.432Z,1741309792.432 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2025-03-07T01:09:52.445Z,1741309792.445 [NavChart] Loaded 2025-03-07T01:09:52.446Z,1741309792.446 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2025-03-07T01:09:52.451Z,1741309792.451 [UniversalFixResidualReporter] Loaded 2025-03-07T01:09:52.452Z,1741309792.452 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2025-03-07T01:09:52.452Z,1741309792.452 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2025-03-07T01:09:52.453Z,1741309792.453 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2025-03-07T01:09:52.653Z,1741309792.653 [SBIT](DEBUG): Construct Startup Built In Test. 2025-03-07T01:09:52.667Z,1741309792.667 [SBIT] Loaded 2025-03-07T01:09:52.668Z,1741309792.668 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2025-03-07T01:09:52.670Z,1741309792.670 [IBIT](DEBUG): Construct Initiated Built In Test. 2025-03-07T01:09:52.683Z,1741309792.683 [IBIT] Loaded 2025-03-07T01:09:52.684Z,1741309792.684 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2025-03-07T01:09:52.689Z,1741309792.689 [CBIT](DEBUG): Construct Continuous Built In Test. 2025-03-07T01:09:52.768Z,1741309792.768 [CBIT] Loaded 2025-03-07T01:09:52.769Z,1741309792.769 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2025-03-07T01:09:52.800Z,1741309792.800 [GFScanner] Loaded 2025-03-07T01:09:52.801Z,1741309792.801 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread. 2025-03-07T01:09:52.801Z,1741309792.801 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2025-03-07T01:09:52.802Z,1741309792.802 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2025-03-07T01:09:53.022Z,1741309793.022 [CTD_Seabird] Loaded 2025-03-07T01:09:53.022Z,1741309793.022 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2025-03-07T01:09:53.023Z,1741309793.023 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A174E0 2025-03-07T01:09:53.023Z,1741309793.023 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 930 2025-03-07T01:09:53.053Z,1741309793.053 [PAR_Licor] Loaded 2025-03-07T01:09:53.054Z,1741309793.054 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2025-03-07T01:09:53.100Z,1741309793.100 [WetLabsBB2FL] Loaded 2025-03-07T01:09:53.100Z,1741309793.100 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2025-03-07T01:09:53.101Z,1741309793.101 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A474E0 2025-03-07T01:09:53.102Z,1741309793.102 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 931 2025-03-07T01:09:53.103Z,1741309793.103 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2025-03-07T01:09:53.103Z,1741309793.103 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2025-03-07T01:09:53.274Z,1741309793.274 [BuoyancyServo] Loaded 2025-03-07T01:09:53.274Z,1741309793.274 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2025-03-07T01:09:53.298Z,1741309793.298 [ElevatorServo] Loaded 2025-03-07T01:09:53.299Z,1741309793.299 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2025-03-07T01:09:53.322Z,1741309793.322 [MassServo] Loaded 2025-03-07T01:09:53.322Z,1741309793.322 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2025-03-07T01:09:53.345Z,1741309793.345 [RudderServo] Loaded 2025-03-07T01:09:53.345Z,1741309793.345 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2025-03-07T01:09:53.363Z,1741309793.363 [ThrusterHE] Loaded 2025-03-07T01:09:53.364Z,1741309793.364 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2025-03-07T01:09:53.364Z,1741309793.364 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2025-03-07T01:09:53.365Z,1741309793.365 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2025-03-07T01:09:53.437Z,1741309793.437 [VerticalControl](DEBUG): Construct VerticalControl. 2025-03-07T01:09:53.490Z,1741309793.490 [VerticalControl] Loaded 2025-03-07T01:09:53.490Z,1741309793.490 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2025-03-07T01:09:53.493Z,1741309793.493 [HorizontalControl](DEBUG): Construct HorizontalControl. 2025-03-07T01:09:53.537Z,1741309793.537 [HorizontalControl] Loaded 2025-03-07T01:09:53.538Z,1741309793.538 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2025-03-07T01:09:53.540Z,1741309793.540 [SpeedControl](DEBUG): Construct SpeedControl. 2025-03-07T01:09:53.542Z,1741309793.542 [SpeedControl] Loaded 2025-03-07T01:09:53.542Z,1741309793.542 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2025-03-07T01:09:53.545Z,1741309793.545 [LoopControl](DEBUG): Construct LoopControl. 2025-03-07T01:09:53.545Z,1741309793.545 [LoopControl] Loaded 2025-03-07T01:09:53.546Z,1741309793.546 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2025-03-07T01:09:53.546Z,1741309793.546 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2025-03-07T01:09:53.547Z,1741309793.547 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2025-03-07T01:09:53.716Z,1741309793.716 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2025-03-07T01:09:53.716Z,1741309793.716 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2025-03-07T01:09:53.937Z,1741309793.937 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2025-03-07T01:09:53.938Z,1741309793.938 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2025-03-07T01:09:54.353Z,1741309794.353 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2025-03-07T01:09:54.354Z,1741309794.354 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2025-03-07T01:09:54.441Z,1741309794.441 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2025-03-07T01:09:54.447Z,1741309794.447 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2025-03-07T01:09:54.450Z,1741309794.450 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2025-03-07T01:09:54.461Z,1741309794.461 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2025-03-07T01:09:54.463Z,1741309794.463 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0 2025-03-07T01:09:54.463Z,1741309794.463 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 932 2025-03-07T01:09:54.467Z,1741309794.467 [Supervisor](INFO): Main Thread ID is 830 2025-03-07T01:09:54.467Z,1741309794.467 [Supervisor](DEBUG): Running supervisor. 2025-03-07T01:09:54.468Z,1741309794.468 [CommandExec ThreadHandler](INFO): Handler Thread ID is 933 2025-03-07T01:09:54.469Z,1741309794.469 [CommandExec](INFO): Initializing the command executive. 2025-03-07T01:09:54.470Z,1741309794.470 [CommandLine ThreadHandler](INFO): Handler Thread ID is 934 2025-03-07T01:09:54.472Z,1741309794.472 [controlThread ThreadHandler](INFO): Handler Thread ID is 935 2025-03-07T01:09:54.473Z,1741309794.473 [controlThread](DEBUG): Initializing ControlThread 2025-03-07T01:09:54.473Z,1741309794.473 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2025-03-07T01:09:54.474Z,1741309794.474 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2025-03-07T01:09:54.474Z,1741309794.474 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2025-03-07T01:09:54.475Z,1741309794.475 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2025-03-07T01:09:54.475Z,1741309794.475 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2025-03-07T01:09:54.481Z,1741309794.481 [NavChart](DEBUG): Initialize NavChart Navigation. 2025-03-07T01:09:54.481Z,1741309794.481 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2025-03-07T01:09:54.482Z,1741309794.482 [SBIT](INFO): Initialize SBIT Component. 2025-03-07T01:09:54.482Z,1741309794.482 [SBIT](IMPORTANT): git: 2025-03-06_B-3-g06c58acc0 2025-03-07T01:09:54.482Z,1741309794.482 [SBIT](INFO): git hash: 06c58acc0c21dac1722dadabfa9aaff283a6c1e9 2025-03-07T01:09:54.483Z,1741309794.483 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2025-03-07T01:09:54.484Z,1741309794.484 [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-03-07T01:09:54.485Z,1741309794.485 [SBIT](INFO): Beginning SBIT in 73.000000 seconds. 2025-03-07T01:09:54.485Z,1741309794.485 [IBIT](INFO): Initialize IBIT Component. 2025-03-07T01:09:54.487Z,1741309794.487 [CBIT](DEBUG): Initialize CBIT Component. 2025-03-07T01:09:54.487Z,1741309794.487 [logger ThreadHandler](INFO): Handler Thread ID is 936 2025-03-07T01:09:54.498Z,1741309794.498 [CBIT](DEBUG): Initialized mux pins. 2025-03-07T01:09:54.498Z,1741309794.498 [CBIT](DEBUG): Initializing the watchdog timer. 2025-03-07T01:09:54.507Z,1741309794.507 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2025-03-07T01:09:54.518Z,1741309794.518 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 938 2025-03-07T01:09:54.520Z,1741309794.520 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2025-03-07T01:09:54.522Z,1741309794.522 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2025-03-07T01:09:54.523Z,1741309794.523 [CBIT](DEBUG): Initializing heartbeat. 2025-03-07T01:09:54.531Z,1741309794.531 [Onboard ThreadHandler](INFO): Handler Thread ID is 939 2025-03-07T01:09:54.548Z,1741309794.548 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 940 2025-03-07T01:09:54.571Z,1741309794.571 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 941 2025-03-07T01:09:54.572Z,1741309794.572 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2025-03-07T01:09:54.576Z,1741309794.576 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 943 2025-03-07T01:09:54.579Z,1741309794.579 [WetLabsBB2FL](INFO): Powering up 2025-03-07T01:09:54.580Z,1741309794.580 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 945 2025-03-07T01:09:54.587Z,1741309794.587 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2025-03-07T01:09:54.587Z,1741309794.587 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2025-03-07T01:09:54.587Z,1741309794.587 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2025-03-07T01:09:54.588Z,1741309794.588 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2025-03-07T01:09:54.588Z,1741309794.588 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2025-03-07T01:09:54.588Z,1741309794.588 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2025-03-07T01:09:54.588Z,1741309794.588 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2025-03-07T01:09:54.588Z,1741309794.588 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2025-03-07T01:09:54.594Z,1741309794.594 [CBIT](DEBUG): Deactivating emergency mode. 2025-03-07T01:09:54.634Z,1741309794.634 [CBIT](DEBUG): Backplane powered. 2025-03-07T01:09:54.634Z,1741309794.634 [GFScanner](DEBUG): Initializing GFScanner 2025-03-07T01:09:54.634Z,1741309794.634 [GFScanner](DEBUG): Deactivating GF circuits. 2025-03-07T01:09:54.644Z,1741309794.644 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2025-03-07T01:09:54.645Z,1741309794.645 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2025-03-07T01:09:54.646Z,1741309794.646 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2025-03-07T01:09:54.647Z,1741309794.647 [LoopControl](DEBUG): Initialize LoopControlComponent. 2025-03-07T01:09:54.647Z,1741309794.647 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2025-03-07T01:09:54.648Z,1741309794.648 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2025-03-07T01:09:54.648Z,1741309794.648 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2025-03-07T01:09:54.651Z,1741309794.651 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2025-03-07T01:09:54.699Z,1741309794.699 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2025-03-07T01:09:54.723Z,1741309794.723 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2025-03-07T01:09:54.747Z,1741309794.747 [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-03-07T01:09:54.748Z,1741309794.748 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2025-03-07T01:09:54.748Z,1741309794.748 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2025-03-07T01:09:54.750Z,1741309794.750 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2025-03-07T01:09:54.949Z,1741309794.949 [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-03-07T01:09:54.954Z,1741309794.954 [Radio_Surface](INFO): Powering up 2025-03-07T01:09:54.964Z,1741309794.964 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2025-03-07T01:09:54.966Z,1741309794.966 [Default:A.Wait](DEBUG): Construct Wait. 2025-03-07T01:09:54.968Z,1741309794.968 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-03-07T01:09:54.997Z,1741309794.997 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2025-03-07T01:09:54.999Z,1741309794.999 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2025-03-07T01:09:55.017Z,1741309795.017 [Default:E.Execute](DEBUG): Construct Execute. 2025-03-07T01:09:55.021Z,1741309795.021 [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-03-07T01:09:55.033Z,1741309795.033 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,Waterlinked,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,GFScanner,LcmUniversalReporter,Reporter,LogSplitter, 2025-03-07T01:09:55.050Z,1741309795.050 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2025-03-07T01:09:55.193Z,1741309795.193 [MultiRay](INFO): Powering up MultiRay Lights 2025-03-07T01:09:55.207Z,1741309795.207 [Power24vConverter](INFO): Powering up. 2025-03-07T01:09:55.245Z,1741309795.245 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2025-03-07T01:09:55.250Z,1741309795.250 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2025-03-07T01:09:55.251Z,1741309795.251 [ElevatorServo](DEBUG): Initializing EZServoServo. 2025-03-07T01:09:55.258Z,1741309795.258 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2025-03-07T01:09:55.259Z,1741309795.259 [MassServo](DEBUG): Initializing EZServoServo. 2025-03-07T01:09:55.266Z,1741309795.266 [MassServo](DEBUG): Initializing MassServo. 2025-03-07T01:09:55.267Z,1741309795.267 [RudderServo](DEBUG): Initializing EZServoServo. 2025-03-07T01:09:55.275Z,1741309795.275 [RudderServo](DEBUG): Initializing RudderServo. 2025-03-07T01:09:55.275Z,1741309795.275 [ThrusterHE](DEBUG): Initializing EZServoServo. 2025-03-07T01:09:55.282Z,1741309795.282 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2025-03-07T01:09:55.491Z,1741309795.491 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2025-03-07T01:09:55.491Z,1741309795.491 [DropWeight] Hardware Fault, FailCount= 1 2025-03-07T01:09:55.491Z,1741309795.491 [DropWeight](ERROR): Hardware Fault 2025-03-07T01:09:55.546Z,1741309795.546 [CommandExec](FAULT): Scheduling is paused 2025-03-07T01:09:55.546Z,1741309795.546 [CBIT](INFO): Critical error at 20250307T010955 2025-03-07T01:09:55.547Z,1741309795.547 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2025-03-07T01:09:55.549Z,1741309795.549 [CBIT](ERROR): Hardware Fault in component: DropWeight 2025-03-07T01:09:55.550Z,1741309795.550 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2025-03-07T01:09:55.875Z,1741309795.875 [CBIT](INFO): Critical error at 20250307T010955 2025-03-07T01:09:57.190Z,1741309797.190 [WetLabsBB2FL](INFO): Powering down 2025-03-07T01:10:01.043Z,1741309801.043 [ThrusterHE](ERROR): Zero Speed Commanded. 2025-03-07T01:10:01.603Z,1741309801.603 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2025-03-07T01:10:22.523Z,1741309822.523 [NAL9602](INFO): Powering up NAL9602 2025-03-07T01:10:32.310Z,1741309832.310 [Waterlinked](INFO): Powering down 2025-03-07T01:10:33.436Z,1741309833.436 [NAL9602](INFO): NAL9602 initialized 2025-03-07T01:11:08.219Z,1741309868.219 [SBIT](IMPORTANT): Beginning Startup BIT 2025-03-07T01:11:08.223Z,1741309868.223 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-03-07T01:11:12.751Z,1741309872.751 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.022537 CHAN A1 (24V): 0.043216 CHAN A2 (12V): -0.005349 CHAN A3 (5V): -0.003211 CHAN B0 (3.3V): -0.001219 CHAN B1 (3.15aV): -0.000551 CHAN B2 (3.15bV): -0.000808 CHAN B3 (GND): -0.000660 OPEN: 0.005008 Full Scale: +/- 1 mA 2025-03-07T01:12:02.680Z,1741309922.680 [SBIT](IMPORTANT): SBIT PASSED 2025-03-07T01:12:02.681Z,1741309922.681 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2025-03-07T01:12:02.697Z,1741309922.697 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool; 2025-03-07T01:12:02.698Z,1741309922.698 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool; 2025-03-07T01:12:02.702Z,1741309922.702 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool; 2025-03-07T01:12:02.703Z,1741309922.703 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter; 2025-03-07T01:12:02.704Z,1741309922.704 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 15.000000 meter; 2025-03-07T01:12:02.704Z,1741309922.704 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 10.000000 meter; 2025-03-07T01:12:02.705Z,1741309922.705 [SBIT](IMPORTANT): GFScanner.loadAtStartup=1 bool; 2025-03-07T01:12:02.706Z,1741309922.706 [SBIT](IMPORTANT): GFScanner.simulateHardware=0 bool; 2025-03-07T01:12:02.715Z,1741309922.715 [SBIT](IMPORTANT): MultiRay.loadAtStartup=1 bool; 2025-03-07T01:12:02.715Z,1741309922.715 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=1 bool; 2025-03-07T01:12:02.716Z,1741309922.716 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=0 bool; 2025-03-07T01:12:02.717Z,1741309922.717 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=185.902950 cubic_centimeter; 2025-03-07T01:12:02.717Z,1741309922.717 [SBIT](IMPORTANT): VerticalControl.massDefault=13.432478 millimeter; 2025-03-07T01:12:03.169Z,1741309923.169 [MissionManager](IMPORTANT): Started mission Startup 2025-03-07T01:12:03.175Z,1741309923.175 [Startup] Running Loop=1 2025-03-07T01:12:03.176Z,1741309923.176 [Startup](DEBUG): Aggregate::initialize Startup 2025-03-07T01:12:03.176Z,1741309923.176 [Startup:A.GoToSurface] Running Loop=1 2025-03-07T01:12:03.176Z,1741309923.176 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-03-07T01:12:03.184Z,1741309923.184 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-03-07T01:12:03.199Z,1741309923.199 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-03-07T01:12:03.200Z,1741309923.200 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-03-07T01:12:03.231Z,1741309923.231 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-03-07T01:12:03.232Z,1741309923.232 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-03-07T01:12:03.234Z,1741309923.234 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-03-07T01:12:03.296Z,1741309923.296 [Startup:StartupSatComms] Running Loop=1 2025-03-07T01:12:03.296Z,1741309923.296 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2025-03-07T01:12:03.297Z,1741309923.297 [Startup:StartupSatComms:A] Running Loop=1 2025-03-07T01:12:03.568Z,1741309923.568 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2025-03-07T01:12:22.509Z,1741309942.509 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005473 2025-03-07T01:12:54.776Z,1741309974.776 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2025-03-07T01:12:54.776Z,1741309974.776 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-07T01:12:54.811Z,1741309974.811 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-07T01:12:55.200Z,1741309975.200 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-07T01:12:55.200Z,1741309975.200 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2025-03-07T01:13:03.312Z,1741309983.312 [Startup:StartupSatComms:A](INFO): Timed out from 2025-03-07T01:12:03.3Z 2025-03-07T01:13:03.312Z,1741309983.312 [Startup:StartupSatComms:A] Stopped 2025-03-07T01:13:03.312Z,1741309983.312 [Startup:StartupSatComms:B] Running Loop=1 2025-03-07T01:13:03.709Z,1741309983.709 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-03-07T01:13:10.239Z,1741309990.239 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250307T004115/Courier0007.lzma 2025-03-07T01:13:11.240Z,1741309991.240 [DataOverHttps](INFO): Moved sent file to Logs/20250307T004115/Courier0007.lzma.bak 2025-03-07T01:13:11.240Z,1741309991.240 [DataOverHttps](INFO): SBD MOMSN=24136989 2025-03-07T01:13:28.007Z,1741310008.007 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20250307T010942/Courier0000.lzma 2025-03-07T01:13:29.008Z,1741310009.008 [DataOverHttps](INFO): Moved sent file to Logs/20250307T010942/Courier0000.lzma.bak 2025-03-07T01:13:29.008Z,1741310009.008 [DataOverHttps](INFO): SBD MOMSN=24136991 2025-03-07T01:13:44.884Z,1741310024.884 [DataOverHttps](INFO): Sending 267 bytes from file Logs/20250307T004115/Express0008.lzma 2025-03-07T01:13:45.884Z,1741310025.884 [DataOverHttps](INFO): Moved sent file to Logs/20250307T004115/Express0008.lzma.bak 2025-03-07T01:13:45.884Z,1741310025.884 [DataOverHttps](INFO): SBD MOMSN=24136996 2025-03-07T01:14:03.550Z,1741310043.550 [Startup:StartupSatComms:B](INFO): Timed out from 2025-03-07T01:13:03.3Z 2025-03-07T01:14:03.551Z,1741310043.551 [Startup:StartupSatComms:B] Stopped 2025-03-07T01:14:03.551Z,1741310043.551 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2025-03-07T01:14:03.551Z,1741310043.551 [Startup:StartupSatComms] Stopped 2025-03-07T01:14:03.551Z,1741310043.551 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2025-03-07T01:14:03.552Z,1741310043.552 [Startup](INFO): Completed Startup 2025-03-07T01:14:03.552Z,1741310043.552 [MissionManager](INFO): Startup is completed. 2025-03-07T01:14:03.552Z,1741310043.552 [MissionManager](INFO): Uninitializing Mission Startup 2025-03-07T01:14:03.552Z,1741310043.552 [Startup] Stopped 2025-03-07T01:14:03.552Z,1741310043.552 [Startup](DEBUG): Aggregate::uninitialize Startup 2025-03-07T01:14:03.552Z,1741310043.552 [Startup:A.GoToSurface] Stopped 2025-03-07T01:14:03.553Z,1741310043.553 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-03-07T01:14:03.934Z,1741310043.934 [MissionManager](IMPORTANT): Started mission Default 2025-03-07T01:14:03.934Z,1741310043.934 [Default] Running Loop=1 2025-03-07T01:14:03.934Z,1741310043.934 [Default](DEBUG): Aggregate::initialize Default 2025-03-07T01:14:03.934Z,1741310043.934 [Default:B.GoToSurface] Running Loop=1 2025-03-07T01:14:03.935Z,1741310043.935 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-03-07T01:14:03.935Z,1741310043.935 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-03-07T01:14:03.935Z,1741310043.935 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-03-07T01:14:03.935Z,1741310043.935 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-03-07T01:14:03.936Z,1741310043.936 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-03-07T01:14:03.936Z,1741310043.936 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-03-07T01:14:03.936Z,1741310043.936 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-03-07T01:14:03.937Z,1741310043.937 [Default:A.Wait] Running Loop=1 2025-03-07T01:14:03.937Z,1741310043.937 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-03-07T01:14:06.644Z,1741310046.644 [DataOverHttps](INFO): Sending 954 bytes from file Logs/20250307T010942/Express0001.lzma 2025-03-07T01:14:07.644Z,1741310047.644 [DataOverHttps](INFO): Moved sent file to Logs/20250307T010942/Express0001.lzma.bak 2025-03-07T01:14:07.644Z,1741310047.644 [DataOverHttps](INFO): SBD MOMSN=24137002 2025-03-07T01:14:17.267Z,1741310057.267 [Default:A.Wait](INFO): Done Waiting. 2025-03-07T01:14:17.267Z,1741310057.267 [Default:A.Wait] Stopped 2025-03-07T01:14:17.267Z,1741310057.267 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-03-07T01:14:17.685Z,1741310057.685 [Default:CheckIn] Running Loop=1 2025-03-07T01:14:17.685Z,1741310057.685 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2025-03-07T01:14:17.685Z,1741310057.685 [Default:CheckIn:Read_GPS] Running Loop=1 2025-03-07T01:14:18.057Z,1741310058.057 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-03-07T01:15:36.296Z,1741310136.296 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-03-07T01:15:55.695Z,1741310155.695 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2025-03-07T01:15:55.695Z,1741310155.695 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2025-03-07T01:15:55.705Z,1741310155.705 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2025-03-07T01:15:56.113Z,1741310156.113 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2025-03-07T01:15:56.113Z,1741310156.113 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2025-03-07T01:15:58.516Z,1741310158.516 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 5. 2025-03-07T01:15:58.519Z,1741310158.519 [BPC1](INFO): Received data from all battery sticks. 2025-03-07T01:17:18.484Z,1741310238.484 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/lab_test_optim.tl 2025-03-07T01:17:18.484Z,1741310238.484 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/lab_test_optim.tl 2025-03-07T01:17:18.485Z,1741310238.485 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/lab_test_optim.tl 2025-03-07T01:17:18.488Z,1741310238.488 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/lab_test_optim.tl 2025-03-07T01:17:19.056Z,1741310239.056 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/lab_test_optim.tl translated into: 15 1 30 1 3 2 100 100 0 Waiting for backseat to start up... Disabling Optim recording after Powering up Optim to try to tide over gap to handoff... ! echo 1 > /dev/loadC3 Optim power on. Spinning for cycles. 1 ! echo 0 > /dev/loadC3 Optim power off. Spinning again. 1 ! echo 1 > /dev/loadC3 Optim power on. Handing off to mission. ! echo 1 > /dev/loadC3; sleep 1; echo 0 > /dev/loadC3; sleep 1; echo 1 > dev/loadC3 Hardcoded Optim command sent. Good luck. Trying to run Optim and Multiray forreal 1 Setting multiray red brightness to 2 Setting muliray white brightness to Recording for 2025-03-07T01:17:19.064Z,1741310239.064 [MissionManager](INFO): DefineArg lab_test_optim.MissionTimeout = 15.000000 min 2025-03-07T01:17:19.067Z,1741310239.067 [MissionManager](INFO): DefineArg lab_test_optim.RecordTime = 1.000000 min 2025-03-07T01:17:19.071Z,1741310239.071 [MissionManager](INFO): DefineArg lab_test_optim.BackseatWait = 30.000000 s 2025-03-07T01:17:19.073Z,1741310239.073 [MissionManager](INFO): DefineArg lab_test_optim.UseMission = 1 bool 2025-03-07T01:17:19.105Z,1741310239.105 [MissionManager](INFO): DefineArg lab_test_optim.UseHardcode = 0 bool 2025-03-07T01:17:19.112Z,1741310239.112 [MissionManager](INFO): DefineArg lab_test_optim.InitialSampleTime = 1.000000 s 2025-03-07T01:17:19.115Z,1741310239.115 [MissionManager](INFO): DefineArg lab_test_optim.SleepCycles = 3.000000 count 2025-03-07T01:17:19.121Z,1741310239.121 [MissionManager](INFO): DefineArg lab_test_optim.LightMode = 2.000000 count 2025-03-07T01:17:19.127Z,1741310239.127 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessWhite = 100.000000 n/a int32 2025-03-07T01:17:19.131Z,1741310239.131 [MissionManager](INFO): DefineArg lab_test_optim.BrightnessRed = 100.000000 n/a int32 2025-03-07T01:17:19.134Z,1741310239.134 [MissionManager](INFO): DefineOutput lab_test_optim.CyclesWaited = 0.000000 count 2025-03-07T01:17:19.137Z,1741310239.137 [MissionManager](INFO): DefineOutput lab_test_optim.RecordingEnabled = 0 bool 2025-03-07T01:17:19.140Z,1741310239.140 [MissionManager](INFO): DefineOutput lab_test_optim.LightsEnabled = 0 bool 2025-03-07T01:17:19.140Z,1741310239.140 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-03-07T01:17:19.140Z,1741310239.140 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-03-07T01:17:19.141Z,1741310239.141 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-03-07T01:17:19.209Z,1741310239.209 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-03-07T01:17:19.213Z,1741310239.213 [MissionManager](INFO): DefineArg lab_test_optim:BackseatDriver.EnableBackseat = 0 bool 2025-03-07T01:17:19.216Z,1741310239.216 [lab_test_optim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-03-07T01:17:19.248Z,1741310239.248 [lab_test_optim:Startup:B.Wait](DEBUG): Construct Wait. 2025-03-07T01:17:19.273Z,1741310239.273 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Construct Wait. 2025-03-07T01:17:19.291Z,1741310239.291 [lab_test_optim:Startup:UseBackdoor:A.Execute](DEBUG): Construct Execute. 2025-03-07T01:17:19.296Z,1741310239.296 [lab_test_optim:Startup:UseBackdoor:D.Execute](DEBUG): Construct Execute. 2025-03-07T01:17:19.326Z,1741310239.326 [lab_test_optim:Startup:UseBackdoor:G.Execute](DEBUG): Construct Execute. 2025-03-07T01:17:19.346Z,1741310239.346 [lab_test_optim:Startup:UseHardcode:A.Execute](DEBUG): Construct Execute. 2025-03-07T01:17:19.422Z,1741310239.422 [lab_test_optim:Run:H.Wait](DEBUG): Construct Wait. 2025-03-07T01:17:19.424Z,1741310239.424 [lab_test_optim:G.Wait](DEBUG): Construct Wait. 2025-03-07T01:17:19.453Z,1741310239.453 [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 lab_test_optim { arguments { MissionTimeout = 15 minute """ Backseat will stay on for this duration, independent of Optim state """ RecordTime = 1 minute """ How long to record after startup sequence (hopefully) turns on Optim camera """ BackseatWait = 30 second """ How long to wait for the backseat to power up before attempting to power the Optim """ UseMission = true """ If true, tries to go through the application and use components/behaviors for commands. Set InitialSampleTime to change delays. If false, backdoors app. Use SleepCycles to change delays. Optim must be on C3. """ UseHardcode = false """ If true, backdoors app with a powercycle and a hardcoded sleep 1. Try the two other modes first? Optim must be on C3. """ InitialSampleTime = 1 second """ PowerOnly sample time for initial record. Will go back to continuous after startup. """ SleepCycles = 3 count """ How many vehicle computation cycles to wait before commanding the Optim off on initial record """ LightMode = 2 count """ Mode for Multiray lights. 0 is off, 1 is red, 2 is white """ BrightnessWhite = 100 none_int """ White Multiray LED brightness, 0-100 """ BrightnessRed = 100 none_int """ Red Multiray LED brightness, 0-100 """ } output { CyclesWaited = 0 count RecordingEnabled = false LightsEnabled = false } timeout duration=MissionTimeout insert Insert/BackseatDriver.tl assign in parallel BackseatDriver:EnableBackseat = true readData strategy="MinError" { while ( RecordingEnabled ) Sensor:PowerOnly.samplePowerOnly } readData strategy="MinError" { while ( LightsEnabled ) Sensor:MultiRay.lightModeLog } aggregate Startup { run in sequence syslog important "Waiting " + BackseatWait~s + " for backseat to start up..." behavior Guidance:Wait { run in sequence set duration = BackseatWait } aggregate UseMission { run in sequence break if ( not UseMission or UseHardcode ) assign in parallel Sensor:PowerOnly.sampleTime1 = InitialSampleTime assign in sequence RecordingEnabled = true syslog important "Disabling Optim recording after " + InitialSampleTime~s assign in sequence RecordingEnabled = false behavior Guidance:Wait { run in sequence set duration = InitialSampleTime } assign in sequence RecordingEnabled = true syslog important "Powering up Optim to try to tide over gap to handoff..." } aggregate UseBackdoor { run in sequence break if ( UseMission or UseHardcode ) behavior Guidance:Execute { run in sequence set command = "! echo 1 > /dev/loadC3" } syslog important "Optim power on. Spinning for " + SleepCycles~count + " cycles." aggregate WaitForStop { run in sequence repeat=SleepCycles assign in sequence CyclesWaited = CyclesWaited + 1 count } behavior Guidance:Execute { run in sequence set command = "! echo 0 > /dev/loadC3" } syslog important "Optim power off. Spinning again." aggregate WaitForStart { run in sequence repeat=SleepCycles assign in sequence CyclesWaited = CyclesWaited + 1 count } behavior Guidance:Execute { run in sequence set command = "! echo 1 > /dev/loadC3" } syslog important "Optim power on. Handing off to mission." } aggregate UseHardcode { run in sequence break if ( not UseHardcode ) behavior Guidance:Execute { run in sequence set command = "! echo 1 > /dev/loadC3; sleep 1; echo 0 > /dev/loadC3; sleep 1; echo 1 > dev/loadC3" } syslog important "Hardcoded Optim command sent. Good luck." } } aggregate Run { run in sequence syslog important "Trying to run Optim and Multiray forreal" assign in sequence RecordingEnabled = true assign in sequence LightsEnabled = true assign in sequence Sensor:MultiRay.lightModeCommand = LightMode aggregate setRed { run in sequence break if ( LightMode != 1 count ) assign in sequence Sensor:MultiRay.brightnessRed = BrightnessRed syslog info "Setting multiray red brightness to" + BrightnessRed~count } aggregate setWhite { run in sequence break if ( LightMode != 2 count ) assign in sequence Sensor:MultiRay.brightnessWhite = BrightnessWhite syslog info "Setting muliray white brightness to" + BrightnessWhite~count } syslog important "Recording for " + RecordTime~min behavior Guidance:Wait { run in sequence set duration = RecordTime } } behavior Guidance:Wait { run in sequence set duration = MissionTimeout } } 2025-03-07T01:17:19.465Z,1741310239.465 [CommandExec](IMPORTANT): Running ./Missions/Engineering/lab_test_optim.tl 2025-03-07T01:17:19.735Z,1741310239.735 [Default] Stopped 2025-03-07T01:17:19.735Z,1741310239.735 [Default](DEBUG): Aggregate::uninitialize Default 2025-03-07T01:17:19.735Z,1741310239.735 [Default:B.GoToSurface] Stopped 2025-03-07T01:17:19.735Z,1741310239.735 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-03-07T01:17:19.735Z,1741310239.735 [Default:CheckIn] Stopped 2025-03-07T01:17:19.735Z,1741310239.735 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2025-03-07T01:17:19.735Z,1741310239.735 [Default:CheckIn:Read_GPS] Stopped 2025-03-07T01:17:19.736Z,1741310239.736 [MissionManager](IMPORTANT): Started mission lab_test_optim 2025-03-07T01:17:19.736Z,1741310239.736 [lab_test_optim] Running Loop=1 2025-03-07T01:17:19.736Z,1741310239.736 [lab_test_optim](DEBUG): Aggregate::initialize lab_test_optim 2025-03-07T01:17:19.736Z,1741310239.736 [lab_test_optim:BackseatDriver] Running Loop=1 2025-03-07T01:17:19.736Z,1741310239.736 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::initialize lab_test_optim:BackseatDriver 2025-03-07T01:17:19.736Z,1741310239.736 [lab_test_optim:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-03-07T01:17:19.736Z,1741310239.736 [lab_test_optim:B] Running Loop=1 2025-03-07T01:17:19.736Z,1741310239.736 [lab_test_optim:C] Running Loop=1 2025-03-07T01:17:19.737Z,1741310239.737 [lab_test_optim:D] Running Loop=1 2025-03-07T01:17:19.737Z,1741310239.737 [lab_test_optim:Startup] Running Loop=1 2025-03-07T01:17:19.737Z,1741310239.737 [lab_test_optim:Startup](DEBUG): Aggregate::initialize lab_test_optim:Startup 2025-03-07T01:17:19.737Z,1741310239.737 [lab_test_optim:Startup:A] Running Loop=1 2025-03-07T01:17:19.738Z,1741310239.738 [lab_test_optim:Startup:A](IMPORTANT): Waiting 30.000000 s for backseat to start up... 2025-03-07T01:17:19.738Z,1741310239.738 [lab_test_optim:Startup:A] Stopped 2025-03-07T01:17:19.738Z,1741310239.738 [lab_test_optim:Startup:B.Wait] Running Loop=1 2025-03-07T01:17:19.738Z,1741310239.738 [lab_test_optim:Startup:B.Wait](DEBUG): Initialize Wait Component. 2025-03-07T01:17:19.738Z,1741310239.738 [lab_test_optim:D] Stopped 2025-03-07T01:17:19.738Z,1741310239.738 [lab_test_optim:C] Stopped 2025-03-07T01:17:19.738Z,1741310239.738 [lab_test_optim:B] Running Loop=1 2025-03-07T01:17:19.739Z,1741310239.739 [lab_test_optim:BackseatDriver] Running Loop=1 2025-03-07T01:17:19.739Z,1741310239.739 [lab_test_optim:BackseatDriver:A.BackseatDriver](INFO): Initializing backseat 2025-03-07T01:17:19.880Z,1741310239.880 [BackseatComponent](INFO): Powering up 2025-03-07T01:17:19.881Z,1741310239.881 [BackseatComponent](INFO): Subscribing to LCM channels. 2025-03-07T01:17:32.981Z,1741310252.981 [CommandExec](IMPORTANT): got command get PowerOnly.loadControl 2025-03-07T01:17:32.981Z,1741310252.981 [CommandExec](IMPORTANT): PowerOnly.loadControl /dev/null 2025-03-07T01:17:45.260Z,1741310265.260 [CommandExec](IMPORTANT): got command show variable poweronly 2025-03-07T01:17:45.293Z,1741310265.293 [CommandExec](IMPORTANT): PowerOnly.loadControl (none) 2025-03-07T01:17:45.293Z,1741310265.293 [CommandExec](IMPORTANT): PowerOnly.loadControl2 (none) 2025-03-07T01:17:45.294Z,1741310265.294 [CommandExec](IMPORTANT): PowerOnly.loadControl3 (none) 2025-03-07T01:17:45.402Z,1741310265.402 [CommandExec](IMPORTANT): PowerOnly.loadAtStartup (bool) 2025-03-07T01:17:45.402Z,1741310265.402 [CommandExec](IMPORTANT): PowerOnly.simulateHardware (bool) 2025-03-07T01:17:45.403Z,1741310265.403 [CommandExec](IMPORTANT): PowerOnly.sampleTime (second) 2025-03-07T01:17:45.403Z,1741310265.403 [CommandExec](IMPORTANT): PowerOnly.sampleTime1 (second) 2025-03-07T01:17:45.403Z,1741310265.403 [CommandExec](IMPORTANT): PowerOnly.sampleTime2 (second) 2025-03-07T01:17:45.404Z,1741310265.404 [CommandExec](IMPORTANT): PowerOnly.sampleTime3 (second) 2025-03-07T01:17:45.523Z,1741310265.523 [CommandExec](IMPORTANT): PowerOnly.enableBroadcast (bool) 2025-03-07T01:17:45.524Z,1741310265.524 [CommandExec](IMPORTANT): PowerOnly.samplePowerOnly (bool) 2025-03-07T01:17:50.436Z,1741310270.436 [lab_test_optim:Startup:B.Wait](INFO): Done Waiting. 2025-03-07T01:17:50.436Z,1741310270.436 [lab_test_optim:Startup:B.Wait] Stopped 2025-03-07T01:17:50.436Z,1741310270.436 [lab_test_optim:Startup:B.Wait](DEBUG): Uninitialize Wait Component. 2025-03-07T01:17:50.436Z,1741310270.436 [lab_test_optim:Startup:UseMission] Running Loop=1 2025-03-07T01:17:50.436Z,1741310270.436 [lab_test_optim:Startup:UseMission](DEBUG): Aggregate::initialize lab_test_optim:Startup:UseMission 2025-03-07T01:17:50.436Z,1741310270.436 [lab_test_optim:Startup:UseMission:A] Running Loop=1 2025-03-07T01:17:50.436Z,1741310270.436 [lab_test_optim:Startup:UseMission:B] Running Loop=1 2025-03-07T01:17:50.848Z,1741310270.848 [lab_test_optim:Startup:UseMission:B] Stopped 2025-03-07T01:17:50.848Z,1741310270.848 [lab_test_optim:Startup:UseMission:C] Running Loop=1 2025-03-07T01:17:50.848Z,1741310270.848 [lab_test_optim:Startup:UseMission:A] Running Loop=1 2025-03-07T01:17:51.244Z,1741310271.244 [lab_test_optim:Startup:UseMission:C](IMPORTANT): Disabling Optim recording after 1.000000 s 2025-03-07T01:17:51.244Z,1741310271.244 [lab_test_optim:Startup:UseMission:C] Stopped 2025-03-07T01:17:51.244Z,1741310271.244 [lab_test_optim:Startup:UseMission:D] Running Loop=1 2025-03-07T01:17:51.245Z,1741310271.245 [lab_test_optim:C] Running Loop=1 2025-03-07T01:17:51.245Z,1741310271.245 [lab_test_optim:C] Running Loop=1 2025-03-07T01:17:51.245Z,1741310271.245 [lab_test_optim:C](DEBUG): Initialize ReadDataComponent to sense PowerOnly.samplePowerOnly 2025-03-07T01:17:51.665Z,1741310271.665 [lab_test_optim:Startup:UseMission:D] Stopped 2025-03-07T01:17:51.665Z,1741310271.665 [lab_test_optim:Startup:UseMission:E.Wait] Running Loop=1 2025-03-07T01:17:51.665Z,1741310271.665 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Initialize Wait Component. 2025-03-07T01:17:52.070Z,1741310272.070 [lab_test_optim:C] Stopped 2025-03-07T01:17:53.268Z,1741310273.268 [lab_test_optim:Startup:UseMission:E.Wait](INFO): Done Waiting. 2025-03-07T01:17:53.268Z,1741310273.268 [lab_test_optim:Startup:UseMission:E.Wait] Stopped 2025-03-07T01:17:53.268Z,1741310273.268 [lab_test_optim:Startup:UseMission:E.Wait](DEBUG): Uninitialize Wait Component. 2025-03-07T01:17:53.268Z,1741310273.268 [lab_test_optim:Startup:UseMission:F] Running Loop=1 2025-03-07T01:17:53.671Z,1741310273.671 [lab_test_optim:Startup:UseMission:F] Stopped 2025-03-07T01:17:53.671Z,1741310273.671 [lab_test_optim:Startup:UseMission:G] Running Loop=1 2025-03-07T01:17:54.084Z,1741310274.084 [lab_test_optim:Startup:UseMission:G](IMPORTANT): Powering up Optim to try to tide over gap to handoff... 2025-03-07T01:17:54.084Z,1741310274.084 [lab_test_optim:Startup:UseMission:G] Stopped 2025-03-07T01:17:54.085Z,1741310274.085 [lab_test_optim:Startup:UseMission](INFO): Completed lab_test_optim:Startup:UseMission 2025-03-07T01:17:54.085Z,1741310274.085 [lab_test_optim:Startup:UseMission] Stopped 2025-03-07T01:17:54.085Z,1741310274.085 [lab_test_optim:Startup:UseMission](DEBUG): Aggregate::uninitialize lab_test_optim:Startup:UseMission 2025-03-07T01:17:54.085Z,1741310274.085 [lab_test_optim:Startup:UseMission:A] Stopped 2025-03-07T01:17:54.085Z,1741310274.085 [lab_test_optim:Startup:UseBackdoor] Running Loop=1 2025-03-07T01:17:54.085Z,1741310274.085 [lab_test_optim:Startup:UseBackdoor](DEBUG): Aggregate::initialize lab_test_optim:Startup:UseBackdoor 2025-03-07T01:17:54.085Z,1741310274.085 [lab_test_optim:Startup:UseBackdoor:A.Execute] Running Loop=1 2025-03-07T01:17:54.086Z,1741310274.086 [lab_test_optim:C] Running Loop=1 2025-03-07T01:17:54.500Z,1741310274.500 [lab_test_optim:Startup:UseBackdoor] Stopped 2025-03-07T01:17:54.500Z,1741310274.500 [lab_test_optim:Startup:UseBackdoor](DEBUG): Aggregate::uninitialize lab_test_optim:Startup:UseBackdoor 2025-03-07T01:17:54.500Z,1741310274.500 [lab_test_optim:Startup:UseBackdoor:A.Execute] Stopped 2025-03-07T01:17:54.500Z,1741310274.500 [lab_test_optim:Startup:UseHardcode] Running Loop=1 2025-03-07T01:17:54.501Z,1741310274.501 [lab_test_optim:Startup:UseHardcode](DEBUG): Aggregate::initialize lab_test_optim:Startup:UseHardcode 2025-03-07T01:17:54.501Z,1741310274.501 [lab_test_optim:Startup:UseHardcode:A.Execute] Running Loop=1 2025-03-07T01:17:54.900Z,1741310274.900 [lab_test_optim:Startup:UseHardcode] Stopped 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Startup:UseHardcode](DEBUG): Aggregate::uninitialize lab_test_optim:Startup:UseHardcode 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Startup:UseHardcode:A.Execute] Stopped 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Startup](INFO): Completed lab_test_optim:Startup 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Startup] Stopped 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Startup](DEBUG): Aggregate::uninitialize lab_test_optim:Startup 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Run] Running Loop=1 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Run](DEBUG): Aggregate::initialize lab_test_optim:Run 2025-03-07T01:17:54.901Z,1741310274.901 [lab_test_optim:Run:A] Running Loop=1 2025-03-07T01:17:55.304Z,1741310275.304 [lab_test_optim:Run:A](IMPORTANT): Trying to run Optim and Multiray forreal 2025-03-07T01:17:55.304Z,1741310275.304 [lab_test_optim:Run:A] Stopped 2025-03-07T01:17:55.305Z,1741310275.305 [lab_test_optim:Run:B] Running Loop=1 2025-03-07T01:17:55.688Z,1741310275.688 [lab_test_optim:Run:B] Stopped 2025-03-07T01:17:55.688Z,1741310275.688 [lab_test_optim:Run:C] Running Loop=1 2025-03-07T01:17:56.092Z,1741310276.092 [lab_test_optim:Run:C] Stopped 2025-03-07T01:17:56.092Z,1741310276.092 [lab_test_optim:Run:D] Running Loop=1 2025-03-07T01:17:56.499Z,1741310276.499 [lab_test_optim:Run:D] Stopped 2025-03-07T01:17:56.499Z,1741310276.499 [lab_test_optim:Run:setRed] Running Loop=1 2025-03-07T01:17:56.500Z,1741310276.500 [lab_test_optim:Run:setRed](DEBUG): Aggregate::initialize lab_test_optim:Run:setRed 2025-03-07T01:17:56.500Z,1741310276.500 [lab_test_optim:Run:setRed:A] Running Loop=1 2025-03-07T01:17:56.500Z,1741310276.500 [lab_test_optim:D] Running Loop=1 2025-03-07T01:17:56.500Z,1741310276.500 [lab_test_optim:D] Running Loop=1 2025-03-07T01:17:56.500Z,1741310276.500 [lab_test_optim:D](DEBUG): Initialize ReadDataComponent to sense MultiRay.lightModeLog 2025-03-07T01:17:56.917Z,1741310276.917 [lab_test_optim:Run:setRed] Stopped 2025-03-07T01:17:56.917Z,1741310276.917 [lab_test_optim:Run:setRed](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setRed 2025-03-07T01:17:56.917Z,1741310276.917 [lab_test_optim:Run:setRed:A] Stopped 2025-03-07T01:17:56.918Z,1741310276.918 [lab_test_optim:Run:setWhite] Running Loop=1 2025-03-07T01:17:56.918Z,1741310276.918 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::initialize lab_test_optim:Run:setWhite 2025-03-07T01:17:56.918Z,1741310276.918 [lab_test_optim:Run:setWhite:A] Running Loop=1 2025-03-07T01:17:57.337Z,1741310277.337 [lab_test_optim:Run:setWhite:A] Stopped 2025-03-07T01:17:57.337Z,1741310277.337 [lab_test_optim:Run:setWhite:B] Running Loop=1 2025-03-07T01:17:57.749Z,1741310277.749 [lab_test_optim:Run:setWhite:B](INFO): Setting muliray white brightness to 100.000000 count 2025-03-07T01:17:57.749Z,1741310277.749 [lab_test_optim:Run:setWhite:B] Stopped 2025-03-07T01:17:57.750Z,1741310277.750 [lab_test_optim:Run:setWhite](INFO): Completed lab_test_optim:Run:setWhite 2025-03-07T01:17:57.750Z,1741310277.750 [lab_test_optim:Run:setWhite] Stopped 2025-03-07T01:17:57.750Z,1741310277.750 [lab_test_optim:Run:setWhite](DEBUG): Aggregate::uninitialize lab_test_optim:Run:setWhite 2025-03-07T01:17:57.750Z,1741310277.750 [lab_test_optim:Run:G] Running Loop=1 2025-03-07T01:17:58.133Z,1741310278.133 [lab_test_optim:Run:G](IMPORTANT): Recording for 1.000000 min 2025-03-07T01:17:58.133Z,1741310278.133 [lab_test_optim:Run:G] Stopped 2025-03-07T01:17:58.133Z,1741310278.133 [lab_test_optim:Run:H.Wait] Running Loop=1 2025-03-07T01:17:58.133Z,1741310278.133 [lab_test_optim:Run:H.Wait](DEBUG): Initialize Wait Component. 2025-03-07T01:18:35.467Z,1741310315.467 [CommandExec](IMPORTANT): got command restart application 2025-03-07T01:18:36.470Z,1741310316.470 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2025-03-07T01:18:36.470Z,1741310316.470 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:36.471Z,1741310316.471 [CommandExec](INFO): Uninitializing the command executive. 2025-03-07T01:18:36.471Z,1741310316.471 [CommandExec](INFO): Uninitializing the command scheduler. 2025-03-07T01:18:36.471Z,1741310316.471 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:36.562Z,1741310316.562 [MissionManager](INFO): MissionManager is completed. 2025-03-07T01:18:36.562Z,1741310316.562 [MissionManager](INFO): Uninitializing Mission lab_test_optim 2025-03-07T01:18:36.562Z,1741310316.562 [lab_test_optim] Stopped 2025-03-07T01:18:36.562Z,1741310316.562 [lab_test_optim](DEBUG): Aggregate::uninitialize lab_test_optim 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:BackseatDriver] Stopped 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:BackseatDriver](DEBUG): Aggregate::uninitialize lab_test_optim:BackseatDriver 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:BackseatDriver:A.BackseatDriver] Stopped 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:B] Stopped 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:C] Stopped 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:D] Stopped 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:Run] Stopped 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:Run](DEBUG): Aggregate::uninitialize lab_test_optim:Run 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:Run:H.Wait] Stopped 2025-03-07T01:18:36.563Z,1741310316.563 [lab_test_optim:Run:H.Wait](DEBUG): Uninitialize Wait Component. 2025-03-07T01:18:36.578Z,1741310316.578 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-03-07T01:18:36.578Z,1741310316.578 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-03-07T01:18:36.578Z,1741310316.578 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:36.579Z,1741310316.579 [NavChartDb](INFO): Join timeout helper Thread ID is 1255 2025-03-07T01:18:36.766Z,1741310316.766 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:36.766Z,1741310316.766 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:36.778Z,1741310316.778 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-03-07T01:18:36.778Z,1741310316.778 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:36.779Z,1741310316.779 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1256 2025-03-07T01:18:36.907Z,1741310316.907 [MissionManager](IMPORTANT): Started mission Default 2025-03-07T01:18:36.907Z,1741310316.907 [Default] Running Loop=1 2025-03-07T01:18:36.907Z,1741310316.907 [Default](DEBUG): Aggregate::initialize Default 2025-03-07T01:18:36.907Z,1741310316.907 [Default:B.GoToSurface] Running Loop=1 2025-03-07T01:18:36.907Z,1741310316.907 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-03-07T01:18:36.907Z,1741310316.907 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-03-07T01:18:36.908Z,1741310316.908 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-03-07T01:18:36.908Z,1741310316.908 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-03-07T01:18:36.908Z,1741310316.908 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-03-07T01:18:36.909Z,1741310316.909 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-03-07T01:18:36.909Z,1741310316.909 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-03-07T01:18:36.909Z,1741310316.909 [Default:A.Wait] Running Loop=1 2025-03-07T01:18:36.910Z,1741310316.910 [Default:A.Wait](DEBUG): Initialize Wait Component. 2025-03-07T01:18:37.075Z,1741310317.075 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:37.075Z,1741310317.075 [WetLabsBB2FL](INFO): Powering down 2025-03-07T01:18:37.076Z,1741310317.076 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:37.086Z,1741310317.086 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-03-07T01:18:37.086Z,1741310317.086 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:37.087Z,1741310317.087 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1257 2025-03-07T01:18:37.686Z,1741310317.686 [CTD_Seabird](INFO): Powering down 2025-03-07T01:18:37.698Z,1741310317.698 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:37.698Z,1741310317.698 [CTD_Seabird](INFO): Powering down 2025-03-07T01:18:37.741Z,1741310317.741 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:37.750Z,1741310317.750 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-03-07T01:18:37.750Z,1741310317.750 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:37.751Z,1741310317.751 [Radio_Surface](INFO): Join timeout helper Thread ID is 1259 2025-03-07T01:18:37.798Z,1741310317.798 [Radio_Surface](INFO): Powering down 2025-03-07T01:18:37.799Z,1741310317.799 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:37.799Z,1741310317.799 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:37.818Z,1741310317.818 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-03-07T01:18:37.818Z,1741310317.818 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:37.819Z,1741310317.819 [Onboard](INFO): Join timeout helper Thread ID is 1260 2025-03-07T01:18:38.126Z,1741310318.126 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-03-07T01:18:38.251Z,1741310318.251 [BackseatComponent](INFO): Sent LCM shutdown request. 2025-03-07T01:18:38.251Z,1741310318.251 [BackseatComponent](INFO): Shutdown requested. Waiting (18.00 sec to power down.). 2025-03-07T01:18:39.974Z,1741310319.974 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:39.975Z,1741310319.975 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:39.987Z,1741310319.987 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-03-07T01:18:39.987Z,1741310319.987 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:39.987Z,1741310319.987 [DataOverHttps](INFO): Join timeout helper Thread ID is 1261 2025-03-07T01:18:40.134Z,1741310320.134 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:40.135Z,1741310320.135 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.136Z,1741310320.136 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2025-03-07T01:18:40.136Z,1741310320.136 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.136Z,1741310320.136 [BackseatComponent](INFO): Join timeout helper Thread ID is 1262 2025-03-07T01:18:40.286Z,1741310320.286 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:40.287Z,1741310320.287 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.299Z,1741310320.299 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-03-07T01:18:40.299Z,1741310320.299 [logger ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.299Z,1741310320.299 [logger](INFO): Join timeout helper Thread ID is 1263 2025-03-07T01:18:40.306Z,1741310320.306 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:40.307Z,1741310320.307 [logger ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.319Z,1741310320.319 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-03-07T01:18:40.319Z,1741310320.319 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.319Z,1741310320.319 [CommandLine](INFO): Join timeout helper Thread ID is 1264 2025-03-07T01:18:40.418Z,1741310320.418 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:40.419Z,1741310320.419 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.439Z,1741310320.439 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-03-07T01:18:40.439Z,1741310320.439 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.439Z,1741310320.439 [CommandExec](INFO): Join timeout helper Thread ID is 1265 2025-03-07T01:18:40.440Z,1741310320.440 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-03-07T01:18:40.440Z,1741310320.440 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.441Z,1741310320.441 [controlThread](INFO): Join timeout helper Thread ID is 1266 2025-03-07T01:18:40.506Z,1741310320.506 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-03-07T01:18:40.506Z,1741310320.506 [controlThread](DEBUG): Uninitializing ControlThread 2025-03-07T01:18:40.507Z,1741310320.507 [AHRS_M2](INFO): Powering down 2025-03-07T01:18:40.579Z,1741310320.579 [MultiRay](INFO): Powering down. 2025-03-07T01:18:40.580Z,1741310320.580 [NAL9602](INFO): Powering down 2025-03-07T01:18:40.581Z,1741310320.581 [Waterlinked](INFO): Powering down 2025-03-07T01:18:40.583Z,1741310320.583 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-03-07T01:18:40.583Z,1741310320.583 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-03-07T01:18:40.584Z,1741310320.584 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-03-07T01:18:40.584Z,1741310320.584 [MissionManager](INFO): Uninitializing Mission Default 2025-03-07T01:18:40.584Z,1741310320.584 [Default] Stopped 2025-03-07T01:18:40.585Z,1741310320.585 [Default](DEBUG): Aggregate::uninitialize Default 2025-03-07T01:18:40.585Z,1741310320.585 [Default:A.Wait] Stopped 2025-03-07T01:18:40.585Z,1741310320.585 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2025-03-07T01:18:40.585Z,1741310320.585 [Default:B.GoToSurface] Stopped 2025-03-07T01:18:40.585Z,1741310320.585 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-03-07T01:18:40.588Z,1741310320.588 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-03-07T01:18:40.588Z,1741310320.588 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-03-07T01:18:40.589Z,1741310320.589 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-03-07T01:18:40.589Z,1741310320.589 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-03-07T01:18:40.589Z,1741310320.589 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-03-07T01:18:40.589Z,1741310320.589 [BuoyancyServo](INFO): Powering down 2025-03-07T01:18:40.602Z,1741310320.602 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-03-07T01:18:40.602Z,1741310320.602 [ElevatorServo](INFO): Powering down 2025-03-07T01:18:40.603Z,1741310320.603 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-03-07T01:18:40.603Z,1741310320.603 [MassServo](INFO): Powering down 2025-03-07T01:18:40.604Z,1741310320.604 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-03-07T01:18:40.604Z,1741310320.604 [RudderServo](INFO): Powering down 2025-03-07T01:18:40.605Z,1741310320.605 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-03-07T01:18:40.605Z,1741310320.605 [ThrusterHE](INFO): Powering down 2025-03-07T01:18:40.606Z,1741310320.606 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-03-07T01:18:40.606Z,1741310320.606 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-03-07T01:18:40.607Z,1741310320.607 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-03-07T01:18:40.607Z,1741310320.607 [CBIT](DEBUG): Powering off loads. 2025-03-07T01:18:40.618Z,1741310320.618 [CBIT](DEBUG): Disabling WDT. 2025-03-07T01:18:40.630Z,1741310320.630 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-03-07T01:18:40.630Z,1741310320.630 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-03-07T01:18:40.631Z,1741310320.631 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.662Z,1741310320.662 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.665Z,1741310320.665 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.672Z,1741310320.672 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.717Z,1741310320.717 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.752Z,1741310320.752 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-03-07T01:18:40.752Z,1741310320.752 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-03-07T01:18:40.768Z,1741310320.768 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.772Z,1741310320.772 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.826Z,1741310320.826 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-03-07T01:18:40.875Z,1741310320.875 [logger ThreadHandler](INFO): Thread cancelled.