2024-12-16T16:32:46.221Z,1734366766.221 [Supervisor](DEBUG): Initializing supervisor.
2024-12-16T16:32:46.225Z,1734366766.225 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-12-16T16:32:46.226Z,1734366766.226 [SyncHandler](INFO): Protected caller Thread ID is 836
2024-12-16T16:32:46.226Z,1734366766.226 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-12-16T16:32:46.227Z,1734366766.227 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-12-16T16:32:46.227Z,1734366766.227 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837
2024-12-16T16:32:46.231Z,1734366766.231 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-12-16T16:32:46.249Z,1734366766.249 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-12-16T16:32:46.250Z,1734366766.250 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-12-16T16:32:46.251Z,1734366766.251 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838
2024-12-16T16:32:46.255Z,1734366766.255 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-12-16T16:32:46.256Z,1734366766.256 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-12-16T16:32:46.256Z,1734366766.256 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839
2024-12-16T16:32:46.259Z,1734366766.259 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-12-16T16:32:46.260Z,1734366766.260 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-12-16T16:32:46.260Z,1734366766.260 [logger ThreadHandler](INFO): Protected caller Thread ID is 840
2024-12-16T16:32:46.264Z,1734366766.264 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-12-16T16:32:46.264Z,1734366766.264 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-12-16T16:32:46.268Z,1734366766.268 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-12-16T16:32:46.542Z,1734366766.542 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-12-16T16:32:46.544Z,1734366766.544 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-12-16T16:32:46.635Z,1734366766.635 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-12-16T16:32:47.160Z,1734366767.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-12-16T16:32:47.161Z,1734366767.161 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-12-16T16:32:47.601Z,1734366767.601 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-12-16T16:32:47.603Z,1734366767.603 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-12-16T16:32:47.709Z,1734366767.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-12-16T16:32:47.711Z,1734366767.711 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-12-16T16:32:48.155Z,1734366768.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-12-16T16:32:48.155Z,1734366768.155 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-12-16T16:32:48.379Z,1734366768.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-12-16T16:32:48.381Z,1734366768.381 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-12-16T16:32:48.910Z,1734366768.910 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-12-16T16:32:49.300Z,1734366769.300 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-12-16T16:32:49.551Z,1734366769.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-12-16T16:32:49.554Z,1734366769.554 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-12-16T16:32:49.645Z,1734366769.645 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-12-16T16:32:50.480Z,1734366770.480 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-12-16T16:32:50.481Z,1734366770.481 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-12-16T16:32:50.869Z,1734366770.869 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-12-16T16:32:50.871Z,1734366770.871 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-12-16T16:32:51.062Z,1734366771.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-12-16T16:32:51.063Z,1734366771.063 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-12-16T16:32:51.228Z,1734366771.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-12-16T16:32:51.229Z,1734366771.229 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-12-16T16:32:51.463Z,1734366771.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-12-16T16:32:51.464Z,1734366771.464 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-12-16T16:32:51.720Z,1734366771.720 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-12-16T16:32:51.722Z,1734366771.722 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2024-12-16T16:32:51.726Z,1734366771.726 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2024-12-16T16:32:51.821Z,1734366771.821 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2024-12-16T16:32:51.934Z,1734366771.934 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2024-12-16T16:32:52.028Z,1734366772.028 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2024-12-16T16:32:52.141Z,1734366772.141 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2024-12-16T16:32:52.244Z,1734366772.244 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2024-12-16T16:32:52.371Z,1734366772.371 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2024-12-16T16:32:52.540Z,1734366772.540 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2024-12-16T16:32:52.703Z,1734366772.703 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2024-12-16T16:32:52.827Z,1734366772.827 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2024-12-16T16:32:53.106Z,1734366773.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-12-16T16:32:53.107Z,1734366773.107 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2024-12-16T16:32:53.108Z,1734366773.108 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2024-12-16T16:32:53.121Z,1734366773.121 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-12-16T16:32:53.196Z,1734366773.196 [VerticalControl](DEBUG): Construct VerticalControl.
2024-12-16T16:32:53.258Z,1734366773.258 [VerticalControl] Loaded
2024-12-16T16:32:53.258Z,1734366773.258 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-12-16T16:32:53.261Z,1734366773.261 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-12-16T16:32:53.309Z,1734366773.309 [HorizontalControl] Loaded
2024-12-16T16:32:53.309Z,1734366773.309 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-12-16T16:32:53.312Z,1734366773.312 [SpeedControl](DEBUG): Construct SpeedControl.
2024-12-16T16:32:53.315Z,1734366773.315 [SpeedControl] Loaded
2024-12-16T16:32:53.315Z,1734366773.315 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-12-16T16:32:53.318Z,1734366773.318 [LoopControl](DEBUG): Construct LoopControl.
2024-12-16T16:32:53.318Z,1734366773.318 [LoopControl] Loaded
2024-12-16T16:32:53.319Z,1734366773.319 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-12-16T16:32:53.319Z,1734366773.319 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-12-16T16:32:53.321Z,1734366773.321 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-12-16T16:32:53.336Z,1734366773.336 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-12-16T16:32:53.337Z,1734366773.337 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-12-16T16:32:53.550Z,1734366773.550 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-12-16T16:32:53.551Z,1734366773.551 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-12-16T16:32:53.737Z,1734366773.737 [BuoyancyServo] Loaded
2024-12-16T16:32:53.737Z,1734366773.737 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-12-16T16:32:53.759Z,1734366773.759 [ElevatorServo] Loaded
2024-12-16T16:32:53.759Z,1734366773.759 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-12-16T16:32:53.780Z,1734366773.780 [MassServo] Loaded
2024-12-16T16:32:53.781Z,1734366773.781 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-12-16T16:32:53.802Z,1734366773.802 [RudderServo] Loaded
2024-12-16T16:32:53.802Z,1734366773.802 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-12-16T16:32:53.819Z,1734366773.819 [ThrusterHE] Loaded
2024-12-16T16:32:53.819Z,1734366773.819 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-12-16T16:32:53.819Z,1734366773.819 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-12-16T16:32:53.820Z,1734366773.820 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-12-16T16:32:53.960Z,1734366773.960 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-12-16T16:32:53.960Z,1734366773.960 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-12-16T16:32:53.974Z,1734366773.974 [NavChart] Loaded
2024-12-16T16:32:53.974Z,1734366773.974 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-12-16T16:32:53.980Z,1734366773.980 [UniversalFixResidualReporter] Loaded
2024-12-16T16:32:53.980Z,1734366773.980 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-12-16T16:32:53.981Z,1734366773.981 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-12-16T16:32:53.981Z,1734366773.981 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-12-16T16:32:54.142Z,1734366774.142 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-12-16T16:32:54.142Z,1734366774.142 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-12-16T16:32:55.794Z,1734366775.794 [AHRS_M2] Loaded
2024-12-16T16:32:55.794Z,1734366775.794 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-12-16T16:32:56.628Z,1734366776.628 [BPC1] Loaded
2024-12-16T16:32:56.628Z,1734366776.628 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-12-16T16:32:56.768Z,1734366776.768 [DataOverHttps] Loaded
2024-12-16T16:32:56.768Z,1734366776.768 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-12-16T16:32:56.769Z,1734366776.769 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2024-12-16T16:32:56.769Z,1734366776.769 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 921
2024-12-16T16:32:56.792Z,1734366776.792 [Depth_Keller] Loaded
2024-12-16T16:32:56.793Z,1734366776.793 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2024-12-16T16:32:56.798Z,1734366776.798 [DropWeight] Loaded
2024-12-16T16:32:56.798Z,1734366776.798 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2024-12-16T16:32:56.862Z,1734366776.862 [NAL9602] Loaded
2024-12-16T16:32:56.863Z,1734366776.863 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-12-16T16:32:56.892Z,1734366776.892 [Onboard] Loaded
2024-12-16T16:32:56.893Z,1734366776.893 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-12-16T16:32:56.894Z,1734366776.894 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2024-12-16T16:32:56.894Z,1734366776.894 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922
2024-12-16T16:32:56.910Z,1734366776.910 [Power24vConverter] Loaded
2024-12-16T16:32:56.910Z,1734366776.910 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-12-16T16:32:56.926Z,1734366776.926 [Radio_Surface] Loaded
2024-12-16T16:32:56.926Z,1734366776.926 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-12-16T16:32:56.927Z,1734366776.927 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0
2024-12-16T16:32:56.927Z,1734366776.927 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923
2024-12-16T16:32:56.943Z,1734366776.943 [Sonardyne_Nano] Loaded
2024-12-16T16:32:56.943Z,1734366776.943 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2024-12-16T16:32:56.943Z,1734366776.943 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-12-16T16:32:56.944Z,1734366776.944 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-12-16T16:32:57.018Z,1734366777.018 [DepthRateCalculator] Loaded
2024-12-16T16:32:57.018Z,1734366777.018 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-12-16T16:32:57.023Z,1734366777.023 [PitchRateCalculator] Loaded
2024-12-16T16:32:57.023Z,1734366777.023 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-12-16T16:32:57.032Z,1734366777.032 [SpeedCalculator] Loaded
2024-12-16T16:32:57.033Z,1734366777.033 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-12-16T16:32:57.037Z,1734366777.037 [YawRateCalculator] Loaded
2024-12-16T16:32:57.037Z,1734366777.037 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-12-16T16:32:57.057Z,1734366777.057 [ElevatorOffsetCalculator] Loaded
2024-12-16T16:32:57.057Z,1734366777.057 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-12-16T16:32:57.058Z,1734366777.058 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-12-16T16:32:57.058Z,1734366777.058 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-12-16T16:32:57.249Z,1734366777.249 [CANONSampler] Loaded
2024-12-16T16:32:57.249Z,1734366777.249 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2024-12-16T16:32:57.312Z,1734366777.312 [CTD_Seabird] Loaded
2024-12-16T16:32:57.313Z,1734366777.313 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-12-16T16:32:57.314Z,1734366777.314 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A614E0
2024-12-16T16:32:57.314Z,1734366777.314 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 924
2024-12-16T16:32:57.337Z,1734366777.337 [PAR_Licor] Loaded
2024-12-16T16:32:57.338Z,1734366777.338 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-12-16T16:32:57.383Z,1734366777.383 [WetLabsBB2FL] Loaded
2024-12-16T16:32:57.384Z,1734366777.384 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-12-16T16:32:57.385Z,1734366777.385 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A914E0
2024-12-16T16:32:57.385Z,1734366777.385 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 925
2024-12-16T16:32:57.386Z,1734366777.386 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-12-16T16:32:57.387Z,1734366777.387 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-12-16T16:32:57.429Z,1734366777.429 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-12-16T16:32:57.430Z,1734366777.430 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-12-16T16:32:57.833Z,1734366777.833 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-12-16T16:32:57.835Z,1734366777.835 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-12-16T16:32:58.176Z,1734366778.176 [SBIT](DEBUG): Construct Startup Built In Test.
2024-12-16T16:32:58.186Z,1734366778.186 [SBIT] Loaded
2024-12-16T16:32:58.186Z,1734366778.186 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-12-16T16:32:58.189Z,1734366778.189 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-12-16T16:32:58.201Z,1734366778.201 [IBIT] Loaded
2024-12-16T16:32:58.202Z,1734366778.202 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-12-16T16:32:58.208Z,1734366778.208 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-12-16T16:32:58.378Z,1734366778.378 [CBIT] Loaded
2024-12-16T16:32:58.379Z,1734366778.379 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-12-16T16:32:58.379Z,1734366778.379 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-12-16T16:32:58.380Z,1734366778.380 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-12-16T16:32:58.911Z,1734366778.911 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-12-16T16:32:58.917Z,1734366778.917 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-12-16T16:32:58.920Z,1734366778.920 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-12-16T16:32:58.932Z,1734366778.932 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-12-16T16:32:58.933Z,1734366778.933 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BF04E0
2024-12-16T16:32:58.933Z,1734366778.933 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 926
2024-12-16T16:32:58.938Z,1734366778.938 [Supervisor](INFO): Main Thread ID is 829
2024-12-16T16:32:58.938Z,1734366778.938 [Supervisor](DEBUG): Running supervisor.
2024-12-16T16:32:58.938Z,1734366778.938 [CommandExec ThreadHandler](INFO): Handler Thread ID is 927
2024-12-16T16:32:58.939Z,1734366778.939 [CommandExec](INFO): Initializing the command executive.
2024-12-16T16:32:58.940Z,1734366778.940 [CommandLine ThreadHandler](INFO): Handler Thread ID is 928
2024-12-16T16:32:58.943Z,1734366778.943 [controlThread ThreadHandler](INFO): Handler Thread ID is 929
2024-12-16T16:32:58.943Z,1734366778.943 [controlThread](DEBUG): Initializing ControlThread
2024-12-16T16:32:58.944Z,1734366778.944 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-12-16T16:32:58.946Z,1734366778.946 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-12-16T16:32:58.947Z,1734366778.947 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-12-16T16:32:58.947Z,1734366778.947 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-12-16T16:32:58.949Z,1734366778.949 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-12-16T16:32:58.949Z,1734366778.949 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-12-16T16:32:58.955Z,1734366778.955 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-12-16T16:32:58.955Z,1734366778.955 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-12-16T16:32:58.956Z,1734366778.956 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-12-16T16:32:58.956Z,1734366778.956 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-12-16T16:32:58.956Z,1734366778.956 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-12-16T16:32:58.961Z,1734366778.961 [SBIT](INFO): Initialize SBIT Component.
2024-12-16T16:32:58.962Z,1734366778.962 [SBIT](IMPORTANT): git: 2024-12-16_A
2024-12-16T16:32:58.962Z,1734366778.962 [SBIT](INFO): git hash: a38fa438d441bb7a1ccbf8550a844b4104921e5e
2024-12-16T16:32:58.962Z,1734366778.962 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-12-16T16:32:58.963Z,1734366778.963 [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-12-16T16:32:58.964Z,1734366778.964 [SBIT](INFO): Beginning SBIT in 60.000000 seconds.
2024-12-16T16:32:58.966Z,1734366778.966 [logger ThreadHandler](INFO): Handler Thread ID is 930
2024-12-16T16:32:58.981Z,1734366778.981 [IBIT](INFO): Initialize IBIT Component.
2024-12-16T16:32:58.982Z,1734366778.982 [CBIT](DEBUG): Initialize CBIT Component.
2024-12-16T16:32:58.989Z,1734366778.989 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 931
2024-12-16T16:32:58.991Z,1734366778.991 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2024-12-16T16:32:58.993Z,1734366778.993 [CBIT](DEBUG): Initialized mux pins.
2024-12-16T16:32:58.993Z,1734366778.993 [CBIT](DEBUG): Initializing the watchdog timer.
2024-12-16T16:32:59.001Z,1734366779.001 [Onboard ThreadHandler](INFO): Handler Thread ID is 932
2024-12-16T16:32:59.017Z,1734366779.017 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-12-16T16:32:59.018Z,1734366779.018 [CBIT](DEBUG): Initializing heartbeat.
2024-12-16T16:32:59.020Z,1734366779.020 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 933
2024-12-16T16:32:59.042Z,1734366779.042 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 934
2024-12-16T16:32:59.043Z,1734366779.043 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-12-16T16:32:59.046Z,1734366779.046 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 936
2024-12-16T16:32:59.049Z,1734366779.049 [WetLabsBB2FL](INFO): Powering up
2024-12-16T16:32:59.051Z,1734366779.051 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 938
2024-12-16T16:32:59.059Z,1734366779.059 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-12-16T16:32:59.059Z,1734366779.059 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2024-12-16T16:32:59.059Z,1734366779.059 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2024-12-16T16:32:59.059Z,1734366779.059 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2024-12-16T16:32:59.059Z,1734366779.059 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2024-12-16T16:32:59.059Z,1734366779.059 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2024-12-16T16:32:59.060Z,1734366779.060 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2024-12-16T16:32:59.060Z,1734366779.060 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2024-12-16T16:32:59.089Z,1734366779.089 [CBIT](DEBUG): Deactivating GF circuits.
2024-12-16T16:32:59.089Z,1734366779.089 [CBIT](DEBUG): Deactivating emergency mode.
2024-12-16T16:32:59.129Z,1734366779.129 [CBIT](DEBUG): Backplane powered.
2024-12-16T16:32:59.130Z,1734366779.130 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2024-12-16T16:32:59.131Z,1734366779.131 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2024-12-16T16:32:59.131Z,1734366779.131 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2024-12-16T16:32:59.137Z,1734366779.137 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2024-12-16T16:32:59.187Z,1734366779.187 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2024-12-16T16:32:59.192Z,1734366779.192 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-12-16T16:32:59.237Z,1734366779.237 [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-12-16T16:32:59.238Z,1734366779.238 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2024-12-16T16:32:59.238Z,1734366779.238 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2024-12-16T16:32:59.251Z,1734366779.251 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2024-12-16T16:32:59.429Z,1734366779.429 [Radio_Surface](INFO): Powering up
2024-12-16T16:32:59.560Z,1734366779.560 [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-12-16T16:32:59.582Z,1734366779.582 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-12-16T16:32:59.583Z,1734366779.583 [Default:A.Wait](DEBUG): Construct Wait.
2024-12-16T16:32:59.593Z,1734366779.593 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-12-16T16:32:59.639Z,1734366779.639 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-12-16T16:32:59.658Z,1734366779.658 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-12-16T16:32:59.664Z,1734366779.664 [Default:E.Execute](DEBUG): Construct Execute.
2024-12-16T16:32:59.676Z,1734366779.676 [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-12-16T16:32:59.685Z,1734366779.685 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,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-12-16T16:32:59.692Z,1734366779.692 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-12-16T16:32:59.884Z,1734366779.884 [Power24vConverter](INFO): Powering up.
2024-12-16T16:32:59.885Z,1734366779.885 [Sonardyne_Nano](INFO): Initializing.
2024-12-16T16:32:59.905Z,1734366779.905 [CANONSampler](INFO): Powering down
2024-12-16T16:32:59.963Z,1734366779.963 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-12-16T16:32:59.969Z,1734366779.969 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-12-16T16:32:59.970Z,1734366779.970 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-12-16T16:32:59.978Z,1734366779.978 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-12-16T16:32:59.979Z,1734366779.979 [MassServo](DEBUG): Initializing EZServoServo.
2024-12-16T16:32:59.985Z,1734366779.985 [MassServo](DEBUG): Initializing MassServo.
2024-12-16T16:32:59.986Z,1734366779.986 [RudderServo](DEBUG): Initializing EZServoServo.
2024-12-16T16:32:59.994Z,1734366779.994 [RudderServo](DEBUG): Initializing RudderServo.
2024-12-16T16:32:59.995Z,1734366779.995 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-12-16T16:33:00.001Z,1734366780.001 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-12-16T16:33:01.661Z,1734366781.661 [WetLabsBB2FL](INFO): Powering down
2024-12-16T16:33:02.119Z,1734366782.119 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2024-12-16T16:33:03.358Z,1734366783.358 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2109
2024-12-16T16:33:03.761Z,1734366783.761 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging
2024-12-16T16:33:05.610Z,1734366785.610 [ThrusterHE](ERROR): Zero Speed Commanded.
2024-12-16T16:33:27.171Z,1734366807.171 [NAL9602](INFO): Powering up NAL9602
2024-12-16T16:33:37.014Z,1734366817.014 [CommandExec](IMPORTANT): got command strobe off
2024-12-16T16:33:37.015Z,1734366817.015 [CommandExec](IMPORTANT): Deactivating strobe
2024-12-16T16:33:38.087Z,1734366818.087 [NAL9602](INFO): NAL9602 initialized
2024-12-16T16:33:44.328Z,1734366824.328 [CommandExec](IMPORTANT): got command strobe off
2024-12-16T16:33:44.328Z,1734366824.328 [CommandExec](IMPORTANT): Deactivating strobe
2024-12-16T16:33:51.614Z,1734366831.614 [CommandExec](IMPORTANT): got command failComponent
2024-12-16T16:33:51.614Z,1734366831.614 [CommandExec](IMPORTANT): Failed components:
2024-12-16T16:33:51.614Z,1734366831.614 [CommandExec](IMPORTANT): No failed Components.
2024-12-16T16:33:59.508Z,1734366839.508 [SBIT](IMPORTANT): Beginning Startup BIT
2024-12-16T16:33:59.513Z,1734366839.513 [CBIT](IMPORTANT): Beginning ground fault scan
2024-12-16T16:34:10.421Z,1734366850.421 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-12-16T16:34:10.832Z,1734366850.832 [CBIT](IMPORTANT): Beginning ground fault scan
2024-12-16T16:34:22.707Z,1734366862.707 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.016002
CHAN A1 (24V): 0.000269
CHAN A2 (12V): -0.002574
CHAN A3 (5V): -0.001663
CHAN B0 (3.3V): 0.000170
CHAN B1 (3.15aV): 0.000239
CHAN B2 (3.15bV): -0.000126
CHAN B3 (GND): -0.000001
OPEN: -0.000533
Full Scale: +/- 1 mA
2024-12-16T16:34:53.776Z,1734366893.776 [SBIT](IMPORTANT): SBIT PASSED
2024-12-16T16:34:53.777Z,1734366893.777 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=11 count;
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): DATMMP.surfaceThreshold=2 meter;
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): Express linearApproximation DATMMP.acoustic_contact_range 15.000000 meter;
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=321.456843 cubic_centimeter;
2024-12-16T16:34:53.778Z,1734366893.778 [SBIT](IMPORTANT): VerticalControl.massDefault=10.109123 millimeter;
2024-12-16T16:34:54.171Z,1734366894.171 [MissionManager](IMPORTANT): Started mission Startup
2024-12-16T16:34:54.172Z,1734366894.172 [Startup] Running Loop=1
2024-12-16T16:34:54.172Z,1734366894.172 [Startup](DEBUG): Aggregate::initialize Startup
2024-12-16T16:34:54.172Z,1734366894.172 [Startup:A.GoToSurface] Running Loop=1
2024-12-16T16:34:54.172Z,1734366894.172 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-12-16T16:34:54.172Z,1734366894.172 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-12-16T16:34:54.173Z,1734366894.173 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-12-16T16:34:54.173Z,1734366894.173 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-12-16T16:34:54.174Z,1734366894.174 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-12-16T16:34:54.174Z,1734366894.174 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-12-16T16:34:54.174Z,1734366894.174 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-12-16T16:34:54.176Z,1734366894.176 [Startup:StartupSatComms] Running Loop=1
2024-12-16T16:34:54.176Z,1734366894.176 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-12-16T16:34:54.176Z,1734366894.176 [Startup:StartupSatComms:A] Running Loop=1
2024-12-16T16:34:54.580Z,1734366894.580 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-12-16T16:35:44.844Z,1734366944.844 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004638
2024-12-16T16:35:45.123Z,1734366945.123 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-12-16T16:35:54.557Z,1734366954.557 [Startup:StartupSatComms:A](INFO): Timed out from 2024-12-16T16:34:54.2Z
2024-12-16T16:35:54.557Z,1734366954.557 [Startup:StartupSatComms:A] Stopped
2024-12-16T16:35:54.557Z,1734366954.557 [Startup:StartupSatComms:B] Running Loop=1
2024-12-16T16:35:54.958Z,1734366954.958 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-12-16T16:35:59.032Z,1734366959.032 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2024-12-16T16:35:59.032Z,1734366959.032 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:35:59.047Z,1734366959.047 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:35:59.461Z,1734366959.461 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:35:59.461Z,1734366959.461 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2024-12-16T16:36:01.356Z,1734366961.356 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20241216T162810/Courier0000.lzma
2024-12-16T16:36:02.152Z,1734366962.152 [CommandExec](IMPORTANT): got command burn on
2024-12-16T16:36:02.153Z,1734366962.153 [CommandExec](IMPORTANT): Activating dropweight wire
2024-12-16T16:36:02.357Z,1734366962.357 [DataOverHttps](INFO): Moved sent file to Logs/20241216T162810/Courier0000.lzma.bak
2024-12-16T16:36:02.357Z,1734366962.357 [DataOverHttps](INFO): SBD MOMSN=23699189
2024-12-16T16:36:14.648Z,1734366974.648 [CommandExec](IMPORTANT): got command burn off
2024-12-16T16:36:14.648Z,1734366974.648 [CommandExec](IMPORTANT): Deactivating dropweight wire
2024-12-16T16:36:17.964Z,1734366977.964 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20241216T162810/Courier0004.lzma
2024-12-16T16:36:18.961Z,1734366978.961 [DataOverHttps](INFO): Moved sent file to Logs/20241216T162810/Courier0004.lzma.bak
2024-12-16T16:36:18.962Z,1734366978.962 [DataOverHttps](INFO): SBD MOMSN=23699192
2024-12-16T16:36:34.423Z,1734366994.423 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20241216T163246/Courier0000.lzma
2024-12-16T16:36:35.425Z,1734366995.425 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0000.lzma.bak
2024-12-16T16:36:35.425Z,1734366995.425 [DataOverHttps](INFO): SBD MOMSN=23699194
2024-12-16T16:36:49.940Z,1734367009.940 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20241216T161227/Express0008.lzma
2024-12-16T16:36:50.945Z,1734367010.945 [DataOverHttps](INFO): Moved sent file to Logs/20241216T161227/Express0008.lzma.bak
2024-12-16T16:36:50.945Z,1734367010.945 [DataOverHttps](INFO): SBD MOMSN=23699203
2024-12-16T16:36:54.761Z,1734367014.761 [Startup:StartupSatComms:B](INFO): Timed out from 2024-12-16T16:35:54.6Z
2024-12-16T16:36:54.761Z,1734367014.761 [Startup:StartupSatComms:B] Stopped
2024-12-16T16:36:54.761Z,1734367014.761 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-12-16T16:36:54.761Z,1734367014.761 [Startup:StartupSatComms] Stopped
2024-12-16T16:36:54.761Z,1734367014.761 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-12-16T16:36:54.762Z,1734367014.762 [Startup](INFO): Completed Startup
2024-12-16T16:36:54.762Z,1734367014.762 [MissionManager](INFO): Startup is completed.
2024-12-16T16:36:54.762Z,1734367014.762 [MissionManager](INFO): Uninitializing Mission Startup
2024-12-16T16:36:54.762Z,1734367014.762 [Startup] Stopped
2024-12-16T16:36:54.762Z,1734367014.762 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-12-16T16:36:54.763Z,1734367014.763 [Startup:A.GoToSurface] Stopped
2024-12-16T16:36:54.763Z,1734367014.763 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-12-16T16:36:55.168Z,1734367015.168 [MissionManager](IMPORTANT): Started mission Default
2024-12-16T16:36:55.169Z,1734367015.169 [Default] Running Loop=1
2024-12-16T16:36:55.169Z,1734367015.169 [Default](DEBUG): Aggregate::initialize Default
2024-12-16T16:36:55.169Z,1734367015.169 [Default:B.GoToSurface] Running Loop=1
2024-12-16T16:36:55.169Z,1734367015.169 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-12-16T16:36:55.169Z,1734367015.169 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-12-16T16:36:55.169Z,1734367015.169 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-12-16T16:36:55.170Z,1734367015.170 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-12-16T16:36:55.170Z,1734367015.170 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-12-16T16:36:55.170Z,1734367015.170 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-12-16T16:36:55.171Z,1734367015.171 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-12-16T16:36:55.171Z,1734367015.171 [Default:A.Wait] Running Loop=1
2024-12-16T16:36:55.171Z,1734367015.171 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-12-16T16:37:01.259Z,1734367021.259 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-12-16T16:37:06.545Z,1734367026.545 [DataOverHttps](INFO): Sending 983 bytes from file Logs/20241216T162810/Express0001.lzma
2024-12-16T16:37:07.537Z,1734367027.537 [DataOverHttps](INFO): Moved sent file to Logs/20241216T162810/Express0001.lzma.bak
2024-12-16T16:37:07.537Z,1734367027.537 [DataOverHttps](INFO): SBD MOMSN=23699244
2024-12-16T16:37:08.490Z,1734367028.490 [Default:A.Wait](INFO): Done Waiting.
2024-12-16T16:37:08.490Z,1734367028.490 [Default:A.Wait] Stopped
2024-12-16T16:37:08.491Z,1734367028.491 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T16:37:08.901Z,1734367028.901 [Default:CheckIn] Running Loop=1
2024-12-16T16:37:08.901Z,1734367028.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T16:37:08.901Z,1734367028.901 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T16:37:09.294Z,1734367029.294 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-12-16T16:38:13.165Z,1734367093.165 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-12-16T16:38:32.566Z,1734367112.566 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2024-12-16T16:38:41.797Z,1734367121.797 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-12-16T16:39:00.013Z,1734367140.013 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2024-12-16T16:39:00.013Z,1734367140.013 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:39:00.024Z,1734367140.024 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:39:00.417Z,1734367140.417 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:39:00.417Z,1734367140.417 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2024-12-16T16:39:13.366Z,1734367153.366 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2024-12-16T16:39:21.788Z,1734367161.788 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T16:39:42.425Z,1734367182.425 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T16:39:58.184Z,1734367198.184 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T16:40:13.129Z,1734367213.129 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T16:40:28.544Z,1734367228.544 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T16:40:28.904Z,1734367228.904 [BPC1](INFO): Calculating totals. Valid battery stick count: 47. Valid reserve battery stick count: 4.
2024-12-16T16:40:28.908Z,1734367228.908 [BPC1](INFO): Received data from all battery sticks.
2024-12-16T16:42:01.041Z,1734367321.041 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2024-12-16T16:42:01.041Z,1734367321.041 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:42:01.070Z,1734367321.070 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:42:01.434Z,1734367321.434 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:42:01.434Z,1734367321.434 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2024-12-16T16:42:09.093Z,1734367329.093 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-12-16T16:37:08.9Z
2024-12-16T16:42:09.093Z,1734367329.093 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T16:42:09.093Z,1734367329.093 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T16:42:09.500Z,1734367329.500 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-12-16T16:42:09.784Z,1734367329.784 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20241216T163246/Courier0004.lzma
2024-12-16T16:42:10.597Z,1734367330.597 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0004.lzma.bak
2024-12-16T16:42:10.597Z,1734367330.597 [DataOverHttps](INFO): SBD MOMSN=23699279
2024-12-16T16:42:28.736Z,1734367348.736 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20241216T162810/Express0005.lzma
2024-12-16T16:42:29.737Z,1734367349.737 [DataOverHttps](INFO): Moved sent file to Logs/20241216T162810/Express0005.lzma.bak
2024-12-16T16:42:29.737Z,1734367349.737 [DataOverHttps](INFO): SBD MOMSN=23699281
2024-12-16T16:42:45.136Z,1734367365.136 [DataOverHttps](INFO): Sending 970 bytes from file Logs/20241216T163246/Express0001.lzma
2024-12-16T16:42:46.137Z,1734367366.137 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0001.lzma.bak
2024-12-16T16:42:46.137Z,1734367366.137 [DataOverHttps](INFO): SBD MOMSN=23699284
2024-12-16T16:43:00.896Z,1734367380.896 [Power24vConverter](INFO): Powering down.
2024-12-16T16:43:04.083Z,1734367384.083 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20241216T163246/Express0005.lzma
2024-12-16T16:43:05.085Z,1734367385.085 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0005.lzma.bak
2024-12-16T16:43:05.085Z,1734367385.085 [DataOverHttps](INFO): SBD MOMSN=23699313
2024-12-16T16:43:06.155Z,1734367386.155 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T16:43:06.155Z,1734367386.155 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T16:43:06.155Z,1734367386.155 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T16:43:40.068Z,1734367420.068 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-12-16T16:43:40.069Z,1734367420.069 [NAL9602] Data Fault, FailCount= 1
2024-12-16T16:43:40.069Z,1734367420.069 [NAL9602](ERROR): Data Fault
2024-12-16T16:43:40.098Z,1734367420.098 [CBIT](ERROR): Data Fault in component: NAL9602
2024-12-16T16:43:40.478Z,1734367420.478 [NAL9602](INFO): Powering down
2024-12-16T16:43:41.329Z,1734367421.329 [CBIT](INFO): Clearing failed state for component NAL9602
2024-12-16T16:43:41.330Z,1734367421.330 [NAL9602] No Fault, FailCount= 1
2024-12-16T16:44:10.773Z,1734367450.773 [NAL9602](INFO): Powering up NAL9602
2024-12-16T16:44:21.677Z,1734367461.677 [NAL9602](INFO): NAL9602 initialized
2024-12-16T16:45:02.088Z,1734367502.088 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2024-12-16T16:45:02.088Z,1734367502.088 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:45:02.099Z,1734367502.099 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:45:02.522Z,1734367502.522 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:45:02.522Z,1734367502.522 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2024-12-16T16:48:03.094Z,1734367683.094 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2024-12-16T16:48:03.094Z,1734367683.094 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:48:03.105Z,1734367683.105 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:48:03.514Z,1734367683.514 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:48:03.514Z,1734367683.514 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2024-12-16T16:48:06.717Z,1734367686.717 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T16:48:06.717Z,1734367686.717 [Default:CheckIn:C.Wait] Stopped
2024-12-16T16:48:06.718Z,1734367686.718 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T16:48:06.718Z,1734367686.718 [Default:CheckIn:D] Running Loop=1
2024-12-16T16:48:07.124Z,1734367687.124 [Default:CheckIn:D] Stopped
2024-12-16T16:48:07.124Z,1734367687.124 [Default:CheckIn:E] Running Loop=1
2024-12-16T16:48:07.525Z,1734367687.525 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.199261 min
2024-12-16T16:48:07.525Z,1734367687.525 [Default:CheckIn:E] Stopped
2024-12-16T16:48:07.525Z,1734367687.525 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T16:48:07.525Z,1734367687.525 [Default:CheckIn] Stopped
2024-12-16T16:48:07.525Z,1734367687.525 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T16:48:07.526Z,1734367687.526 [Default:CheckIn](INFO): Running loop #2
2024-12-16T16:48:07.526Z,1734367687.526 [Default:CheckIn] Running Loop=2
2024-12-16T16:48:07.526Z,1734367687.526 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T16:48:07.526Z,1734367687.526 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T16:51:04.097Z,1734367864.097 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2024-12-16T16:51:04.097Z,1734367864.097 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:51:04.108Z,1734367864.108 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:51:04.500Z,1734367864.500 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:51:04.500Z,1734367864.500 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2024-12-16T16:53:07.710Z,1734367987.710 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-12-16T16:48:07.5Z
2024-12-16T16:53:07.710Z,1734367987.710 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T16:53:07.710Z,1734367987.710 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T16:53:15.051Z,1734367995.051 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20241216T163246/Courier0007.lzma
2024-12-16T16:53:16.053Z,1734367996.053 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0007.lzma.bak
2024-12-16T16:53:16.053Z,1734367996.053 [DataOverHttps](INFO): SBD MOMSN=23699363
2024-12-16T16:53:31.399Z,1734368011.399 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20241216T163246/Express0008.lzma
2024-12-16T16:53:32.413Z,1734368012.413 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0008.lzma.bak
2024-12-16T16:53:32.413Z,1734368012.413 [DataOverHttps](INFO): SBD MOMSN=23699365
2024-12-16T16:53:33.561Z,1734368013.561 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T16:53:33.561Z,1734368013.561 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T16:53:33.561Z,1734368013.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T16:54:05.095Z,1734368045.095 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2024-12-16T16:54:05.095Z,1734368045.095 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:54:05.106Z,1734368045.106 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:54:05.479Z,1734368045.479 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:54:05.479Z,1734368045.479 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2024-12-16T16:54:22.829Z,1734368062.829 [NAL9602](FAULT): GPS failed to acquire within timeout.
2024-12-16T16:54:22.829Z,1734368062.829 [NAL9602] Data Fault, FailCount= 2
2024-12-16T16:54:22.829Z,1734368062.829 [NAL9602](ERROR): Data Fault
2024-12-16T16:54:22.855Z,1734368062.855 [CBIT](ERROR): Data Fault in component: NAL9602
2024-12-16T16:54:23.238Z,1734368063.238 [NAL9602](INFO): Powering down
2024-12-16T16:54:24.089Z,1734368064.089 [CBIT](INFO): Clearing failed state for component NAL9602
2024-12-16T16:54:24.089Z,1734368064.089 [NAL9602] No Fault, FailCount= 2
2024-12-16T16:54:53.530Z,1734368093.530 [NAL9602](INFO): Powering up NAL9602
2024-12-16T16:55:04.441Z,1734368104.441 [NAL9602](INFO): NAL9602 initialized
2024-12-16T16:57:06.060Z,1734368226.060 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2024-12-16T16:57:06.060Z,1734368226.060 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T16:57:06.071Z,1734368226.071 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T16:57:06.497Z,1734368226.497 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T16:57:06.497Z,1734368226.497 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2024-12-16T16:58:34.126Z,1734368314.126 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T16:58:34.126Z,1734368314.126 [Default:CheckIn:C.Wait] Stopped
2024-12-16T16:58:34.126Z,1734368314.126 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T16:58:34.126Z,1734368314.126 [Default:CheckIn:D] Running Loop=1
2024-12-16T16:58:34.545Z,1734368314.545 [Default:CheckIn:D] Stopped
2024-12-16T16:58:34.546Z,1734368314.546 [Default:CheckIn:E] Running Loop=1
2024-12-16T16:58:34.958Z,1734368314.958 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.656283 min
2024-12-16T16:58:34.958Z,1734368314.958 [Default:CheckIn:E] Stopped
2024-12-16T16:58:34.958Z,1734368314.958 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T16:58:34.958Z,1734368314.958 [Default:CheckIn] Stopped
2024-12-16T16:58:34.958Z,1734368314.958 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T16:58:34.958Z,1734368314.958 [Default:CheckIn](INFO): Running loop #3
2024-12-16T16:58:34.959Z,1734368314.959 [Default:CheckIn] Running Loop=3
2024-12-16T16:58:34.959Z,1734368314.959 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T16:58:34.959Z,1734368314.959 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:00:07.053Z,1734368407.053 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2024-12-16T17:00:07.053Z,1734368407.053 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T17:00:07.064Z,1734368407.064 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T17:00:07.485Z,1734368407.485 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T17:00:07.485Z,1734368407.485 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2024-12-16T17:03:08.061Z,1734368588.061 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2024-12-16T17:03:08.061Z,1734368588.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-12-16T17:03:08.071Z,1734368588.071 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-12-16T17:03:08.476Z,1734368588.476 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-12-16T17:03:08.476Z,1734368588.476 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2024-12-16T17:03:35.127Z,1734368615.127 [Default:CheckIn:Read_GPS](INFO): Timed out from 2024-12-16T16:58:34.0Z
2024-12-16T17:03:35.128Z,1734368615.128 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:03:35.128Z,1734368615.128 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:03:42.108Z,1734368622.108 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20241216T163246/Courier0010.lzma
2024-12-16T17:03:43.109Z,1734368623.109 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0010.lzma.bak
2024-12-16T17:03:43.109Z,1734368623.109 [DataOverHttps](INFO): SBD MOMSN=23699407
2024-12-16T17:03:58.431Z,1734368638.431 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20241216T163246/Express0011.lzma
2024-12-16T17:03:59.433Z,1734368639.433 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0011.lzma.bak
2024-12-16T17:03:59.433Z,1734368639.433 [DataOverHttps](INFO): SBD MOMSN=23699409
2024-12-16T17:04:00.570Z,1734368640.570 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:04:00.570Z,1734368640.570 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:04:00.570Z,1734368640.570 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:04:19.942Z,1734368659.942 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170419.00,A,3648.15499,N,12147.27392,W,0.253,0.00,161224,,,A*75
2024-12-16T17:04:19.946Z,1734368659.946 [NAL9602](INFO): GPS fix at 20241216T170419: (36.802583, -121.787899)
2024-12-16T17:04:52.284Z,1734368692.284 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:09:01.181Z,1734368941.181 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:09:01.181Z,1734368941.181 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:09:01.181Z,1734368941.181 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:09:01.181Z,1734368941.181 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:09:01.600Z,1734368941.600 [Default:CheckIn:D] Stopped
2024-12-16T17:09:01.600Z,1734368941.600 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:09:01.996Z,1734368941.996 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.107186 min
2024-12-16T17:09:01.996Z,1734368941.996 [Default:CheckIn:E] Stopped
2024-12-16T17:09:01.996Z,1734368941.996 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:09:01.996Z,1734368941.996 [Default:CheckIn] Stopped
2024-12-16T17:09:01.997Z,1734368941.997 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:09:01.997Z,1734368941.997 [Default:CheckIn](INFO): Running loop #4
2024-12-16T17:09:01.997Z,1734368941.997 [Default:CheckIn] Running Loop=4
2024-12-16T17:09:01.997Z,1734368941.997 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:09:01.997Z,1734368941.997 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:09:04.006Z,1734368944.006 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170903.00,A,3648.15475,N,12147.27885,W,0.447,352.66,161224,,,A*7B
2024-12-16T17:09:04.009Z,1734368944.009 [NAL9602](INFO): GPS fix at 20241216T170903: (36.802579, -121.787981)
2024-12-16T17:09:04.036Z,1734368944.036 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:09:04.036Z,1734368944.036 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:09:10.819Z,1734368950.819 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20241216T163246/Courier0013.lzma
2024-12-16T17:09:11.821Z,1734368951.821 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0013.lzma.bak
2024-12-16T17:09:11.821Z,1734368951.821 [DataOverHttps](INFO): SBD MOMSN=23699450
2024-12-16T17:09:27.483Z,1734368967.483 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20241216T163246/Express0014.lzma
2024-12-16T17:09:28.485Z,1734368968.485 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0014.lzma.bak
2024-12-16T17:09:28.485Z,1734368968.485 [DataOverHttps](INFO): SBD MOMSN=23699456
2024-12-16T17:09:29.866Z,1734368969.866 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:09:29.866Z,1734368969.866 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:09:29.866Z,1734368969.866 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:09:46.830Z,1734368986.830 [NAL9602](INFO): SBD MO Status=2, MOMSN=60950, MT Status=2, MTMSN=0
2024-12-16T17:09:46.830Z,1734368986.830 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-12-16T17:14:06.208Z,1734369246.208 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-12-16T17:14:30.442Z,1734369270.442 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:14:30.442Z,1734369270.442 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:14:30.442Z,1734369270.442 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:14:30.442Z,1734369270.442 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:14:30.852Z,1734369270.852 [Default:CheckIn:D] Stopped
2024-12-16T17:14:30.852Z,1734369270.852 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:14:31.251Z,1734369271.251 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.594714 min
2024-12-16T17:14:31.251Z,1734369271.251 [Default:CheckIn:E] Stopped
2024-12-16T17:14:31.251Z,1734369271.251 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:14:31.276Z,1734369271.276 [Default:CheckIn] Stopped
2024-12-16T17:14:31.276Z,1734369271.276 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:14:31.276Z,1734369271.276 [Default:CheckIn](INFO): Running loop #5
2024-12-16T17:14:31.278Z,1734369271.278 [Default:CheckIn] Running Loop=5
2024-12-16T17:14:31.278Z,1734369271.278 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:14:31.279Z,1734369271.279 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:14:33.266Z,1734369273.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171432.00,A,3648.16481,N,12147.28572,W,0.253,352.66,161224,,,A*74
2024-12-16T17:14:33.268Z,1734369273.268 [NAL9602](INFO): GPS fix at 20241216T171432: (36.802747, -121.788095)
2024-12-16T17:14:33.279Z,1734369273.279 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:14:33.279Z,1734369273.279 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:14:40.676Z,1734369280.676 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20241216T163246/Courier0016.lzma
2024-12-16T17:14:41.677Z,1734369281.677 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0016.lzma.bak
2024-12-16T17:14:41.677Z,1734369281.677 [DataOverHttps](INFO): SBD MOMSN=23699459
2024-12-16T17:15:00.351Z,1734369300.351 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20241216T163246/Express0017.lzma
2024-12-16T17:15:01.353Z,1734369301.353 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0017.lzma.bak
2024-12-16T17:15:01.353Z,1734369301.353 [DataOverHttps](INFO): SBD MOMSN=23699462
2024-12-16T17:15:02.408Z,1734369302.408 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:15:02.408Z,1734369302.408 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:15:02.408Z,1734369302.408 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:15:05.620Z,1734369305.620 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:20:02.986Z,1734369602.986 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:20:02.986Z,1734369602.986 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:20:02.986Z,1734369602.986 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:20:02.986Z,1734369602.986 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:20:03.386Z,1734369603.386 [Default:CheckIn:D] Stopped
2024-12-16T17:20:03.386Z,1734369603.386 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:20:03.786Z,1734369603.786 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.136959 min
2024-12-16T17:20:03.786Z,1734369603.786 [Default:CheckIn:E] Stopped
2024-12-16T17:20:03.786Z,1734369603.786 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:20:03.786Z,1734369603.786 [Default:CheckIn] Stopped
2024-12-16T17:20:03.787Z,1734369603.787 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:20:03.787Z,1734369603.787 [Default:CheckIn](INFO): Running loop #6
2024-12-16T17:20:03.787Z,1734369603.787 [Default:CheckIn] Running Loop=6
2024-12-16T17:20:03.787Z,1734369603.787 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:20:03.787Z,1734369603.787 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:20:05.797Z,1734369605.797 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172005.00,A,3648.16442,N,12147.28211,W,0.214,352.66,161224,,,A*79
2024-12-16T17:20:05.800Z,1734369605.800 [NAL9602](INFO): GPS fix at 20241216T172005: (36.802740, -121.788035)
2024-12-16T17:20:05.830Z,1734369605.830 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:20:05.830Z,1734369605.830 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:20:13.371Z,1734369613.371 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0019.lzma
2024-12-16T17:20:14.373Z,1734369614.373 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0019.lzma.bak
2024-12-16T17:20:14.373Z,1734369614.373 [DataOverHttps](INFO): SBD MOMSN=23699503
2024-12-16T17:20:32.955Z,1734369632.955 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20241216T163246/Express0020.lzma
2024-12-16T17:20:33.957Z,1734369633.957 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0020.lzma.bak
2024-12-16T17:20:33.957Z,1734369633.957 [DataOverHttps](INFO): SBD MOMSN=23699506
2024-12-16T17:20:35.354Z,1734369635.354 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:20:35.354Z,1734369635.354 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:20:35.354Z,1734369635.354 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:20:36.549Z,1734369636.549 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-12-16T17:20:36.627Z,1734369636.627 [NAL9602](ERROR): received:
+CSQ:0
OK950, 2, 0, 0, 0
OK
2024-12-16T17:25:08.453Z,1734369908.453 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2024-12-16T17:25:35.925Z,1734369935.925 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:25:35.925Z,1734369935.925 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:25:35.926Z,1734369935.926 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:25:35.926Z,1734369935.926 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:25:36.334Z,1734369936.334 [Default:CheckIn:D] Stopped
2024-12-16T17:25:36.335Z,1734369936.335 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:25:36.742Z,1734369936.742 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.686100 min
2024-12-16T17:25:36.742Z,1734369936.742 [Default:CheckIn:E] Stopped
2024-12-16T17:25:36.743Z,1734369936.743 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:25:36.743Z,1734369936.743 [Default:CheckIn] Stopped
2024-12-16T17:25:36.743Z,1734369936.743 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:25:36.743Z,1734369936.743 [Default:CheckIn](INFO): Running loop #7
2024-12-16T17:25:36.743Z,1734369936.743 [Default:CheckIn] Running Loop=7
2024-12-16T17:25:36.743Z,1734369936.743 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:25:36.743Z,1734369936.743 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:25:38.750Z,1734369938.750 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172538.00,A,3648.16786,N,12147.28517,W,0.175,0.00,161224,,,A*78
2024-12-16T17:25:38.752Z,1734369938.752 [NAL9602](INFO): GPS fix at 20241216T172538: (36.802798, -121.788086)
2024-12-16T17:25:38.787Z,1734369938.787 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:25:38.787Z,1734369938.787 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:25:45.963Z,1734369945.963 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0022.lzma
2024-12-16T17:25:46.965Z,1734369946.965 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0022.lzma.bak
2024-12-16T17:25:46.965Z,1734369946.965 [DataOverHttps](INFO): SBD MOMSN=23699509
2024-12-16T17:26:02.587Z,1734369962.587 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20241216T163246/Express0023.lzma
2024-12-16T17:26:03.589Z,1734369963.589 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0023.lzma.bak
2024-12-16T17:26:03.589Z,1734369963.589 [DataOverHttps](INFO): SBD MOMSN=23699512
2024-12-16T17:26:04.630Z,1734369964.630 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:26:04.630Z,1734369964.630 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:26:04.630Z,1734369964.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:26:11.476Z,1734369971.476 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:31:05.198Z,1734370265.198 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:31:05.198Z,1734370265.198 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:31:05.198Z,1734370265.198 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:31:05.198Z,1734370265.198 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:31:05.589Z,1734370265.589 [Default:CheckIn:D] Stopped
2024-12-16T17:31:05.589Z,1734370265.589 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.173682 min
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn:E] Stopped
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn] Stopped
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn](INFO): Running loop #8
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn] Running Loop=8
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:31:05.996Z,1734370265.996 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:31:08.007Z,1734370268.007 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173107.00,A,3648.16891,N,12147.28511,W,0.603,133.66,161224,,,A*79
2024-12-16T17:31:08.009Z,1734370268.009 [NAL9602](INFO): GPS fix at 20241216T173107: (36.802815, -121.788085)
2024-12-16T17:31:08.021Z,1734370268.021 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:31:08.021Z,1734370268.021 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:31:15.399Z,1734370275.399 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20241216T163246/Courier0025.lzma
2024-12-16T17:31:16.401Z,1734370276.401 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0025.lzma.bak
2024-12-16T17:31:16.401Z,1734370276.401 [DataOverHttps](INFO): SBD MOMSN=23699558
2024-12-16T17:31:32.139Z,1734370292.139 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20241216T163246/Express0026.lzma
2024-12-16T17:31:33.141Z,1734370293.141 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0026.lzma.bak
2024-12-16T17:31:33.141Z,1734370293.141 [DataOverHttps](INFO): SBD MOMSN=23699561
2024-12-16T17:31:34.286Z,1734370294.286 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:31:34.286Z,1734370294.286 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:31:34.286Z,1734370294.286 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:31:38.713Z,1734370298.713 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2024-12-16T17:31:38.791Z,1734370298.791 [NAL9602](ERROR): received:
+CSQ:0
OK950, 2, 0, 0, 0
OK
2024-12-16T17:32:26.822Z,1734370346.822 [NAL9602](INFO): SBD MO Status=2, MOMSN=60950, MT Status=2, MTMSN=0
2024-12-16T17:32:26.822Z,1734370346.822 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-12-16T17:32:43.390Z,1734370363.390 [NAL9602](INFO): SBD MO Status=0, MOMSN=60950, MT Status=0, MTMSN=0
2024-12-16T17:32:43.390Z,1734370363.390 [NAL9602](INFO): No messages in MT queue
2024-12-16T17:33:14.087Z,1734370394.087 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:34:13.957Z,1734370453.957 [DataOverHttps](IMPORTANT): SBD MTMSN=20241216T173413
2024-12-16T17:34:23.784Z,1734370463.784 [DataOverHttps](INFO): Received command: failc
2024-12-16T17:34:23.785Z,1734370463.785 [CommandExec](IMPORTANT): got command failComponent
2024-12-16T17:34:23.785Z,1734370463.785 [CommandExec](IMPORTANT): Failed components:
2024-12-16T17:34:23.785Z,1734370463.785 [CommandExec](IMPORTANT): No failed Components.
2024-12-16T17:34:24.785Z,1734370464.785 [DataOverHttps](IMPORTANT): SBD MTMSN=20241216T173423
2024-12-16T17:34:32.671Z,1734370472.671 [DataOverHttps](INFO): Received command: ibit
2024-12-16T17:34:32.752Z,1734370472.752 [CommandExec](IMPORTANT): got command ibit
2024-12-16T17:34:32.920Z,1734370472.920 [IBIT](IMPORTANT): Beginning Initiated BIT
2024-12-16T17:34:32.920Z,1734370472.920 [IBIT](IMPORTANT): Beginning control surface checks.
2024-12-16T17:34:32.940Z,1734370472.940 [CBIT](IMPORTANT): Beginning ground fault scan
2024-12-16T17:34:34.526Z,1734370474.526 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173433.00,A,3648.13292,N,12147.21340,W,0.019,128.05,161224,,,A*7E
2024-12-16T17:34:34.529Z,1734370474.529 [NAL9602](INFO): GPS fix at 20241216T173433: (36.802215, -121.786890)
2024-12-16T17:34:35.824Z,1734370475.824 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2024-12-16T17:34:43.832Z,1734370483.832 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-12-16T17:34:44.248Z,1734370484.248 [CBIT](IMPORTANT): Beginning ground fault scan
2024-12-16T17:34:47.109Z,1734370487.109 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2024-12-16T17:34:48.257Z,1734370488.257 [NAL9602](INFO): SBD MO Status=0, MOMSN=60951, MT Status=0, MTMSN=0
2024-12-16T17:34:48.257Z,1734370488.257 [NAL9602](INFO): No messages in MT queue
2024-12-16T17:34:49.470Z,1734370489.470 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173448.00,A,3648.13262,N,12147.21352,W,0.175,128.05,161224,,,A*75
2024-12-16T17:34:49.473Z,1734370489.473 [NAL9602](INFO): GPS fix at 20241216T173448: (36.802210, -121.786892)
2024-12-16T17:34:51.894Z,1734370491.894 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173451.00,A,3648.13266,N,12147.21345,W,0.058,128.05,161224,,,A*71
2024-12-16T17:34:51.896Z,1734370491.896 [NAL9602](INFO): GPS fix at 20241216T173451: (36.802211, -121.786891)
2024-12-16T17:34:55.131Z,1734370495.131 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173454.00,A,3648.13272,N,12147.21339,W,0.078,128.05,161224,,,A*78
2024-12-16T17:34:55.145Z,1734370495.145 [NAL9602](INFO): GPS fix at 20241216T173454: (36.802212, -121.786890)
2024-12-16T17:34:55.252Z,1734370495.252 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-12-16T17:34:55.864Z,1734370495.864 [CBIT](IMPORTANT): Beginning ground fault scan
2024-12-16T17:34:57.955Z,1734370497.955 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173457.00,A,3648.13280,N,12147.21336,W,0.039,128.05,161224,,,A*7C
2024-12-16T17:34:57.957Z,1734370497.957 [NAL9602](INFO): GPS fix at 20241216T173457: (36.802213, -121.786889)
2024-12-16T17:34:58.532Z,1734370498.532 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2024-12-16T17:35:01.186Z,1734370501.186 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173500.00,A,3648.13288,N,12147.21336,W,0.019,128.05,161224,,,A*75
2024-12-16T17:35:01.188Z,1734370501.188 [NAL9602](INFO): GPS fix at 20241216T173500: (36.802215, -121.786889)
2024-12-16T17:35:04.013Z,1734370504.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173503.00,A,3648.13295,N,12147.21338,W,0.019,128.05,161224,,,A*74
2024-12-16T17:35:04.016Z,1734370504.016 [NAL9602](INFO): GPS fix at 20241216T173503: (36.802216, -121.786890)
2024-12-16T17:35:06.143Z,1734370506.143 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2024-12-16T17:35:06.144Z,1734370506.144 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2024-12-16T17:35:07.254Z,1734370507.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173506.00,A,3648.13302,N,12147.21340,W,0.058,128.05,161224,,,A*74
2024-12-16T17:35:07.257Z,1734370507.257 [NAL9602](INFO): GPS fix at 20241216T173506: (36.802217, -121.786890)
2024-12-16T17:35:10.079Z,1734370510.079 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173509.00,A,3648.13307,N,12147.21340,W,0.039,128.05,161224,,,A*79
2024-12-16T17:35:10.082Z,1734370510.082 [NAL9602](INFO): GPS fix at 20241216T173509: (36.802218, -121.786890)
2024-12-16T17:35:12.905Z,1734370512.905 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173512.00,A,3648.13312,N,12147.21339,W,0.058,128.05,161224,,,A*7E
2024-12-16T17:35:12.907Z,1734370512.907 [NAL9602](INFO): GPS fix at 20241216T173512: (36.802219, -121.786890)
2024-12-16T17:35:16.146Z,1734370516.146 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173515.00,A,3648.13315,N,12147.21339,W,0.019,128.05,161224,,,A*7B
2024-12-16T17:35:16.148Z,1734370516.148 [NAL9602](INFO): GPS fix at 20241216T173515: (36.802219, -121.786890)
2024-12-16T17:35:18.965Z,1734370518.965 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173518.00,A,3648.13320,N,12147.21345,W,0.019,128.05,161224,,,A*7B
2024-12-16T17:35:18.968Z,1734370518.968 [NAL9602](INFO): GPS fix at 20241216T173518: (36.802220, -121.786891)
2024-12-16T17:35:19.407Z,1734370519.407 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802219 Longitude: -121.786888
2024-12-16T17:35:19.804Z,1734370519.804 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.572001
2024-12-16T17:35:19.805Z,1734370519.805 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2024-12-16T17:35:19.805Z,1734370519.805 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2024-12-16T17:35:20.192Z,1734370520.192 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2024-12-16T17:35:20.193Z,1734370520.193 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2024-12-16T17:35:20.193Z,1734370520.193 [IBIT](IMPORTANT): Pressure:9.289022 PSI
2024-12-16T17:35:20.193Z,1734370520.193 [IBIT](IMPORTANT): Humidity:16.609694 %
2024-12-16T17:35:20.606Z,1734370520.606 [IBIT](IMPORTANT): Vehicle Pitch:-0.718218 degrees
2024-12-16T17:35:20.606Z,1734370520.606 [IBIT](IMPORTANT): Vehicle Roll:-3.827184 degrees
2024-12-16T17:35:20.606Z,1734370520.606 [IBIT](IMPORTANT): Vehicle Heading:52.321205 degrees
2024-12-16T17:35:21.021Z,1734370521.021 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2024-12-16T17:35:21.022Z,1734370521.022 [IBIT](IMPORTANT): buoyancyNeutral: 321.456848 cc
2024-12-16T17:35:21.022Z,1734370521.022 [IBIT](IMPORTANT): massDefault: 1.010912 cm
2024-12-16T17:35:21.022Z,1734370521.022 [IBIT](IMPORTANT): stopDepth: 250.000000 m
2024-12-16T17:35:21.022Z,1734370521.022 [IBIT](IMPORTANT): abortDepth: 270.000000 m
2024-12-16T17:35:21.023Z,1734370521.023 [IBIT](IMPORTANT): IBIT PASSED
2024-12-16T17:35:51.692Z,1734370551.692 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:36:34.932Z,1734370594.932 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:36:34.932Z,1734370594.932 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:36:34.932Z,1734370594.932 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:36:34.932Z,1734370594.932 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:36:35.330Z,1734370595.330 [Default:CheckIn:D] Stopped
2024-12-16T17:36:35.330Z,1734370595.330 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:36:35.743Z,1734370595.743 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.669356 min
2024-12-16T17:36:35.743Z,1734370595.743 [Default:CheckIn:E] Stopped
2024-12-16T17:36:35.744Z,1734370595.744 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:36:35.744Z,1734370595.744 [Default:CheckIn] Stopped
2024-12-16T17:36:35.744Z,1734370595.744 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:36:35.744Z,1734370595.744 [Default:CheckIn](INFO): Running loop #9
2024-12-16T17:36:35.744Z,1734370595.744 [Default:CheckIn] Running Loop=9
2024-12-16T17:36:35.744Z,1734370595.744 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:36:35.744Z,1734370595.744 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:36:37.746Z,1734370597.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173637.00,A,3648.13376,N,12147.21288,W,0.019,128.05,161224,,,D*73
2024-12-16T17:36:37.749Z,1734370597.749 [NAL9602](INFO): GPS fix at 20241216T173637: (36.802229, -121.786881)
2024-12-16T17:36:37.780Z,1734370597.780 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:36:37.780Z,1734370597.780 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:36:45.179Z,1734370605.179 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20241216T163246/Courier0028.lzma
2024-12-16T17:36:46.181Z,1734370606.181 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0028.lzma.bak
2024-12-16T17:36:46.181Z,1734370606.181 [DataOverHttps](INFO): SBD MOMSN=23699570
2024-12-16T17:36:56.378Z,1734370616.378 [NAL9602](INFO): SBD MO Status=0, MOMSN=60952, MT Status=0, MTMSN=0
2024-12-16T17:36:56.378Z,1734370616.378 [NAL9602](INFO): No messages in MT queue
2024-12-16T17:37:04.444Z,1734370624.444 [DataOverHttps](INFO): Sending 837 bytes from file Logs/20241216T163246/Express0029.lzma
2024-12-16T17:37:05.445Z,1734370625.445 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0029.lzma.bak
2024-12-16T17:37:05.445Z,1734370625.445 [DataOverHttps](INFO): SBD MOMSN=23699573
2024-12-16T17:37:21.207Z,1734370641.207 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20241216T163246/Express0032.lzma
2024-12-16T17:37:22.209Z,1734370642.209 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0032.lzma.bak
2024-12-16T17:37:22.209Z,1734370642.209 [DataOverHttps](INFO): SBD MOMSN=23699606
2024-12-16T17:37:23.466Z,1734370643.466 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:37:23.466Z,1734370643.466 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:37:23.466Z,1734370643.466 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:37:27.088Z,1734370647.088 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:41:34.766Z,1734370894.766 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:41:47.289Z,1734370907.289 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:41:59.008Z,1734370919.008 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:42:10.724Z,1734370930.724 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:42:22.453Z,1734370942.453 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:42:24.091Z,1734370944.091 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:42:24.091Z,1734370944.091 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:42:24.091Z,1734370944.091 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:42:24.091Z,1734370944.091 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:42:24.494Z,1734370944.494 [Default:CheckIn:D] Stopped
2024-12-16T17:42:24.494Z,1734370944.494 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:42:24.908Z,1734370944.908 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.488761 min
2024-12-16T17:42:24.908Z,1734370944.908 [Default:CheckIn:E] Stopped
2024-12-16T17:42:24.908Z,1734370944.908 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:42:24.909Z,1734370944.909 [Default:CheckIn] Stopped
2024-12-16T17:42:24.909Z,1734370944.909 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:42:24.909Z,1734370944.909 [Default:CheckIn](INFO): Running loop #10
2024-12-16T17:42:24.909Z,1734370944.909 [Default:CheckIn] Running Loop=10
2024-12-16T17:42:24.909Z,1734370944.909 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:42:24.909Z,1734370944.909 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:42:26.901Z,1734370946.901 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174226.00,A,3648.13394,N,12147.21242,W,0.019,128.05,161224,,,D*7A
2024-12-16T17:42:26.904Z,1734370946.904 [NAL9602](INFO): GPS fix at 20241216T174226: (36.802232, -121.786874)
2024-12-16T17:42:26.915Z,1734370946.915 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:42:26.916Z,1734370946.916 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:42:34.171Z,1734370954.171 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:42:34.491Z,1734370954.491 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20241216T163246/Courier0034.lzma
2024-12-16T17:42:35.495Z,1734370955.495 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0034.lzma.bak
2024-12-16T17:42:35.496Z,1734370955.496 [DataOverHttps](INFO): SBD MOMSN=23699647
2024-12-16T17:42:46.290Z,1734370966.290 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:42:53.703Z,1734370973.703 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20241216T163246/Express0035.lzma
2024-12-16T17:42:54.705Z,1734370974.705 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0035.lzma.bak
2024-12-16T17:42:54.705Z,1734370974.705 [DataOverHttps](INFO): SBD MOMSN=23699651
2024-12-16T17:42:56.055Z,1734370976.055 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:42:56.067Z,1734370976.067 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:42:56.067Z,1734370976.067 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:42:57.868Z,1734370977.868 [NAL9602](INFO): SBD MO Status=0, MOMSN=60953, MT Status=0, MTMSN=0
2024-12-16T17:42:57.868Z,1734370977.868 [NAL9602](INFO): No messages in MT queue
2024-12-16T17:42:58.094Z,1734370978.094 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:43:28.348Z,1734371008.348 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:45:24.294Z,1734371124.294 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:45:36.820Z,1734371136.820 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:45:48.535Z,1734371148.535 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:46:00.654Z,1734371160.654 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:46:12.773Z,1734371172.773 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:46:24.894Z,1734371184.894 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:46:37.014Z,1734371197.014 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:46:48.730Z,1734371208.730 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:47:00.459Z,1734371220.459 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:47:12.566Z,1734371232.566 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:47:24.687Z,1734371244.687 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:47:36.806Z,1734371256.806 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T17:47:50.551Z,1734371270.551 [BPC1](INFO): Calculating totals. Valid battery stick count: 49. Valid reserve battery stick count: 5.
2024-12-16T17:47:50.553Z,1734371270.553 [BPC1](INFO): Received data from all battery sticks.
2024-12-16T17:47:56.613Z,1734371276.613 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:47:56.614Z,1734371276.614 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:47:56.614Z,1734371276.614 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:47:56.614Z,1734371276.614 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:47:57.022Z,1734371277.022 [Default:CheckIn:D] Stopped
2024-12-16T17:47:57.022Z,1734371277.022 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.030892 min
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn:E] Stopped
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn] Stopped
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn](INFO): Running loop #11
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn] Running Loop=11
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:47:57.434Z,1734371277.434 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:47:59.438Z,1734371279.438 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174758.00,A,3648.13381,N,12147.21302,W,0.019,128.05,161224,,,D*77
2024-12-16T17:47:59.441Z,1734371279.441 [NAL9602](INFO): GPS fix at 20241216T174758: (36.802230, -121.786884)
2024-12-16T17:47:59.471Z,1734371279.471 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:47:59.471Z,1734371279.471 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:48:07.063Z,1734371287.063 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20241216T163246/Courier0037.lzma
2024-12-16T17:48:08.065Z,1734371288.065 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0037.lzma.bak
2024-12-16T17:48:08.065Z,1734371288.065 [DataOverHttps](INFO): SBD MOMSN=23699669
2024-12-16T17:48:16.810Z,1734371296.810 [NAL9602](INFO): SBD MO Status=0, MOMSN=60954, MT Status=0, MTMSN=0
2024-12-16T17:48:16.810Z,1734371296.810 [NAL9602](INFO): No messages in MT queue
2024-12-16T17:48:26.519Z,1734371306.519 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20241216T163246/Express0038.lzma
2024-12-16T17:48:27.521Z,1734371307.521 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0038.lzma.bak
2024-12-16T17:48:27.521Z,1734371307.521 [DataOverHttps](INFO): SBD MOMSN=23699672
2024-12-16T17:48:28.598Z,1734371308.598 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:48:28.598Z,1734371308.598 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:48:28.599Z,1734371308.599 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:48:47.573Z,1734371327.573 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:53:29.171Z,1734371609.171 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:53:29.171Z,1734371609.171 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:53:29.171Z,1734371609.171 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:53:29.171Z,1734371609.171 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:53:29.576Z,1734371609.576 [Default:CheckIn:D] Stopped
2024-12-16T17:53:29.576Z,1734371609.576 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:53:29.993Z,1734371609.993 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.573462 min
2024-12-16T17:53:29.993Z,1734371609.993 [Default:CheckIn:E] Stopped
2024-12-16T17:53:29.993Z,1734371609.993 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:53:29.993Z,1734371609.993 [Default:CheckIn] Stopped
2024-12-16T17:53:29.993Z,1734371609.993 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:53:29.993Z,1734371609.993 [Default:CheckIn](INFO): Running loop #12
2024-12-16T17:53:29.993Z,1734371609.993 [Default:CheckIn] Running Loop=12
2024-12-16T17:53:29.994Z,1734371609.994 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:53:29.994Z,1734371609.994 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:53:31.987Z,1734371611.987 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175331.00,A,3648.13386,N,12147.21348,W,0.058,128.05,161224,,,D*71
2024-12-16T17:53:31.989Z,1734371611.989 [NAL9602](INFO): GPS fix at 20241216T175331: (36.802231, -121.786891)
2024-12-16T17:53:32.000Z,1734371612.000 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:53:32.000Z,1734371612.000 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:53:39.675Z,1734371619.675 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0040.lzma
2024-12-16T17:53:40.677Z,1734371620.677 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0040.lzma.bak
2024-12-16T17:53:40.677Z,1734371620.677 [DataOverHttps](INFO): SBD MOMSN=23699728
2024-12-16T17:53:46.941Z,1734371626.941 [NAL9602](INFO): SBD MO Status=0, MOMSN=60955, MT Status=0, MTMSN=0
2024-12-16T17:53:46.941Z,1734371626.941 [NAL9602](INFO): No messages in MT queue
2024-12-16T17:53:56.565Z,1734371636.565 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20241216T163246/Express0041.lzma
2024-12-16T17:53:57.565Z,1734371637.565 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0041.lzma.bak
2024-12-16T17:53:57.565Z,1734371637.565 [DataOverHttps](INFO): SBD MOMSN=23699731
2024-12-16T17:53:58.666Z,1734371638.666 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:53:58.666Z,1734371638.666 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:53:58.666Z,1734371638.666 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:54:17.635Z,1734371657.635 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T17:58:59.234Z,1734371939.234 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T17:58:59.234Z,1734371939.234 [Default:CheckIn:C.Wait] Stopped
2024-12-16T17:58:59.234Z,1734371939.234 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T17:58:59.234Z,1734371939.234 [Default:CheckIn:D] Running Loop=1
2024-12-16T17:58:59.642Z,1734371939.642 [Default:CheckIn:D] Stopped
2024-12-16T17:58:59.642Z,1734371939.642 [Default:CheckIn:E] Running Loop=1
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.074561 min
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn:E] Stopped
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn] Stopped
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn](INFO): Running loop #13
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn] Running Loop=13
2024-12-16T17:59:00.053Z,1734371940.053 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T17:59:00.054Z,1734371940.054 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T17:59:02.058Z,1734371942.058 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175901.00,A,3648.13372,N,12147.21311,W,0.019,128.05,161224,,,D*7A
2024-12-16T17:59:02.060Z,1734371942.060 [NAL9602](INFO): GPS fix at 20241216T175901: (36.802229, -121.786885)
2024-12-16T17:59:02.092Z,1734371942.092 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T17:59:02.092Z,1734371942.092 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T17:59:09.227Z,1734371949.227 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0043.lzma
2024-12-16T17:59:10.229Z,1734371950.229 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0043.lzma.bak
2024-12-16T17:59:10.229Z,1734371950.229 [DataOverHttps](INFO): SBD MOMSN=23699746
2024-12-16T17:59:25.971Z,1734371965.971 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20241216T163246/Express0044.lzma
2024-12-16T17:59:26.973Z,1734371966.973 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0044.lzma.bak
2024-12-16T17:59:26.973Z,1734371966.973 [DataOverHttps](INFO): SBD MOMSN=23699749
2024-12-16T17:59:28.327Z,1734371968.327 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T17:59:28.327Z,1734371968.327 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T17:59:28.328Z,1734371968.328 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T17:59:30.738Z,1734371970.738 [NAL9602](INFO): SBD MO Status=0, MOMSN=60956, MT Status=0, MTMSN=0
2024-12-16T17:59:30.738Z,1734371970.738 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:00:01.445Z,1734372001.445 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:04:28.902Z,1734372268.902 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:04:28.902Z,1734372268.902 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:04:28.902Z,1734372268.902 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:04:28.902Z,1734372268.902 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:04:29.310Z,1734372269.310 [Default:CheckIn:D] Stopped
2024-12-16T18:04:29.310Z,1734372269.310 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:04:29.715Z,1734372269.715 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.569027 min
2024-12-16T18:04:29.715Z,1734372269.715 [Default:CheckIn:E] Stopped
2024-12-16T18:04:29.715Z,1734372269.715 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:04:29.716Z,1734372269.716 [Default:CheckIn] Stopped
2024-12-16T18:04:29.716Z,1734372269.716 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:04:29.716Z,1734372269.716 [Default:CheckIn](INFO): Running loop #14
2024-12-16T18:04:29.716Z,1734372269.716 [Default:CheckIn] Running Loop=14
2024-12-16T18:04:29.716Z,1734372269.716 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:04:29.716Z,1734372269.716 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:04:31.726Z,1734372271.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180430.00,A,3648.13676,N,12147.20985,W,0.078,36.92,161224,,,D*4F
2024-12-16T18:04:31.737Z,1734372271.737 [NAL9602](INFO): GPS fix at 20241216T180430: (36.802279, -121.786831)
2024-12-16T18:04:31.748Z,1734372271.748 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:04:31.748Z,1734372271.748 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:04:38.615Z,1734372278.615 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0046.lzma
2024-12-16T18:04:39.617Z,1734372279.617 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0046.lzma.bak
2024-12-16T18:04:39.617Z,1734372279.617 [DataOverHttps](INFO): SBD MOMSN=23699800
2024-12-16T18:04:44.246Z,1734372284.246 [NAL9602](INFO): SBD MO Status=0, MOMSN=60957, MT Status=0, MTMSN=0
2024-12-16T18:04:44.246Z,1734372284.246 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:04:58.123Z,1734372298.123 [DataOverHttps](INFO): Sending 133 bytes from file Logs/20241216T163246/Express0047.lzma
2024-12-16T18:04:59.125Z,1734372299.125 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0047.lzma.bak
2024-12-16T18:04:59.126Z,1734372299.126 [DataOverHttps](INFO): SBD MOMSN=23699803
2024-12-16T18:05:00.462Z,1734372300.462 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:05:00.462Z,1734372300.462 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:05:00.462Z,1734372300.462 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:05:15.000Z,1734372315.000 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:10:01.066Z,1734372601.066 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:10:01.066Z,1734372601.066 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:10:01.066Z,1734372601.066 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:10:01.066Z,1734372601.066 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:10:01.469Z,1734372601.469 [Default:CheckIn:D] Stopped
2024-12-16T18:10:01.469Z,1734372601.469 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:10:01.879Z,1734372601.879 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.105013 min
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn:E] Stopped
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn] Stopped
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn](INFO): Running loop #15
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn] Running Loop=15
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:10:01.880Z,1734372601.880 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:10:03.885Z,1734372603.885 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181003.00,A,3648.13640,N,12147.20586,W,0.097,90.31,161224,,,D*44
2024-12-16T18:10:03.887Z,1734372603.887 [NAL9602](INFO): GPS fix at 20241216T181003: (36.802273, -121.786764)
2024-12-16T18:10:03.922Z,1734372603.922 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:10:03.922Z,1734372603.922 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:10:10.771Z,1734372610.771 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0049.lzma
2024-12-16T18:10:11.773Z,1734372611.773 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0049.lzma.bak
2024-12-16T18:10:11.774Z,1734372611.774 [DataOverHttps](INFO): SBD MOMSN=23699826
2024-12-16T18:10:29.366Z,1734372629.366 [NAL9602](INFO): SBD MO Status=2, MOMSN=60958, MT Status=2, MTMSN=0
2024-12-16T18:10:29.366Z,1734372629.366 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-12-16T18:10:30.743Z,1734372630.743 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20241216T163246/Express0050.lzma
2024-12-16T18:10:31.745Z,1734372631.745 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0050.lzma.bak
2024-12-16T18:10:31.745Z,1734372631.745 [DataOverHttps](INFO): SBD MOMSN=23699861
2024-12-16T18:10:33.010Z,1734372633.010 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:10:33.011Z,1734372633.011 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:10:33.011Z,1734372633.011 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:10:41.486Z,1734372641.486 [NAL9602](INFO): SBD MO Status=0, MOMSN=60958, MT Status=0, MTMSN=0
2024-12-16T18:10:41.486Z,1734372641.486 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:11:12.185Z,1734372672.185 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:15:33.598Z,1734372933.598 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:15:33.598Z,1734372933.598 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:15:33.598Z,1734372933.598 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:15:33.598Z,1734372933.598 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:15:33.998Z,1734372933.998 [Default:CheckIn:D] Stopped
2024-12-16T18:15:33.998Z,1734372933.998 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:15:34.400Z,1734372934.400 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.647160 min
2024-12-16T18:15:34.400Z,1734372934.400 [Default:CheckIn:E] Stopped
2024-12-16T18:15:34.400Z,1734372934.400 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:15:34.400Z,1734372934.400 [Default:CheckIn] Stopped
2024-12-16T18:15:34.400Z,1734372934.400 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:15:34.400Z,1734372934.400 [Default:CheckIn](INFO): Running loop #16
2024-12-16T18:15:34.400Z,1734372934.400 [Default:CheckIn] Running Loop=16
2024-12-16T18:15:34.401Z,1734372934.401 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:15:34.401Z,1734372934.401 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:15:36.406Z,1734372936.406 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181535.00,A,3648.13642,N,12147.20559,W,0.058,90.31,161224,,,D*47
2024-12-16T18:15:36.408Z,1734372936.408 [NAL9602](INFO): GPS fix at 20241216T181535: (36.802274, -121.786760)
2024-12-16T18:15:36.440Z,1734372936.440 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:15:36.440Z,1734372936.440 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:15:43.611Z,1734372943.611 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0052.lzma
2024-12-16T18:15:44.613Z,1734372944.613 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0052.lzma.bak
2024-12-16T18:15:44.613Z,1734372944.613 [DataOverHttps](INFO): SBD MOMSN=23699940
2024-12-16T18:15:49.334Z,1734372949.334 [NAL9602](INFO): SBD MO Status=0, MOMSN=60959, MT Status=0, MTMSN=0
2024-12-16T18:15:49.334Z,1734372949.334 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:16:00.304Z,1734372960.304 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20241216T163246/Express0053.lzma
2024-12-16T18:16:01.305Z,1734372961.305 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0053.lzma.bak
2024-12-16T18:16:01.305Z,1734372961.305 [DataOverHttps](INFO): SBD MOMSN=23699943
2024-12-16T18:16:02.673Z,1734372962.673 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:16:02.673Z,1734372962.673 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:16:02.673Z,1734372962.673 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:16:20.036Z,1734372980.036 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:21:03.267Z,1734373263.267 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:21:03.267Z,1734373263.267 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:21:03.267Z,1734373263.267 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:21:03.267Z,1734373263.267 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:21:03.666Z,1734373263.666 [Default:CheckIn:D] Stopped
2024-12-16T18:21:03.666Z,1734373263.666 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:21:04.066Z,1734373264.066 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.141626 min
2024-12-16T18:21:04.067Z,1734373264.067 [Default:CheckIn:E] Stopped
2024-12-16T18:21:04.067Z,1734373264.067 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:21:04.067Z,1734373264.067 [Default:CheckIn] Stopped
2024-12-16T18:21:04.067Z,1734373264.067 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:21:04.067Z,1734373264.067 [Default:CheckIn](INFO): Running loop #17
2024-12-16T18:21:04.067Z,1734373264.067 [Default:CheckIn] Running Loop=17
2024-12-16T18:21:04.067Z,1734373264.067 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:21:04.068Z,1734373264.068 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:21:06.078Z,1734373266.078 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182105.00,A,3648.13589,N,12147.20576,W,0.019,90.31,161224,,,D*4F
2024-12-16T18:21:06.081Z,1734373266.081 [NAL9602](INFO): GPS fix at 20241216T182105: (36.802265, -121.786763)
2024-12-16T18:21:06.092Z,1734373266.092 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:21:06.092Z,1734373266.092 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:21:13.315Z,1734373273.315 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0055.lzma
2024-12-16T18:21:14.317Z,1734373274.317 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0055.lzma.bak
2024-12-16T18:21:14.317Z,1734373274.317 [DataOverHttps](INFO): SBD MOMSN=23699985
2024-12-16T18:21:19.810Z,1734373279.810 [NAL9602](INFO): SBD MO Status=0, MOMSN=60960, MT Status=0, MTMSN=0
2024-12-16T18:21:19.810Z,1734373279.810 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:21:30.207Z,1734373290.207 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20241216T163246/Express0056.lzma
2024-12-16T18:21:31.209Z,1734373291.209 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0056.lzma.bak
2024-12-16T18:21:31.209Z,1734373291.209 [DataOverHttps](INFO): SBD MOMSN=23699989
2024-12-16T18:21:32.346Z,1734373292.346 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:21:32.346Z,1734373292.346 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:21:32.347Z,1734373292.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:21:50.513Z,1734373310.513 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:26:32.926Z,1734373592.926 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:26:32.926Z,1734373592.926 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:26:32.926Z,1734373592.926 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:26:32.926Z,1734373592.926 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:26:33.338Z,1734373593.338 [Default:CheckIn:D] Stopped
2024-12-16T18:26:33.338Z,1734373593.338 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:26:33.749Z,1734373593.749 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.636157 min
2024-12-16T18:26:33.749Z,1734373593.749 [Default:CheckIn:E] Stopped
2024-12-16T18:26:33.749Z,1734373593.749 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:26:33.749Z,1734373593.749 [Default:CheckIn] Stopped
2024-12-16T18:26:33.750Z,1734373593.750 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:26:33.750Z,1734373593.750 [Default:CheckIn](INFO): Running loop #18
2024-12-16T18:26:33.750Z,1734373593.750 [Default:CheckIn] Running Loop=18
2024-12-16T18:26:33.750Z,1734373593.750 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:26:33.750Z,1734373593.750 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:26:35.746Z,1734373595.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182635.00,A,3648.13698,N,12147.20567,W,0.078,90.31,161224,,,D*4F
2024-12-16T18:26:35.749Z,1734373595.749 [NAL9602](INFO): GPS fix at 20241216T182635: (36.802283, -121.786761)
2024-12-16T18:26:35.786Z,1734373595.786 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:26:35.786Z,1734373595.786 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:26:42.979Z,1734373602.979 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0058.lzma
2024-12-16T18:26:43.981Z,1734373603.981 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0058.lzma.bak
2024-12-16T18:26:43.981Z,1734373603.981 [DataOverHttps](INFO): SBD MOMSN=23700029
2024-12-16T18:26:55.986Z,1734373615.986 [NAL9602](INFO): SBD MO Status=0, MOMSN=60961, MT Status=0, MTMSN=0
2024-12-16T18:26:55.986Z,1734373615.986 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:27:02.583Z,1734373622.583 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20241216T163246/Express0059.lzma
2024-12-16T18:27:03.581Z,1734373623.581 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0059.lzma.bak
2024-12-16T18:27:03.581Z,1734373623.581 [DataOverHttps](INFO): SBD MOMSN=23700032
2024-12-16T18:27:04.886Z,1734373624.886 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:27:04.886Z,1734373624.886 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:27:04.886Z,1734373624.886 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:27:26.692Z,1734373646.692 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:32:05.461Z,1734373925.461 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:32:05.461Z,1734373925.461 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:32:05.461Z,1734373925.461 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:32:05.462Z,1734373925.462 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:32:05.866Z,1734373925.866 [Default:CheckIn:D] Stopped
2024-12-16T18:32:05.866Z,1734373925.866 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:32:06.275Z,1734373926.275 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.178296 min
2024-12-16T18:32:06.275Z,1734373926.275 [Default:CheckIn:E] Stopped
2024-12-16T18:32:06.276Z,1734373926.276 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:32:06.276Z,1734373926.276 [Default:CheckIn] Stopped
2024-12-16T18:32:06.276Z,1734373926.276 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:32:06.276Z,1734373926.276 [Default:CheckIn](INFO): Running loop #19
2024-12-16T18:32:06.276Z,1734373926.276 [Default:CheckIn] Running Loop=19
2024-12-16T18:32:06.276Z,1734373926.276 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:32:06.276Z,1734373926.276 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:32:08.286Z,1734373928.286 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183207.00,A,3648.19199,N,12147.15640,W,4.471,30.76,161224,,,D*47
2024-12-16T18:32:08.288Z,1734373928.288 [NAL9602](INFO): GPS fix at 20241216T183207: (36.803200, -121.785940)
2024-12-16T18:32:08.316Z,1734373928.316 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:32:08.316Z,1734373928.316 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:32:15.191Z,1734373935.191 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0061.lzma
2024-12-16T18:32:16.193Z,1734373936.193 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0061.lzma.bak
2024-12-16T18:32:16.193Z,1734373936.193 [DataOverHttps](INFO): SBD MOMSN=23700036
2024-12-16T18:32:23.274Z,1734373943.274 [NAL9602](INFO): SBD MO Status=0, MOMSN=60962, MT Status=0, MTMSN=0
2024-12-16T18:32:23.274Z,1734373943.274 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:32:34.635Z,1734373954.635 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20241216T163246/Express0062.lzma
2024-12-16T18:32:35.637Z,1734373955.637 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0062.lzma.bak
2024-12-16T18:32:35.637Z,1734373955.637 [DataOverHttps](INFO): SBD MOMSN=23700039
2024-12-16T18:32:37.026Z,1734373957.026 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:32:37.026Z,1734373957.026 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:32:37.026Z,1734373957.026 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:32:53.972Z,1734373973.972 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:37:37.614Z,1734374257.614 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:37:37.614Z,1734374257.614 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:37:37.614Z,1734374257.614 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:37:37.614Z,1734374257.614 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:37:38.010Z,1734374258.010 [Default:CheckIn:D] Stopped
2024-12-16T18:37:38.010Z,1734374258.010 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:37:38.414Z,1734374258.414 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.714022 min
2024-12-16T18:37:38.414Z,1734374258.414 [Default:CheckIn:E] Stopped
2024-12-16T18:37:38.414Z,1734374258.414 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:37:38.414Z,1734374258.414 [Default:CheckIn] Stopped
2024-12-16T18:37:38.414Z,1734374258.414 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:37:38.414Z,1734374258.414 [Default:CheckIn](INFO): Running loop #20
2024-12-16T18:37:38.415Z,1734374258.415 [Default:CheckIn] Running Loop=20
2024-12-16T18:37:38.415Z,1734374258.415 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:37:38.415Z,1734374258.415 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:37:40.428Z,1734374260.428 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183739.00,A,3648.47540,N,12147.29184,W,7.931,228.52,161224,,,D*73
2024-12-16T18:37:40.430Z,1734374260.430 [NAL9602](INFO): GPS fix at 20241216T183739: (36.807923, -121.788197)
2024-12-16T18:37:40.441Z,1734374260.441 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:37:40.441Z,1734374260.441 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:37:47.659Z,1734374267.659 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0064.lzma
2024-12-16T18:37:48.661Z,1734374268.661 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0064.lzma.bak
2024-12-16T18:37:48.661Z,1734374268.661 [DataOverHttps](INFO): SBD MOMSN=23700082
2024-12-16T18:38:04.376Z,1734374284.376 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20241216T163246/Express0065.lzma
2024-12-16T18:38:05.377Z,1734374285.377 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0065.lzma.bak
2024-12-16T18:38:05.377Z,1734374285.377 [DataOverHttps](INFO): SBD MOMSN=23700085
2024-12-16T18:38:06.700Z,1734374286.700 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:38:06.700Z,1734374286.700 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:38:06.700Z,1734374286.700 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:38:13.959Z,1734374293.959 [NAL9602](INFO): SBD MO Status=0, MOMSN=60963, MT Status=0, MTMSN=0
2024-12-16T18:38:13.959Z,1734374293.959 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:38:44.661Z,1734374324.661 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:43:07.429Z,1734374587.429 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:43:07.429Z,1734374587.429 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:43:07.430Z,1734374587.430 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:43:07.430Z,1734374587.430 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:43:07.828Z,1734374587.828 [Default:CheckIn:D] Stopped
2024-12-16T18:43:07.828Z,1734374587.828 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:43:08.231Z,1734374588.231 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.210994 min
2024-12-16T18:43:08.231Z,1734374588.231 [Default:CheckIn:E] Stopped
2024-12-16T18:43:08.231Z,1734374588.231 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:43:08.231Z,1734374588.231 [Default:CheckIn] Stopped
2024-12-16T18:43:08.231Z,1734374588.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:43:08.231Z,1734374588.231 [Default:CheckIn](INFO): Running loop #21
2024-12-16T18:43:08.232Z,1734374588.232 [Default:CheckIn] Running Loop=21
2024-12-16T18:43:08.232Z,1734374588.232 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:43:08.232Z,1734374588.232 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:43:10.248Z,1734374590.248 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184309.00,A,3648.18145,N,12149.78118,W,28.030,259.97,161224,,,D*4D
2024-12-16T18:43:10.250Z,1734374590.250 [NAL9602](INFO): GPS fix at 20241216T184309: (36.803024, -121.829686)
2024-12-16T18:43:10.261Z,1734374590.261 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:43:10.262Z,1734374590.262 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:43:17.115Z,1734374597.115 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0067.lzma
2024-12-16T18:43:18.117Z,1734374598.117 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0067.lzma.bak
2024-12-16T18:43:18.117Z,1734374598.117 [DataOverHttps](INFO): SBD MOMSN=23700089
2024-12-16T18:43:29.638Z,1734374609.638 [NAL9602](INFO): SBD MO Status=0, MOMSN=60964, MT Status=0, MTMSN=0
2024-12-16T18:43:29.638Z,1734374609.638 [NAL9602](INFO): No messages in MT queue
2024-12-16T18:43:33.851Z,1734374613.851 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20241216T163246/Express0068.lzma
2024-12-16T18:43:34.853Z,1734374614.853 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0068.lzma.bak
2024-12-16T18:43:34.853Z,1734374614.853 [DataOverHttps](INFO): SBD MOMSN=23700096
2024-12-16T18:43:36.106Z,1734374616.106 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:43:36.107Z,1734374616.107 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:43:36.107Z,1734374616.107 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:44:00.337Z,1734374640.337 [NAL9602](INFO): Not Powering down - fast GPS
2024-12-16T18:48:36.681Z,1734374916.681 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-12-16T18:48:36.681Z,1734374916.681 [Default:CheckIn:C.Wait] Stopped
2024-12-16T18:48:36.681Z,1734374916.681 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-12-16T18:48:36.681Z,1734374916.681 [Default:CheckIn:D] Running Loop=1
2024-12-16T18:48:37.086Z,1734374917.086 [Default:CheckIn:D] Stopped
2024-12-16T18:48:37.086Z,1734374917.086 [Default:CheckIn:E] Running Loop=1
2024-12-16T18:48:37.493Z,1734374917.493 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 131.698617 min
2024-12-16T18:48:37.493Z,1734374917.493 [Default:CheckIn:E] Stopped
2024-12-16T18:48:37.493Z,1734374917.493 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-12-16T18:48:37.493Z,1734374917.493 [Default:CheckIn] Stopped
2024-12-16T18:48:37.493Z,1734374917.493 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-12-16T18:48:37.493Z,1734374917.493 [Default:CheckIn](INFO): Running loop #22
2024-12-16T18:48:37.493Z,1734374917.493 [Default:CheckIn] Running Loop=22
2024-12-16T18:48:37.494Z,1734374917.494 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-12-16T18:48:37.494Z,1734374917.494 [Default:CheckIn:Read_GPS] Running Loop=1
2024-12-16T18:48:39.502Z,1734374919.502 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184838.00,A,3647.92958,N,12150.99921,W,1.672,302.60,161224,,,D*74
2024-12-16T18:48:39.504Z,1734374919.504 [NAL9602](INFO): GPS fix at 20241216T184838: (36.798826, -121.849987)
2024-12-16T18:48:39.536Z,1734374919.536 [Default:CheckIn:Read_GPS] Stopped
2024-12-16T18:48:39.536Z,1734374919.536 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-12-16T18:48:48.591Z,1734374928.591 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20241216T163246/Courier0070.lzma
2024-12-16T18:48:49.593Z,1734374929.593 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Courier0070.lzma.bak
2024-12-16T18:48:49.593Z,1734374929.593 [DataOverHttps](INFO): SBD MOMSN=23700140
2024-12-16T18:48:56.513Z,1734374936.513 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T18:49:08.514Z,1734374948.514 [DataOverHttps](INFO): Sending 146 bytes from file Logs/20241216T163246/Express0071.lzma
2024-12-16T18:49:09.050Z,1734374949.050 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T18:49:09.513Z,1734374949.513 [DataOverHttps](INFO): Moved sent file to Logs/20241216T163246/Express0071.lzma.bak
2024-12-16T18:49:09.514Z,1734374949.514 [DataOverHttps](INFO): SBD MOMSN=23700143
2024-12-16T18:49:10.683Z,1734374950.683 [Default:CheckIn:Read_Iridium] Stopped
2024-12-16T18:49:10.684Z,1734374950.684 [Default:CheckIn:C.Wait] Running Loop=1
2024-12-16T18:49:10.684Z,1734374950.684 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-12-16T18:49:11.554Z,1734374951.554 [NAL9602](INFO): SBD MO Status=2, MOMSN=60965, MT Status=2, MTMSN=0
2024-12-16T18:49:11.554Z,1734374951.554 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-12-16T18:49:17.809Z,1734374957.809 [DataOverHttps](IMPORTANT): SBD MTMSN=20241216T184916
2024-12-16T18:49:20.765Z,1734374960.765 [BPC1](ERROR): BPC1B got IPBS message with 4 sticks (min is 7).
2024-12-16T18:49:20.778Z,1734374960.778 [NAL9602](INFO): SBD MO Status=0, MOMSN=60965, MT Status=0, MTMSN=0
2024-12-16T18:49:20.778Z,1734374960.778 [NAL9602](INFO): No messages in MT queue