2024-09-04T15:14:33.145Z,1725462873.145 [Supervisor](DEBUG): Initializing supervisor.
2024-09-04T15:14:33.149Z,1725462873.149 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-09-04T15:14:33.150Z,1725462873.150 [SyncHandler](INFO): Protected caller Thread ID is 6104
2024-09-04T15:14:33.150Z,1725462873.150 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-09-04T15:14:33.151Z,1725462873.151 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-09-04T15:14:33.151Z,1725462873.151 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6105
2024-09-04T15:14:33.155Z,1725462873.155 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-09-04T15:14:33.172Z,1725462873.172 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-09-04T15:14:33.173Z,1725462873.173 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-09-04T15:14:33.174Z,1725462873.174 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 6106
2024-09-04T15:14:33.178Z,1725462873.178 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-09-04T15:14:33.179Z,1725462873.179 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-09-04T15:14:33.179Z,1725462873.179 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6107
2024-09-04T15:14:33.181Z,1725462873.181 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-09-04T15:14:33.182Z,1725462873.182 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-09-04T15:14:33.182Z,1725462873.182 [logger ThreadHandler](INFO): Protected caller Thread ID is 6108
2024-09-04T15:14:33.186Z,1725462873.186 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-09-04T15:14:33.186Z,1725462873.186 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-09-04T15:14:33.192Z,1725462873.192 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-09-04T15:14:33.550Z,1725462873.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-09-04T15:14:33.552Z,1725462873.552 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-09-04T15:14:33.648Z,1725462873.648 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-09-04T15:14:34.223Z,1725462874.223 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-09-04T15:14:34.224Z,1725462874.224 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-09-04T15:14:34.601Z,1725462874.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-09-04T15:14:34.603Z,1725462874.603 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-09-04T15:14:34.713Z,1725462874.713 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-09-04T15:14:34.713Z,1725462874.713 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-09-04T15:14:35.153Z,1725462875.153 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-09-04T15:14:35.155Z,1725462875.155 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-09-04T15:14:35.391Z,1725462875.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-09-04T15:14:35.393Z,1725462875.393 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-09-04T15:14:35.960Z,1725462875.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-09-04T15:14:35.962Z,1725462875.962 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-09-04T15:14:36.115Z,1725462876.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-09-04T15:14:36.117Z,1725462876.117 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-09-04T15:14:36.210Z,1725462876.210 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-09-04T15:14:37.443Z,1725462877.443 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-09-04T15:14:37.444Z,1725462877.444 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-09-04T15:14:37.970Z,1725462877.970 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-09-04T15:14:37.972Z,1725462877.972 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-09-04T15:14:38.188Z,1725462878.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-09-04T15:14:38.189Z,1725462878.189 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-09-04T15:14:38.319Z,1725462878.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-09-04T15:14:38.320Z,1725462878.320 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-09-04T15:14:38.568Z,1725462878.568 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-09-04T15:14:38.569Z,1725462878.569 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-09-04T15:14:38.843Z,1725462878.843 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-09-04T15:14:38.845Z,1725462878.845 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2024-09-04T15:14:38.847Z,1725462878.847 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2024-09-04T15:14:38.953Z,1725462878.953 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2024-09-04T15:14:39.053Z,1725462879.053 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2024-09-04T15:14:39.172Z,1725462879.172 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2024-09-04T15:14:39.271Z,1725462879.271 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2024-09-04T15:14:39.390Z,1725462879.390 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2024-09-04T15:14:39.499Z,1725462879.499 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2024-09-04T15:14:39.632Z,1725462879.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2024-09-04T15:14:39.804Z,1725462879.804 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2024-09-04T15:14:39.972Z,1725462879.972 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2024-09-04T15:14:40.100Z,1725462880.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2024-09-04T15:14:40.390Z,1725462880.390 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-09-04T15:14:40.392Z,1725462880.392 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2024-09-04T15:14:40.392Z,1725462880.392 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2024-09-04T15:14:40.407Z,1725462880.407 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-09-04T15:14:40.482Z,1725462880.482 [VerticalControl](DEBUG): Construct VerticalControl.
2024-09-04T15:14:40.540Z,1725462880.540 [VerticalControl] Loaded
2024-09-04T15:14:40.541Z,1725462880.541 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-09-04T15:14:40.543Z,1725462880.543 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-09-04T15:14:40.589Z,1725462880.589 [HorizontalControl] Loaded
2024-09-04T15:14:40.590Z,1725462880.590 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-09-04T15:14:40.592Z,1725462880.592 [SpeedControl](DEBUG): Construct SpeedControl.
2024-09-04T15:14:40.595Z,1725462880.595 [SpeedControl] Loaded
2024-09-04T15:14:40.595Z,1725462880.595 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-09-04T15:14:40.598Z,1725462880.598 [LoopControl](DEBUG): Construct LoopControl.
2024-09-04T15:14:40.598Z,1725462880.598 [LoopControl] Loaded
2024-09-04T15:14:40.599Z,1725462880.599 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-09-04T15:14:40.599Z,1725462880.599 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-09-04T15:14:40.601Z,1725462880.601 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-09-04T15:14:40.617Z,1725462880.617 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-09-04T15:14:40.617Z,1725462880.617 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-09-04T15:14:40.841Z,1725462880.841 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-09-04T15:14:40.842Z,1725462880.842 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-09-04T15:14:41.011Z,1725462881.011 [BuoyancyServo] Loaded
2024-09-04T15:14:41.011Z,1725462881.011 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-09-04T15:14:41.033Z,1725462881.033 [ElevatorServo] Loaded
2024-09-04T15:14:41.033Z,1725462881.033 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-09-04T15:14:41.054Z,1725462881.054 [MassServo] Loaded
2024-09-04T15:14:41.054Z,1725462881.054 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-09-04T15:14:41.075Z,1725462881.075 [RudderServo] Loaded
2024-09-04T15:14:41.075Z,1725462881.075 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-09-04T15:14:41.092Z,1725462881.092 [ThrusterHE] Loaded
2024-09-04T15:14:41.092Z,1725462881.092 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-09-04T15:14:41.092Z,1725462881.092 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-09-04T15:14:41.093Z,1725462881.093 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-09-04T15:14:41.234Z,1725462881.234 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-09-04T15:14:41.234Z,1725462881.234 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-09-04T15:14:41.248Z,1725462881.248 [NavChart] Loaded
2024-09-04T15:14:41.248Z,1725462881.248 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-09-04T15:14:41.253Z,1725462881.253 [UniversalFixResidualReporter] Loaded
2024-09-04T15:14:41.254Z,1725462881.254 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-09-04T15:14:41.254Z,1725462881.254 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-09-04T15:14:41.255Z,1725462881.255 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-09-04T15:14:41.357Z,1725462881.357 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-09-04T15:14:41.358Z,1725462881.358 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-09-04T15:14:42.228Z,1725462882.228 [AHRS_M2] Loaded
2024-09-04T15:14:42.229Z,1725462882.229 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-09-04T15:14:43.080Z,1725462883.080 [BPC1] Loaded
2024-09-04T15:14:43.080Z,1725462883.080 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-09-04T15:14:43.190Z,1725462883.190 [DATMMP] Loaded
2024-09-04T15:14:43.191Z,1725462883.191 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2024-09-04T15:14:43.192Z,1725462883.192 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 4094C4E0
2024-09-04T15:14:43.192Z,1725462883.192 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 6190
2024-09-04T15:14:43.666Z,1725462883.666 [DataOverHttps] Loaded
2024-09-04T15:14:43.666Z,1725462883.666 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-09-04T15:14:43.686Z,1725462883.686 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4097C4E0
2024-09-04T15:14:43.687Z,1725462883.687 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6191
2024-09-04T15:14:43.733Z,1725462883.733 [Depth_Keller] Loaded
2024-09-04T15:14:43.734Z,1725462883.734 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2024-09-04T15:14:43.771Z,1725462883.771 [DropWeight] Loaded
2024-09-04T15:14:43.771Z,1725462883.771 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2024-09-04T15:14:43.904Z,1725462883.904 [NAL9602] Loaded
2024-09-04T15:14:43.904Z,1725462883.904 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-09-04T15:14:43.943Z,1725462883.943 [Onboard] Loaded
2024-09-04T15:14:43.943Z,1725462883.943 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-09-04T15:14:43.958Z,1725462883.958 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409AC4E0
2024-09-04T15:14:43.959Z,1725462883.959 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 6192
2024-09-04T15:14:43.985Z,1725462883.985 [Power24vConverter] Loaded
2024-09-04T15:14:43.985Z,1725462883.985 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-09-04T15:14:44.014Z,1725462884.014 [Radio_Surface] Loaded
2024-09-04T15:14:44.014Z,1725462884.014 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-09-04T15:14:44.015Z,1725462884.015 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409DC4E0
2024-09-04T15:14:44.015Z,1725462884.015 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6193
2024-09-04T15:14:44.016Z,1725462884.016 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-09-04T15:14:44.017Z,1725462884.017 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-09-04T15:14:44.149Z,1725462884.149 [DepthRateCalculator] Loaded
2024-09-04T15:14:44.149Z,1725462884.149 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-09-04T15:14:44.154Z,1725462884.154 [PitchRateCalculator] Loaded
2024-09-04T15:14:44.154Z,1725462884.154 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-09-04T15:14:44.163Z,1725462884.163 [SpeedCalculator] Loaded
2024-09-04T15:14:44.163Z,1725462884.163 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-09-04T15:14:44.167Z,1725462884.167 [YawRateCalculator] Loaded
2024-09-04T15:14:44.168Z,1725462884.168 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-09-04T15:14:44.186Z,1725462884.186 [ElevatorOffsetCalculator] Loaded
2024-09-04T15:14:44.186Z,1725462884.186 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-09-04T15:14:44.187Z,1725462884.187 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-09-04T15:14:44.188Z,1725462884.188 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-09-04T15:14:44.381Z,1725462884.381 [CANONSampler] Loaded
2024-09-04T15:14:44.382Z,1725462884.382 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2024-09-04T15:14:44.445Z,1725462884.445 [CTD_Seabird] Loaded
2024-09-04T15:14:44.446Z,1725462884.446 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-09-04T15:14:44.447Z,1725462884.447 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A984E0
2024-09-04T15:14:44.447Z,1725462884.447 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 6194
2024-09-04T15:14:44.472Z,1725462884.472 [PAR_Licor] Loaded
2024-09-04T15:14:44.472Z,1725462884.472 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-09-04T15:14:44.515Z,1725462884.515 [WetLabsBB2FL] Loaded
2024-09-04T15:14:44.515Z,1725462884.515 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-09-04T15:14:44.516Z,1725462884.516 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC84E0
2024-09-04T15:14:44.516Z,1725462884.516 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6195
2024-09-04T15:14:44.517Z,1725462884.517 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-09-04T15:14:44.518Z,1725462884.518 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-09-04T15:14:44.563Z,1725462884.563 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-09-04T15:14:44.564Z,1725462884.564 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-09-04T15:14:44.982Z,1725462884.982 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-09-04T15:14:44.984Z,1725462884.984 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-09-04T15:14:45.163Z,1725462885.163 [SBIT](DEBUG): Construct Startup Built In Test.
2024-09-04T15:14:45.172Z,1725462885.172 [SBIT] Loaded
2024-09-04T15:14:45.172Z,1725462885.172 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-09-04T15:14:45.175Z,1725462885.175 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-09-04T15:14:45.188Z,1725462885.188 [IBIT] Loaded
2024-09-04T15:14:45.188Z,1725462885.188 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-09-04T15:14:45.194Z,1725462885.194 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-09-04T15:14:45.298Z,1725462885.298 [CBIT] Loaded
2024-09-04T15:14:45.299Z,1725462885.299 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-09-04T15:14:45.299Z,1725462885.299 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-09-04T15:14:45.300Z,1725462885.300 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-09-04T15:14:45.448Z,1725462885.448 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-09-04T15:14:45.454Z,1725462885.454 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-09-04T15:14:45.457Z,1725462885.457 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-09-04T15:14:45.468Z,1725462885.468 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-09-04T15:14:45.469Z,1725462885.469 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C224E0
2024-09-04T15:14:45.470Z,1725462885.470 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6196
2024-09-04T15:14:45.474Z,1725462885.474 [Supervisor](INFO): Main Thread ID is 6102
2024-09-04T15:14:45.474Z,1725462885.474 [Supervisor](DEBUG): Running supervisor.
2024-09-04T15:14:45.475Z,1725462885.475 [CommandExec ThreadHandler](INFO): Handler Thread ID is 6197
2024-09-04T15:14:45.475Z,1725462885.475 [CommandExec](INFO): Initializing the command executive.
2024-09-04T15:14:45.477Z,1725462885.477 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6198
2024-09-04T15:14:45.479Z,1725462885.479 [controlThread ThreadHandler](INFO): Handler Thread ID is 6199
2024-09-04T15:14:45.480Z,1725462885.480 [controlThread](DEBUG): Initializing ControlThread
2024-09-04T15:14:45.480Z,1725462885.480 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-09-04T15:14:45.482Z,1725462885.482 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-09-04T15:14:45.483Z,1725462885.483 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-09-04T15:14:45.484Z,1725462885.484 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-09-04T15:14:45.486Z,1725462885.486 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-09-04T15:14:45.486Z,1725462885.486 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-09-04T15:14:45.492Z,1725462885.492 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-09-04T15:14:45.492Z,1725462885.492 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-09-04T15:14:45.493Z,1725462885.493 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-09-04T15:14:45.493Z,1725462885.493 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-09-04T15:14:45.493Z,1725462885.493 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-09-04T15:14:45.499Z,1725462885.499 [SBIT](INFO): Initialize SBIT Component.
2024-09-04T15:14:45.499Z,1725462885.499 [SBIT](IMPORTANT): git: 2024-08-26
2024-09-04T15:14:45.499Z,1725462885.499 [SBIT](INFO): git hash: 0bed43752cc9ba2701310745442753812c003a61
2024-09-04T15:14:45.500Z,1725462885.500 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-09-04T15:14:45.501Z,1725462885.501 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2024-09-04T15:14:45.502Z,1725462885.502 [SBIT](INFO): Beginning SBIT in 62.000000 seconds.
2024-09-04T15:14:45.503Z,1725462885.503 [IBIT](INFO): Initialize IBIT Component.
2024-09-04T15:14:45.503Z,1725462885.503 [CBIT](DEBUG): Initialize CBIT Component.
2024-09-04T15:14:45.504Z,1725462885.504 [logger ThreadHandler](INFO): Handler Thread ID is 6200
2024-09-04T15:14:45.514Z,1725462885.514 [CBIT](DEBUG): Initialized mux pins.
2024-09-04T15:14:45.515Z,1725462885.515 [CBIT](DEBUG): Initializing the watchdog timer.
2024-09-04T15:14:45.523Z,1725462885.523 [DATMMP ThreadHandler](INFO): Handler Thread ID is 6201
2024-09-04T15:14:45.523Z,1725462885.523 [DATMMP](INFO): Start
2024-09-04T15:14:45.524Z,1725462885.524 [DATMMP](INFO): Powering up
2024-09-04T15:14:45.524Z,1725462885.524 [DATMMP](DEBUG): Initializing DATMMP.
2024-09-04T15:14:45.528Z,1725462885.528 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6203
2024-09-04T15:14:45.530Z,1725462885.530 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2024-09-04T15:14:45.538Z,1725462885.538 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-09-04T15:14:45.539Z,1725462885.539 [CBIT](DEBUG): Initializing heartbeat.
2024-09-04T15:14:45.540Z,1725462885.540 [Onboard ThreadHandler](INFO): Handler Thread ID is 6204
2024-09-04T15:14:45.560Z,1725462885.560 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6205
2024-09-04T15:14:45.571Z,1725462885.571 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 6206
2024-09-04T15:14:45.572Z,1725462885.572 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-09-04T15:14:45.577Z,1725462885.577 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6208
2024-09-04T15:14:45.583Z,1725462885.583 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6210
2024-09-04T15:14:45.584Z,1725462885.584 [WetLabsBB2FL](INFO): Powering up
2024-09-04T15:14:45.592Z,1725462885.592 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-09-04T15:14:45.592Z,1725462885.592 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2024-09-04T15:14:45.592Z,1725462885.592 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2024-09-04T15:14:45.593Z,1725462885.593 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2024-09-04T15:14:45.593Z,1725462885.593 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2024-09-04T15:14:45.593Z,1725462885.593 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2024-09-04T15:14:45.593Z,1725462885.593 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2024-09-04T15:14:45.593Z,1725462885.593 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2024-09-04T15:14:45.610Z,1725462885.610 [CBIT](DEBUG): Deactivating GF circuits.
2024-09-04T15:14:45.611Z,1725462885.611 [CBIT](DEBUG): Deactivating emergency mode.
2024-09-04T15:14:45.650Z,1725462885.650 [CBIT](DEBUG): Backplane powered.
2024-09-04T15:14:45.651Z,1725462885.651 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2024-09-04T15:14:45.652Z,1725462885.652 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2024-09-04T15:14:45.652Z,1725462885.652 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2024-09-04T15:14:45.659Z,1725462885.659 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2024-09-04T15:14:45.701Z,1725462885.701 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2024-09-04T15:14:45.722Z,1725462885.722 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-09-04T15:14:45.766Z,1725462885.766 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2024-09-04T15:14:45.767Z,1725462885.767 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2024-09-04T15:14:45.767Z,1725462885.767 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2024-09-04T15:14:45.771Z,1725462885.771 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2024-09-04T15:14:45.774Z,1725462885.774 [DATMMP](INFO): Starting
2024-09-04T15:14:45.962Z,1725462885.962 [Radio_Surface](INFO): Powering up
2024-09-04T15:14:46.026Z,1725462886.026 [DATMMP](INFO): Starting
2024-09-04T15:14:46.053Z,1725462886.053 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2024-09-04T15:14:46.075Z,1725462886.075 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-09-04T15:14:46.076Z,1725462886.076 [Default:A.Wait](DEBUG): Construct Wait.
2024-09-04T15:14:46.091Z,1725462886.091 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-09-04T15:14:46.118Z,1725462886.118 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-09-04T15:14:46.129Z,1725462886.129 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-09-04T15:14:46.135Z,1725462886.135 [Default:E.Execute](DEBUG): Construct Execute.
2024-09-04T15:14:46.149Z,1725462886.149 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2024-09-04T15:14:46.153Z,1725462886.153 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,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,Reporter,LogSplitter,
2024-09-04T15:14:46.167Z,1725462886.167 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-09-04T15:14:46.279Z,1725462886.279 [DATMMP](INFO): Starting
2024-09-04T15:14:46.295Z,1725462886.295 [Power24vConverter](INFO): Powering up.
2024-09-04T15:14:46.296Z,1725462886.296 [CANONSampler](INFO): Powering down
2024-09-04T15:14:46.364Z,1725462886.364 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-09-04T15:14:46.371Z,1725462886.371 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-09-04T15:14:46.372Z,1725462886.372 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-09-04T15:14:46.379Z,1725462886.379 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-09-04T15:14:46.380Z,1725462886.380 [MassServo](DEBUG): Initializing EZServoServo.
2024-09-04T15:14:46.387Z,1725462886.387 [MassServo](DEBUG): Initializing MassServo.
2024-09-04T15:14:46.387Z,1725462886.387 [RudderServo](DEBUG): Initializing EZServoServo.
2024-09-04T15:14:46.395Z,1725462886.395 [RudderServo](DEBUG): Initializing RudderServo.
2024-09-04T15:14:46.395Z,1725462886.395 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-09-04T15:14:46.403Z,1725462886.403 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-09-04T15:14:46.530Z,1725462886.530 [DATMMP](INFO): Starting
2024-09-04T15:14:46.782Z,1725462886.782 [DATMMP](INFO): Starting
2024-09-04T15:14:47.034Z,1725462887.034 [DATMMP](INFO): Starting
2024-09-04T15:14:47.286Z,1725462887.286 [DATMMP](INFO): Starting
2024-09-04T15:14:47.539Z,1725462887.539 [DATMMP](INFO): Starting
2024-09-04T15:14:47.790Z,1725462887.790 [DATMMP](INFO): Starting
2024-09-04T15:14:48.042Z,1725462888.042 [DATMMP](INFO): Starting
2024-09-04T15:14:48.191Z,1725462888.191 [WetLabsBB2FL](INFO): Powering down
2024-09-04T15:14:48.294Z,1725462888.294 [DATMMP](INFO): Starting
2024-09-04T15:14:48.546Z,1725462888.546 [DATMMP](INFO): Starting
2024-09-04T15:14:48.798Z,1725462888.798 [DATMMP](INFO): Starting
2024-09-04T15:14:49.051Z,1725462889.051 [DATMMP](INFO): Starting
2024-09-04T15:14:49.302Z,1725462889.302 [DATMMP](INFO): Starting
2024-09-04T15:14:49.554Z,1725462889.554 [DATMMP](INFO): Starting
2024-09-04T15:14:49.808Z,1725462889.808 [DATMMP](INFO): Starting
2024-09-04T15:14:50.059Z,1725462890.059 [DATMMP](INFO): Starting
2024-09-04T15:14:50.311Z,1725462890.311 [DATMMP](INFO): Starting
2024-09-04T15:14:50.562Z,1725462890.562 [DATMMP](INFO): Starting
2024-09-04T15:14:50.814Z,1725462890.814 [DATMMP](INFO): Starting
2024-09-04T15:14:51.066Z,1725462891.066 [DATMMP](INFO): Starting
2024-09-04T15:14:51.318Z,1725462891.318 [DATMMP](INFO): Starting
2024-09-04T15:14:51.571Z,1725462891.571 [DATMMP](INFO): Starting
2024-09-04T15:14:51.824Z,1725462891.824 [DATMMP](INFO): Starting
2024-09-04T15:14:52.056Z,1725462892.056 [ThrusterHE](ERROR): Zero Speed Commanded.
2024-09-04T15:14:52.075Z,1725462892.075 [DATMMP](INFO): Starting
2024-09-04T15:14:52.326Z,1725462892.326 [DATMMP](INFO): Starting
2024-09-04T15:14:52.578Z,1725462892.578 [DATMMP](INFO): Starting
2024-09-04T15:14:52.831Z,1725462892.831 [DATMMP](INFO): Starting
2024-09-04T15:14:53.082Z,1725462893.082 [DATMMP](INFO): Starting
2024-09-04T15:14:53.334Z,1725462893.334 [DATMMP](INFO): Starting
2024-09-04T15:14:53.586Z,1725462893.586 [DATMMP](INFO): Starting
2024-09-04T15:14:53.838Z,1725462893.838 [DATMMP](INFO): Starting
2024-09-04T15:14:54.091Z,1725462894.091 [DATMMP](INFO): Starting
2024-09-04T15:14:54.343Z,1725462894.343 [DATMMP](INFO): Starting
2024-09-04T15:14:54.594Z,1725462894.594 [DATMMP](INFO): Starting
2024-09-04T15:14:54.846Z,1725462894.846 [DATMMP](INFO): Starting
2024-09-04T15:14:55.099Z,1725462895.099 [DATMMP](INFO): Starting
2024-09-04T15:14:55.351Z,1725462895.351 [DATMMP](INFO): Starting
2024-09-04T15:14:55.602Z,1725462895.602 [DATMMP](INFO): Starting
2024-09-04T15:14:55.856Z,1725462895.856 [DATMMP](INFO): Starting
2024-09-04T15:14:56.106Z,1725462896.106 [DATMMP](INFO): Starting
2024-09-04T15:14:56.359Z,1725462896.359 [DATMMP](INFO): Starting
2024-09-04T15:14:56.610Z,1725462896.610 [DATMMP](INFO): Starting
2024-09-04T15:14:56.862Z,1725462896.862 [DATMMP](INFO): Starting
2024-09-04T15:14:57.115Z,1725462897.115 [DATMMP](INFO): Starting
2024-09-04T15:14:57.115Z,1725462897.115 [DATMMP](INFO): DAT read:
2024-09-04T15:14:57.116Z,1725462897.116 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series
2024-09-04T15:14:57.367Z,1725462897.367 [DATMMP](INFO): Starting
2024-09-04T15:14:57.618Z,1725462897.618 [DATMMP](INFO): Starting
2024-09-04T15:14:57.871Z,1725462897.871 [DATMMP](INFO): Starting
2024-09-04T15:14:58.123Z,1725462898.123 [DATMMP](INFO): Starting
2024-09-04T15:14:58.375Z,1725462898.375 [DATMMP](INFO): Starting
2024-09-04T15:14:58.626Z,1725462898.626 [DATMMP](INFO): Starting
2024-09-04T15:14:58.627Z,1725462898.627 [DATMMP](INFO): DAT read: MF Frequency Band
2024-09-04T15:14:58.628Z,1725462898.628 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2024-09-04T15:14:58.629Z,1725462898.629 [DATMMP](INFO): DAT read: Jul 30 2000 18:33:26
2024-09-04T15:14:58.878Z,1725462898.878 [DATMMP](INFO): Starting
2024-09-04T15:14:59.132Z,1725462899.132 [DATMMP](INFO): Starting
2024-09-04T15:14:59.237Z,1725462899.237 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004743
2024-09-04T15:14:59.383Z,1725462899.383 [DATMMP](INFO): Starting
2024-09-04T15:14:59.635Z,1725462899.635 [DATMMP](INFO): Starting
2024-09-04T15:14:59.635Z,1725462899.635 [DATMMP](INFO): DAT read: Features enabled [Bearing]
2024-09-04T15:14:59.636Z,1725462899.636 [DATMMP](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2024-09-04T15:14:59.637Z,1725462899.637 [DATMMP](INFO): commRate: 1200
2024-09-04T15:14:59.887Z,1725462899.887 [DATMMP](INFO): Starting
2024-09-04T15:15:00.139Z,1725462900.139 [DATMMP](INFO): Starting
2024-09-04T15:15:00.390Z,1725462900.390 [DATMMP](INFO): Starting
2024-09-04T15:15:00.642Z,1725462900.642 [DATMMP](INFO): Starting
2024-09-04T15:15:00.894Z,1725462900.894 [DATMMP](INFO): Starting
2024-09-04T15:15:01.147Z,1725462901.147 [DATMMP](INFO): Starting
2024-09-04T15:15:01.399Z,1725462901.399 [DATMMP](INFO): Starting
2024-09-04T15:15:01.650Z,1725462901.650 [DATMMP](INFO): Starting
2024-09-04T15:15:01.702Z,1725462901.702 [DATMMP](INFO): entering command mode
2024-09-04T15:15:01.903Z,1725462901.903 [DATMMP](INFO): Starting
2024-09-04T15:15:01.903Z,1725462901.903 [DATMMP](INFO): DAT read:
2024-09-04T15:15:01.903Z,1725462901.903 [DATMMP](INFO): DAT read: user:1>
2024-09-04T15:15:01.904Z,1725462901.904 [DATMMP](DEBUG): read user prompt 1: user:1>
2024-09-04T15:15:01.904Z,1725462901.904 [DATMMP](INFO): entering MMP mode
2024-09-04T15:15:02.154Z,1725462902.154 [DATMMP](INFO): Starting
2024-09-04T15:15:02.155Z,1725462902.155 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-04T15:15:02.157Z,1725462902.157 [DATMMP](INFO): status rx: x1
2024-09-04T15:15:02.157Z,1725462902.157 [DATMMP](INFO): MMP status: 1: started
2024-09-04T15:15:02.157Z,1725462902.157 [DATMMP](INFO): Received message type: status
2024-09-04T15:15:02.157Z,1725462902.157 [DATMMP](INFO): Handled
2024-09-04T15:15:02.407Z,1725462902.407 [DATMMP](INFO): Starting
2024-09-04T15:15:02.408Z,1725462902.408 [DATMMP](INFO): Sent Tx Power Config 8
2024-09-04T15:15:02.408Z,1725462902.408 [DATMMP](INFO): Setting local address: 8
2024-09-04T15:15:02.410Z,1725462902.410 [DATMMP](INFO): Setting time to: 15:15:2 And date to:9/4/2024
2024-09-04T15:15:02.659Z,1725462902.659 [DATMMP](INFO): Starting
2024-09-04T15:15:02.659Z,1725462902.659 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-04T15:15:02.660Z,1725462902.660 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0
2024-09-04T15:15:02.660Z,1725462902.660 [DATMMP](INFO): Received message type: mdmpower
2024-09-04T15:15:02.660Z,1725462902.660 [DATMMP](INFO): Handled
2024-09-04T15:15:02.911Z,1725462902.911 [DATMMP](INFO): Starting
2024-09-04T15:15:02.911Z,1725462902.911 [DATMMP](INFO): GSXN notify for xid: 10
2024-09-04T15:15:02.912Z,1725462902.912 [DATMMP](INFO): sreg_txpower rx: x8
2024-09-04T15:15:02.912Z,1725462902.912 [DATMMP](INFO): Received message type: sreg_txpower
2024-09-04T15:15:02.912Z,1725462902.912 [DATMMP](INFO): Match for : sreg_txpower
2024-09-04T15:15:02.912Z,1725462902.912 [DATMMP](INFO): ACK
2024-09-04T15:15:03.163Z,1725462903.163 [DATMMP](INFO): Starting
2024-09-04T15:15:03.163Z,1725462903.163 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-04T15:15:03.164Z,1725462903.164 [DATMMP](INFO): mdmlocal rx: x8 x0 x0 x0
2024-09-04T15:15:03.164Z,1725462903.164 [DATMMP](INFO): Received message type: mdmlocal
2024-09-04T15:15:03.164Z,1725462903.164 [DATMMP](INFO): Handled
2024-09-04T15:15:03.415Z,1725462903.415 [DATMMP](INFO): Starting
2024-09-04T15:15:03.415Z,1725462903.415 [DATMMP](INFO): GSXN notify for xid: 11
2024-09-04T15:15:03.416Z,1725462903.416 [DATMMP](INFO): sreg_locaddr rx: x8
2024-09-04T15:15:03.416Z,1725462903.416 [DATMMP](INFO): Received message type: sreg_locaddr
2024-09-04T15:15:03.416Z,1725462903.416 [DATMMP](INFO): Match for : sreg_locaddr
2024-09-04T15:15:03.416Z,1725462903.416 [DATMMP](INFO): ACK
2024-09-04T15:15:03.667Z,1725462903.667 [DATMMP](INFO): Starting
2024-09-04T15:15:03.667Z,1725462903.667 [DATMMP](INFO): GSXN notify for xid: 12
2024-09-04T15:15:03.668Z,1725462903.668 [DATMMP](INFO): timedate rx: x0 xF xF x2 x8 x4 x7C x0
2024-09-04T15:15:03.668Z,1725462903.668 [DATMMP](INFO): Received message type: timedate
2024-09-04T15:15:03.669Z,1725462903.669 [DATMMP](INFO): Match for : timedate
2024-09-04T15:15:03.669Z,1725462903.669 [DATMMP](INFO): ACK
2024-09-04T15:15:03.919Z,1725462903.919 [DATMMP](INFO): Starting
2024-09-04T15:15:03.919Z,1725462903.919 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-04T15:15:03.920Z,1725462903.920 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0
2024-09-04T15:15:03.920Z,1725462903.920 [DATMMP](INFO): Received message type: sys_verb
2024-09-04T15:15:03.920Z,1725462903.920 [DATMMP](INFO): Handled
2024-09-04T15:15:04.171Z,1725462904.171 [DATMMP](INFO): Starting
2024-09-04T15:15:04.171Z,1725462904.171 [DATMMP](INFO): GSXN notify for xid: 13
2024-09-04T15:15:04.172Z,1725462904.172 [DATMMP](INFO): sreg_verbosity rx: x0
2024-09-04T15:15:04.172Z,1725462904.172 [DATMMP](INFO): Received message type: sreg_verbosity
2024-09-04T15:15:04.172Z,1725462904.172 [DATMMP](INFO): Match for : sreg_verbosity
2024-09-04T15:15:04.172Z,1725462904.172 [DATMMP](INFO): ACK
2024-09-04T15:15:04.423Z,1725462904.423 [DATMMP](INFO): Starting
2024-09-04T15:15:04.423Z,1725462904.423 [DATMMP](INFO): GSXN notify for xid: 14
2024-09-04T15:15:04.424Z,1725462904.424 [DATMMP](INFO): version rx: x2 x5
2024-09-04T15:15:04.424Z,1725462904.424 [DATMMP](INFO): DatMMPVersion: 2.5
2024-09-04T15:15:04.424Z,1725462904.424 [DATMMP](INFO): Received message type: version
2024-09-04T15:15:04.424Z,1725462904.424 [DATMMP](INFO): Match for : version
2024-09-04T15:15:04.424Z,1725462904.424 [DATMMP](INFO): ACK
2024-09-04T15:15:04.425Z,1725462904.425 [DATMMP](INFO): in MMP mode: config complete going to runnable
2024-09-04T15:15:14.040Z,1725462914.040 [NAL9602](INFO): Powering up NAL9602
2024-09-04T15:15:17.779Z,1725462917.779 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-04T15:15:17.780Z,1725462917.780 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2024-09-04T15:15:17.780Z,1725462917.780 [DATMMP](INFO): Received message type: timesync
2024-09-04T15:15:17.780Z,1725462917.780 [DATMMP](INFO): Handled
2024-09-04T15:15:24.948Z,1725462924.948 [NAL9602](INFO): NAL9602 initialized
2024-09-04T15:15:27.867Z,1725462927.867 [DATMMP](INFO): GSXN notify for xid: 0
2024-09-04T15:15:27.868Z,1725462927.868 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2024-09-04T15:15:27.868Z,1725462927.868 [DATMMP](INFO): Received message type: timesync
2024-09-04T15:15:27.868Z,1725462927.868 [DATMMP](INFO): Handled
2024-09-04T15:15:47.986Z,1725462947.986 [SBIT](IMPORTANT): Beginning Startup BIT
2024-09-04T15:15:48.007Z,1725462948.007 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-04T15:15:53.239Z,1725462953.239 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:15:58.959Z,1725462958.959 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-09-04T15:15:59.367Z,1725462959.367 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-04T15:16:10.188Z,1725462970.188 [CommandExec](IMPORTANT): got command strobe off
2024-09-04T15:16:10.188Z,1725462970.188 [CommandExec](IMPORTANT): Deactivating strobe
2024-09-04T15:16:10.280Z,1725462970.280 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-09-04T15:16:10.692Z,1725462970.692 [CBIT](IMPORTANT): Beginning ground fault scan
2024-09-04T15:16:13.021Z,1725462973.021 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:16:21.599Z,1725462981.599 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.021446
CHAN A1 (24V): 0.000792
CHAN A2 (12V): -0.001847
CHAN A3 (5V): -0.001445
CHAN B0 (3.3V): 0.000105
CHAN B1 (3.15aV): -0.000202
CHAN B2 (3.15bV): -0.000398
CHAN B3 (GND): 0.000758
OPEN: -0.000521
Full Scale: +/- 1 mA
2024-09-04T15:16:41.746Z,1725463001.746 [SBIT](IMPORTANT): SBIT PASSED
2024-09-04T15:16:41.746Z,1725463001.746 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-09-04T15:16:41.763Z,1725463001.763 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=20 count;
2024-09-04T15:16:41.763Z,1725463001.763 [SBIT](IMPORTANT): CANONSampler.simulateHardware=0 bool;
2024-09-04T15:16:41.763Z,1725463001.763 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2024-09-04T15:16:41.763Z,1725463001.763 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2024-09-04T15:16:41.763Z,1725463001.763 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2024-09-04T15:16:41.763Z,1725463001.763 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter;
2024-09-04T15:16:41.764Z,1725463001.764 [SBIT](IMPORTANT): Express none _.predict_plankton_data_pct_dinos_sqerr;
2024-09-04T15:16:41.764Z,1725463001.764 [SBIT](IMPORTANT): Normal all WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;
2024-09-04T15:16:41.764Z,1725463001.764 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=178.865235 cubic_centimeter;
2024-09-04T15:16:41.764Z,1725463001.764 [SBIT](IMPORTANT): VerticalControl.massDefault=10.548359 millimeter;
2024-09-04T15:16:42.151Z,1725463002.151 [MissionManager](IMPORTANT): Started mission Startup
2024-09-04T15:16:42.152Z,1725463002.152 [Startup] Running Loop=1
2024-09-04T15:16:42.152Z,1725463002.152 [Startup](DEBUG): Aggregate::initialize Startup
2024-09-04T15:16:42.152Z,1725463002.152 [Startup:A.GoToSurface] Running Loop=1
2024-09-04T15:16:42.152Z,1725463002.152 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-04T15:16:42.152Z,1725463002.152 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-04T15:16:42.153Z,1725463002.153 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-04T15:16:42.153Z,1725463002.153 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-04T15:16:42.154Z,1725463002.154 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-04T15:16:42.154Z,1725463002.154 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-04T15:16:42.154Z,1725463002.154 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-04T15:16:42.156Z,1725463002.156 [Startup:StartupSatComms] Running Loop=1
2024-09-04T15:16:42.156Z,1725463002.156 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-09-04T15:16:42.156Z,1725463002.156 [Startup:StartupSatComms:A] Running Loop=1
2024-09-04T15:16:42.554Z,1725463002.554 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-09-04T15:17:42.351Z,1725463062.351 [Startup:StartupSatComms:A](INFO): Timed out from 2024-09-04T15:16:42.2Z
2024-09-04T15:17:42.351Z,1725463062.351 [Startup:StartupSatComms:A] Stopped
2024-09-04T15:17:42.351Z,1725463062.351 [Startup:StartupSatComms:B] Running Loop=1
2024-09-04T15:17:42.752Z,1725463062.752 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-09-04T15:17:45.599Z,1725463065.599 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2024-09-04T15:17:45.599Z,1725463065.599 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:17:45.646Z,1725463065.646 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:17:46.003Z,1725463066.003 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:17:46.003Z,1725463066.003 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2024-09-04T15:17:49.547Z,1725463069.547 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240830T165211/Courier0042.lzma
2024-09-04T15:17:50.548Z,1725463070.548 [DataOverHttps](INFO): Moved sent file to Logs/20240830T165211/Courier0042.lzma.bak
2024-09-04T15:17:50.549Z,1725463070.549 [DataOverHttps](INFO): SBD MOMSN=23124622
2024-09-04T15:17:58.387Z,1725463078.387 [CommandExec](IMPORTANT): got command get CANONSampler.loadAtStartup
2024-09-04T15:17:58.388Z,1725463078.388 [CommandExec](IMPORTANT): CANONSampler.loadAtStartup 1 bool
2024-09-04T15:18:05.954Z,1725463085.954 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20240904T151433/Courier0000.lzma
2024-09-04T15:18:06.956Z,1725463086.956 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0000.lzma.bak
2024-09-04T15:18:06.956Z,1725463086.956 [DataOverHttps](INFO): SBD MOMSN=23124624
2024-09-04T15:18:22.619Z,1725463102.619 [CommandLine](INFO): End of History
2024-09-04T15:18:23.064Z,1725463103.064 [DataOverHttps](INFO): Sending 247 bytes from file Logs/20240830T165211/Express0043.lzma
2024-09-04T15:18:24.064Z,1725463104.064 [DataOverHttps](INFO): Moved sent file to Logs/20240830T165211/Express0043.lzma.bak
2024-09-04T15:18:24.064Z,1725463104.064 [DataOverHttps](INFO): SBD MOMSN=23124627
2024-09-04T15:18:30.716Z,1725463110.716 [CommandExec](IMPORTANT): got command get CANONSampler.loadAtStartup
2024-09-04T15:18:30.716Z,1725463110.716 [CommandExec](IMPORTANT): CANONSampler.loadAtStartup 1 bool
2024-09-04T15:18:40.952Z,1725463120.952 [DataOverHttps](INFO): Sending 954 bytes from file Logs/20240904T151433/Express0001.lzma
2024-09-04T15:18:41.952Z,1725463121.952 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0001.lzma.bak
2024-09-04T15:18:41.952Z,1725463121.952 [DataOverHttps](INFO): SBD MOMSN=23124633
2024-09-04T15:18:42.536Z,1725463122.536 [Startup:StartupSatComms:B](INFO): Timed out from 2024-09-04T15:17:42.4Z
2024-09-04T15:18:42.536Z,1725463122.536 [Startup:StartupSatComms:B] Stopped
2024-09-04T15:18:42.536Z,1725463122.536 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-09-04T15:18:42.536Z,1725463122.536 [Startup:StartupSatComms] Stopped
2024-09-04T15:18:42.537Z,1725463122.537 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-09-04T15:18:42.537Z,1725463122.537 [Startup](INFO): Completed Startup
2024-09-04T15:18:42.538Z,1725463122.538 [MissionManager](INFO): Startup is completed.
2024-09-04T15:18:42.538Z,1725463122.538 [MissionManager](INFO): Uninitializing Mission Startup
2024-09-04T15:18:42.538Z,1725463122.538 [Startup] Stopped
2024-09-04T15:18:42.538Z,1725463122.538 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-09-04T15:18:42.538Z,1725463122.538 [Startup:A.GoToSurface] Stopped
2024-09-04T15:18:42.538Z,1725463122.538 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-09-04T15:18:42.944Z,1725463122.944 [MissionManager](IMPORTANT): Started mission Default
2024-09-04T15:18:42.944Z,1725463122.944 [Default] Running Loop=1
2024-09-04T15:18:42.944Z,1725463122.944 [Default](DEBUG): Aggregate::initialize Default
2024-09-04T15:18:42.944Z,1725463122.944 [Default:B.GoToSurface] Running Loop=1
2024-09-04T15:18:42.944Z,1725463122.944 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-04T15:18:42.944Z,1725463122.944 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-04T15:18:42.945Z,1725463122.945 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-04T15:18:42.945Z,1725463122.945 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-04T15:18:42.945Z,1725463122.945 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-04T15:18:42.945Z,1725463122.945 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-04T15:18:42.946Z,1725463122.946 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-04T15:18:42.946Z,1725463122.946 [Default:A.Wait] Running Loop=1
2024-09-04T15:18:42.946Z,1725463122.946 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-09-04T15:18:56.257Z,1725463136.257 [Default:A.Wait](INFO): Done Waiting.
2024-09-04T15:18:56.257Z,1725463136.257 [Default:A.Wait] Stopped
2024-09-04T15:18:56.257Z,1725463136.257 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T15:18:56.664Z,1725463136.664 [Default:CheckIn] Running Loop=1
2024-09-04T15:18:56.664Z,1725463136.664 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T15:18:56.664Z,1725463136.664 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T15:18:57.069Z,1725463137.069 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-09-04T15:19:01.539Z,1725463141.539 [CommandExec](IMPORTANT): got command failComponent
2024-09-04T15:19:01.539Z,1725463141.539 [CommandExec](IMPORTANT): Failed components:
2024-09-04T15:19:01.539Z,1725463141.539 [CommandExec](IMPORTANT): No failed Components.
2024-09-04T15:20:28.776Z,1725463228.776 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T15:20:46.559Z,1725463246.559 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2024-09-04T15:20:46.559Z,1725463246.559 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:20:46.602Z,1725463246.602 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:20:47.020Z,1725463247.020 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:20:47.020Z,1725463247.020 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2024-09-04T15:21:04.337Z,1725463264.337 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:06.401Z,1725463266.401 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:15.306Z,1725463275.306 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:17.369Z,1725463277.369 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:22.004Z,1725463282.004 [DataOverHttps](IMPORTANT): SBD MTMSN=20240904T152121
2024-09-04T15:21:26.283Z,1725463286.283 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:28.640Z,1725463288.640 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:29.327Z,1725463289.327 [DataOverHttps](INFO): Received command: load Insert/SampleAtDepth.tl;set SampleAtDepth.TargetDepth 0 m;run
2024-09-04T15:21:29.457Z,1725463289.457 [CommandExec](IMPORTANT): got command load ./Missions/Insert/SampleAtDepth.tl
2024-09-04T15:21:29.458Z,1725463289.458 [MissionManager](INFO): Loading Mission from file: ./Missions/Insert/SampleAtDepth.tl
2024-09-04T15:21:29.458Z,1725463289.458 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Insert/SampleAtDepth.tl
2024-09-04T15:21:29.480Z,1725463289.480 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Insert/SampleAtDepth.tl
2024-09-04T15:21:29.836Z,1725463289.836 [MissionManager](DEBUG): TethyslAPI: ./Missions/Insert/SampleAtDepth.tl translated into:
5
10
3
0
NaN
3
SampleAtDepth received an invalid target depth. Skipping sample.
Moving to
Timed out trying to reach the targeted depth. Stopping mission.
stop
At
, settling for
Timed out triggering CANONSampler. Stopping mission.
stop
CANONSampler sampling at
in
water with
chlorophyll fluorescence.
Timed out sampling with CANONSampler. Stopping mission.
stop
ESP sampling at
in
water with
chlorophyll fluorescence.
2024-09-04T15:21:29.843Z,1725463289.843 [MissionManager](INFO): DefineArg SampleAtDepth.TargetDepth = 5.000000 m
2024-09-04T15:21:29.846Z,1725463289.846 [MissionManager](INFO): DefineArg SampleAtDepth.SettleTime = 10.000000 s
2024-09-04T15:21:29.850Z,1725463289.850 [MissionManager](INFO): DefineArg SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2024-09-04T15:21:29.853Z,1725463289.853 [MissionManager](INFO): DefineArg SampleAtDepth.RotateOnly = 0.000000 bool
2024-09-04T15:21:29.873Z,1725463289.873 [MissionManager](INFO): DefineArg SampleAtDepth.UseCANONSampler = 1 bool
2024-09-04T15:21:29.881Z,1725463289.881 [MissionManager](INFO): DefineArg SampleAtDepth.UseESP = 0 bool
2024-09-04T15:21:29.884Z,1725463289.884 [MissionManager](INFO): DefineArg SampleAtDepth.ESPCartridgeType = nan count
2024-09-04T15:21:29.900Z,1725463289.900 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTriggerTimeout = 3.000000 min
2024-09-04T15:21:29.904Z,1725463289.904 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2024-09-04T15:21:29.927Z,1725463289.927 [SampleAtDepth:sample:ApproachDepth:B.Pitch](DEBUG): Construct.
2024-09-04T15:21:29.934Z,1725463289.934 [SampleAtDepth:sample:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-09-04T15:21:29.949Z,1725463289.949 [SampleAtDepth:sample:SampleWrapper:A.Pitch](DEBUG): Construct.
2024-09-04T15:21:29.971Z,1725463289.971 [SampleAtDepth:sample:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2024-09-04T15:21:29.989Z,1725463289.989 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-09-04T15:21:29.996Z,1725463289.996 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2024-09-04T15:21:29.996Z,1725463289.996 [MissionManager](ERROR): Slate does not contain celsius
2024-09-04T15:21:30.005Z,1725463290.005 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-09-04T15:21:30.013Z,1725463290.013 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](DEBUG): Construct.
2024-09-04T15:21:30.056Z,1725463290.056 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
aggregate SampleAtDepth {
"""
Take a water sample at a specified depth.
"""
arguments {
TargetDepth = 5 meter
"""
Depth to sample at. Initialized to 5 m.
"""
SettleTime = 10 second
"""
Time to wait after reaching target depth before triggering sample.
Initialized to 10 minutes.
"""
MaxWaitNotReachingDepth = 3 hour
"""
Maximum wait time the vehicle cannot reach the targeted depth.
Initialized to 3 hours.
"""
RotateOnly = 0 bool
UseCANONSampler = Science:CANONSampler.loadAtStartup
"""
Whether to use CANON Sampler to sample.
"""
UseESP = Science:ESPComponent.loadAtStartup
"""
Whether to use ESP to sample.
"""
ESPCartridgeType = NaN count
"""
Specifies ESP cartridge type code.
"""
CANONSamplerTriggerTimeout = 3 minute
"""
How long to wait for a CANON Sampler sample to start.
"""
CANONSamplerTimeout = Science:CANONSampler.sampleTimeout
"""
How long to wait for a CANON Sampler sample to complete.
"""
}
run when ( called )
aggregate ReportInvalidDepth {
run in sequence
break if ( not ( isNaN ( TargetDepth ) ) )
syslog fault "SampleAtDepth received an invalid target depth. Skipping sample."
}
aggregate sample {
run in sequence
break if ( isNaN ( TargetDepth ) )
aggregate ApproachDepth {
run in sequence
syslog "Moving to " + TargetDepth~meter
behavior Guidance:Pitch {
run in sequence
timeout duration=MaxWaitNotReachingDepth {
syslog important "Timed out trying to reach the targeted depth. Stopping mission."
behavior Guidance:Execute {
run in sequence
set command = "stop"
}
}
set depth = TargetDepth
}
}
aggregate SampleWrapper {
run in sequence
behavior Guidance:Pitch {
run in parallel
set depth = TargetDepth
}
syslog important "At " + Universal:depth~meter + ", settling for " + SettleTime~minute
behavior Guidance:Wait {
run in sequence
set duration = SettleTime
}
aggregate SampleCANONSampler {
run in sequence
break if ( not ( UseCANONSampler ) )
assign in parallel Science:CANONSampler.sampleTimeout = CANONSamplerTimeout
assign in parallel Science:CANONSampler.rotateOnly = RotateOnly
readDatum id="TriggerCANONSampler" {
timeout duration=CANONSamplerTriggerTimeout {
syslog important "Timed out triggering CANONSampler. Stopping mission."
behavior Guidance:Execute {
run in sequence
set command = "stop"
}
}
Science:CANONSampler.sampling
}
syslog important "CANONSampler sampling at " + Universal:depth~meter + " in "
+ Science:CTD_NeilBrown.bin_mean_sea_water_temperature~celsius + " water with "
+ Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water~microgram_per_liter
+ " chlorophyll fluorescence."
readDatum {
timeout duration=CANONSamplerTimeout {
syslog important "Timed out sampling with CANONSampler. Stopping mission."
behavior Guidance:Execute {
run in sequence
set command = "stop"
}
}
Science:CANONSampler.sample_number
}
}
aggregate SampleESP {
run in sequence
break if ( not ( UseESP ) )
aggregate SelectESPCartridge {
run in sequence
break if ( isNaN ( ESPCartridgeType ) )
behavior Science:ESPCartridgeSelect {
run in sequence
timeout duration=P1M
set cartridgeType = ESPCartridgeType
}
}
readDatum id="TriggerESP" {
Science:ESPComponent.sampling
}
syslog important "ESP sampling at " + Universal:depth~meter + " in "
+ Science:CTD_Seabird.bin_mean_sea_water_temperature~celsius + " water with "
+ Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water~microgram_per_liter
+ "chlorophyll fluorescence."
readDatum id="WaitForESP" {
Science:ESPComponent.sample_number
}
}
}
}
}
2024-09-04T15:21:30.057Z,1725463290.057 [CommandExec](IMPORTANT): Loaded ./Missions/Insert/SampleAtDepth.tl id=SampleAtDepth
2024-09-04T15:21:31.966Z,1725463291.966 [CommandExec](IMPORTANT): got command set SampleAtDepth.TargetDepth 0 meter
2024-09-04T15:21:31.967Z,1725463291.967 [CommandExec](IMPORTANT): got command run
2024-09-04T15:21:31.969Z,1725463291.969 [CommandExec](IMPORTANT): Running
2024-09-04T15:21:32.223Z,1725463292.223 [Default] Stopped
2024-09-04T15:21:32.223Z,1725463292.223 [Default](DEBUG): Aggregate::uninitialize Default
2024-09-04T15:21:32.223Z,1725463292.223 [Default:B.GoToSurface] Stopped
2024-09-04T15:21:32.223Z,1725463292.223 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-09-04T15:21:32.223Z,1725463292.223 [Default:CheckIn] Stopped
2024-09-04T15:21:32.223Z,1725463292.223 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T15:21:32.223Z,1725463292.223 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T15:21:32.223Z,1725463292.223 [MissionManager](IMPORTANT): Started mission SampleAtDepth
2024-09-04T15:21:32.223Z,1725463292.223 [SampleAtDepth] Running Loop=1
2024-09-04T15:21:32.223Z,1725463292.223 [SampleAtDepth](DEBUG): Aggregate::initialize SampleAtDepth
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:ReportInvalidDepth] Running Loop=1
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:ReportInvalidDepth](DEBUG): Aggregate::initialize SampleAtDepth:ReportInvalidDepth
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:ReportInvalidDepth:A] Running Loop=1
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:ReportInvalidDepth] Stopped
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:ReportInvalidDepth](DEBUG): Aggregate::uninitialize SampleAtDepth:ReportInvalidDepth
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:ReportInvalidDepth:A] Stopped
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:sample] Running Loop=1
2024-09-04T15:21:32.224Z,1725463292.224 [SampleAtDepth:sample](DEBUG): Aggregate::initialize SampleAtDepth:sample
2024-09-04T15:21:32.225Z,1725463292.225 [SampleAtDepth:sample:ApproachDepth] Running Loop=1
2024-09-04T15:21:32.225Z,1725463292.225 [SampleAtDepth:sample:ApproachDepth](DEBUG): Aggregate::initialize SampleAtDepth:sample:ApproachDepth
2024-09-04T15:21:32.225Z,1725463292.225 [SampleAtDepth:sample:ApproachDepth:A] Running Loop=1
2024-09-04T15:21:32.640Z,1725463292.640 [SampleAtDepth:sample:ApproachDepth:A](INFO): Moving to 0.000000 m
2024-09-04T15:21:32.640Z,1725463292.640 [SampleAtDepth:sample:ApproachDepth:A] Stopped
2024-09-04T15:21:32.640Z,1725463292.640 [SampleAtDepth:sample:ApproachDepth:B.Pitch] Running Loop=1
2024-09-04T15:21:32.640Z,1725463292.640 [SampleAtDepth:sample:ApproachDepth:B.Pitch](DEBUG): Initialize.
2024-09-04T15:21:37.121Z,1725463297.121 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:39.544Z,1725463299.544 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:48.033Z,1725463308.033 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:50.459Z,1725463310.459 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:21:58.591Z,1725463318.591 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:01.361Z,1725463321.361 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:07.452Z,1725463327.452 [CommandExec](IMPORTANT): got command show stack
2024-09-04T15:22:07.452Z,1725463327.452 [CommandExec](IMPORTANT): Behavior Stack:
2024-09-04T15:22:07.452Z,1725463327.452 [SampleAtDepth:sample:ApproachDepth](IMPORTANT): Priority 0: SampleAtDepth:sample:ApproachDepth:B.Pitch
2024-09-04T15:22:09.450Z,1725463329.450 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:12.278Z,1725463332.278 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:20.753Z,1725463340.753 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:23.177Z,1725463343.177 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:31.659Z,1725463351.659 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:34.090Z,1725463354.090 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:42.570Z,1725463362.570 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:44.507Z,1725463364.507 [CommandExec](IMPORTANT): got command show stack
2024-09-04T15:22:44.508Z,1725463364.508 [CommandExec](IMPORTANT): Behavior Stack:
2024-09-04T15:22:44.508Z,1725463364.508 [SampleAtDepth:sample:ApproachDepth](IMPORTANT): Priority 0: SampleAtDepth:sample:ApproachDepth:B.Pitch
2024-09-04T15:22:44.993Z,1725463364.993 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:53.481Z,1725463373.481 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:22:56.380Z,1725463376.380 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:23:04.390Z,1725463384.390 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:23:07.621Z,1725463387.621 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:23:15.700Z,1725463395.700 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:23:18.934Z,1725463398.934 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:23:27.424Z,1725463407.424 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:23:29.837Z,1725463409.837 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:23:41.239Z,1725463421.239 [CommandExec](IMPORTANT): got command show stack
2024-09-04T15:23:41.240Z,1725463421.240 [CommandExec](IMPORTANT): Behavior Stack:
2024-09-04T15:23:41.240Z,1725463421.240 [SampleAtDepth:sample:ApproachDepth](IMPORTANT): Priority 0: SampleAtDepth:sample:ApproachDepth:B.Pitch
2024-09-04T15:23:47.567Z,1725463427.567 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2024-09-04T15:23:47.567Z,1725463427.567 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:23:47.578Z,1725463427.578 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:23:47.991Z,1725463427.991 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:23:47.991Z,1725463427.991 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2024-09-04T15:23:49.991Z,1725463429.991 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:24:08.150Z,1725463448.150 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:24:27.943Z,1725463467.943 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:24:47.335Z,1725463487.335 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:25:05.178Z,1725463505.178 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:25:24.509Z,1725463524.509 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:25:26.132Z,1725463526.132 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-04T15:25:26.132Z,1725463526.132 [NAL9602] Data Fault, FailCount= 1
2024-09-04T15:25:26.132Z,1725463526.132 [NAL9602](ERROR): Data Fault
2024-09-04T15:25:26.148Z,1725463526.148 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-04T15:25:26.528Z,1725463526.528 [NAL9602](INFO): Powering down
2024-09-04T15:25:27.356Z,1725463527.356 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-04T15:25:27.356Z,1725463527.356 [NAL9602] No Fault, FailCount= 1
2024-09-04T15:25:43.895Z,1725463543.895 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:25:45.566Z,1725463545.566 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:25:56.841Z,1725463556.841 [NAL9602](INFO): Powering up NAL9602
2024-09-04T15:26:07.740Z,1725463567.740 [NAL9602](INFO): NAL9602 initialized
2024-09-04T15:26:39.295Z,1725463599.295 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:26:48.563Z,1725463608.563 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2024-09-04T15:26:48.563Z,1725463608.563 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:26:48.578Z,1725463608.578 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:26:48.965Z,1725463608.965 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:26:48.965Z,1725463608.965 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2024-09-04T15:27:02.757Z,1725463622.757 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:27:08.507Z,1725463628.507 [CommandExec](IMPORTANT): got command show stack
2024-09-04T15:27:08.508Z,1725463628.508 [CommandExec](IMPORTANT): Behavior Stack:
2024-09-04T15:27:08.508Z,1725463628.508 [SampleAtDepth:sample:ApproachDepth](IMPORTANT): Priority 0: SampleAtDepth:sample:ApproachDepth:B.Pitch
2024-09-04T15:29:31.078Z,1725463771.078 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:29:43.492Z,1725463783.492 [CommandExec](IMPORTANT): got command show stack
2024-09-04T15:29:43.492Z,1725463783.492 [CommandExec](IMPORTANT): Behavior Stack:
2024-09-04T15:29:43.492Z,1725463783.492 [SampleAtDepth:sample:ApproachDepth](IMPORTANT): Priority 0: SampleAtDepth:sample:ApproachDepth:B.Pitch
2024-09-04T15:29:49.575Z,1725463789.575 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2024-09-04T15:29:49.575Z,1725463789.575 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:29:49.586Z,1725463789.586 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:29:49.998Z,1725463789.998 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:29:49.998Z,1725463789.998 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2024-09-04T15:30:05.487Z,1725463805.487 [CommandExec](IMPORTANT): got command failComponent
2024-09-04T15:30:05.487Z,1725463805.487 [CommandExec](IMPORTANT): Failed components:
2024-09-04T15:30:05.487Z,1725463805.487 [CommandExec](IMPORTANT): No failed Components.
2024-09-04T15:30:14.464Z,1725463814.464 [CommandExec](IMPORTANT): got command show stack
2024-09-04T15:30:14.464Z,1725463814.464 [CommandExec](IMPORTANT): Behavior Stack:
2024-09-04T15:30:14.465Z,1725463814.465 [SampleAtDepth:sample:ApproachDepth](IMPORTANT): Priority 0: SampleAtDepth:sample:ApproachDepth:B.Pitch
2024-09-04T15:30:37.340Z,1725463837.340 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:30:37.394Z,1725463837.394 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:30:48.245Z,1725463848.245 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:30:48.320Z,1725463848.320 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:30:58.745Z,1725463858.745 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:30:59.157Z,1725463859.157 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:09.661Z,1725463869.661 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:10.059Z,1725463870.059 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:20.165Z,1725463880.165 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:20.976Z,1725463880.976 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:31.074Z,1725463891.074 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:31.889Z,1725463891.889 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:42.381Z,1725463902.381 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:42.789Z,1725463902.789 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:53.693Z,1725463913.693 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:31:53.768Z,1725463913.768 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:04.669Z,1725463924.669 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:04.813Z,1725463924.813 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:15.112Z,1725463935.112 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:15.514Z,1725463935.514 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:26.012Z,1725463946.012 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:26.441Z,1725463946.441 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:37.324Z,1725463957.324 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:37.405Z,1725463957.405 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:48.235Z,1725463968.235 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:48.306Z,1725463968.306 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:32:50.603Z,1725463970.603 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2024-09-04T15:32:50.603Z,1725463970.603 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:32:50.614Z,1725463970.614 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:32:51.021Z,1725463971.021 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:32:51.021Z,1725463971.021 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2024-09-04T15:32:59.533Z,1725463979.533 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-09-04T15:33:23.312Z,1725464003.312 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:33:43.119Z,1725464023.119 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:34:02.903Z,1725464042.903 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:34:22.295Z,1725464062.295 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:34:31.205Z,1725464071.205 [CommandExec](IMPORTANT): got command show stack
2024-09-04T15:34:31.205Z,1725464071.205 [CommandExec](IMPORTANT): Behavior Stack:
2024-09-04T15:34:31.205Z,1725464071.205 [SampleAtDepth:sample:ApproachDepth](IMPORTANT): Priority 0: SampleAtDepth:sample:ApproachDepth:B.Pitch
2024-09-04T15:34:42.117Z,1725464082.117 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:34:50.767Z,1725464090.767 [CommandExec](IMPORTANT): got command stop
2024-09-04T15:34:50.767Z,1725464090.767 [CommandExec](IMPORTANT): Scheduling is paused
2024-09-04T15:34:50.767Z,1725464090.767 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2024-09-04T15:34:51.083Z,1725464091.083 [MissionManager](INFO): MissionManager is completed.
2024-09-04T15:34:51.084Z,1725464091.084 [MissionManager](INFO): Uninitializing Mission SampleAtDepth
2024-09-04T15:34:51.084Z,1725464091.084 [SampleAtDepth] Stopped
2024-09-04T15:34:51.084Z,1725464091.084 [SampleAtDepth](DEBUG): Aggregate::uninitialize SampleAtDepth
2024-09-04T15:34:51.084Z,1725464091.084 [SampleAtDepth:sample] Stopped
2024-09-04T15:34:51.084Z,1725464091.084 [SampleAtDepth:sample](DEBUG): Aggregate::uninitialize SampleAtDepth:sample
2024-09-04T15:34:51.084Z,1725464091.084 [SampleAtDepth:sample:ApproachDepth] Stopped
2024-09-04T15:34:51.084Z,1725464091.084 [SampleAtDepth:sample:ApproachDepth](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:ApproachDepth
2024-09-04T15:34:51.084Z,1725464091.084 [SampleAtDepth:sample:ApproachDepth:B.Pitch] Stopped
2024-09-04T15:34:51.433Z,1725464091.433 [MissionManager](IMPORTANT): Started mission Default
2024-09-04T15:34:51.433Z,1725464091.433 [Default] Running Loop=1
2024-09-04T15:34:51.433Z,1725464091.433 [Default](DEBUG): Aggregate::initialize Default
2024-09-04T15:34:51.433Z,1725464091.433 [Default:B.GoToSurface] Running Loop=1
2024-09-04T15:34:51.433Z,1725464091.433 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-04T15:34:51.434Z,1725464091.434 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-04T15:34:51.434Z,1725464091.434 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-04T15:34:51.439Z,1725464091.439 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-04T15:34:51.439Z,1725464091.439 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-04T15:34:51.439Z,1725464091.439 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-04T15:34:51.440Z,1725464091.440 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-04T15:34:51.440Z,1725464091.440 [Default:A.Wait] Running Loop=1
2024-09-04T15:34:51.440Z,1725464091.440 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-09-04T15:35:01.112Z,1725464101.112 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T15:35:04.863Z,1725464104.863 [Default:A.Wait](INFO): Done Waiting.
2024-09-04T15:35:04.864Z,1725464104.864 [Default:A.Wait] Stopped
2024-09-04T15:35:04.864Z,1725464104.864 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T15:35:05.191Z,1725464105.191 [Default:CheckIn] Running Loop=1
2024-09-04T15:35:05.191Z,1725464105.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T15:35:05.191Z,1725464105.191 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T15:35:51.628Z,1725464151.628 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2024-09-04T15:35:51.628Z,1725464151.628 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:35:51.645Z,1725464151.645 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:35:52.058Z,1725464152.058 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:35:52.058Z,1725464152.058 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2024-09-04T15:36:01.310Z,1725464161.310 [BPC1](ERROR): BPC1A: No match for serial number FFFF in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2024-09-04T15:36:08.593Z,1725464168.593 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-04T15:36:08.593Z,1725464168.593 [NAL9602] Data Fault, FailCount= 2
2024-09-04T15:36:08.593Z,1725464168.593 [NAL9602](ERROR): Data Fault
2024-09-04T15:36:08.611Z,1725464168.611 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-04T15:36:08.984Z,1725464168.984 [NAL9602](INFO): Powering down
2024-09-04T15:36:09.813Z,1725464169.813 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-04T15:36:09.813Z,1725464169.813 [NAL9602] No Fault, FailCount= 2
2024-09-04T15:36:39.300Z,1725464199.300 [NAL9602](INFO): Powering up NAL9602
2024-09-04T15:36:50.196Z,1725464210.196 [NAL9602](INFO): NAL9602 initialized
2024-09-04T15:37:03.168Z,1725464223.168 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-09-04T15:38:52.616Z,1725464332.616 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2024-09-04T15:38:52.616Z,1725464332.616 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:38:52.626Z,1725464332.626 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:38:53.033Z,1725464333.033 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:38:53.033Z,1725464333.033 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2024-09-04T15:39:51.994Z,1725464391.994 [BPC1](INFO): Calculating totals. Valid battery stick count: 40. Valid reserve battery stick count: 3.
2024-09-04T15:39:51.997Z,1725464391.997 [BPC1](INFO): Received data from all battery sticks.
2024-09-04T15:40:05.353Z,1725464405.353 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-04T15:35:05.2Z
2024-09-04T15:40:05.353Z,1725464405.353 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T15:40:05.353Z,1725464405.353 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T15:40:05.749Z,1725464405.749 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-09-04T15:40:14.258Z,1725464414.258 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20240904T151433/Courier0004.lzma
2024-09-04T15:40:15.260Z,1725464415.260 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0004.lzma.bak
2024-09-04T15:40:15.261Z,1725464415.261 [DataOverHttps](INFO): SBD MOMSN=23124737
2024-09-04T15:40:30.996Z,1725464430.996 [DataOverHttps](INFO): Sending 669 bytes from file Logs/20240904T151433/Express0005.lzma
2024-09-04T15:40:31.996Z,1725464431.996 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0005.lzma.bak
2024-09-04T15:40:31.996Z,1725464431.996 [DataOverHttps](INFO): SBD MOMSN=23124739
2024-09-04T15:40:47.530Z,1725464447.530 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240904T151433/Express0008.lzma
2024-09-04T15:40:48.532Z,1725464448.532 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0008.lzma.bak
2024-09-04T15:40:48.532Z,1725464448.532 [DataOverHttps](INFO): SBD MOMSN=23124786
2024-09-04T15:40:49.828Z,1725464449.828 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T15:40:49.829Z,1725464449.829 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T15:40:49.829Z,1725464449.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T15:41:53.687Z,1725464513.687 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2024-09-04T15:41:53.687Z,1725464513.687 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:41:53.702Z,1725464513.702 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:41:54.104Z,1725464514.104 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:41:54.104Z,1725464514.104 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2024-09-04T15:44:54.659Z,1725464694.659 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2024-09-04T15:44:54.659Z,1725464694.659 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:44:54.709Z,1725464694.709 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:44:55.126Z,1725464695.126 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:44:55.126Z,1725464695.126 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2024-09-04T15:45:50.412Z,1725464750.412 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T15:45:50.412Z,1725464750.412 [Default:CheckIn:C.Wait] Stopped
2024-09-04T15:45:50.412Z,1725464750.412 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T15:45:50.412Z,1725464750.412 [Default:CheckIn:D] Running Loop=1
2024-09-04T15:45:50.817Z,1725464750.817 [Default:CheckIn:D] Stopped
2024-09-04T15:45:50.817Z,1725464750.817 [Default:CheckIn:E] Running Loop=1
2024-09-04T15:45:51.233Z,1725464751.233 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.989724 min
2024-09-04T15:45:51.234Z,1725464751.234 [Default:CheckIn:E] Stopped
2024-09-04T15:45:51.234Z,1725464751.234 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T15:45:51.234Z,1725464751.234 [Default:CheckIn] Stopped
2024-09-04T15:45:51.234Z,1725464751.234 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T15:45:51.234Z,1725464751.234 [Default:CheckIn](INFO): Running loop #2
2024-09-04T15:45:51.234Z,1725464751.234 [Default:CheckIn] Running Loop=2
2024-09-04T15:45:51.234Z,1725464751.234 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T15:45:51.235Z,1725464751.235 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T15:46:52.212Z,1725464812.212 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-04T15:46:52.212Z,1725464812.212 [NAL9602] Data Fault, FailCount= 3
2024-09-04T15:46:52.212Z,1725464812.212 [NAL9602](ERROR): Data Fault
2024-09-04T15:46:52.229Z,1725464812.229 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-04T15:46:52.617Z,1725464812.617 [NAL9602](INFO): Powering down
2024-09-04T15:46:53.461Z,1725464813.461 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-04T15:46:53.461Z,1725464813.461 [NAL9602] No Fault, FailCount= 3
2024-09-04T15:47:22.920Z,1725464842.920 [NAL9602](INFO): Powering up NAL9602
2024-09-04T15:47:33.828Z,1725464853.828 [NAL9602](INFO): NAL9602 initialized
2024-09-04T15:47:55.676Z,1725464875.676 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2024-09-04T15:47:55.676Z,1725464875.676 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:47:55.686Z,1725464875.686 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:47:56.088Z,1725464876.088 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:47:56.088Z,1725464876.088 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2024-09-04T15:48:54.299Z,1725464934.299 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:49:25.423Z,1725464965.423 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:49:56.555Z,1725464996.555 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:50:27.687Z,1725465027.687 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:50:51.405Z,1725465051.405 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-04T15:45:51.2Z
2024-09-04T15:50:51.405Z,1725465051.405 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T15:50:51.405Z,1725465051.405 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T15:50:56.653Z,1725465056.653 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2024-09-04T15:50:56.653Z,1725465056.653 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:50:56.683Z,1725465056.683 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:50:57.057Z,1725465057.057 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:50:57.057Z,1725465057.057 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2024-09-04T15:50:58.815Z,1725465058.815 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:51:01.827Z,1725465061.827 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.739365
2024-09-04T15:51:32.951Z,1725465092.951 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:52:04.083Z,1725465124.083 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:52:35.223Z,1725465155.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:53:06.347Z,1725465186.347 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:53:37.483Z,1725465217.483 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:53:57.642Z,1725465237.642 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2024-09-04T15:53:57.642Z,1725465237.642 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:53:57.653Z,1725465237.653 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:53:58.065Z,1725465238.065 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:53:58.065Z,1725465238.065 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2024-09-04T15:54:08.635Z,1725465248.635 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:54:39.783Z,1725465279.783 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:55:10.907Z,1725465310.907 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:55:42.031Z,1725465342.031 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:56:13.155Z,1725465373.155 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:56:44.279Z,1725465404.279 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:56:58.627Z,1725465418.627 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2024-09-04T15:56:58.627Z,1725465418.627 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:56:58.637Z,1725465418.637 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T15:56:59.061Z,1725465419.061 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T15:56:59.061Z,1725465419.061 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2024-09-04T15:57:15.427Z,1725465435.427 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:57:35.788Z,1725465455.788 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-04T15:57:35.788Z,1725465455.788 [NAL9602] Data Fault, FailCount= 4
2024-09-04T15:57:35.788Z,1725465455.788 [NAL9602](ERROR): Data Fault
2024-09-04T15:57:35.805Z,1725465455.805 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-04T15:57:36.193Z,1725465456.193 [NAL9602](INFO): Powering down
2024-09-04T15:57:37.012Z,1725465457.012 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-04T15:57:37.012Z,1725465457.012 [NAL9602] No Fault, FailCount= 4
2024-09-04T15:57:46.555Z,1725465466.555 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:58:06.492Z,1725465486.492 [NAL9602](INFO): Powering up NAL9602
2024-09-04T15:58:17.396Z,1725465497.396 [NAL9602](INFO): NAL9602 initialized
2024-09-04T15:58:17.683Z,1725465497.683 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:58:48.807Z,1725465528.807 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:59:19.931Z,1725465559.931 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:59:51.063Z,1725465591.063 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T15:59:59.682Z,1725465599.682 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2024-09-04T15:59:59.682Z,1725465599.682 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T15:59:59.693Z,1725465599.693 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:00:00.104Z,1725465600.104 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:00:00.104Z,1725465600.104 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2024-09-04T16:00:22.203Z,1725465622.203 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:00:53.327Z,1725465653.327 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:01:24.455Z,1725465684.455 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:01:55.579Z,1725465715.579 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:02:26.703Z,1725465746.703 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:02:57.827Z,1725465777.827 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:03:00.682Z,1725465780.682 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2024-09-04T16:03:00.682Z,1725465780.682 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T16:03:00.693Z,1725465780.693 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:03:01.103Z,1725465781.103 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:03:01.103Z,1725465781.103 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2024-09-04T16:03:28.951Z,1725465808.951 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:04:00.079Z,1725465840.079 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:04:31.203Z,1725465871.203 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:05:02.327Z,1725465902.327 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:05:33.451Z,1725465933.451 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:06:01.521Z,1725465961.521 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2024-09-04T16:06:01.521Z,1725465961.521 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T16:06:01.532Z,1725465961.532 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:06:01.965Z,1725465961.965 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:06:01.965Z,1725465961.965 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2024-09-04T16:06:04.575Z,1725465964.575 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:06:35.699Z,1725465995.699 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:07:06.823Z,1725466026.823 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:07:15.163Z,1725466035.163 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003498
2024-09-04T16:07:24.463Z,1725466044.463 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240904T151433/Courier0010.lzma
2024-09-04T16:07:25.464Z,1725466045.464 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0010.lzma.bak
2024-09-04T16:07:25.464Z,1725466045.464 [DataOverHttps](INFO): SBD MOMSN=23124886
2024-09-04T16:07:42.963Z,1725466062.963 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20240904T151433/Express0011.lzma
2024-09-04T16:07:43.964Z,1725466063.964 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0011.lzma.bak
2024-09-04T16:07:43.964Z,1725466063.964 [DataOverHttps](INFO): SBD MOMSN=23124892
2024-09-04T16:07:45.800Z,1725466065.800 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T16:07:45.801Z,1725466065.801 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T16:07:45.801Z,1725466065.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T16:08:18.508Z,1725466098.508 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-04T16:08:18.508Z,1725466098.508 [NAL9602] Data Fault, FailCount= 5
2024-09-04T16:08:18.508Z,1725466098.508 [NAL9602](ERROR): Data Fault
2024-09-04T16:08:18.611Z,1725466098.611 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-04T16:08:18.612Z,1725466098.612 [CBIT](CRITICAL): Data Fault in component: NAL9602
2024-09-04T16:08:18.921Z,1725466098.921 [NAL9602](INFO): Powering down
2024-09-04T16:08:19.026Z,1725466099.026 [CommandExec](FAULT): Scheduling is paused
2024-09-04T16:08:19.038Z,1725466099.038 [CBIT](INFO): Critical error at 20240904T160818
2024-09-04T16:09:02.656Z,1725466142.656 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2024-09-04T16:09:02.656Z,1725466142.656 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T16:09:02.666Z,1725466142.666 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:09:03.075Z,1725466143.075 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:09:03.076Z,1725466143.076 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2024-09-04T16:10:18.656Z,1725466218.656 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-04T16:10:18.656Z,1725466218.656 [NAL9602] No Fault, FailCount= 5
2024-09-04T16:10:19.036Z,1725466219.036 [NAL9602](INFO): Powering up NAL9602
2024-09-04T16:10:29.990Z,1725466229.990 [NAL9602](INFO): NAL9602 initialized
2024-09-04T16:12:03.781Z,1725466323.781 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2024-09-04T16:12:03.781Z,1725466323.781 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T16:12:03.812Z,1725466323.812 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:12:04.184Z,1725466324.184 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:12:04.184Z,1725466324.184 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2024-09-04T16:12:46.237Z,1725466366.237 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T16:12:46.239Z,1725466366.239 [Default:CheckIn:C.Wait] Stopped
2024-09-04T16:12:46.239Z,1725466366.239 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T16:12:46.240Z,1725466366.240 [Default:CheckIn:D] Running Loop=1
2024-09-04T16:12:46.660Z,1725466366.660 [Default:CheckIn:D] Stopped
2024-09-04T16:12:46.660Z,1725466366.660 [Default:CheckIn:E] Running Loop=1
2024-09-04T16:12:47.054Z,1725466367.054 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.920447 min
2024-09-04T16:12:47.054Z,1725466367.054 [Default:CheckIn:E] Stopped
2024-09-04T16:12:47.073Z,1725466367.073 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T16:12:47.073Z,1725466367.073 [Default:CheckIn] Stopped
2024-09-04T16:12:47.073Z,1725466367.073 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T16:12:47.074Z,1725466367.074 [Default:CheckIn](INFO): Running loop #3
2024-09-04T16:12:47.074Z,1725466367.074 [Default:CheckIn] Running Loop=3
2024-09-04T16:12:47.074Z,1725466367.074 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T16:12:47.074Z,1725466367.074 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T16:15:04.844Z,1725466504.844 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2024-09-04T16:15:04.844Z,1725466504.844 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T16:15:04.871Z,1725466504.871 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:15:04.871Z,1725466504.871 [CBIT](FAULT): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:17:47.236Z,1725466667.236 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-04T16:12:47.1Z
2024-09-04T16:17:47.236Z,1725466667.236 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T16:17:47.236Z,1725466667.236 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T16:17:53.986Z,1725466673.986 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20240904T151433/Courier0013.lzma
2024-09-04T16:17:55.391Z,1725466675.391 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0013.lzma.bak
2024-09-04T16:17:55.391Z,1725466675.391 [DataOverHttps](INFO): SBD MOMSN=23124920
2024-09-04T16:18:10.415Z,1725466690.415 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20240904T151433/Express0014.lzma
2024-09-04T16:18:11.416Z,1725466691.416 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0014.lzma.bak
2024-09-04T16:18:11.416Z,1725466691.416 [DataOverHttps](INFO): SBD MOMSN=23124926
2024-09-04T16:18:13.095Z,1725466693.095 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T16:18:13.095Z,1725466693.095 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T16:18:13.095Z,1725466693.095 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T16:20:31.668Z,1725466831.668 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-04T16:20:31.668Z,1725466831.668 [NAL9602] Data Fault, FailCount= 1
2024-09-04T16:20:31.668Z,1725466831.668 [NAL9602](ERROR): Data Fault
2024-09-04T16:20:31.684Z,1725466831.684 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-04T16:20:32.072Z,1725466832.072 [NAL9602](INFO): Powering down
2024-09-04T16:20:32.895Z,1725466832.895 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-04T16:20:32.895Z,1725466832.895 [NAL9602] No Fault, FailCount= 1
2024-09-04T16:20:43.587Z,1725466843.587 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:21:02.376Z,1725466862.376 [NAL9602](INFO): Powering up NAL9602
2024-09-04T16:21:13.276Z,1725466873.276 [NAL9602](INFO): NAL9602 initialized
2024-09-04T16:21:14.715Z,1725466874.715 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-09-04T16:23:13.789Z,1725466993.789 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T16:23:13.789Z,1725466993.789 [Default:CheckIn:C.Wait] Stopped
2024-09-04T16:23:13.789Z,1725466993.789 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T16:23:13.789Z,1725466993.789 [Default:CheckIn:D] Running Loop=1
2024-09-04T16:23:14.192Z,1725466994.192 [Default:CheckIn:D] Stopped
2024-09-04T16:23:14.192Z,1725466994.192 [Default:CheckIn:E] Running Loop=1
2024-09-04T16:23:14.571Z,1725466994.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.379313 min
2024-09-04T16:23:14.571Z,1725466994.571 [Default:CheckIn:E] Stopped
2024-09-04T16:23:14.571Z,1725466994.571 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T16:23:14.571Z,1725466994.571 [Default:CheckIn] Stopped
2024-09-04T16:23:14.571Z,1725466994.571 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T16:23:14.572Z,1725466994.572 [Default:CheckIn](INFO): Running loop #4
2024-09-04T16:23:14.572Z,1725466994.572 [Default:CheckIn] Running Loop=4
2024-09-04T16:23:14.572Z,1725466994.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T16:23:14.572Z,1725466994.572 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T16:26:21.487Z,1725467181.487 [CommandExec](IMPORTANT): got command failComponent
2024-09-04T16:26:21.487Z,1725467181.487 [CommandExec](IMPORTANT): Failed components:
2024-09-04T16:26:21.488Z,1725467181.488 [CommandExec](IMPORTANT): DeadReckonUsingMultipleVelocitySources: Software Fault
2024-09-04T16:27:22.563Z,1725467242.563 [CommandExec](IMPORTANT): got command failComponent
2024-09-04T16:27:22.563Z,1725467242.563 [CommandExec](IMPORTANT): Failed components:
2024-09-04T16:27:22.564Z,1725467242.564 [CommandExec](IMPORTANT): DeadReckonUsingMultipleVelocitySources: Software Fault
2024-09-04T16:27:31.247Z,1725467251.247 [CommandExec](IMPORTANT): got command failComponent
2024-09-04T16:27:31.248Z,1725467251.248 [CommandExec](IMPORTANT): Failed components:
2024-09-04T16:27:31.248Z,1725467251.248 [CommandExec](IMPORTANT): DeadReckonUsingMultipleVelocitySources: Software Fault
2024-09-04T16:28:14.936Z,1725467294.936 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-04T16:23:14.6Z
2024-09-04T16:28:14.937Z,1725467294.937 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T16:28:14.937Z,1725467294.937 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T16:28:25.046Z,1725467305.046 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240904T151433/Courier0016.lzma
2024-09-04T16:28:26.048Z,1725467306.048 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0016.lzma.bak
2024-09-04T16:28:26.049Z,1725467306.049 [DataOverHttps](INFO): SBD MOMSN=23124968
2024-09-04T16:28:41.899Z,1725467321.899 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20240904T151433/Express0017.lzma
2024-09-04T16:28:42.916Z,1725467322.916 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0017.lzma.bak
2024-09-04T16:28:42.916Z,1725467322.916 [DataOverHttps](INFO): SBD MOMSN=23124970
2024-09-04T16:28:44.508Z,1725467324.508 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T16:28:44.508Z,1725467324.508 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T16:28:44.508Z,1725467324.508 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T16:30:04.903Z,1725467404.903 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:30:04.903Z,1725467404.903 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2024-09-04T16:31:15.684Z,1725467475.684 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-09-04T16:31:15.684Z,1725467475.684 [NAL9602] Data Fault, FailCount= 2
2024-09-04T16:31:15.684Z,1725467475.684 [NAL9602](ERROR): Data Fault
2024-09-04T16:31:15.731Z,1725467475.731 [CBIT](ERROR): Data Fault in component: NAL9602
2024-09-04T16:31:16.088Z,1725467476.088 [NAL9602](INFO): Powering down
2024-09-04T16:31:16.909Z,1725467476.909 [CBIT](INFO): Clearing failed state for component NAL9602
2024-09-04T16:31:16.909Z,1725467476.909 [NAL9602] No Fault, FailCount= 2
2024-09-04T16:31:46.388Z,1725467506.388 [NAL9602](INFO): Powering up NAL9602
2024-09-04T16:31:57.296Z,1725467517.296 [NAL9602](INFO): NAL9602 initialized
2024-09-04T16:33:05.691Z,1725467585.691 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2024-09-04T16:33:05.691Z,1725467585.691 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T16:33:05.701Z,1725467585.701 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:33:06.117Z,1725467586.117 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:33:06.117Z,1725467586.117 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2024-09-04T16:33:45.280Z,1725467625.280 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T16:33:45.280Z,1725467625.280 [Default:CheckIn:C.Wait] Stopped
2024-09-04T16:33:45.280Z,1725467625.280 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T16:33:45.280Z,1725467625.280 [Default:CheckIn:D] Running Loop=1
2024-09-04T16:33:45.684Z,1725467625.684 [Default:CheckIn:D] Stopped
2024-09-04T16:33:45.684Z,1725467625.684 [Default:CheckIn:E] Running Loop=1
2024-09-04T16:33:46.109Z,1725467626.109 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.904175 min
2024-09-04T16:33:46.109Z,1725467626.109 [Default:CheckIn:E] Stopped
2024-09-04T16:33:46.109Z,1725467626.109 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T16:33:46.109Z,1725467626.109 [Default:CheckIn] Stopped
2024-09-04T16:33:46.109Z,1725467626.109 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T16:33:46.109Z,1725467626.109 [Default:CheckIn](INFO): Running loop #5
2024-09-04T16:33:46.109Z,1725467626.109 [Default:CheckIn] Running Loop=5
2024-09-04T16:33:46.110Z,1725467626.110 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T16:33:46.110Z,1725467626.110 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T16:36:06.811Z,1725467766.811 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2024-09-04T16:36:06.811Z,1725467766.811 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-09-04T16:36:06.821Z,1725467766.821 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-09-04T16:36:07.237Z,1725467767.237 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-09-04T16:36:07.237Z,1725467767.237 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2024-09-04T16:38:46.133Z,1725467926.133 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-09-04T16:33:46.1Z
2024-09-04T16:38:46.133Z,1725467926.133 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T16:38:46.133Z,1725467926.133 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T16:38:56.202Z,1725467936.202 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20240904T151433/Courier0019.lzma
2024-09-04T16:38:57.205Z,1725467937.205 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0019.lzma.bak
2024-09-04T16:38:57.205Z,1725467937.205 [DataOverHttps](INFO): SBD MOMSN=23125020
2024-09-04T16:39:00.710Z,1725467940.710 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163859.00,A,3648.16110,N,12147.28729,W,2.177,0.00,040924,,,A*7D
2024-09-04T16:39:00.713Z,1725467940.713 [NAL9602](INFO): GPS fix at 20240904T163859: (36.802685, -121.788122)
2024-09-04T16:39:01.158Z,1725467941.158 [DeadReckonUsingMultipleVelocitySources](INFO): Failure count cleared after critical for DeadReckonUsingMultipleVelocitySources
2024-09-04T16:39:13.886Z,1725467953.886 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20240904T151433/Express0020.lzma
2024-09-04T16:39:14.888Z,1725467954.888 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0020.lzma.bak
2024-09-04T16:39:14.888Z,1725467954.888 [DataOverHttps](INFO): SBD MOMSN=23125022
2024-09-04T16:39:16.946Z,1725467956.946 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T16:39:16.947Z,1725467956.947 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T16:39:16.947Z,1725467956.947 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T16:39:33.438Z,1725467973.438 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T16:40:57.541Z,1725468057.541 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:41:09.721Z,1725468069.721 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:41:21.841Z,1725468081.841 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:41:33.965Z,1725468093.965 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:41:45.677Z,1725468105.677 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:41:57.797Z,1725468117.797 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:42:09.513Z,1725468129.513 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:42:22.445Z,1725468142.445 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-09-04T16:44:17.310Z,1725468257.310 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T16:44:17.310Z,1725468257.310 [Default:CheckIn:C.Wait] Stopped
2024-09-04T16:44:17.311Z,1725468257.311 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T16:44:17.311Z,1725468257.311 [Default:CheckIn:D] Running Loop=1
2024-09-04T16:44:17.707Z,1725468257.707 [Default:CheckIn:D] Stopped
2024-09-04T16:44:17.707Z,1725468257.707 [Default:CheckIn:E] Running Loop=1
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.437817 min
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn:E] Stopped
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn] Stopped
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn](INFO): Running loop #6
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn] Running Loop=6
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T16:44:18.082Z,1725468258.082 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T16:44:20.067Z,1725468260.067 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164419.00,A,3648.16014,N,12147.28098,W,0.350,0.00,040924,,,A*7F
2024-09-04T16:44:20.069Z,1725468260.069 [NAL9602](INFO): GPS fix at 20240904T164419: (36.802669, -121.788016)
2024-09-04T16:44:20.176Z,1725468260.176 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T16:44:20.176Z,1725468260.176 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T16:44:30.323Z,1725468270.323 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20240904T151433/Courier0022.lzma
2024-09-04T16:44:31.325Z,1725468271.325 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0022.lzma.bak
2024-09-04T16:44:31.325Z,1725468271.325 [DataOverHttps](INFO): SBD MOMSN=23125041
2024-09-04T16:44:44.361Z,1725468284.361 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2024-09-04T16:44:47.271Z,1725468287.271 [DataOverHttps](INFO): Sending 262 bytes from file Logs/20240904T151433/Express0023.lzma
2024-09-04T16:44:48.272Z,1725468288.272 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0023.lzma.bak
2024-09-04T16:44:48.273Z,1725468288.273 [DataOverHttps](INFO): SBD MOMSN=23125044
2024-09-04T16:44:50.057Z,1725468290.057 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T16:44:50.058Z,1725468290.058 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T16:44:50.058Z,1725468290.058 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T16:44:50.439Z,1725468290.439 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:45:03.813Z,1725468303.813 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:45:17.155Z,1725468317.155 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:45:30.881Z,1725468330.881 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:45:44.233Z,1725468344.233 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:45:57.559Z,1725468357.559 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:46:11.295Z,1725468371.295 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:46:25.441Z,1725468385.441 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:46:38.814Z,1725468398.814 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:46:52.145Z,1725468412.145 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T16:47:04.324Z,1725468424.324 [BPC1](INFO): Calculating totals. Valid battery stick count: 41. Valid reserve battery stick count: 5.
2024-09-04T16:47:04.347Z,1725468424.347 [BPC1](INFO): Received data from all battery sticks.
2024-09-04T16:49:22.200Z,1725468562.200 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T16:49:50.907Z,1725468590.907 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T16:49:50.907Z,1725468590.907 [Default:CheckIn:C.Wait] Stopped
2024-09-04T16:49:50.907Z,1725468590.907 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T16:49:50.908Z,1725468590.908 [Default:CheckIn:D] Running Loop=1
2024-09-04T16:49:51.306Z,1725468591.306 [Default:CheckIn:D] Stopped
2024-09-04T16:49:51.306Z,1725468591.306 [Default:CheckIn:E] Running Loop=1
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 74.997876 min
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn:E] Stopped
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn] Stopped
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn](INFO): Running loop #7
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn] Running Loop=7
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T16:49:51.710Z,1725468591.710 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T16:49:53.719Z,1725468593.719 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164953.00,A,3648.17229,N,12147.28525,W,1.613,348.23,040924,,,A*7F
2024-09-04T16:49:53.721Z,1725468593.721 [NAL9602](INFO): GPS fix at 20240904T164953: (36.802872, -121.788088)
2024-09-04T16:49:53.732Z,1725468593.732 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T16:49:53.732Z,1725468593.732 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T16:50:00.334Z,1725468600.334 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20240904T151433/Courier0025.lzma
2024-09-04T16:50:01.336Z,1725468601.336 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0025.lzma.bak
2024-09-04T16:50:01.336Z,1725468601.336 [DataOverHttps](INFO): SBD MOMSN=23125066
2024-09-04T16:50:17.047Z,1725468617.047 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20240904T151433/Express0026.lzma
2024-09-04T16:50:18.048Z,1725468618.048 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0026.lzma.bak
2024-09-04T16:50:18.049Z,1725468618.049 [DataOverHttps](INFO): SBD MOMSN=23125069
2024-09-04T16:50:19.981Z,1725468619.981 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T16:50:19.981Z,1725468619.981 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T16:50:19.981Z,1725468619.981 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T16:50:26.499Z,1725468626.499 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T16:55:20.500Z,1725468920.500 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T16:55:20.501Z,1725468920.501 [Default:CheckIn:C.Wait] Stopped
2024-09-04T16:55:20.501Z,1725468920.501 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T16:55:20.501Z,1725468920.501 [Default:CheckIn:D] Running Loop=1
2024-09-04T16:55:20.903Z,1725468920.903 [Default:CheckIn:D] Stopped
2024-09-04T16:55:20.903Z,1725468920.903 [Default:CheckIn:E] Running Loop=1
2024-09-04T16:55:21.306Z,1725468921.306 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.491162 min
2024-09-04T16:55:21.306Z,1725468921.306 [Default:CheckIn:E] Stopped
2024-09-04T16:55:21.306Z,1725468921.306 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T16:55:21.306Z,1725468921.306 [Default:CheckIn] Stopped
2024-09-04T16:55:21.306Z,1725468921.306 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T16:55:21.307Z,1725468921.307 [Default:CheckIn](INFO): Running loop #8
2024-09-04T16:55:21.307Z,1725468921.307 [Default:CheckIn] Running Loop=8
2024-09-04T16:55:21.307Z,1725468921.307 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T16:55:21.307Z,1725468921.307 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T16:55:23.317Z,1725468923.317 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165522.00,A,3648.16234,N,12147.28557,W,0.486,0.00,040924,,,A*7D
2024-09-04T16:55:23.320Z,1725468923.320 [NAL9602](INFO): GPS fix at 20240904T165522: (36.802706, -121.788093)
2024-09-04T16:55:23.330Z,1725468923.330 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T16:55:23.330Z,1725468923.330 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T16:55:30.734Z,1725468930.734 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0028.lzma
2024-09-04T16:55:31.736Z,1725468931.736 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0028.lzma.bak
2024-09-04T16:55:31.736Z,1725468931.736 [DataOverHttps](INFO): SBD MOMSN=23125087
2024-09-04T16:55:47.566Z,1725468947.566 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240904T151433/Express0029.lzma
2024-09-04T16:55:48.569Z,1725468948.569 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0029.lzma.bak
2024-09-04T16:55:48.569Z,1725468948.569 [DataOverHttps](INFO): SBD MOMSN=23125090
2024-09-04T16:55:49.990Z,1725468949.990 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T16:55:49.990Z,1725468949.990 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T16:55:49.990Z,1725468949.990 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T16:55:54.020Z,1725468954.020 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T16:55:54.102Z,1725468954.102 [NAL9602](ERROR): received:
+CSQ:0
OK
2024-09-04T16:58:03.805Z,1725469083.805 [NAL9602](INFO): SBD MO Status=2, MOMSN=56382, MT Status=2, MTMSN=0
2024-09-04T16:58:03.805Z,1725469083.805 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:00:15.645Z,1725469215.645 [NAL9602](INFO): SBD MO Status=2, MOMSN=56382, MT Status=2, MTMSN=0
2024-09-04T17:00:15.645Z,1725469215.645 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:00:24.938Z,1725469224.938 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T17:00:50.465Z,1725469250.465 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:00:50.465Z,1725469250.465 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:00:50.465Z,1725469250.465 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:00:50.465Z,1725469250.465 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:00:50.896Z,1725469250.896 [Default:CheckIn:D] Stopped
2024-09-04T17:00:50.896Z,1725469250.896 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:00:51.271Z,1725469251.271 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.991048 min
2024-09-04T17:00:51.271Z,1725469251.271 [Default:CheckIn:E] Stopped
2024-09-04T17:00:51.272Z,1725469251.272 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:00:51.272Z,1725469251.272 [Default:CheckIn] Stopped
2024-09-04T17:00:51.272Z,1725469251.272 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:00:51.272Z,1725469251.272 [Default:CheckIn](INFO): Running loop #9
2024-09-04T17:00:51.272Z,1725469251.272 [Default:CheckIn] Running Loop=9
2024-09-04T17:00:51.272Z,1725469251.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:00:51.272Z,1725469251.272 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:00:53.280Z,1725469253.280 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170052.00,A,3648.16309,N,12147.28534,W,0.836,286.95,040924,,,A*76
2024-09-04T17:00:53.291Z,1725469253.291 [NAL9602](INFO): GPS fix at 20240904T170052: (36.802718, -121.788089)
2024-09-04T17:00:53.312Z,1725469253.312 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:00:53.312Z,1725469253.312 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:01:03.934Z,1725469263.934 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0031.lzma
2024-09-04T17:01:05.512Z,1725469265.512 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0031.lzma.bak
2024-09-04T17:01:05.513Z,1725469265.513 [DataOverHttps](INFO): SBD MOMSN=23125123
2024-09-04T17:01:20.727Z,1725469280.727 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20240904T151433/Express0032.lzma
2024-09-04T17:01:21.728Z,1725469281.728 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0032.lzma.bak
2024-09-04T17:01:21.728Z,1725469281.728 [DataOverHttps](INFO): SBD MOMSN=23125126
2024-09-04T17:01:23.251Z,1725469283.251 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:01:23.251Z,1725469283.251 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:01:23.251Z,1725469283.251 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:01:25.671Z,1725469285.671 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T17:06:24.049Z,1725469584.049 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:06:24.050Z,1725469584.050 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:06:24.050Z,1725469584.050 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:06:24.050Z,1725469584.050 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:06:24.472Z,1725469584.472 [Default:CheckIn:D] Stopped
2024-09-04T17:06:24.472Z,1725469584.472 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 91.550643 min
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn:E] Stopped
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn] Stopped
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn](INFO): Running loop #10
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn] Running Loop=10
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:06:24.892Z,1725469584.892 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:06:26.856Z,1725469586.856 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170626.00,A,3648.16262,N,12147.28227,W,0.525,53.42,040924,,,A*45
2024-09-04T17:06:26.858Z,1725469586.858 [NAL9602](INFO): GPS fix at 20240904T170626: (36.802710, -121.788038)
2024-09-04T17:06:26.897Z,1725469586.897 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:06:26.897Z,1725469586.897 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:06:36.214Z,1725469596.214 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0034.lzma
2024-09-04T17:06:37.216Z,1725469597.216 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0034.lzma.bak
2024-09-04T17:06:37.217Z,1725469597.217 [DataOverHttps](INFO): SBD MOMSN=23125145
2024-09-04T17:06:55.959Z,1725469615.959 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240904T151433/Express0035.lzma
2024-09-04T17:06:56.968Z,1725469616.968 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0035.lzma.bak
2024-09-04T17:06:56.969Z,1725469616.969 [DataOverHttps](INFO): SBD MOMSN=23125148
2024-09-04T17:06:57.308Z,1725469617.308 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T17:06:57.391Z,1725469617.391 [NAL9602](ERROR): received:
+CSQ:0
OK382, 2, 0, 0, 0
OK
2024-09-04T17:06:58.996Z,1725469618.996 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:06:58.996Z,1725469618.996 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:06:58.997Z,1725469618.997 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:09:24.789Z,1725469764.789 [NAL9602](INFO): SBD MO Status=2, MOMSN=56382, MT Status=2, MTMSN=0
2024-09-04T17:09:24.789Z,1725469764.789 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:10:17.309Z,1725469817.309 [NAL9602](INFO): SBD MO Status=2, MOMSN=56382, MT Status=2, MTMSN=0
2024-09-04T17:10:17.309Z,1725469817.309 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:10:34.283Z,1725469834.283 [NAL9602](INFO): SBD MO Status=2, MOMSN=56382, MT Status=2, MTMSN=0
2024-09-04T17:10:34.284Z,1725469834.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:11:05.009Z,1725469865.009 [NAL9602](INFO): SBD MO Status=0, MOMSN=56382, MT Status=0, MTMSN=0
2024-09-04T17:11:05.009Z,1725469865.009 [NAL9602](INFO): No messages in MT queue
2024-09-04T17:11:35.713Z,1725469895.713 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T17:11:59.561Z,1725469919.561 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:11:59.561Z,1725469919.561 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:11:59.561Z,1725469919.561 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:11:59.561Z,1725469919.561 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:11:59.979Z,1725469919.979 [Default:CheckIn:D] Stopped
2024-09-04T17:11:59.979Z,1725469919.979 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.142432 min
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn:E] Stopped
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn] Stopped
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn](INFO): Running loop #11
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn] Running Loop=11
2024-09-04T17:12:00.361Z,1725469920.361 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:12:00.362Z,1725469920.362 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:12:02.381Z,1725469922.381 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171201.00,A,3648.16237,N,12147.28679,W,1.575,62.28,040924,,,A*40
2024-09-04T17:12:02.384Z,1725469922.384 [NAL9602](INFO): GPS fix at 20240904T171201: (36.802706, -121.788113)
2024-09-04T17:12:02.394Z,1725469922.394 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:12:02.394Z,1725469922.394 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:12:09.746Z,1725469929.746 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0037.lzma
2024-09-04T17:12:10.749Z,1725469930.749 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0037.lzma.bak
2024-09-04T17:12:10.749Z,1725469930.749 [DataOverHttps](INFO): SBD MOMSN=23125177
2024-09-04T17:12:27.501Z,1725469947.501 [NAL9602](INFO): SBD MO Status=2, MOMSN=56383, MT Status=2, MTMSN=0
2024-09-04T17:12:27.501Z,1725469947.501 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:12:29.638Z,1725469949.638 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20240904T151433/Express0038.lzma
2024-09-04T17:12:30.640Z,1725469950.640 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0038.lzma.bak
2024-09-04T17:12:30.640Z,1725469950.640 [DataOverHttps](INFO): SBD MOMSN=23125180
2024-09-04T17:12:31.962Z,1725469951.962 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:12:31.962Z,1725469951.962 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:12:31.963Z,1725469951.963 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:12:50.925Z,1725469970.925 [NAL9602](INFO): SBD MO Status=2, MOMSN=56383, MT Status=2, MTMSN=0
2024-09-04T17:12:50.925Z,1725469970.925 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:13:23.653Z,1725470003.653 [NAL9602](INFO): SBD MO Status=2, MOMSN=56383, MT Status=2, MTMSN=0
2024-09-04T17:13:23.653Z,1725470003.653 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T17:17:04.228Z,1725470224.228 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T17:17:32.516Z,1725470252.516 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:17:32.516Z,1725470252.516 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:17:32.516Z,1725470252.516 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:17:32.516Z,1725470252.516 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:17:32.927Z,1725470252.927 [Default:CheckIn:D] Stopped
2024-09-04T17:17:32.927Z,1725470252.927 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 102.691561 min
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn:E] Stopped
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn] Stopped
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn](INFO): Running loop #12
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn] Running Loop=12
2024-09-04T17:17:33.334Z,1725470253.334 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:17:33.335Z,1725470253.335 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:17:35.337Z,1725470255.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171734.00,A,3648.16347,N,12147.28304,W,0.058,75.06,040924,,,A*4B
2024-09-04T17:17:35.339Z,1725470255.339 [NAL9602](INFO): GPS fix at 20240904T171734: (36.802724, -121.788051)
2024-09-04T17:17:35.350Z,1725470255.350 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:17:35.350Z,1725470255.350 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:17:43.378Z,1725470263.378 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0040.lzma
2024-09-04T17:17:44.380Z,1725470264.380 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0040.lzma.bak
2024-09-04T17:17:44.380Z,1725470264.380 [DataOverHttps](INFO): SBD MOMSN=23125196
2024-09-04T17:18:00.074Z,1725470280.074 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20240904T151433/Express0041.lzma
2024-09-04T17:18:01.076Z,1725470281.076 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0041.lzma.bak
2024-09-04T17:18:01.076Z,1725470281.076 [DataOverHttps](INFO): SBD MOMSN=23125199
2024-09-04T17:18:02.426Z,1725470282.426 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:18:02.427Z,1725470282.427 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:18:02.427Z,1725470282.427 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:18:07.251Z,1725470287.251 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T17:23:03.061Z,1725470583.061 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:23:03.061Z,1725470583.061 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:23:03.061Z,1725470583.061 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:23:03.061Z,1725470583.061 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:23:03.446Z,1725470583.446 [Default:CheckIn:D] Stopped
2024-09-04T17:23:03.446Z,1725470583.446 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:23:03.853Z,1725470583.853 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.200203 min
2024-09-04T17:23:03.853Z,1725470583.853 [Default:CheckIn:E] Stopped
2024-09-04T17:23:03.854Z,1725470583.854 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:23:03.854Z,1725470583.854 [Default:CheckIn] Stopped
2024-09-04T17:23:03.854Z,1725470583.854 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:23:03.854Z,1725470583.854 [Default:CheckIn](INFO): Running loop #13
2024-09-04T17:23:03.854Z,1725470583.854 [Default:CheckIn] Running Loop=13
2024-09-04T17:23:03.854Z,1725470583.854 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:23:03.854Z,1725470583.854 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:23:05.861Z,1725470585.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172305.00,A,3648.16554,N,12147.28169,W,0.233,75.06,040924,,,A*4C
2024-09-04T17:23:05.864Z,1725470585.864 [NAL9602](INFO): GPS fix at 20240904T172305: (36.802759, -121.788028)
2024-09-04T17:23:05.874Z,1725470585.874 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:23:05.874Z,1725470585.874 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:23:13.678Z,1725470593.678 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0043.lzma
2024-09-04T17:23:14.681Z,1725470594.681 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0043.lzma.bak
2024-09-04T17:23:14.681Z,1725470594.681 [DataOverHttps](INFO): SBD MOMSN=23125223
2024-09-04T17:23:30.475Z,1725470610.475 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240904T151433/Express0044.lzma
2024-09-04T17:23:31.478Z,1725470611.478 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0044.lzma.bak
2024-09-04T17:23:31.478Z,1725470611.478 [DataOverHttps](INFO): SBD MOMSN=23125226
2024-09-04T17:23:32.951Z,1725470612.951 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:23:32.951Z,1725470612.951 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:23:32.951Z,1725470612.951 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:23:36.564Z,1725470616.564 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T17:23:36.638Z,1725470616.638 [NAL9602](ERROR): received:
+CSQ:0
OK383, 2, 0, 0, 0
OK
2024-09-04T17:28:08.460Z,1725470888.460 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T17:28:33.525Z,1725470913.525 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:28:33.525Z,1725470913.525 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:28:33.525Z,1725470913.525 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:28:33.526Z,1725470913.526 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:28:33.923Z,1725470913.923 [Default:CheckIn:D] Stopped
2024-09-04T17:28:33.923Z,1725470913.923 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:28:34.326Z,1725470914.326 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.708154 min
2024-09-04T17:28:34.326Z,1725470914.326 [Default:CheckIn:E] Stopped
2024-09-04T17:28:34.327Z,1725470914.327 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:28:34.327Z,1725470914.327 [Default:CheckIn] Stopped
2024-09-04T17:28:34.327Z,1725470914.327 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:28:34.327Z,1725470914.327 [Default:CheckIn](INFO): Running loop #14
2024-09-04T17:28:34.327Z,1725470914.327 [Default:CheckIn] Running Loop=14
2024-09-04T17:28:34.327Z,1725470914.327 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:28:34.327Z,1725470914.327 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:28:36.334Z,1725470916.334 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172835.00,A,3648.16256,N,12147.28524,W,1.050,51.96,040924,,,A*45
2024-09-04T17:28:36.336Z,1725470916.336 [NAL9602](INFO): GPS fix at 20240904T172835: (36.802709, -121.788087)
2024-09-04T17:28:36.371Z,1725470916.371 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:28:36.371Z,1725470916.371 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:28:43.930Z,1725470923.930 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0046.lzma
2024-09-04T17:28:44.932Z,1725470924.932 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0046.lzma.bak
2024-09-04T17:28:44.932Z,1725470924.932 [DataOverHttps](INFO): SBD MOMSN=23125243
2024-09-04T17:29:03.762Z,1725470943.762 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20240904T151433/Express0047.lzma
2024-09-04T17:29:04.764Z,1725470944.764 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0047.lzma.bak
2024-09-04T17:29:04.765Z,1725470944.765 [DataOverHttps](INFO): SBD MOMSN=23125246
2024-09-04T17:29:06.299Z,1725470946.299 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:29:06.300Z,1725470946.300 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:29:06.300Z,1725470946.300 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:29:08.299Z,1725470948.299 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T17:34:06.898Z,1725471246.898 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:34:06.898Z,1725471246.898 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:34:06.898Z,1725471246.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:34:06.898Z,1725471246.898 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:34:07.313Z,1725471247.313 [Default:CheckIn:D] Stopped
2024-09-04T17:34:07.314Z,1725471247.314 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:34:07.693Z,1725471247.693 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.264673 min
2024-09-04T17:34:07.693Z,1725471247.693 [Default:CheckIn:E] Stopped
2024-09-04T17:34:07.694Z,1725471247.694 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:34:07.694Z,1725471247.694 [Default:CheckIn] Stopped
2024-09-04T17:34:07.694Z,1725471247.694 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:34:07.694Z,1725471247.694 [Default:CheckIn](INFO): Running loop #15
2024-09-04T17:34:07.694Z,1725471247.694 [Default:CheckIn] Running Loop=15
2024-09-04T17:34:07.694Z,1725471247.694 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:34:07.694Z,1725471247.694 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:34:09.709Z,1725471249.709 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173409.00,A,3648.16735,N,12147.28665,W,0.408,91.56,040924,,,A*49
2024-09-04T17:34:09.721Z,1725471249.721 [NAL9602](INFO): GPS fix at 20240904T173409: (36.802789, -121.788111)
2024-09-04T17:34:09.732Z,1725471249.732 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:34:09.732Z,1725471249.732 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:34:17.262Z,1725471257.262 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0049.lzma
2024-09-04T17:34:18.264Z,1725471258.264 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0049.lzma.bak
2024-09-04T17:34:18.265Z,1725471258.265 [DataOverHttps](INFO): SBD MOMSN=23125274
2024-09-04T17:34:36.810Z,1725471276.810 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20240904T151433/Express0050.lzma
2024-09-04T17:34:37.812Z,1725471277.812 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0050.lzma.bak
2024-09-04T17:34:37.812Z,1725471277.812 [DataOverHttps](INFO): SBD MOMSN=23125277
2024-09-04T17:34:39.282Z,1725471279.282 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:34:39.282Z,1725471279.282 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:34:39.282Z,1725471279.282 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:34:40.476Z,1725471280.476 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T17:34:40.558Z,1725471280.558 [NAL9602](ERROR): received:
+CSQ:0
OK383, 2, 0, 0, 0
OK
2024-09-04T17:39:12.372Z,1725471552.372 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T17:39:39.849Z,1725471579.849 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:39:39.849Z,1725471579.849 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:39:39.850Z,1725471579.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:39:39.850Z,1725471579.850 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:39:40.256Z,1725471580.256 [Default:CheckIn:D] Stopped
2024-09-04T17:39:40.256Z,1725471580.256 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:39:40.669Z,1725471580.669 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 124.813713 min
2024-09-04T17:39:40.669Z,1725471580.669 [Default:CheckIn:E] Stopped
2024-09-04T17:39:40.669Z,1725471580.669 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:39:40.669Z,1725471580.669 [Default:CheckIn] Stopped
2024-09-04T17:39:40.669Z,1725471580.669 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:39:40.670Z,1725471580.670 [Default:CheckIn](INFO): Running loop #16
2024-09-04T17:39:40.670Z,1725471580.670 [Default:CheckIn] Running Loop=16
2024-09-04T17:39:40.670Z,1725471580.670 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:39:40.670Z,1725471580.670 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:39:42.670Z,1725471582.670 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173941.00,A,3648.16715,N,12147.28534,W,0.019,91.63,040924,,,A*4F
2024-09-04T17:39:42.672Z,1725471582.672 [NAL9602](INFO): GPS fix at 20240904T173941: (36.802786, -121.788089)
2024-09-04T17:39:42.687Z,1725471582.687 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:39:42.687Z,1725471582.687 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:39:49.970Z,1725471589.970 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0052.lzma
2024-09-04T17:39:50.972Z,1725471590.972 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0052.lzma.bak
2024-09-04T17:39:50.972Z,1725471590.972 [DataOverHttps](INFO): SBD MOMSN=23125292
2024-09-04T17:40:08.622Z,1725471608.622 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20240904T151433/Express0053.lzma
2024-09-04T17:40:09.624Z,1725471609.624 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0053.lzma.bak
2024-09-04T17:40:09.625Z,1725471609.625 [DataOverHttps](INFO): SBD MOMSN=23125295
2024-09-04T17:40:10.966Z,1725471610.966 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:40:10.967Z,1725471610.967 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:40:10.967Z,1725471610.967 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:40:15.391Z,1725471615.391 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T17:45:11.680Z,1725471911.680 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:45:11.681Z,1725471911.681 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:45:11.681Z,1725471911.681 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:45:11.681Z,1725471911.681 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:45:12.081Z,1725471912.081 [Default:CheckIn:D] Stopped
2024-09-04T17:45:12.081Z,1725471912.081 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:45:12.486Z,1725471912.486 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.344124 min
2024-09-04T17:45:12.486Z,1725471912.486 [Default:CheckIn:E] Stopped
2024-09-04T17:45:12.486Z,1725471912.486 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:45:12.486Z,1725471912.486 [Default:CheckIn] Stopped
2024-09-04T17:45:12.486Z,1725471912.486 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:45:12.487Z,1725471912.487 [Default:CheckIn](INFO): Running loop #17
2024-09-04T17:45:12.487Z,1725471912.487 [Default:CheckIn] Running Loop=17
2024-09-04T17:45:12.487Z,1725471912.487 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:45:12.487Z,1725471912.487 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:45:14.496Z,1725471914.496 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174513.00,A,3648.15788,N,12147.28212,W,0.233,150.46,040924,,,A*76
2024-09-04T17:45:14.498Z,1725471914.498 [NAL9602](INFO): GPS fix at 20240904T174513: (36.802631, -121.788035)
2024-09-04T17:45:14.509Z,1725471914.509 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:45:14.509Z,1725471914.509 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:45:22.334Z,1725471922.334 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0055.lzma
2024-09-04T17:45:23.337Z,1725471923.337 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0055.lzma.bak
2024-09-04T17:45:23.337Z,1725471923.337 [DataOverHttps](INFO): SBD MOMSN=23125313
2024-09-04T17:45:39.127Z,1725471939.127 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20240904T151433/Express0056.lzma
2024-09-04T17:45:40.124Z,1725471940.124 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0056.lzma.bak
2024-09-04T17:45:40.124Z,1725471940.124 [DataOverHttps](INFO): SBD MOMSN=23125316
2024-09-04T17:45:41.585Z,1725471941.585 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:45:41.585Z,1725471941.585 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:45:41.585Z,1725471941.585 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:45:45.200Z,1725471945.200 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T17:45:45.278Z,1725471945.278 [NAL9602](ERROR): received:
+CSQ:0
OK383, 2, 0, 0, 0
OK
2024-09-04T17:48:10.245Z,1725472090.245 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:48:22.397Z,1725472102.397 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:48:34.114Z,1725472114.114 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:48:46.239Z,1725472126.239 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:48:58.785Z,1725472138.785 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:49:10.500Z,1725472150.500 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:49:21.813Z,1725472161.813 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:49:33.550Z,1725472173.550 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:50:16.360Z,1725472216.360 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T17:50:42.282Z,1725472242.282 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:50:42.282Z,1725472242.282 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:50:42.283Z,1725472242.283 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:50:42.283Z,1725472242.283 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:50:42.681Z,1725472242.681 [Default:CheckIn:D] Stopped
2024-09-04T17:50:42.681Z,1725472242.681 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:50:43.092Z,1725472243.092 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 135.854134 min
2024-09-04T17:50:43.092Z,1725472243.092 [Default:CheckIn:E] Stopped
2024-09-04T17:50:43.092Z,1725472243.092 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:50:43.092Z,1725472243.092 [Default:CheckIn] Stopped
2024-09-04T17:50:43.092Z,1725472243.092 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:50:43.092Z,1725472243.092 [Default:CheckIn](INFO): Running loop #18
2024-09-04T17:50:43.093Z,1725472243.093 [Default:CheckIn] Running Loop=18
2024-09-04T17:50:43.093Z,1725472243.093 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:50:43.093Z,1725472243.093 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:50:45.102Z,1725472245.102 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175044.00,A,3648.16262,N,12147.29377,W,0.156,150.46,040924,,,A*71
2024-09-04T17:50:45.104Z,1725472245.104 [NAL9602](INFO): GPS fix at 20240904T175044: (36.802710, -121.788229)
2024-09-04T17:50:45.114Z,1725472245.114 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:50:45.114Z,1725472245.114 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:50:55.018Z,1725472255.018 [DataOverHttps](INFO): Sending 71 bytes from file Logs/20240904T151433/Courier0058.lzma
2024-09-04T17:50:56.021Z,1725472256.021 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0058.lzma.bak
2024-09-04T17:50:56.021Z,1725472256.021 [DataOverHttps](INFO): SBD MOMSN=23125347
2024-09-04T17:51:12.190Z,1725472272.190 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20240904T151433/Express0059.lzma
2024-09-04T17:51:13.192Z,1725472273.192 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0059.lzma.bak
2024-09-04T17:51:13.192Z,1725472273.192 [DataOverHttps](INFO): SBD MOMSN=23125350
2024-09-04T17:51:14.663Z,1725472274.663 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:51:14.663Z,1725472274.663 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:51:14.663Z,1725472274.663 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:51:17.475Z,1725472277.475 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T17:52:07.265Z,1725472327.265 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:52:18.577Z,1725472338.577 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:52:30.341Z,1725472350.341 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:52:42.056Z,1725472362.056 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:52:54.240Z,1725472374.240 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:53:05.949Z,1725472385.949 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:53:17.665Z,1725472397.665 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:53:29.785Z,1725472409.785 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:53:41.500Z,1725472421.500 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:53:53.218Z,1725472433.218 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:54:04.934Z,1725472444.934 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:54:17.053Z,1725472457.053 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-09-04T17:54:20.714Z,1725472460.714 [BPC1](INFO): Calculating totals. Valid battery stick count: 42. Valid reserve battery stick count: 5.
2024-09-04T17:54:20.717Z,1725472460.717 [BPC1](INFO): Received data from all battery sticks.
2024-09-04T17:56:15.141Z,1725472575.141 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T17:56:15.142Z,1725472575.142 [Default:CheckIn:C.Wait] Stopped
2024-09-04T17:56:15.142Z,1725472575.142 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T17:56:15.142Z,1725472575.142 [Default:CheckIn:D] Running Loop=1
2024-09-04T17:56:15.545Z,1725472575.545 [Default:CheckIn:D] Stopped
2024-09-04T17:56:15.545Z,1725472575.545 [Default:CheckIn:E] Running Loop=1
2024-09-04T17:56:15.963Z,1725472575.963 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.401872 min
2024-09-04T17:56:15.963Z,1725472575.963 [Default:CheckIn:E] Stopped
2024-09-04T17:56:15.963Z,1725472575.963 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T17:56:15.963Z,1725472575.963 [Default:CheckIn] Stopped
2024-09-04T17:56:15.963Z,1725472575.963 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T17:56:15.963Z,1725472575.963 [Default:CheckIn](INFO): Running loop #19
2024-09-04T17:56:15.963Z,1725472575.963 [Default:CheckIn] Running Loop=19
2024-09-04T17:56:15.964Z,1725472575.964 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T17:56:15.964Z,1725472575.964 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T17:56:17.957Z,1725472577.957 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175617.00,A,3648.17182,N,12147.29181,W,0.214,321.81,040924,,,A*7C
2024-09-04T17:56:17.960Z,1725472577.960 [NAL9602](INFO): GPS fix at 20240904T175617: (36.802864, -121.788197)
2024-09-04T17:56:17.978Z,1725472577.978 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T17:56:17.978Z,1725472577.978 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T17:56:28.554Z,1725472588.554 [DataOverHttps](INFO): Sending 84 bytes from file Logs/20240904T151433/Courier0061.lzma
2024-09-04T17:56:29.556Z,1725472589.556 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0061.lzma.bak
2024-09-04T17:56:29.557Z,1725472589.557 [DataOverHttps](INFO): SBD MOMSN=23125366
2024-09-04T17:56:45.414Z,1725472605.414 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20240904T151433/Express0062.lzma
2024-09-04T17:56:46.416Z,1725472606.416 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0062.lzma.bak
2024-09-04T17:56:46.417Z,1725472606.417 [DataOverHttps](INFO): SBD MOMSN=23125372
2024-09-04T17:56:48.325Z,1725472608.325 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T17:56:48.325Z,1725472608.325 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T17:56:48.326Z,1725472608.326 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T17:56:48.712Z,1725472608.712 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T17:56:48.790Z,1725472608.790 [NAL9602](ERROR): received:
+CSQ:0
OK383, 2, 0, 0, 0
OK
2024-09-04T18:01:20.377Z,1725472880.377 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T18:01:49.101Z,1725472909.101 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T18:01:49.101Z,1725472909.101 [Default:CheckIn:C.Wait] Stopped
2024-09-04T18:01:49.101Z,1725472909.101 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T18:01:49.102Z,1725472909.102 [Default:CheckIn:D] Running Loop=1
2024-09-04T18:01:49.494Z,1725472909.494 [Default:CheckIn:D] Stopped
2024-09-04T18:01:49.494Z,1725472909.494 [Default:CheckIn:E] Running Loop=1
2024-09-04T18:01:49.876Z,1725472909.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 146.967692 min
2024-09-04T18:01:49.876Z,1725472909.876 [Default:CheckIn:E] Stopped
2024-09-04T18:01:49.876Z,1725472909.876 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T18:01:49.876Z,1725472909.876 [Default:CheckIn] Stopped
2024-09-04T18:01:49.877Z,1725472909.877 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T18:01:49.877Z,1725472909.877 [Default:CheckIn](INFO): Running loop #20
2024-09-04T18:01:49.877Z,1725472909.877 [Default:CheckIn] Running Loop=20
2024-09-04T18:01:49.877Z,1725472909.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T18:01:49.877Z,1725472909.877 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T18:01:51.893Z,1725472911.893 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180151.00,A,3648.17307,N,12147.27996,W,0.719,321.81,040924,,,A*74
2024-09-04T18:01:51.895Z,1725472911.895 [NAL9602](INFO): GPS fix at 20240904T180151: (36.802884, -121.787999)
2024-09-04T18:01:51.905Z,1725472911.905 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T18:01:51.905Z,1725472911.905 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T18:01:59.262Z,1725472919.262 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0064.lzma
2024-09-04T18:02:00.264Z,1725472920.264 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0064.lzma.bak
2024-09-04T18:02:00.265Z,1725472920.265 [DataOverHttps](INFO): SBD MOMSN=23125447
2024-09-04T18:02:16.518Z,1725472936.518 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20240904T151433/Express0065.lzma
2024-09-04T18:02:17.521Z,1725472937.521 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0065.lzma.bak
2024-09-04T18:02:17.521Z,1725472937.521 [DataOverHttps](INFO): SBD MOMSN=23125450
2024-09-04T18:02:19.381Z,1725472939.381 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T18:02:19.381Z,1725472939.381 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T18:02:19.381Z,1725472939.381 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T18:02:24.693Z,1725472944.693 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T18:05:28.287Z,1725473128.287 [CommandExec](IMPORTANT): got command get depth
2024-09-04T18:05:28.287Z,1725473128.287 [CommandExec](IMPORTANT): depth -0.137740 m
2024-09-04T18:05:34.793Z,1725473134.793 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0 meter
2024-09-04T18:05:34.797Z,1725473134.797 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2024-09-04T18:05:35.101Z,1725473135.101 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,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,Reporter,LogSplitter,
2024-09-04T18:05:36.437Z,1725473136.437 [CommandExec](IMPORTANT): got command get depth
2024-09-04T18:05:36.437Z,1725473136.437 [CommandExec](IMPORTANT): depth 0.000000 m
2024-09-04T18:06:00.396Z,1725473160.396 [DataOverHttps](IMPORTANT): SBD MTMSN=20240904T180559
2024-09-04T18:06:07.786Z,1725473167.786 [DataOverHttps](INFO): Received command: load Insert/SampleAtDepth.tl;set SampleAtDepth.TargetDepth 0 m;run
2024-09-04T18:06:07.860Z,1725473167.860 [CommandExec](IMPORTANT): got command load ./Missions/Insert/SampleAtDepth.tl
2024-09-04T18:06:07.860Z,1725473167.860 [MissionManager](INFO): Loading Mission from file: ./Missions/Insert/SampleAtDepth.tl
2024-09-04T18:06:07.861Z,1725473167.861 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Insert/SampleAtDepth.tl
2024-09-04T18:06:07.862Z,1725473167.862 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Insert/SampleAtDepth.tl
2024-09-04T18:06:08.271Z,1725473168.271 [MissionManager](DEBUG): TethyslAPI: ./Missions/Insert/SampleAtDepth.tl translated into:
5
10
3
0
NaN
3
SampleAtDepth received an invalid target depth. Skipping sample.
Moving to
Timed out trying to reach the targeted depth. Stopping mission.
stop
At
, settling for
Timed out triggering CANONSampler. Stopping mission.
stop
CANONSampler sampling at
in
water with
chlorophyll fluorescence.
Timed out sampling with CANONSampler. Stopping mission.
stop
ESP sampling at
in
water with
chlorophyll fluorescence.
2024-09-04T18:06:08.276Z,1725473168.276 [MissionManager](INFO): DefineArg SampleAtDepth.TargetDepth = 5.000000 m
2024-09-04T18:06:08.278Z,1725473168.278 [MissionManager](INFO): DefineArg SampleAtDepth.SettleTime = 10.000000 s
2024-09-04T18:06:08.280Z,1725473168.280 [MissionManager](INFO): DefineArg SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2024-09-04T18:06:08.283Z,1725473168.283 [MissionManager](INFO): DefineArg SampleAtDepth.RotateOnly = 0.000000 bool
2024-09-04T18:06:08.285Z,1725473168.285 [MissionManager](INFO): DefineArg SampleAtDepth.UseCANONSampler = 1 bool
2024-09-04T18:06:08.287Z,1725473168.287 [MissionManager](INFO): DefineArg SampleAtDepth.UseESP = 0 bool
2024-09-04T18:06:08.289Z,1725473168.289 [MissionManager](INFO): DefineArg SampleAtDepth.ESPCartridgeType = nan count
2024-09-04T18:06:08.292Z,1725473168.292 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTriggerTimeout = 3.000000 min
2024-09-04T18:06:08.294Z,1725473168.294 [MissionManager](INFO): DefineArg SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2024-09-04T18:06:08.345Z,1725473168.345 [SampleAtDepth:sample:ApproachDepth:B.Pitch](DEBUG): Construct.
2024-09-04T18:06:08.375Z,1725473168.375 [SampleAtDepth:sample:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-09-04T18:06:08.378Z,1725473168.378 [SampleAtDepth:sample:SampleWrapper:A.Pitch](DEBUG): Construct.
2024-09-04T18:06:08.401Z,1725473168.401 [SampleAtDepth:sample:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2024-09-04T18:06:08.416Z,1725473168.416 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-09-04T18:06:08.419Z,1725473168.419 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2024-09-04T18:06:08.419Z,1725473168.419 [MissionManager](ERROR): Slate does not contain celsius
2024-09-04T18:06:08.423Z,1725473168.423 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2024-09-04T18:06:08.427Z,1725473168.427 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](DEBUG): Construct.
2024-09-04T18:06:08.440Z,1725473168.440 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
aggregate SampleAtDepth {
"""
Take a water sample at a specified depth.
"""
arguments {
TargetDepth = 5 meter
"""
Depth to sample at. Initialized to 5 m.
"""
SettleTime = 10 second
"""
Time to wait after reaching target depth before triggering sample.
Initialized to 10 minutes.
"""
MaxWaitNotReachingDepth = 3 hour
"""
Maximum wait time the vehicle cannot reach the targeted depth.
Initialized to 3 hours.
"""
RotateOnly = 0 bool
UseCANONSampler = Science:CANONSampler.loadAtStartup
"""
Whether to use CANON Sampler to sample.
"""
UseESP = Science:ESPComponent.loadAtStartup
"""
Whether to use ESP to sample.
"""
ESPCartridgeType = NaN count
"""
Specifies ESP cartridge type code.
"""
CANONSamplerTriggerTimeout = 3 minute
"""
How long to wait for a CANON Sampler sample to start.
"""
CANONSamplerTimeout = Science:CANONSampler.sampleTimeout
"""
How long to wait for a CANON Sampler sample to complete.
"""
}
run when ( called )
aggregate ReportInvalidDepth {
run in sequence
break if ( not ( isNaN ( TargetDepth ) ) )
syslog fault "SampleAtDepth received an invalid target depth. Skipping sample."
}
aggregate sample {
run in sequence
break if ( isNaN ( TargetDepth ) )
aggregate ApproachDepth {
run in sequence
syslog "Moving to " + TargetDepth~meter
behavior Guidance:Pitch {
run in sequence
timeout duration=MaxWaitNotReachingDepth {
syslog important "Timed out trying to reach the targeted depth. Stopping mission."
behavior Guidance:Execute {
run in sequence
set command = "stop"
}
}
set depth = TargetDepth
}
}
aggregate SampleWrapper {
run in sequence
behavior Guidance:Pitch {
run in parallel
set depth = TargetDepth
}
syslog important "At " + Universal:depth~meter + ", settling for " + SettleTime~minute
behavior Guidance:Wait {
run in sequence
set duration = SettleTime
}
aggregate SampleCANONSampler {
run in sequence
break if ( not ( UseCANONSampler ) )
assign in parallel Science:CANONSampler.sampleTimeout = CANONSamplerTimeout
assign in parallel Science:CANONSampler.rotateOnly = RotateOnly
readDatum id="TriggerCANONSampler" {
timeout duration=CANONSamplerTriggerTimeout {
syslog important "Timed out triggering CANONSampler. Stopping mission."
behavior Guidance:Execute {
run in sequence
set command = "stop"
}
}
Science:CANONSampler.sampling
}
syslog important "CANONSampler sampling at " + Universal:depth~meter + " in "
+ Science:CTD_NeilBrown.bin_mean_sea_water_temperature~celsius + " water with "
+ Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water~microgram_per_liter
+ " chlorophyll fluorescence."
readDatum {
timeout duration=CANONSamplerTimeout {
syslog important "Timed out sampling with CANONSampler. Stopping mission."
behavior Guidance:Execute {
run in sequence
set command = "stop"
}
}
Science:CANONSampler.sample_number
}
}
aggregate SampleESP {
run in sequence
break if ( not ( UseESP ) )
aggregate SelectESPCartridge {
run in sequence
break if ( isNaN ( ESPCartridgeType ) )
behavior Science:ESPCartridgeSelect {
run in sequence
timeout duration=P1M
set cartridgeType = ESPCartridgeType
}
}
readDatum id="TriggerESP" {
Science:ESPComponent.sampling
}
syslog important "ESP sampling at " + Universal:depth~meter + " in "
+ Science:CTD_Seabird.bin_mean_sea_water_temperature~celsius + " water with "
+ Science:WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water~microgram_per_liter
+ "chlorophyll fluorescence."
readDatum id="WaitForESP" {
Science:ESPComponent.sample_number
}
}
}
}
}
2024-09-04T18:06:08.441Z,1725473168.441 [CommandExec](IMPORTANT): Loaded ./Missions/Insert/SampleAtDepth.tl id=SampleAtDepth
2024-09-04T18:06:10.299Z,1725473170.299 [CommandExec](IMPORTANT): got command set SampleAtDepth.TargetDepth 0 meter
2024-09-04T18:06:10.300Z,1725473170.300 [CommandExec](IMPORTANT): got command run
2024-09-04T18:06:10.301Z,1725473170.301 [CommandExec](IMPORTANT): Running
2024-09-04T18:06:10.621Z,1725473170.621 [Default] Stopped
2024-09-04T18:06:10.621Z,1725473170.621 [Default](DEBUG): Aggregate::uninitialize Default
2024-09-04T18:06:10.622Z,1725473170.622 [Default:B.GoToSurface] Stopped
2024-09-04T18:06:10.622Z,1725473170.622 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-09-04T18:06:10.622Z,1725473170.622 [Default:CheckIn] Stopped
2024-09-04T18:06:10.622Z,1725473170.622 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T18:06:10.622Z,1725473170.622 [Default:CheckIn:C.Wait] Stopped
2024-09-04T18:06:10.622Z,1725473170.622 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T18:06:10.622Z,1725473170.622 [MissionManager](IMPORTANT): Started mission SampleAtDepth
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth] Running Loop=1
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth](DEBUG): Aggregate::initialize SampleAtDepth
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth:ReportInvalidDepth] Running Loop=1
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth:ReportInvalidDepth](DEBUG): Aggregate::initialize SampleAtDepth:ReportInvalidDepth
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth:ReportInvalidDepth:A] Running Loop=1
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth:ReportInvalidDepth] Stopped
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth:ReportInvalidDepth](DEBUG): Aggregate::uninitialize SampleAtDepth:ReportInvalidDepth
2024-09-04T18:06:10.623Z,1725473170.623 [SampleAtDepth:ReportInvalidDepth:A] Stopped
2024-09-04T18:06:10.624Z,1725473170.624 [SampleAtDepth:sample] Running Loop=1
2024-09-04T18:06:10.624Z,1725473170.624 [SampleAtDepth:sample](DEBUG): Aggregate::initialize SampleAtDepth:sample
2024-09-04T18:06:10.624Z,1725473170.624 [SampleAtDepth:sample:ApproachDepth] Running Loop=1
2024-09-04T18:06:10.624Z,1725473170.624 [SampleAtDepth:sample:ApproachDepth](DEBUG): Aggregate::initialize SampleAtDepth:sample:ApproachDepth
2024-09-04T18:06:10.624Z,1725473170.624 [SampleAtDepth:sample:ApproachDepth:A] Running Loop=1
2024-09-04T18:06:11.027Z,1725473171.027 [SampleAtDepth:sample:ApproachDepth:A](INFO): Moving to 0.000000 m
2024-09-04T18:06:11.027Z,1725473171.027 [SampleAtDepth:sample:ApproachDepth:A] Stopped
2024-09-04T18:06:11.027Z,1725473171.027 [SampleAtDepth:sample:ApproachDepth:B.Pitch] Running Loop=1
2024-09-04T18:06:11.028Z,1725473171.028 [SampleAtDepth:sample:ApproachDepth:B.Pitch](DEBUG): Initialize.
2024-09-04T18:06:11.424Z,1725473171.424 [SampleAtDepth:sample:ApproachDepth:B.Pitch] Stopped
2024-09-04T18:06:11.424Z,1725473171.424 [SampleAtDepth:sample:ApproachDepth](INFO): Completed SampleAtDepth:sample:ApproachDepth
2024-09-04T18:06:11.424Z,1725473171.424 [SampleAtDepth:sample:ApproachDepth] Stopped
2024-09-04T18:06:11.425Z,1725473171.425 [SampleAtDepth:sample:ApproachDepth](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:ApproachDepth
2024-09-04T18:06:11.425Z,1725473171.425 [SampleAtDepth:sample:SampleWrapper] Running Loop=1
2024-09-04T18:06:11.425Z,1725473171.425 [SampleAtDepth:sample:SampleWrapper](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper
2024-09-04T18:06:11.425Z,1725473171.425 [SampleAtDepth:sample:SampleWrapper:A.Pitch] Running Loop=1
2024-09-04T18:06:11.425Z,1725473171.425 [SampleAtDepth:sample:SampleWrapper:A.Pitch](DEBUG): Initialize.
2024-09-04T18:06:11.425Z,1725473171.425 [SampleAtDepth:sample:SampleWrapper:B] Running Loop=1
2024-09-04T18:06:11.834Z,1725473171.834 [SampleAtDepth:sample:SampleWrapper:B](IMPORTANT): At 0.000000 m , settling for 0.166667 min
2024-09-04T18:06:11.834Z,1725473171.834 [SampleAtDepth:sample:SampleWrapper:B] Stopped
2024-09-04T18:06:11.834Z,1725473171.834 [SampleAtDepth:sample:SampleWrapper:C.Wait] Running Loop=1
2024-09-04T18:06:11.834Z,1725473171.834 [SampleAtDepth:sample:SampleWrapper:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T18:06:11.834Z,1725473171.834 [SampleAtDepth:sample:SampleWrapper:A.Pitch] Running Loop=1
2024-09-04T18:06:22.363Z,1725473182.363 [SampleAtDepth:sample:SampleWrapper:C.Wait](INFO): Done Waiting.
2024-09-04T18:06:22.363Z,1725473182.363 [SampleAtDepth:sample:SampleWrapper:C.Wait] Stopped
2024-09-04T18:06:22.363Z,1725473182.363 [SampleAtDepth:sample:SampleWrapper:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T18:06:22.363Z,1725473182.363 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler] Running Loop=1
2024-09-04T18:06:22.364Z,1725473182.364 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper:SampleCANONSampler
2024-09-04T18:06:22.364Z,1725473182.364 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2024-09-04T18:06:22.364Z,1725473182.364 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2024-09-04T18:06:22.364Z,1725473182.364 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2024-09-04T18:06:22.745Z,1725473182.745 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler](DEBUG): Initialize ReadDataComponent to sense CANONSampler.sampling
2024-09-04T18:06:22.746Z,1725473182.746 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2024-09-04T18:06:22.746Z,1725473182.746 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2024-09-04T18:06:23.537Z,1725473183.537 [CANONSampler](INFO): Powering up
2024-09-04T18:07:24.633Z,1725473244.633 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2024-09-04T18:07:24.633Z,1725473244.633 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D] Running Loop=1
2024-09-04T18:07:24.988Z,1725473244.988 [CANONSampler](INFO): CP
2024-09-04T18:07:24.989Z,1725473244.989 [CANONSampler](INFO): 5A1IMAXON 2.1
2024-09-04T18:07:24.989Z,1725473244.989 [CANONSampler](INFO): Last pos=8
2024-09-04T18:07:24.989Z,1725473244.989 [CANONSampler](INFO): S>S
2024-09-04T18:07:24.990Z,1725473244.990 [CANONSampler](INFO): ELMO will go to position 9
2024-09-04T18:07:25.091Z,1725473245.091 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D](ERROR): data element is not active.
2024-09-04T18:07:25.092Z,1725473245.092 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D](IMPORTANT): CANONSampler sampling at 0.000000 m in water with nan ug/l chlorophyll fluorescence.
2024-09-04T18:07:25.092Z,1725473245.092 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:D] Stopped
2024-09-04T18:07:25.092Z,1725473245.092 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E] Running Loop=1
2024-09-04T18:07:25.397Z,1725473245.397 [CANONSampler](INFO): Homing...........................
2024-09-04T18:07:25.407Z,1725473245.407 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E](DEBUG): Initialize ReadDataComponent to sense CANONSampler.sample_number
2024-09-04T18:07:33.891Z,1725473253.891 [CANONSampler](INFO): Pumping for 75 revs........ Pump completed 76 revs + 56 ticks
2024-09-04T18:07:33.891Z,1725473253.891 [CANONSampler](INFO): DONE
2024-09-04T18:07:33.892Z,1725473253.892 [CANONSampler](INFO): Pump ran for 8.00 seconds
2024-09-04T18:07:33.893Z,1725473253.893 [CANONSampler](INFO): Moving to 35100 cnts...............................
2024-09-04T18:07:33.894Z,1725473253.894 [CANONSampler](INFO): Enabling Drive..
2024-09-04T18:07:33.895Z,1725473253.895 [CANONSampler](INFO): Enabling Profile Position Mode..
2024-09-04T18:07:33.895Z,1725473253.895 [CANONSampler](INFO): Moving relative -30436 cnts..
2024-09-04T18:07:33.896Z,1725473253.896 [CANONSampler](INFO): Begin turning....
2024-09-04T18:07:34.281Z,1725473254.281 [CANONSampler](INFO): t = 100, AtTarget = 0, Pos = 104
2024-09-04T18:07:34.281Z,1725473254.281 [CANONSampler](INFO): t = 200, AtTarget = 0, Pos = 265
2024-09-04T18:07:34.692Z,1725473254.692 [CANONSampler](INFO): t = 300, AtTarget = 0, Pos = 426
2024-09-04T18:07:34.692Z,1725473254.692 [CANONSampler](INFO): t = 400, AtTarget = 0, Pos = 587
2024-09-04T18:07:35.099Z,1725473255.099 [CANONSampler](INFO): t = 500, AtTarget = 0, Pos = 747
2024-09-04T18:07:35.100Z,1725473255.100 [CANONSampler](INFO): t = 600, AtTarget = 0, Pos = 908
2024-09-04T18:07:35.518Z,1725473255.518 [CANONSampler](INFO): t = 700, AtTarget = 0, Pos = 1068
2024-09-04T18:07:35.519Z,1725473255.519 [CANONSampler](INFO): t = 800, AtTarget = 0, Pos = 1232
2024-09-04T18:07:35.901Z,1725473255.901 [CANONSampler](INFO): t = 900, AtTarget = 0, Pos = 1396
2024-09-04T18:07:35.901Z,1725473255.901 [CANONSampler](INFO): t = 1000, AtTarget = 0, Pos = 1559
2024-09-04T18:07:36.309Z,1725473256.309 [CANONSampler](INFO): t = 1100, AtTarget = 0, Pos = 1726
2024-09-04T18:07:36.310Z,1725473256.310 [CANONSampler](INFO): t = 1200, AtTarget = 0, Pos = 1893
2024-09-04T18:07:36.709Z,1725473256.709 [CANONSampler](INFO): t = 1300, AtTarget = 0, Pos = 2060
2024-09-04T18:07:36.710Z,1725473256.710 [CANONSampler](INFO): t = 1400, AtTarget = 0, Pos = 2227
2024-09-04T18:07:37.113Z,1725473257.113 [CANONSampler](INFO): t = 1500, AtTarget = 0, Pos = 2394
2024-09-04T18:07:37.113Z,1725473257.113 [CANONSampler](INFO): t = 1600, AtTarget = 0, Pos = 2561
2024-09-04T18:07:37.517Z,1725473257.517 [CANONSampler](INFO): t = 1700, AtTarget = 0, Pos = 2728
2024-09-04T18:07:37.517Z,1725473257.517 [CANONSampler](INFO): t = 1800, AtTarget = 0, Pos = 2895
2024-09-04T18:07:37.921Z,1725473257.921 [CANONSampler](INFO): t = 1900, AtTarget = 0, Pos = 3062
2024-09-04T18:07:38.322Z,1725473258.322 [CANONSampler](INFO): t = 2000, AtTarget = 0, Pos = 3229
2024-09-04T18:07:38.323Z,1725473258.323 [CANONSampler](INFO): t = 2100, AtTarget = 0, Pos = 3396
2024-09-04T18:07:38.730Z,1725473258.730 [CANONSampler](INFO): t = 2200, AtTarget = 0, Pos = 3562
2024-09-04T18:07:38.730Z,1725473258.730 [CANONSampler](INFO): t = 2300, AtTarget = 0, Pos = 3729
2024-09-04T18:07:39.129Z,1725473259.129 [CANONSampler](INFO): t = 2400, AtTarget = 0, Pos = 3896
2024-09-04T18:07:39.130Z,1725473259.130 [CANONSampler](INFO): t = 2500, AtTarget = 0, Pos = 4063
2024-09-04T18:07:39.533Z,1725473259.533 [CANONSampler](INFO): t = 2600, AtTarget = 0, Pos = 4230
2024-09-04T18:07:39.533Z,1725473259.533 [CANONSampler](INFO): t = 2700, AtTarget = 0, Pos = 4397
2024-09-04T18:07:39.941Z,1725473259.941 [CANONSampler](INFO): t = 2800, AtTarget = 0, Pos = 4564
2024-09-04T18:07:39.942Z,1725473259.942 [CANONSampler](INFO): t = 2900, AtTarget = 0, Pos = 4731
2024-09-04T18:07:40.341Z,1725473260.341 [CANONSampler](INFO): t = 3000, AtTarget = 0, Pos = 4898
2024-09-04T18:07:40.342Z,1725473260.342 [CANONSampler](INFO): t = 3100, AtTarget = 0, Pos = 5065
2024-09-04T18:07:40.743Z,1725473260.743 [CANONSampler](INFO): t = 3200, AtTarget = 0, Pos = 5232
2024-09-04T18:07:40.744Z,1725473260.744 [CANONSampler](INFO): t = 3300, AtTarget = 0, Pos = 5399
2024-09-04T18:07:41.149Z,1725473261.149 [CANONSampler](INFO): t = 3400, AtTarget = 0, Pos = 5566
2024-09-04T18:07:41.150Z,1725473261.150 [CANONSampler](INFO): t = 3500, AtTarget = 0, Pos = 5733
2024-09-04T18:07:41.560Z,1725473261.560 [CANONSampler](INFO): t = 3600, AtTarget = 0, Pos = 5900
2024-09-04T18:07:41.561Z,1725473261.561 [CANONSampler](INFO): t = 3700, AtTarget = 0, Pos = 6066
2024-09-04T18:07:41.961Z,1725473261.961 [CANONSampler](INFO): t = 3800, AtTarget = 0, Pos = 6233
2024-09-04T18:07:41.962Z,1725473261.962 [CANONSampler](INFO): t = 3900, AtTarget = 0, Pos = 6401
2024-09-04T18:07:42.361Z,1725473262.361 [CANONSampler](INFO): t = 4000, AtTarget = 0, Pos = 6567
2024-09-04T18:07:42.362Z,1725473262.362 [CANONSampler](INFO): t = 4100, AtTarget = 0, Pos = 6734
2024-09-04T18:07:42.769Z,1725473262.769 [CANONSampler](INFO): t = 4200, AtTarget = 0, Pos = 6901
2024-09-04T18:07:42.770Z,1725473262.770 [CANONSampler](INFO): t = 4300, AtTarget = 0, Pos = 7068
2024-09-04T18:07:43.173Z,1725473263.173 [CANONSampler](INFO): t = 4400, AtTarget = 0, Pos = 7235
2024-09-04T18:07:43.173Z,1725473263.173 [CANONSampler](INFO): t = 4500, AtTarget = 0, Pos = 7402
2024-09-04T18:07:43.573Z,1725473263.573 [CANONSampler](INFO): t = 4600, AtTarget = 0, Pos = 7569
2024-09-04T18:07:43.574Z,1725473263.574 [CANONSampler](INFO): t = 4700, AtTarget = 0, Pos = 7736
2024-09-04T18:07:43.977Z,1725473263.977 [CANONSampler](INFO): t = 4800, AtTarget = 0, Pos = 7903
2024-09-04T18:07:44.385Z,1725473264.385 [CANONSampler](INFO): t = 4900, AtTarget = 0, Pos = 8070
2024-09-04T18:07:44.386Z,1725473264.386 [CANONSampler](INFO): t = 5000, AtTarget = 0, Pos = 8237
2024-09-04T18:07:44.787Z,1725473264.787 [CANONSampler](INFO): t = 5100, AtTarget = 0, Pos = 8404
2024-09-04T18:07:44.788Z,1725473264.788 [CANONSampler](INFO): t = 5200, AtTarget = 0, Pos = 8570
2024-09-04T18:07:45.189Z,1725473265.189 [CANONSampler](INFO): t = 5300, AtTarget = 0, Pos = 8738
2024-09-04T18:07:45.189Z,1725473265.189 [CANONSampler](INFO): t = 5400, AtTarget = 0, Pos = 8905
2024-09-04T18:07:45.591Z,1725473265.591 [CANONSampler](INFO): t = 5500, AtTarget = 0, Pos = 9071
2024-09-04T18:07:45.592Z,1725473265.592 [CANONSampler](INFO): t = 5600, AtTarget = 0, Pos = 9238
2024-09-04T18:07:45.997Z,1725473265.997 [CANONSampler](INFO): t = 5700, AtTarget = 0, Pos = 9405
2024-09-04T18:07:45.998Z,1725473265.998 [CANONSampler](INFO): t = 5800, AtTarget = 0, Pos = 9572
2024-09-04T18:07:46.400Z,1725473266.400 [CANONSampler](INFO): t = 5900, AtTarget = 0, Pos = 9739
2024-09-04T18:07:46.400Z,1725473266.400 [CANONSampler](INFO): t = 6000, AtTarget = 0, Pos = 9906
2024-09-04T18:07:46.804Z,1725473266.804 [CANONSampler](INFO): t = 6100, AtTarget = 0, Pos = 10073
2024-09-04T18:07:46.805Z,1725473266.805 [CANONSampler](INFO): t = 6200, AtTarget = 0, Pos = 10243
2024-09-04T18:07:47.213Z,1725473267.213 [CANONSampler](INFO): t = 6300, AtTarget = 0, Pos = 10413
2024-09-04T18:07:47.214Z,1725473267.214 [CANONSampler](INFO): t = 6400, AtTarget = 0, Pos = 10584
2024-09-04T18:07:47.612Z,1725473267.612 [CANONSampler](INFO): t = 6500, AtTarget = 0, Pos = 10754
2024-09-04T18:07:47.612Z,1725473267.612 [CANONSampler](INFO): t = 6600, AtTarget = 0, Pos = 10924
2024-09-04T18:07:48.016Z,1725473268.016 [CANONSampler](INFO): t = 6700, AtTarget = 0, Pos = 11094
2024-09-04T18:07:48.016Z,1725473268.016 [CANONSampler](INFO): t = 6800, AtTarget = 0, Pos = 11264
2024-09-04T18:07:48.425Z,1725473268.425 [CANONSampler](INFO): t = 6900, AtTarget = 0, Pos = 11434
2024-09-04T18:07:48.426Z,1725473268.426 [CANONSampler](INFO): t = 7000, AtTarget = 0, Pos = 11604
2024-09-04T18:07:48.833Z,1725473268.833 [CANONSampler](INFO): t = 7100, AtTarget = 0, Pos = 11775
2024-09-04T18:07:48.834Z,1725473268.834 [CANONSampler](INFO): t = 7200, AtTarget = 0, Pos = 11944
2024-09-04T18:07:49.232Z,1725473269.232 [CANONSampler](INFO): t = 7300, AtTarget = 0, Pos = 12115
2024-09-04T18:07:49.668Z,1725473269.668 [CANONSampler](INFO): t = 7400, AtTarget = 0, Pos = 12285
2024-09-04T18:07:49.669Z,1725473269.669 [CANONSampler](INFO): t = 7500, AtTarget = 0, Pos = 12455
2024-09-04T18:07:50.041Z,1725473270.041 [CANONSampler](INFO): t = 7600, AtTarget = 0, Pos = 12625
2024-09-04T18:07:50.041Z,1725473270.041 [CANONSampler](INFO): t = 7700, AtTarget = 0, Pos = 12795
2024-09-04T18:07:50.441Z,1725473270.441 [CANONSampler](INFO): t = 7800, AtTarget = 0, Pos = 12965
2024-09-04T18:07:50.441Z,1725473270.441 [CANONSampler](INFO): t = 7900, AtTarget = 0, Pos = 13135
2024-09-04T18:07:50.846Z,1725473270.846 [CANONSampler](INFO): t = 8000, AtTarget = 0, Pos = 13306
2024-09-04T18:07:50.847Z,1725473270.847 [CANONSampler](INFO): t = 8100, AtTarget = 0, Pos = 13476
2024-09-04T18:07:51.249Z,1725473271.249 [CANONSampler](INFO): t = 8200, AtTarget = 0, Pos = 13646
2024-09-04T18:07:51.250Z,1725473271.250 [CANONSampler](INFO): t = 8300, AtTarget = 0, Pos = 13816
2024-09-04T18:07:51.653Z,1725473271.653 [CANONSampler](INFO): t = 8400, AtTarget = 0, Pos = 13986
2024-09-04T18:07:51.654Z,1725473271.654 [CANONSampler](INFO): t = 8500, AtTarget = 0, Pos = 14156
2024-09-04T18:07:52.065Z,1725473272.065 [CANONSampler](INFO): t = 8600, AtTarget = 0, Pos = 14326
2024-09-04T18:07:52.066Z,1725473272.066 [CANONSampler](INFO): t = 8700, AtTarget = 0, Pos = 14497
2024-09-04T18:07:52.470Z,1725473272.470 [CANONSampler](INFO): t = 8800, AtTarget = 0, Pos = 14667
2024-09-04T18:07:52.471Z,1725473272.471 [CANONSampler](INFO): t = 8900, AtTarget = 0, Pos = 14837
2024-09-04T18:07:52.869Z,1725473272.869 [CANONSampler](INFO): t = 9000, AtTarget = 0, Pos = 15007
2024-09-04T18:07:52.869Z,1725473272.869 [CANONSampler](INFO): t = 9100, AtTarget = 0, Pos = 15177
2024-09-04T18:07:53.277Z,1725473273.277 [CANONSampler](INFO): t = 9200, AtTarget = 0, Pos = 15347
2024-09-04T18:07:53.677Z,1725473273.677 [CANONSampler](INFO): t = 9300, AtTarget = 0, Pos = 15517
2024-09-04T18:07:53.678Z,1725473273.678 [CANONSampler](INFO): t = 9400, AtTarget = 0, Pos = 15687
2024-09-04T18:07:54.081Z,1725473274.081 [CANONSampler](INFO): t = 9500, AtTarget = 0, Pos = 15858
2024-09-04T18:07:54.081Z,1725473274.081 [CANONSampler](INFO): t = 9600, AtTarget = 0, Pos = 16028
2024-09-04T18:07:54.480Z,1725473274.480 [CANONSampler](INFO): t = 9700, AtTarget = 0, Pos = 16198
2024-09-04T18:07:54.481Z,1725473274.481 [CANONSampler](INFO): t = 9800, AtTarget = 0, Pos = 16368
2024-09-04T18:07:54.886Z,1725473274.886 [CANONSampler](INFO): t = 9900, AtTarget = 0, Pos = 16538
2024-09-04T18:07:54.887Z,1725473274.887 [CANONSampler](INFO): t = 10000, AtTarget = 0, Pos = 16708
2024-09-04T18:07:55.293Z,1725473275.293 [CANONSampler](INFO): t = 10100, AtTarget = 0, Pos = 16882
2024-09-04T18:07:55.293Z,1725473275.293 [CANONSampler](INFO): t = 10200, AtTarget = 0, Pos = 17056
2024-09-04T18:07:55.692Z,1725473275.692 [CANONSampler](INFO): t = 10300, AtTarget = 0, Pos = 17231
2024-09-04T18:07:55.693Z,1725473275.693 [CANONSampler](INFO): t = 10400, AtTarget = 0, Pos = 17405
2024-09-04T18:07:56.101Z,1725473276.101 [CANONSampler](INFO): t = 10500, AtTarget = 0, Pos = 17579
2024-09-04T18:07:56.102Z,1725473276.102 [CANONSampler](INFO): t = 10600, AtTarget = 0, Pos = 17753
2024-09-04T18:07:56.509Z,1725473276.509 [CANONSampler](INFO): t = 10700, AtTarget = 0, Pos = 17927
2024-09-04T18:07:56.910Z,1725473276.910 [CANONSampler](INFO): t = 10800, AtTarget = 0, Pos = 18101
2024-09-04T18:07:56.936Z,1725473276.936 [CANONSampler](INFO): t = 10900, AtTarget = 0, Pos = 18275
2024-09-04T18:07:57.309Z,1725473277.309 [CANONSampler](INFO): t = 11000, AtTarget = 0, Pos = 18449
2024-09-04T18:07:57.310Z,1725473277.310 [CANONSampler](INFO): t = 11100, AtTarget = 0, Pos = 18624
2024-09-04T18:07:57.711Z,1725473277.711 [CANONSampler](INFO): t = 11200, AtTarget = 0, Pos = 18798
2024-09-04T18:07:57.712Z,1725473277.712 [CANONSampler](INFO): t = 11300, AtTarget = 0, Pos = 18972
2024-09-04T18:07:58.125Z,1725473278.125 [CANONSampler](INFO): t = 11400, AtTarget = 0, Pos = 19146
2024-09-04T18:07:58.126Z,1725473278.126 [CANONSampler](INFO): t = 11500, AtTarget = 0, Pos = 19320
2024-09-04T18:07:58.521Z,1725473278.521 [CANONSampler](INFO): t = 11600, AtTarget = 0, Pos = 19494
2024-09-04T18:07:58.522Z,1725473278.522 [CANONSampler](INFO): t = 11700, AtTarget = 0, Pos = 19668
2024-09-04T18:07:58.933Z,1725473278.933 [CANONSampler](INFO): t = 11800, AtTarget = 0, Pos = 19842
2024-09-04T18:07:58.933Z,1725473278.933 [CANONSampler](INFO): t = 11900, AtTarget = 0, Pos = 20017
2024-09-04T18:07:59.335Z,1725473279.335 [CANONSampler](INFO): t = 12000, AtTarget = 0, Pos = 20191
2024-09-04T18:07:59.738Z,1725473279.738 [CANONSampler](INFO): t = 12100, AtTarget = 0, Pos = 20365
2024-09-04T18:07:59.767Z,1725473279.767 [CANONSampler](INFO): t = 12200, AtTarget = 0, Pos = 20539
2024-09-04T18:08:00.168Z,1725473280.168 [CANONSampler](INFO): t = 12300, AtTarget = 0, Pos = 20713
2024-09-04T18:08:00.168Z,1725473280.168 [CANONSampler](INFO): t = 12400, AtTarget = 0, Pos = 20887
2024-09-04T18:08:00.545Z,1725473280.545 [CANONSampler](INFO): t = 12500, AtTarget = 0, Pos = 21061
2024-09-04T18:08:00.546Z,1725473280.546 [CANONSampler](INFO): t = 12600, AtTarget = 0, Pos = 21235
2024-09-04T18:08:00.949Z,1725473280.949 [CANONSampler](INFO): t = 12700, AtTarget = 0, Pos = 21409
2024-09-04T18:08:00.950Z,1725473280.950 [CANONSampler](INFO): t = 12800, AtTarget = 0, Pos = 21584
2024-09-04T18:08:01.348Z,1725473281.348 [CANONSampler](INFO): t = 12900, AtTarget = 0, Pos = 21758
2024-09-04T18:08:01.349Z,1725473281.349 [CANONSampler](INFO): t = 13000, AtTarget = 0, Pos = 21932
2024-09-04T18:08:01.758Z,1725473281.758 [CANONSampler](INFO): t = 13100, AtTarget = 0, Pos = 22106
2024-09-04T18:08:01.758Z,1725473281.758 [CANONSampler](INFO): t = 13200, AtTarget = 0, Pos = 22280
2024-09-04T18:08:02.167Z,1725473282.167 [CANONSampler](INFO): t = 13300, AtTarget = 0, Pos = 22454
2024-09-04T18:08:02.565Z,1725473282.565 [CANONSampler](INFO): t = 13400, AtTarget = 0, Pos = 22628
2024-09-04T18:08:02.566Z,1725473282.566 [CANONSampler](INFO): t = 13500, AtTarget = 0, Pos = 22802
2024-09-04T18:08:02.969Z,1725473282.969 [CANONSampler](INFO): t = 13600, AtTarget = 0, Pos = 22977
2024-09-04T18:08:02.970Z,1725473282.970 [CANONSampler](INFO): t = 13700, AtTarget = 0, Pos = 23151
2024-09-04T18:08:03.373Z,1725473283.373 [CANONSampler](INFO): t = 13800, AtTarget = 0, Pos = 23325
2024-09-04T18:08:03.374Z,1725473283.374 [CANONSampler](INFO): t = 13900, AtTarget = 0, Pos = 23499
2024-09-04T18:08:03.777Z,1725473283.777 [CANONSampler](INFO): t = 14000, AtTarget = 0, Pos = 23673
2024-09-04T18:08:03.777Z,1725473283.777 [CANONSampler](INFO): t = 14100, AtTarget = 0, Pos = 23847
2024-09-04T18:08:04.176Z,1725473284.176 [CANONSampler](INFO): t = 14200, AtTarget = 0, Pos = 24021
2024-09-04T18:08:04.177Z,1725473284.177 [CANONSampler](INFO): t = 14300, AtTarget = 0, Pos = 24195
2024-09-04T18:08:04.581Z,1725473284.581 [CANONSampler](INFO): t = 14400, AtTarget = 0, Pos = 24370
2024-09-04T18:08:04.582Z,1725473284.582 [CANONSampler](INFO): t = 14500, AtTarget = 0, Pos = 24544
2024-09-04T18:08:04.997Z,1725473284.997 [CANONSampler](INFO): t = 14600, AtTarget = 0, Pos = 24718
2024-09-04T18:08:05.389Z,1725473285.389 [CANONSampler](INFO): t = 14700, AtTarget = 0, Pos = 24892
2024-09-04T18:08:05.390Z,1725473285.390 [CANONSampler](INFO): t = 14800, AtTarget = 0, Pos = 25066
2024-09-04T18:08:05.792Z,1725473285.792 [CANONSampler](INFO): t = 14900, AtTarget = 0, Pos = 25240
2024-09-04T18:08:05.792Z,1725473285.792 [CANONSampler](INFO): t = 15000, AtTarget = 0, Pos = 25414
2024-09-04T18:08:06.245Z,1725473286.245 [CANONSampler](INFO): t = 15100, AtTarget = 0, Pos = 25589
2024-09-04T18:08:06.245Z,1725473286.245 [CANONSampler](INFO): t = 15200, AtTarget = 0, Pos = 25762
2024-09-04T18:08:06.605Z,1725473286.605 [CANONSampler](INFO): t = 15300, AtTarget = 0, Pos = 25937
2024-09-04T18:08:06.606Z,1725473286.606 [CANONSampler](INFO): t = 15400, AtTarget = 0, Pos = 26111
2024-09-04T18:08:07.005Z,1725473287.005 [CANONSampler](INFO): t = 15500, AtTarget = 0, Pos = 26285
2024-09-04T18:08:07.006Z,1725473287.006 [CANONSampler](INFO): t = 15600, AtTarget = 0, Pos = 26459
2024-09-04T18:08:07.409Z,1725473287.409 [CANONSampler](INFO): t = 15700, AtTarget = 0, Pos = 26633
2024-09-04T18:08:07.409Z,1725473287.409 [CANONSampler](INFO): t = 15800, AtTarget = 0, Pos = 26807
2024-09-04T18:08:07.826Z,1725473287.826 [CANONSampler](INFO): t = 15900, AtTarget = 0, Pos = 26981
2024-09-04T18:08:08.221Z,1725473288.221 [CANONSampler](INFO): t = 16000, AtTarget = 0, Pos = 27155
2024-09-04T18:08:08.222Z,1725473288.222 [CANONSampler](INFO): t = 16100, AtTarget = 0, Pos = 27330
2024-09-04T18:08:08.621Z,1725473288.621 [CANONSampler](INFO): t = 16200, AtTarget = 0, Pos = 27504
2024-09-04T18:08:08.621Z,1725473288.621 [CANONSampler](INFO): t = 16300, AtTarget = 0, Pos = 27678
2024-09-04T18:08:09.029Z,1725473289.029 [CANONSampler](INFO): t = 16400, AtTarget = 0, Pos = 27852
2024-09-04T18:08:09.030Z,1725473289.030 [CANONSampler](INFO): t = 16500, AtTarget = 0, Pos = 28026
2024-09-04T18:08:09.429Z,1725473289.429 [CANONSampler](INFO): t = 16600, AtTarget = 0, Pos = 28200
2024-09-04T18:08:09.429Z,1725473289.429 [CANONSampler](INFO): t = 16700, AtTarget = 0, Pos = 28374
2024-09-04T18:08:09.833Z,1725473289.833 [CANONSampler](INFO): t = 16800, AtTarget = 0, Pos = 28548
2024-09-04T18:08:09.833Z,1725473289.833 [CANONSampler](INFO): t = 16900, AtTarget = 0, Pos = 28722
2024-09-04T18:08:10.242Z,1725473290.242 [CANONSampler](INFO): t = 17000, AtTarget = 0, Pos = 28896
2024-09-04T18:08:10.242Z,1725473290.242 [CANONSampler](INFO): t = 17100, AtTarget = 0, Pos = 29070
2024-09-04T18:08:10.652Z,1725473290.652 [CANONSampler](INFO): t = 17200, AtTarget = 0, Pos = 29244
2024-09-04T18:08:11.043Z,1725473291.043 [CANONSampler](INFO): t = 17300, AtTarget = 0, Pos = 29419
2024-09-04T18:08:11.044Z,1725473291.044 [CANONSampler](INFO): t = 17400, AtTarget = 0, Pos = 29593
2024-09-04T18:08:11.453Z,1725473291.453 [CANONSampler](INFO): t = 17500, AtTarget = 0, Pos = 29767
2024-09-04T18:08:11.454Z,1725473291.454 [CANONSampler](INFO): t = 17600, AtTarget = 0, Pos = 29941
2024-09-04T18:08:11.853Z,1725473291.853 [CANONSampler](INFO): t = 17700, AtTarget = 0, Pos = 30115
2024-09-04T18:08:11.853Z,1725473291.853 [CANONSampler](INFO): t = 17800, AtTarget = 0, Pos = 30289
2024-09-04T18:08:12.266Z,1725473292.266 [CANONSampler](INFO): t = 17900, AtTarget = 0, Pos = 30463
2024-09-04T18:08:12.266Z,1725473292.266 [CANONSampler](INFO): t = 18000, AtTarget = 0, Pos = 30637
2024-09-04T18:08:12.665Z,1725473292.665 [CANONSampler](INFO): t = 18100, AtTarget = 0, Pos = 30812
2024-09-04T18:08:12.666Z,1725473292.666 [CANONSampler](INFO): t = 18200, AtTarget = 0, Pos = 30986
2024-09-04T18:08:13.066Z,1725473293.066 [CANONSampler](INFO): t = 18300, AtTarget = 0, Pos = 31160
2024-09-04T18:08:13.067Z,1725473293.067 [CANONSampler](INFO): t = 18400, AtTarget = 0, Pos = 31334
2024-09-04T18:08:13.470Z,1725473293.470 [CANONSampler](INFO): t = 18500, AtTarget = 0, Pos = 31508
2024-09-04T18:08:13.872Z,1725473293.872 [CANONSampler](INFO): t = 18600, AtTarget = 0, Pos = 31682
2024-09-04T18:08:13.873Z,1725473293.873 [CANONSampler](INFO): t = 18700, AtTarget = 0, Pos = 31856
2024-09-04T18:08:14.281Z,1725473294.281 [CANONSampler](INFO): t = 18800, AtTarget = 0, Pos = 32030
2024-09-04T18:08:14.282Z,1725473294.282 [CANONSampler](INFO): t = 18900, AtTarget = 0, Pos = 32204
2024-09-04T18:08:14.681Z,1725473294.681 [CANONSampler](INFO): t = 19000, AtTarget = 0, Pos = 32378
2024-09-04T18:08:14.681Z,1725473294.681 [CANONSampler](INFO): t = 19100, AtTarget = 0, Pos = 32552
2024-09-04T18:08:15.084Z,1725473295.084 [CANONSampler](INFO): t = 19200, AtTarget = 0, Pos = 32726
2024-09-04T18:08:15.085Z,1725473295.085 [CANONSampler](INFO): t = 19300, AtTarget = 0, Pos = -32636
2024-09-04T18:08:15.488Z,1725473295.488 [CANONSampler](INFO): t = 19400, AtTarget = 0, Pos = -32461
2024-09-04T18:08:15.488Z,1725473295.488 [CANONSampler](INFO): t = 19500, AtTarget = 0, Pos = -32287
2024-09-04T18:08:15.901Z,1725473295.901 [CANONSampler](INFO): t = 19600, AtTarget = 0, Pos = -32113
2024-09-04T18:08:15.901Z,1725473295.901 [CANONSampler](INFO): t = 19700, AtTarget = 0, Pos = -31939
2024-09-04T18:08:16.302Z,1725473296.302 [CANONSampler](INFO): t = 19800, AtTarget = 0, Pos = -31765
2024-09-04T18:08:16.701Z,1725473296.701 [CANONSampler](INFO): t = 19900, AtTarget = 0, Pos = -31591
2024-09-04T18:08:16.702Z,1725473296.702 [CANONSampler](INFO): t = 20000, AtTarget = 0, Pos = -31417
2024-09-04T18:08:17.122Z,1725473297.122 [CANONSampler](INFO): t = 20100, AtTarget = 0, Pos = -31243
2024-09-04T18:08:17.123Z,1725473297.123 [CANONSampler](INFO): t = 20200, AtTarget = 0, Pos = -31069
2024-09-04T18:08:17.509Z,1725473297.509 [CANONSampler](INFO): t = 20300, AtTarget = 0, Pos = -30894
2024-09-04T18:08:17.510Z,1725473297.510 [CANONSampler](INFO): t = 20400, AtTarget = 0, Pos = -30720
2024-09-04T18:08:17.913Z,1725473297.913 [CANONSampler](INFO): t = 20500, AtTarget = 0, Pos = -30546
2024-09-04T18:08:17.914Z,1725473297.914 [CANONSampler](INFO): t = 20600, AtTarget = 0, Pos = -30435
2024-09-04T18:08:18.316Z,1725473298.316 [CANONSampler](INFO): t = 20700, AtTarget = 1, Pos = -30433
2024-09-04T18:09:14.475Z,1725473354.475 [CANONSampler](INFO): Pumping for 500 revs........ Pump completed 501 revs + 32 ticks
2024-09-04T18:09:14.475Z,1725473354.475 [CANONSampler](INFO): DONE
2024-09-04T18:09:14.476Z,1725473354.476 [CANONSampler](INFO): Pump ran for 55.00 seconds
2024-09-04T18:09:14.477Z,1725473354.477 [CANONSampler](INFO): Sampling complete, Homing................................
2024-09-04T18:09:14.478Z,1725473354.478 [CANONSampler](INFO): Enabling Drive..
2024-09-04T18:09:14.478Z,1725473354.478 [CANONSampler](INFO): Enabling Profile Position Mode..
2024-09-04T18:09:14.479Z,1725473354.479 [CANONSampler](INFO): Moving relative -1 cnts..
2024-09-04T18:09:14.479Z,1725473354.479 [CANONSampler](INFO): Begin turning....
2024-09-04T18:09:48.409Z,1725473388.409 [CANONSampler](INFO): Enabling Drive..
2024-09-04T18:09:48.410Z,1725473388.410 [CANONSampler](INFO): Enabling Profile Position Mode..
2024-09-04T18:09:48.410Z,1725473388.410 [CANONSampler](INFO): Moving relative 800 cnts..
2024-09-04T18:09:48.411Z,1725473388.411 [CANONSampler](INFO): Begin turning....
2024-09-04T18:09:50.434Z,1725473390.434 [CANONSampler](INFO): Sample 9, (err_code=0)
2024-09-04T18:09:50.434Z,1725473390.434 [CANONSampler](IMPORTANT): Sample 9, (err_code=0)
2024-09-04T18:09:50.452Z,1725473390.452 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:E] Stopped
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler](INFO): Completed SampleAtDepth:sample:SampleWrapper:SampleCANONSampler
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler] Stopped
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper:SampleCANONSampler
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:A] Stopped
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleCANONSampler:B] Stopped
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleESP] Running Loop=1
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper:SampleESP
2024-09-04T18:09:50.453Z,1725473390.453 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge] Running Loop=1
2024-09-04T18:09:50.454Z,1725473390.454 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge](DEBUG): Aggregate::initialize SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge
2024-09-04T18:09:50.454Z,1725473390.454 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect] Running Loop=1
2024-09-04T18:09:50.454Z,1725473390.454 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.
2024-09-04T18:09:50.869Z,1725473390.869 [SampleAtDepth:sample:SampleWrapper:SampleESP] Stopped
2024-09-04T18:09:50.869Z,1725473390.869 [SampleAtDepth:sample:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper:SampleESP
2024-09-04T18:09:50.869Z,1725473390.869 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge] Stopped
2024-09-04T18:09:50.869Z,1725473390.869 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge
2024-09-04T18:09:50.870Z,1725473390.870 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect] Stopped
2024-09-04T18:09:50.870Z,1725473390.870 [SampleAtDepth:sample:SampleWrapper:SampleESP:SelectESPCartridge:A.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.
2024-09-04T18:09:50.870Z,1725473390.870 [SampleAtDepth:sample:SampleWrapper](INFO): Completed SampleAtDepth:sample:SampleWrapper
2024-09-04T18:09:50.870Z,1725473390.870 [SampleAtDepth:sample:SampleWrapper] Stopped
2024-09-04T18:09:50.870Z,1725473390.870 [SampleAtDepth:sample:SampleWrapper](DEBUG): Aggregate::uninitialize SampleAtDepth:sample:SampleWrapper
2024-09-04T18:09:50.871Z,1725473390.871 [SampleAtDepth:sample:SampleWrapper:A.Pitch] Stopped
2024-09-04T18:09:50.871Z,1725473390.871 [SampleAtDepth:sample](INFO): Completed SampleAtDepth:sample
2024-09-04T18:09:50.871Z,1725473390.871 [SampleAtDepth:sample] Stopped
2024-09-04T18:09:50.871Z,1725473390.871 [SampleAtDepth:sample](DEBUG): Aggregate::uninitialize SampleAtDepth:sample
2024-09-04T18:09:50.871Z,1725473390.871 [SampleAtDepth](INFO): Completed SampleAtDepth
2024-09-04T18:09:50.871Z,1725473390.871 [MissionManager](INFO): SampleAtDepth is completed.
2024-09-04T18:09:50.871Z,1725473390.871 [MissionManager](INFO): Uninitializing Mission SampleAtDepth
2024-09-04T18:09:50.871Z,1725473390.871 [SampleAtDepth] Stopped
2024-09-04T18:09:50.871Z,1725473390.871 [SampleAtDepth](DEBUG): Aggregate::uninitialize SampleAtDepth
2024-09-04T18:09:51.236Z,1725473391.236 [CANONSampler](INFO): Powering down
2024-09-04T18:09:51.347Z,1725473391.347 [MissionManager](IMPORTANT): Started mission Default
2024-09-04T18:09:51.347Z,1725473391.347 [Default] Running Loop=1
2024-09-04T18:09:51.347Z,1725473391.347 [Default](DEBUG): Aggregate::initialize Default
2024-09-04T18:09:51.348Z,1725473391.348 [Default:B.GoToSurface] Running Loop=1
2024-09-04T18:09:51.348Z,1725473391.348 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-09-04T18:09:51.348Z,1725473391.348 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-09-04T18:09:51.348Z,1725473391.348 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-09-04T18:09:51.348Z,1725473391.348 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-09-04T18:09:51.349Z,1725473391.349 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-09-04T18:09:51.349Z,1725473391.349 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-09-04T18:09:51.349Z,1725473391.349 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-09-04T18:09:51.350Z,1725473391.350 [Default:A.Wait] Running Loop=1
2024-09-04T18:09:51.350Z,1725473391.350 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-09-04T18:10:04.582Z,1725473404.582 [Default:A.Wait](INFO): Done Waiting.
2024-09-04T18:10:04.582Z,1725473404.582 [Default:A.Wait] Stopped
2024-09-04T18:10:04.582Z,1725473404.582 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T18:10:04.982Z,1725473404.982 [Default:CheckIn] Running Loop=1
2024-09-04T18:10:04.982Z,1725473404.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T18:10:04.982Z,1725473404.982 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T18:10:06.992Z,1725473406.992 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181006.00,A,3648.16858,N,12147.27978,W,0.194,0.00,040924,,,A*7C
2024-09-04T18:10:06.995Z,1725473406.995 [NAL9602](INFO): GPS fix at 20240904T181006: (36.802810, -121.787996)
2024-09-04T18:10:07.029Z,1725473407.029 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T18:10:07.029Z,1725473407.029 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T18:10:13.531Z,1725473413.531 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0067.lzma
2024-09-04T18:10:14.532Z,1725473414.532 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0067.lzma.bak
2024-09-04T18:10:14.533Z,1725473414.533 [DataOverHttps](INFO): SBD MOMSN=23125469
2024-09-04T18:10:35.340Z,1725473435.340 [DataOverHttps](INFO): Sending 647 bytes from file Logs/20240904T151433/Express0068.lzma
2024-09-04T18:10:36.340Z,1725473436.340 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0068.lzma.bak
2024-09-04T18:10:36.341Z,1725473436.341 [DataOverHttps](INFO): SBD MOMSN=23125472
2024-09-04T18:10:56.555Z,1725473456.555 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20240904T151433/Express0071.lzma
2024-09-04T18:10:57.557Z,1725473457.557 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0071.lzma.bak
2024-09-04T18:10:57.557Z,1725473457.557 [DataOverHttps](INFO): SBD MOMSN=23125490
2024-09-04T18:10:59.691Z,1725473459.691 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T18:10:59.692Z,1725473459.692 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T18:10:59.692Z,1725473459.692 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T18:15:09.140Z,1725473709.140 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T18:15:39.844Z,1725473739.844 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T18:16:00.085Z,1725473760.085 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T18:16:00.085Z,1725473760.085 [Default:CheckIn:C.Wait] Stopped
2024-09-04T18:16:00.085Z,1725473760.085 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T18:16:00.085Z,1725473760.085 [Default:CheckIn:D] Running Loop=1
2024-09-04T18:16:00.500Z,1725473760.500 [Default:CheckIn:D] Stopped
2024-09-04T18:16:00.501Z,1725473760.501 [Default:CheckIn:E] Running Loop=1
2024-09-04T18:16:00.885Z,1725473760.885 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.152550 min
2024-09-04T18:16:00.885Z,1725473760.885 [Default:CheckIn:E] Stopped
2024-09-04T18:16:00.886Z,1725473760.886 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T18:16:00.886Z,1725473760.886 [Default:CheckIn] Stopped
2024-09-04T18:16:00.886Z,1725473760.886 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T18:16:00.886Z,1725473760.886 [Default:CheckIn](INFO): Running loop #2
2024-09-04T18:16:00.886Z,1725473760.886 [Default:CheckIn] Running Loop=2
2024-09-04T18:16:00.886Z,1725473760.886 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T18:16:00.886Z,1725473760.886 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T18:16:02.893Z,1725473762.893 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181602.00,A,3648.16910,N,12147.28535,W,0.175,317.19,040924,,,A*7B
2024-09-04T18:16:02.904Z,1725473762.904 [NAL9602](INFO): GPS fix at 20240904T181602: (36.802818, -121.788089)
2024-09-04T18:16:02.918Z,1725473762.918 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T18:16:02.918Z,1725473762.918 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T18:16:10.643Z,1725473770.643 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0073.lzma
2024-09-04T18:16:11.644Z,1725473771.644 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0073.lzma.bak
2024-09-04T18:16:11.645Z,1725473771.645 [DataOverHttps](INFO): SBD MOMSN=23125511
2024-09-04T18:16:31.698Z,1725473791.698 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20240904T151433/Express0074.lzma
2024-09-04T18:16:32.701Z,1725473792.701 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0074.lzma.bak
2024-09-04T18:16:32.701Z,1725473792.701 [DataOverHttps](INFO): SBD MOMSN=23125514
2024-09-04T18:16:33.632Z,1725473793.632 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T18:16:33.723Z,1725473793.723 [NAL9602](ERROR): received:
+CSQ:0
OK383, 2, 0, 0, 0
OK
2024-09-04T18:16:34.467Z,1725473794.467 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T18:16:34.467Z,1725473794.467 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T18:16:34.467Z,1725473794.467 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T18:17:19.288Z,1725473839.288 [NAL9602](INFO): SBD MO Status=2, MOMSN=56383, MT Status=2, MTMSN=0
2024-09-04T18:17:19.288Z,1725473839.288 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-09-04T18:21:05.527Z,1725474065.527 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T18:21:35.033Z,1725474095.033 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T18:21:35.033Z,1725474095.033 [Default:CheckIn:C.Wait] Stopped
2024-09-04T18:21:35.033Z,1725474095.033 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T18:21:35.033Z,1725474095.033 [Default:CheckIn:D] Running Loop=1
2024-09-04T18:21:35.439Z,1725474095.439 [Default:CheckIn:D] Stopped
2024-09-04T18:21:35.439Z,1725474095.439 [Default:CheckIn:E] Running Loop=1
2024-09-04T18:21:35.855Z,1725474095.855 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.734864 min
2024-09-04T18:21:35.855Z,1725474095.855 [Default:CheckIn:E] Stopped
2024-09-04T18:21:35.855Z,1725474095.855 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T18:21:35.856Z,1725474095.856 [Default:CheckIn] Stopped
2024-09-04T18:21:35.856Z,1725474095.856 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T18:21:35.856Z,1725474095.856 [Default:CheckIn](INFO): Running loop #3
2024-09-04T18:21:35.856Z,1725474095.856 [Default:CheckIn] Running Loop=3
2024-09-04T18:21:35.856Z,1725474095.856 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T18:21:35.856Z,1725474095.856 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T18:21:36.232Z,1725474096.232 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T18:21:37.849Z,1725474097.849 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182137.00,A,3648.16175,N,12147.28465,W,0.389,317.19,040924,,,A*77
2024-09-04T18:21:37.851Z,1725474097.851 [NAL9602](INFO): GPS fix at 20240904T182137: (36.802696, -121.788077)
2024-09-04T18:21:37.863Z,1725474097.863 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T18:21:37.863Z,1725474097.863 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T18:21:45.138Z,1725474105.138 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0076.lzma
2024-09-04T18:21:46.140Z,1725474106.140 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0076.lzma.bak
2024-09-04T18:21:46.141Z,1725474106.141 [DataOverHttps](INFO): SBD MOMSN=23125525
2024-09-04T18:22:02.794Z,1725474122.794 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20240904T151433/Express0077.lzma
2024-09-04T18:22:03.797Z,1725474123.797 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0077.lzma.bak
2024-09-04T18:22:03.797Z,1725474123.797 [DataOverHttps](INFO): SBD MOMSN=23125528
2024-09-04T18:22:05.365Z,1725474125.365 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T18:22:05.365Z,1725474125.365 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T18:22:05.365Z,1725474125.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T18:22:08.556Z,1725474128.556 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-09-04T18:22:08.636Z,1725474128.636 [NAL9602](ERROR): received:
+CSQ:0
OK383, 2, 0, 0, 0
OK
2024-09-04T18:26:40.448Z,1725474400.448 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-09-04T18:27:05.923Z,1725474425.923 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-09-04T18:27:05.923Z,1725474425.923 [Default:CheckIn:C.Wait] Stopped
2024-09-04T18:27:05.923Z,1725474425.923 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-09-04T18:27:05.923Z,1725474425.923 [Default:CheckIn:D] Running Loop=1
2024-09-04T18:27:06.317Z,1725474426.317 [Default:CheckIn:D] Stopped
2024-09-04T18:27:06.317Z,1725474426.317 [Default:CheckIn:E] Running Loop=1
2024-09-04T18:27:06.717Z,1725474426.717 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.249495 min
2024-09-04T18:27:06.717Z,1725474426.717 [Default:CheckIn:E] Stopped
2024-09-04T18:27:06.717Z,1725474426.717 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-09-04T18:27:06.717Z,1725474426.717 [Default:CheckIn] Stopped
2024-09-04T18:27:06.717Z,1725474426.717 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-09-04T18:27:06.717Z,1725474426.717 [Default:CheckIn](INFO): Running loop #4
2024-09-04T18:27:06.718Z,1725474426.718 [Default:CheckIn] Running Loop=4
2024-09-04T18:27:06.718Z,1725474426.718 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-09-04T18:27:06.718Z,1725474426.718 [Default:CheckIn:Read_GPS] Running Loop=1
2024-09-04T18:27:08.737Z,1725474428.737 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182708.00,A,3648.16235,N,12147.28322,W,0.214,317.19,040924,,,A*7B
2024-09-04T18:27:08.739Z,1725474428.739 [NAL9602](INFO): GPS fix at 20240904T182708: (36.802706, -121.788054)
2024-09-04T18:27:08.749Z,1725474428.749 [Default:CheckIn:Read_GPS] Stopped
2024-09-04T18:27:08.750Z,1725474428.750 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-09-04T18:27:16.270Z,1725474436.270 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20240904T151433/Courier0079.lzma
2024-09-04T18:27:17.281Z,1725474437.281 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Courier0079.lzma.bak
2024-09-04T18:27:17.281Z,1725474437.281 [DataOverHttps](INFO): SBD MOMSN=23125550
2024-09-04T18:27:34.195Z,1725474454.195 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20240904T151433/Express0080.lzma
2024-09-04T18:27:35.196Z,1725474455.196 [DataOverHttps](INFO): Moved sent file to Logs/20240904T151433/Express0080.lzma.bak
2024-09-04T18:27:35.197Z,1725474455.197 [DataOverHttps](INFO): SBD MOMSN=23125553
2024-09-04T18:27:36.625Z,1725474456.625 [Default:CheckIn:Read_Iridium] Stopped
2024-09-04T18:27:36.625Z,1725474456.625 [Default:CheckIn:C.Wait] Running Loop=1
2024-09-04T18:27:36.626Z,1725474456.626 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-09-04T18:27:41.455Z,1725474461.455 [NAL9602](INFO): Not Powering down - fast GPS
2024-09-04T18:28:22.285Z,1725474502.285 [CommandExec](IMPORTANT): got command restart system
2024-09-04T18:28:24.371Z,1725474504.371 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2024-09-04T18:28:24.371Z,1725474504.371 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-04T18:28:24.372Z,1725474504.372 [CommandExec](INFO): Uninitializing the command executive.
2024-09-04T18:28:24.372Z,1725474504.372 [CommandExec](INFO): Uninitializing the command scheduler.
2024-09-04T18:28:24.372Z,1725474504.372 [CommandExec ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:24.567Z,1725474504.567 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2024-09-04T18:28:24.567Z,1725474504.567 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2024-09-04T18:28:24.567Z,1725474504.567 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:24.568Z,1725474504.568 [NavChartDb](INFO): Join timeout helper Thread ID is 7044
2024-09-04T18:28:24.884Z,1725474504.884 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-04T18:28:24.884Z,1725474504.884 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:24.894Z,1725474504.894 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2024-09-04T18:28:24.895Z,1725474504.895 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:24.895Z,1725474504.895 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7045
2024-09-04T18:28:25.255Z,1725474505.255 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-04T18:28:25.255Z,1725474505.255 [WetLabsBB2FL](INFO): Powering down
2024-09-04T18:28:25.256Z,1725474505.256 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:25.270Z,1725474505.270 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2024-09-04T18:28:25.271Z,1725474505.271 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:25.271Z,1725474505.271 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7046
2024-09-04T18:28:25.992Z,1725474505.992 [CTD_Seabird](INFO): Powering down
2024-09-04T18:28:26.006Z,1725474506.006 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2024-09-04T18:28:26.007Z,1725474506.007 [CTD_Seabird](INFO): Powering down
2024-09-04T18:28:26.018Z,1725474506.018 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:26.026Z,1725474506.026 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2024-09-04T18:28:26.026Z,1725474506.026 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2024-09-04T18:28:26.027Z,1725474506.027 [Radio_Surface](INFO): Join timeout helper Thread ID is 7047
2024-09-04T18:28:26.095Z,1725474506.095 [Radio_Surface](INFO): Powering down
2024-09-04T18:28:26.096Z,1725474506.096 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller threa