2023-05-10T18:14:19.920Z,1683742459.920 [Supervisor](DEBUG): Initializing supervisor.
2023-05-10T18:14:19.925Z,1683742459.925 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-10T18:14:19.926Z,1683742459.926 [SyncHandler](INFO): Protected caller Thread ID is 4760
2023-05-10T18:14:19.926Z,1683742459.926 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-10T18:14:19.928Z,1683742459.928 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-10T18:14:19.928Z,1683742459.928 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4761
2023-05-10T18:14:19.932Z,1683742459.932 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-10T18:14:19.950Z,1683742459.950 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-10T18:14:19.951Z,1683742459.951 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-10T18:14:19.951Z,1683742459.951 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4762
2023-05-10T18:14:19.955Z,1683742459.955 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-10T18:14:19.956Z,1683742459.956 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-10T18:14:19.957Z,1683742459.957 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4763
2023-05-10T18:14:19.959Z,1683742459.959 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-10T18:14:19.960Z,1683742459.960 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-10T18:14:19.960Z,1683742459.960 [logger ThreadHandler](INFO): Protected caller Thread ID is 4764
2023-05-10T18:14:19.964Z,1683742459.964 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-10T18:14:19.964Z,1683742459.964 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-10T18:14:19.966Z,1683742459.966 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-10T18:14:20.413Z,1683742460.413 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-10T18:14:20.414Z,1683742460.414 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-10T18:14:20.618Z,1683742460.618 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-10T18:14:20.619Z,1683742460.619 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-10T18:14:20.697Z,1683742460.697 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-10T18:14:20.906Z,1683742460.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-10T18:14:20.907Z,1683742460.907 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-10T18:14:20.984Z,1683742460.984 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-10T18:14:21.077Z,1683742461.077 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-10T18:14:21.078Z,1683742461.078 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-10T18:14:21.400Z,1683742461.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-10T18:14:21.401Z,1683742461.401 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-10T18:14:21.529Z,1683742461.529 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-10T18:14:21.529Z,1683742461.529 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-10T18:14:22.008Z,1683742462.008 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-10T18:14:22.009Z,1683742462.009 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-10T18:14:22.185Z,1683742462.185 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-10T18:14:22.186Z,1683742462.186 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-10T18:14:22.566Z,1683742462.566 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-10T18:14:22.567Z,1683742462.567 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-10T18:14:22.835Z,1683742462.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-10T18:14:22.835Z,1683742462.835 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-10T18:14:22.942Z,1683742462.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-10T18:14:22.942Z,1683742462.942 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-10T18:14:23.689Z,1683742463.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-10T18:14:23.690Z,1683742463.690 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-10T18:14:24.013Z,1683742464.013 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-10T18:14:24.013Z,1683742464.013 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-10T18:14:24.546Z,1683742464.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-10T18:14:24.548Z,1683742464.548 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-05-10T18:14:24.549Z,1683742464.549 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-05-10T18:14:24.999Z,1683742464.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-05-10T18:14:25.085Z,1683742465.085 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-05-10T18:14:25.214Z,1683742465.214 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-05-10T18:14:25.298Z,1683742465.298 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-05-10T18:14:25.557Z,1683742465.557 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-10T18:14:25.558Z,1683742465.558 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-05-10T18:14:25.659Z,1683742465.659 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-05-10T18:14:25.768Z,1683742465.768 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-05-10T18:14:25.878Z,1683742465.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-05-10T18:14:26.022Z,1683742466.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-05-10T18:14:26.118Z,1683742466.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-05-10T18:14:26.211Z,1683742466.211 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-05-10T18:14:26.211Z,1683742466.211 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-10T18:14:26.223Z,1683742466.223 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-10T18:14:26.234Z,1683742466.234 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-10T18:14:26.234Z,1683742466.234 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-10T18:14:26.332Z,1683742466.332 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-10T18:14:26.333Z,1683742466.333 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-10T18:14:26.382Z,1683742466.382 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-10T18:14:26.441Z,1683742466.441 [VerticalControl] Loaded
2023-05-10T18:14:26.441Z,1683742466.441 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-10T18:14:26.444Z,1683742466.444 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-10T18:14:26.488Z,1683742466.488 [HorizontalControl] Loaded
2023-05-10T18:14:26.488Z,1683742466.488 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-10T18:14:26.490Z,1683742466.490 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-10T18:14:26.493Z,1683742466.493 [SpeedControl] Loaded
2023-05-10T18:14:26.493Z,1683742466.493 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-10T18:14:26.496Z,1683742466.496 [LoopControl](DEBUG): Construct LoopControl.
2023-05-10T18:14:26.496Z,1683742466.496 [LoopControl] Loaded
2023-05-10T18:14:26.497Z,1683742466.497 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-10T18:14:26.497Z,1683742466.497 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-10T18:14:26.498Z,1683742466.498 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-10T18:14:26.652Z,1683742466.652 [BuoyancyServo] Loaded
2023-05-10T18:14:26.652Z,1683742466.652 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-10T18:14:26.672Z,1683742466.672 [ElevatorServo] Loaded
2023-05-10T18:14:26.672Z,1683742466.672 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-10T18:14:26.691Z,1683742466.691 [MassServo] Loaded
2023-05-10T18:14:26.691Z,1683742466.691 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-10T18:14:26.709Z,1683742466.709 [RudderServo] Loaded
2023-05-10T18:14:26.710Z,1683742466.710 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-10T18:14:26.724Z,1683742466.724 [ThrusterHE] Loaded
2023-05-10T18:14:26.724Z,1683742466.724 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-10T18:14:26.725Z,1683742466.725 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-10T18:14:26.725Z,1683742466.725 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-10T18:14:26.775Z,1683742466.775 [DepthRateCalculator] Loaded
2023-05-10T18:14:26.775Z,1683742466.775 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-10T18:14:26.780Z,1683742466.780 [PitchRateCalculator] Loaded
2023-05-10T18:14:26.780Z,1683742466.780 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-10T18:14:26.790Z,1683742466.790 [SpeedCalculator] Loaded
2023-05-10T18:14:26.790Z,1683742466.790 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-10T18:14:26.794Z,1683742466.794 [YawRateCalculator] Loaded
2023-05-10T18:14:26.795Z,1683742466.795 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-10T18:14:26.813Z,1683742466.813 [ElevatorOffsetCalculator] Loaded
2023-05-10T18:14:26.813Z,1683742466.813 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-10T18:14:26.814Z,1683742466.814 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-10T18:14:26.814Z,1683742466.814 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-10T18:14:26.925Z,1683742466.925 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-10T18:14:26.926Z,1683742466.926 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-10T18:14:26.939Z,1683742466.939 [NavChart] Loaded
2023-05-10T18:14:26.939Z,1683742466.939 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-10T18:14:26.945Z,1683742466.945 [UniversalFixResidualReporter] Loaded
2023-05-10T18:14:26.945Z,1683742466.945 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-10T18:14:26.946Z,1683742466.946 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-10T18:14:26.946Z,1683742466.946 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-10T18:14:27.374Z,1683742467.374 [AHRS_M2] Loaded
2023-05-10T18:14:27.374Z,1683742467.374 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-10T18:14:27.409Z,1683742467.409 [BackseatComponent] Loaded
2023-05-10T18:14:27.410Z,1683742467.410 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-10T18:14:27.411Z,1683742467.411 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E74E0
2023-05-10T18:14:27.411Z,1683742467.411 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4846
2023-05-10T18:14:27.414Z,1683742467.414 [LcmUniversalReporter] Loaded
2023-05-10T18:14:27.414Z,1683742467.414 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-10T18:14:28.237Z,1683742468.237 [BPC1] Loaded
2023-05-10T18:14:28.238Z,1683742468.238 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-10T18:14:28.309Z,1683742468.309 [DataOverHttps] Loaded
2023-05-10T18:14:28.309Z,1683742468.309 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-10T18:14:28.310Z,1683742468.310 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409174E0
2023-05-10T18:14:28.311Z,1683742468.311 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4847
2023-05-10T18:14:28.331Z,1683742468.331 [Depth_Keller] Loaded
2023-05-10T18:14:28.331Z,1683742468.331 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-10T18:14:28.393Z,1683742468.393 [NAL9602] Loaded
2023-05-10T18:14:28.393Z,1683742468.393 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-10T18:14:28.423Z,1683742468.423 [Onboard] Loaded
2023-05-10T18:14:28.423Z,1683742468.423 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-10T18:14:28.425Z,1683742468.425 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409474E0
2023-05-10T18:14:28.425Z,1683742468.425 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4848
2023-05-10T18:14:28.437Z,1683742468.437 [Power24vConverter] Loaded
2023-05-10T18:14:28.437Z,1683742468.437 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-10T18:14:28.450Z,1683742468.450 [Radio_Surface] Loaded
2023-05-10T18:14:28.451Z,1683742468.451 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-10T18:14:28.452Z,1683742468.452 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409774E0
2023-05-10T18:14:28.452Z,1683742468.452 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4849
2023-05-10T18:14:28.538Z,1683742468.538 [DATMMP] Loaded
2023-05-10T18:14:28.539Z,1683742468.539 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2023-05-10T18:14:28.540Z,1683742468.540 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409A84E0
2023-05-10T18:14:28.540Z,1683742468.540 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 4850
2023-05-10T18:14:28.541Z,1683742468.541 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-10T18:14:28.541Z,1683742468.541 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-10T18:14:28.614Z,1683742468.614 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-10T18:14:28.615Z,1683742468.615 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-10T18:14:28.763Z,1683742468.763 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-10T18:14:28.764Z,1683742468.764 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-10T18:14:28.791Z,1683742468.791 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-10T18:14:28.791Z,1683742468.791 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-10T18:14:28.958Z,1683742468.958 [CTD_Seabird] Loaded
2023-05-10T18:14:28.959Z,1683742468.959 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-10T18:14:28.960Z,1683742468.960 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ADE4E0
2023-05-10T18:14:28.960Z,1683742468.960 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4851
2023-05-10T18:14:28.993Z,1683742468.993 [ESPComponent] Loaded
2023-05-10T18:14:28.993Z,1683742468.993 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-10T18:14:29.013Z,1683742469.013 [PAR_Licor] Loaded
2023-05-10T18:14:29.014Z,1683742469.014 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-10T18:14:29.045Z,1683742469.045 [WetLabsBB2FL] Loaded
2023-05-10T18:14:29.045Z,1683742469.045 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-10T18:14:29.046Z,1683742469.046 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0
2023-05-10T18:14:29.046Z,1683742469.046 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4852
2023-05-10T18:14:29.047Z,1683742469.047 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-10T18:14:29.048Z,1683742469.048 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-10T18:14:29.588Z,1683742469.588 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-10T18:14:29.589Z,1683742469.589 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-10T18:14:29.727Z,1683742469.727 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-10T18:14:29.737Z,1683742469.737 [SBIT] Loaded
2023-05-10T18:14:29.737Z,1683742469.737 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-10T18:14:29.740Z,1683742469.740 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-10T18:14:29.752Z,1683742469.752 [IBIT] Loaded
2023-05-10T18:14:29.752Z,1683742469.752 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-10T18:14:29.758Z,1683742469.758 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-10T18:14:29.862Z,1683742469.862 [CBIT] Loaded
2023-05-10T18:14:29.862Z,1683742469.862 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-10T18:14:29.863Z,1683742469.863 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-10T18:14:29.869Z,1683742469.869 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-10T18:14:29.872Z,1683742469.872 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-10T18:14:29.883Z,1683742469.883 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-10T18:14:29.884Z,1683742469.884 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BF14E0
2023-05-10T18:14:29.884Z,1683742469.884 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4853
2023-05-10T18:14:29.888Z,1683742469.888 [Supervisor](INFO): Main Thread ID is 4122
2023-05-10T18:14:29.889Z,1683742469.889 [Supervisor](DEBUG): Running supervisor.
2023-05-10T18:14:29.889Z,1683742469.889 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4854
2023-05-10T18:14:29.890Z,1683742469.890 [CommandExec](INFO): Initializing the command executive.
2023-05-10T18:14:29.891Z,1683742469.891 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4855
2023-05-10T18:14:29.893Z,1683742469.893 [controlThread ThreadHandler](INFO): Handler Thread ID is 4856
2023-05-10T18:14:29.894Z,1683742469.894 [controlThread](DEBUG): Initializing ControlThread
2023-05-10T18:14:29.895Z,1683742469.895 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-10T18:14:29.896Z,1683742469.896 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-10T18:14:29.897Z,1683742469.897 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-10T18:14:29.897Z,1683742469.897 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-10T18:14:29.899Z,1683742469.899 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-10T18:14:29.899Z,1683742469.899 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-10T18:14:29.900Z,1683742469.900 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-10T18:14:29.900Z,1683742469.900 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-10T18:14:29.900Z,1683742469.900 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-10T18:14:29.901Z,1683742469.901 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-10T18:14:29.902Z,1683742469.902 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-10T18:14:29.909Z,1683742469.909 [SBIT](INFO): Initialize SBIT Component.
2023-05-10T18:14:29.909Z,1683742469.909 [SBIT](IMPORTANT): git: 2023-01-24-38-g3a865bb8c
2023-05-10T18:14:29.910Z,1683742469.910 [SBIT](INFO): git hash: 3a865bb8cac9b788bcd3aa40e502ce5ce0bbf34f
2023-05-10T18:14:29.910Z,1683742469.910 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-10T18:14:29.911Z,1683742469.911 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-05-10T18:14:29.912Z,1683742469.912 [SBIT](INFO): Beginning SBIT in 81.000000 seconds.
2023-05-10T18:14:29.913Z,1683742469.913 [IBIT](INFO): Initialize IBIT Component.
2023-05-10T18:14:29.914Z,1683742469.914 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-10T18:14:29.915Z,1683742469.915 [logger ThreadHandler](INFO): Handler Thread ID is 4857
2023-05-10T18:14:29.925Z,1683742469.925 [CBIT](DEBUG): Initialized mux pins.
2023-05-10T18:14:29.925Z,1683742469.925 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-10T18:14:29.933Z,1683742469.933 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4858
2023-05-10T18:14:29.945Z,1683742469.945 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4859
2023-05-10T18:14:29.946Z,1683742469.946 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-10T18:14:29.949Z,1683742469.949 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-10T18:14:29.949Z,1683742469.949 [CBIT](DEBUG): Initializing heartbeat.
2023-05-10T18:14:29.957Z,1683742469.957 [Onboard ThreadHandler](INFO): Handler Thread ID is 4860
2023-05-10T18:14:29.975Z,1683742469.975 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4861
2023-05-10T18:14:29.994Z,1683742469.994 [DATMMP ThreadHandler](INFO): Handler Thread ID is 4862
2023-05-10T18:14:29.994Z,1683742469.994 [DATMMP](INFO): Start
2023-05-10T18:14:29.994Z,1683742469.994 [DATMMP](INFO): Powering up
2023-05-10T18:14:29.995Z,1683742469.995 [DATMMP](DEBUG): Initializing DATMMP.
2023-05-10T18:14:29.998Z,1683742469.998 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4864
2023-05-10T18:14:29.998Z,1683742469.998 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-10T18:14:30.002Z,1683742470.002 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4866
2023-05-10T18:14:30.005Z,1683742470.005 [WetLabsBB2FL](INFO): Powering up
2023-05-10T18:14:30.006Z,1683742470.006 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4868
2023-05-10T18:14:30.009Z,1683742470.009 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-10T18:14:30.009Z,1683742470.009 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-10T18:14:30.010Z,1683742470.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-10T18:14:30.010Z,1683742470.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-10T18:14:30.010Z,1683742470.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-10T18:14:30.010Z,1683742470.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-10T18:14:30.010Z,1683742470.010 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-10T18:14:30.010Z,1683742470.010 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-10T18:14:30.021Z,1683742470.021 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-10T18:14:30.021Z,1683742470.021 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-10T18:14:30.056Z,1683742470.056 [CBIT](DEBUG): Backplane powered.
2023-05-10T18:14:30.058Z,1683742470.058 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-10T18:14:30.070Z,1683742470.070 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T18:14:30.098Z,1683742470.098 [MissionManager](DEBUG):
2023-05-10T18:14:30.098Z,1683742470.098 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-10T18:14:30.177Z,1683742470.177 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-10T18:14:30.178Z,1683742470.178 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-10T18:14:30.193Z,1683742470.193 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T18:14:30.233Z,1683742470.233 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-10T18:14:30.236Z,1683742470.236 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-10T18:14:30.245Z,1683742470.245 [DATMMP](INFO): Starting
2023-05-10T18:14:30.258Z,1683742470.258 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-10T18:14:30.277Z,1683742470.277 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2023-05-10T18:14:30.281Z,1683742470.281 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,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,
2023-05-10T18:14:30.287Z,1683742470.287 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-10T18:14:30.351Z,1683742470.351 [Power24vConverter](INFO): Powering up.
2023-05-10T18:14:30.381Z,1683742470.381 [Radio_Surface](INFO): Powering up
2023-05-10T18:14:30.391Z,1683742470.391 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-10T18:14:30.401Z,1683742470.401 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-10T18:14:30.402Z,1683742470.402 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-10T18:14:30.409Z,1683742470.409 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-10T18:14:30.410Z,1683742470.410 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-10T18:14:30.421Z,1683742470.421 [MassServo](DEBUG): Initializing MassServo.
2023-05-10T18:14:30.422Z,1683742470.422 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-10T18:14:30.429Z,1683742470.429 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-10T18:14:30.430Z,1683742470.430 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-10T18:14:30.437Z,1683742470.437 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-10T18:14:30.497Z,1683742470.497 [DATMMP](INFO): Starting
2023-05-10T18:14:30.749Z,1683742470.749 [DATMMP](INFO): Starting
2023-05-10T18:14:31.001Z,1683742471.001 [DATMMP](INFO): Starting
2023-05-10T18:14:31.253Z,1683742471.253 [DATMMP](INFO): Starting
2023-05-10T18:14:31.505Z,1683742471.505 [DATMMP](INFO): Starting
2023-05-10T18:14:31.758Z,1683742471.758 [DATMMP](INFO): Starting
2023-05-10T18:14:32.009Z,1683742472.009 [DATMMP](INFO): Starting
2023-05-10T18:14:32.113Z,1683742472.113 [WetLabsBB2FL](INFO): Powering down
2023-05-10T18:14:32.261Z,1683742472.261 [DATMMP](INFO): Starting
2023-05-10T18:14:32.513Z,1683742472.513 [DATMMP](INFO): Starting
2023-05-10T18:14:32.766Z,1683742472.766 [DATMMP](INFO): Starting
2023-05-10T18:14:33.017Z,1683742473.017 [DATMMP](INFO): Starting
2023-05-10T18:14:33.269Z,1683742473.269 [DATMMP](INFO): Starting
2023-05-10T18:14:33.521Z,1683742473.521 [DATMMP](INFO): Starting
2023-05-10T18:14:33.773Z,1683742473.773 [DATMMP](INFO): Starting
2023-05-10T18:14:34.025Z,1683742474.025 [DATMMP](INFO): Starting
2023-05-10T18:14:34.277Z,1683742474.277 [DATMMP](INFO): Starting
2023-05-10T18:14:34.529Z,1683742474.529 [DATMMP](INFO): Starting
2023-05-10T18:14:34.781Z,1683742474.781 [DATMMP](INFO): Starting
2023-05-10T18:14:35.033Z,1683742475.033 [DATMMP](INFO): Starting
2023-05-10T18:14:35.285Z,1683742475.285 [DATMMP](INFO): Starting
2023-05-10T18:14:35.537Z,1683742475.537 [DATMMP](INFO): Starting
2023-05-10T18:14:35.789Z,1683742475.789 [DATMMP](INFO): Starting
2023-05-10T18:14:36.041Z,1683742476.041 [DATMMP](INFO): Starting
2023-05-10T18:14:36.181Z,1683742476.181 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-10T18:14:36.293Z,1683742476.293 [DATMMP](INFO): Starting
2023-05-10T18:14:36.545Z,1683742476.545 [DATMMP](INFO): Starting
2023-05-10T18:14:36.797Z,1683742476.797 [DATMMP](INFO): Starting
2023-05-10T18:14:37.049Z,1683742477.049 [DATMMP](INFO): Starting
2023-05-10T18:14:37.301Z,1683742477.301 [DATMMP](INFO): Starting
2023-05-10T18:14:37.553Z,1683742477.553 [DATMMP](INFO): Starting
2023-05-10T18:14:37.805Z,1683742477.805 [DATMMP](INFO): Starting
2023-05-10T18:14:38.057Z,1683742478.057 [DATMMP](INFO): Starting
2023-05-10T18:14:38.309Z,1683742478.309 [DATMMP](INFO): Starting
2023-05-10T18:14:38.561Z,1683742478.561 [DATMMP](INFO): Starting
2023-05-10T18:14:38.813Z,1683742478.813 [DATMMP](INFO): Starting
2023-05-10T18:14:39.065Z,1683742479.065 [DATMMP](INFO): Starting
2023-05-10T18:14:39.317Z,1683742479.317 [DATMMP](INFO): Starting
2023-05-10T18:14:39.569Z,1683742479.569 [DATMMP](INFO): Starting
2023-05-10T18:14:39.821Z,1683742479.821 [DATMMP](INFO): Starting
2023-05-10T18:14:40.073Z,1683742480.073 [DATMMP](INFO): Starting
2023-05-10T18:14:40.325Z,1683742480.325 [DATMMP](INFO): Starting
2023-05-10T18:14:40.577Z,1683742480.577 [DATMMP](INFO): Starting
2023-05-10T18:14:40.829Z,1683742480.829 [DATMMP](INFO): Starting
2023-05-10T18:14:41.081Z,1683742481.081 [DATMMP](INFO): Starting
2023-05-10T18:14:41.333Z,1683742481.333 [DATMMP](INFO): Starting
2023-05-10T18:14:41.585Z,1683742481.585 [DATMMP](INFO): Starting
2023-05-10T18:14:41.837Z,1683742481.837 [DATMMP](INFO): Starting
2023-05-10T18:14:42.089Z,1683742482.089 [DATMMP](INFO): Starting
2023-05-10T18:14:42.089Z,1683742482.089 [DATMMP](INFO): DAT read:
2023-05-10T18:14:42.090Z,1683742482.090 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series
2023-05-10T18:14:42.341Z,1683742482.341 [DATMMP](INFO): Starting
2023-05-10T18:14:42.593Z,1683742482.593 [DATMMP](INFO): Starting
2023-05-10T18:14:42.845Z,1683742482.845 [DATMMP](INFO): Starting
2023-05-10T18:14:43.097Z,1683742483.097 [DATMMP](INFO): Starting
2023-05-10T18:14:43.349Z,1683742483.349 [DATMMP](INFO): Starting
2023-05-10T18:14:43.601Z,1683742483.601 [DATMMP](INFO): Starting
2023-05-10T18:14:43.853Z,1683742483.853 [DATMMP](INFO): Starting
2023-05-10T18:14:43.853Z,1683742483.853 [DATMMP](INFO): DAT read: MF Frequency Band
2023-05-10T18:14:43.854Z,1683742483.854 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2023-05-10T18:14:43.855Z,1683742483.855 [DATMMP](INFO): DAT read: Apr 10 2000 18:14:37
2023-05-10T18:14:44.105Z,1683742484.105 [DATMMP](INFO): Starting
2023-05-10T18:14:44.357Z,1683742484.357 [DATMMP](INFO): Starting
2023-05-10T18:14:44.609Z,1683742484.609 [DATMMP](INFO): Starting
2023-05-10T18:14:44.861Z,1683742484.861 [DATMMP](INFO): Starting
2023-05-10T18:14:45.113Z,1683742485.113 [DATMMP](INFO): Starting
2023-05-10T18:14:45.114Z,1683742485.114 [DATMMP](INFO): DAT read: Features enabled [Bearing]
2023-05-10T18:14:45.115Z,1683742485.115 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2023-05-10T18:14:45.115Z,1683742485.115 [DATMMP](INFO): commRate: 800
2023-05-10T18:14:45.365Z,1683742485.365 [DATMMP](INFO): Starting
2023-05-10T18:14:45.617Z,1683742485.617 [DATMMP](INFO): Starting
2023-05-10T18:14:45.869Z,1683742485.869 [DATMMP](INFO): Starting
2023-05-10T18:14:46.121Z,1683742486.121 [DATMMP](INFO): Starting
2023-05-10T18:14:46.373Z,1683742486.373 [DATMMP](INFO): Starting
2023-05-10T18:14:46.625Z,1683742486.625 [DATMMP](INFO): Starting
2023-05-10T18:14:46.877Z,1683742486.877 [DATMMP](INFO): Starting
2023-05-10T18:14:47.129Z,1683742487.129 [DATMMP](INFO): Starting
2023-05-10T18:14:47.181Z,1683742487.181 [DATMMP](INFO): entering command mode
2023-05-10T18:14:47.381Z,1683742487.381 [DATMMP](INFO): Starting
2023-05-10T18:14:47.381Z,1683742487.381 [DATMMP](INFO): DAT read:
2023-05-10T18:14:47.381Z,1683742487.381 [DATMMP](INFO): DAT read: user:1>
2023-05-10T18:14:47.382Z,1683742487.382 [DATMMP](DEBUG): read user prompt 1: user:1>
2023-05-10T18:14:47.382Z,1683742487.382 [DATMMP](INFO): entering MMP mode
2023-05-10T18:14:47.633Z,1683742487.633 [DATMMP](INFO): Starting
2023-05-10T18:14:47.634Z,1683742487.634 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:14:47.636Z,1683742487.636 [DATMMP](INFO): status rx: x1
2023-05-10T18:14:47.636Z,1683742487.636 [DATMMP](INFO): MMP status: 1: started
2023-05-10T18:14:47.636Z,1683742487.636 [DATMMP](INFO): Received message type: status
2023-05-10T18:14:47.636Z,1683742487.636 [DATMMP](INFO): Handled
2023-05-10T18:14:47.885Z,1683742487.885 [DATMMP](INFO): Starting
2023-05-10T18:14:47.886Z,1683742487.886 [DATMMP](INFO): Sent Tx Power Config 8
2023-05-10T18:14:47.887Z,1683742487.887 [DATMMP](INFO): Setting local address: 5
2023-05-10T18:14:47.888Z,1683742487.888 [DATMMP](INFO): Setting time to: 18:14:47 And date to:5/10/2023
2023-05-10T18:14:48.137Z,1683742488.137 [DATMMP](INFO): Starting
2023-05-10T18:14:48.137Z,1683742488.137 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:14:48.138Z,1683742488.138 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0
2023-05-10T18:14:48.138Z,1683742488.138 [DATMMP](INFO): Received message type: mdmpower
2023-05-10T18:14:48.138Z,1683742488.138 [DATMMP](INFO): Handled
2023-05-10T18:14:48.389Z,1683742488.389 [DATMMP](INFO): Starting
2023-05-10T18:14:48.389Z,1683742488.389 [DATMMP](INFO): GSXN notify for xid: 10
2023-05-10T18:14:48.390Z,1683742488.390 [DATMMP](INFO): sreg_txpower rx: x8
2023-05-10T18:14:48.390Z,1683742488.390 [DATMMP](INFO): Received message type: sreg_txpower
2023-05-10T18:14:48.390Z,1683742488.390 [DATMMP](INFO): Match for : sreg_txpower
2023-05-10T18:14:48.390Z,1683742488.390 [DATMMP](INFO): ACK
2023-05-10T18:14:48.641Z,1683742488.641 [DATMMP](INFO): Starting
2023-05-10T18:14:48.642Z,1683742488.642 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:14:48.642Z,1683742488.642 [DATMMP](INFO): mdmlocal rx: x5 x0 x0 x0
2023-05-10T18:14:48.643Z,1683742488.643 [DATMMP](INFO): Received message type: mdmlocal
2023-05-10T18:14:48.643Z,1683742488.643 [DATMMP](INFO): Handled
2023-05-10T18:14:48.893Z,1683742488.893 [DATMMP](INFO): Starting
2023-05-10T18:14:48.893Z,1683742488.893 [DATMMP](INFO): GSXN notify for xid: 11
2023-05-10T18:14:48.894Z,1683742488.894 [DATMMP](INFO): sreg_locaddr rx: x5
2023-05-10T18:14:48.894Z,1683742488.894 [DATMMP](INFO): Received message type: sreg_locaddr
2023-05-10T18:14:48.894Z,1683742488.894 [DATMMP](INFO): Match for : sreg_locaddr
2023-05-10T18:14:48.894Z,1683742488.894 [DATMMP](INFO): ACK
2023-05-10T18:14:49.145Z,1683742489.145 [DATMMP](INFO): Starting
2023-05-10T18:14:49.146Z,1683742489.146 [DATMMP](INFO): GSXN notify for xid: 12
2023-05-10T18:14:49.147Z,1683742489.147 [DATMMP](INFO): timedate rx: x0 x12 xE x2F x4 xA x7B x0
2023-05-10T18:14:49.147Z,1683742489.147 [DATMMP](INFO): Received message type: timedate
2023-05-10T18:14:49.147Z,1683742489.147 [DATMMP](INFO): Match for : timedate
2023-05-10T18:14:49.147Z,1683742489.147 [DATMMP](INFO): ACK
2023-05-10T18:14:49.397Z,1683742489.397 [DATMMP](INFO): Starting
2023-05-10T18:14:49.397Z,1683742489.397 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:14:49.398Z,1683742489.398 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0
2023-05-10T18:14:49.398Z,1683742489.398 [DATMMP](INFO): Received message type: sys_verb
2023-05-10T18:14:49.398Z,1683742489.398 [DATMMP](INFO): Handled
2023-05-10T18:14:49.649Z,1683742489.649 [DATMMP](INFO): Starting
2023-05-10T18:14:49.649Z,1683742489.649 [DATMMP](INFO): GSXN notify for xid: 13
2023-05-10T18:14:49.650Z,1683742489.650 [DATMMP](INFO): sreg_verbosity rx: x0
2023-05-10T18:14:49.650Z,1683742489.650 [DATMMP](INFO): Received message type: sreg_verbosity
2023-05-10T18:14:49.650Z,1683742489.650 [DATMMP](INFO): Match for : sreg_verbosity
2023-05-10T18:14:49.650Z,1683742489.650 [DATMMP](INFO): ACK
2023-05-10T18:14:49.901Z,1683742489.901 [DATMMP](INFO): Starting
2023-05-10T18:14:49.901Z,1683742489.901 [DATMMP](INFO): GSXN notify for xid: 14
2023-05-10T18:14:49.902Z,1683742489.902 [DATMMP](INFO): version rx: x2 x5
2023-05-10T18:14:49.902Z,1683742489.902 [DATMMP](INFO): DatMMPVersion: 2.5
2023-05-10T18:14:49.902Z,1683742489.902 [DATMMP](INFO): Received message type: version
2023-05-10T18:14:49.903Z,1683742489.903 [DATMMP](INFO): Match for : version
2023-05-10T18:14:49.903Z,1683742489.903 [DATMMP](INFO): ACK
2023-05-10T18:14:49.903Z,1683742489.903 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-05-10T18:14:58.574Z,1683742498.574 [NAL9602](INFO): Powering up NAL9602
2023-05-10T18:15:04.533Z,1683742504.533 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:15:04.534Z,1683742504.534 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2023-05-10T18:15:04.534Z,1683742504.534 [DATMMP](INFO): Received message type: timesync
2023-05-10T18:15:04.534Z,1683742504.534 [DATMMP](INFO): Handled
2023-05-10T18:15:09.486Z,1683742509.486 [NAL9602](INFO): NAL9602 initialized
2023-05-10T18:15:14.361Z,1683742514.361 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:15:14.362Z,1683742514.362 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2023-05-10T18:15:14.362Z,1683742514.362 [DATMMP](INFO): Received message type: timesync
2023-05-10T18:15:14.362Z,1683742514.362 [DATMMP](INFO): Handled
2023-05-10T18:15:51.532Z,1683742551.532 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-10T18:15:51.537Z,1683742551.537 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-10T18:16:02.474Z,1683742562.474 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.010690
CHAN A1 (24V): -0.007619
CHAN A2 (12V): -0.004634
CHAN A3 (5V): -0.003179
CHAN B0 (3.3V): -0.001117
CHAN B1 (3.15aV): -0.001265
CHAN B2 (3.15bV): -0.001652
CHAN B3 (GND): -0.000657
OPEN: 0.004578
Full Scale: +/- 1 mA
2023-05-10T18:16:08.790Z,1683742568.790 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-10T18:16:08.794Z,1683742568.794 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2023-05-10T18:16:08.794Z,1683742568.794 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-10T18:16:08.798Z,1683742568.798 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2023-05-10T18:16:08.798Z,1683742568.798 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-10T18:16:08.802Z,1683742568.802 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2023-05-10T18:16:08.802Z,1683742568.802 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-05-10T18:16:08.803Z,1683742568.803 [CommandExec](IMPORTANT): got command report touch acoustic_contact_range
2023-05-10T18:16:09.001Z,1683742569.001 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-10T18:16:45.265Z,1683742605.265 [SBIT](IMPORTANT): SBIT PASSED
2023-05-10T18:16:45.265Z,1683742605.265 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-10T18:16:45.266Z,1683742605.266 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;
2023-05-10T18:16:45.266Z,1683742605.266 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;
2023-05-10T18:16:45.266Z,1683742605.266 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;
2023-05-10T18:16:45.266Z,1683742605.266 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=184.896478 cubic_centimeter;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;
2023-05-10T18:16:45.267Z,1683742605.267 [SBIT](IMPORTANT): VerticalControl.massDefault=15.484465 millimeter;
2023-05-10T18:16:45.667Z,1683742605.667 [MissionManager](IMPORTANT): Started mission Startup
2023-05-10T18:16:45.668Z,1683742605.668 [Startup] Running Loop=1
2023-05-10T18:16:45.668Z,1683742605.668 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-10T18:16:45.668Z,1683742605.668 [Startup:A.GoToSurface] Running Loop=1
2023-05-10T18:16:45.668Z,1683742605.668 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T18:16:45.669Z,1683742605.669 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T18:16:45.669Z,1683742605.669 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T18:16:45.670Z,1683742605.670 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T18:16:45.670Z,1683742605.670 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T18:16:45.670Z,1683742605.670 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T18:16:45.672Z,1683742605.672 [Startup:StartupSatComms] Running Loop=1
2023-05-10T18:16:45.672Z,1683742605.672 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-10T18:16:45.672Z,1683742605.672 [Startup:StartupSatComms:A] Running Loop=1
2023-05-10T18:16:46.072Z,1683742606.072 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-10T18:16:46.072Z,1683742606.072 [Startup:StartupSatComms:A] Stopped
2023-05-10T18:16:46.072Z,1683742606.072 [Startup:StartupSatComms:B] Running Loop=1
2023-05-10T18:16:46.472Z,1683742606.472 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T18:16:56.955Z,1683742616.955 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:16:57.931Z,1683742617.931 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004619
2023-05-10T18:17:05.288Z,1683742625.288 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230510T174355/Courier0010.lzma
2023-05-10T18:17:06.307Z,1683742626.307 [DataOverHttps](INFO): Moved sent file to Logs/20230510T174355/Courier0010.lzma.bak
2023-05-10T18:17:06.307Z,1683742626.307 [DataOverHttps](INFO): SBD MOMSN=18286712
2023-05-10T18:17:10.282Z,1683742630.282 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:17:22.512Z,1683742642.512 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230510T181419/Courier0000.lzma
2023-05-10T18:17:23.514Z,1683742643.514 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0000.lzma.bak
2023-05-10T18:17:23.514Z,1683742643.514 [DataOverHttps](INFO): SBD MOMSN=18286718
2023-05-10T18:17:23.614Z,1683742643.614 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:17:33.546Z,1683742653.546 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683742643 second
2023-05-10T18:17:36.953Z,1683742656.953 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:17:40.616Z,1683742660.616 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20230510T174355/Express0011.lzma
2023-05-10T18:17:41.630Z,1683742661.630 [DataOverHttps](INFO): Moved sent file to Logs/20230510T174355/Express0011.lzma.bak
2023-05-10T18:17:41.631Z,1683742661.631 [DataOverHttps](INFO): SBD MOMSN=18286721
2023-05-10T18:17:46.130Z,1683742666.130 [CommandExec](IMPORTANT): got command set NAL9602.platform_communications 1 bool
2023-05-10T18:17:46.258Z,1683742666.258 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-10T18:16:46.1Z
2023-05-10T18:17:46.258Z,1683742666.258 [Startup:StartupSatComms:B] Stopped
2023-05-10T18:17:46.258Z,1683742666.258 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-10T18:17:46.258Z,1683742666.258 [Startup:StartupSatComms] Stopped
2023-05-10T18:17:46.258Z,1683742666.258 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-10T18:17:46.259Z,1683742666.259 [Startup](INFO): Completed Startup
2023-05-10T18:17:46.259Z,1683742666.259 [MissionManager](INFO): Startup is completed.
2023-05-10T18:17:46.259Z,1683742666.259 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-10T18:17:46.259Z,1683742666.259 [Startup] Stopped
2023-05-10T18:17:46.259Z,1683742666.259 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-10T18:17:46.259Z,1683742666.259 [Startup:A.GoToSurface] Stopped
2023-05-10T18:17:46.259Z,1683742666.259 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T18:17:46.669Z,1683742666.669 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T18:17:46.670Z,1683742666.670 [Default] Running Loop=1
2023-05-10T18:17:46.670Z,1683742666.670 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T18:17:46.670Z,1683742666.670 [Default:B.GoToSurface] Running Loop=1
2023-05-10T18:17:46.670Z,1683742666.670 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T18:17:46.670Z,1683742666.670 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T18:17:46.670Z,1683742666.670 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T18:17:46.671Z,1683742666.671 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T18:17:46.671Z,1683742666.671 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T18:17:46.671Z,1683742666.671 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T18:17:46.672Z,1683742666.672 [Default:A.Wait] Running Loop=1
2023-05-10T18:17:46.672Z,1683742666.672 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T18:17:50.286Z,1683742670.286 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:17:55.196Z,1683742675.196 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T18:17:55.196Z,1683742675.196 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T18:17:55.281Z,1683742675.281 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 9.000000 count
2023-05-10T18:17:55.285Z,1683742675.285 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-10T18:17:55.288Z,1683742675.288 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-10T18:17:55.292Z,1683742675.292 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-10T18:17:55.295Z,1683742675.295 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-10T18:17:55.299Z,1683742675.299 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-10T18:17:55.302Z,1683742675.302 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-10T18:17:55.306Z,1683742675.306 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-10T18:17:55.309Z,1683742675.309 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-10T18:17:55.312Z,1683742675.312 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-10T18:17:55.421Z,1683742675.421 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-10T18:17:55.439Z,1683742675.439 [MissionManager](DEBUG):
The acoustic address of the asset to be tracked. 21 is waveglider Tiny
9
Depth of acoustic target if known and fixed (or nearly fixed). For
example, if the acoustic target is a Wave Glider, set it to zero. This
will improve 2D projected position estimates in the Earth reference
frame. Defaults to NaN.
0
How long to wait between acoustic queries
15
Number of return pings to request with each acoustic query (more than 1
will activate oneway mode)
1
Number of fixes to average to produce smoothed lat/lon/dep output
2
Number of fixes to ignore at the start of mission (as the vehicle just
leaves surface, contact's location estimate especailly bearing can be
erroneous. Initialized to 8, corresponding to 2 minutes if query
interval TrackingUpdatePeriod = 15 s.
2
1
Modem ID1.
9
Modem ID2.
5
Modem ID. Set to modemId1 or modemId2. Initialized to 1.
1
2023-05-10T18:17:55.451Z,1683742675.451 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T18:17:55.577Z,1683742675.577 [Default] Stopped
2023-05-10T18:17:55.577Z,1683742675.577 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T18:17:55.577Z,1683742675.577 [Default:A.Wait] Stopped
2023-05-10T18:17:55.577Z,1683742675.577 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T18:17:55.578Z,1683742675.578 [Default:B.GoToSurface] Stopped
2023-05-10T18:17:55.578Z,1683742675.578 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T18:17:55.578Z,1683742675.578 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-10T18:17:55.578Z,1683742675.578 [senddata_direct_and_track_test] Running Loop=1
2023-05-10T18:17:55.578Z,1683742675.578 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-10T18:17:55.578Z,1683742675.578 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T18:17:55.578Z,1683742675.578 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-10T18:17:55.579Z,1683742675.579 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-10T18:17:55.579Z,1683742675.579 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-10T18:17:55.579Z,1683742675.579 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-10T18:17:55.579Z,1683742675.579 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T18:17:55.579Z,1683742675.579 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T18:18:00.266Z,1683742680.266 [DataOverHttps](INFO): Sending 1184 bytes from file Logs/20230510T181419/Express0001.lzma
2023-05-10T18:18:01.266Z,1683742681.266 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0001.lzma.bak
2023-05-10T18:18:01.266Z,1683742681.266 [DataOverHttps](INFO): SBD MOMSN=18286726
2023-05-10T18:18:04.090Z,1683742684.090 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:18:10.925Z,1683742690.925 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T18:18:11.089Z,1683742691.089 [DATMMP](INFO): ****** received valid address query ******
2023-05-10T18:18:11.089Z,1683742691.089 [DATMMP](INFO): ****** received valid ping request ******
2023-05-10T18:18:11.090Z,1683742691.090 [DATMMP](INFO): Querying Benthos address 9
2023-05-10T18:18:11.341Z,1683742691.341 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:11.342Z,1683742691.342 [DATMMP](INFO): timestamp rx: x0 x12 x12 x9 xDA0
2023-05-10T18:18:11.342Z,1683742691.342 [DATMMP](INFO): Received message type: timestamp
2023-05-10T18:18:11.342Z,1683742691.342 [DATMMP](INFO): Handled
2023-05-10T18:18:11.343Z,1683742691.343 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:11.593Z,1683742691.593 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:11.845Z,1683742691.845 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:12.097Z,1683742692.097 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:12.349Z,1683742692.349 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:12.601Z,1683742692.601 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:12.853Z,1683742692.853 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:13.105Z,1683742693.105 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:13.357Z,1683742693.357 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:13.609Z,1683742693.609 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:13.610Z,1683742693.610 [DATMMP](INFO): doppler rx: xFFFF
2023-05-10T18:18:13.610Z,1683742693.610 [DATMMP](INFO): Received message type: doppler
2023-05-10T18:18:13.610Z,1683742693.610 [DATMMP](INFO): Handled
2023-05-10T18:18:13.610Z,1683742693.610 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:13.861Z,1683742693.861 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:13.862Z,1683742693.862 [DATMMP](INFO): timestamp rx: x1 x12 x12 xB xED0
2023-05-10T18:18:13.863Z,1683742693.863 [DATMMP](INFO): Rx dataTimestamp_ set to:1683742728.032768
2023-05-10T18:18:13.863Z,1683742693.863 [DATMMP](INFO): Rx ping set to:1683742693.862365
2023-05-10T18:18:13.864Z,1683742693.864 [DATMMP](INFO): Received message type: timestamp
2023-05-10T18:18:13.864Z,1683742693.864 [DATMMP](INFO): Handled
2023-05-10T18:18:13.864Z,1683742693.864 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:14.114Z,1683742694.114 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:14.365Z,1683742694.365 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:14.366Z,1683742694.366 [DATMMP](INFO): nav_stat rx: x0 x1 x1
2023-05-10T18:18:14.366Z,1683742694.366 [DATMMP](INFO): Received message type: nav_stat
2023-05-10T18:18:14.366Z,1683742694.366 [DATMMP](INFO): Handled
2023-05-10T18:18:14.366Z,1683742694.366 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:14.617Z,1683742694.617 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:14.618Z,1683742694.618 [DATMMP](INFO): directional_debug rx: xDF4 x244 x23 x10E x1060 x1231 x1142 x1573
2023-05-10T18:18:14.620Z,1683742694.620 [DATMMP](INFO): Received message type: directional_debug
2023-05-10T18:18:14.620Z,1683742694.620 [DATMMP](INFO): Handled
2023-05-10T18:18:14.620Z,1683742694.620 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:14.869Z,1683742694.869 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:14.871Z,1683742694.871 [DATMMP](INFO): directional rx: xDED x210 x5F8 xFDBC xBF1 xFDC2 x0 x613 x3 xFFEE x27B5966 x-43569E0
2023-05-10T18:18:14.873Z,1683742694.873 [DATMMP](INFO): Received message type: directional
2023-05-10T18:18:14.873Z,1683742694.873 [DATMMP](INFO): Handled
2023-05-10T18:18:14.873Z,1683742694.873 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:15.121Z,1683742695.121 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:15.123Z,1683742695.123 [DATMMP](INFO): remote_header rx: x0 x7A x0 x4C x2E x5 x9 x0
2023-05-10T18:18:15.123Z,1683742695.123 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-10T18:18:15.123Z,1683742695.123 [DATMMP](INFO): Received message type: remote_header
2023-05-10T18:18:15.123Z,1683742695.123 [DATMMP](INFO): Handled
2023-05-10T18:18:15.124Z,1683742695.124 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:15.373Z,1683742695.373 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:15.375Z,1683742695.375 [DATMMP](INFO): acstats rx: x9 x0 xFFFF x2A5 x22 x9F xB6 xBF xD xFFFF x0 x24 x0 x0
2023-05-10T18:18:15.375Z,1683742695.375 [DATMMP](INFO): Received message type: acstats
2023-05-10T18:18:15.375Z,1683742695.375 [DATMMP](INFO): Handled
2023-05-10T18:18:15.375Z,1683742695.375 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:15.625Z,1683742695.625 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-10T18:18:15.626Z,1683742695.626 [DATMMP](INFO): cmd_result rx: x2 x9 x0 x4
2023-05-10T18:18:15.626Z,1683742695.626 [DATMMP](ERROR): 4:Command error: data
2023-05-10T18:18:15.627Z,1683742695.627 [DATMMP](ERROR): 4:COMPLETE
2023-05-10T18:18:15.627Z,1683742695.627 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:15.877Z,1683742695.877 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:16.134Z,1683742696.134 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:16.381Z,1683742696.381 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:16.633Z,1683742696.633 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:16.885Z,1683742696.885 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:17.137Z,1683742697.137 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:17.389Z,1683742697.389 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:17.426Z,1683742697.426 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:18:17.641Z,1683742697.641 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:17.893Z,1683742697.893 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:18.145Z,1683742698.145 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:18.397Z,1683742698.397 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:18.649Z,1683742698.649 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:18.901Z,1683742698.901 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:19.153Z,1683742699.153 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:19.405Z,1683742699.405 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:19.657Z,1683742699.657 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:19.910Z,1683742699.910 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:20.162Z,1683742700.162 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:20.413Z,1683742700.413 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:20.665Z,1683742700.665 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:20.917Z,1683742700.917 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:21.169Z,1683742701.169 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:26.285Z,1683742706.285 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T18:18:26.462Z,1683742706.462 [DATMMP](INFO): ****** received valid address query ******
2023-05-10T18:18:26.462Z,1683742706.462 [DATMMP](INFO): ****** received valid ping request ******
2023-05-10T18:18:26.462Z,1683742706.462 [DATMMP](INFO): Querying Benthos address 9
2023-05-10T18:18:26.713Z,1683742706.713 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:26.714Z,1683742706.714 [DATMMP](INFO): timestamp rx: x0 x12 x12 x18 x1D3F
2023-05-10T18:18:26.714Z,1683742706.714 [DATMMP](INFO): Received message type: timestamp
2023-05-10T18:18:26.714Z,1683742706.714 [DATMMP](INFO): Handled
2023-05-10T18:18:26.715Z,1683742706.715 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:26.965Z,1683742706.965 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:27.217Z,1683742707.217 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:27.469Z,1683742707.469 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:27.721Z,1683742707.721 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:27.973Z,1683742707.973 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:28.225Z,1683742708.225 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:28.477Z,1683742708.477 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:28.729Z,1683742708.729 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:28.982Z,1683742708.982 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:28.982Z,1683742708.982 [DATMMP](INFO): doppler rx: x0
2023-05-10T18:18:28.982Z,1683742708.982 [DATMMP](INFO): Received message type: doppler
2023-05-10T18:18:28.982Z,1683742708.982 [DATMMP](INFO): Handled
2023-05-10T18:18:28.983Z,1683742708.983 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:29.233Z,1683742709.233 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:29.234Z,1683742709.234 [DATMMP](INFO): timestamp rx: x1 x12 x12 x1A x1E6F
2023-05-10T18:18:29.235Z,1683742709.235 [DATMMP](INFO): Rx dataTimestamp_ set to:1683742718.088064
2023-05-10T18:18:29.235Z,1683742709.235 [DATMMP](INFO): Rx ping set to:1683742709.234198
2023-05-10T18:18:29.235Z,1683742709.235 [DATMMP](INFO): Received message type: timestamp
2023-05-10T18:18:29.235Z,1683742709.235 [DATMMP](INFO): Handled
2023-05-10T18:18:29.235Z,1683742709.235 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:29.485Z,1683742709.485 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:29.737Z,1683742709.737 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:29.738Z,1683742709.738 [DATMMP](INFO): nav_stat rx: x0 x1 x1
2023-05-10T18:18:29.738Z,1683742709.738 [DATMMP](INFO): Received message type: nav_stat
2023-05-10T18:18:29.738Z,1683742709.738 [DATMMP](INFO): Handled
2023-05-10T18:18:29.738Z,1683742709.738 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:29.989Z,1683742709.989 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:29.991Z,1683742709.991 [DATMMP](INFO): directional_debug rx: x868 x9 x21 x96E x1040 x1231 x11A2 x1553
2023-05-10T18:18:29.992Z,1683742709.992 [DATMMP](INFO): Received message type: directional_debug
2023-05-10T18:18:29.992Z,1683742709.992 [DATMMP](INFO): Handled
2023-05-10T18:18:29.992Z,1683742709.992 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:30.241Z,1683742710.241 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:30.243Z,1683742710.243 [DATMMP](INFO): directional rx: x86A xFFF0 xB84 xFFF7 x375 xFFE8 x0 x601 x4 xFFEE x27B5966 x-43569E0
2023-05-10T18:18:30.245Z,1683742710.245 [DATMMP](INFO): Received message type: directional
2023-05-10T18:18:30.245Z,1683742710.245 [DATMMP](INFO): Handled
2023-05-10T18:18:30.245Z,1683742710.245 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:30.493Z,1683742710.493 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:30.494Z,1683742710.494 [DATMMP](INFO): remote_header rx: x0 x7A x0 x4B x7B x5 x9 x0
2023-05-10T18:18:30.495Z,1683742710.495 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-10T18:18:30.495Z,1683742710.495 [DATMMP](INFO): Received message type: remote_header
2023-05-10T18:18:30.495Z,1683742710.495 [DATMMP](INFO): Handled
2023-05-10T18:18:30.495Z,1683742710.495 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:30.745Z,1683742710.745 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T18:18:30.747Z,1683742710.747 [DATMMP](INFO): acstats rx: x9 x0 x0 x2C7 x22 x8A xA9 xBC xD xFFFF x0 x23 x0 x0
2023-05-10T18:18:30.747Z,1683742710.747 [DATMMP](INFO): Received message type: acstats
2023-05-10T18:18:30.747Z,1683742710.747 [DATMMP](INFO): Handled
2023-05-10T18:18:30.747Z,1683742710.747 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:30.997Z,1683742710.997 [DATMMP](INFO): GSXN notify for xid: 16
2023-05-10T18:18:30.998Z,1683742710.998 [DATMMP](INFO): cmd_result rx: x2 x9 x0 x4
2023-05-10T18:18:30.999Z,1683742710.999 [DATMMP](ERROR): 4:Command error: data
2023-05-10T18:18:30.999Z,1683742710.999 [DATMMP](ERROR): 4:COMPLETE
2023-05-10T18:18:30.999Z,1683742710.999 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:31.104Z,1683742711.104 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:18:31.249Z,1683742711.249 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:31.501Z,1683742711.501 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:31.753Z,1683742711.753 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:32.005Z,1683742712.005 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:32.257Z,1683742712.257 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:32.509Z,1683742712.509 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:32.761Z,1683742712.761 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:33.013Z,1683742713.013 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:33.265Z,1683742713.265 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:33.517Z,1683742713.517 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:33.769Z,1683742713.769 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:34.021Z,1683742714.021 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:34.033Z,1683742714.033 [CommandExec](IMPORTANT): got command stop
2023-05-10T18:18:34.034Z,1683742714.034 [CommandExec](IMPORTANT): Scheduling is paused
2023-05-10T18:18:34.034Z,1683742714.034 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-05-10T18:18:34.273Z,1683742714.273 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:34.335Z,1683742714.335 [MissionManager](INFO): MissionManager is completed.
2023-05-10T18:18:34.335Z,1683742714.335 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test] Stopped
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-10T18:18:34.336Z,1683742714.336 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T18:18:34.525Z,1683742714.525 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:34.766Z,1683742714.766 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T18:18:34.766Z,1683742714.766 [Default] Running Loop=1
2023-05-10T18:18:34.766Z,1683742714.766 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T18:18:34.766Z,1683742714.766 [Default:B.GoToSurface] Running Loop=1
2023-05-10T18:18:34.766Z,1683742714.766 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T18:18:34.766Z,1683742714.766 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T18:18:34.767Z,1683742714.767 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T18:18:34.767Z,1683742714.767 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T18:18:34.767Z,1683742714.767 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T18:18:34.767Z,1683742714.767 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T18:18:34.768Z,1683742714.768 [Default:A.Wait] Running Loop=1
2023-05-10T18:18:34.768Z,1683742714.768 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T18:18:34.789Z,1683742714.789 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:35.041Z,1683742715.041 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:35.293Z,1683742715.293 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:35.545Z,1683742715.545 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:35.797Z,1683742715.797 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:36.049Z,1683742716.049 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:36.301Z,1683742716.301 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:36.553Z,1683742716.553 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-10T18:18:44.432Z,1683742724.432 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:18:48.096Z,1683742728.096 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T18:18:48.096Z,1683742728.096 [Default:A.Wait] Stopped
2023-05-10T18:18:48.096Z,1683742728.096 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T18:18:48.514Z,1683742728.514 [Default:CheckIn] Running Loop=1
2023-05-10T18:18:48.514Z,1683742728.514 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T18:18:48.514Z,1683742728.514 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T18:18:48.884Z,1683742728.884 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-10T18:18:57.822Z,1683742737.822 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:19:11.152Z,1683742751.152 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T18:20:13.305Z,1683742813.305 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T18:21:51.964Z,1683742911.964 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 5.
2023-05-10T18:21:51.967Z,1683742911.967 [BPC1](INFO): Received data from all battery sticks.
2023-05-10T18:23:48.702Z,1683743028.702 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T18:18:48.5Z
2023-05-10T18:23:48.702Z,1683743028.702 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T18:23:48.703Z,1683743028.703 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T18:23:49.105Z,1683743029.105 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T18:23:55.412Z,1683743035.412 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20230510T181419/Courier0004.lzma
2023-05-10T18:23:56.414Z,1683743036.414 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0004.lzma.bak
2023-05-10T18:23:56.415Z,1683743036.415 [DataOverHttps](INFO): SBD MOMSN=18286754
2023-05-10T18:24:12.389Z,1683743052.389 [DataOverHttps](INFO): Sending 408 bytes from file Logs/20230510T181419/Express0005.lzma
2023-05-10T18:24:13.391Z,1683743053.391 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0005.lzma.bak
2023-05-10T18:24:13.391Z,1683743053.391 [DataOverHttps](INFO): SBD MOMSN=18286756
2023-05-10T18:24:16.170Z,1683743056.170 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T18:24:16.171Z,1683743056.171 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T18:24:16.171Z,1683743056.171 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T18:24:19.393Z,1683743059.393 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T18:29:16.758Z,1683743356.758 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-10T18:29:16.759Z,1683743356.759 [Default:CheckIn:C.Wait] Stopped
2023-05-10T18:29:16.759Z,1683743356.759 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T18:29:16.759Z,1683743356.759 [Default:CheckIn:D] Running Loop=1
2023-05-10T18:29:17.155Z,1683743357.155 [Default:CheckIn:D] Stopped
2023-05-10T18:29:17.155Z,1683743357.155 [Default:CheckIn:E] Running Loop=1
2023-05-10T18:29:17.554Z,1683743357.554 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.706484 min
2023-05-10T18:29:17.554Z,1683743357.554 [Default:CheckIn:E] Stopped
2023-05-10T18:29:17.555Z,1683743357.555 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-10T18:29:17.555Z,1683743357.555 [Default:CheckIn] Stopped
2023-05-10T18:29:17.555Z,1683743357.555 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T18:29:17.555Z,1683743357.555 [Default:CheckIn](INFO): Running loop #2
2023-05-10T18:29:17.555Z,1683743357.555 [Default:CheckIn] Running Loop=2
2023-05-10T18:29:17.555Z,1683743357.555 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T18:29:17.555Z,1683743357.555 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T18:29:19.170Z,1683743359.170 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-10T18:29:19.170Z,1683743359.170 [NAL9602] Data Fault, FailCount= 1
2023-05-10T18:29:19.170Z,1683743359.170 [NAL9602](ERROR): Data Fault
2023-05-10T18:29:19.190Z,1683743359.190 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-10T18:29:19.565Z,1683743359.565 [NAL9602](INFO): Powering down
2023-05-10T18:29:20.396Z,1683743360.396 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-10T18:29:20.396Z,1683743360.396 [NAL9602] No Fault, FailCount= 1
2023-05-10T18:29:49.869Z,1683743389.869 [NAL9602](INFO): Powering up NAL9602
2023-05-10T18:30:00.796Z,1683743400.796 [NAL9602](INFO): NAL9602 initialized
2023-05-10T18:34:17.732Z,1683743657.732 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T18:29:17.6Z
2023-05-10T18:34:17.732Z,1683743657.732 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T18:34:17.732Z,1683743657.732 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T18:34:24.928Z,1683743664.928 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230510T181419/Courier0007.lzma
2023-05-10T18:34:25.930Z,1683743665.930 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0007.lzma.bak
2023-05-10T18:34:25.930Z,1683743665.930 [DataOverHttps](INFO): SBD MOMSN=18286799
2023-05-10T18:34:43.080Z,1683743683.080 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20230510T181419/Express0008.lzma
2023-05-10T18:34:44.082Z,1683743684.082 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0008.lzma.bak
2023-05-10T18:34:44.083Z,1683743684.083 [DataOverHttps](INFO): SBD MOMSN=18286801
2023-05-10T18:34:46.820Z,1683743686.820 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T18:34:46.820Z,1683743686.820 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T18:34:46.820Z,1683743686.820 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T18:35:04.581Z,1683743704.581 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T18:35:35.289Z,1683743735.289 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T18:39:47.395Z,1683743987.395 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-10T18:39:47.395Z,1683743987.395 [Default:CheckIn:C.Wait] Stopped
2023-05-10T18:39:47.395Z,1683743987.395 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T18:39:47.395Z,1683743987.395 [Default:CheckIn:D] Running Loop=1
2023-05-10T18:39:47.800Z,1683743987.800 [Default:CheckIn:D] Stopped
2023-05-10T18:39:47.800Z,1683743987.800 [Default:CheckIn:E] Running Loop=1
2023-05-10T18:39:48.211Z,1683743988.211 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.217230 min
2023-05-10T18:39:48.211Z,1683743988.211 [Default:CheckIn:E] Stopped
2023-05-10T18:39:48.211Z,1683743988.211 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-10T18:39:48.211Z,1683743988.211 [Default:CheckIn] Stopped
2023-05-10T18:39:48.212Z,1683743988.212 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T18:39:48.212Z,1683743988.212 [Default:CheckIn](INFO): Running loop #3
2023-05-10T18:39:48.212Z,1683743988.212 [Default:CheckIn] Running Loop=3
2023-05-10T18:39:48.212Z,1683743988.212 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T18:39:48.212Z,1683743988.212 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T18:44:48.413Z,1683744288.413 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T18:39:48.2Z
2023-05-10T18:44:48.414Z,1683744288.414 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T18:44:48.414Z,1683744288.414 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T18:44:52.034Z,1683744292.034 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T18:44:55.988Z,1683744295.988 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230510T181419/Courier0010.lzma
2023-05-10T18:44:56.990Z,1683744296.990 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0010.lzma.bak
2023-05-10T18:44:56.991Z,1683744296.991 [DataOverHttps](INFO): SBD MOMSN=18286814
2023-05-10T18:45:13.992Z,1683744313.992 [DataOverHttps](INFO): Sending 218 bytes from file Logs/20230510T181419/Express0011.lzma
2023-05-10T18:45:14.994Z,1683744314.994 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0011.lzma.bak
2023-05-10T18:45:14.995Z,1683744314.995 [DataOverHttps](INFO): SBD MOMSN=18286816
2023-05-10T18:45:17.504Z,1683744317.504 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T18:45:17.504Z,1683744317.504 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T18:45:17.504Z,1683744317.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T18:45:22.737Z,1683744322.737 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T18:50:18.079Z,1683744618.079 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-10T18:50:18.080Z,1683744618.080 [Default:CheckIn:C.Wait] Stopped
2023-05-10T18:50:18.080Z,1683744618.080 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T18:50:18.080Z,1683744618.080 [Default:CheckIn:D] Running Loop=1
2023-05-10T18:50:18.487Z,1683744618.487 [Default:CheckIn:D] Stopped
2023-05-10T18:50:18.488Z,1683744618.488 [Default:CheckIn:E] Running Loop=1
2023-05-10T18:50:18.883Z,1683744618.883 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.728695 min
2023-05-10T18:50:18.883Z,1683744618.883 [Default:CheckIn:E] Stopped
2023-05-10T18:50:18.883Z,1683744618.883 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-10T18:50:18.883Z,1683744618.883 [Default:CheckIn] Stopped
2023-05-10T18:50:18.884Z,1683744618.884 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T18:50:18.884Z,1683744618.884 [Default:CheckIn](INFO): Running loop #4
2023-05-10T18:50:18.884Z,1683744618.884 [Default:CheckIn] Running Loop=4
2023-05-10T18:50:18.884Z,1683744618.884 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T18:50:18.884Z,1683744618.884 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T18:50:20.484Z,1683744620.484 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-10T18:50:20.484Z,1683744620.484 [NAL9602] Data Fault, FailCount= 2
2023-05-10T18:50:20.484Z,1683744620.484 [NAL9602](ERROR): Data Fault
2023-05-10T18:50:20.504Z,1683744620.504 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-10T18:50:20.893Z,1683744620.893 [NAL9602](INFO): Powering down
2023-05-10T18:50:21.728Z,1683744621.728 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-10T18:50:21.728Z,1683744621.728 [NAL9602] No Fault, FailCount= 2
2023-05-10T18:50:51.193Z,1683744651.193 [NAL9602](INFO): Powering up NAL9602
2023-05-10T18:51:02.102Z,1683744662.102 [NAL9602](INFO): NAL9602 initialized
2023-05-10T18:55:19.096Z,1683744919.096 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T18:50:18.9Z
2023-05-10T18:55:19.096Z,1683744919.096 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T18:55:19.097Z,1683744919.097 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T18:55:26.636Z,1683744926.636 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230510T181419/Courier0013.lzma
2023-05-10T18:55:27.638Z,1683744927.638 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0013.lzma.bak
2023-05-10T18:55:27.638Z,1683744927.638 [DataOverHttps](INFO): SBD MOMSN=18286827
2023-05-10T18:55:44.836Z,1683744944.836 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20230510T181419/Express0014.lzma
2023-05-10T18:55:45.838Z,1683744945.838 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0014.lzma.bak
2023-05-10T18:55:45.839Z,1683744945.839 [DataOverHttps](INFO): SBD MOMSN=18286829
2023-05-10T18:55:48.598Z,1683744948.598 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T18:55:48.598Z,1683744948.598 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T18:55:48.598Z,1683744948.598 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T18:56:05.944Z,1683744965.944 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T18:56:36.654Z,1683744996.654 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T19:00:49.171Z,1683745249.171 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-10T19:00:49.171Z,1683745249.171 [Default:CheckIn:C.Wait] Stopped
2023-05-10T19:00:49.171Z,1683745249.171 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T19:00:49.171Z,1683745249.171 [Default:CheckIn:D] Running Loop=1
2023-05-10T19:00:49.562Z,1683745249.562 [Default:CheckIn:D] Stopped
2023-05-10T19:00:49.562Z,1683745249.562 [Default:CheckIn:E] Running Loop=1
2023-05-10T19:00:49.972Z,1683745249.972 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.246602 min
2023-05-10T19:00:49.972Z,1683745249.972 [Default:CheckIn:E] Stopped
2023-05-10T19:00:49.972Z,1683745249.972 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-10T19:00:49.972Z,1683745249.972 [Default:CheckIn] Stopped
2023-05-10T19:00:49.972Z,1683745249.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T19:00:49.972Z,1683745249.972 [Default:CheckIn](INFO): Running loop #5
2023-05-10T19:00:49.973Z,1683745249.973 [Default:CheckIn] Running Loop=5
2023-05-10T19:00:49.973Z,1683745249.973 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T19:00:49.973Z,1683745249.973 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T19:01:22.734Z,1683745282.734 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-10T19:01:22.817Z,1683745282.817 [NAL9602](ERROR): received:
+CSQ:0
OK
2023-05-10T19:05:50.175Z,1683745550.175 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T19:00:49.0Z
2023-05-10T19:05:50.176Z,1683745550.176 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T19:05:50.176Z,1683745550.176 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T19:05:54.206Z,1683745554.206 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T19:05:57.068Z,1683745557.068 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230510T181419/Courier0016.lzma
2023-05-10T19:05:58.070Z,1683745558.070 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0016.lzma.bak
2023-05-10T19:05:58.070Z,1683745558.070 [DataOverHttps](INFO): SBD MOMSN=18286840
2023-05-10T19:06:14.089Z,1683745574.089 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20230510T181419/Express0017.lzma
2023-05-10T19:06:15.090Z,1683745575.090 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0017.lzma.bak
2023-05-10T19:06:15.090Z,1683745575.090 [DataOverHttps](INFO): SBD MOMSN=18286842
2023-05-10T19:06:17.704Z,1683745577.704 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T19:06:17.704Z,1683745577.704 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T19:06:17.705Z,1683745577.705 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T19:06:24.942Z,1683745584.942 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T19:11:18.272Z,1683745878.272 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-10T19:11:18.272Z,1683745878.272 [Default:CheckIn:C.Wait] Stopped
2023-05-10T19:11:18.272Z,1683745878.272 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T19:11:18.272Z,1683745878.272 [Default:CheckIn:D] Running Loop=1
2023-05-10T19:11:18.658Z,1683745878.658 [Default:CheckIn:D] Stopped
2023-05-10T19:11:18.658Z,1683745878.658 [Default:CheckIn:E] Running Loop=1
2023-05-10T19:11:19.074Z,1683745879.074 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.731535 min
2023-05-10T19:11:19.074Z,1683745879.074 [Default:CheckIn:E] Stopped
2023-05-10T19:11:19.075Z,1683745879.075 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-10T19:11:19.075Z,1683745879.075 [Default:CheckIn] Stopped
2023-05-10T19:11:19.075Z,1683745879.075 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T19:11:19.075Z,1683745879.075 [Default:CheckIn](INFO): Running loop #6
2023-05-10T19:11:19.075Z,1683745879.075 [Default:CheckIn] Running Loop=6
2023-05-10T19:11:19.075Z,1683745879.075 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T19:11:19.075Z,1683745879.075 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T19:11:20.675Z,1683745880.675 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-10T19:11:20.675Z,1683745880.675 [NAL9602] Data Fault, FailCount= 3
2023-05-10T19:11:20.675Z,1683745880.675 [NAL9602](ERROR): Data Fault
2023-05-10T19:11:20.711Z,1683745880.711 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-10T19:11:21.072Z,1683745881.072 [NAL9602](INFO): Powering down
2023-05-10T19:11:21.906Z,1683745881.906 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-10T19:11:21.906Z,1683745881.906 [NAL9602] No Fault, FailCount= 3
2023-05-10T19:11:51.373Z,1683745911.373 [NAL9602](INFO): Powering up NAL9602
2023-05-10T19:12:02.282Z,1683745922.282 [NAL9602](INFO): NAL9602 initialized
2023-05-10T19:16:19.240Z,1683746179.240 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T19:11:19.1Z
2023-05-10T19:16:19.240Z,1683746179.240 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T19:16:19.241Z,1683746179.241 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T19:16:26.236Z,1683746186.236 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230510T181419/Courier0019.lzma
2023-05-10T19:16:27.347Z,1683746187.347 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0019.lzma.bak
2023-05-10T19:16:27.347Z,1683746187.347 [DataOverHttps](INFO): SBD MOMSN=18286855
2023-05-10T19:16:44.417Z,1683746204.417 [DataOverHttps](INFO): Sending 236 bytes from file Logs/20230510T181419/Express0020.lzma
2023-05-10T19:16:45.418Z,1683746205.418 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0020.lzma.bak
2023-05-10T19:16:45.419Z,1683746205.419 [DataOverHttps](INFO): SBD MOMSN=18286857
2023-05-10T19:16:47.928Z,1683746207.928 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T19:16:47.928Z,1683746207.928 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T19:16:47.928Z,1683746207.928 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T19:17:06.099Z,1683746226.099 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T19:17:36.794Z,1683746256.794 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T19:21:48.499Z,1683746508.499 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-10T19:21:48.499Z,1683746508.499 [Default:CheckIn:C.Wait] Stopped
2023-05-10T19:21:48.499Z,1683746508.499 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T19:21:48.499Z,1683746508.499 [Default:CheckIn:D] Running Loop=1
2023-05-10T19:21:48.899Z,1683746508.899 [Default:CheckIn:D] Stopped
2023-05-10T19:21:48.899Z,1683746508.899 [Default:CheckIn:E] Running Loop=1
2023-05-10T19:21:49.315Z,1683746509.315 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.235555 min
2023-05-10T19:21:49.316Z,1683746509.316 [Default:CheckIn:E] Stopped
2023-05-10T19:21:49.316Z,1683746509.316 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-10T19:21:49.316Z,1683746509.316 [Default:CheckIn] Stopped
2023-05-10T19:21:49.316Z,1683746509.316 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T19:21:49.316Z,1683746509.316 [Default:CheckIn](INFO): Running loop #7
2023-05-10T19:21:49.316Z,1683746509.316 [Default:CheckIn] Running Loop=7
2023-05-10T19:21:49.316Z,1683746509.316 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T19:21:49.317Z,1683746509.317 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T19:24:19.586Z,1683746659.586 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:24:32.912Z,1683746672.912 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:24:46.250Z,1683746686.250 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:24:59.577Z,1683746699.577 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:25:12.909Z,1683746712.909 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:25:26.242Z,1683746726.242 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:25:39.573Z,1683746739.573 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:25:52.905Z,1683746752.905 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:26:06.237Z,1683746766.237 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:26:19.570Z,1683746779.570 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:26:32.930Z,1683746792.930 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:26:46.665Z,1683746806.665 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T19:26:49.517Z,1683746809.517 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T19:21:49.3Z
2023-05-10T19:26:49.517Z,1683746809.517 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T19:26:49.518Z,1683746809.518 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T19:26:53.154Z,1683746813.154 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T19:26:56.360Z,1683746816.360 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20230510T181419/Courier0022.lzma
2023-05-10T19:26:57.362Z,1683746817.362 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Courier0022.lzma.bak
2023-05-10T19:26:57.363Z,1683746817.363 [DataOverHttps](INFO): SBD MOMSN=18286868
2023-05-10T19:27:17.908Z,1683746837.908 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20230510T181419/Express0023.lzma
2023-05-10T19:27:18.903Z,1683746838.903 [DataOverHttps](INFO): Moved sent file to Logs/20230510T181419/Express0023.lzma.bak
2023-05-10T19:27:18.903Z,1683746838.903 [DataOverHttps](INFO): SBD MOMSN=18286870
2023-05-10T19:27:22.791Z,1683746842.791 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T19:27:22.791Z,1683746842.791 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T19:27:22.791Z,1683746842.791 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T19:27:23.949Z,1683746843.949 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T19:27:29.614Z,1683746849.614 [CommandExec](IMPORTANT): got command restart application
2023-05-10T19:27:30.617Z,1683746850.617 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:30.617Z,1683746850.617 [CommandExec](INFO): Uninitializing the command executive.
2023-05-10T19:27:30.617Z,1683746850.617 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-10T19:27:30.617Z,1683746850.617 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:30.740Z,1683746850.740 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2023-05-10T19:27:30.741Z,1683746850.741 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-10T19:27:30.741Z,1683746850.741 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:30.742Z,1683746850.742 [NavChartDb](INFO): Join timeout helper Thread ID is 4927
2023-05-10T19:27:30.949Z,1683746850.949 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:30.949Z,1683746850.949 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:30.957Z,1683746850.957 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-10T19:27:30.957Z,1683746850.957 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:30.957Z,1683746850.957 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4928
2023-05-10T19:27:31.057Z,1683746851.057 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:31.057Z,1683746851.057 [WetLabsBB2FL](INFO): Powering down
2023-05-10T19:27:31.058Z,1683746851.058 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.077Z,1683746851.077 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-10T19:27:31.077Z,1683746851.077 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.077Z,1683746851.077 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4929
2023-05-10T19:27:31.197Z,1683746851.197 [CTD_Seabird](INFO): Powering down
2023-05-10T19:27:31.209Z,1683746851.209 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:31.209Z,1683746851.209 [CTD_Seabird](INFO): Powering down
2023-05-10T19:27:31.225Z,1683746851.225 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.229Z,1683746851.229 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler
2023-05-10T19:27:31.229Z,1683746851.229 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.229Z,1683746851.229 [DATMMP](INFO): Join timeout helper Thread ID is 4930
2023-05-10T19:27:31.305Z,1683746851.305 [DATMMP](INFO): Stop
2023-05-10T19:27:31.305Z,1683746851.305 [DATMMP](INFO): uninitialize
2023-05-10T19:27:31.305Z,1683746851.305 [DATMMP](INFO): Powering down
2023-05-10T19:27:31.377Z,1683746851.377 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:31.377Z,1683746851.377 [DATMMP](INFO): uninitialize
2023-05-10T19:27:31.377Z,1683746851.377 [DATMMP](INFO): Powering down
2023-05-10T19:27:31.378Z,1683746851.378 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.379Z,1683746851.379 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-10T19:27:31.379Z,1683746851.379 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.380Z,1683746851.380 [Radio_Surface](INFO): Join timeout helper Thread ID is 4931
2023-05-10T19:27:31.733Z,1683746851.733 [Radio_Surface](INFO): Powering down
2023-05-10T19:27:31.734Z,1683746851.734 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:31.734Z,1683746851.734 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.749Z,1683746851.749 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-10T19:27:31.750Z,1683746851.750 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:31.750Z,1683746851.750 [Onboard](INFO): Join timeout helper Thread ID is 4932
2023-05-10T19:27:33.653Z,1683746853.653 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:33.653Z,1683746853.653 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:33.667Z,1683746853.667 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-10T19:27:33.667Z,1683746853.667 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:33.667Z,1683746853.667 [DataOverHttps](INFO): Join timeout helper Thread ID is 4933
2023-05-10T19:27:34.169Z,1683746854.169 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:34.172Z,1683746854.172 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.196Z,1683746854.196 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-10T19:27:34.196Z,1683746854.196 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.197Z,1683746854.197 [BackseatComponent](INFO): Join timeout helper Thread ID is 4934
2023-05-10T19:27:34.253Z,1683746854.253 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:34.253Z,1683746854.253 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.261Z,1683746854.261 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-10T19:27:34.261Z,1683746854.261 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.262Z,1683746854.262 [logger](INFO): Join timeout helper Thread ID is 4935
2023-05-10T19:27:34.285Z,1683746854.285 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:34.285Z,1683746854.285 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.301Z,1683746854.301 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-10T19:27:34.301Z,1683746854.301 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.302Z,1683746854.302 [CommandLine](INFO): Join timeout helper Thread ID is 4936
2023-05-10T19:27:34.369Z,1683746854.369 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:34.369Z,1683746854.369 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.381Z,1683746854.381 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-10T19:27:34.381Z,1683746854.381 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.382Z,1683746854.382 [CommandExec](INFO): Join timeout helper Thread ID is 4937
2023-05-10T19:27:34.383Z,1683746854.383 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-10T19:27:34.383Z,1683746854.383 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.383Z,1683746854.383 [controlThread](INFO): Join timeout helper Thread ID is 4938
2023-05-10T19:27:34.441Z,1683746854.441 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T19:27:34.441Z,1683746854.441 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-10T19:27:34.442Z,1683746854.442 [AHRS_M2](INFO): Powering down
2023-05-10T19:27:34.514Z,1683746854.514 [NAL9602](INFO): Powering down
2023-05-10T19:27:34.516Z,1683746854.516 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-10T19:27:34.517Z,1683746854.517 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-10T19:27:34.517Z,1683746854.517 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-10T19:27:34.518Z,1683746854.518 [MissionManager](INFO): Uninitializing Mission Default
2023-05-10T19:27:34.518Z,1683746854.518 [Default] Stopped
2023-05-10T19:27:34.518Z,1683746854.518 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T19:27:34.518Z,1683746854.518 [Default:B.GoToSurface] Stopped
2023-05-10T19:27:34.518Z,1683746854.518 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T19:27:34.518Z,1683746854.518 [Default:CheckIn] Stopped
2023-05-10T19:27:34.518Z,1683746854.518 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T19:27:34.518Z,1683746854.518 [Default:CheckIn:C.Wait] Stopped
2023-05-10T19:27:34.518Z,1683746854.518 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T19:27:34.521Z,1683746854.521 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-10T19:27:34.522Z,1683746854.522 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-10T19:27:34.522Z,1683746854.522 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-10T19:27:34.522Z,1683746854.522 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-10T19:27:34.522Z,1683746854.522 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-10T19:27:34.523Z,1683746854.523 [BuoyancyServo](INFO): Powering down
2023-05-10T19:27:34.537Z,1683746854.537 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-10T19:27:34.537Z,1683746854.537 [ElevatorServo](INFO): Powering down
2023-05-10T19:27:34.538Z,1683746854.538 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-10T19:27:34.538Z,1683746854.538 [MassServo](INFO): Powering down
2023-05-10T19:27:34.539Z,1683746854.539 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-10T19:27:34.539Z,1683746854.539 [RudderServo](INFO): Powering down
2023-05-10T19:27:34.539Z,1683746854.539 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-10T19:27:34.540Z,1683746854.540 [ThrusterHE](INFO): Powering down
2023-05-10T19:27:34.541Z,1683746854.541 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-10T19:27:34.541Z,1683746854.541 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-10T19:27:34.541Z,1683746854.541 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-10T19:27:34.541Z,1683746854.541 [CBIT](DEBUG): Powering off loads.
2023-05-10T19:27:34.552Z,1683746854.552 [CBIT](DEBUG): Disabling WDT.
2023-05-10T19:27:34.564Z,1683746854.564 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-10T19:27:34.565Z,1683746854.565 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.620Z,1683746854.620 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.625Z,1683746854.625 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.627Z,1683746854.627 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.633Z,1683746854.633 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.677Z,1683746854.677 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.722Z,1683746854.722 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.727Z,1683746854.727 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.759Z,1683746854.759 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T19:27:34.823Z,1683746854.823 [logger ThreadHandler](INFO): Thread cancelled.