2025-06-02T16:26:52.847Z,1748881612.847 [Supervisor](DEBUG): Initializing supervisor.
2025-06-02T16:26:52.852Z,1748881612.852 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2025-06-02T16:26:52.852Z,1748881612.852 [SyncHandler](INFO): Protected caller Thread ID is 829
2025-06-02T16:26:52.853Z,1748881612.853 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2025-06-02T16:26:52.854Z,1748881612.854 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2025-06-02T16:26:52.854Z,1748881612.854 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 830
2025-06-02T16:26:52.858Z,1748881612.858 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2025-06-02T16:26:52.878Z,1748881612.878 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2025-06-02T16:26:52.879Z,1748881612.879 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2025-06-02T16:26:52.880Z,1748881612.880 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 831
2025-06-02T16:26:52.884Z,1748881612.884 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2025-06-02T16:26:52.885Z,1748881612.885 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2025-06-02T16:26:52.886Z,1748881612.886 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 832
2025-06-02T16:26:52.888Z,1748881612.888 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2025-06-02T16:26:52.889Z,1748881612.889 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2025-06-02T16:26:52.889Z,1748881612.889 [logger ThreadHandler](INFO): Protected caller Thread ID is 833
2025-06-02T16:26:52.893Z,1748881612.893 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2025-06-02T16:26:52.894Z,1748881612.894 [Supervisor](INFO): Looking for Config files in directory: Config/
2025-06-02T16:26:52.899Z,1748881612.899 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2025-06-02T16:26:53.005Z,1748881613.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2025-06-02T16:26:53.007Z,1748881613.007 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2025-06-02T16:26:53.240Z,1748881613.240 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2025-06-02T16:26:53.242Z,1748881613.242 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2025-06-02T16:26:53.514Z,1748881613.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2025-06-02T16:26:53.516Z,1748881613.516 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2025-06-02T16:26:53.632Z,1748881613.632 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2025-06-02T16:26:53.634Z,1748881613.634 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2025-06-02T16:26:54.403Z,1748881614.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2025-06-02T16:26:54.404Z,1748881614.404 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2025-06-02T16:26:54.931Z,1748881614.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2025-06-02T16:26:54.932Z,1748881614.932 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2025-06-02T16:26:55.503Z,1748881615.503 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2025-06-02T16:26:55.505Z,1748881615.505 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2025-06-02T16:26:56.424Z,1748881616.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2025-06-02T16:26:56.426Z,1748881616.426 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2025-06-02T16:26:56.790Z,1748881616.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2025-06-02T16:26:56.791Z,1748881616.791 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2025-06-02T16:26:57.183Z,1748881617.183 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2025-06-02T16:26:57.183Z,1748881617.183 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2025-06-02T16:26:57.419Z,1748881617.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2025-06-02T16:26:57.421Z,1748881617.421 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2025-06-02T16:26:57.612Z,1748881617.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2025-06-02T16:26:57.614Z,1748881617.614 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2025-06-02T16:26:57.721Z,1748881617.721 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Guidance
2025-06-02T16:26:57.722Z,1748881617.722 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2025-06-02T16:26:57.813Z,1748881617.813 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2025-06-02T16:26:58.009Z,1748881618.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2025-06-02T16:26:58.010Z,1748881618.010 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2025-06-02T16:26:58.269Z,1748881618.269 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2025-06-02T16:26:58.271Z,1748881618.271 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2025-06-02T16:26:58.275Z,1748881618.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2025-06-02T16:26:58.368Z,1748881618.368 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2025-06-02T16:26:58.646Z,1748881618.646 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2025-06-02T16:26:58.647Z,1748881618.647 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2025-06-02T16:26:58.741Z,1748881618.741 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2025-06-02T16:26:58.923Z,1748881618.923 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2025-06-02T16:26:59.034Z,1748881619.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2025-06-02T16:26:59.156Z,1748881619.156 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2025-06-02T16:26:59.279Z,1748881619.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2025-06-02T16:26:59.384Z,1748881619.384 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2025-06-02T16:26:59.557Z,1748881619.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2025-06-02T16:26:59.665Z,1748881619.665 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2025-06-02T16:26:59.761Z,1748881619.761 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2025-06-02T16:26:59.870Z,1748881619.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2025-06-02T16:26:59.968Z,1748881619.968 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2025-06-02T16:26:59.980Z,1748881619.980 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2025-06-02T16:27:00.208Z,1748881620.208 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2025-06-02T16:27:00.209Z,1748881620.209 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2025-06-02T16:27:00.406Z,1748881620.406 [BuoyancyServo] Loaded
2025-06-02T16:27:00.406Z,1748881620.406 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2025-06-02T16:27:00.430Z,1748881620.430 [ElevatorServo] Loaded
2025-06-02T16:27:00.430Z,1748881620.430 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2025-06-02T16:27:00.453Z,1748881620.453 [MassServo] Loaded
2025-06-02T16:27:00.453Z,1748881620.453 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2025-06-02T16:27:00.475Z,1748881620.475 [RudderServo] Loaded
2025-06-02T16:27:00.476Z,1748881620.476 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2025-06-02T16:27:00.494Z,1748881620.494 [ThrusterHE] Loaded
2025-06-02T16:27:00.494Z,1748881620.494 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2025-06-02T16:27:00.495Z,1748881620.495 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2025-06-02T16:27:00.496Z,1748881620.496 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2025-06-02T16:27:01.516Z,1748881621.516 [SBIT](DEBUG): Construct Startup Built In Test.
2025-06-02T16:27:01.532Z,1748881621.532 [SBIT] Loaded
2025-06-02T16:27:01.532Z,1748881621.532 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2025-06-02T16:27:01.535Z,1748881621.535 [IBIT](DEBUG): Construct Initiated Built In Test.
2025-06-02T16:27:01.556Z,1748881621.556 [IBIT] Loaded
2025-06-02T16:27:01.556Z,1748881621.556 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2025-06-02T16:27:01.562Z,1748881621.562 [CBIT](DEBUG): Construct Continuous Built In Test.
2025-06-02T16:27:01.758Z,1748881621.758 [CBIT] Loaded
2025-06-02T16:27:01.759Z,1748881621.759 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2025-06-02T16:27:01.790Z,1748881621.790 [GFScanner] Loaded
2025-06-02T16:27:01.791Z,1748881621.791 [ComponentRegistry](DEBUG): SyncComponent "GFScanner" handled in the control thread.
2025-06-02T16:27:01.791Z,1748881621.791 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2025-06-02T16:27:01.792Z,1748881621.792 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2025-06-02T16:27:02.016Z,1748881622.016 [CTD_Seabird] Loaded
2025-06-02T16:27:02.016Z,1748881622.016 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2025-06-02T16:27:02.017Z,1748881622.017 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406864E0
2025-06-02T16:27:02.018Z,1748881622.018 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 922
2025-06-02T16:27:02.053Z,1748881622.053 [ESPComponent] Loaded
2025-06-02T16:27:02.053Z,1748881622.053 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2025-06-02T16:27:02.075Z,1748881622.075 [PAR_Licor] Loaded
2025-06-02T16:27:02.076Z,1748881622.076 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2025-06-02T16:27:02.122Z,1748881622.122 [WetLabsBB2FL] Loaded
2025-06-02T16:27:02.122Z,1748881622.122 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2025-06-02T16:27:02.123Z,1748881622.123 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0
2025-06-02T16:27:02.123Z,1748881622.123 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 923
2025-06-02T16:27:02.124Z,1748881622.124 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2025-06-02T16:27:02.125Z,1748881622.125 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2025-06-02T16:27:02.198Z,1748881622.198 [DepthRateCalculator] Loaded
2025-06-02T16:27:02.198Z,1748881622.198 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2025-06-02T16:27:02.204Z,1748881622.204 [PitchRateCalculator] Loaded
2025-06-02T16:27:02.204Z,1748881622.204 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2025-06-02T16:27:02.215Z,1748881622.215 [SpeedCalculator] Loaded
2025-06-02T16:27:02.215Z,1748881622.215 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2025-06-02T16:27:02.220Z,1748881622.220 [YawRateCalculator] Loaded
2025-06-02T16:27:02.220Z,1748881622.220 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2025-06-02T16:27:02.240Z,1748881622.240 [ElevatorOffsetCalculator] Loaded
2025-06-02T16:27:02.240Z,1748881622.240 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2025-06-02T16:27:02.241Z,1748881622.241 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2025-06-02T16:27:02.241Z,1748881622.241 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2025-06-02T16:27:02.416Z,1748881622.416 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2025-06-02T16:27:02.417Z,1748881622.417 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2025-06-02T16:27:02.465Z,1748881622.465 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2025-06-02T16:27:02.466Z,1748881622.466 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2025-06-02T16:27:02.609Z,1748881622.609 [DeadReckonUsingMultipleVelocitySources] Loaded
2025-06-02T16:27:02.610Z,1748881622.610 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2025-06-02T16:27:02.624Z,1748881622.624 [NavChart] Loaded
2025-06-02T16:27:02.624Z,1748881622.624 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2025-06-02T16:27:02.630Z,1748881622.630 [UniversalFixResidualReporter] Loaded
2025-06-02T16:27:02.630Z,1748881622.630 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2025-06-02T16:27:02.631Z,1748881622.631 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2025-06-02T16:27:02.631Z,1748881622.631 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2025-06-02T16:27:03.533Z,1748881623.533 [AHRS_M2] Loaded
2025-06-02T16:27:03.533Z,1748881623.533 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2025-06-02T16:27:03.786Z,1748881623.786 [BackseatComponent] Loaded
2025-06-02T16:27:03.787Z,1748881623.787 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2025-06-02T16:27:03.788Z,1748881623.788 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A824E0
2025-06-02T16:27:03.789Z,1748881623.789 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 924
2025-06-02T16:27:03.791Z,1748881623.791 [LcmUniversalReporter] Loaded
2025-06-02T16:27:03.792Z,1748881623.792 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2025-06-02T16:27:04.542Z,1748881624.542 [BPC1] Loaded
2025-06-02T16:27:04.542Z,1748881624.542 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2025-06-02T16:27:04.644Z,1748881624.644 [DAT] Loaded
2025-06-02T16:27:04.645Z,1748881624.645 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2025-06-02T16:27:04.646Z,1748881624.646 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AB24E0
2025-06-02T16:27:04.646Z,1748881624.646 [DAT ThreadHandler](INFO): Protected caller Thread ID is 925
2025-06-02T16:27:04.788Z,1748881624.788 [DataOverHttps] Loaded
2025-06-02T16:27:04.788Z,1748881624.788 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2025-06-02T16:27:04.789Z,1748881624.789 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AE24E0
2025-06-02T16:27:04.789Z,1748881624.789 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926
2025-06-02T16:27:04.813Z,1748881624.813 [Depth_Keller] Loaded
2025-06-02T16:27:04.814Z,1748881624.814 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2025-06-02T16:27:04.819Z,1748881624.819 [DropWeight] Loaded
2025-06-02T16:27:04.819Z,1748881624.819 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2025-06-02T16:27:04.882Z,1748881624.882 [NAL9602] Loaded
2025-06-02T16:27:04.882Z,1748881624.882 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2025-06-02T16:27:04.909Z,1748881624.909 [Onboard] Loaded
2025-06-02T16:27:04.909Z,1748881624.909 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2025-06-02T16:27:04.910Z,1748881624.910 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40B124E0
2025-06-02T16:27:04.911Z,1748881624.911 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927
2025-06-02T16:27:04.917Z,1748881624.917 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2025-06-02T16:27:04.931Z,1748881624.931 [PowerOnly] Loaded
2025-06-02T16:27:04.931Z,1748881624.931 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2025-06-02T16:27:04.945Z,1748881624.945 [Power24vConverter] Loaded
2025-06-02T16:27:04.946Z,1748881624.946 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2025-06-02T16:27:04.962Z,1748881624.962 [Radio_Surface] Loaded
2025-06-02T16:27:04.962Z,1748881624.962 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2025-06-02T16:27:04.963Z,1748881624.963 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B424E0
2025-06-02T16:27:04.964Z,1748881624.964 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928
2025-06-02T16:27:04.980Z,1748881624.980 [Sonardyne_Nano] Loaded
2025-06-02T16:27:04.980Z,1748881624.980 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2025-06-02T16:27:04.981Z,1748881624.981 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2025-06-02T16:27:04.981Z,1748881624.981 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2025-06-02T16:27:05.071Z,1748881625.071 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2025-06-02T16:27:05.072Z,1748881625.072 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2025-06-02T16:27:05.310Z,1748881625.310 [VerticalControl](DEBUG): Construct VerticalControl.
2025-06-02T16:27:05.461Z,1748881625.461 [VerticalControl] Loaded
2025-06-02T16:27:05.462Z,1748881625.462 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2025-06-02T16:27:05.465Z,1748881625.465 [HorizontalControl](DEBUG): Construct HorizontalControl.
2025-06-02T16:27:05.559Z,1748881625.559 [HorizontalControl] Loaded
2025-06-02T16:27:05.559Z,1748881625.559 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2025-06-02T16:27:05.574Z,1748881625.574 [SpeedControl](DEBUG): Construct SpeedControl.
2025-06-02T16:27:05.575Z,1748881625.575 [SpeedControl] Loaded
2025-06-02T16:27:05.610Z,1748881625.610 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2025-06-02T16:27:05.691Z,1748881625.691 [LoopControl](DEBUG): Construct LoopControl.
2025-06-02T16:27:05.692Z,1748881625.692 [LoopControl] Loaded
2025-06-02T16:27:05.693Z,1748881625.693 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2025-06-02T16:27:05.694Z,1748881625.694 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2025-06-02T16:27:05.695Z,1748881625.695 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2025-06-02T16:27:05.713Z,1748881625.713 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2025-06-02T16:27:05.714Z,1748881625.714 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2025-06-02T16:27:06.147Z,1748881626.147 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2025-06-02T16:27:06.153Z,1748881626.153 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2025-06-02T16:27:06.156Z,1748881626.156 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2025-06-02T16:27:06.168Z,1748881626.168 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2025-06-02T16:27:06.169Z,1748881626.169 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C684E0
2025-06-02T16:27:06.169Z,1748881626.169 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929
2025-06-02T16:27:06.173Z,1748881626.173 [Supervisor](INFO): Main Thread ID is 822
2025-06-02T16:27:06.174Z,1748881626.174 [Supervisor](DEBUG): Running supervisor.
2025-06-02T16:27:06.174Z,1748881626.174 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930
2025-06-02T16:27:06.175Z,1748881626.175 [CommandExec](INFO): Initializing the command executive.
2025-06-02T16:27:06.176Z,1748881626.176 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931
2025-06-02T16:27:06.178Z,1748881626.178 [controlThread ThreadHandler](INFO): Handler Thread ID is 932
2025-06-02T16:27:06.179Z,1748881626.179 [controlThread](DEBUG): Initializing ControlThread
2025-06-02T16:27:06.181Z,1748881626.181 [SBIT](INFO): Initialize SBIT Component.
2025-06-02T16:27:06.181Z,1748881626.181 [SBIT](IMPORTANT): git: 2025-05-29
2025-06-02T16:27:06.181Z,1748881626.181 [SBIT](INFO): git hash: c78c975c7bb2a66b27244d2837f68dff299fa024
2025-06-02T16:27:06.182Z,1748881626.182 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2025-06-02T16:27:06.183Z,1748881626.183 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2025-06-02T16:27:06.184Z,1748881626.184 [SBIT](INFO): Beginning SBIT in 125.000000 seconds.
2025-06-02T16:27:06.185Z,1748881626.185 [IBIT](INFO): Initialize IBIT Component.
2025-06-02T16:27:06.186Z,1748881626.186 [CBIT](DEBUG): Initialize CBIT Component.
2025-06-02T16:27:06.187Z,1748881626.187 [logger ThreadHandler](INFO): Handler Thread ID is 933
2025-06-02T16:27:06.200Z,1748881626.200 [CBIT](DEBUG): Initialized mux pins.
2025-06-02T16:27:06.200Z,1748881626.200 [CBIT](DEBUG): Initializing the watchdog timer.
2025-06-02T16:27:06.212Z,1748881626.212 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 934
2025-06-02T16:27:06.213Z,1748881626.213 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2025-06-02T16:27:06.217Z,1748881626.217 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 936
2025-06-02T16:27:06.220Z,1748881626.220 [WetLabsBB2FL](INFO): Powering up
2025-06-02T16:27:06.222Z,1748881626.222 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 938
2025-06-02T16:27:06.224Z,1748881626.224 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2025-06-02T16:27:06.224Z,1748881626.224 [CBIT](DEBUG): Initializing heartbeat.
2025-06-02T16:27:06.238Z,1748881626.238 [DAT ThreadHandler](INFO): Handler Thread ID is 939
2025-06-02T16:27:06.239Z,1748881626.239 [DAT](INFO): Powering up
2025-06-02T16:27:06.239Z,1748881626.239 [DAT](DEBUG): Initializing DAT.
2025-06-02T16:27:06.248Z,1748881626.248 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 941
2025-06-02T16:27:06.250Z,1748881626.250 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2025-06-02T16:27:06.260Z,1748881626.260 [Onboard ThreadHandler](INFO): Handler Thread ID is 942
2025-06-02T16:27:06.278Z,1748881626.278 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 943
2025-06-02T16:27:06.296Z,1748881626.296 [CBIT](DEBUG): Deactivating emergency mode.
2025-06-02T16:27:06.297Z,1748881626.297 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 944
2025-06-02T16:27:06.304Z,1748881626.304 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2025-06-02T16:27:06.304Z,1748881626.304 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2025-06-02T16:27:06.305Z,1748881626.305 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2025-06-02T16:27:06.305Z,1748881626.305 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2025-06-02T16:27:06.305Z,1748881626.305 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2025-06-02T16:27:06.305Z,1748881626.305 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2025-06-02T16:27:06.305Z,1748881626.305 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2025-06-02T16:27:06.306Z,1748881626.306 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2025-06-02T16:27:06.344Z,1748881626.344 [CBIT](DEBUG): Backplane powered.
2025-06-02T16:27:06.344Z,1748881626.344 [GFScanner](DEBUG): Initializing GFScanner
2025-06-02T16:27:06.344Z,1748881626.344 [GFScanner](DEBUG): Deactivating GF circuits.
2025-06-02T16:27:06.368Z,1748881626.368 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2025-06-02T16:27:06.368Z,1748881626.368 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2025-06-02T16:27:06.369Z,1748881626.369 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2025-06-02T16:27:06.369Z,1748881626.369 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2025-06-02T16:27:06.369Z,1748881626.369 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2025-06-02T16:27:06.371Z,1748881626.371 [NavChart](DEBUG): Initialize NavChart Navigation.
2025-06-02T16:27:06.371Z,1748881626.371 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2025-06-02T16:27:06.375Z,1748881626.375 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2025-06-02T16:27:06.384Z,1748881626.384 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2025-06-02T16:27:06.385Z,1748881626.385 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2025-06-02T16:27:06.386Z,1748881626.386 [LoopControl](DEBUG): Initialize LoopControlComponent.
2025-06-02T16:27:06.386Z,1748881626.386 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2025-06-02T16:27:06.387Z,1748881626.387 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2025-06-02T16:27:06.387Z,1748881626.387 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2025-06-02T16:27:06.400Z,1748881626.400 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2025-06-02T16:27:06.473Z,1748881626.473 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2025-06-02T16:27:06.495Z,1748881626.495 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2025-06-02T16:27:06.527Z,1748881626.527 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2025-06-02T16:27:06.527Z,1748881626.527 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2025-06-02T16:27:06.528Z,1748881626.528 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2025-06-02T16:27:06.536Z,1748881626.536 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2025-06-02T16:27:06.684Z,1748881626.684 [Radio_Surface](INFO): Powering up
2025-06-02T16:27:06.836Z,1748881626.836 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2025-06-02T16:27:06.865Z,1748881626.865 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2025-06-02T16:27:06.866Z,1748881626.866 [Default:A.Wait](DEBUG): Construct Wait.
2025-06-02T16:27:06.869Z,1748881626.869 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-06-02T16:27:06.913Z,1748881626.913 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2025-06-02T16:27:06.916Z,1748881626.916 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2025-06-02T16:27:06.938Z,1748881626.938 [Default:E.Execute](DEBUG): Construct Execute.
2025-06-02T16:27:06.942Z,1748881626.942 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2025-06-02T16:27:06.961Z,1748881626.961 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,GFScanner,LcmUniversalReporter,Reporter,LogSplitter,
2025-06-02T16:27:06.998Z,1748881626.998 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2025-06-02T16:27:07.128Z,1748881627.128 [Depth_Keller](INFO): Initializing.
2025-06-02T16:27:07.130Z,1748881627.130 [PowerOnly](INFO): Powering up loadControl
2025-06-02T16:27:07.148Z,1748881627.148 [Power24vConverter](INFO): Powering up.
2025-06-02T16:27:07.149Z,1748881627.149 [Sonardyne_Nano](INFO): Initializing.
2025-06-02T16:27:07.176Z,1748881627.176 [DepthRateCalculator](ERROR): Depth measurement is not active
2025-06-02T16:27:07.237Z,1748881627.237 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2025-06-02T16:27:07.244Z,1748881627.244 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2025-06-02T16:27:07.245Z,1748881627.245 [ElevatorServo](DEBUG): Initializing EZServoServo.
2025-06-02T16:27:07.253Z,1748881627.253 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2025-06-02T16:27:07.254Z,1748881627.254 [MassServo](DEBUG): Initializing EZServoServo.
2025-06-02T16:27:07.260Z,1748881627.260 [MassServo](DEBUG): Initializing MassServo.
2025-06-02T16:27:07.261Z,1748881627.261 [RudderServo](DEBUG): Initializing EZServoServo.
2025-06-02T16:27:07.268Z,1748881627.268 [RudderServo](DEBUG): Initializing RudderServo.
2025-06-02T16:27:07.269Z,1748881627.269 [ThrusterHE](DEBUG): Initializing EZServoServo.
2025-06-02T16:27:07.276Z,1748881627.276 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2025-06-02T16:27:08.832Z,1748881628.832 [WetLabsBB2FL](INFO): Powering down
2025-06-02T16:27:09.399Z,1748881629.399 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2025-06-02T16:27:10.637Z,1748881630.637 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2025-06-02T16:27:12.877Z,1748881632.877 [ThrusterHE](ERROR): Zero Speed Commanded.
2025-06-02T16:27:13.284Z,1748881633.284 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2025-06-02T16:27:18.336Z,1748881638.336 [DAT](INFO): DAT read:
2025-06-02T16:27:18.338Z,1748881638.338 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2025-06-02T16:27:20.101Z,1748881640.101 [DAT](INFO): DAT read: MF Frequency Band
2025-06-02T16:27:20.102Z,1748881640.102 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2025-06-02T16:27:20.103Z,1748881640.103 [DAT](INFO): DAT read: Jun 2 2025 16:27:15
2025-06-02T16:27:21.361Z,1748881641.361 [DAT](INFO): DAT read: Features enabled [Bearing]
2025-06-02T16:27:21.362Z,1748881641.362 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2025-06-02T16:27:21.362Z,1748881641.362 [DAT](INFO): commRate: 1200
2025-06-02T16:27:23.428Z,1748881643.428 [DAT](INFO): entering command mode
2025-06-02T16:27:23.628Z,1748881643.628 [DAT](INFO): DAT read:
2025-06-02T16:27:23.629Z,1748881643.629 [DAT](INFO): DAT read: user:1>
2025-06-02T16:27:23.629Z,1748881643.629 [DAT](INFO): setting verbose to 3
2025-06-02T16:27:23.881Z,1748881643.881 [DAT](INFO): DAT read: user:1>
2025-06-02T16:27:23.882Z,1748881643.882 [DAT](INFO): DAT read: Verbose | 3
2025-06-02T16:27:23.882Z,1748881643.882 [DAT](INFO): set verbose to 3
2025-06-02T16:27:23.882Z,1748881643.882 [DAT](INFO): setting DatVerbose to 27440
2025-06-02T16:27:24.133Z,1748881644.133 [DAT](INFO): DAT read: user:2>
2025-06-02T16:27:24.133Z,1748881644.133 [DAT](INFO): DAT read: DatVerbose | 27440
2025-06-02T16:27:24.134Z,1748881644.134 [DAT](INFO): set DatVerbose to 27440
2025-06-02T16:27:24.134Z,1748881644.134 [DAT](INFO): setting transmit power to 8
2025-06-02T16:27:24.385Z,1748881644.385 [DAT](INFO): DAT read: user:3>
2025-06-02T16:27:24.386Z,1748881644.386 [DAT](INFO): DAT read: TxPower | 8 (Max)
2025-06-02T16:27:24.386Z,1748881644.386 [DAT](INFO): set transmit power to 8
2025-06-02T16:27:24.386Z,1748881644.386 [DAT](INFO): setting local address to 5
2025-06-02T16:27:24.637Z,1748881644.637 [DAT](INFO): DAT read: user:4>
2025-06-02T16:27:24.638Z,1748881644.638 [DAT](INFO): DAT read: LocalAddr | 5
2025-06-02T16:27:24.638Z,1748881644.638 [DAT](INFO): set local address to 5
2025-06-02T16:27:24.639Z,1748881644.639 [DAT](INFO): Setting time to: 16:27:24 And date to:6/2/2025
2025-06-02T16:27:24.889Z,1748881644.889 [DAT](INFO): DAT read: user:5>
2025-06-02T16:27:24.890Z,1748881644.890 [DAT](INFO): DAT read: Mon Jun 2, 2025 16:27:24
2025-06-02T16:27:24.890Z,1748881644.890 [DAT](INFO): Local DAT time set to Mon Jun 2, 2025 16:27:24
2025-06-02T16:27:35.258Z,1748881655.258 [NAL9602](INFO): Powering up NAL9602
2025-06-02T16:27:46.168Z,1748881666.168 [NAL9602](INFO): NAL9602 initialized
2025-06-02T16:29:08.014Z,1748881748.014 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004546
2025-06-02T16:29:11.836Z,1748881751.836 [SBIT](IMPORTANT): Beginning Startup BIT
2025-06-02T16:29:11.841Z,1748881751.841 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-06-02T16:29:16.369Z,1748881756.369 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007257
CHAN A1 (24V): 0.002651
CHAN A2 (12V): -0.005688
CHAN A3 (5V): -0.002813
CHAN B0 (3.3V): -0.001043
CHAN B1 (3.15aV): -0.001085
CHAN B2 (3.15bV): -0.001085
CHAN B3 (GND): 0.000208
OPEN: 0.006742
Full Scale: +/- 1 mA
2025-06-02T16:30:06.035Z,1748881806.035 [SBIT](IMPORTANT): SBIT PASSED
2025-06-02T16:30:06.052Z,1748881806.052 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2025-06-02T16:30:06.052Z,1748881806.052 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=5 count;
2025-06-02T16:30:06.053Z,1748881806.053 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;
2025-06-02T16:30:06.053Z,1748881806.053 [SBIT](IMPORTANT): Express linearApproximation PowerOnly.component_avgCurrent_loadControl 50.000000 milliampere;
2025-06-02T16:30:06.053Z,1748881806.053 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=266.500578 cubic_centimeter;
2025-06-02T16:30:06.053Z,1748881806.053 [SBIT](IMPORTANT): VerticalControl.massDefault=26.489817 millimeter;
2025-06-02T16:30:06.450Z,1748881806.450 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2025-06-02T16:30:06.450Z,1748881806.450 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-02T16:30:06.451Z,1748881806.451 [MissionManager](IMPORTANT): Started mission Startup
2025-06-02T16:30:06.468Z,1748881806.468 [Startup] Running Loop=1
2025-06-02T16:30:06.468Z,1748881806.468 [Startup](DEBUG): Aggregate::initialize Startup
2025-06-02T16:30:06.468Z,1748881806.468 [Startup:A.GoToSurface] Running Loop=1
2025-06-02T16:30:06.468Z,1748881806.468 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-02T16:30:06.469Z,1748881806.469 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-06-02T16:30:06.469Z,1748881806.469 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-06-02T16:30:06.470Z,1748881806.470 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-06-02T16:30:06.470Z,1748881806.470 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-06-02T16:30:06.470Z,1748881806.470 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-02T16:30:06.471Z,1748881806.471 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-02T16:30:06.477Z,1748881806.477 [Startup:StartupSatComms] Running Loop=1
2025-06-02T16:30:06.477Z,1748881806.477 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2025-06-02T16:30:06.477Z,1748881806.477 [Startup:StartupSatComms:A] Running Loop=1
2025-06-02T16:30:06.494Z,1748881806.494 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-02T16:30:06.842Z,1748881806.842 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2025-06-02T16:30:06.852Z,1748881806.852 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-02T16:30:06.852Z,1748881806.852 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2025-06-02T16:31:06.631Z,1748881866.631 [Startup:StartupSatComms:A](INFO): Timed out from 2025-06-02T16:30:06.5Z
2025-06-02T16:31:06.631Z,1748881866.631 [Startup:StartupSatComms:A] Stopped
2025-06-02T16:31:06.631Z,1748881866.631 [Startup:StartupSatComms:B] Running Loop=1
2025-06-02T16:31:07.037Z,1748881867.037 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-06-02T16:31:13.465Z,1748881873.465 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250602T152429/Courier0037.lzma
2025-06-02T16:31:14.467Z,1748881874.467 [DataOverHttps](INFO): Moved sent file to Logs/20250602T152429/Courier0037.lzma.bak
2025-06-02T16:31:14.467Z,1748881874.467 [DataOverHttps](INFO): SBD MOMSN=25073065
2025-06-02T16:31:30.104Z,1748881890.104 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250602T162652/Courier0000.lzma
2025-06-02T16:31:31.106Z,1748881891.106 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0000.lzma.bak
2025-06-02T16:31:31.106Z,1748881891.106 [DataOverHttps](INFO): SBD MOMSN=25073067
2025-06-02T16:31:47.401Z,1748881907.401 [DataOverHttps](INFO): Sending 160 bytes from file Logs/20250602T152429/Express0038.lzma
2025-06-02T16:31:48.402Z,1748881908.402 [DataOverHttps](INFO): Moved sent file to Logs/20250602T152429/Express0038.lzma.bak
2025-06-02T16:31:48.402Z,1748881908.402 [DataOverHttps](INFO): SBD MOMSN=25073070
2025-06-02T16:32:04.438Z,1748881924.438 [DataOverHttps](INFO): Sending 922 bytes from file Logs/20250602T162652/Express0001.lzma
2025-06-02T16:32:05.438Z,1748881925.438 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0001.lzma.bak
2025-06-02T16:32:05.438Z,1748881925.438 [DataOverHttps](INFO): SBD MOMSN=25073074
2025-06-02T16:32:06.831Z,1748881926.831 [Startup:StartupSatComms:B](INFO): Timed out from 2025-06-02T16:31:06.6Z
2025-06-02T16:32:06.831Z,1748881926.831 [Startup:StartupSatComms:B] Stopped
2025-06-02T16:32:06.831Z,1748881926.831 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2025-06-02T16:32:06.831Z,1748881926.831 [Startup:StartupSatComms] Stopped
2025-06-02T16:32:06.831Z,1748881926.831 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2025-06-02T16:32:06.832Z,1748881926.832 [Startup](INFO): Completed Startup
2025-06-02T16:32:06.832Z,1748881926.832 [MissionManager](INFO): Startup is completed.
2025-06-02T16:32:06.833Z,1748881926.833 [MissionManager](INFO): Uninitializing Mission Startup
2025-06-02T16:32:06.833Z,1748881926.833 [Startup] Stopped
2025-06-02T16:32:06.833Z,1748881926.833 [Startup](DEBUG): Aggregate::uninitialize Startup
2025-06-02T16:32:06.833Z,1748881926.833 [Startup:A.GoToSurface] Stopped
2025-06-02T16:32:06.833Z,1748881926.833 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-06-02T16:32:07.245Z,1748881927.245 [MissionManager](IMPORTANT): Started mission Default
2025-06-02T16:32:07.245Z,1748881927.245 [Default] Running Loop=1
2025-06-02T16:32:07.245Z,1748881927.245 [Default](DEBUG): Aggregate::initialize Default
2025-06-02T16:32:07.245Z,1748881927.245 [Default:B.GoToSurface] Running Loop=1
2025-06-02T16:32:07.245Z,1748881927.245 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-02T16:32:07.245Z,1748881927.245 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-06-02T16:32:07.246Z,1748881927.246 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-06-02T16:32:07.246Z,1748881927.246 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-06-02T16:32:07.246Z,1748881927.246 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-06-02T16:32:07.246Z,1748881927.246 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-02T16:32:07.247Z,1748881927.247 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-02T16:32:07.247Z,1748881927.247 [Default:A.Wait] Running Loop=1
2025-06-02T16:32:07.247Z,1748881927.247 [Default:A.Wait](DEBUG): Initialize Wait Component.
2025-06-02T16:32:20.634Z,1748881940.634 [Default:A.Wait](INFO): Done Waiting.
2025-06-02T16:32:20.634Z,1748881940.634 [Default:A.Wait] Stopped
2025-06-02T16:32:20.634Z,1748881940.634 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T16:32:20.966Z,1748881940.966 [Default:CheckIn] Running Loop=1
2025-06-02T16:32:20.966Z,1748881940.966 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T16:32:20.966Z,1748881940.966 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T16:32:21.373Z,1748881941.373 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-06-02T16:32:49.643Z,1748881969.643 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-02T16:33:07.434Z,1748881987.434 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2025-06-02T16:33:07.434Z,1748881987.434 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-02T16:33:07.445Z,1748881987.445 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-02T16:33:07.865Z,1748881987.865 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-02T16:33:07.865Z,1748881987.865 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2025-06-02T16:33:16.313Z,1748881996.313 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-06-02T16:33:16.314Z,1748881996.314 [BPC1](INFO): Calculating totals. Valid battery stick count: 51. Valid reserve battery stick count: 5.
2025-06-02T16:33:16.317Z,1748881996.317 [BPC1](INFO): Received data from all battery sticks.
2025-06-02T16:35:16.573Z,1748882116.573 [DataOverHttps](IMPORTANT): SBD MTMSN=20250602T163516
2025-06-02T16:35:23.908Z,1748882123.908 [DataOverHttps](INFO): Received command: strobe off
2025-06-02T16:35:23.929Z,1748882123.929 [CommandExec](IMPORTANT): got command strobe off
2025-06-02T16:35:23.930Z,1748882123.930 [CommandExec](IMPORTANT): Deactivating strobe
2025-06-02T16:35:24.910Z,1748882124.910 [DataOverHttps](IMPORTANT): SBD MTMSN=20250602T163524
2025-06-02T16:35:32.696Z,1748882132.696 [DataOverHttps](INFO): Received command: ! echo i > /dev/loadB4
2025-06-02T16:35:32.718Z,1748882132.718 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB4
2025-06-02T16:36:08.424Z,1748882168.424 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2025-06-02T16:36:08.425Z,1748882168.425 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-02T16:36:08.435Z,1748882168.435 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-02T16:36:08.844Z,1748882168.844 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-02T16:36:08.844Z,1748882168.844 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2025-06-02T16:37:21.161Z,1748882241.161 [Default:CheckIn:Read_GPS](INFO): Timed out from 2025-06-02T16:32:20.0Z
2025-06-02T16:37:21.161Z,1748882241.161 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T16:37:21.161Z,1748882241.161 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T16:37:21.554Z,1748882241.554 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2025-06-02T16:37:28.176Z,1748882248.176 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250602T162652/Courier0004.lzma
2025-06-02T16:37:29.178Z,1748882249.178 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0004.lzma.bak
2025-06-02T16:37:29.178Z,1748882249.178 [DataOverHttps](INFO): SBD MOMSN=25073153
2025-06-02T16:37:46.679Z,1748882266.679 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20250602T162652/Courier0007.lzma
2025-06-02T16:37:47.682Z,1748882267.682 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0007.lzma.bak
2025-06-02T16:37:47.682Z,1748882267.682 [DataOverHttps](INFO): SBD MOMSN=25073155
2025-06-02T16:37:47.818Z,1748882267.818 [NAL9602](FAULT): GPS failed to acquire within timeout.
2025-06-02T16:37:47.819Z,1748882267.819 [NAL9602] Data Fault, FailCount= 1
2025-06-02T16:37:47.819Z,1748882267.819 [NAL9602](ERROR): Data Fault
2025-06-02T16:37:47.863Z,1748882267.863 [CBIT](ERROR): Data Fault in component: NAL9602
2025-06-02T16:37:48.222Z,1748882268.222 [NAL9602](INFO): Powering down
2025-06-02T16:37:49.048Z,1748882269.048 [CBIT](INFO): Clearing failed state for component NAL9602
2025-06-02T16:37:49.048Z,1748882269.048 [NAL9602] No Fault, FailCount= 1
2025-06-02T16:38:03.524Z,1748882283.524 [DataOverHttps](INFO): Sending 354 bytes from file Logs/20250602T162652/Express0005.lzma
2025-06-02T16:38:04.526Z,1748882284.526 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0005.lzma.bak
2025-06-02T16:38:04.526Z,1748882284.526 [DataOverHttps](INFO): SBD MOMSN=25073157
2025-06-02T16:38:05.600Z,1748882285.600 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T16:38:05.600Z,1748882285.600 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T16:38:05.600Z,1748882285.600 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T16:38:18.523Z,1748882298.523 [NAL9602](INFO): Powering up NAL9602
2025-06-02T16:38:29.433Z,1748882309.433 [NAL9602](INFO): NAL9602 initialized
2025-06-02T16:39:09.456Z,1748882349.456 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2025-06-02T16:39:09.456Z,1748882349.456 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-02T16:39:09.475Z,1748882349.475 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-02T16:39:09.889Z,1748882349.889 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-02T16:39:09.889Z,1748882349.889 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2025-06-02T16:42:10.432Z,1748882530.432 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2025-06-02T16:42:10.432Z,1748882530.432 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2025-06-02T16:42:10.443Z,1748882530.443 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2025-06-02T16:42:10.851Z,1748882530.851 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2025-06-02T16:42:10.852Z,1748882530.852 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2025-06-02T16:43:06.182Z,1748882586.182 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T16:43:06.182Z,1748882586.182 [Default:CheckIn:C.Wait] Stopped
2025-06-02T16:43:06.182Z,1748882586.182 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T16:43:06.182Z,1748882586.182 [Default:CheckIn:D] Running Loop=1
2025-06-02T16:43:06.593Z,1748882586.593 [Default:CheckIn:D] Stopped
2025-06-02T16:43:06.593Z,1748882586.593 [Default:CheckIn:E] Running Loop=1
2025-06-02T16:43:07.008Z,1748882587.008 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.989143 min
2025-06-02T16:43:07.008Z,1748882587.008 [Default:CheckIn:E] Stopped
2025-06-02T16:43:07.008Z,1748882587.008 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T16:43:07.008Z,1748882587.008 [Default:CheckIn] Stopped
2025-06-02T16:43:07.008Z,1748882587.008 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T16:43:07.009Z,1748882587.009 [Default:CheckIn](INFO): Running loop #2
2025-06-02T16:43:07.009Z,1748882587.009 [Default:CheckIn] Running Loop=2
2025-06-02T16:43:07.009Z,1748882587.009 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T16:43:07.009Z,1748882587.009 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T16:44:08.399Z,1748882648.399 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164405.00,A,3648.13109,N,12147.26906,W,0.350,206.22,020625,,,A*76
2025-06-02T16:44:08.403Z,1748882648.403 [NAL9602](INFO): GPS fix at 20250602T164405: (36.802185, -121.787818)
2025-06-02T16:44:08.414Z,1748882648.414 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T16:44:08.414Z,1748882648.414 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T16:44:16.316Z,1748882656.316 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20250602T162652/Courier0010.lzma
2025-06-02T16:44:17.318Z,1748882657.318 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0010.lzma.bak
2025-06-02T16:44:17.318Z,1748882657.318 [DataOverHttps](INFO): SBD MOMSN=25073173
2025-06-02T16:44:35.872Z,1748882675.872 [DataOverHttps](INFO): Sending 429 bytes from file Logs/20250602T162652/Express0011.lzma
2025-06-02T16:44:36.874Z,1748882676.874 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0011.lzma.bak
2025-06-02T16:44:36.874Z,1748882676.874 [DataOverHttps](INFO): SBD MOMSN=25073176
2025-06-02T16:44:37.915Z,1748882677.915 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T16:44:37.915Z,1748882677.915 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T16:44:37.915Z,1748882677.915 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T16:44:40.727Z,1748882680.727 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T16:49:38.492Z,1748882978.492 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T16:49:38.492Z,1748882978.492 [Default:CheckIn:C.Wait] Stopped
2025-06-02T16:49:38.492Z,1748882978.492 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T16:49:38.493Z,1748882978.493 [Default:CheckIn:D] Running Loop=1
2025-06-02T16:49:38.902Z,1748882978.902 [Default:CheckIn:D] Stopped
2025-06-02T16:49:38.902Z,1748882978.902 [Default:CheckIn:E] Running Loop=1
2025-06-02T16:49:39.298Z,1748882979.298 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.527625 min
2025-06-02T16:49:39.298Z,1748882979.298 [Default:CheckIn:E] Stopped
2025-06-02T16:49:39.298Z,1748882979.298 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T16:49:39.298Z,1748882979.298 [Default:CheckIn] Stopped
2025-06-02T16:49:39.298Z,1748882979.298 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T16:49:39.299Z,1748882979.299 [Default:CheckIn](INFO): Running loop #3
2025-06-02T16:49:39.299Z,1748882979.299 [Default:CheckIn] Running Loop=3
2025-06-02T16:49:39.299Z,1748882979.299 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T16:49:39.299Z,1748882979.299 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T16:49:41.310Z,1748882981.310 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164941.00,A,3648.15620,N,12147.28208,W,0.311,0.00,020625,,,A*7B
2025-06-02T16:49:41.312Z,1748882981.312 [NAL9602](INFO): GPS fix at 20250602T164941: (36.802603, -121.788035)
2025-06-02T16:49:41.322Z,1748882981.322 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T16:49:41.323Z,1748882981.323 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T16:49:48.879Z,1748882988.879 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250602T162652/Courier0013.lzma
2025-06-02T16:49:49.882Z,1748882989.882 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0013.lzma.bak
2025-06-02T16:49:49.882Z,1748882989.882 [DataOverHttps](INFO): SBD MOMSN=25073234
2025-06-02T16:50:05.852Z,1748883005.852 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20250602T162652/Express0014.lzma
2025-06-02T16:50:06.855Z,1748883006.855 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0014.lzma.bak
2025-06-02T16:50:06.855Z,1748883006.855 [DataOverHttps](INFO): SBD MOMSN=25073237
2025-06-02T16:50:08.011Z,1748883008.011 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T16:50:08.011Z,1748883008.011 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T16:50:08.012Z,1748883008.012 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T16:54:43.901Z,1748883283.901 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-02T16:55:08.558Z,1748883308.558 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T16:55:08.558Z,1748883308.558 [Default:CheckIn:C.Wait] Stopped
2025-06-02T16:55:08.558Z,1748883308.558 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T16:55:08.558Z,1748883308.558 [Default:CheckIn:D] Running Loop=1
2025-06-02T16:55:08.969Z,1748883308.969 [Default:CheckIn:D] Stopped
2025-06-02T16:55:08.969Z,1748883308.969 [Default:CheckIn:E] Running Loop=1
2025-06-02T16:55:09.362Z,1748883309.362 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.028733 min
2025-06-02T16:55:09.362Z,1748883309.362 [Default:CheckIn:E] Stopped
2025-06-02T16:55:09.362Z,1748883309.362 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T16:55:09.362Z,1748883309.362 [Default:CheckIn] Stopped
2025-06-02T16:55:09.362Z,1748883309.362 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T16:55:09.362Z,1748883309.362 [Default:CheckIn](INFO): Running loop #4
2025-06-02T16:55:09.362Z,1748883309.362 [Default:CheckIn] Running Loop=4
2025-06-02T16:55:09.363Z,1748883309.363 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T16:55:09.363Z,1748883309.363 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T16:55:11.377Z,1748883311.377 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165511.00,A,3648.16184,N,12147.29157,W,0.544,18.59,020625,,,A*42
2025-06-02T16:55:11.380Z,1748883311.380 [NAL9602](INFO): GPS fix at 20250602T165511: (36.802697, -121.788193)
2025-06-02T16:55:11.390Z,1748883311.390 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T16:55:11.390Z,1748883311.390 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T16:55:19.303Z,1748883319.303 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0016.lzma
2025-06-02T16:55:20.306Z,1748883320.306 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0016.lzma.bak
2025-06-02T16:55:20.306Z,1748883320.306 [DataOverHttps](INFO): SBD MOMSN=25073246
2025-06-02T16:55:38.168Z,1748883338.168 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20250602T162652/Express0017.lzma
2025-06-02T16:55:39.170Z,1748883339.170 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0017.lzma.bak
2025-06-02T16:55:39.170Z,1748883339.170 [DataOverHttps](INFO): SBD MOMSN=25073256
2025-06-02T16:55:40.489Z,1748883340.489 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T16:55:40.489Z,1748883340.489 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T16:55:40.489Z,1748883340.489 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T16:55:43.701Z,1748883343.701 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:00:41.082Z,1748883641.082 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:00:41.082Z,1748883641.082 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:00:41.082Z,1748883641.082 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:00:41.082Z,1748883641.082 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:00:41.473Z,1748883641.473 [Default:CheckIn:D] Stopped
2025-06-02T17:00:41.473Z,1748883641.473 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:00:41.877Z,1748883641.877 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.570475 min
2025-06-02T17:00:41.877Z,1748883641.877 [Default:CheckIn:E] Stopped
2025-06-02T17:00:41.877Z,1748883641.878 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:00:41.878Z,1748883641.878 [Default:CheckIn] Stopped
2025-06-02T17:00:41.878Z,1748883641.878 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:00:41.878Z,1748883641.878 [Default:CheckIn](INFO): Running loop #5
2025-06-02T17:00:41.878Z,1748883641.878 [Default:CheckIn] Running Loop=5
2025-06-02T17:00:41.878Z,1748883641.878 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:00:41.878Z,1748883641.878 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:00:43.896Z,1748883643.896 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170043.00,A,3648.16354,N,12147.28959,W,0.894,200.73,020625,,,A*7F
2025-06-02T17:00:43.898Z,1748883643.898 [NAL9602](INFO): GPS fix at 20250602T170043: (36.802726, -121.788160)
2025-06-02T17:00:43.909Z,1748883643.909 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:00:43.909Z,1748883643.909 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:00:51.251Z,1748883651.251 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0019.lzma
2025-06-02T17:00:52.254Z,1748883652.254 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0019.lzma.bak
2025-06-02T17:00:52.254Z,1748883652.254 [DataOverHttps](INFO): SBD MOMSN=25073308
2025-06-02T17:01:08.124Z,1748883668.124 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20250602T162652/Express0020.lzma
2025-06-02T17:01:09.126Z,1748883669.126 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0020.lzma.bak
2025-06-02T17:01:09.126Z,1748883669.126 [DataOverHttps](INFO): SBD MOMSN=25073311
2025-06-02T17:01:10.178Z,1748883670.178 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:01:10.178Z,1748883670.178 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:01:10.178Z,1748883670.178 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:05:45.695Z,1748883945.695 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2025-06-02T17:06:10.753Z,1748883970.753 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:06:10.753Z,1748883970.753 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:06:10.753Z,1748883970.753 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:06:10.753Z,1748883970.753 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:06:11.164Z,1748883971.164 [Default:CheckIn:D] Stopped
2025-06-02T17:06:11.164Z,1748883971.164 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:06:11.558Z,1748883971.558 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.065322 min
2025-06-02T17:06:11.558Z,1748883971.558 [Default:CheckIn:E] Stopped
2025-06-02T17:06:11.558Z,1748883971.558 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:06:11.558Z,1748883971.558 [Default:CheckIn] Stopped
2025-06-02T17:06:11.558Z,1748883971.558 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:06:11.558Z,1748883971.558 [Default:CheckIn](INFO): Running loop #6
2025-06-02T17:06:11.558Z,1748883971.558 [Default:CheckIn] Running Loop=6
2025-06-02T17:06:11.559Z,1748883971.559 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:06:11.559Z,1748883971.559 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:06:13.573Z,1748883973.573 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170613.00,A,3648.16613,N,12147.28364,W,0.816,39.81,020625,,,A*41
2025-06-02T17:06:13.575Z,1748883973.575 [NAL9602](INFO): GPS fix at 20250602T170613: (36.802769, -121.788061)
2025-06-02T17:06:13.586Z,1748883973.586 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:06:13.586Z,1748883973.586 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:06:21.579Z,1748883981.579 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0022.lzma
2025-06-02T17:06:22.582Z,1748883982.582 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0022.lzma.bak
2025-06-02T17:06:22.582Z,1748883982.582 [DataOverHttps](INFO): SBD MOMSN=25073373
2025-06-02T17:06:38.537Z,1748883998.537 [DataOverHttps](INFO): Sending 252 bytes from file Logs/20250602T162652/Express0023.lzma
2025-06-02T17:06:39.538Z,1748883999.538 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0023.lzma.bak
2025-06-02T17:06:39.538Z,1748883999.538 [DataOverHttps](INFO): SBD MOMSN=25073376
2025-06-02T17:06:40.651Z,1748884000.651 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:06:40.651Z,1748884000.651 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:06:40.651Z,1748884000.651 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:06:45.890Z,1748884005.890 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:11:41.223Z,1748884301.223 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:11:41.223Z,1748884301.223 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:11:41.223Z,1748884301.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:11:41.223Z,1748884301.223 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:11:41.633Z,1748884301.633 [Default:CheckIn:D] Stopped
2025-06-02T17:11:41.634Z,1748884301.634 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.573145 min
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn:E] Stopped
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn] Stopped
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn](INFO): Running loop #7
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn] Running Loop=7
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:11:42.030Z,1748884302.030 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:11:44.041Z,1748884304.041 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171143.00,A,3648.14507,N,12147.25474,W,2.099,168.47,020625,,,A*7F
2025-06-02T17:11:44.044Z,1748884304.044 [NAL9602](INFO): GPS fix at 20250602T171143: (36.802418, -121.787579)
2025-06-02T17:11:44.054Z,1748884304.054 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:11:44.054Z,1748884304.054 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:11:51.595Z,1748884311.595 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0025.lzma
2025-06-02T17:11:52.598Z,1748884312.598 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0025.lzma.bak
2025-06-02T17:11:52.598Z,1748884312.598 [DataOverHttps](INFO): SBD MOMSN=25073386
2025-06-02T17:12:02.232Z,1748884322.232 [NAL9602](INFO): SBD MO Status=2, MOMSN=20820, MT Status=2, MTMSN=0
2025-06-02T17:12:02.233Z,1748884322.233 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T17:12:08.716Z,1748884328.716 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20250602T162652/Express0026.lzma
2025-06-02T17:12:09.718Z,1748884329.718 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0026.lzma.bak
2025-06-02T17:12:09.718Z,1748884329.718 [DataOverHttps](INFO): SBD MOMSN=25073389
2025-06-02T17:12:10.756Z,1748884330.756 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:12:10.756Z,1748884330.756 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:12:10.756Z,1748884330.756 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:12:33.743Z,1748884353.743 [NAL9602](INFO): SBD MO Status=2, MOMSN=20820, MT Status=2, MTMSN=0
2025-06-02T17:12:33.755Z,1748884353.755 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T17:12:44.238Z,1748884364.238 [NAL9602](INFO): SBD MO Status=0, MOMSN=20820, MT Status=0, MTMSN=0
2025-06-02T17:12:44.239Z,1748884364.239 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:12:48.861Z,1748884368.861 [DataOverHttps](IMPORTANT): SBD MTMSN=20250602T171248
2025-06-02T17:12:56.396Z,1748884376.396 [DataOverHttps](INFO): Received command: ibit
2025-06-02T17:12:56.453Z,1748884376.453 [CommandExec](IMPORTANT): got command ibit
2025-06-02T17:12:56.782Z,1748884376.782 [IBIT](IMPORTANT): Beginning Initiated BIT
2025-06-02T17:12:56.782Z,1748884376.782 [IBIT](IMPORTANT): Beginning control surface checks.
2025-06-02T17:12:56.786Z,1748884376.786 [GFScanner](IMPORTANT): Beginning ground fault scan
2025-06-02T17:12:57.397Z,1748884377.397 [DataOverHttps](IMPORTANT): SBD MTMSN=20250602T171257
2025-06-02T17:12:58.383Z,1748884378.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171258.00,A,3648.13912,N,12147.24128,W,0.097,108.91,020625,,,D*70
2025-06-02T17:12:58.385Z,1748884378.385 [NAL9602](INFO): GPS fix at 20250602T171258: (36.802319, -121.787355)
2025-06-02T17:13:01.420Z,1748884381.420 [GFScanner](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007131
CHAN A1 (24V): 0.003110
CHAN A2 (12V): -0.005147
CHAN A3 (5V): -0.002434
CHAN B0 (3.3V): -0.001104
CHAN B1 (3.15aV): -0.001223
CHAN B2 (3.15bV): -0.000956
CHAN B3 (GND): -0.000097
OPEN: 0.006701
Full Scale: +/- 1 mA
2025-06-02T17:13:01.615Z,1748884381.615 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171301.00,A,3648.13880,N,12147.24024,W,2.022,110.79,020625,,,D*79
2025-06-02T17:13:01.617Z,1748884381.617 [NAL9602](INFO): GPS fix at 20250602T171301: (36.802313, -121.787337)
2025-06-02T17:13:04.437Z,1748884384.437 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171304.00,A,3648.13750,N,12147.23880,W,2.022,136.47,020625,,,D*76
2025-06-02T17:13:04.439Z,1748884384.439 [NAL9602](INFO): GPS fix at 20250602T171304: (36.802292, -121.787313)
2025-06-02T17:13:05.132Z,1748884385.132 [DataOverHttps](INFO): Received command: failc
2025-06-02T17:13:05.140Z,1748884385.140 [CommandExec](IMPORTANT): got command failComponent
2025-06-02T17:13:05.141Z,1748884385.141 [CommandExec](IMPORTANT): Failed components:
2025-06-02T17:13:05.141Z,1748884385.141 [CommandExec](IMPORTANT): No failed Components.
2025-06-02T17:13:07.265Z,1748884387.265 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171307.00,A,3648.13690,N,12147.23736,W,1.575,115.33,020625,,,D*7C
2025-06-02T17:13:07.267Z,1748884387.267 [NAL9602](INFO): GPS fix at 20250602T171307: (36.802282, -121.787289)
2025-06-02T17:13:10.502Z,1748884390.502 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171310.00,A,3648.13718,N,12147.23579,W,0.836,89.02,020625,,,D*4F
2025-06-02T17:13:10.504Z,1748884390.504 [NAL9602](INFO): GPS fix at 20250602T171310: (36.802286, -121.787263)
2025-06-02T17:13:13.333Z,1748884393.333 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171313.00,A,3648.13782,N,12147.23487,W,0.525,54.29,020625,,,D*49
2025-06-02T17:13:13.335Z,1748884393.335 [NAL9602](INFO): GPS fix at 20250602T171313: (36.802297, -121.787248)
2025-06-02T17:13:16.564Z,1748884396.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171316.00,A,3648.13872,N,12147.23401,W,1.477,34.11,020625,,,D*48
2025-06-02T17:13:16.566Z,1748884396.566 [NAL9602](INFO): GPS fix at 20250602T171316: (36.802312, -121.787233)
2025-06-02T17:13:19.391Z,1748884399.391 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171319.00,A,3648.13904,N,12147.23363,W,0.272,34.11,020625,,,D*46
2025-06-02T17:13:19.394Z,1748884399.394 [NAL9602](INFO): GPS fix at 20250602T171319: (36.802317, -121.787227)
2025-06-02T17:13:22.625Z,1748884402.625 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171322.00,A,3648.13982,N,12147.23297,W,1.477,29.32,020625,,,D*45
2025-06-02T17:13:22.627Z,1748884402.627 [NAL9602](INFO): GPS fix at 20250602T171322: (36.802330, -121.787216)
2025-06-02T17:13:25.451Z,1748884405.451 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171325.00,A,3648.14148,N,12147.23161,W,2.449,33.15,020625,,,D*41
2025-06-02T17:13:25.453Z,1748884405.453 [NAL9602](INFO): GPS fix at 20250602T171325: (36.802358, -121.787194)
2025-06-02T17:13:28.282Z,1748884408.282 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171328.00,A,3648.14312,N,12147.22998,W,2.410,37.28,020625,,,D*48
2025-06-02T17:13:28.295Z,1748884408.295 [NAL9602](INFO): GPS fix at 20250602T171328: (36.802385, -121.787166)
2025-06-02T17:13:31.507Z,1748884411.507 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171331.00,A,3648.14499,N,12147.22926,W,2.041,19.71,020625,,,D*41
2025-06-02T17:13:31.509Z,1748884411.509 [NAL9602](INFO): GPS fix at 20250602T171331: (36.802416, -121.787154)
2025-06-02T17:13:34.359Z,1748884414.359 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171334.00,A,3648.14644,N,12147.22810,W,1.944,35.50,020625,,,D*40
2025-06-02T17:13:34.361Z,1748884414.361 [NAL9602](INFO): GPS fix at 20250602T171334: (36.802441, -121.787135)
2025-06-02T17:13:37.589Z,1748884417.589 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171337.00,A,3648.14756,N,12147.22736,W,1.186,22.86,020625,,,D*41
2025-06-02T17:13:37.591Z,1748884417.591 [NAL9602](INFO): GPS fix at 20250602T171337: (36.802459, -121.787123)
2025-06-02T17:13:40.424Z,1748884420.424 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171340.00,A,3648.14777,N,12147.22704,W,0.058,22.86,020625,,,D*40
2025-06-02T17:13:40.426Z,1748884420.426 [NAL9602](INFO): GPS fix at 20250602T171340: (36.802463, -121.787117)
2025-06-02T17:13:43.249Z,1748884423.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171343.00,A,3648.14773,N,12147.22686,W,0.039,22.86,020625,,,D*4B
2025-06-02T17:13:43.252Z,1748884423.252 [NAL9602](INFO): GPS fix at 20250602T171343: (36.802462, -121.787114)
2025-06-02T17:13:43.269Z,1748884423.269 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 3
Latitude: 36.802464 Longitude: -121.787117
2025-06-02T17:13:43.724Z,1748884423.724 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.532000
2025-06-02T17:13:43.724Z,1748884423.724 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2025-06-02T17:13:43.724Z,1748884423.724 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2025-06-02T17:13:44.067Z,1748884424.067 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2025-06-02T17:13:44.067Z,1748884424.067 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2025-06-02T17:13:44.067Z,1748884424.067 [IBIT](IMPORTANT): Pressure:10.381582 PSI
2025-06-02T17:13:44.084Z,1748884424.084 [IBIT](IMPORTANT): Humidity:5.805152 %
2025-06-02T17:13:44.476Z,1748884424.476 [IBIT](IMPORTANT): Vehicle Pitch:-3.193623 degrees
2025-06-02T17:13:44.476Z,1748884424.476 [IBIT](IMPORTANT): Vehicle Roll:3.843026 degrees
2025-06-02T17:13:44.477Z,1748884424.477 [IBIT](IMPORTANT): Vehicle Heading:46.440758 degrees
2025-06-02T17:13:44.880Z,1748884424.880 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2025-06-02T17:13:44.881Z,1748884424.881 [IBIT](IMPORTANT): buoyancyNeutral: 266.500580 cc
2025-06-02T17:13:44.881Z,1748884424.881 [IBIT](IMPORTANT): massDefault: 2.648982 cm
2025-06-02T17:13:44.881Z,1748884424.881 [IBIT](IMPORTANT): stopDepth: 275.000000 m
2025-06-02T17:13:44.881Z,1748884424.881 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2025-06-02T17:13:44.882Z,1748884424.882 [IBIT](IMPORTANT): IBIT PASSED
2025-06-02T17:14:15.967Z,1748884455.967 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:17:11.351Z,1748884631.351 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:17:11.351Z,1748884631.351 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:17:11.351Z,1748884631.351 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:17:11.351Z,1748884631.351 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:17:11.738Z,1748884631.738 [Default:CheckIn:D] Stopped
2025-06-02T17:17:11.738Z,1748884631.738 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:17:12.146Z,1748884632.146 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.074882 min
2025-06-02T17:17:12.146Z,1748884632.146 [Default:CheckIn:E] Stopped
2025-06-02T17:17:12.146Z,1748884632.146 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:17:12.146Z,1748884632.146 [Default:CheckIn] Stopped
2025-06-02T17:17:12.146Z,1748884632.146 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:17:12.146Z,1748884632.146 [Default:CheckIn](INFO): Running loop #8
2025-06-02T17:17:12.147Z,1748884632.147 [Default:CheckIn] Running Loop=8
2025-06-02T17:17:12.147Z,1748884632.147 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:17:12.147Z,1748884632.147 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:17:14.156Z,1748884634.156 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171713.00,A,3648.14638,N,12147.21732,W,0.078,20.42,020625,,,D*46
2025-06-02T17:17:14.158Z,1748884634.158 [NAL9602](INFO): GPS fix at 20250602T171713: (36.802440, -121.786955)
2025-06-02T17:17:14.168Z,1748884634.168 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:17:14.169Z,1748884634.169 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:17:21.523Z,1748884641.523 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250602T162652/Courier0028.lzma
2025-06-02T17:17:22.527Z,1748884642.527 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0028.lzma.bak
2025-06-02T17:17:22.527Z,1748884642.527 [DataOverHttps](INFO): SBD MOMSN=25073453
2025-06-02T17:17:28.698Z,1748884648.698 [NAL9602](INFO): SBD MO Status=0, MOMSN=20821, MT Status=0, MTMSN=0
2025-06-02T17:17:28.699Z,1748884648.699 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:17:38.374Z,1748884658.374 [DataOverHttps](INFO): Sending 1159 bytes from file Logs/20250602T162652/Express0029.lzma
2025-06-02T17:17:39.374Z,1748884659.374 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0029.lzma.bak
2025-06-02T17:17:39.374Z,1748884659.374 [DataOverHttps](INFO): SBD MOMSN=25073456
2025-06-02T17:17:55.347Z,1748884675.347 [DataOverHttps](INFO): Sending 51 bytes from file Logs/20250602T162652/Express0032.lzma
2025-06-02T17:17:56.350Z,1748884676.350 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0032.lzma.bak
2025-06-02T17:17:56.350Z,1748884676.350 [DataOverHttps](INFO): SBD MOMSN=25073503
2025-06-02T17:17:57.407Z,1748884677.407 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:17:57.407Z,1748884677.407 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:17:57.408Z,1748884677.408 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:17:59.411Z,1748884679.411 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:22:58.037Z,1748884978.037 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:22:58.037Z,1748884978.037 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:22:58.037Z,1748884978.037 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:22:58.037Z,1748884978.037 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:22:58.434Z,1748884978.434 [Default:CheckIn:D] Stopped
2025-06-02T17:22:58.434Z,1748884978.434 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:22:58.837Z,1748884978.837 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.853145 min
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn:E] Stopped
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn] Stopped
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn](INFO): Running loop #9
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn] Running Loop=9
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:22:58.838Z,1748884978.838 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:23:00.854Z,1748884980.854 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172300.00,A,3648.14843,N,12147.22035,W,0.058,20.42,020625,,,D*40
2025-06-02T17:23:00.857Z,1748884980.857 [NAL9602](INFO): GPS fix at 20250602T172300: (36.802474, -121.787006)
2025-06-02T17:23:00.868Z,1748884980.868 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:23:00.868Z,1748884980.868 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:23:08.219Z,1748884988.219 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250602T162652/Courier0034.lzma
2025-06-02T17:23:09.222Z,1748884989.222 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0034.lzma.bak
2025-06-02T17:23:09.222Z,1748884989.222 [DataOverHttps](INFO): SBD MOMSN=25073513
2025-06-02T17:23:16.605Z,1748884996.605 [NAL9602](INFO): SBD MO Status=0, MOMSN=20822, MT Status=0, MTMSN=0
2025-06-02T17:23:16.605Z,1748884996.605 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:23:25.048Z,1748885005.048 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20250602T162652/Express0035.lzma
2025-06-02T17:23:26.050Z,1748885006.050 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0035.lzma.bak
2025-06-02T17:23:26.050Z,1748885006.050 [DataOverHttps](INFO): SBD MOMSN=25073519
2025-06-02T17:23:27.138Z,1748885007.138 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:23:27.138Z,1748885007.138 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:23:27.138Z,1748885007.138 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:23:47.313Z,1748885027.313 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:28:27.726Z,1748885307.726 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:28:27.726Z,1748885307.726 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:28:27.726Z,1748885307.726 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:28:27.726Z,1748885307.726 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:28:28.130Z,1748885308.130 [Default:CheckIn:D] Stopped
2025-06-02T17:28:28.130Z,1748885308.130 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:28:28.535Z,1748885308.535 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.348079 min
2025-06-02T17:28:28.535Z,1748885308.535 [Default:CheckIn:E] Stopped
2025-06-02T17:28:28.535Z,1748885308.535 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:28:28.536Z,1748885308.536 [Default:CheckIn] Stopped
2025-06-02T17:28:28.536Z,1748885308.536 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:28:28.536Z,1748885308.536 [Default:CheckIn](INFO): Running loop #10
2025-06-02T17:28:28.536Z,1748885308.536 [Default:CheckIn] Running Loop=10
2025-06-02T17:28:28.536Z,1748885308.536 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:28:28.536Z,1748885308.536 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:28:30.551Z,1748885310.551 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172830.00,A,3648.14966,N,12147.22197,W,0.039,20.42,020625,,,D*40
2025-06-02T17:28:30.554Z,1748885310.554 [NAL9602](INFO): GPS fix at 20250602T172830: (36.802494, -121.787033)
2025-06-02T17:28:30.564Z,1748885310.564 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:28:30.564Z,1748885310.564 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:28:38.043Z,1748885318.043 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0037.lzma
2025-06-02T17:28:39.046Z,1748885319.046 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0037.lzma.bak
2025-06-02T17:28:39.046Z,1748885319.046 [DataOverHttps](INFO): SBD MOMSN=25073577
2025-06-02T17:28:54.900Z,1748885334.900 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20250602T162652/Express0038.lzma
2025-06-02T17:28:55.903Z,1748885335.903 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0038.lzma.bak
2025-06-02T17:28:55.903Z,1748885335.903 [DataOverHttps](INFO): SBD MOMSN=25073586
2025-06-02T17:28:57.297Z,1748885337.297 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:28:57.297Z,1748885337.297 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:28:57.298Z,1748885337.298 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:29:24.768Z,1748885364.768 [NAL9602](INFO): SBD MO Status=2, MOMSN=20823, MT Status=2, MTMSN=0
2025-06-02T17:29:24.768Z,1748885364.768 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T17:30:04.777Z,1748885404.777 [NAL9602](INFO): SBD MO Status=2, MOMSN=20823, MT Status=2, MTMSN=0
2025-06-02T17:30:04.778Z,1748885404.778 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T17:30:35.903Z,1748885435.903 [NAL9602](INFO): SBD MO Status=0, MOMSN=20823, MT Status=0, MTMSN=0
2025-06-02T17:30:35.903Z,1748885435.903 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:31:06.613Z,1748885466.613 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:33:57.938Z,1748885637.938 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:33:57.938Z,1748885637.938 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:33:57.938Z,1748885637.938 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:33:57.938Z,1748885637.938 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:33:58.338Z,1748885638.338 [Default:CheckIn:D] Stopped
2025-06-02T17:33:58.339Z,1748885638.339 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:33:58.749Z,1748885638.749 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.851562 min
2025-06-02T17:33:58.749Z,1748885638.749 [Default:CheckIn:E] Stopped
2025-06-02T17:33:58.749Z,1748885638.749 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:33:58.749Z,1748885638.749 [Default:CheckIn] Stopped
2025-06-02T17:33:58.750Z,1748885638.750 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:33:58.750Z,1748885638.750 [Default:CheckIn](INFO): Running loop #11
2025-06-02T17:33:58.750Z,1748885638.750 [Default:CheckIn] Running Loop=11
2025-06-02T17:33:58.750Z,1748885638.750 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:33:58.750Z,1748885638.750 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:34:00.757Z,1748885640.757 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173400.00,A,3648.14955,N,12147.22385,W,0.039,20.42,020625,,,D*4F
2025-06-02T17:34:00.759Z,1748885640.759 [NAL9602](INFO): GPS fix at 20250602T173400: (36.802492, -121.787064)
2025-06-02T17:34:00.788Z,1748885640.788 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:34:00.789Z,1748885640.789 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:34:08.723Z,1748885648.723 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20250602T162652/Courier0040.lzma
2025-06-02T17:34:09.726Z,1748885649.726 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0040.lzma.bak
2025-06-02T17:34:09.726Z,1748885649.726 [DataOverHttps](INFO): SBD MOMSN=25073593
2025-06-02T17:34:10.449Z,1748885650.449 [NAL9602](INFO): SBD MO Status=0, MOMSN=20824, MT Status=0, MTMSN=0
2025-06-02T17:34:10.449Z,1748885650.449 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:34:25.786Z,1748885665.786 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20250602T162652/Express0041.lzma
2025-06-02T17:34:26.782Z,1748885666.782 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0041.lzma.bak
2025-06-02T17:34:26.782Z,1748885666.782 [DataOverHttps](INFO): SBD MOMSN=25073599
2025-06-02T17:34:27.838Z,1748885667.838 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:34:27.839Z,1748885667.839 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:34:27.839Z,1748885667.839 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:34:41.161Z,1748885681.161 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:39:28.427Z,1748885968.427 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:39:28.428Z,1748885968.428 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:39:28.428Z,1748885968.428 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:39:28.428Z,1748885968.428 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:39:28.843Z,1748885968.843 [Default:CheckIn:D] Stopped
2025-06-02T17:39:28.843Z,1748885968.843 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:39:29.235Z,1748885969.235 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.359965 min
2025-06-02T17:39:29.235Z,1748885969.235 [Default:CheckIn:E] Stopped
2025-06-02T17:39:29.235Z,1748885969.235 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:39:29.235Z,1748885969.235 [Default:CheckIn] Stopped
2025-06-02T17:39:29.235Z,1748885969.235 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:39:29.235Z,1748885969.235 [Default:CheckIn](INFO): Running loop #12
2025-06-02T17:39:29.235Z,1748885969.235 [Default:CheckIn] Running Loop=12
2025-06-02T17:39:29.236Z,1748885969.236 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:39:29.236Z,1748885969.236 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:39:31.250Z,1748885971.250 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173931.00,A,3648.15166,N,12147.22133,W,0.039,124.63,020625,,,D*70
2025-06-02T17:39:31.252Z,1748885971.252 [NAL9602](INFO): GPS fix at 20250602T173931: (36.802528, -121.787022)
2025-06-02T17:39:31.262Z,1748885971.262 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:39:31.262Z,1748885971.262 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:39:32.123Z,1748885972.123 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:39:32.148Z,1748885972.148 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:39:32.148Z,1748885972.148 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:40:12.498Z,1748886012.498 [NAL9602](INFO): SBD MO Status=2, MOMSN=20825, MT Status=2, MTMSN=0
2025-06-02T17:40:12.498Z,1748886012.498 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T17:40:32.315Z,1748886032.315 [NAL9602](INFO): SBD MO Status=0, MOMSN=20825, MT Status=0, MTMSN=0
2025-06-02T17:40:32.316Z,1748886032.316 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:40:54.530Z,1748886054.530 [BPC1](ERROR): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-06-02T17:40:54.531Z,1748886054.531 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2025-06-02T17:40:54.534Z,1748886054.534 [BPC1](INFO): Received data from all battery sticks.
2025-06-02T17:41:02.997Z,1748886062.997 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:44:32.701Z,1748886272.701 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:44:32.701Z,1748886272.701 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:44:32.701Z,1748886272.701 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:44:32.701Z,1748886272.701 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:44:33.115Z,1748886273.115 [Default:CheckIn:D] Stopped
2025-06-02T17:44:33.115Z,1748886273.115 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:44:33.509Z,1748886273.509 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.431169 min
2025-06-02T17:44:33.509Z,1748886273.509 [Default:CheckIn:E] Stopped
2025-06-02T17:44:33.509Z,1748886273.509 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:44:33.509Z,1748886273.509 [Default:CheckIn] Stopped
2025-06-02T17:44:33.510Z,1748886273.510 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:44:33.510Z,1748886273.510 [Default:CheckIn](INFO): Running loop #13
2025-06-02T17:44:33.510Z,1748886273.510 [Default:CheckIn] Running Loop=13
2025-06-02T17:44:33.510Z,1748886273.510 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:44:33.510Z,1748886273.510 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:44:35.512Z,1748886275.512 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174435.00,A,3648.15364,N,12147.21943,W,0.039,124.63,020625,,,D*72
2025-06-02T17:44:35.514Z,1748886275.514 [NAL9602](INFO): GPS fix at 20250602T174435: (36.802561, -121.786991)
2025-06-02T17:44:35.525Z,1748886275.525 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:44:35.526Z,1748886275.526 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:44:43.087Z,1748886283.087 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0043.lzma
2025-06-02T17:44:44.090Z,1748886284.090 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0043.lzma.bak
2025-06-02T17:44:44.090Z,1748886284.090 [DataOverHttps](INFO): SBD MOMSN=25073658
2025-06-02T17:45:00.012Z,1748886300.012 [DataOverHttps](INFO): Sending 90 bytes from file Logs/20250602T162652/Courier0046.lzma
2025-06-02T17:45:01.014Z,1748886301.014 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0046.lzma.bak
2025-06-02T17:45:01.014Z,1748886301.014 [DataOverHttps](INFO): SBD MOMSN=25073664
2025-06-02T17:45:17.129Z,1748886317.129 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20250602T162652/Express0044.lzma
2025-06-02T17:45:18.130Z,1748886318.130 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0044.lzma.bak
2025-06-02T17:45:18.130Z,1748886318.130 [DataOverHttps](INFO): SBD MOMSN=25073667
2025-06-02T17:45:23.207Z,1748886323.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=20826, MT Status=2, MTMSN=0
2025-06-02T17:45:23.207Z,1748886323.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T17:45:35.901Z,1748886335.901 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20250602T162652/Express0047.lzma
2025-06-02T17:45:36.902Z,1748886336.902 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0047.lzma.bak
2025-06-02T17:45:36.902Z,1748886336.902 [DataOverHttps](INFO): SBD MOMSN=25073670
2025-06-02T17:45:38.185Z,1748886338.185 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:45:38.186Z,1748886338.186 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:45:38.186Z,1748886338.186 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:46:09.293Z,1748886369.293 [NAL9602](INFO): SBD MO Status=2, MOMSN=20826, MT Status=2, MTMSN=0
2025-06-02T17:46:09.294Z,1748886369.294 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T17:46:58.574Z,1748886418.574 [NAL9602](INFO): SBD MO Status=0, MOMSN=20826, MT Status=0, MTMSN=0
2025-06-02T17:46:58.574Z,1748886418.574 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:47:29.281Z,1748886449.281 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:50:38.798Z,1748886638.798 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:50:38.798Z,1748886638.798 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:50:38.798Z,1748886638.798 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:50:38.798Z,1748886638.798 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:50:39.212Z,1748886639.212 [Default:CheckIn:D] Stopped
2025-06-02T17:50:39.212Z,1748886639.212 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:50:39.617Z,1748886639.617 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.532780 min
2025-06-02T17:50:39.617Z,1748886639.617 [Default:CheckIn:E] Stopped
2025-06-02T17:50:39.617Z,1748886639.617 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:50:39.617Z,1748886639.617 [Default:CheckIn] Stopped
2025-06-02T17:50:39.617Z,1748886639.617 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:50:39.617Z,1748886639.617 [Default:CheckIn](INFO): Running loop #14
2025-06-02T17:50:39.617Z,1748886639.617 [Default:CheckIn] Running Loop=14
2025-06-02T17:50:39.618Z,1748886639.618 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:50:39.618Z,1748886639.618 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:50:41.618Z,1748886641.618 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175041.00,A,3648.15644,N,12147.21617,W,0.039,124.63,020625,,,D*7D
2025-06-02T17:50:41.620Z,1748886641.620 [NAL9602](INFO): GPS fix at 20250602T175041: (36.802607, -121.786936)
2025-06-02T17:50:41.651Z,1748886641.651 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:50:41.651Z,1748886641.651 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:50:49.239Z,1748886649.239 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250602T162652/Courier0049.lzma
2025-06-02T17:50:50.242Z,1748886650.242 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0049.lzma.bak
2025-06-02T17:50:50.242Z,1748886650.242 [DataOverHttps](INFO): SBD MOMSN=25073728
2025-06-02T17:50:54.148Z,1748886654.148 [NAL9602](INFO): SBD MO Status=0, MOMSN=20827, MT Status=0, MTMSN=0
2025-06-02T17:50:54.148Z,1748886654.148 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:51:06.232Z,1748886666.232 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20250602T162652/Express0050.lzma
2025-06-02T17:51:07.234Z,1748886667.234 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0050.lzma.bak
2025-06-02T17:51:07.235Z,1748886667.235 [DataOverHttps](INFO): SBD MOMSN=25073731
2025-06-02T17:51:08.293Z,1748886668.293 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:51:08.293Z,1748886668.293 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:51:08.293Z,1748886668.293 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:51:24.845Z,1748886684.845 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T17:56:08.887Z,1748886968.887 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T17:56:08.887Z,1748886968.887 [Default:CheckIn:C.Wait] Stopped
2025-06-02T17:56:08.887Z,1748886968.887 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T17:56:08.887Z,1748886968.887 [Default:CheckIn:D] Running Loop=1
2025-06-02T17:56:09.276Z,1748886969.276 [Default:CheckIn:D] Stopped
2025-06-02T17:56:09.276Z,1748886969.276 [Default:CheckIn:E] Running Loop=1
2025-06-02T17:56:09.680Z,1748886969.680 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.033846 min
2025-06-02T17:56:09.680Z,1748886969.680 [Default:CheckIn:E] Stopped
2025-06-02T17:56:09.681Z,1748886969.681 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T17:56:09.681Z,1748886969.681 [Default:CheckIn] Stopped
2025-06-02T17:56:09.681Z,1748886969.681 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T17:56:09.681Z,1748886969.681 [Default:CheckIn](INFO): Running loop #15
2025-06-02T17:56:09.681Z,1748886969.681 [Default:CheckIn] Running Loop=15
2025-06-02T17:56:09.681Z,1748886969.681 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T17:56:09.681Z,1748886969.681 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T17:56:11.693Z,1748886971.693 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175611.00,A,3648.14730,N,12147.21933,W,0.175,67.07,020625,,,D*49
2025-06-02T17:56:11.695Z,1748886971.695 [NAL9602](INFO): GPS fix at 20250602T175611: (36.802455, -121.786989)
2025-06-02T17:56:11.705Z,1748886971.705 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T17:56:11.705Z,1748886971.705 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T17:56:19.739Z,1748886979.739 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0052.lzma
2025-06-02T17:56:20.742Z,1748886980.742 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0052.lzma.bak
2025-06-02T17:56:20.742Z,1748886980.742 [DataOverHttps](INFO): SBD MOMSN=25073741
2025-06-02T17:56:37.264Z,1748886997.264 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20250602T162652/Express0053.lzma
2025-06-02T17:56:38.266Z,1748886998.266 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0053.lzma.bak
2025-06-02T17:56:38.266Z,1748886998.266 [DataOverHttps](INFO): SBD MOMSN=25073744
2025-06-02T17:56:38.774Z,1748886998.774 [NAL9602](INFO): SBD MO Status=0, MOMSN=20828, MT Status=0, MTMSN=0
2025-06-02T17:56:38.774Z,1748886998.774 [NAL9602](INFO): No messages in MT queue
2025-06-02T17:56:39.590Z,1748886999.590 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T17:56:39.590Z,1748886999.590 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T17:56:39.590Z,1748886999.590 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T17:57:09.483Z,1748887029.483 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:01:40.166Z,1748887300.166 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:01:40.166Z,1748887300.166 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:01:40.166Z,1748887300.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:01:40.166Z,1748887300.166 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:01:40.573Z,1748887300.573 [Default:CheckIn:D] Stopped
2025-06-02T18:01:40.573Z,1748887300.573 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:01:40.982Z,1748887300.982 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.555469 min
2025-06-02T18:01:40.982Z,1748887300.982 [Default:CheckIn:E] Stopped
2025-06-02T18:01:40.982Z,1748887300.982 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:01:40.982Z,1748887300.982 [Default:CheckIn] Stopped
2025-06-02T18:01:40.982Z,1748887300.982 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:01:40.983Z,1748887300.983 [Default:CheckIn](INFO): Running loop #16
2025-06-02T18:01:40.983Z,1748887300.983 [Default:CheckIn] Running Loop=16
2025-06-02T18:01:40.983Z,1748887300.983 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:01:40.983Z,1748887300.983 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:01:42.986Z,1748887302.986 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180142.00,A,3648.14653,N,12147.21443,W,0.078,32.84,020625,,,D*4B
2025-06-02T18:01:42.988Z,1748887302.988 [NAL9602](INFO): GPS fix at 20250602T180142: (36.802442, -121.786907)
2025-06-02T18:01:42.998Z,1748887302.998 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:01:42.998Z,1748887302.998 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:01:50.475Z,1748887310.475 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250602T162652/Courier0055.lzma
2025-06-02T18:01:51.478Z,1748887311.478 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0055.lzma.bak
2025-06-02T18:01:51.478Z,1748887311.478 [DataOverHttps](INFO): SBD MOMSN=25073802
2025-06-02T18:02:04.402Z,1748887324.402 [NAL9602](INFO): SBD MO Status=0, MOMSN=20829, MT Status=0, MTMSN=0
2025-06-02T18:02:04.403Z,1748887324.403 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:02:07.636Z,1748887327.636 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20250602T162652/Express0056.lzma
2025-06-02T18:02:08.638Z,1748887328.638 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0056.lzma.bak
2025-06-02T18:02:08.638Z,1748887328.638 [DataOverHttps](INFO): SBD MOMSN=25073805
2025-06-02T18:02:09.699Z,1748887329.699 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:02:09.699Z,1748887329.699 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:02:09.699Z,1748887329.699 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:02:35.096Z,1748887355.096 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:07:10.234Z,1748887630.234 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:07:10.234Z,1748887630.234 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:07:10.234Z,1748887630.234 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:07:10.234Z,1748887630.234 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:07:10.635Z,1748887630.635 [Default:CheckIn:D] Stopped
2025-06-02T18:07:10.635Z,1748887630.635 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:07:11.043Z,1748887631.043 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.056502 min
2025-06-02T18:07:11.043Z,1748887631.043 [Default:CheckIn:E] Stopped
2025-06-02T18:07:11.044Z,1748887631.044 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:07:11.044Z,1748887631.044 [Default:CheckIn] Stopped
2025-06-02T18:07:11.044Z,1748887631.044 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:07:11.044Z,1748887631.044 [Default:CheckIn](INFO): Running loop #17
2025-06-02T18:07:11.044Z,1748887631.044 [Default:CheckIn] Running Loop=17
2025-06-02T18:07:11.044Z,1748887631.044 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:07:11.044Z,1748887631.044 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:07:13.054Z,1748887633.054 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180712.00,A,3648.14968,N,12147.22204,W,0.194,126.37,020625,,,D*76
2025-06-02T18:07:13.056Z,1748887633.056 [NAL9602](INFO): GPS fix at 20250602T180712: (36.802495, -121.787034)
2025-06-02T18:07:13.089Z,1748887633.089 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:07:13.089Z,1748887633.089 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:07:20.879Z,1748887640.879 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0058.lzma
2025-06-02T18:07:21.882Z,1748887641.882 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0058.lzma.bak
2025-06-02T18:07:21.882Z,1748887641.882 [DataOverHttps](INFO): SBD MOMSN=25073815
2025-06-02T18:07:37.988Z,1748887657.988 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20250602T162652/Express0059.lzma
2025-06-02T18:07:38.990Z,1748887658.990 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0059.lzma.bak
2025-06-02T18:07:38.990Z,1748887658.990 [DataOverHttps](INFO): SBD MOMSN=25073818
2025-06-02T18:07:40.133Z,1748887660.133 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:07:40.133Z,1748887660.133 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:07:40.133Z,1748887660.133 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:07:42.153Z,1748887662.153 [NAL9602](INFO): SBD MO Status=2, MOMSN=20830, MT Status=2, MTMSN=0
2025-06-02T18:07:42.154Z,1748887662.154 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T18:09:35.258Z,1748887775.258 [NAL9602](INFO): SBD MO Status=2, MOMSN=20830, MT Status=2, MTMSN=0
2025-06-02T18:09:35.259Z,1748887775.259 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T18:09:57.074Z,1748887797.074 [NAL9602](INFO): SBD MO Status=0, MOMSN=20830, MT Status=0, MTMSN=0
2025-06-02T18:09:57.074Z,1748887797.074 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:10:27.779Z,1748887827.779 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:12:40.720Z,1748887960.720 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:12:40.720Z,1748887960.720 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:12:40.720Z,1748887960.720 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:12:40.720Z,1748887960.720 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:12:41.105Z,1748887961.105 [Default:CheckIn:D] Stopped
2025-06-02T18:12:41.105Z,1748887961.105 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:12:41.514Z,1748887961.514 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.564339 min
2025-06-02T18:12:41.514Z,1748887961.514 [Default:CheckIn:E] Stopped
2025-06-02T18:12:41.514Z,1748887961.514 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:12:41.514Z,1748887961.514 [Default:CheckIn] Stopped
2025-06-02T18:12:41.515Z,1748887961.515 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:12:41.515Z,1748887961.515 [Default:CheckIn](INFO): Running loop #18
2025-06-02T18:12:41.515Z,1748887961.515 [Default:CheckIn] Running Loop=18
2025-06-02T18:12:41.515Z,1748887961.515 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:12:41.515Z,1748887961.515 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:12:43.525Z,1748887963.525 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181243.00,A,3648.15306,N,12147.21692,W,0.078,126.37,020625,,,D*7E
2025-06-02T18:12:43.527Z,1748887963.527 [NAL9602](INFO): GPS fix at 20250602T181243: (36.802551, -121.786949)
2025-06-02T18:12:43.538Z,1748887963.538 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:12:43.538Z,1748887963.538 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:12:51.263Z,1748887971.263 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0061.lzma
2025-06-02T18:12:52.266Z,1748887972.266 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0061.lzma.bak
2025-06-02T18:12:52.266Z,1748887972.266 [DataOverHttps](INFO): SBD MOMSN=25073878
2025-06-02T18:12:56.467Z,1748887976.467 [NAL9602](INFO): SBD MO Status=0, MOMSN=20831, MT Status=0, MTMSN=0
2025-06-02T18:12:56.467Z,1748887976.467 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:13:08.220Z,1748887988.220 [DataOverHttps](INFO): Sending 166 bytes from file Logs/20250602T162652/Express0062.lzma
2025-06-02T18:13:09.222Z,1748887989.222 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0062.lzma.bak
2025-06-02T18:13:09.222Z,1748887989.222 [DataOverHttps](INFO): SBD MOMSN=25073881
2025-06-02T18:13:10.608Z,1748887990.608 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:13:10.608Z,1748887990.608 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:13:10.608Z,1748887990.608 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:13:27.151Z,1748888007.151 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:18:11.187Z,1748888291.187 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:18:11.187Z,1748888291.187 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:18:11.187Z,1748888291.187 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:18:11.187Z,1748888291.187 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:18:11.596Z,1748888291.596 [Default:CheckIn:D] Stopped
2025-06-02T18:18:11.596Z,1748888291.596 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.072510 min
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn:E] Stopped
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn] Stopped
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn](INFO): Running loop #19
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn] Running Loop=19
2025-06-02T18:18:12.013Z,1748888292.013 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:18:12.014Z,1748888292.014 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:18:14.010Z,1748888294.010 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181813.00,A,3648.15089,N,12147.21766,W,0.233,126.37,020625,,,D*72
2025-06-02T18:18:14.013Z,1748888294.013 [NAL9602](INFO): GPS fix at 20250602T181813: (36.802515, -121.786961)
2025-06-02T18:18:14.024Z,1748888294.024 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:18:14.024Z,1748888294.024 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:18:21.671Z,1748888301.671 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0064.lzma
2025-06-02T18:18:22.674Z,1748888302.674 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0064.lzma.bak
2025-06-02T18:18:22.674Z,1748888302.674 [DataOverHttps](INFO): SBD MOMSN=25073891
2025-06-02T18:18:33.017Z,1748888313.017 [NAL9602](INFO): SBD MO Status=0, MOMSN=20832, MT Status=0, MTMSN=0
2025-06-02T18:18:33.017Z,1748888313.017 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:18:38.632Z,1748888318.632 [DataOverHttps](INFO): Sending 164 bytes from file Logs/20250602T162652/Express0065.lzma
2025-06-02T18:18:39.634Z,1748888319.634 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0065.lzma.bak
2025-06-02T18:18:39.634Z,1748888319.634 [DataOverHttps](INFO): SBD MOMSN=25073894
2025-06-02T18:18:40.688Z,1748888320.688 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:18:40.688Z,1748888320.688 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:18:40.688Z,1748888320.688 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:19:03.710Z,1748888343.710 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:23:41.274Z,1748888621.274 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:23:41.274Z,1748888621.274 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:23:41.275Z,1748888621.275 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:23:41.275Z,1748888621.275 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:23:41.686Z,1748888621.686 [Default:CheckIn:D] Stopped
2025-06-02T18:23:41.686Z,1748888621.686 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:23:42.085Z,1748888622.085 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.574015 min
2025-06-02T18:23:42.085Z,1748888622.085 [Default:CheckIn:E] Stopped
2025-06-02T18:23:42.085Z,1748888622.085 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:23:42.085Z,1748888622.085 [Default:CheckIn] Stopped
2025-06-02T18:23:42.085Z,1748888622.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:23:42.086Z,1748888622.086 [Default:CheckIn](INFO): Running loop #20
2025-06-02T18:23:42.086Z,1748888622.086 [Default:CheckIn] Running Loop=20
2025-06-02T18:23:42.086Z,1748888622.086 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:23:42.086Z,1748888622.086 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:23:44.090Z,1748888624.090 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182343.00,A,3648.18938,N,12147.17516,W,3.091,29.31,020625,,,D*40
2025-06-02T18:23:44.092Z,1748888624.092 [NAL9602](INFO): GPS fix at 20250602T182343: (36.803156, -121.786253)
2025-06-02T18:23:44.102Z,1748888624.102 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:23:44.102Z,1748888624.102 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:23:51.895Z,1748888631.895 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0067.lzma
2025-06-02T18:23:52.898Z,1748888632.898 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0067.lzma.bak
2025-06-02T18:23:52.898Z,1748888632.898 [DataOverHttps](INFO): SBD MOMSN=25073953
2025-06-02T18:24:01.461Z,1748888641.461 [NAL9602](INFO): SBD MO Status=0, MOMSN=20833, MT Status=0, MTMSN=0
2025-06-02T18:24:01.461Z,1748888641.461 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:24:08.756Z,1748888648.756 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250602T162652/Express0068.lzma
2025-06-02T18:24:09.758Z,1748888649.758 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0068.lzma.bak
2025-06-02T18:24:09.758Z,1748888649.758 [DataOverHttps](INFO): SBD MOMSN=25073956
2025-06-02T18:24:11.170Z,1748888651.170 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:24:11.170Z,1748888651.170 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:24:11.170Z,1748888651.170 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:24:32.165Z,1748888672.165 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:29:11.749Z,1748888951.749 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:29:11.749Z,1748888951.749 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:29:11.749Z,1748888951.749 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:29:11.749Z,1748888951.749 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:29:12.165Z,1748888952.165 [Default:CheckIn:D] Stopped
2025-06-02T18:29:12.165Z,1748888952.165 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.081999 min
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn:E] Stopped
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn] Stopped
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn](INFO): Running loop #21
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn] Running Loop=21
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:29:12.554Z,1748888952.554 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:29:14.563Z,1748888954.563 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182914.00,A,3648.49858,N,12147.24482,W,7.251,239.93,020625,,,D*76
2025-06-02T18:29:14.566Z,1748888954.566 [NAL9602](INFO): GPS fix at 20250602T182914: (36.808310, -121.787414)
2025-06-02T18:29:14.577Z,1748888954.577 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:29:14.577Z,1748888954.577 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:29:22.307Z,1748888962.307 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0070.lzma
2025-06-02T18:29:27.326Z,1748888967.326 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0070.lzma.bak
2025-06-02T18:29:27.326Z,1748888967.326 [DataOverHttps](INFO): SBD MOMSN=25073966
2025-06-02T18:29:45.288Z,1748888985.288 [NAL9602](INFO): SBD MO Status=0, MOMSN=20834, MT Status=0, MTMSN=0
2025-06-02T18:29:45.289Z,1748888985.289 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:29:45.372Z,1748888985.372 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20250602T162652/Express0071.lzma
2025-06-02T18:29:46.374Z,1748888986.374 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0071.lzma.bak
2025-06-02T18:29:46.374Z,1748888986.374 [DataOverHttps](INFO): SBD MOMSN=25073969
2025-06-02T18:29:47.721Z,1748888987.721 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:29:47.721Z,1748888987.721 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:29:47.721Z,1748888987.721 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:30:15.984Z,1748889015.984 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:34:48.326Z,1748889288.326 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:34:48.326Z,1748889288.326 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:34:48.326Z,1748889288.326 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:34:48.326Z,1748889288.326 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:34:48.718Z,1748889288.718 [Default:CheckIn:D] Stopped
2025-06-02T18:34:48.718Z,1748889288.718 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:34:49.127Z,1748889289.127 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.691219 min
2025-06-02T18:34:49.127Z,1748889289.127 [Default:CheckIn:E] Stopped
2025-06-02T18:34:49.127Z,1748889289.127 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:34:49.127Z,1748889289.127 [Default:CheckIn] Stopped
2025-06-02T18:34:49.128Z,1748889289.128 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:34:49.128Z,1748889289.128 [Default:CheckIn](INFO): Running loop #22
2025-06-02T18:34:49.128Z,1748889289.128 [Default:CheckIn] Running Loop=22
2025-06-02T18:34:49.128Z,1748889289.128 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:34:49.128Z,1748889289.128 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:34:51.139Z,1748889291.139 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183450.00,A,3648.18350,N,12148.36742,W,17.495,250.96,020625,,,D*4B
2025-06-02T18:34:51.141Z,1748889291.141 [NAL9602](INFO): GPS fix at 20250602T183450: (36.803058, -121.806124)
2025-06-02T18:34:51.152Z,1748889291.152 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:34:51.152Z,1748889291.152 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:34:59.055Z,1748889299.055 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0073.lzma
2025-06-02T18:35:00.058Z,1748889300.058 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0073.lzma.bak
2025-06-02T18:35:00.058Z,1748889300.058 [DataOverHttps](INFO): SBD MOMSN=25074028
2025-06-02T18:35:09.324Z,1748889309.324 [NAL9602](INFO): SBD MO Status=0, MOMSN=20835, MT Status=0, MTMSN=0
2025-06-02T18:35:09.324Z,1748889309.324 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:35:16.166Z,1748889316.166 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20250602T162652/Express0074.lzma
2025-06-02T18:35:17.162Z,1748889317.162 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0074.lzma.bak
2025-06-02T18:35:17.162Z,1748889317.162 [DataOverHttps](INFO): SBD MOMSN=25074031
2025-06-02T18:35:18.220Z,1748889318.220 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:35:18.220Z,1748889318.220 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:35:18.220Z,1748889318.220 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:35:40.033Z,1748889340.033 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:40:18.836Z,1748889618.836 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:40:18.837Z,1748889618.837 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:40:18.837Z,1748889618.837 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:40:18.837Z,1748889618.837 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:40:19.221Z,1748889619.221 [Default:CheckIn:D] Stopped
2025-06-02T18:40:19.221Z,1748889619.221 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:40:19.627Z,1748889619.627 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.199609 min
2025-06-02T18:40:19.628Z,1748889619.628 [Default:CheckIn:E] Stopped
2025-06-02T18:40:19.628Z,1748889619.628 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:40:19.628Z,1748889619.628 [Default:CheckIn] Stopped
2025-06-02T18:40:19.628Z,1748889619.628 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:40:19.628Z,1748889619.628 [Default:CheckIn](INFO): Running loop #23
2025-06-02T18:40:19.628Z,1748889619.628 [Default:CheckIn] Running Loop=23
2025-06-02T18:40:19.629Z,1748889619.629 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:40:19.629Z,1748889619.629 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:40:21.641Z,1748889621.641 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184021.00,A,3647.78429,N,12150.23952,W,14.909,258.73,020625,,,D*44
2025-06-02T18:40:21.643Z,1748889621.643 [NAL9602](INFO): GPS fix at 20250602T184021: (36.796405, -121.837325)
2025-06-02T18:40:21.658Z,1748889621.658 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:40:21.658Z,1748889621.658 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:40:29.668Z,1748889629.668 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20250602T162652/Courier0076.lzma
2025-06-02T18:40:30.670Z,1748889630.670 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0076.lzma.bak
2025-06-02T18:40:30.670Z,1748889630.670 [DataOverHttps](INFO): SBD MOMSN=25074042
2025-06-02T18:40:46.644Z,1748889646.644 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20250602T162652/Express0077.lzma
2025-06-02T18:40:47.647Z,1748889647.647 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0077.lzma.bak
2025-06-02T18:40:47.648Z,1748889647.648 [DataOverHttps](INFO): SBD MOMSN=25074051
2025-06-02T18:40:48.713Z,1748889648.713 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:40:48.714Z,1748889648.714 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:40:48.714Z,1748889648.714 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:41:02.842Z,1748889662.842 [NAL9602](INFO): SBD MO Status=0, MOMSN=20836, MT Status=0, MTMSN=0
2025-06-02T18:41:02.842Z,1748889662.842 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:41:33.549Z,1748889693.549 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:42:16.386Z,1748889736.386 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2025-06-02T18:45:49.291Z,1748889949.291 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2025-06-02T18:45:49.291Z,1748889949.291 [Default:CheckIn:C.Wait] Stopped
2025-06-02T18:45:49.291Z,1748889949.291 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2025-06-02T18:45:49.291Z,1748889949.291 [Default:CheckIn:D] Running Loop=1
2025-06-02T18:45:49.694Z,1748889949.694 [Default:CheckIn:D] Stopped
2025-06-02T18:45:49.694Z,1748889949.694 [Default:CheckIn:E] Running Loop=1
2025-06-02T18:45:50.100Z,1748889950.100 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.707487 min
2025-06-02T18:45:50.100Z,1748889950.100 [Default:CheckIn:E] Stopped
2025-06-02T18:45:50.101Z,1748889950.101 [Default:CheckIn](INFO): Completed Default:CheckIn
2025-06-02T18:45:50.101Z,1748889950.101 [Default:CheckIn] Stopped
2025-06-02T18:45:50.101Z,1748889950.101 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2025-06-02T18:45:50.101Z,1748889950.101 [Default:CheckIn](INFO): Running loop #24
2025-06-02T18:45:50.101Z,1748889950.101 [Default:CheckIn] Running Loop=24
2025-06-02T18:45:50.101Z,1748889950.101 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2025-06-02T18:45:50.101Z,1748889950.101 [Default:CheckIn:Read_GPS] Running Loop=1
2025-06-02T18:45:52.179Z,1748889952.179 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184551.00,A,3647.85362,N,12150.87001,W,1.089,44.82,020625,,,A*4C
2025-06-02T18:45:52.182Z,1748889952.182 [NAL9602](INFO): GPS fix at 20250602T184551: (36.797560, -121.847833)
2025-06-02T18:45:52.192Z,1748889952.192 [Default:CheckIn:Read_GPS] Stopped
2025-06-02T18:45:52.192Z,1748889952.192 [Default:CheckIn:Read_Iridium] Running Loop=1
2025-06-02T18:46:00.703Z,1748889960.703 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20250602T162652/Courier0079.lzma
2025-06-02T18:46:01.706Z,1748889961.706 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Courier0079.lzma.bak
2025-06-02T18:46:01.706Z,1748889961.706 [DataOverHttps](INFO): SBD MOMSN=25074103
2025-06-02T18:46:17.853Z,1748889977.853 [DataOverHttps](INFO): Sending 189 bytes from file Logs/20250602T162652/Express0080.lzma
2025-06-02T18:46:18.854Z,1748889978.854 [DataOverHttps](INFO): Moved sent file to Logs/20250602T162652/Express0080.lzma.bak
2025-06-02T18:46:18.854Z,1748889978.854 [DataOverHttps](INFO): SBD MOMSN=25074106
2025-06-02T18:46:20.032Z,1748889980.032 [Default:CheckIn:Read_Iridium] Stopped
2025-06-02T18:46:20.032Z,1748889980.032 [Default:CheckIn:C.Wait] Running Loop=1
2025-06-02T18:46:20.032Z,1748889980.032 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2025-06-02T18:46:27.266Z,1748889987.266 [NAL9602](INFO): SBD MO Status=2, MOMSN=20837, MT Status=2, MTMSN=0
2025-06-02T18:46:27.266Z,1748889987.266 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-02T18:47:12.175Z,1748890032.175 [NAL9602](INFO): SBD MO Status=0, MOMSN=20837, MT Status=0, MTMSN=0
2025-06-02T18:47:12.175Z,1748890032.175 [NAL9602](INFO): No messages in MT queue
2025-06-02T18:47:14.971Z,1748890034.971 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging
2025-06-02T18:47:42.827Z,1748890062.827 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-02T18:48:30.149Z,1748890110.149 [DataOverHttps](IMPORTANT): SBD MTMSN=20250602T184829
2025-06-02T18:48:32.517Z,1748890112.517 [BPC1](FAULT): Battery stick #2 (s/n: 0124) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2025-06-02T18:48:32.518Z,1748890112.518 [BPC1](INFO): Calculating totals. Valid battery stick count: 54. Valid reserve battery stick count: 6.
2025-06-02T18:48:32.521Z,1748890112.521 [BPC1](INFO): Received data from all battery sticks.
2025-06-02T18:48:37.819Z,1748890117.819 [DataOverHttps](INFO): Received command: restart logs