2024-04-23T20:29:58.603Z,1713904198.603 [Supervisor](DEBUG): Initializing supervisor. 2024-04-23T20:29:58.608Z,1713904198.608 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-04-23T20:29:58.608Z,1713904198.608 [SyncHandler](INFO): Protected caller Thread ID is 834 2024-04-23T20:29:58.609Z,1713904198.609 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-04-23T20:29:58.610Z,1713904198.610 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-04-23T20:29:58.610Z,1713904198.610 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 835 2024-04-23T20:29:58.614Z,1713904198.614 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-04-23T20:29:58.632Z,1713904198.632 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-04-23T20:29:58.633Z,1713904198.633 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-04-23T20:29:58.633Z,1713904198.633 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 836 2024-04-23T20:29:58.637Z,1713904198.637 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-04-23T20:29:58.638Z,1713904198.638 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-04-23T20:29:58.639Z,1713904198.639 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 837 2024-04-23T20:29:58.641Z,1713904198.641 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-04-23T20:29:58.642Z,1713904198.642 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-04-23T20:29:58.642Z,1713904198.642 [logger ThreadHandler](INFO): Protected caller Thread ID is 838 2024-04-23T20:29:58.646Z,1713904198.646 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-04-23T20:29:58.646Z,1713904198.646 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-04-23T20:29:58.650Z,1713904198.650 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-04-23T20:29:59.011Z,1713904199.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-04-23T20:29:59.013Z,1713904199.013 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-04-23T20:29:59.799Z,1713904199.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-04-23T20:29:59.801Z,1713904199.801 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-04-23T20:29:59.923Z,1713904199.923 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-04-23T20:29:59.925Z,1713904199.925 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-04-23T20:30:00.506Z,1713904200.506 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-04-23T20:30:00.506Z,1713904200.506 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-04-23T20:30:00.618Z,1713904200.618 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-04-23T20:30:00.619Z,1713904200.619 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-04-23T20:30:00.712Z,1713904200.712 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-04-23T20:30:01.158Z,1713904201.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-04-23T20:30:01.160Z,1713904201.160 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-04-23T20:30:01.404Z,1713904201.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-04-23T20:30:01.405Z,1713904201.405 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-04-23T20:30:01.556Z,1713904201.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-04-23T20:30:01.558Z,1713904201.558 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-04-23T20:30:01.834Z,1713904201.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-04-23T20:30:01.836Z,1713904201.836 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-04-23T20:30:03.149Z,1713904203.149 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-04-23T20:30:03.150Z,1713904203.150 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-04-23T20:30:03.557Z,1713904203.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-04-23T20:30:03.558Z,1713904203.558 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-04-23T20:30:03.649Z,1713904203.649 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-04-23T20:30:03.864Z,1713904203.864 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-04-23T20:30:03.866Z,1713904203.866 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-04-23T20:30:04.117Z,1713904204.117 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-04-23T20:30:04.118Z,1713904204.118 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-04-23T20:30:04.502Z,1713904204.502 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-04-23T20:30:04.504Z,1713904204.504 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2024-04-23T20:30:04.507Z,1713904204.507 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2024-04-23T20:30:04.631Z,1713904204.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2024-04-23T20:30:04.799Z,1713904204.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2024-04-23T20:30:04.897Z,1713904204.897 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2024-04-23T20:30:04.994Z,1713904204.994 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2024-04-23T20:30:05.118Z,1713904205.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2024-04-23T20:30:05.238Z,1713904205.238 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2024-04-23T20:30:05.518Z,1713904205.518 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-04-23T20:30:05.519Z,1713904205.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2024-04-23T20:30:05.670Z,1713904205.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2024-04-23T20:30:05.776Z,1713904205.776 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2024-04-23T20:30:05.882Z,1713904205.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2024-04-23T20:30:05.997Z,1713904205.997 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2024-04-23T20:30:06.001Z,1713904206.001 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-04-23T20:30:06.156Z,1713904206.156 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-04-23T20:30:06.157Z,1713904206.157 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-04-23T20:30:06.173Z,1713904206.173 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-04-23T20:30:06.175Z,1713904206.175 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-04-23T20:30:06.247Z,1713904206.247 [DepthRateCalculator] Loaded 2024-04-23T20:30:06.247Z,1713904206.247 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-04-23T20:30:06.253Z,1713904206.253 [PitchRateCalculator] Loaded 2024-04-23T20:30:06.253Z,1713904206.253 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-04-23T20:30:06.264Z,1713904206.264 [SpeedCalculator] Loaded 2024-04-23T20:30:06.264Z,1713904206.264 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-04-23T20:30:06.269Z,1713904206.269 [YawRateCalculator] Loaded 2024-04-23T20:30:06.269Z,1713904206.269 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-04-23T20:30:06.291Z,1713904206.291 [ElevatorOffsetCalculator] Loaded 2024-04-23T20:30:06.292Z,1713904206.292 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-04-23T20:30:06.292Z,1713904206.292 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-04-23T20:30:06.294Z,1713904206.294 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-04-23T20:30:06.365Z,1713904206.365 [VerticalControl](DEBUG): Construct VerticalControl. 2024-04-23T20:30:06.423Z,1713904206.423 [VerticalControl] Loaded 2024-04-23T20:30:06.423Z,1713904206.423 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-04-23T20:30:06.426Z,1713904206.426 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-04-23T20:30:06.469Z,1713904206.469 [HorizontalControl] Loaded 2024-04-23T20:30:06.469Z,1713904206.469 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-04-23T20:30:06.472Z,1713904206.472 [SpeedControl](DEBUG): Construct SpeedControl. 2024-04-23T20:30:06.475Z,1713904206.475 [SpeedControl] Loaded 2024-04-23T20:30:06.475Z,1713904206.475 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-04-23T20:30:06.477Z,1713904206.477 [LoopControl](DEBUG): Construct LoopControl. 2024-04-23T20:30:06.478Z,1713904206.478 [LoopControl] Loaded 2024-04-23T20:30:06.478Z,1713904206.478 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-04-23T20:30:06.479Z,1713904206.479 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-04-23T20:30:06.479Z,1713904206.479 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-04-23T20:30:06.619Z,1713904206.619 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-04-23T20:30:06.620Z,1713904206.620 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-04-23T20:30:06.634Z,1713904206.634 [NavChart] Loaded 2024-04-23T20:30:06.634Z,1713904206.634 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-04-23T20:30:06.640Z,1713904206.640 [UniversalFixResidualReporter] Loaded 2024-04-23T20:30:06.640Z,1713904206.640 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-04-23T20:30:06.640Z,1713904206.640 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-04-23T20:30:06.641Z,1713904206.641 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-04-23T20:30:06.869Z,1713904206.869 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-04-23T20:30:06.870Z,1713904206.870 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-04-23T20:30:07.935Z,1713904207.935 [AHRS_M2] Loaded 2024-04-23T20:30:07.935Z,1713904207.935 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-04-23T20:30:08.186Z,1713904208.186 [BackseatComponent] Loaded 2024-04-23T20:30:08.186Z,1713904208.186 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2024-04-23T20:30:08.188Z,1713904208.188 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409204E0 2024-04-23T20:30:08.188Z,1713904208.188 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 921 2024-04-23T20:30:08.191Z,1713904208.191 [LcmUniversalReporter] Loaded 2024-04-23T20:30:08.191Z,1713904208.191 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2024-04-23T20:30:09.011Z,1713904209.011 [BPC1] Loaded 2024-04-23T20:30:09.011Z,1713904209.011 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-04-23T20:30:09.156Z,1713904209.156 [DataOverHttps] Loaded 2024-04-23T20:30:09.156Z,1713904209.156 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-04-23T20:30:09.157Z,1713904209.157 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409504E0 2024-04-23T20:30:09.158Z,1713904209.158 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 922 2024-04-23T20:30:09.178Z,1713904209.178 [Depth_Keller] Loaded 2024-04-23T20:30:09.179Z,1713904209.179 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-04-23T20:30:09.184Z,1713904209.184 [DropWeight] Loaded 2024-04-23T20:30:09.184Z,1713904209.184 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-04-23T20:30:09.222Z,1713904209.222 [DVL_micro] Loaded 2024-04-23T20:30:09.223Z,1713904209.223 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2024-04-23T20:30:09.285Z,1713904209.285 [NAL9602] Loaded 2024-04-23T20:30:09.285Z,1713904209.285 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-04-23T20:30:09.315Z,1713904209.315 [Onboard] Loaded 2024-04-23T20:30:09.315Z,1713904209.315 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-04-23T20:30:09.316Z,1713904209.316 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409804E0 2024-04-23T20:30:09.317Z,1713904209.317 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 923 2024-04-23T20:30:09.329Z,1713904209.329 [Power24vConverter] Loaded 2024-04-23T20:30:09.329Z,1713904209.329 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-04-23T20:30:09.343Z,1713904209.343 [Radio_Surface] Loaded 2024-04-23T20:30:09.343Z,1713904209.343 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-04-23T20:30:09.344Z,1713904209.344 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409B04E0 2024-04-23T20:30:09.344Z,1713904209.344 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 924 2024-04-23T20:30:09.358Z,1713904209.358 [Sonardyne_Nano] Loaded 2024-04-23T20:30:09.358Z,1713904209.358 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2024-04-23T20:30:09.451Z,1713904209.451 [DAT] Loaded 2024-04-23T20:30:09.452Z,1713904209.452 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-04-23T20:30:09.453Z,1713904209.453 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409E04E0 2024-04-23T20:30:09.453Z,1713904209.453 [DAT ThreadHandler](INFO): Protected caller Thread ID is 925 2024-04-23T20:30:09.454Z,1713904209.454 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-04-23T20:30:09.454Z,1713904209.454 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-04-23T20:30:09.620Z,1713904209.620 [BuoyancyServo] Loaded 2024-04-23T20:30:09.621Z,1713904209.621 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-04-23T20:30:09.641Z,1713904209.641 [ElevatorServo] Loaded 2024-04-23T20:30:09.642Z,1713904209.642 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-04-23T20:30:09.662Z,1713904209.662 [MassServo] Loaded 2024-04-23T20:30:09.662Z,1713904209.662 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-04-23T20:30:09.681Z,1713904209.681 [RudderServo] Loaded 2024-04-23T20:30:09.681Z,1713904209.681 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-04-23T20:30:09.696Z,1713904209.696 [ThrusterHE] Loaded 2024-04-23T20:30:09.697Z,1713904209.697 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-04-23T20:30:09.697Z,1713904209.697 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-04-23T20:30:09.698Z,1713904209.698 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-04-23T20:30:09.783Z,1713904209.783 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-04-23T20:30:09.784Z,1713904209.784 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-04-23T20:30:09.828Z,1713904209.828 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-04-23T20:30:09.829Z,1713904209.829 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-04-23T20:30:10.249Z,1713904210.249 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-04-23T20:30:10.249Z,1713904210.249 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-04-23T20:30:10.477Z,1713904210.477 [CTD_Seabird] Loaded 2024-04-23T20:30:10.478Z,1713904210.478 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-04-23T20:30:10.479Z,1713904210.479 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B964E0 2024-04-23T20:30:10.479Z,1713904210.479 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 926 2024-04-23T20:30:10.513Z,1713904210.513 [ESPComponent] Loaded 2024-04-23T20:30:10.513Z,1713904210.513 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2024-04-23T20:30:10.534Z,1713904210.534 [PAR_Licor] Loaded 2024-04-23T20:30:10.534Z,1713904210.534 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-04-23T20:30:10.579Z,1713904210.579 [WetLabsBB2FL] Loaded 2024-04-23T20:30:10.579Z,1713904210.579 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-04-23T20:30:10.580Z,1713904210.580 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BC64E0 2024-04-23T20:30:10.581Z,1713904210.581 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 927 2024-04-23T20:30:10.581Z,1713904210.581 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-04-23T20:30:10.582Z,1713904210.582 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-04-23T20:30:10.762Z,1713904210.762 [SBIT](DEBUG): Construct Startup Built In Test. 2024-04-23T20:30:10.772Z,1713904210.772 [SBIT] Loaded 2024-04-23T20:30:10.772Z,1713904210.772 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-04-23T20:30:10.775Z,1713904210.775 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-04-23T20:30:10.788Z,1713904210.788 [IBIT] Loaded 2024-04-23T20:30:10.789Z,1713904210.789 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-04-23T20:30:10.794Z,1713904210.794 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-04-23T20:30:10.903Z,1713904210.903 [CBIT] Loaded 2024-04-23T20:30:10.903Z,1713904210.903 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-04-23T20:30:10.904Z,1713904210.904 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-04-23T20:30:10.910Z,1713904210.910 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-04-23T20:30:10.913Z,1713904210.913 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-04-23T20:30:10.924Z,1713904210.924 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-04-23T20:30:10.925Z,1713904210.925 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C354E0 2024-04-23T20:30:10.926Z,1713904210.926 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928 2024-04-23T20:30:10.930Z,1713904210.930 [Supervisor](INFO): Main Thread ID is 827 2024-04-23T20:30:10.930Z,1713904210.930 [Supervisor](DEBUG): Running supervisor. 2024-04-23T20:30:10.931Z,1713904210.931 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929 2024-04-23T20:30:10.931Z,1713904210.931 [CommandExec](INFO): Initializing the command executive. 2024-04-23T20:30:10.933Z,1713904210.933 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930 2024-04-23T20:30:10.935Z,1713904210.935 [controlThread ThreadHandler](INFO): Handler Thread ID is 931 2024-04-23T20:30:10.935Z,1713904210.935 [controlThread](DEBUG): Initializing ControlThread 2024-04-23T20:30:10.936Z,1713904210.936 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-04-23T20:30:10.937Z,1713904210.937 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-04-23T20:30:10.937Z,1713904210.937 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-04-23T20:30:10.937Z,1713904210.937 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-04-23T20:30:10.938Z,1713904210.938 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-04-23T20:30:10.938Z,1713904210.938 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-04-23T20:30:10.940Z,1713904210.940 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-04-23T20:30:10.941Z,1713904210.941 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-04-23T20:30:10.941Z,1713904210.941 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-04-23T20:30:10.942Z,1713904210.942 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-04-23T20:30:10.942Z,1713904210.942 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-04-23T20:30:10.952Z,1713904210.952 [SBIT](INFO): Initialize SBIT Component. 2024-04-23T20:30:10.953Z,1713904210.953 [SBIT](IMPORTANT): git: 2024-04-11 2024-04-23T20:30:10.953Z,1713904210.953 [SBIT](INFO): git hash: 8b14ac3cbe1df2c95d6505c0066306c41245f1d7 2024-04-23T20:30:10.953Z,1713904210.953 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-04-23T20:30:10.954Z,1713904210.954 [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-23T20:30:10.955Z,1713904210.955 [SBIT](INFO): Beginning SBIT in 134.000000 seconds. 2024-04-23T20:30:10.956Z,1713904210.956 [IBIT](INFO): Initialize IBIT Component. 2024-04-23T20:30:10.957Z,1713904210.957 [CBIT](DEBUG): Initialize CBIT Component. 2024-04-23T20:30:10.958Z,1713904210.958 [logger ThreadHandler](INFO): Handler Thread ID is 932 2024-04-23T20:30:10.968Z,1713904210.968 [CBIT](DEBUG): Initialized mux pins. 2024-04-23T20:30:10.968Z,1713904210.968 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2024-04-23T20:30:10.968Z,1713904210.968 [CBIT](DEBUG): Initializing the watchdog timer. 2024-04-23T20:30:10.976Z,1713904210.976 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 933 2024-04-23T20:30:10.988Z,1713904210.988 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 934 2024-04-23T20:30:10.990Z,1713904210.990 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-04-23T20:30:10.992Z,1713904210.992 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2024-04-23T20:30:10.992Z,1713904210.992 [CBIT](DEBUG): Initializing heartbeat. 2024-04-23T20:30:11.000Z,1713904211.000 [Onboard ThreadHandler](INFO): Handler Thread ID is 935 2024-04-23T20:30:11.018Z,1713904211.018 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 936 2024-04-23T20:30:11.040Z,1713904211.040 [DAT ThreadHandler](INFO): Handler Thread ID is 937 2024-04-23T20:30:11.041Z,1713904211.041 [DAT](INFO): Powering up 2024-04-23T20:30:11.041Z,1713904211.041 [DAT](DEBUG): Initializing DAT. 2024-04-23T20:30:11.045Z,1713904211.045 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 939 2024-04-23T20:30:11.046Z,1713904211.046 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-04-23T20:30:11.049Z,1713904211.049 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 941 2024-04-23T20:30:11.052Z,1713904211.052 [WetLabsBB2FL](INFO): Powering up 2024-04-23T20:30:11.054Z,1713904211.054 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2024-04-23T20:30:11.062Z,1713904211.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2024-04-23T20:30:11.062Z,1713904211.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2024-04-23T20:30:11.062Z,1713904211.062 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2024-04-23T20:30:11.062Z,1713904211.062 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2024-04-23T20:30:11.063Z,1713904211.063 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2024-04-23T20:30:11.063Z,1713904211.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2024-04-23T20:30:11.063Z,1713904211.063 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2024-04-23T20:30:11.063Z,1713904211.063 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2024-04-23T20:30:11.064Z,1713904211.064 [CBIT](DEBUG): Deactivating GF circuits. 2024-04-23T20:30:11.064Z,1713904211.064 [CBIT](DEBUG): Deactivating emergency mode. 2024-04-23T20:30:11.104Z,1713904211.104 [CBIT](DEBUG): Backplane powered. 2024-04-23T20:30:11.105Z,1713904211.105 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-04-23T20:30:11.105Z,1713904211.105 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Startup.tx 2024-04-23T20:30:11.142Z,1713904211.142 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-23T20:30:11.194Z,1713904211.194 [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-23T20:30:11.195Z,1713904211.195 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-04-23T20:30:11.195Z,1713904211.195 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Default.tx 2024-04-23T20:30:11.266Z,1713904211.266 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-04-23T20:30:11.267Z,1713904211.267 [Default:A.Wait](DEBUG): Construct Wait. 2024-04-23T20:30:11.269Z,1713904211.269 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-04-23T20:30:11.326Z,1713904211.326 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-04-23T20:30:11.328Z,1713904211.328 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-04-23T20:30:11.354Z,1713904211.354 [Default:E.Execute](DEBUG): Construct Execute. 2024-04-23T20:30:11.361Z,1713904211.361 [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-23T20:30:11.366Z,1713904211.366 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,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-23T20:30:11.386Z,1713904211.386 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-04-23T20:30:11.424Z,1713904211.424 [Radio_Surface](INFO): Powering up 2024-04-23T20:30:11.569Z,1713904211.569 [Power24vConverter](INFO): Powering up. 2024-04-23T20:30:11.570Z,1713904211.570 [Sonardyne_Nano](INFO): Initializing. 2024-04-23T20:30:11.634Z,1713904211.634 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-04-23T20:30:11.640Z,1713904211.640 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-04-23T20:30:11.641Z,1713904211.641 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-04-23T20:30:11.648Z,1713904211.648 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-04-23T20:30:11.649Z,1713904211.649 [MassServo](DEBUG): Initializing EZServoServo. 2024-04-23T20:30:11.657Z,1713904211.657 [MassServo](DEBUG): Initializing MassServo. 2024-04-23T20:30:11.657Z,1713904211.657 [RudderServo](DEBUG): Initializing EZServoServo. 2024-04-23T20:30:11.664Z,1713904211.664 [RudderServo](DEBUG): Initializing RudderServo. 2024-04-23T20:30:11.665Z,1713904211.665 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-04-23T20:30:11.672Z,1713904211.672 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-04-23T20:30:11.674Z,1713904211.674 [CommandExec](FAULT): Scheduling is paused 2024-04-23T20:30:11.674Z,1713904211.674 [CBIT](INFO): Critical error at 20240423T203010 2024-04-23T20:30:11.675Z,1713904211.675 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2024-04-23T20:30:13.664Z,1713904213.664 [WetLabsBB2FL](INFO): Powering down 2024-04-23T20:30:13.799Z,1713904213.799 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-04-23T20:30:15.053Z,1713904215.053 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2207 2024-04-23T20:30:17.137Z,1713904217.137 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-04-23T20:30:18.077Z,1713904218.077 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2024-04-23T20:30:23.136Z,1713904223.136 [DAT](INFO): DAT read: 2024-04-23T20:30:23.138Z,1713904223.138 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-04-23T20:30:24.649Z,1713904224.649 [DAT](INFO): DAT read: MF Frequency Band 2024-04-23T20:30:24.650Z,1713904224.650 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2024-04-23T20:30:24.651Z,1713904224.651 [DAT](INFO): DAT read: Apr 23 2024 20:29:53 2024-04-23T20:30:25.909Z,1713904225.909 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-04-23T20:30:25.910Z,1713904225.910 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2024-04-23T20:30:25.911Z,1713904225.911 [DAT](INFO): commRate: 800 2024-04-23T20:30:27.976Z,1713904227.976 [DAT](INFO): entering command mode 2024-04-23T20:30:28.176Z,1713904228.176 [DAT](INFO): DAT read: 2024-04-23T20:30:28.177Z,1713904228.177 [DAT](INFO): DAT read: user:1> 2024-04-23T20:30:28.177Z,1713904228.177 [DAT](INFO): setting verbose to 3 2024-04-23T20:30:28.429Z,1713904228.429 [DAT](INFO): DAT read: user:1> 2024-04-23T20:30:28.430Z,1713904228.430 [DAT](INFO): DAT read: Verbose | 3 2024-04-23T20:30:28.430Z,1713904228.430 [DAT](INFO): set verbose to 3 2024-04-23T20:30:28.430Z,1713904228.430 [DAT](INFO): setting DatVerbose to 27440 2024-04-23T20:30:28.681Z,1713904228.681 [DAT](INFO): DAT read: user:2> 2024-04-23T20:30:28.686Z,1713904228.686 [DAT](INFO): DAT read: DatVerbose | 27440 2024-04-23T20:30:28.687Z,1713904228.687 [DAT](INFO): set DatVerbose to 27440 2024-04-23T20:30:28.687Z,1713904228.687 [DAT](INFO): setting transmit power to 8 2024-04-23T20:30:28.934Z,1713904228.934 [DAT](INFO): DAT read: user:3> 2024-04-23T20:30:28.937Z,1713904228.937 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-04-23T20:30:28.938Z,1713904228.938 [DAT](INFO): set transmit power to 8 2024-04-23T20:30:28.938Z,1713904228.938 [DAT](INFO): setting local address to 11 2024-04-23T20:30:29.186Z,1713904229.186 [DAT](INFO): DAT read: user:4> 2024-04-23T20:30:29.187Z,1713904229.187 [DAT](INFO): DAT read: LocalAddr | 11 2024-04-23T20:30:29.187Z,1713904229.187 [DAT](INFO): set local address to 11 2024-04-23T20:30:29.188Z,1713904229.188 [DAT](INFO): Setting time to: 20:30:29 And date to:4/23/2024 2024-04-23T20:30:29.437Z,1713904229.437 [DAT](INFO): DAT read: user:5> 2024-04-23T20:30:29.438Z,1713904229.438 [DAT](INFO): DAT read: Tue Apr 23, 2024 20:30:29 2024-04-23T20:30:29.438Z,1713904229.438 [DAT](INFO): Local DAT time set to Tue Apr 23, 2024 20:30:29 2024-04-23T20:30:39.658Z,1713904239.658 [NAL9602](INFO): Powering up NAL9602 2024-04-23T20:30:50.570Z,1713904250.570 [NAL9602](INFO): NAL9602 initialized 2024-04-23T20:31:07.155Z,1713904267.155 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+18.3,0000.0,1489.0,000 2024-04-23T20:32:24.318Z,1713904344.318 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file). 2024-04-23T20:32:25.523Z,1713904345.523 [SBIT](IMPORTANT): Beginning Startup BIT 2024-04-23T20:32:25.527Z,1713904345.527 [CBIT](IMPORTANT): Beginning ground fault scan 2024-04-23T20:32:36.905Z,1713904356.905 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.000534 CHAN A1 (24V): -0.000096 CHAN A2 (12V): -0.003944 CHAN A3 (5V): -0.007471 CHAN B0 (3.3V): -0.000644 CHAN B1 (3.15aV): 0.002638 CHAN B2 (3.15bV): 0.000374 CHAN B3 (GND): -0.002196 OPEN: 0.001006 Full Scale: +/- 1 mA 2024-04-23T20:33:11.192Z,1713904391.192 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-04-23T20:33:11.192Z,1713904391.192 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-04-23T20:33:11.234Z,1713904391.234 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-04-23T20:33:11.617Z,1713904391.617 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-04-23T20:33:11.617Z,1713904391.617 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-04-23T20:33:19.255Z,1713904399.255 [SBIT](IMPORTANT): SBIT PASSED 2024-04-23T20:33:19.255Z,1713904399.255 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2024-04-23T20:33:19.656Z,1713904399.656 [MissionManager](IMPORTANT): Started mission Startup 2024-04-23T20:33:19.656Z,1713904399.656 [Startup] Running Loop=1 2024-04-23T20:33:19.656Z,1713904399.656 [Startup](DEBUG): Aggregate::initialize Startup 2024-04-23T20:33:19.656Z,1713904399.656 [Startup:A.GoToSurface] Running Loop=1 2024-04-23T20:33:19.657Z,1713904399.657 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-23T20:33:19.657Z,1713904399.657 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-23T20:33:19.658Z,1713904399.658 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-23T20:33:19.658Z,1713904399.658 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-23T20:33:19.658Z,1713904399.658 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-23T20:33:19.659Z,1713904399.659 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-23T20:33:19.660Z,1713904399.660 [Startup:StartupSatComms] Running Loop=1 2024-04-23T20:33:19.660Z,1713904399.660 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-04-23T20:33:19.661Z,1713904399.661 [Startup:StartupSatComms:A] Running Loop=1 2024-04-23T20:33:20.127Z,1713904400.127 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-04-23T20:34:08.442Z,1713904448.442 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004100 2024-04-23T20:34:19.866Z,1713904459.866 [Startup:StartupSatComms:A](INFO): Timed out from 2024-04-23T20:33:19.7Z 2024-04-23T20:34:19.867Z,1713904459.867 [Startup:StartupSatComms:A] Stopped 2024-04-23T20:34:19.867Z,1713904459.867 [Startup:StartupSatComms:B] Running Loop=1 2024-04-23T20:34:20.321Z,1713904460.321 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-23T20:34:30.091Z,1713904470.091 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20240423T163357/Courier0124.lzma 2024-04-23T20:34:31.095Z,1713904471.095 [DataOverHttps](INFO): Moved sent file to Logs/20240423T163357/Courier0124.lzma.bak 2024-04-23T20:34:31.095Z,1713904471.095 [DataOverHttps](INFO): SBD MOMSN=19424111 2024-04-23T20:34:48.760Z,1713904488.760 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20240423T202958/Courier0000.lzma 2024-04-23T20:34:49.762Z,1713904489.762 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Courier0000.lzma.bak 2024-04-23T20:34:49.762Z,1713904489.762 [DataOverHttps](INFO): SBD MOMSN=19424113 2024-04-23T20:35:07.223Z,1713904507.223 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20240423T163357/Express0125.lzma 2024-04-23T20:35:08.226Z,1713904508.226 [DataOverHttps](INFO): Moved sent file to Logs/20240423T163357/Express0125.lzma.bak 2024-04-23T20:35:08.226Z,1713904508.226 [DataOverHttps](INFO): SBD MOMSN=19424117 2024-04-23T20:35:20.187Z,1713904520.187 [Startup:StartupSatComms:B](INFO): Timed out from 2024-04-23T20:34:19.9Z 2024-04-23T20:35:20.187Z,1713904520.187 [Startup:StartupSatComms:B] Stopped 2024-04-23T20:35:20.188Z,1713904520.188 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-04-23T20:35:20.188Z,1713904520.188 [Startup:StartupSatComms] Stopped 2024-04-23T20:35:20.188Z,1713904520.188 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-04-23T20:35:20.189Z,1713904520.189 [Startup](INFO): Completed Startup 2024-04-23T20:35:20.189Z,1713904520.189 [MissionManager](INFO): Startup is completed. 2024-04-23T20:35:20.189Z,1713904520.189 [MissionManager](INFO): Uninitializing Mission Startup 2024-04-23T20:35:20.189Z,1713904520.189 [Startup] Stopped 2024-04-23T20:35:20.189Z,1713904520.189 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-04-23T20:35:20.190Z,1713904520.190 [Startup:A.GoToSurface] Stopped 2024-04-23T20:35:20.190Z,1713904520.190 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-04-23T20:35:20.598Z,1713904520.598 [MissionManager](IMPORTANT): Started mission Default 2024-04-23T20:35:20.599Z,1713904520.599 [Default] Running Loop=1 2024-04-23T20:35:20.599Z,1713904520.599 [Default](DEBUG): Aggregate::initialize Default 2024-04-23T20:35:20.599Z,1713904520.599 [Default:B.GoToSurface] Running Loop=1 2024-04-23T20:35:20.599Z,1713904520.599 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-04-23T20:35:20.599Z,1713904520.599 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-04-23T20:35:20.604Z,1713904520.604 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-04-23T20:35:20.604Z,1713904520.604 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-04-23T20:35:20.604Z,1713904520.604 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-04-23T20:35:20.605Z,1713904520.605 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-04-23T20:35:20.605Z,1713904520.605 [Default:A.Wait] Running Loop=1 2024-04-23T20:35:20.605Z,1713904520.605 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-04-23T20:35:25.853Z,1713904525.853 [DataOverHttps](INFO): Sending 767 bytes from file Logs/20240423T202958/Express0001.lzma 2024-04-23T20:35:26.854Z,1713904526.854 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Express0001.lzma.bak 2024-04-23T20:35:26.854Z,1713904526.854 [DataOverHttps](INFO): SBD MOMSN=19424119 2024-04-23T20:35:33.915Z,1713904533.915 [Default:A.Wait](INFO): Done Waiting. 2024-04-23T20:35:33.915Z,1713904533.915 [Default:A.Wait] Stopped 2024-04-23T20:35:33.915Z,1713904533.915 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-04-23T20:35:34.323Z,1713904534.323 [Default:CheckIn] Running Loop=1 2024-04-23T20:35:34.323Z,1713904534.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-23T20:35:34.323Z,1713904534.323 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-23T20:35:34.733Z,1713904534.733 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-04-23T20:35:53.298Z,1713904553.298 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-04-23T20:35:58.563Z,1713904558.563 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203529.00,A,3648.16648,N,12147.28205,W,0.097,0.00,230424,,,A*76 2024-04-23T20:35:58.579Z,1713904558.579 [NAL9602](INFO): GPS fix at 20240423T203529: (36.802775, -121.788034) 2024-04-23T20:35:58.602Z,1713904558.602 [Default:CheckIn:Read_GPS] Stopped 2024-04-23T20:35:58.603Z,1713904558.603 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-23T20:35:59.172Z,1713904559.172 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-04-23T20:36:17.020Z,1713904577.020 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20240423T202958/Courier0004.lzma 2024-04-23T20:36:18.026Z,1713904578.026 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Courier0004.lzma.bak 2024-04-23T20:36:18.026Z,1713904578.026 [DataOverHttps](INFO): SBD MOMSN=19424135 2024-04-23T20:36:28.924Z,1713904588.924 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:36:30.985Z,1713904590.985 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-23T20:36:41.168Z,1713904601.168 [DataOverHttps](INFO): Sending 320 bytes from file Logs/20240423T202958/Express0005.lzma 2024-04-23T20:36:43.089Z,1713904603.089 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Express0005.lzma.bak 2024-04-23T20:36:43.089Z,1713904603.089 [DataOverHttps](INFO): SBD MOMSN=19424138 2024-04-23T20:36:43.576Z,1713904603.576 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:36:45.231Z,1713904605.231 [Default:CheckIn:Read_Iridium] Stopped 2024-04-23T20:36:45.231Z,1713904605.231 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-23T20:36:45.231Z,1713904605.231 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-23T20:36:58.915Z,1713904618.915 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:37:13.866Z,1713904633.866 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:37:28.812Z,1713904648.812 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:37:43.355Z,1713904663.355 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:37:57.899Z,1713904677.899 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:38:12.905Z,1713904692.905 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:38:27.468Z,1713904707.468 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:38:42.404Z,1713904722.404 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:41:05.084Z,1713904865.084 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-04-23T20:41:45.844Z,1713904905.844 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-23T20:41:45.844Z,1713904905.844 [Default:CheckIn:C.Wait] Stopped 2024-04-23T20:41:45.844Z,1713904905.844 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-23T20:41:45.844Z,1713904905.844 [Default:CheckIn:D] Running Loop=1 2024-04-23T20:41:46.258Z,1713904906.258 [Default:CheckIn:D] Stopped 2024-04-23T20:41:46.258Z,1713904906.258 [Default:CheckIn:E] Running Loop=1 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.427653 min 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn:E] Stopped 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn] Stopped 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn](INFO): Running loop #2 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn] Running Loop=2 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-23T20:41:46.723Z,1713904906.723 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-23T20:41:48.672Z,1713904908.672 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204122.00,A,3648.16576,N,12147.27997,W,0.661,13.51,230424,,,A*46 2024-04-23T20:41:48.675Z,1713904908.675 [NAL9602](INFO): GPS fix at 20240423T204122: (36.802763, -121.787999) 2024-04-23T20:41:48.724Z,1713904908.724 [Default:CheckIn:Read_GPS] Stopped 2024-04-23T20:41:48.724Z,1713904908.724 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-23T20:41:56.447Z,1713904916.447 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240423T202958/Courier0007.lzma 2024-04-23T20:41:57.450Z,1713904917.450 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Courier0007.lzma.bak 2024-04-23T20:41:57.450Z,1713904917.450 [DataOverHttps](INFO): SBD MOMSN=19424157 2024-04-23T20:42:18.276Z,1713904938.276 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20240423T202958/Express0008.lzma 2024-04-23T20:42:19.278Z,1713904939.278 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Express0008.lzma.bak 2024-04-23T20:42:19.278Z,1713904939.278 [DataOverHttps](INFO): SBD MOMSN=19424162 2024-04-23T20:42:19.439Z,1713904939.439 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-04-23T20:42:19.512Z,1713904939.512 [NAL9602](ERROR): received: +CSQ:0 OK 2024-04-23T20:42:24.193Z,1713904944.193 [Default:CheckIn:Read_Iridium] Stopped 2024-04-23T20:42:24.193Z,1713904944.193 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-23T20:42:24.193Z,1713904944.193 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-23T20:46:18.524Z,1713905178.524 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:46:33.503Z,1713905193.503 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:46:48.050Z,1713905208.050 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:46:50.879Z,1713905210.879 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-04-23T20:47:02.593Z,1713905222.593 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:47:17.539Z,1713905237.539 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:47:21.613Z,1713905241.613 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-23T20:47:24.831Z,1713905244.831 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-23T20:47:24.831Z,1713905244.831 [Default:CheckIn:C.Wait] Stopped 2024-04-23T20:47:24.831Z,1713905244.831 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-23T20:47:24.831Z,1713905244.831 [Default:CheckIn:D] Running Loop=1 2024-04-23T20:47:25.249Z,1713905245.249 [Default:CheckIn:D] Stopped 2024-04-23T20:47:25.249Z,1713905245.249 [Default:CheckIn:E] Running Loop=1 2024-04-23T20:47:25.640Z,1713905245.640 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.077501 min 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn:E] Stopped 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn] Stopped 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn](INFO): Running loop #3 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn] Running Loop=3 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-23T20:47:25.641Z,1713905245.641 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-23T20:47:27.647Z,1713905247.647 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204701.00,A,3648.16441,N,12147.28352,W,0.078,132.88,230424,,,D*75 2024-04-23T20:47:27.650Z,1713905247.650 [NAL9602](INFO): GPS fix at 20240423T204701: (36.802740, -121.788059) 2024-04-23T20:47:27.680Z,1713905247.680 [Default:CheckIn:Read_GPS] Stopped 2024-04-23T20:47:27.680Z,1713905247.680 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-23T20:47:32.141Z,1713905252.141 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:47:32.369Z,1713905252.369 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20240423T202958/Courier0010.lzma 2024-04-23T20:47:33.373Z,1713905253.373 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Courier0010.lzma.bak 2024-04-23T20:47:33.374Z,1713905253.374 [DataOverHttps](INFO): SBD MOMSN=19424176 2024-04-23T20:47:47.208Z,1713905267.208 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:47:51.435Z,1713905271.435 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20240423T202958/Express0011.lzma 2024-04-23T20:47:52.439Z,1713905272.439 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Express0011.lzma.bak 2024-04-23T20:47:52.440Z,1713905272.440 [DataOverHttps](INFO): SBD MOMSN=19424179 2024-04-23T20:47:55.260Z,1713905275.260 [Default:CheckIn:Read_Iridium] Stopped 2024-04-23T20:47:55.260Z,1713905275.260 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-23T20:47:55.260Z,1713905275.260 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-23T20:48:01.655Z,1713905281.655 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:48:13.399Z,1713905293.399 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file). 2024-04-23T20:48:16.625Z,1713905296.625 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:48:31.264Z,1713905311.264 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:52:29.727Z,1713905549.727 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-04-23T20:52:55.992Z,1713905575.992 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-04-23T20:52:55.992Z,1713905575.992 [Default:CheckIn:C.Wait] Stopped 2024-04-23T20:52:55.992Z,1713905575.992 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-04-23T20:52:55.993Z,1713905575.993 [Default:CheckIn:D] Running Loop=1 2024-04-23T20:52:56.417Z,1713905576.417 [Default:CheckIn:D] Stopped 2024-04-23T20:52:56.417Z,1713905576.417 [Default:CheckIn:E] Running Loop=1 2024-04-23T20:52:56.814Z,1713905576.814 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.596969 min 2024-04-23T20:52:56.814Z,1713905576.814 [Default:CheckIn:E] Stopped 2024-04-23T20:52:56.814Z,1713905576.814 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-04-23T20:52:56.814Z,1713905576.814 [Default:CheckIn] Stopped 2024-04-23T20:52:56.814Z,1713905576.814 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-04-23T20:52:56.814Z,1713905576.814 [Default:CheckIn](INFO): Running loop #4 2024-04-23T20:52:56.815Z,1713905576.815 [Default:CheckIn] Running Loop=4 2024-04-23T20:52:56.815Z,1713905576.815 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-04-23T20:52:56.815Z,1713905576.815 [Default:CheckIn:Read_GPS] Running Loop=1 2024-04-23T20:52:58.812Z,1713905578.812 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205232.00,A,3648.15805,N,12147.28310,W,1.127,68.58,230424,,,D*41 2024-04-23T20:52:58.814Z,1713905578.814 [NAL9602](INFO): GPS fix at 20240423T205232: (36.802634, -121.788052) 2024-04-23T20:52:58.843Z,1713905578.843 [Default:CheckIn:Read_GPS] Stopped 2024-04-23T20:52:58.843Z,1713905578.843 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-04-23T20:53:06.587Z,1713905586.587 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240423T202958/Courier0013.lzma 2024-04-23T20:53:07.590Z,1713905587.590 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Courier0013.lzma.bak 2024-04-23T20:53:07.590Z,1713905587.590 [DataOverHttps](INFO): SBD MOMSN=19424192 2024-04-23T20:53:25.548Z,1713905605.548 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20240423T202958/Express0014.lzma 2024-04-23T20:53:26.550Z,1713905606.550 [DataOverHttps](INFO): Moved sent file to Logs/20240423T202958/Express0014.lzma.bak 2024-04-23T20:53:26.550Z,1713905606.550 [DataOverHttps](INFO): SBD MOMSN=19424195 2024-04-23T20:53:29.534Z,1713905609.534 [Default:CheckIn:Read_Iridium] Stopped 2024-04-23T20:53:29.534Z,1713905609.534 [Default:CheckIn:C.Wait] Running Loop=1 2024-04-23T20:53:29.534Z,1713905609.534 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-04-23T20:53:31.142Z,1713905611.142 [NAL9602](INFO): Not Powering down - fast GPS 2024-04-23T20:55:39.322Z,1713905739.322 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2024-04-23T20:56:18.045Z,1713905778.045 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:56:32.595Z,1713905792.595 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:56:47.139Z,1713905807.139 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:57:02.097Z,1713905822.097 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:57:16.643Z,1713905836.643 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:57:31.579Z,1713905851.579 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2024-04-23T20:57:34.033Z,1713905854.033 [CommandExec](IMPORTANT): got command restart system 2024-04-23T20:57:36.092Z,1713905856.092 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-23T20:57:36.092Z,1713905856.092 [CommandExec](INFO): Uninitializing the command executive. 2024-04-23T20:57:36.092Z,1713905856.092 [CommandExec](INFO): Uninitializing the command scheduler. 2024-04-23T20:57:36.093Z,1713905856.093 [CommandExec ThreadHandler](INFO): Thread cancelled. 2024-04-23T20:57:36.236Z,1713905856.236 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2024-04-23T20:57:36.236Z,1713905856.236 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2024-04-23T20:57:36.236Z,1713905856.236 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-23T20:57:36.237Z,1713905856.237 [NavChartDb](INFO): Join timeout helper Thread ID is 1068 2024-04-23T20:57:36.624Z,1713905856.624 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2024-04-23T20:57:36.624Z,1713905856.624 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2024-04-23T20:57:36.632Z,1713905856.632 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2024-04-23T20:57:36.632Z,1713905856.632 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2024-04-23T20:57:36.632Z,1713905856.632 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1069 2024-04-23T20:57:37.020Z,1713905857.020 [We