2023-07-05T18:07:40.387Z,1688580460.387 [Supervisor](DEBUG): Initializing supervisor.
2023-07-05T18:07:40.391Z,1688580460.391 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-07-05T18:07:40.392Z,1688580460.392 [SyncHandler](INFO): Protected caller Thread ID is 839
2023-07-05T18:07:40.392Z,1688580460.392 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-07-05T18:07:40.393Z,1688580460.393 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-07-05T18:07:40.393Z,1688580460.393 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840
2023-07-05T18:07:40.397Z,1688580460.397 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-07-05T18:07:40.415Z,1688580460.415 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-07-05T18:07:40.416Z,1688580460.416 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-07-05T18:07:40.417Z,1688580460.417 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841
2023-07-05T18:07:40.421Z,1688580460.421 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-07-05T18:07:40.422Z,1688580460.422 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-07-05T18:07:40.422Z,1688580460.422 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842
2023-07-05T18:07:40.424Z,1688580460.424 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-07-05T18:07:40.425Z,1688580460.425 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-07-05T18:07:40.426Z,1688580460.426 [logger ThreadHandler](INFO): Protected caller Thread ID is 843
2023-07-05T18:07:40.429Z,1688580460.429 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-07-05T18:07:40.429Z,1688580460.429 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-07-05T18:07:40.434Z,1688580460.434 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-07-05T18:07:40.532Z,1688580460.532 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-07-05T18:07:40.533Z,1688580460.533 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-07-05T18:07:41.243Z,1688580461.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-07-05T18:07:41.245Z,1688580461.245 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-07-05T18:07:41.467Z,1688580461.467 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-07-05T18:07:41.469Z,1688580461.469 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-07-05T18:07:41.547Z,1688580461.547 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-07-05T18:07:41.678Z,1688580461.678 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-07-05T18:07:41.680Z,1688580461.680 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-07-05T18:07:41.762Z,1688580461.762 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-07-05T18:07:41.870Z,1688580461.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-07-05T18:07:41.871Z,1688580461.871 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-07-05T18:07:42.258Z,1688580462.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-07-05T18:07:42.259Z,1688580462.259 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-07-05T18:07:42.748Z,1688580462.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-07-05T18:07:42.748Z,1688580462.748 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-07-05T18:07:42.966Z,1688580462.966 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-07-05T18:07:42.966Z,1688580462.966 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-07-05T18:07:43.160Z,1688580463.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-07-05T18:07:43.161Z,1688580463.161 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-07-05T18:07:43.679Z,1688580463.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-07-05T18:07:44.489Z,1688580464.489 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-07-05T18:07:44.942Z,1688580464.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-07-05T18:07:44.944Z,1688580464.944 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-07-05T18:07:45.163Z,1688580465.163 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-07-05T18:07:45.165Z,1688580465.165 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-07-05T18:07:45.545Z,1688580465.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-07-05T18:07:45.547Z,1688580465.547 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-07-05T18:07:45.901Z,1688580465.901 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-07-05T18:07:45.903Z,1688580465.903 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2023-07-05T18:07:45.905Z,1688580465.905 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2023-07-05T18:07:45.989Z,1688580465.989 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2023-07-05T18:07:46.152Z,1688580466.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2023-07-05T18:07:46.253Z,1688580466.253 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2023-07-05T18:07:46.339Z,1688580466.339 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2023-07-05T18:07:46.434Z,1688580466.434 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2023-07-05T18:07:46.547Z,1688580466.547 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2023-07-05T18:07:46.834Z,1688580466.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-07-05T18:07:46.835Z,1688580466.835 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2023-07-05T18:07:46.951Z,1688580466.951 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2023-07-05T18:07:47.051Z,1688580467.051 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2023-07-05T18:07:47.193Z,1688580467.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2023-07-05T18:07:47.294Z,1688580467.294 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2023-07-05T18:07:47.299Z,1688580467.299 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-07-05T18:07:47.424Z,1688580467.424 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-07-05T18:07:47.426Z,1688580467.426 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-07-05T18:07:47.492Z,1688580467.492 [VerticalControl](DEBUG): Construct VerticalControl.
2023-07-05T18:07:47.552Z,1688580467.552 [VerticalControl] Loaded
2023-07-05T18:07:47.553Z,1688580467.553 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-07-05T18:07:47.555Z,1688580467.555 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-07-05T18:07:47.596Z,1688580467.596 [HorizontalControl] Loaded
2023-07-05T18:07:47.597Z,1688580467.597 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-07-05T18:07:47.599Z,1688580467.599 [SpeedControl](DEBUG): Construct SpeedControl.
2023-07-05T18:07:47.602Z,1688580467.602 [SpeedControl] Loaded
2023-07-05T18:07:47.602Z,1688580467.602 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-07-05T18:07:47.605Z,1688580467.605 [LoopControl](DEBUG): Construct LoopControl.
2023-07-05T18:07:47.605Z,1688580467.605 [LoopControl] Loaded
2023-07-05T18:07:47.606Z,1688580467.606 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-07-05T18:07:47.606Z,1688580467.606 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-07-05T18:07:47.607Z,1688580467.607 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-07-05T18:07:47.675Z,1688580467.675 [DepthRateCalculator] Loaded
2023-07-05T18:07:47.675Z,1688580467.675 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-07-05T18:07:47.680Z,1688580467.680 [PitchRateCalculator] Loaded
2023-07-05T18:07:47.680Z,1688580467.680 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-07-05T18:07:47.690Z,1688580467.690 [SpeedCalculator] Loaded
2023-07-05T18:07:47.690Z,1688580467.690 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-07-05T18:07:47.694Z,1688580467.694 [YawRateCalculator] Loaded
2023-07-05T18:07:47.695Z,1688580467.695 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-07-05T18:07:47.713Z,1688580467.713 [ElevatorOffsetCalculator] Loaded
2023-07-05T18:07:47.713Z,1688580467.713 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-07-05T18:07:47.713Z,1688580467.713 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-07-05T18:07:47.714Z,1688580467.714 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-07-05T18:07:47.756Z,1688580467.756 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-07-05T18:07:47.757Z,1688580467.757 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-07-05T18:07:47.838Z,1688580467.838 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-07-05T18:07:47.839Z,1688580467.839 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-07-05T18:07:48.192Z,1688580468.192 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-07-05T18:07:48.193Z,1688580468.193 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-07-05T18:07:48.372Z,1688580468.372 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-07-05T18:07:48.372Z,1688580468.372 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-07-05T18:07:49.133Z,1688580469.133 [AHRS_M2] Loaded
2023-07-05T18:07:49.133Z,1688580469.133 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-07-05T18:07:49.381Z,1688580469.381 [BackseatComponent] Loaded
2023-07-05T18:07:49.381Z,1688580469.381 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-07-05T18:07:49.383Z,1688580469.383 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4098D4E0
2023-07-05T18:07:49.383Z,1688580469.383 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 926
2023-07-05T18:07:49.386Z,1688580469.386 [LcmUniversalReporter] Loaded
2023-07-05T18:07:49.386Z,1688580469.386 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-07-05T18:07:50.578Z,1688580470.578 [BPC1] Loaded
2023-07-05T18:07:50.578Z,1688580470.578 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-07-05T18:07:50.718Z,1688580470.718 [DataOverHttps] Loaded
2023-07-05T18:07:50.718Z,1688580470.718 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-07-05T18:07:50.719Z,1688580470.719 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409BD4E0
2023-07-05T18:07:50.720Z,1688580470.720 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 927
2023-07-05T18:07:50.740Z,1688580470.740 [Depth_Keller] Loaded
2023-07-05T18:07:50.741Z,1688580470.741 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-07-05T18:07:50.745Z,1688580470.745 [DropWeight] Loaded
2023-07-05T18:07:50.745Z,1688580470.745 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-07-05T18:07:50.808Z,1688580470.808 [NAL9602] Loaded
2023-07-05T18:07:50.808Z,1688580470.808 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-07-05T18:07:50.837Z,1688580470.837 [Onboard] Loaded
2023-07-05T18:07:50.837Z,1688580470.837 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-07-05T18:07:50.838Z,1688580470.838 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409ED4E0
2023-07-05T18:07:50.839Z,1688580470.839 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 928
2023-07-05T18:07:50.845Z,1688580470.845 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2023-07-05T18:07:50.856Z,1688580470.856 [PowerOnly] Loaded
2023-07-05T18:07:50.856Z,1688580470.856 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-07-05T18:07:50.867Z,1688580470.867 [Power24vConverter] Loaded
2023-07-05T18:07:50.868Z,1688580470.868 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-07-05T18:07:50.881Z,1688580470.881 [Radio_Surface] Loaded
2023-07-05T18:07:50.881Z,1688580470.881 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-07-05T18:07:50.882Z,1688580470.882 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1D4E0
2023-07-05T18:07:50.882Z,1688580470.882 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 929
2023-07-05T18:07:50.926Z,1688580470.926 [RDI_Pathfinder] Loaded
2023-07-05T18:07:50.926Z,1688580470.926 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2023-07-05T18:07:51.019Z,1688580471.019 [DAT] Loaded
2023-07-05T18:07:51.019Z,1688580471.019 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-07-05T18:07:51.020Z,1688580471.020 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A4D4E0
2023-07-05T18:07:51.020Z,1688580471.020 [DAT ThreadHandler](INFO): Protected caller Thread ID is 930
2023-07-05T18:07:51.021Z,1688580471.021 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-07-05T18:07:51.021Z,1688580471.021 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-07-05T18:07:51.156Z,1688580471.156 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-07-05T18:07:51.156Z,1688580471.156 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-07-05T18:07:51.169Z,1688580471.169 [NavChart] Loaded
2023-07-05T18:07:51.170Z,1688580471.170 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-07-05T18:07:51.175Z,1688580471.175 [UniversalFixResidualReporter] Loaded
2023-07-05T18:07:51.176Z,1688580471.176 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-07-05T18:07:51.176Z,1688580471.176 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-07-05T18:07:51.178Z,1688580471.178 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-07-05T18:07:51.343Z,1688580471.343 [SBIT](DEBUG): Construct Startup Built In Test.
2023-07-05T18:07:51.352Z,1688580471.352 [SBIT] Loaded
2023-07-05T18:07:51.353Z,1688580471.353 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-07-05T18:07:51.356Z,1688580471.356 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-07-05T18:07:51.368Z,1688580471.368 [IBIT] Loaded
2023-07-05T18:07:51.368Z,1688580471.368 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-07-05T18:07:51.374Z,1688580471.374 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-07-05T18:07:51.478Z,1688580471.478 [CBIT] Loaded
2023-07-05T18:07:51.479Z,1688580471.479 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-07-05T18:07:51.479Z,1688580471.479 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-07-05T18:07:51.480Z,1688580471.480 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-07-05T18:07:51.635Z,1688580471.635 [BuoyancyServo] Loaded
2023-07-05T18:07:51.636Z,1688580471.636 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-07-05T18:07:51.656Z,1688580471.656 [ElevatorServo] Loaded
2023-07-05T18:07:51.656Z,1688580471.656 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-07-05T18:07:51.676Z,1688580471.676 [MassServo] Loaded
2023-07-05T18:07:51.676Z,1688580471.676 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-07-05T18:07:51.694Z,1688580471.694 [RudderServo] Loaded
2023-07-05T18:07:51.695Z,1688580471.695 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-07-05T18:07:51.712Z,1688580471.712 [ThrusterServo] Loaded
2023-07-05T18:07:51.712Z,1688580471.712 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-07-05T18:07:51.712Z,1688580471.712 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-07-05T18:07:51.713Z,1688580471.713 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-07-05T18:07:51.729Z,1688580471.729 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-07-05T18:07:51.730Z,1688580471.730 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-07-05T18:07:51.946Z,1688580471.946 [CTD_Seabird] Loaded
2023-07-05T18:07:51.946Z,1688580471.946 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-07-05T18:07:51.947Z,1688580471.947 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B954E0
2023-07-05T18:07:51.948Z,1688580471.948 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 931
2023-07-05T18:07:51.968Z,1688580471.968 [PAR_Licor] Loaded
2023-07-05T18:07:51.968Z,1688580471.968 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-07-05T18:07:51.998Z,1688580471.998 [WetLabsBB2FL] Loaded
2023-07-05T18:07:51.999Z,1688580471.999 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-07-05T18:07:51.000Z,1688580472.000 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BC54E0
2023-07-05T18:07:52.000Z,1688580472.000 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 932
2023-07-05T18:07:52.020Z,1688580472.020 [WetLabsUBAT] Loaded
2023-07-05T18:07:52.020Z,1688580472.020 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2023-07-05T18:07:52.021Z,1688580472.021 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BF54E0
2023-07-05T18:07:52.021Z,1688580472.021 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 933
2023-07-05T18:07:52.022Z,1688580472.022 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-07-05T18:07:52.028Z,1688580472.028 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-07-05T18:07:52.031Z,1688580472.031 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-07-05T18:07:52.042Z,1688580472.042 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-07-05T18:07:52.043Z,1688580472.043 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C254E0
2023-07-05T18:07:52.044Z,1688580472.044 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 934
2023-07-05T18:07:52.048Z,1688580472.048 [Supervisor](INFO): Main Thread ID is 830
2023-07-05T18:07:52.049Z,1688580472.049 [Supervisor](DEBUG): Running supervisor.
2023-07-05T18:07:52.049Z,1688580472.049 [CommandExec ThreadHandler](INFO): Handler Thread ID is 935
2023-07-05T18:07:52.050Z,1688580472.050 [CommandExec](INFO): Initializing the command executive.
2023-07-05T18:07:52.051Z,1688580472.051 [CommandLine ThreadHandler](INFO): Handler Thread ID is 936
2023-07-05T18:07:52.053Z,1688580472.053 [controlThread ThreadHandler](INFO): Handler Thread ID is 937
2023-07-05T18:07:52.054Z,1688580472.054 [controlThread](DEBUG): Initializing ControlThread
2023-07-05T18:07:52.055Z,1688580472.055 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-07-05T18:07:52.056Z,1688580472.056 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-07-05T18:07:52.057Z,1688580472.057 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-07-05T18:07:52.057Z,1688580472.057 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-07-05T18:07:52.058Z,1688580472.058 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-07-05T18:07:52.058Z,1688580472.058 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-07-05T18:07:52.059Z,1688580472.059 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-07-05T18:07:52.059Z,1688580472.059 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-07-05T18:07:52.059Z,1688580472.059 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-07-05T18:07:52.066Z,1688580472.066 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-07-05T18:07:52.066Z,1688580472.066 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-07-05T18:07:52.067Z,1688580472.067 [SBIT](INFO): Initialize SBIT Component.
2023-07-05T18:07:52.067Z,1688580472.067 [SBIT](IMPORTANT): git: 2023-06-26B
2023-07-05T18:07:52.067Z,1688580472.067 [SBIT](INFO): git hash: f75d2ab6bc2685676400d6978afc6d6cf710d518
2023-07-05T18:07:52.068Z,1688580472.068 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-07-05T18:07:52.069Z,1688580472.069 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-07-05T18:07:52.070Z,1688580472.070 [SBIT](INFO): Beginning SBIT in 49.000000 seconds.
2023-07-05T18:07:52.070Z,1688580472.070 [IBIT](INFO): Initialize IBIT Component.
2023-07-05T18:07:52.071Z,1688580472.071 [CBIT](DEBUG): Initialize CBIT Component.
2023-07-05T18:07:52.072Z,1688580472.072 [logger ThreadHandler](INFO): Handler Thread ID is 938
2023-07-05T18:07:52.083Z,1688580472.083 [CBIT](DEBUG): Initialized mux pins.
2023-07-05T18:07:52.083Z,1688580472.083 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2023-07-05T18:07:52.083Z,1688580472.083 [CBIT](DEBUG): Initializing the watchdog timer.
2023-07-05T18:07:52.091Z,1688580472.091 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 939
2023-07-05T18:07:52.103Z,1688580472.103 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 940
2023-07-05T18:07:52.104Z,1688580472.104 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-07-05T18:07:52.107Z,1688580472.107 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2023-07-05T18:07:52.107Z,1688580472.107 [CBIT](DEBUG): Initializing heartbeat.
2023-07-05T18:07:52.115Z,1688580472.115 [Onboard ThreadHandler](INFO): Handler Thread ID is 941
2023-07-05T18:07:52.132Z,1688580472.132 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 942
2023-07-05T18:07:52.152Z,1688580472.152 [DAT ThreadHandler](INFO): Handler Thread ID is 943
2023-07-05T18:07:52.152Z,1688580472.152 [DAT](INFO): Powering up
2023-07-05T18:07:52.153Z,1688580472.153 [DAT](DEBUG): Initializing DAT.
2023-07-05T18:07:52.156Z,1688580472.156 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 945
2023-07-05T18:07:52.157Z,1688580472.157 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-07-05T18:07:52.160Z,1688580472.160 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 947
2023-07-05T18:07:52.163Z,1688580472.163 [WetLabsBB2FL](INFO): Powering up
2023-07-05T18:07:52.164Z,1688580472.164 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 949
2023-07-05T18:07:52.167Z,1688580472.167 [WetLabsUBAT](INFO): Powering up
2023-07-05T18:07:52.169Z,1688580472.169 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 951
2023-07-05T18:07:52.177Z,1688580472.177 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-07-05T18:07:52.177Z,1688580472.177 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-07-05T18:07:52.178Z,1688580472.178 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-07-05T18:07:52.178Z,1688580472.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-07-05T18:07:52.178Z,1688580472.178 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-07-05T18:07:52.178Z,1688580472.178 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-07-05T18:07:52.178Z,1688580472.178 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-07-05T18:07:52.179Z,1688580472.179 [CBIT](DEBUG): Deactivating GF circuits.
2023-07-05T18:07:52.179Z,1688580472.179 [CBIT](DEBUG): Deactivating emergency mode.
2023-07-05T18:07:52.179Z,1688580472.179 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-07-05T18:07:52.219Z,1688580472.219 [CBIT](DEBUG): Backplane powered.
2023-07-05T18:07:52.224Z,1688580472.224 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-07-05T18:07:52.264Z,1688580472.264 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-07-05T18:07:52.312Z,1688580472.312 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2023-07-05T18:07:52.313Z,1688580472.313 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-07-05T18:07:52.377Z,1688580472.377 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-07-05T18:07:52.379Z,1688580472.379 [Default:A.Wait](DEBUG): Construct Wait.
2023-07-05T18:07:52.381Z,1688580472.381 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-07-05T18:07:52.425Z,1688580472.425 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-07-05T18:07:52.448Z,1688580472.448 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-07-05T18:07:52.462Z,1688580472.462 [Default:E.Execute](DEBUG): Construct Execute.
2023-07-05T18:07:52.473Z,1688580472.473 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2023-07-05T18:07:52.478Z,1688580472.478 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-07-05T18:07:52.491Z,1688580472.491 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-07-05T18:07:52.539Z,1688580472.539 [Radio_Surface](INFO): Powering up
2023-07-05T18:07:52.654Z,1688580472.654 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m
2023-07-05T18:07:52.656Z,1688580472.656 [PowerOnly](INFO): Powering up loadControl
2023-07-05T18:07:52.675Z,1688580472.675 [Power24vConverter](INFO): Powering up.
2023-07-05T18:07:52.676Z,1688580472.676 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2023-07-05T18:07:52.711Z,1688580472.711 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-07-05T18:07:52.737Z,1688580472.737 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-07-05T18:07:52.743Z,1688580472.743 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-07-05T18:07:52.744Z,1688580472.744 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-07-05T18:07:52.751Z,1688580472.751 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-07-05T18:07:52.752Z,1688580472.752 [MassServo](DEBUG): Initializing EZServoServo.
2023-07-05T18:07:52.759Z,1688580472.759 [MassServo](DEBUG): Initializing MassServo.
2023-07-05T18:07:52.760Z,1688580472.760 [RudderServo](DEBUG): Initializing EZServoServo.
2023-07-05T18:07:52.767Z,1688580472.767 [RudderServo](DEBUG): Initializing RudderServo.
2023-07-05T18:07:52.768Z,1688580472.768 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-07-05T18:07:52.775Z,1688580472.775 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-07-05T18:07:52.777Z,1688580472.777 [CommandExec](FAULT): Scheduling is paused
2023-07-05T18:07:52.778Z,1688580472.778 [CBIT](INFO): Critical error at 20230705T180752
2023-07-05T18:07:52.778Z,1688580472.778 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2023-07-05T18:07:54.775Z,1688580474.775 [WetLabsBB2FL](INFO): Powering down
2023-07-05T18:07:59.188Z,1688580479.188 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-07-05T18:08:01.495Z,1688580481.495 [WetLabsUBAT](INFO): Powering down
2023-07-05T18:08:05.003Z,1688580485.003 [DAT](INFO): DAT read: 

2023-07-05T18:08:05.005Z,1688580485.005 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-07-05T18:08:06.516Z,1688580486.516 [DAT](INFO): DAT read: MF Frequency Band

2023-07-05T18:08:06.517Z,1688580486.517 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-07-05T18:08:06.518Z,1688580486.518 [DAT](INFO): DAT read: Jul  5 2023 18:08:06 

2023-07-05T18:08:07.776Z,1688580487.776 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-07-05T18:08:07.777Z,1688580487.777 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-07-05T18:08:07.777Z,1688580487.777 [DAT](INFO): commRate: 800
2023-07-05T18:08:09.843Z,1688580489.843 [DAT](INFO): entering command mode
2023-07-05T18:08:10.043Z,1688580490.043 [DAT](INFO): DAT read: 

2023-07-05T18:08:10.044Z,1688580490.044 [DAT](INFO): DAT read: user:1>

2023-07-05T18:08:10.044Z,1688580490.044 [DAT](INFO): setting verbose to 3
2023-07-05T18:08:10.295Z,1688580490.295 [DAT](INFO): DAT read: user:1>

2023-07-05T18:08:10.297Z,1688580490.297 [DAT](INFO): DAT read: Verbose         | 3           

2023-07-05T18:08:10.297Z,1688580490.297 [DAT](INFO): set verbose to 3
2023-07-05T18:08:10.297Z,1688580490.297 [DAT](INFO): setting DatVerbose to 27440
2023-07-05T18:08:10.547Z,1688580490.547 [DAT](INFO): DAT read: user:2>

2023-07-05T18:08:10.548Z,1688580490.548 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-07-05T18:08:10.549Z,1688580490.549 [DAT](INFO): set DatVerbose to 27440
2023-07-05T18:08:10.549Z,1688580490.549 [DAT](INFO): setting transmit power to 8
2023-07-05T18:08:10.799Z,1688580490.799 [DAT](INFO): DAT read: user:3>

2023-07-05T18:08:10.800Z,1688580490.800 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-07-05T18:08:10.801Z,1688580490.801 [DAT](INFO): set transmit power to 8
2023-07-05T18:08:10.801Z,1688580490.801 [DAT](INFO): setting local address to 10
2023-07-05T18:08:11.051Z,1688580491.051 [DAT](INFO): DAT read: user:4>

2023-07-05T18:08:11.052Z,1688580491.052 [DAT](INFO): DAT read: LocalAddr       | 10          

2023-07-05T18:08:11.053Z,1688580491.053 [DAT](INFO): set local address to 10
2023-07-05T18:08:11.054Z,1688580491.054 [DAT](INFO): Setting time to: 18:8:11 And date to:7/5/2023
2023-07-05T18:08:11.305Z,1688580491.305 [DAT](INFO): DAT read: user:5>

2023-07-05T18:08:11.308Z,1688580491.308 [DAT](INFO): DAT read: Wed Jul 5, 2023  18:08:11  

2023-07-05T18:08:11.309Z,1688580491.309 [DAT](INFO): Local DAT time set to Wed Jul 5, 2023  18:08:11  

2023-07-05T18:08:20.816Z,1688580500.816 [NAL9602](INFO): Powering up NAL9602
2023-07-05T18:08:31.724Z,1688580511.724 [NAL9602](INFO): NAL9602 initialized
2023-07-05T18:08:41.465Z,1688580521.465 [SBIT](IMPORTANT): Beginning Startup BIT
2023-07-05T18:08:41.474Z,1688580521.474 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T18:08:52.405Z,1688580532.405 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.901060
CHAN A1 (24V): 0.876663
CHAN A2 (12V): 0.919735
CHAN A3 (5V): 0.586672
CHAN B0 (3.3V): 0.337660
CHAN B1 (3.15aV): 0.475911
CHAN B2 (3.15bV): 0.479993
CHAN B3 (GND): -0.006236
OPEN: 0.016920
Full Scale: +/- 1 mA
2023-07-05T18:09:35.194Z,1688580575.194 [SBIT](IMPORTANT): SBIT PASSED
2023-07-05T18:09:35.195Z,1688580575.195 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2023-07-05T18:09:35.607Z,1688580575.607 [MissionManager](IMPORTANT): Started mission Startup
2023-07-05T18:09:35.607Z,1688580575.607 [Startup] Running Loop=1
2023-07-05T18:09:35.608Z,1688580575.608 [Startup](DEBUG): Aggregate::initialize Startup
2023-07-05T18:09:35.608Z,1688580575.608 [Startup:A.GoToSurface] Running Loop=1
2023-07-05T18:09:35.608Z,1688580575.608 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-07-05T18:09:35.608Z,1688580575.608 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-07-05T18:09:35.609Z,1688580575.609 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-07-05T18:09:35.609Z,1688580575.609 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-07-05T18:09:35.609Z,1688580575.609 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-07-05T18:09:35.610Z,1688580575.610 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-07-05T18:09:35.611Z,1688580575.611 [Startup:StartupSatComms] Running Loop=1
2023-07-05T18:09:35.611Z,1688580575.611 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-07-05T18:09:35.612Z,1688580575.612 [Startup:StartupSatComms:A] Running Loop=1
2023-07-05T18:09:35.989Z,1688580575.989 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-07-05T18:10:35.794Z,1688580635.794 [Startup:StartupSatComms:A](INFO): Timed out from 2023-07-05T18:09:35.6Z
2023-07-05T18:10:35.794Z,1688580635.794 [Startup:StartupSatComms:A] Stopped
2023-07-05T18:10:35.794Z,1688580635.794 [Startup:StartupSatComms:B] Running Loop=1
2023-07-05T18:10:36.170Z,1688580636.170 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-07-05T18:10:52.332Z,1688580652.332 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-07-05T18:10:52.332Z,1688580652.332 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-07-05T18:10:52.343Z,1688580652.343 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-07-05T18:10:52.770Z,1688580652.770 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-07-05T18:10:52.770Z,1688580652.770 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-07-05T18:11:25.629Z,1688580685.629 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004533
2023-07-05T18:11:33.144Z,1688580693.144 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230703T091950/Courier0699.lzma
2023-07-05T18:11:34.147Z,1688580694.147 [DataOverHttps](INFO): Moved sent file to Logs/20230703T091950/Courier0699.lzma.bak
2023-07-05T18:11:34.147Z,1688580694.147 [DataOverHttps](INFO): SBD MOMSN=18450024
2023-07-05T18:11:35.961Z,1688580695.961 [Startup:StartupSatComms:B](INFO): Timed out from 2023-07-05T18:10:35.8Z
2023-07-05T18:11:35.961Z,1688580695.961 [Startup:StartupSatComms:B] Stopped
2023-07-05T18:11:35.962Z,1688580695.962 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-07-05T18:11:35.962Z,1688580695.962 [Startup:StartupSatComms] Stopped
2023-07-05T18:11:35.962Z,1688580695.962 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-07-05T18:11:35.963Z,1688580695.963 [Startup](INFO): Completed Startup
2023-07-05T18:11:35.963Z,1688580695.963 [MissionManager](INFO): Startup is completed.
2023-07-05T18:11:35.963Z,1688580695.963 [MissionManager](INFO): Uninitializing Mission Startup
2023-07-05T18:11:35.963Z,1688580695.963 [Startup] Stopped
2023-07-05T18:11:35.963Z,1688580695.963 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-07-05T18:11:35.963Z,1688580695.963 [Startup:A.GoToSurface] Stopped
2023-07-05T18:11:35.964Z,1688580695.964 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-07-05T18:11:36.408Z,1688580696.408 [MissionManager](IMPORTANT): Started mission Default
2023-07-05T18:11:36.409Z,1688580696.409 [Default] Running Loop=1
2023-07-05T18:11:36.409Z,1688580696.409 [Default](DEBUG): Aggregate::initialize Default
2023-07-05T18:11:36.409Z,1688580696.409 [Default:B.GoToSurface] Running Loop=1
2023-07-05T18:11:36.409Z,1688580696.409 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-07-05T18:11:36.409Z,1688580696.409 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-07-05T18:11:36.409Z,1688580696.409 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-07-05T18:11:36.410Z,1688580696.410 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-07-05T18:11:36.410Z,1688580696.410 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-07-05T18:11:36.415Z,1688580696.415 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-07-05T18:11:36.415Z,1688580696.415 [Default:A.Wait] Running Loop=1
2023-07-05T18:11:36.415Z,1688580696.415 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:11:49.720Z,1688580709.720 [Default:A.Wait](INFO): Done Waiting.
2023-07-05T18:11:49.720Z,1688580709.720 [Default:A.Wait] Stopped
2023-07-05T18:11:49.720Z,1688580709.720 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:11:50.109Z,1688580710.109 [Default:CheckIn] Running Loop=1
2023-07-05T18:11:50.109Z,1688580710.109 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:11:50.110Z,1688580710.110 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:11:50.559Z,1688580710.559 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-07-05T18:12:52.728Z,1688580772.728 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2023-07-05T18:12:53.238Z,1688580773.238 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230703T091950/Courier0702.lzma
2023-07-05T18:12:54.241Z,1688580774.241 [DataOverHttps](INFO): Moved sent file to Logs/20230703T091950/Courier0702.lzma.bak
2023-07-05T18:12:54.241Z,1688580774.241 [DataOverHttps](INFO): SBD MOMSN=18450026
2023-07-05T18:13:33.913Z,1688580813.913 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-07-05T18:13:48.066Z,1688580828.066 [NAL9602](INFO): SBD MO Status=2, MOMSN=27521, MT Status=2, MTMSN=0
2023-07-05T18:13:48.066Z,1688580828.066 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:13:48.465Z,1688580828.465 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T18:13:49.680Z,1688580829.680 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181359.00,A,3648.16222,N,12147.28253,W,0.117,125.41,050723,,,A*7F
2023-07-05T18:13:49.683Z,1688580829.683 [NAL9602](INFO): GPS fix at 20230705T181359: (36.802704, -121.788042)
2023-07-05T18:13:49.715Z,1688580829.715 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:13:49.715Z,1688580829.715 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:13:50.124Z,1688580830.124 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-07-05T18:14:01.086Z,1688580841.086 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20230705T180740/Courier0000.lzma
2023-07-05T18:14:02.088Z,1688580842.088 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0000.lzma.bak
2023-07-05T18:14:02.089Z,1688580842.089 [DataOverHttps](INFO): SBD MOMSN=18450029
2023-07-05T18:14:19.626Z,1688580859.626 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20230705T180740/Courier0004.lzma
2023-07-05T18:14:20.628Z,1688580860.628 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0004.lzma.bak
2023-07-05T18:14:20.629Z,1688580860.629 [DataOverHttps](INFO): SBD MOMSN=18450033
2023-07-05T18:14:22.089Z,1688580862.089 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T18:14:38.932Z,1688580878.932 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230703T091950/Express0700.lzma
2023-07-05T18:14:39.933Z,1688580879.933 [DataOverHttps](INFO): Moved sent file to Logs/20230703T091950/Express0700.lzma.bak
2023-07-05T18:14:39.933Z,1688580879.933 [DataOverHttps](INFO): SBD MOMSN=18450036
2023-07-05T18:14:56.705Z,1688580896.705 [DataOverHttps](INFO): Sending 1699 bytes from file Logs/20230703T091950/Express0703.lzma
2023-07-05T18:14:57.705Z,1688580897.705 [DataOverHttps](INFO): Moved sent file to Logs/20230703T091950/Express0703.lzma.bak
2023-07-05T18:14:57.705Z,1688580897.705 [DataOverHttps](INFO): SBD MOMSN=18450039
2023-07-05T18:15:15.335Z,1688580915.335 [DataOverHttps](INFO): Sending 693 bytes from file Logs/20230705T180740/Express0001.lzma
2023-07-05T18:15:16.336Z,1688580916.336 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0001.lzma.bak
2023-07-05T18:15:16.337Z,1688580916.337 [DataOverHttps](INFO): SBD MOMSN=18450520
2023-07-05T18:15:33.271Z,1688580933.271 [DataOverHttps](INFO): Sending 322 bytes from file Logs/20230705T180740/Express0005.lzma
2023-07-05T18:15:34.273Z,1688580934.273 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0005.lzma.bak
2023-07-05T18:15:34.273Z,1688580934.273 [DataOverHttps](INFO): SBD MOMSN=18450534
2023-07-05T18:15:35.995Z,1688580935.995 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:15:35.995Z,1688580935.995 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:15:35.996Z,1688580935.996 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:15:56.185Z,1688580956.185 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-07-05T18:15:56.192Z,1688580956.192 [BPC1](INFO): Received data from all battery sticks.
2023-07-05T18:16:41.005Z,1688581001.005 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2023-07-05T18:18:57.288Z,1688581137.288 [CommandExec](IMPORTANT): got command show variable poweronly
2023-07-05T18:18:57.316Z,1688581137.316 [CommandExec](IMPORTANT): PowerOnly.loadAtStartup (bool)
2023-07-05T18:18:57.316Z,1688581137.316 [CommandExec](IMPORTANT): PowerOnly.simulateHardware (bool)
2023-07-05T18:18:57.317Z,1688581137.317 [CommandExec](IMPORTANT): PowerOnly.sampleTime (second)
2023-07-05T18:18:57.317Z,1688581137.317 [CommandExec](IMPORTANT): PowerOnly.sampleTime1 (second)
2023-07-05T18:18:57.317Z,1688581137.317 [CommandExec](IMPORTANT): PowerOnly.sampleTime2 (second)
2023-07-05T18:18:57.318Z,1688581137.318 [CommandExec](IMPORTANT): PowerOnly.sampleTime3 (second)
2023-07-05T18:18:57.394Z,1688581137.394 [CommandExec](IMPORTANT): PowerOnly.loadControl (none)
2023-07-05T18:18:57.403Z,1688581137.403 [CommandExec](IMPORTANT): PowerOnly.loadControl2 (none)
2023-07-05T18:18:57.403Z,1688581137.403 [CommandExec](IMPORTANT): PowerOnly.loadControl3 (none)
2023-07-05T18:18:57.514Z,1688581137.514 [CommandExec](IMPORTANT): PowerOnly.enableBroadcast (bool)
2023-07-05T18:18:57.515Z,1688581137.515 [CommandExec](IMPORTANT): PowerOnly.samplePowerOnly (bool)
2023-07-05T18:18:57.515Z,1688581137.515 [CommandExec](IMPORTANT): PowerOnly.component_voltage_loadControl (volt)
2023-07-05T18:18:57.516Z,1688581137.516 [CommandExec](IMPORTANT): PowerOnly.component_avgVoltage_loadControl (volt)
2023-07-05T18:18:57.516Z,1688581137.516 [CommandExec](IMPORTANT): PowerOnly.component_current_loadControl (milliampere)
2023-07-05T18:18:57.516Z,1688581137.516 [CommandExec](IMPORTANT): PowerOnly.component_avgCurrent_loadControl (milliampere)
2023-07-05T18:18:57.517Z,1688581137.517 [CommandExec](IMPORTANT): PowerOnly.sampleLoad1 (bool)
2023-07-05T18:19:14.870Z,1688581154.870 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 1 second
2023-07-05T18:19:15.337Z,1688581155.337 [PowerOnly](INFO): Powering down loadControl
2023-07-05T18:19:24.927Z,1688581164.927 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 0 second
2023-07-05T18:19:25.028Z,1688581165.028 [PowerOnly](INFO): Powering up loadControl
2023-07-05T18:19:32.215Z,1688581172.215 [CommandExec](IMPORTANT): got command 
2023-07-05T18:19:32.215Z,1688581172.215 [CommandExec](FAULT): Incomplete syntax. Try: help
2023-07-05T18:19:35.444Z,1688581175.444 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T18:19:35.592Z,1688581175.592 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T18:19:46.550Z,1688581186.550 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.901087
CHAN A1 (24V): 0.876454
CHAN A2 (12V): 0.918314
CHAN A3 (5V): 0.580548
CHAN B0 (3.3V): 0.333893
CHAN B1 (3.15aV): 0.459473
CHAN B2 (3.15bV): 0.477205
CHAN B3 (GND): -0.017206
OPEN: 0.020397
Full Scale: +/- 1 mA
2023-07-05T18:20:36.573Z,1688581236.573 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:20:36.573Z,1688581236.573 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:20:36.573Z,1688581236.573 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:20:36.573Z,1688581236.573 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:20:36.964Z,1688581236.964 [Default:CheckIn:D] Stopped
2023-07-05T18:20:36.964Z,1688581236.964 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:20:37.388Z,1688581237.388 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.009253 min 
2023-07-05T18:20:37.388Z,1688581237.388 [Default:CheckIn:E] Stopped
2023-07-05T18:20:37.388Z,1688581237.388 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:20:37.388Z,1688581237.388 [Default:CheckIn] Stopped
2023-07-05T18:20:37.388Z,1688581237.388 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:20:37.389Z,1688581237.389 [Default:CheckIn](INFO): Running loop #2
2023-07-05T18:20:37.389Z,1688581237.389 [Default:CheckIn] Running Loop=2
2023-07-05T18:20:37.389Z,1688581237.389 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:20:37.389Z,1688581237.389 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:20:39.377Z,1688581239.377 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182049.00,A,3648.16320,N,12147.27887,W,0.330,302.97,050723,,,D*7F
2023-07-05T18:20:39.379Z,1688581239.379 [NAL9602](INFO): GPS fix at 20230705T182049: (36.802720, -121.787981)
2023-07-05T18:20:39.409Z,1688581239.409 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:20:39.409Z,1688581239.409 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:20:47.542Z,1688581247.542 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20230705T180740/Courier0007.lzma
2023-07-05T18:20:48.544Z,1688581248.544 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0007.lzma.bak
2023-07-05T18:20:48.545Z,1688581248.545 [DataOverHttps](INFO): SBD MOMSN=18450538
2023-07-05T18:21:05.292Z,1688581265.292 [DataOverHttps](INFO): Sending 651 bytes from file Logs/20230705T180740/Express0008.lzma
2023-07-05T18:21:06.292Z,1688581266.292 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0008.lzma.bak
2023-07-05T18:21:06.293Z,1688581266.293 [DataOverHttps](INFO): SBD MOMSN=18450541
2023-07-05T18:21:08.086Z,1688581268.086 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:21:08.086Z,1688581268.086 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:21:08.086Z,1688581268.086 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:21:30.134Z,1688581290.134 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 1 second
2023-07-05T18:21:30.676Z,1688581290.676 [PowerOnly](INFO): Powering down loadControl
2023-07-05T18:21:38.900Z,1688581298.900 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T18:21:39.257Z,1688581299.257 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T18:21:50.119Z,1688581310.119 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.914786
CHAN A1 (24V): 0.889691
CHAN A2 (12V): 0.932527
CHAN A3 (5V): 0.824548
CHAN B0 (3.3V): 0.542121
CHAN B1 (3.15aV): 0.850580
CHAN B2 (3.15bV): 0.859218
CHAN B3 (GND): -0.024563
OPEN: 0.019305
Full Scale: +/- 1 mA
2023-07-05T18:22:26.420Z,1688581346.420 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadB1
2023-07-05T18:22:29.020Z,1688581349.020 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T18:22:29.304Z,1688581349.304 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T18:22:40.232Z,1688581360.232 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.001195
CHAN A1 (24V): 0.052912
CHAN A2 (12V): 0.001263
CHAN A3 (5V): 0.001242
CHAN B0 (3.3V): 0.002670
CHAN B1 (3.15aV): 0.002929
CHAN B2 (3.15bV): 0.002271
CHAN B3 (GND): 0.001921
OPEN: 0.006453
Full Scale: +/- 1 mA
2023-07-05T18:22:49.851Z,1688581369.851 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T18:22:49.912Z,1688581369.912 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T18:23:00.820Z,1688581380.820 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.001185
CHAN A1 (24V): 0.052642
CHAN A2 (12V): 0.000039
CHAN A3 (5V): 0.001619
CHAN B0 (3.3V): 0.002482
CHAN B1 (3.15aV): 0.001666
CHAN B2 (3.15bV): 0.001855
CHAN B3 (GND): 0.002018
OPEN: 0.006107
Full Scale: +/- 1 mA
2023-07-05T18:23:10.052Z,1688581390.052 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T18:23:10.107Z,1688581390.107 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T18:23:21.043Z,1688581401.043 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.000446
CHAN A1 (24V): 0.052433
CHAN A2 (12V): 0.000013
CHAN A3 (5V): -0.000153
CHAN B0 (3.3V): 0.002709
CHAN B1 (3.15aV): 0.002330
CHAN B2 (3.15bV): 0.003014
CHAN B3 (GND): 0.002315
OPEN: 0.006210
Full Scale: +/- 1 mA
2023-07-05T18:23:33.983Z,1688581413.983 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 0 second
2023-07-05T18:23:34.300Z,1688581414.300 [PowerOnly](INFO): Powering up loadControl
2023-07-05T18:23:38.751Z,1688581418.751 [NAL9602](INFO): SBD MO Status=2, MOMSN=27521, MT Status=2, MTMSN=0
2023-07-05T18:23:38.752Z,1688581418.752 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:23:41.055Z,1688581421.055 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T18:23:41.229Z,1688581421.229 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T18:23:52.117Z,1688581432.117 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.916255
CHAN A1 (24V): 0.891186
CHAN A2 (12V): 0.932966
CHAN A3 (5V): 0.826493
CHAN B0 (3.3V): 0.542753
CHAN B1 (3.15aV): 0.853838
CHAN B2 (3.15bV): 0.860554
CHAN B3 (GND): -0.022759
OPEN: 0.022944
Full Scale: +/- 1 mA
2023-07-05T18:24:37.745Z,1688581477.745 [NAL9602](INFO): SBD MO Status=2, MOMSN=27521, MT Status=2, MTMSN=0
2023-07-05T18:24:37.745Z,1688581477.745 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:25:41.977Z,1688581541.977 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T18:26:08.651Z,1688581568.651 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:26:08.651Z,1688581568.651 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:26:08.651Z,1688581568.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:26:08.652Z,1688581568.652 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:26:09.068Z,1688581569.068 [Default:CheckIn:D] Stopped
2023-07-05T18:26:09.068Z,1688581569.068 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:26:09.493Z,1688581569.493 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.544329 min 
2023-07-05T18:26:09.493Z,1688581569.493 [Default:CheckIn:E] Stopped
2023-07-05T18:26:09.493Z,1688581569.493 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:26:09.493Z,1688581569.493 [Default:CheckIn] Stopped
2023-07-05T18:26:09.493Z,1688581569.493 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:26:09.493Z,1688581569.493 [Default:CheckIn](INFO): Running loop #3
2023-07-05T18:26:09.493Z,1688581569.493 [Default:CheckIn] Running Loop=3
2023-07-05T18:26:09.494Z,1688581569.494 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:26:09.494Z,1688581569.494 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:26:11.469Z,1688581571.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,182622.00,A,3648.16358,N,12147.28193,W,0.214,302.97,050723,,,D*7F
2023-07-05T18:26:11.472Z,1688581571.472 [NAL9602](INFO): GPS fix at 20230705T182622: (36.802726, -121.788032)
2023-07-05T18:26:11.518Z,1688581571.518 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:26:11.531Z,1688581571.531 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:26:19.230Z,1688581579.230 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0010.lzma
2023-07-05T18:26:20.233Z,1688581580.233 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0010.lzma.bak
2023-07-05T18:26:20.233Z,1688581580.233 [DataOverHttps](INFO): SBD MOMSN=18450568
2023-07-05T18:26:39.743Z,1688581599.743 [DataOverHttps](INFO): Sending 688 bytes from file Logs/20230705T180740/Express0011.lzma
2023-07-05T18:26:40.745Z,1688581600.745 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0011.lzma.bak
2023-07-05T18:26:40.745Z,1688581600.745 [DataOverHttps](INFO): SBD MOMSN=18450571
2023-07-05T18:26:42.600Z,1688581602.600 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:26:42.600Z,1688581602.600 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:26:42.600Z,1688581602.600 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:26:44.196Z,1688581604.196 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T18:27:46.845Z,1688581666.845 [RDI_Pathfinder](ERROR): only read 1 of 4 data items
2023-07-05T18:29:34.560Z,1688581774.560 [CommandExec](IMPORTANT): got command show variable cbit
2023-07-05T18:29:34.568Z,1688581774.568 [CommandExec](IMPORTANT): CBIT.GFActive (bool)
2023-07-05T18:29:34.623Z,1688581774.623 [CommandExec](IMPORTANT): CBITMainGroundfault.ad (none)
2023-07-05T18:29:34.624Z,1688581774.624 [CommandExec](IMPORTANT): CBITMainGroundfault.adRes (bit)
2023-07-05T18:29:34.624Z,1688581774.624 [CommandExec](IMPORTANT): CBITMainGroundfault.adTimeout (millisecond)
2023-07-05T18:29:34.624Z,1688581774.624 [CommandExec](IMPORTANT): CBITMainGroundfault.adVref (volt)
2023-07-05T18:29:34.625Z,1688581774.625 [CommandExec](IMPORTANT): CBITWaterAlarmBow.ad (none)
2023-07-05T18:29:34.625Z,1688581774.625 [CommandExec](IMPORTANT): CBITWaterAlarmBow.adRes (bit)
2023-07-05T18:29:34.625Z,1688581774.625 [CommandExec](IMPORTANT): CBITWaterAlarmBow.adVref (volt)
2023-07-05T18:29:34.625Z,1688581774.625 [CommandExec](IMPORTANT): CBITWaterAlarmStern.ad (none)
2023-07-05T18:29:34.626Z,1688581774.626 [CommandExec](IMPORTANT): CBITWaterAlarmStern.adRes (bit)
2023-07-05T18:29:34.626Z,1688581774.626 [CommandExec](IMPORTANT): CBITWaterAlarmStern.adVref (volt)
2023-07-05T18:29:34.627Z,1688581774.627 [CommandExec](IMPORTANT): CBITWaterAlarmAux.ad (none)
2023-07-05T18:29:34.627Z,1688581774.627 [CommandExec](IMPORTANT): CBITWaterAlarmAux.adRes (bit)
2023-07-05T18:29:34.627Z,1688581774.627 [CommandExec](IMPORTANT): CBITWaterAlarmAux.adVref (volt)
2023-07-05T18:29:34.638Z,1688581774.638 [CommandExec](IMPORTANT): CBIT.loadAtStartup (bool)
2023-07-05T18:29:34.639Z,1688581774.639 [CommandExec](IMPORTANT): CBIT.simulateHardware (bool)
2023-07-05T18:29:34.639Z,1688581774.639 [CommandExec](IMPORTANT): CBIT.stopDepth (meter)
2023-07-05T18:29:34.639Z,1688581774.639 [CommandExec](IMPORTANT): CBIT.abortDepth (meter)
2023-07-05T18:29:34.640Z,1688581774.640 [CommandExec](IMPORTANT): CBIT.humidityThreshold (percent)
2023-07-05T18:29:34.640Z,1688581774.640 [CommandExec](IMPORTANT): CBIT.pressureThreshold (pound_per_square_inch)
2023-07-05T18:29:34.640Z,1688581774.640 [CommandExec](IMPORTANT): CBIT.tempThreshold (fahrenheit)
2023-07-05T18:29:34.641Z,1688581774.641 [CommandExec](IMPORTANT): CBIT.navErrorThreshold (percent)
2023-07-05T18:29:34.641Z,1688581774.641 [CommandExec](IMPORTANT): CBIT.runNavErrorCritical (bool)
2023-07-05T18:29:34.641Z,1688581774.641 [CommandExec](IMPORTANT): CBIT.abortDepthTimeout (second)
2023-07-05T18:29:34.642Z,1688581774.642 [CommandExec](IMPORTANT): CBIT.battFailReport (count)
2023-07-05T18:29:34.642Z,1688581774.642 [CommandExec](IMPORTANT): CBIT.battTempThreshold (celsius)
2023-07-05T18:29:34.642Z,1688581774.642 [CommandExec](IMPORTANT): CBIT.envTimeout (second)
2023-07-05T18:29:34.669Z,1688581774.669 [CommandExec](IMPORTANT): CBIT.runElevOffsetCalc (bool)
2023-07-05T18:29:34.669Z,1688581774.669 [CommandExec](IMPORTANT): CBIT.runFaultClassifier (bool)
2023-07-05T18:29:34.669Z,1688581774.669 [CommandExec](IMPORTANT): CBIT.vehicleOpen (bool)
2023-07-05T18:29:34.670Z,1688581774.670 [CommandExec](IMPORTANT): CBIT.allowAuxLeak (bool)
2023-07-05T18:29:34.670Z,1688581774.670 [CommandExec](IMPORTANT): CBIT.gfChanA0_Threshold (milliampere)
2023-07-05T18:29:34.670Z,1688581774.670 [CommandExec](IMPORTANT): CBIT.gfChanA1_Threshold (milliampere)
2023-07-05T18:29:34.671Z,1688581774.671 [CommandExec](IMPORTANT): CBIT.gfChanA2_Threshold (milliampere)
2023-07-05T18:29:34.671Z,1688581774.671 [CommandExec](IMPORTANT): CBIT.gfChanA3_Threshold (milliampere)
2023-07-05T18:29:34.672Z,1688581774.672 [CommandExec](IMPORTANT): CBIT.gfChanB0_Threshold (milliampere)
2023-07-05T18:29:34.672Z,1688581774.672 [CommandExec](IMPORTANT): CBIT.gfChanB1_Threshold (milliampere)
2023-07-05T18:29:34.672Z,1688581774.672 [CommandExec](IMPORTANT): CBIT.gfChanB2_Threshold (milliampere)
2023-07-05T18:29:34.673Z,1688581774.673 [CommandExec](IMPORTANT): CBIT.gfChanB3_Threshold (milliampere)
2023-07-05T18:29:34.673Z,1688581774.673 [CommandExec](IMPORTANT): CBIT.gfScanTimeout (hour)
2023-07-05T18:29:34.673Z,1688581774.673 [CommandExec](IMPORTANT): CBIT.gfBattOffset (microampere)
2023-07-05T18:29:34.674Z,1688581774.674 [CommandExec](IMPORTANT): CBIT.gf24Offset (microampere)
2023-07-05T18:29:34.674Z,1688581774.674 [CommandExec](IMPORTANT): CBIT.gf12Offset (microampere)
2023-07-05T18:29:34.674Z,1688581774.674 [CommandExec](IMPORTANT): CBIT.gf5Offset (microampere)
2023-07-05T18:29:34.713Z,1688581774.713 [CommandExec](IMPORTANT): CBIT.gf3_3Offset (microampere)
2023-07-05T18:29:34.713Z,1688581774.713 [CommandExec](IMPORTANT): CBIT.gf3_15Offset (microampere)
2023-07-05T18:29:34.714Z,1688581774.714 [CommandExec](IMPORTANT): CBIT.gfCommOffset (microampere)
2023-07-05T18:29:34.945Z,1688581774.945 [CommandExec](IMPORTANT): CBIT.enableBroadcast (bool)
2023-07-05T18:29:34.946Z,1688581774.946 [CommandExec](IMPORTANT): CBIT.empiricalFaultElevOffset (radian)
2023-07-05T18:29:34.959Z,1688581774.959 [CommandExec](IMPORTANT): CBIT.shorePowerOn (bool)
2023-07-05T18:29:34.959Z,1688581774.959 [CommandExec](IMPORTANT): CBIT.ampHoursUsed (ampere_hour)
2023-07-05T18:29:34.960Z,1688581774.960 [CommandExec](IMPORTANT): CBIT.platform_fault (enum)
2023-07-05T18:29:34.960Z,1688581774.960 [CommandExec](IMPORTANT): CBIT.platform_fault_leak (enum)
2023-07-05T18:29:34.961Z,1688581774.961 [CommandExec](IMPORTANT): CBIT.GFCHANA0Current (milliampere)
2023-07-05T18:29:34.961Z,1688581774.961 [CommandExec](IMPORTANT): CBIT.GFCHANA1Current (milliampere)
2023-07-05T18:29:34.961Z,1688581774.961 [CommandExec](IMPORTANT): CBIT.GFCHANA2Current (milliampere)
2023-07-05T18:29:34.961Z,1688581774.961 [CommandExec](IMPORTANT): CBIT.GFCHANA3Current (milliampere)
2023-07-05T18:29:34.962Z,1688581774.962 [CommandExec](IMPORTANT): CBIT.GFCHANB0Current (milliampere)
2023-07-05T18:29:34.962Z,1688581774.962 [CommandExec](IMPORTANT): CBIT.GFCHANB1Current (milliampere)
2023-07-05T18:29:34.979Z,1688581774.979 [CommandExec](IMPORTANT): CBIT.GFCHANB2Current (milliampere)
2023-07-05T18:29:34.980Z,1688581774.980 [CommandExec](IMPORTANT): CBIT.GFCHANB3Current (milliampere)
2023-07-05T18:29:34.980Z,1688581774.980 [CommandExec](IMPORTANT): CBIT.GFCHANOpenCurrent (milliampere)
2023-07-05T18:29:34.980Z,1688581774.980 [CommandExec](IMPORTANT): CBIT.empericalClassifierFaultDetected (enum)
2023-07-05T18:29:34.980Z,1688581774.980 [CommandExec](IMPORTANT): CBIT.binnedDepthRate (meter_per_second)
2023-07-05T18:29:41.451Z,1688581781.451 [CommandLine](INFO): End of History
2023-07-05T18:29:41.453Z,1688581781.453 [CommandLine](INFO): End of History
2023-07-05T18:29:41.459Z,1688581781.459 [CommandLine](INFO): End of History
2023-07-05T18:29:41.461Z,1688581781.461 [CommandLine](INFO): End of History
2023-07-05T18:31:09.693Z,1688581869.693 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2023-07-05T18:31:43.224Z,1688581903.224 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:31:43.224Z,1688581903.224 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:31:43.224Z,1688581903.224 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:31:43.224Z,1688581903.224 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:31:43.605Z,1688581903.605 [Default:CheckIn:D] Stopped
2023-07-05T18:31:43.605Z,1688581903.605 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:31:44.002Z,1688581904.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.119932 min 
2023-07-05T18:31:44.002Z,1688581904.002 [Default:CheckIn:E] Stopped
2023-07-05T18:31:44.003Z,1688581904.003 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:31:44.003Z,1688581904.003 [Default:CheckIn] Stopped
2023-07-05T18:31:44.003Z,1688581904.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:31:44.003Z,1688581904.003 [Default:CheckIn](INFO): Running loop #4
2023-07-05T18:31:44.003Z,1688581904.003 [Default:CheckIn] Running Loop=4
2023-07-05T18:31:44.003Z,1688581904.003 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:31:44.003Z,1688581904.003 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:31:46.018Z,1688581906.018 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183156.00,A,3648.16363,N,12147.28139,W,0.175,328.82,050723,,,A*7F
2023-07-05T18:31:46.020Z,1688581906.020 [NAL9602](INFO): GPS fix at 20230705T183156: (36.802727, -121.788023)
2023-07-05T18:31:46.032Z,1688581906.032 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:31:46.032Z,1688581906.032 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:31:53.284Z,1688581913.284 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0013.lzma
2023-07-05T18:31:54.284Z,1688581914.284 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0013.lzma.bak
2023-07-05T18:31:54.284Z,1688581914.284 [DataOverHttps](INFO): SBD MOMSN=18450593
2023-07-05T18:32:10.928Z,1688581930.928 [DataOverHttps](INFO): Sending 898 bytes from file Logs/20230705T180740/Express0014.lzma
2023-07-05T18:32:11.928Z,1688581931.928 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0014.lzma.bak
2023-07-05T18:32:11.929Z,1688581931.929 [DataOverHttps](INFO): SBD MOMSN=18450596
2023-07-05T18:32:13.698Z,1688581933.698 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:32:13.698Z,1688581933.698 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:32:13.698Z,1688581933.698 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:32:16.476Z,1688581936.476 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T18:32:16.555Z,1688581936.555 [NAL9602](ERROR): received: 
+CSQ:0

OK521, 2, 0, 0, 0

OK
2023-07-05T18:32:35.704Z,1688581955.704 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 1 second
2023-07-05T18:32:36.276Z,1688581956.276 [PowerOnly](INFO): Powering down loadControl
2023-07-05T18:32:37.086Z,1688581957.086 [NAL9602](INFO): SBD MO Status=2, MOMSN=27521, MT Status=2, MTMSN=0
2023-07-05T18:32:37.087Z,1688581957.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:33:11.461Z,1688581991.461 [NAL9602](INFO): SBD MO Status=2, MOMSN=27521, MT Status=2, MTMSN=0
2023-07-05T18:33:11.462Z,1688581991.462 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:34:05.561Z,1688582045.561 [NAL9602](INFO): SBD MO Status=2, MOMSN=27521, MT Status=2, MTMSN=0
2023-07-05T18:34:05.561Z,1688582045.561 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:36:47.963Z,1688582207.963 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T18:37:14.264Z,1688582234.264 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:37:14.264Z,1688582234.264 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:37:14.264Z,1688582234.264 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:37:14.264Z,1688582234.264 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:37:14.662Z,1688582234.662 [Default:CheckIn:D] Stopped
2023-07-05T18:37:14.662Z,1688582234.662 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:37:15.084Z,1688582235.084 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.637559 min 
2023-07-05T18:37:15.084Z,1688582235.084 [Default:CheckIn:E] Stopped
2023-07-05T18:37:15.084Z,1688582235.084 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:37:15.084Z,1688582235.084 [Default:CheckIn] Stopped
2023-07-05T18:37:15.084Z,1688582235.084 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:37:15.085Z,1688582235.085 [Default:CheckIn](INFO): Running loop #5
2023-07-05T18:37:15.085Z,1688582235.085 [Default:CheckIn] Running Loop=5
2023-07-05T18:37:15.085Z,1688582235.085 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:37:15.085Z,1688582235.085 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:37:17.082Z,1688582237.082 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,183727.00,A,3648.16412,N,12147.28317,W,0.214,206.84,050723,,,D*7A
2023-07-05T18:37:17.089Z,1688582237.089 [NAL9602](INFO): GPS fix at 20230705T183727: (36.802735, -121.788053)
2023-07-05T18:37:17.146Z,1688582237.146 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:37:17.146Z,1688582237.146 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:37:24.486Z,1688582244.486 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230705T180740/Courier0016.lzma
2023-07-05T18:37:25.488Z,1688582245.488 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0016.lzma.bak
2023-07-05T18:37:25.489Z,1688582245.489 [DataOverHttps](INFO): SBD MOMSN=18450664
2023-07-05T18:37:44.159Z,1688582264.159 [DataOverHttps](INFO): Sending 258 bytes from file Logs/20230705T180740/Express0017.lzma
2023-07-05T18:37:45.152Z,1688582265.152 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0017.lzma.bak
2023-07-05T18:37:45.153Z,1688582265.153 [DataOverHttps](INFO): SBD MOMSN=18450667
2023-07-05T18:37:46.980Z,1688582266.980 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:37:46.980Z,1688582266.980 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:37:46.980Z,1688582266.980 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:37:50.180Z,1688582270.180 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T18:42:47.544Z,1688582567.544 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:42:47.544Z,1688582567.544 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:42:47.544Z,1688582567.544 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:42:47.544Z,1688582567.544 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:42:47.973Z,1688582567.973 [Default:CheckIn:D] Stopped
2023-07-05T18:42:47.973Z,1688582567.973 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:42:48.356Z,1688582568.356 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.192745 min 
2023-07-05T18:42:48.356Z,1688582568.356 [Default:CheckIn:E] Stopped
2023-07-05T18:42:48.356Z,1688582568.356 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:42:48.356Z,1688582568.356 [Default:CheckIn] Stopped
2023-07-05T18:42:48.356Z,1688582568.356 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:42:48.357Z,1688582568.357 [Default:CheckIn](INFO): Running loop #6
2023-07-05T18:42:48.357Z,1688582568.357 [Default:CheckIn] Running Loop=6
2023-07-05T18:42:48.357Z,1688582568.357 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:42:48.357Z,1688582568.357 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:42:50.355Z,1688582570.355 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184301.00,A,3648.16403,N,12147.28395,W,0.233,78.76,050723,,,D*44
2023-07-05T18:42:50.357Z,1688582570.357 [NAL9602](INFO): GPS fix at 20230705T184301: (36.802734, -121.788066)
2023-07-05T18:42:50.368Z,1688582570.368 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:42:50.368Z,1688582570.368 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:42:58.330Z,1688582578.330 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0019.lzma
2023-07-05T18:42:59.332Z,1688582579.332 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0019.lzma.bak
2023-07-05T18:42:59.333Z,1688582579.333 [DataOverHttps](INFO): SBD MOMSN=18450672
2023-07-05T18:43:15.966Z,1688582595.966 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230705T180740/Express0020.lzma
2023-07-05T18:43:16.969Z,1688582596.969 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0020.lzma.bak
2023-07-05T18:43:16.969Z,1688582596.969 [DataOverHttps](INFO): SBD MOMSN=18450675
2023-07-05T18:43:18.661Z,1688582598.661 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:43:18.661Z,1688582598.661 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:43:18.661Z,1688582598.661 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:43:21.060Z,1688582601.060 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T18:43:21.135Z,1688582601.135 [NAL9602](ERROR): received: 
+CSQ:0

OK521, 2, 0, 0, 0

OK
2023-07-05T18:44:23.991Z,1688582663.991 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-07-05T18:44:25.999Z,1688582665.999 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.243160
2023-07-05T18:44:59.131Z,1688582699.131 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-07-05T18:45:26.960Z,1688582726.960 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004333
2023-07-05T18:45:58.622Z,1688582758.622 [NAL9602](INFO): SBD MO Status=0, MOMSN=27521, MT Status=0, MTMSN=0
2023-07-05T18:45:58.622Z,1688582758.622 [NAL9602](INFO): No messages in MT queue
2023-07-05T18:46:29.352Z,1688582789.352 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T18:48:19.241Z,1688582899.241 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:48:19.241Z,1688582899.241 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:48:19.241Z,1688582899.241 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:48:19.241Z,1688582899.241 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:48:19.630Z,1688582899.630 [Default:CheckIn:D] Stopped
2023-07-05T18:48:19.630Z,1688582899.630 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:48:20.031Z,1688582900.031 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.720357 min 
2023-07-05T18:48:20.031Z,1688582900.031 [Default:CheckIn:E] Stopped
2023-07-05T18:48:20.031Z,1688582900.031 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:48:20.031Z,1688582900.031 [Default:CheckIn] Stopped
2023-07-05T18:48:20.031Z,1688582900.031 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:48:20.031Z,1688582900.031 [Default:CheckIn](INFO): Running loop #7
2023-07-05T18:48:20.032Z,1688582900.032 [Default:CheckIn] Running Loop=7
2023-07-05T18:48:20.032Z,1688582900.032 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:48:20.032Z,1688582900.032 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:48:22.045Z,1688582902.045 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,184833.00,A,3648.16454,N,12147.28169,W,0.700,122.14,050723,,,D*72
2023-07-05T18:48:22.060Z,1688582902.060 [NAL9602](INFO): GPS fix at 20230705T184833: (36.802742, -121.788028)
2023-07-05T18:48:22.071Z,1688582902.071 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:48:22.071Z,1688582902.071 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:48:30.214Z,1688582910.214 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0022.lzma
2023-07-05T18:48:31.216Z,1688582911.216 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0022.lzma.bak
2023-07-05T18:48:31.217Z,1688582911.217 [DataOverHttps](INFO): SBD MOMSN=18450679
2023-07-05T18:48:47.450Z,1688582927.450 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230705T180740/Express0023.lzma
2023-07-05T18:48:48.310Z,1688582928.310 [NAL9602](INFO): SBD MO Status=2, MOMSN=27522, MT Status=2, MTMSN=0
2023-07-05T18:48:48.310Z,1688582928.310 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:48:48.456Z,1688582928.456 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0023.lzma.bak
2023-07-05T18:48:48.457Z,1688582928.457 [DataOverHttps](INFO): SBD MOMSN=18450682
2023-07-05T18:48:50.342Z,1688582930.342 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:48:50.342Z,1688582930.342 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:48:50.342Z,1688582930.342 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:49:18.197Z,1688582958.197 [NAL9602](INFO): SBD MO Status=2, MOMSN=27522, MT Status=2, MTMSN=0
2023-07-05T18:49:18.198Z,1688582958.198 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:50:01.435Z,1688583001.435 [NAL9602](INFO): SBD MO Status=2, MOMSN=27522, MT Status=2, MTMSN=0
2023-07-05T18:50:01.435Z,1688583001.435 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:50:33.493Z,1688583033.493 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 1 second
2023-07-05T18:50:44.220Z,1688583044.220 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 1 second persist
2023-07-05T18:50:44.221Z,1688583044.221 [CommandExec](FAULT): Not allowing to overwrite existing Data/persisted.cfg after unclean shutdown.
2023-07-05T18:51:03.640Z,1688583063.640 [NAL9602](INFO): SBD MO Status=2, MOMSN=27522, MT Status=2, MTMSN=0
2023-07-05T18:51:03.640Z,1688583063.640 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:51:37.985Z,1688583097.985 [NAL9602](INFO): SBD MO Status=2, MOMSN=27522, MT Status=2, MTMSN=0
2023-07-05T18:51:37.985Z,1688583097.985 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T18:53:23.830Z,1688583203.830 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T18:53:50.927Z,1688583230.927 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:53:50.927Z,1688583230.927 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:53:50.928Z,1688583230.928 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:53:50.928Z,1688583230.928 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:53:51.315Z,1688583231.315 [Default:CheckIn:D] Stopped
2023-07-05T18:53:51.315Z,1688583231.315 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:53:51.726Z,1688583231.726 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.248446 min 
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn:E] Stopped
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn] Stopped
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn](INFO): Running loop #8
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn] Running Loop=8
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:53:51.727Z,1688583231.727 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:53:53.726Z,1688583233.726 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185404.00,A,3648.16554,N,12147.28373,W,0.350,195.06,050723,,,A*78
2023-07-05T18:53:53.728Z,1688583233.728 [NAL9602](INFO): GPS fix at 20230705T185404: (36.802759, -121.788062)
2023-07-05T18:53:53.740Z,1688583233.740 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:53:53.740Z,1688583233.740 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:53:54.556Z,1688583234.556 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2023-07-05T18:54:01.814Z,1688583241.814 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0025.lzma
2023-07-05T18:54:02.816Z,1688583242.816 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0025.lzma.bak
2023-07-05T18:54:02.817Z,1688583242.817 [DataOverHttps](INFO): SBD MOMSN=18450685
2023-07-05T18:54:19.171Z,1688583259.171 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20230705T180740/Express0026.lzma
2023-07-05T18:54:20.173Z,1688583260.173 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0026.lzma.bak
2023-07-05T18:54:20.173Z,1688583260.173 [DataOverHttps](INFO): SBD MOMSN=18450688
2023-07-05T18:54:22.024Z,1688583262.024 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:54:22.024Z,1688583262.024 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:54:22.025Z,1688583262.025 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:54:26.052Z,1688583266.052 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T18:59:22.617Z,1688583562.617 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T18:59:22.618Z,1688583562.618 [Default:CheckIn:C.Wait] Stopped
2023-07-05T18:59:22.618Z,1688583562.618 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T18:59:22.618Z,1688583562.618 [Default:CheckIn:D] Running Loop=1
2023-07-05T18:59:23.004Z,1688583563.004 [Default:CheckIn:D] Stopped
2023-07-05T18:59:23.004Z,1688583563.004 [Default:CheckIn:E] Running Loop=1
2023-07-05T18:59:23.419Z,1688583563.419 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.776579 min 
2023-07-05T18:59:23.419Z,1688583563.419 [Default:CheckIn:E] Stopped
2023-07-05T18:59:23.419Z,1688583563.419 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T18:59:23.419Z,1688583563.419 [Default:CheckIn] Stopped
2023-07-05T18:59:23.419Z,1688583563.419 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T18:59:23.419Z,1688583563.419 [Default:CheckIn](INFO): Running loop #9
2023-07-05T18:59:23.419Z,1688583563.419 [Default:CheckIn] Running Loop=9
2023-07-05T18:59:23.420Z,1688583563.420 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T18:59:23.420Z,1688583563.420 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T18:59:25.410Z,1688583565.410 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185936.00,A,3648.16647,N,12147.28424,W,0.272,182.36,050723,,,A*74
2023-07-05T18:59:25.412Z,1688583565.412 [NAL9602](INFO): GPS fix at 20230705T185936: (36.802774, -121.788071)
2023-07-05T18:59:25.427Z,1688583565.427 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T18:59:25.428Z,1688583565.428 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T18:59:32.962Z,1688583572.962 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0028.lzma
2023-07-05T18:59:33.964Z,1688583573.964 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0028.lzma.bak
2023-07-05T18:59:33.965Z,1688583573.965 [DataOverHttps](INFO): SBD MOMSN=18450695
2023-07-05T18:59:50.998Z,1688583590.998 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230705T180740/Express0029.lzma
2023-07-05T18:59:52.001Z,1688583592.001 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0029.lzma.bak
2023-07-05T18:59:52.001Z,1688583592.001 [DataOverHttps](INFO): SBD MOMSN=18450698
2023-07-05T18:59:53.715Z,1688583593.715 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T18:59:53.715Z,1688583593.715 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T18:59:53.715Z,1688583593.715 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T18:59:56.120Z,1688583596.120 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T18:59:56.195Z,1688583596.195 [NAL9602](ERROR): received: 
+CSQ:0

OK522, 2, 0, 0, 0

OK
2023-07-05T19:04:28.016Z,1688583868.016 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T19:04:34.535Z,1688583874.535 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2023-07-05T19:04:34.535Z,1688583874.535 [RDI_Pathfinder] Communications Fault, FailCount= 1
2023-07-05T19:04:34.535Z,1688583874.535 [RDI_Pathfinder](ERROR): Communications Fault
2023-07-05T19:04:34.587Z,1688583874.587 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2023-07-05T19:04:34.959Z,1688583874.959 [RDI_Pathfinder](INFO): Powering down
2023-07-05T19:04:35.718Z,1688583875.718 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2023-07-05T19:04:35.719Z,1688583875.719 [RDI_Pathfinder] No Fault, FailCount= 1
2023-07-05T19:04:36.093Z,1688583876.093 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2023-07-05T19:04:54.286Z,1688583894.286 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:04:54.286Z,1688583894.286 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:04:54.286Z,1688583894.286 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:04:54.286Z,1688583894.286 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:04:54.691Z,1688583894.691 [Default:CheckIn:D] Stopped
2023-07-05T19:04:54.691Z,1688583894.691 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:04:55.110Z,1688583895.110 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.304696 min 
2023-07-05T19:04:55.110Z,1688583895.110 [Default:CheckIn:E] Stopped
2023-07-05T19:04:55.111Z,1688583895.111 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:04:55.111Z,1688583895.111 [Default:CheckIn] Stopped
2023-07-05T19:04:55.111Z,1688583895.111 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:04:55.111Z,1688583895.111 [Default:CheckIn](INFO): Running loop #10
2023-07-05T19:04:55.111Z,1688583895.111 [Default:CheckIn] Running Loop=10
2023-07-05T19:04:55.111Z,1688583895.111 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:04:55.111Z,1688583895.111 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:04:57.102Z,1688583897.102 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190507.00,A,3648.16628,N,12147.28682,W,0.058,182.36,050723,,,A*73
2023-07-05T19:04:57.113Z,1688583897.113 [NAL9602](INFO): GPS fix at 20230705T190507: (36.802771, -121.788114)
2023-07-05T19:04:57.125Z,1688583897.125 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:04:57.125Z,1688583897.125 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:05:04.334Z,1688583904.334 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0031.lzma
2023-07-05T19:05:05.336Z,1688583905.336 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0031.lzma.bak
2023-07-05T19:05:05.337Z,1688583905.337 [DataOverHttps](INFO): SBD MOMSN=18450701
2023-07-05T19:05:21.662Z,1688583921.662 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20230705T180740/Express0032.lzma
2023-07-05T19:05:22.665Z,1688583922.665 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0032.lzma.bak
2023-07-05T19:05:22.665Z,1688583922.665 [DataOverHttps](INFO): SBD MOMSN=18450704
2023-07-05T19:05:24.600Z,1688583924.600 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:05:24.600Z,1688583924.600 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:05:24.600Z,1688583924.600 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:05:30.232Z,1688583930.232 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T19:08:48.528Z,1688584128.528 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:08:48.650Z,1688584128.650 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:08:59.540Z,1688584139.540 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.914575
CHAN A1 (24V): 0.889458
CHAN A2 (12V): 0.932037
CHAN A3 (5V): 0.815531
CHAN B0 (3.3V): 0.536036
CHAN B1 (3.15aV): 0.837610
CHAN B2 (3.15bV): 0.846937
CHAN B3 (GND): -0.035525
OPEN: 0.022977
Full Scale: +/- 1 mA
2023-07-05T19:09:47.448Z,1688584187.448 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:09:47.634Z,1688584187.634 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:09:58.519Z,1688584198.519 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.915533
CHAN A1 (24V): 0.890118
CHAN A2 (12V): 0.933027
CHAN A3 (5V): 0.822421
CHAN B0 (3.3V): 0.543028
CHAN B1 (3.15aV): 0.848301
CHAN B2 (3.15bV): 0.855799
CHAN B3 (GND): -0.036355
OPEN: 0.023127
Full Scale: +/- 1 mA
2023-07-05T19:10:06.016Z,1688584206.016 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:10:06.212Z,1688584206.212 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:10:17.134Z,1688584217.134 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.917480
CHAN A1 (24V): 0.891691
CHAN A2 (12V): 0.934393
CHAN A3 (5V): 0.828153
CHAN B0 (3.3V): 0.545152
CHAN B1 (3.15aV): 0.854847
CHAN B2 (3.15bV): 0.862085
CHAN B3 (GND): -0.039299
OPEN: 0.023450
Full Scale: +/- 1 mA
2023-07-05T19:10:25.177Z,1688584225.177 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:10:25.177Z,1688584225.177 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:10:25.177Z,1688584225.177 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:10:25.177Z,1688584225.177 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:10:25.580Z,1688584225.580 [Default:CheckIn:D] Stopped
2023-07-05T19:10:25.580Z,1688584225.580 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:10:25.966Z,1688584225.966 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 58.819519 min 
2023-07-05T19:10:25.966Z,1688584225.966 [Default:CheckIn:E] Stopped
2023-07-05T19:10:25.966Z,1688584225.966 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:10:25.966Z,1688584225.966 [Default:CheckIn] Stopped
2023-07-05T19:10:25.966Z,1688584225.966 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:10:25.967Z,1688584225.967 [Default:CheckIn](INFO): Running loop #11
2023-07-05T19:10:25.967Z,1688584225.967 [Default:CheckIn] Running Loop=11
2023-07-05T19:10:25.967Z,1688584225.967 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:10:25.967Z,1688584225.967 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:10:27.978Z,1688584227.978 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191038.00,A,3648.16460,N,12147.28363,W,0.369,135.27,050723,,,D*77
2023-07-05T19:10:27.981Z,1688584227.981 [NAL9602](INFO): GPS fix at 20230705T191038: (36.802743, -121.788061)
2023-07-05T19:10:27.992Z,1688584227.992 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:10:27.992Z,1688584227.992 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:10:34.192Z,1688584234.192 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:10:34.569Z,1688584234.569 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:10:35.483Z,1688584235.483 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0034.lzma
2023-07-05T19:10:36.485Z,1688584236.485 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0034.lzma.bak
2023-07-05T19:10:36.485Z,1688584236.485 [DataOverHttps](INFO): SBD MOMSN=18450709
2023-07-05T19:10:45.427Z,1688584245.427 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.488723
CHAN A1 (24V): 0.744150
CHAN A2 (12V): 0.351821
CHAN A3 (5V): 0.115221
CHAN B0 (3.3V): 0.068850
CHAN B1 (3.15aV): 0.061853
CHAN B2 (3.15bV): 0.056423
CHAN B3 (GND): -0.011369
OPEN: 0.017533
Full Scale: +/- 1 mA
2023-07-05T19:10:49.188Z,1688584249.188 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:10:49.557Z,1688584249.557 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:10:53.588Z,1688584253.588 [DataOverHttps](INFO): Sending 437 bytes from file Logs/20230705T180740/Express0035.lzma
2023-07-05T19:10:54.589Z,1688584254.589 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0035.lzma.bak
2023-07-05T19:10:54.589Z,1688584254.589 [DataOverHttps](INFO): SBD MOMSN=18450712
2023-07-05T19:10:56.274Z,1688584256.274 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:10:56.274Z,1688584256.274 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:10:56.275Z,1688584256.275 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:10:58.684Z,1688584258.684 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T19:10:58.763Z,1688584258.763 [NAL9602](ERROR): received: 
+CSQ:1

OK522, 2, 0, 0, 0

OK
2023-07-05T19:11:00.395Z,1688584260.395 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.272973
CHAN A1 (24V): 0.484882
CHAN A2 (12V): 0.198973
CHAN A3 (5V): 0.062689
CHAN B0 (3.3V): 0.038700
CHAN B1 (3.15aV): 0.035705
CHAN B2 (3.15bV): 0.035739
CHAN B3 (GND): -0.009521
OPEN: 0.013757
Full Scale: +/- 1 mA
2023-07-05T19:11:03.596Z,1688584263.596 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:11:03.966Z,1688584263.966 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:11:14.880Z,1688584274.880 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.200984
CHAN A1 (24V): 0.388821
CHAN A2 (12V): 0.154323
CHAN A3 (5V): 0.048770
CHAN B0 (3.3V): 0.030168
CHAN B1 (3.15aV): 0.029106
CHAN B2 (3.15bV): 0.029468
CHAN B3 (GND): -0.007954
OPEN: 0.012395
Full Scale: +/- 1 mA
2023-07-05T19:11:20.584Z,1688584280.584 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:11:20.921Z,1688584280.921 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:11:31.844Z,1688584291.844 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.165758
CHAN A1 (24V): 0.332735
CHAN A2 (12V): 0.129473
CHAN A3 (5V): 0.041763
CHAN B0 (3.3V): 0.025680
CHAN B1 (3.15aV): 0.025061
CHAN B2 (3.15bV): 0.025120
CHAN B3 (GND): -0.006868
OPEN: 0.011597
Full Scale: +/- 1 mA
2023-07-05T19:11:42.275Z,1688584302.275 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:11:42.353Z,1688584302.353 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:11:53.246Z,1688584313.246 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.144393
CHAN A1 (24V): 0.297241
CHAN A2 (12V): 0.113947
CHAN A3 (5V): 0.035985
CHAN B0 (3.3V): 0.022667
CHAN B1 (3.15aV): 0.022555
CHAN B2 (3.15bV): 0.022581
CHAN B3 (GND): -0.006412
OPEN: 0.010948
Full Scale: +/- 1 mA
2023-07-05T19:12:05.752Z,1688584325.752 [RDI_Pathfinder](ERROR): only read 0 of 4 data items
2023-07-05T19:12:09.891Z,1688584329.891 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:12:10.251Z,1688584330.251 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:12:21.141Z,1688584341.141 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.125962
CHAN A1 (24V): 0.269135
CHAN A2 (12V): 0.100190
CHAN A3 (5V): 0.032495
CHAN B0 (3.3V): 0.020460
CHAN B1 (3.15aV): 0.021151
CHAN B2 (3.15bV): 0.020734
CHAN B3 (GND): -0.005900
OPEN: 0.010847
Full Scale: +/- 1 mA
2023-07-05T19:12:55.492Z,1688584375.492 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2023-07-05T19:13:47.157Z,1688584427.157 [NAL9602](INFO): SBD MO Status=0, MOMSN=27522, MT Status=0, MTMSN=0
2023-07-05T19:13:47.157Z,1688584427.157 [NAL9602](INFO): No messages in MT queue
2023-07-05T19:14:17.861Z,1688584457.861 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T19:15:33.824Z,1688584533.824 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:15:33.862Z,1688584533.862 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:15:44.791Z,1688584544.791 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.909424
CHAN A1 (24V): 0.883428
CHAN A2 (12V): 0.925763
CHAN A3 (5V): 0.677604
CHAN B0 (3.3V): 0.404385
CHAN B1 (3.15aV): 0.619286
CHAN B2 (3.15bV): 0.625057
CHAN B3 (GND): -0.059168
OPEN: 0.019951
Full Scale: +/- 1 mA
2023-07-05T19:15:53.712Z,1688584553.712 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:15:54.039Z,1688584554.039 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:15:56.879Z,1688584556.879 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:15:56.880Z,1688584556.880 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:15:56.880Z,1688584556.880 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:15:56.880Z,1688584556.880 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:15:57.265Z,1688584557.265 [Default:CheckIn:D] Stopped
2023-07-05T19:15:57.265Z,1688584557.265 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:15:57.688Z,1688584557.688 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 64.347603 min 
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn:E] Stopped
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn] Stopped
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn](INFO): Running loop #12
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn] Running Loop=12
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:15:57.689Z,1688584557.689 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:15:59.676Z,1688584559.676 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191610.00,A,3648.16600,N,12147.28229,W,0.117,14.60,050723,,,D*4A
2023-07-05T19:15:59.678Z,1688584559.678 [NAL9602](INFO): GPS fix at 20230705T191610: (36.802767, -121.788038)
2023-07-05T19:15:59.708Z,1688584559.708 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:15:59.708Z,1688584559.708 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:16:04.972Z,1688584564.972 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.910520
CHAN A1 (24V): 0.884367
CHAN A2 (12V): 0.926032
CHAN A3 (5V): 0.672390
CHAN B0 (3.3V): 0.397519
CHAN B1 (3.15aV): 0.608135
CHAN B2 (3.15bV): 0.612114
CHAN B3 (GND): -0.060715
OPEN: 0.019904
Full Scale: +/- 1 mA
2023-07-05T19:16:07.902Z,1688584567.902 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0037.lzma
2023-07-05T19:16:08.904Z,1688584568.904 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0037.lzma.bak
2023-07-05T19:16:08.905Z,1688584568.905 [DataOverHttps](INFO): SBD MOMSN=18450724
2023-07-05T19:16:21.486Z,1688584581.486 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:16:21.486Z,1688584581.486 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:16:25.140Z,1688584585.140 [DataOverHttps](INFO): Sending 643 bytes from file Logs/20230705T180740/Express0038.lzma
2023-07-05T19:16:26.141Z,1688584586.141 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0038.lzma.bak
2023-07-05T19:16:26.141Z,1688584586.141 [DataOverHttps](INFO): SBD MOMSN=18450728
2023-07-05T19:16:27.982Z,1688584587.982 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:16:27.982Z,1688584587.982 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:16:27.982Z,1688584587.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:17:32.201Z,1688584652.201 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:17:32.201Z,1688584652.201 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:17:49.562Z,1688584669.562 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:17:49.562Z,1688584669.562 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:18:14.206Z,1688584694.206 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:18:14.207Z,1688584694.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:18:40.089Z,1688584720.089 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:18:40.089Z,1688584720.089 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:18:47.332Z,1688584727.332 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:18:47.370Z,1688584727.369 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:18:58.265Z,1688584738.265 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.908335
CHAN A1 (24V): 0.882370
CHAN A2 (12V): 0.924552
CHAN A3 (5V): 0.661489
CHAN B0 (3.3V): 0.390853
CHAN B1 (3.15aV): 0.594333
CHAN B2 (3.15bV): 0.598283
CHAN B3 (GND): -0.065156
OPEN: 0.020319
Full Scale: +/- 1 mA
2023-07-05T19:19:26.116Z,1688584766.116 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:19:26.117Z,1688584766.117 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:19:38.556Z,1688584778.556 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:19:38.662Z,1688584778.662 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:19:49.591Z,1688584789.591 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.053006
CHAN A1 (24V): 0.138533
CHAN A2 (12V): 0.040778
CHAN A3 (5V): 0.014385
CHAN B0 (3.3V): 0.010496
CHAN B1 (3.15aV): 0.010502
CHAN B2 (3.15bV): 0.010463
CHAN B3 (GND): -0.001195
OPEN: 0.008734
Full Scale: +/- 1 mA
2023-07-05T19:20:14.189Z,1688584814.189 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-07-05T19:21:01.462Z,1688584861.462 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:21:01.462Z,1688584861.462 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:21:01.864Z,1688584861.864 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T19:21:28.545Z,1688584888.545 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:21:28.545Z,1688584888.545 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:21:28.545Z,1688584888.545 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:21:28.545Z,1688584888.545 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:21:28.955Z,1688584888.955 [Default:CheckIn:D] Stopped
2023-07-05T19:21:28.955Z,1688584888.955 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:21:29.348Z,1688584889.348 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 69.875773 min 
2023-07-05T19:21:29.348Z,1688584889.348 [Default:CheckIn:E] Stopped
2023-07-05T19:21:29.348Z,1688584889.348 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:21:29.349Z,1688584889.349 [Default:CheckIn] Stopped
2023-07-05T19:21:29.349Z,1688584889.349 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:21:29.349Z,1688584889.349 [Default:CheckIn](INFO): Running loop #13
2023-07-05T19:21:29.350Z,1688584889.350 [Default:CheckIn] Running Loop=13
2023-07-05T19:21:29.350Z,1688584889.350 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:21:29.350Z,1688584889.350 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:21:31.359Z,1688584891.359 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192142.00,A,3648.16586,N,12147.28221,W,0.194,46.88,050723,,,A*43
2023-07-05T19:21:31.361Z,1688584891.361 [NAL9602](INFO): GPS fix at 20230705T192142: (36.802764, -121.788037)
2023-07-05T19:21:31.388Z,1688584891.388 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:21:31.388Z,1688584891.388 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:21:39.618Z,1688584899.618 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0040.lzma
2023-07-05T19:21:40.621Z,1688584900.621 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0040.lzma.bak
2023-07-05T19:21:40.621Z,1688584900.621 [DataOverHttps](INFO): SBD MOMSN=18450754
2023-07-05T19:21:56.783Z,1688584916.783 [DataOverHttps](INFO): Sending 526 bytes from file Logs/20230705T180740/Express0041.lzma
2023-07-05T19:21:57.785Z,1688584917.785 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0041.lzma.bak
2023-07-05T19:21:57.785Z,1688584917.785 [DataOverHttps](INFO): SBD MOMSN=18450757
2023-07-05T19:21:59.710Z,1688584919.710 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:21:59.710Z,1688584919.710 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:21:59.710Z,1688584919.710 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:22:04.129Z,1688584924.129 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T19:23:23.302Z,1688585003.302 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-07-05T19:23:23.304Z,1688585003.304 [BPC1](INFO): Received data from all battery sticks.
2023-07-05T19:27:00.262Z,1688585220.262 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:27:00.262Z,1688585220.262 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:27:00.262Z,1688585220.262 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:27:00.262Z,1688585220.262 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:27:00.680Z,1688585220.680 [Default:CheckIn:D] Stopped
2023-07-05T19:27:00.680Z,1688585220.680 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:27:01.061Z,1688585221.061 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 75.404517 min 
2023-07-05T19:27:01.061Z,1688585221.061 [Default:CheckIn:E] Stopped
2023-07-05T19:27:01.061Z,1688585221.061 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:27:01.061Z,1688585221.061 [Default:CheckIn] Stopped
2023-07-05T19:27:01.061Z,1688585221.061 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:27:01.062Z,1688585221.062 [Default:CheckIn](INFO): Running loop #14
2023-07-05T19:27:01.062Z,1688585221.062 [Default:CheckIn] Running Loop=14
2023-07-05T19:27:01.062Z,1688585221.062 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:27:01.062Z,1688585221.062 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:27:03.074Z,1688585223.074 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192713.00,A,3648.16651,N,12147.28345,W,0.816,46.88,050723,,,A*48
2023-07-05T19:27:03.076Z,1688585223.076 [NAL9602](INFO): GPS fix at 20230705T192713: (36.802775, -121.788057)
2023-07-05T19:27:03.112Z,1688585223.112 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:27:03.112Z,1688585223.112 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:27:10.626Z,1688585230.626 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230705T180740/Courier0043.lzma
2023-07-05T19:27:11.629Z,1688585231.629 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0043.lzma.bak
2023-07-05T19:27:11.629Z,1688585231.629 [DataOverHttps](INFO): SBD MOMSN=18450768
2023-07-05T19:27:20.180Z,1688585240.180 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:27:20.479Z,1688585240.479 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:27:26.105Z,1688585246.105 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:27:26.106Z,1688585246.106 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:27:28.382Z,1688585248.382 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230705T180740/Express0044.lzma
2023-07-05T19:27:29.388Z,1688585249.388 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0044.lzma.bak
2023-07-05T19:27:29.388Z,1688585249.388 [DataOverHttps](INFO): SBD MOMSN=18450771
2023-07-05T19:27:31.455Z,1688585251.455 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:27:31.455Z,1688585251.455 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:27:31.455Z,1688585251.455 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:27:31.504Z,1688585251.504 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.000742
CHAN A1 (24V): 0.052236
CHAN A2 (12V): 0.000459
CHAN A3 (5V): 0.000315
CHAN B0 (3.3V): 0.002085
CHAN B1 (3.15aV): 0.002288
CHAN B2 (3.15bV): 0.001905
CHAN B3 (GND): 0.002519
OPEN: 0.006269
Full Scale: +/- 1 mA
2023-07-05T19:27:34.664Z,1688585254.664 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:27:35.048Z,1688585255.048 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:27:45.918Z,1688585265.918 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.000047
CHAN A1 (24V): 0.052227
CHAN A2 (12V): 0.000412
CHAN A3 (5V): 0.000439
CHAN B0 (3.3V): 0.002235
CHAN B1 (3.15aV): 0.001244
CHAN B2 (3.15bV): 0.002206
CHAN B3 (GND): 0.002393
OPEN: 0.006133
Full Scale: +/- 1 mA
2023-07-05T19:27:49.041Z,1688585269.041 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:27:49.167Z,1688585269.167 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:28:00.084Z,1688585280.084 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.000489
CHAN A1 (24V): 0.052395
CHAN A2 (12V): 0.000195
CHAN A3 (5V): 0.000280
CHAN B0 (3.3V): 0.001894
CHAN B1 (3.15aV): 0.001667
CHAN B2 (3.15bV): 0.002223
CHAN B3 (GND): 0.002350
OPEN: 0.006033
Full Scale: +/- 1 mA
2023-07-05T19:28:22.257Z,1688585302.257 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:28:22.258Z,1688585302.258 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:30:51.422Z,1688585451.422 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2023-07-05T19:32:05.668Z,1688585525.668 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T19:32:31.950Z,1688585551.950 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:32:31.950Z,1688585551.950 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:32:31.950Z,1688585551.950 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:32:31.950Z,1688585551.950 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:32:32.346Z,1688585552.346 [Default:CheckIn:D] Stopped
2023-07-05T19:32:32.347Z,1688585552.347 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.932292 min 
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn:E] Stopped
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn] Stopped
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn](INFO): Running loop #15
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn] Running Loop=15
2023-07-05T19:32:32.751Z,1688585552.751 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:32:32.752Z,1688585552.752 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:32:34.762Z,1688585554.762 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193245.00,A,3648.16820,N,12147.28184,W,0.311,0.00,050723,,,A*76
2023-07-05T19:32:34.764Z,1688585554.764 [NAL9602](INFO): GPS fix at 20230705T193245: (36.802803, -121.788031)
2023-07-05T19:32:34.781Z,1688585554.781 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:32:34.781Z,1688585554.781 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:32:42.676Z,1688585562.676 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0046.lzma
2023-07-05T19:32:43.677Z,1688585563.677 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0046.lzma.bak
2023-07-05T19:32:43.677Z,1688585563.677 [DataOverHttps](INFO): SBD MOMSN=18450774
2023-07-05T19:33:03.451Z,1688585583.451 [DataOverHttps](INFO): Sending 494 bytes from file Logs/20230705T180740/Express0047.lzma
2023-07-05T19:33:04.453Z,1688585584.453 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0047.lzma.bak
2023-07-05T19:33:04.453Z,1688585584.453 [DataOverHttps](INFO): SBD MOMSN=18450777
2023-07-05T19:33:06.299Z,1688585586.299 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:33:06.299Z,1688585586.299 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:33:06.300Z,1688585586.300 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:33:07.080Z,1688585587.080 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T19:33:25.097Z,1688585605.097 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 1 second
2023-07-05T19:38:06.882Z,1688585886.882 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:38:06.882Z,1688585886.882 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:38:06.883Z,1688585886.883 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:38:06.883Z,1688585886.883 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:38:07.293Z,1688585887.293 [Default:CheckIn:D] Stopped
2023-07-05T19:38:07.293Z,1688585887.293 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:38:07.712Z,1688585887.712 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.514730 min 
2023-07-05T19:38:07.712Z,1688585887.712 [Default:CheckIn:E] Stopped
2023-07-05T19:38:07.712Z,1688585887.712 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:38:07.712Z,1688585887.712 [Default:CheckIn] Stopped
2023-07-05T19:38:07.712Z,1688585887.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:38:07.712Z,1688585887.712 [Default:CheckIn](INFO): Running loop #16
2023-07-05T19:38:07.712Z,1688585887.712 [Default:CheckIn] Running Loop=16
2023-07-05T19:38:07.713Z,1688585887.713 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:38:07.713Z,1688585887.713 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:38:09.702Z,1688585889.702 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193820.00,A,3648.16605,N,12147.28003,W,0.389,0.00,050723,,,A*79
2023-07-05T19:38:09.704Z,1688585889.704 [NAL9602](INFO): GPS fix at 20230705T193820: (36.802768, -121.788000)
2023-07-05T19:38:09.756Z,1688585889.756 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:38:09.757Z,1688585889.757 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:38:19.958Z,1688585899.958 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0049.lzma
2023-07-05T19:38:20.961Z,1688585900.961 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0049.lzma.bak
2023-07-05T19:38:20.961Z,1688585900.961 [DataOverHttps](INFO): SBD MOMSN=18450790
2023-07-05T19:38:40.302Z,1688585920.302 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20230705T180740/Express0050.lzma
2023-07-05T19:38:40.404Z,1688585920.404 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T19:38:40.479Z,1688585920.479 [NAL9602](ERROR): received: 
+CSQ:0

OK523, 2, 0, 0, 0

OK
2023-07-05T19:38:41.308Z,1688585921.308 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0050.lzma.bak
2023-07-05T19:38:41.308Z,1688585921.308 [DataOverHttps](INFO): SBD MOMSN=18450793
2023-07-05T19:38:43.251Z,1688585923.251 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:38:43.252Z,1688585923.252 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:38:43.252Z,1688585923.252 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:38:45.588Z,1688585925.588 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:38:45.775Z,1688585925.775 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:38:56.608Z,1688585936.608 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.906228
CHAN A1 (24V): 0.881577
CHAN A2 (12V): 0.924000
CHAN A3 (5V): 0.627824
CHAN B0 (3.3V): 0.337195
CHAN B1 (3.15aV): 0.525518
CHAN B2 (3.15bV): 0.535075
CHAN B3 (GND): -0.078969
OPEN: 0.017060
Full Scale: +/- 1 mA
2023-07-05T19:40:16.696Z,1688586016.696 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:40:16.999Z,1688586016.999 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:40:27.918Z,1688586027.918 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.881497
CHAN A1 (24V): 0.857440
CHAN A2 (12V): 0.896496
CHAN A3 (5V): 0.291698
CHAN B0 (3.3V): 0.088220
CHAN B1 (3.15aV): 0.091575
CHAN B2 (3.15bV): 0.095879
CHAN B3 (GND): -0.018646
OPEN: 0.010544
Full Scale: +/- 1 mA
2023-07-05T19:40:33.156Z,1688586033.156 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:40:33.574Z,1688586033.574 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:40:44.488Z,1688586044.488 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.887014
CHAN A1 (24V): 0.860984
CHAN A2 (12V): 0.900049
CHAN A3 (5V): 0.311009
CHAN B0 (3.3V): 0.094595
CHAN B1 (3.15aV): 0.102603
CHAN B2 (3.15bV): 0.106405
CHAN B3 (GND): -0.021626
OPEN: 0.010547
Full Scale: +/- 1 mA
2023-07-05T19:41:05.788Z,1688586065.788 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:41:05.899Z,1688586065.899 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:41:16.792Z,1688586076.792 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.094292
CHAN A1 (24V): 0.222502
CHAN A2 (12V): 0.073747
CHAN A3 (5V): 0.021815
CHAN B0 (3.3V): 0.014624
CHAN B1 (3.15aV): 0.013508
CHAN B2 (3.15bV): 0.014447
CHAN B3 (GND): -0.003272
OPEN: 0.009893
Full Scale: +/- 1 mA
2023-07-05T19:42:39.728Z,1688586159.728 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T19:42:40.047Z,1688586160.047 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T19:42:50.928Z,1688586170.928 [CBIT](IMPORTANT): Low side ground fault detected
mA:
CHAN A0 (Batt): 0.909355
CHAN A1 (24V): 0.884125
CHAN A2 (12V): 0.926072
CHAN A3 (5V): 0.660997
CHAN B0 (3.3V): 0.362506
CHAN B1 (3.15aV): 0.569992
CHAN B2 (3.15bV): 0.568800
CHAN B3 (GND): -0.081114
OPEN: 0.017069
Full Scale: +/- 1 mA
2023-07-05T19:43:11.888Z,1688586191.888 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T19:43:42.596Z,1688586222.596 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T19:43:43.818Z,1688586223.818 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:43:43.818Z,1688586223.818 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:43:43.819Z,1688586223.819 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:43:43.819Z,1688586223.819 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:43:44.228Z,1688586224.228 [Default:CheckIn:D] Stopped
2023-07-05T19:43:44.228Z,1688586224.228 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:43:44.626Z,1688586224.626 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.130322 min 
2023-07-05T19:43:44.626Z,1688586224.626 [Default:CheckIn:E] Stopped
2023-07-05T19:43:44.643Z,1688586224.643 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:43:44.643Z,1688586224.643 [Default:CheckIn] Stopped
2023-07-05T19:43:44.643Z,1688586224.643 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:43:44.643Z,1688586224.643 [Default:CheckIn](INFO): Running loop #17
2023-07-05T19:43:44.643Z,1688586224.643 [Default:CheckIn] Running Loop=17
2023-07-05T19:43:44.643Z,1688586224.643 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:43:44.643Z,1688586224.643 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:43:46.633Z,1688586226.633 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194357.00,A,3648.17312,N,12147.28253,W,0.603,0.00,050723,,,A*77
2023-07-05T19:43:46.636Z,1688586226.636 [NAL9602](INFO): GPS fix at 20230705T194357: (36.802885, -121.788042)
2023-07-05T19:43:46.647Z,1688586226.647 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:43:46.647Z,1688586226.647 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:43:54.390Z,1688586234.390 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0052.lzma
2023-07-05T19:43:55.393Z,1688586235.393 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0052.lzma.bak
2023-07-05T19:43:55.393Z,1688586235.393 [DataOverHttps](INFO): SBD MOMSN=18450797
2023-07-05T19:44:07.650Z,1688586247.650 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:44:07.651Z,1688586247.651 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:44:12.527Z,1688586252.527 [DataOverHttps](INFO): Sending 632 bytes from file Logs/20230705T180740/Express0053.lzma
2023-07-05T19:44:13.529Z,1688586253.529 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0053.lzma.bak
2023-07-05T19:44:13.529Z,1688586253.529 [DataOverHttps](INFO): SBD MOMSN=18450800
2023-07-05T19:44:15.371Z,1688586255.371 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:44:15.371Z,1688586255.371 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:44:15.372Z,1688586255.372 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:45:10.665Z,1688586310.665 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:45:10.665Z,1688586310.665 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:46:10.862Z,1688586370.862 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T19:46:10.862Z,1688586370.862 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T19:48:48.823Z,1688586528.823 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T19:49:15.927Z,1688586555.927 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:49:15.927Z,1688586555.927 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:49:15.927Z,1688586555.927 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:49:15.927Z,1688586555.927 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:49:16.311Z,1688586556.311 [Default:CheckIn:D] Stopped
2023-07-05T19:49:16.311Z,1688586556.311 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:49:16.711Z,1688586556.711 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 97.665039 min 
2023-07-05T19:49:16.711Z,1688586556.711 [Default:CheckIn:E] Stopped
2023-07-05T19:49:16.711Z,1688586556.711 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:49:16.712Z,1688586556.712 [Default:CheckIn] Stopped
2023-07-05T19:49:16.712Z,1688586556.712 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:49:16.712Z,1688586556.712 [Default:CheckIn](INFO): Running loop #18
2023-07-05T19:49:16.712Z,1688586556.712 [Default:CheckIn] Running Loop=18
2023-07-05T19:49:16.712Z,1688586556.712 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:49:16.712Z,1688586556.712 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:49:18.722Z,1688586558.722 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194929.00,A,3648.16957,N,12147.28120,W,0.447,0.00,050723,,,A*7B
2023-07-05T19:49:18.724Z,1688586558.724 [NAL9602](INFO): GPS fix at 20230705T194929: (36.802826, -121.788020)
2023-07-05T19:49:18.760Z,1688586558.760 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:49:18.760Z,1688586558.760 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:49:26.126Z,1688586566.126 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0055.lzma
2023-07-05T19:49:27.129Z,1688586567.129 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0055.lzma.bak
2023-07-05T19:49:27.129Z,1688586567.129 [DataOverHttps](INFO): SBD MOMSN=18450819
2023-07-05T19:49:43.887Z,1688586583.887 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230705T180740/Express0056.lzma
2023-07-05T19:49:44.889Z,1688586584.889 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0056.lzma.bak
2023-07-05T19:49:44.889Z,1688586584.889 [DataOverHttps](INFO): SBD MOMSN=18450822
2023-07-05T19:49:46.619Z,1688586586.619 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:49:46.619Z,1688586586.619 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:49:46.619Z,1688586586.619 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:49:51.040Z,1688586591.040 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T19:50:07.633Z,1688586607.633 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2023-07-05T19:54:47.187Z,1688586887.187 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T19:54:47.187Z,1688586887.187 [Default:CheckIn:C.Wait] Stopped
2023-07-05T19:54:47.187Z,1688586887.187 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T19:54:47.187Z,1688586887.187 [Default:CheckIn:D] Running Loop=1
2023-07-05T19:54:47.614Z,1688586887.614 [Default:CheckIn:D] Stopped
2023-07-05T19:54:47.614Z,1688586887.614 [Default:CheckIn:E] Running Loop=1
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.186751 min 
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn:E] Stopped
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn] Stopped
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn](INFO): Running loop #19
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn] Running Loop=19
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T19:54:48.007Z,1688586888.007 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T19:54:50.009Z,1688586890.009 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195500.00,A,3648.16555,N,12147.28451,W,0.078,0.00,050723,,,D*7D
2023-07-05T19:54:50.011Z,1688586890.011 [NAL9602](INFO): GPS fix at 20230705T195500: (36.802759, -121.788075)
2023-07-05T19:54:50.050Z,1688586890.050 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T19:54:50.050Z,1688586890.050 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T19:54:57.678Z,1688586897.678 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0058.lzma
2023-07-05T19:54:58.681Z,1688586898.681 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0058.lzma.bak
2023-07-05T19:54:58.681Z,1688586898.681 [DataOverHttps](INFO): SBD MOMSN=18450826
2023-07-05T19:55:14.994Z,1688586914.994 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230705T180740/Express0059.lzma
2023-07-05T19:55:15.997Z,1688586915.997 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0059.lzma.bak
2023-07-05T19:55:15.997Z,1688586915.997 [DataOverHttps](INFO): SBD MOMSN=18450829
2023-07-05T19:55:17.903Z,1688586917.903 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T19:55:17.903Z,1688586917.903 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T19:55:17.904Z,1688586917.904 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T19:55:20.708Z,1688586920.708 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T19:55:20.791Z,1688586920.791 [NAL9602](ERROR): received: 
+CSQ:0

OK523, 2, 0, 0, 0

OK
2023-07-05T19:59:51.808Z,1688587191.808 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T20:00:18.482Z,1688587218.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:00:18.482Z,1688587218.482 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:00:18.482Z,1688587218.482 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:00:18.482Z,1688587218.482 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:00:18.901Z,1688587218.901 [Default:CheckIn:D] Stopped
2023-07-05T20:00:18.901Z,1688587218.901 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:00:19.357Z,1688587219.357 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 108.708195 min 
2023-07-05T20:00:19.357Z,1688587219.357 [Default:CheckIn:E] Stopped
2023-07-05T20:00:19.357Z,1688587219.357 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:00:19.357Z,1688587219.357 [Default:CheckIn] Stopped
2023-07-05T20:00:19.357Z,1688587219.357 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:00:19.358Z,1688587219.358 [Default:CheckIn](INFO): Running loop #20
2023-07-05T20:00:19.358Z,1688587219.358 [Default:CheckIn] Running Loop=20
2023-07-05T20:00:19.358Z,1688587219.358 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:00:19.358Z,1688587219.358 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:00:21.314Z,1688587221.314 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200032.00,A,3648.16720,N,12147.28326,W,0.058,0.00,050723,,,D*73
2023-07-05T20:00:21.321Z,1688587221.321 [NAL9602](INFO): GPS fix at 20230705T200032: (36.802787, -121.788054)
2023-07-05T20:00:21.375Z,1688587221.375 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:00:21.375Z,1688587221.375 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:00:28.706Z,1688587228.706 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0061.lzma
2023-07-05T20:00:29.709Z,1688587229.709 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0061.lzma.bak
2023-07-05T20:00:29.709Z,1688587229.709 [DataOverHttps](INFO): SBD MOMSN=18450832
2023-07-05T20:00:45.951Z,1688587245.951 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230705T180740/Express0062.lzma
2023-07-05T20:00:46.953Z,1688587246.953 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0062.lzma.bak
2023-07-05T20:00:46.953Z,1688587246.953 [DataOverHttps](INFO): SBD MOMSN=18450835
2023-07-05T20:00:48.790Z,1688587248.790 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:00:48.790Z,1688587248.790 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:00:48.790Z,1688587248.790 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:00:54.023Z,1688587254.023 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T20:05:49.390Z,1688587549.390 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:05:49.391Z,1688587549.391 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:05:49.391Z,1688587549.391 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:05:49.391Z,1688587549.391 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:05:49.763Z,1688587549.763 [Default:CheckIn:D] Stopped
2023-07-05T20:05:49.763Z,1688587549.763 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:05:50.167Z,1688587550.167 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 114.222567 min 
2023-07-05T20:05:50.167Z,1688587550.167 [Default:CheckIn:E] Stopped
2023-07-05T20:05:50.167Z,1688587550.167 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:05:50.167Z,1688587550.167 [Default:CheckIn] Stopped
2023-07-05T20:05:50.167Z,1688587550.167 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:05:50.168Z,1688587550.168 [Default:CheckIn](INFO): Running loop #21
2023-07-05T20:05:50.168Z,1688587550.168 [Default:CheckIn] Running Loop=21
2023-07-05T20:05:50.168Z,1688587550.168 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:05:50.168Z,1688587550.168 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:05:52.174Z,1688587552.174 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200602.00,A,3648.17377,N,12147.27622,W,0.175,0.00,050723,,,A*74
2023-07-05T20:05:52.176Z,1688587552.176 [NAL9602](INFO): GPS fix at 20230705T200602: (36.802896, -121.787937)
2023-07-05T20:05:52.220Z,1688587552.220 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:05:52.220Z,1688587552.220 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:06:00.130Z,1688587560.130 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0064.lzma
2023-07-05T20:06:01.133Z,1688587561.133 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0064.lzma.bak
2023-07-05T20:06:01.133Z,1688587561.133 [DataOverHttps](INFO): SBD MOMSN=18450839
2023-07-05T20:06:17.498Z,1688587577.498 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230705T180740/Express0065.lzma
2023-07-05T20:06:18.501Z,1688587578.501 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0065.lzma.bak
2023-07-05T20:06:18.501Z,1688587578.501 [DataOverHttps](INFO): SBD MOMSN=18450842
2023-07-05T20:06:20.481Z,1688587580.481 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:06:20.481Z,1688587580.481 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:06:20.481Z,1688587580.481 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:06:22.884Z,1688587582.884 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T20:06:22.963Z,1688587582.963 [NAL9602](ERROR): received: 
+CSQ:0

OK523, 2, 0, 0, 0

OK
2023-07-05T20:09:53.388Z,1688587793.388 [RDI_Pathfinder](ERROR): only read 3 of 4 data items
2023-07-05T20:10:25.701Z,1688587825.701 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range.
2023-07-05T20:10:54.769Z,1688587854.769 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T20:11:21.093Z,1688587881.093 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:11:21.093Z,1688587881.093 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:11:21.093Z,1688587881.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:11:21.093Z,1688587881.093 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:11:21.468Z,1688587881.468 [Default:CheckIn:D] Stopped
2023-07-05T20:11:21.468Z,1688587881.468 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:11:21.851Z,1688587881.851 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.750993 min 
2023-07-05T20:11:21.851Z,1688587881.851 [Default:CheckIn:E] Stopped
2023-07-05T20:11:21.851Z,1688587881.851 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:11:21.851Z,1688587881.851 [Default:CheckIn] Stopped
2023-07-05T20:11:21.851Z,1688587881.851 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:11:21.851Z,1688587881.851 [Default:CheckIn](INFO): Running loop #22
2023-07-05T20:11:21.851Z,1688587881.851 [Default:CheckIn] Running Loop=22
2023-07-05T20:11:21.852Z,1688587881.852 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:11:21.852Z,1688587881.852 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:11:23.861Z,1688587883.861 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201134.00,A,3648.16847,N,12147.27669,W,0.447,0.00,050723,,,A*75
2023-07-05T20:11:23.864Z,1688587883.864 [NAL9602](INFO): GPS fix at 20230705T201134: (36.802808, -121.787945)
2023-07-05T20:11:23.875Z,1688587883.875 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:11:23.875Z,1688587883.875 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:11:31.486Z,1688587891.486 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0067.lzma
2023-07-05T20:11:32.489Z,1688587892.489 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0067.lzma.bak
2023-07-05T20:11:32.489Z,1688587892.489 [DataOverHttps](INFO): SBD MOMSN=18450845
2023-07-05T20:11:48.834Z,1688587908.834 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230705T180740/Express0068.lzma
2023-07-05T20:11:49.837Z,1688587909.837 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0068.lzma.bak
2023-07-05T20:11:49.837Z,1688587909.837 [DataOverHttps](INFO): SBD MOMSN=18450848
2023-07-05T20:11:51.754Z,1688587911.754 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:11:51.754Z,1688587911.754 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:11:51.754Z,1688587911.754 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:11:55.772Z,1688587915.772 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T20:16:52.329Z,1688588212.329 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:16:52.329Z,1688588212.329 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:16:52.329Z,1688588212.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:16:52.329Z,1688588212.329 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:16:52.726Z,1688588212.726 [Default:CheckIn:D] Stopped
2023-07-05T20:16:52.727Z,1688588212.727 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.271965 min 
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn:E] Stopped
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn] Stopped
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn](INFO): Running loop #23
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn] Running Loop=23
2023-07-05T20:16:53.131Z,1688588213.131 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:16:53.132Z,1688588213.132 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:16:55.138Z,1688588215.138 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201705.00,A,3648.16261,N,12147.27497,W,0.330,0.00,050723,,,A*7B
2023-07-05T20:16:55.140Z,1688588215.140 [NAL9602](INFO): GPS fix at 20230705T201705: (36.802710, -121.787916)
2023-07-05T20:16:55.151Z,1688588215.151 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:16:55.151Z,1688588215.151 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:17:02.430Z,1688588222.430 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0070.lzma
2023-07-05T20:17:03.429Z,1688588223.429 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0070.lzma.bak
2023-07-05T20:17:03.429Z,1688588223.429 [DataOverHttps](INFO): SBD MOMSN=18450852
2023-07-05T20:17:19.770Z,1688588239.770 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230705T180740/Express0071.lzma
2023-07-05T20:17:20.773Z,1688588240.773 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0071.lzma.bak
2023-07-05T20:17:20.773Z,1688588240.773 [DataOverHttps](INFO): SBD MOMSN=18450855
2023-07-05T20:17:22.648Z,1688588242.648 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:17:22.648Z,1688588242.648 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:17:22.648Z,1688588242.648 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:17:25.868Z,1688588245.868 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T20:17:25.951Z,1688588245.951 [NAL9602](ERROR): received: 
+CSQ:0

OK523, 2, 0, 0, 0

OK
2023-07-05T20:18:46.270Z,1688588326.270 [NAL9602](INFO): SBD MO Status=2, MOMSN=27523, MT Status=2, MTMSN=0
2023-07-05T20:18:46.271Z,1688588326.271 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T20:21:57.764Z,1688588517.764 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T20:22:23.231Z,1688588543.231 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:22:23.231Z,1688588543.231 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:22:23.231Z,1688588543.231 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:22:23.231Z,1688588543.231 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:22:23.678Z,1688588543.678 [Default:CheckIn:D] Stopped
2023-07-05T20:22:23.678Z,1688588543.678 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:22:24.036Z,1688588544.036 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.787826 min 
2023-07-05T20:22:24.036Z,1688588544.036 [Default:CheckIn:E] Stopped
2023-07-05T20:22:24.036Z,1688588544.036 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:22:24.036Z,1688588544.036 [Default:CheckIn] Stopped
2023-07-05T20:22:24.036Z,1688588544.036 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:22:24.036Z,1688588544.036 [Default:CheckIn](INFO): Running loop #24
2023-07-05T20:22:24.037Z,1688588544.037 [Default:CheckIn] Running Loop=24
2023-07-05T20:22:24.037Z,1688588544.037 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:22:24.037Z,1688588544.037 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:22:26.053Z,1688588546.053 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202236.00,A,3648.16816,N,12147.27684,W,0.117,46.88,050723,,,A*42
2023-07-05T20:22:26.056Z,1688588546.056 [NAL9602](INFO): GPS fix at 20230705T202236: (36.802803, -121.787947)
2023-07-05T20:22:26.067Z,1688588546.067 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:22:26.067Z,1688588546.067 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:22:33.974Z,1688588553.974 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0073.lzma
2023-07-05T20:22:34.977Z,1688588554.977 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0073.lzma.bak
2023-07-05T20:22:34.977Z,1688588554.977 [DataOverHttps](INFO): SBD MOMSN=18450858
2023-07-05T20:22:51.382Z,1688588571.382 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230705T180740/Express0074.lzma
2023-07-05T20:22:52.385Z,1688588572.385 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0074.lzma.bak
2023-07-05T20:22:52.385Z,1688588572.385 [DataOverHttps](INFO): SBD MOMSN=18450861
2023-07-05T20:22:54.336Z,1688588574.336 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:22:54.336Z,1688588574.336 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:22:54.336Z,1688588574.336 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:22:58.768Z,1688588578.768 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T20:27:54.968Z,1688588874.968 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:27:54.968Z,1688588874.968 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:27:54.969Z,1688588874.969 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:27:54.969Z,1688588874.969 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:27:55.380Z,1688588875.380 [Default:CheckIn:D] Stopped
2023-07-05T20:27:55.380Z,1688588875.380 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:27:55.735Z,1688588875.735 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.316187 min 
2023-07-05T20:27:55.735Z,1688588875.735 [Default:CheckIn:E] Stopped
2023-07-05T20:27:55.736Z,1688588875.736 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:27:55.736Z,1688588875.736 [Default:CheckIn] Stopped
2023-07-05T20:27:55.736Z,1688588875.736 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:27:55.736Z,1688588875.736 [Default:CheckIn](INFO): Running loop #25
2023-07-05T20:27:55.736Z,1688588875.736 [Default:CheckIn] Running Loop=25
2023-07-05T20:27:55.736Z,1688588875.736 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:27:55.736Z,1688588875.736 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:27:57.734Z,1688588877.734 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202808.00,A,3648.17048,N,12147.28110,W,0.311,0.00,050723,,,A*74
2023-07-05T20:27:57.736Z,1688588877.736 [NAL9602](INFO): GPS fix at 20230705T202808: (36.802841, -121.788018)
2023-07-05T20:27:57.775Z,1688588877.775 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:27:57.775Z,1688588877.775 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:28:05.102Z,1688588885.102 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0076.lzma
2023-07-05T20:28:06.105Z,1688588886.105 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0076.lzma.bak
2023-07-05T20:28:06.105Z,1688588886.105 [DataOverHttps](INFO): SBD MOMSN=18450865
2023-07-05T20:28:25.318Z,1688588905.318 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230705T180740/Express0077.lzma
2023-07-05T20:28:26.313Z,1688588906.313 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0077.lzma.bak
2023-07-05T20:28:26.313Z,1688588906.313 [DataOverHttps](INFO): SBD MOMSN=18450868
2023-07-05T20:28:28.048Z,1688588908.048 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:28:28.048Z,1688588908.048 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:28:28.048Z,1688588908.048 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:28:28.433Z,1688588908.433 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T20:28:28.507Z,1688588908.507 [NAL9602](ERROR): received: 
+CSQ:0

OK523, 2, 0, 0, 0

OK
2023-07-05T20:30:53.077Z,1688589053.077 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-07-05T20:30:53.080Z,1688589053.080 [BPC1](INFO): Received data from all battery sticks.
2023-07-05T20:32:59.924Z,1688589179.924 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T20:33:28.635Z,1688589208.635 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:33:28.635Z,1688589208.635 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:33:28.635Z,1688589208.635 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:33:28.636Z,1688589208.636 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:33:29.021Z,1688589209.021 [Default:CheckIn:D] Stopped
2023-07-05T20:33:29.021Z,1688589209.021 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:33:29.444Z,1688589209.444 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.876872 min 
2023-07-05T20:33:29.444Z,1688589209.444 [Default:CheckIn:E] Stopped
2023-07-05T20:33:29.445Z,1688589209.445 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:33:29.445Z,1688589209.445 [Default:CheckIn] Stopped
2023-07-05T20:33:29.445Z,1688589209.445 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:33:29.445Z,1688589209.445 [Default:CheckIn](INFO): Running loop #26
2023-07-05T20:33:29.445Z,1688589209.445 [Default:CheckIn] Running Loop=26
2023-07-05T20:33:29.445Z,1688589209.445 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:33:29.445Z,1688589209.445 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:33:31.434Z,1688589211.434 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203342.00,A,3648.17025,N,12147.28152,W,0.039,0.00,050723,,,A*74
2023-07-05T20:33:31.437Z,1688589211.437 [NAL9602](INFO): GPS fix at 20230705T203342: (36.802838, -121.788025)
2023-07-05T20:33:31.467Z,1688589211.467 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:33:31.467Z,1688589211.467 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:33:39.210Z,1688589219.210 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230705T180740/Courier0079.lzma
2023-07-05T20:33:40.213Z,1688589220.213 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0079.lzma.bak
2023-07-05T20:33:40.213Z,1688589220.213 [DataOverHttps](INFO): SBD MOMSN=18450871
2023-07-05T20:33:56.639Z,1688589236.639 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230705T180740/Express0080.lzma
2023-07-05T20:33:57.641Z,1688589237.641 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0080.lzma.bak
2023-07-05T20:33:57.641Z,1688589237.641 [DataOverHttps](INFO): SBD MOMSN=18450874
2023-07-05T20:33:59.388Z,1688589239.388 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:33:59.388Z,1688589239.388 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:33:59.388Z,1688589239.388 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:34:03.756Z,1688589243.756 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T20:38:59.932Z,1688589539.932 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:38:59.932Z,1688589539.932 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:38:59.932Z,1688589539.932 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:38:59.932Z,1688589539.932 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:39:00.334Z,1688589540.334 [Default:CheckIn:D] Stopped
2023-07-05T20:39:00.334Z,1688589540.334 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:39:00.743Z,1688589540.743 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.398747 min 
2023-07-05T20:39:00.743Z,1688589540.743 [Default:CheckIn:E] Stopped
2023-07-05T20:39:00.744Z,1688589540.744 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:39:00.744Z,1688589540.744 [Default:CheckIn] Stopped
2023-07-05T20:39:00.744Z,1688589540.744 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:39:00.744Z,1688589540.744 [Default:CheckIn](INFO): Running loop #27
2023-07-05T20:39:00.744Z,1688589540.744 [Default:CheckIn] Running Loop=27
2023-07-05T20:39:00.744Z,1688589540.744 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:39:00.744Z,1688589540.744 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:39:02.746Z,1688589542.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203913.00,A,3648.17395,N,12147.28181,W,0.097,0.00,050723,,,A*78
2023-07-05T20:39:02.748Z,1688589542.748 [NAL9602](INFO): GPS fix at 20230705T203913: (36.802899, -121.788030)
2023-07-05T20:39:02.760Z,1688589542.760 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:39:02.760Z,1688589542.760 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:39:10.922Z,1688589550.922 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0082.lzma
2023-07-05T20:39:11.925Z,1688589551.925 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0082.lzma.bak
2023-07-05T20:39:11.925Z,1688589551.925 [DataOverHttps](INFO): SBD MOMSN=18450878
2023-07-05T20:39:28.130Z,1688589568.130 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230705T180740/Express0083.lzma
2023-07-05T20:39:29.133Z,1688589569.133 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0083.lzma.bak
2023-07-05T20:39:29.133Z,1688589569.133 [DataOverHttps](INFO): SBD MOMSN=18450881
2023-07-05T20:39:31.051Z,1688589571.051 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:39:31.051Z,1688589571.051 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:39:31.051Z,1688589571.051 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:39:33.444Z,1688589573.444 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T20:39:33.523Z,1688589573.523 [NAL9602](ERROR): received: 
+CSQ:0

OK523, 2, 0, 0, 0

OK
2023-07-05T20:44:04.931Z,1688589844.931 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T20:44:31.630Z,1688589871.630 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:44:31.630Z,1688589871.630 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:44:31.630Z,1688589871.630 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:44:31.630Z,1688589871.630 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:44:32.022Z,1688589872.022 [Default:CheckIn:D] Stopped
2023-07-05T20:44:32.022Z,1688589872.022 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:44:32.420Z,1688589872.420 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.926888 min 
2023-07-05T20:44:32.420Z,1688589872.420 [Default:CheckIn:E] Stopped
2023-07-05T20:44:32.420Z,1688589872.420 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:44:32.420Z,1688589872.420 [Default:CheckIn] Stopped
2023-07-05T20:44:32.420Z,1688589872.420 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:44:32.420Z,1688589872.420 [Default:CheckIn](INFO): Running loop #28
2023-07-05T20:44:32.420Z,1688589872.420 [Default:CheckIn] Running Loop=28
2023-07-05T20:44:32.421Z,1688589872.421 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:44:32.421Z,1688589872.421 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:44:34.429Z,1688589874.429 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204445.00,A,3648.16841,N,12147.27757,W,0.350,0.00,050723,,,A*78
2023-07-05T20:44:34.432Z,1688589874.432 [NAL9602](INFO): GPS fix at 20230705T204445: (36.802807, -121.787959)
2023-07-05T20:44:34.443Z,1688589874.443 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:44:34.444Z,1688589874.444 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:44:41.822Z,1688589881.822 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0085.lzma
2023-07-05T20:44:42.825Z,1688589882.825 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0085.lzma.bak
2023-07-05T20:44:42.825Z,1688589882.825 [DataOverHttps](INFO): SBD MOMSN=18450884
2023-07-05T20:44:59.014Z,1688589899.014 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230705T180740/Express0086.lzma
2023-07-05T20:45:00.017Z,1688589900.017 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0086.lzma.bak
2023-07-05T20:45:00.017Z,1688589900.017 [DataOverHttps](INFO): SBD MOMSN=18450887
2023-07-05T20:45:01.911Z,1688589901.911 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:45:01.912Z,1688589901.912 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:45:01.912Z,1688589901.912 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:45:06.748Z,1688589906.748 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T20:49:15.649Z,1688590155.649 [RDI_Pathfinder](ERROR): only read 2 of 4 data items
2023-07-05T20:50:02.484Z,1688590202.484 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:50:02.484Z,1688590202.484 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:50:02.484Z,1688590202.484 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:50:02.484Z,1688590202.484 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:50:02.897Z,1688590202.897 [Default:CheckIn:D] Stopped
2023-07-05T20:50:02.897Z,1688590202.897 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.441471 min 
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn:E] Stopped
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn] Stopped
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn](INFO): Running loop #29
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn] Running Loop=29
2023-07-05T20:50:03.367Z,1688590203.367 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:50:03.368Z,1688590203.368 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:50:05.341Z,1688590205.341 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205016.00,A,3648.16656,N,12147.27716,W,0.136,0.00,050723,,,A*74
2023-07-05T20:50:05.344Z,1688590205.344 [NAL9602](INFO): GPS fix at 20230705T205016: (36.802776, -121.787953)
2023-07-05T20:50:05.375Z,1688590205.375 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:50:05.375Z,1688590205.375 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:50:12.622Z,1688590212.622 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230705T180740/Courier0088.lzma
2023-07-05T20:50:13.625Z,1688590213.625 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0088.lzma.bak
2023-07-05T20:50:13.625Z,1688590213.625 [DataOverHttps](INFO): SBD MOMSN=18450891
2023-07-05T20:50:29.921Z,1688590229.921 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230705T180740/Express0089.lzma
2023-07-05T20:50:30.921Z,1688590230.921 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0089.lzma.bak
2023-07-05T20:50:30.921Z,1688590230.921 [DataOverHttps](INFO): SBD MOMSN=18450894
2023-07-05T20:50:32.803Z,1688590232.803 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:50:32.803Z,1688590232.803 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:50:32.804Z,1688590232.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:50:36.004Z,1688590236.004 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T20:50:36.079Z,1688590236.079 [NAL9602](ERROR): received: 
+CSQ:0

OK523, 2, 0, 0, 0

OK
2023-07-05T20:50:39.644Z,1688590239.644 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2023-07-05T20:51:30.145Z,1688590290.145 [NAL9602](INFO): SBD MO Status=0, MOMSN=27523, MT Status=0, MTMSN=0
2023-07-05T20:51:30.146Z,1688590290.146 [NAL9602](INFO): No messages in MT queue
2023-07-05T20:52:00.848Z,1688590320.848 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T20:55:33.386Z,1688590533.386 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T20:55:33.386Z,1688590533.386 [Default:CheckIn:C.Wait] Stopped
2023-07-05T20:55:33.386Z,1688590533.386 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T20:55:33.386Z,1688590533.386 [Default:CheckIn:D] Running Loop=1
2023-07-05T20:55:33.773Z,1688590533.773 [Default:CheckIn:D] Stopped
2023-07-05T20:55:33.773Z,1688590533.773 [Default:CheckIn:E] Running Loop=1
2023-07-05T20:55:34.170Z,1688590534.170 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 163.956071 min 
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn:E] Stopped
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn] Stopped
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn](INFO): Running loop #30
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn] Running Loop=30
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T20:55:34.187Z,1688590534.187 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T20:55:36.182Z,1688590536.182 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205547.00,A,3648.16788,N,12147.28053,W,0.039,0.00,050723,,,A*70
2023-07-05T20:55:36.184Z,1688590536.184 [NAL9602](INFO): GPS fix at 20230705T205547: (36.802798, -121.788009)
2023-07-05T20:55:36.196Z,1688590536.196 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T20:55:36.196Z,1688590536.196 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T20:55:44.018Z,1688590544.018 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0091.lzma
2023-07-05T20:55:45.473Z,1688590545.473 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0091.lzma.bak
2023-07-05T20:55:45.473Z,1688590545.473 [DataOverHttps](INFO): SBD MOMSN=18450898
2023-07-05T20:56:01.297Z,1688590561.297 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230705T180740/Express0092.lzma
2023-07-05T20:56:02.294Z,1688590562.294 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0092.lzma.bak
2023-07-05T20:56:02.294Z,1688590562.294 [DataOverHttps](INFO): SBD MOMSN=18450901
2023-07-05T20:56:04.071Z,1688590564.071 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T20:56:04.071Z,1688590564.071 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T20:56:04.072Z,1688590564.072 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T20:56:11.730Z,1688590571.730 [NAL9602](INFO): SBD MO Status=2, MOMSN=27524, MT Status=2, MTMSN=0
2023-07-05T20:56:11.730Z,1688590571.730 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T20:56:37.181Z,1688590597.181 [NAL9602](INFO): SBD MO Status=2, MOMSN=27524, MT Status=2, MTMSN=0
2023-07-05T20:56:37.181Z,1688590597.181 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:00:13.334Z,1688590813.334 [NAL9602](INFO): SBD MO Status=2, MOMSN=27524, MT Status=2, MTMSN=0
2023-07-05T21:00:13.334Z,1688590813.334 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:00:30.294Z,1688590830.293 [NAL9602](INFO): SBD MO Status=0, MOMSN=27524, MT Status=0, MTMSN=0
2023-07-05T21:00:30.294Z,1688590830.294 [NAL9602](INFO): No messages in MT queue
2023-07-05T21:01:00.000Z,1688590861.000 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T21:01:04.642Z,1688590864.642 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:01:04.642Z,1688590864.642 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:01:04.642Z,1688590864.642 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:01:04.642Z,1688590864.642 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:01:05.048Z,1688590865.048 [Default:CheckIn:D] Stopped
2023-07-05T21:01:05.048Z,1688590865.048 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 169.477327 min 
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn:E] Stopped
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn] Stopped
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn](INFO): Running loop #31
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn] Running Loop=31
2023-07-05T21:01:05.481Z,1688590865.481 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:01:05.482Z,1688590865.482 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:01:07.462Z,1688590867.462 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210118.00,A,3648.16855,N,12147.28295,W,0.175,99.77,050723,,,A*44
2023-07-05T21:01:07.464Z,1688590867.464 [NAL9602](INFO): GPS fix at 20230705T210118: (36.802809, -121.788049)
2023-07-05T21:01:07.523Z,1688590867.523 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:01:07.523Z,1688590867.523 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:01:15.474Z,1688590875.474 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0094.lzma
2023-07-05T21:01:16.477Z,1688590876.477 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0094.lzma.bak
2023-07-05T21:01:16.477Z,1688590876.477 [DataOverHttps](INFO): SBD MOMSN=18450904
2023-07-05T21:01:32.898Z,1688590892.898 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230705T180740/Express0095.lzma
2023-07-05T21:01:33.901Z,1688590893.901 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0095.lzma.bak
2023-07-05T21:01:33.901Z,1688590893.901 [DataOverHttps](INFO): SBD MOMSN=18450907
2023-07-05T21:01:34.537Z,1688590894.537 [NAL9602](INFO): SBD MO Status=2, MOMSN=27525, MT Status=2, MTMSN=0
2023-07-05T21:01:34.537Z,1688590894.537 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:01:36.595Z,1688590896.595 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:01:36.595Z,1688590896.595 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:01:36.595Z,1688590896.595 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:02:05.250Z,1688590925.250 [NAL9602](INFO): SBD MO Status=0, MOMSN=27525, MT Status=0, MTMSN=0
2023-07-05T21:02:05.251Z,1688590925.251 [NAL9602](INFO): No messages in MT queue
2023-07-05T21:02:35.945Z,1688590955.945 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T21:06:37.156Z,1688591197.156 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:06:37.156Z,1688591197.156 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:06:37.156Z,1688591197.156 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:06:37.156Z,1688591197.156 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:06:37.577Z,1688591197.577 [Default:CheckIn:D] Stopped
2023-07-05T21:06:37.577Z,1688591197.577 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:06:37.956Z,1688591197.956 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 175.019466 min 
2023-07-05T21:06:37.956Z,1688591197.956 [Default:CheckIn:E] Stopped
2023-07-05T21:06:37.956Z,1688591197.956 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:06:37.956Z,1688591197.956 [Default:CheckIn] Stopped
2023-07-05T21:06:37.956Z,1688591197.956 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:06:37.956Z,1688591197.956 [Default:CheckIn](INFO): Running loop #32
2023-07-05T21:06:37.956Z,1688591197.956 [Default:CheckIn] Running Loop=32
2023-07-05T21:06:37.957Z,1688591197.957 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:06:37.957Z,1688591197.957 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:06:39.965Z,1688591199.965 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210650.00,A,3648.16822,N,12147.27768,W,0.175,83.18,050723,,,A*45
2023-07-05T21:06:39.968Z,1688591199.968 [NAL9602](INFO): GPS fix at 20230705T210650: (36.802804, -121.787961)
2023-07-05T21:06:39.979Z,1688591199.979 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:06:39.979Z,1688591199.979 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:06:47.754Z,1688591207.754 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0097.lzma
2023-07-05T21:06:48.757Z,1688591208.757 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0097.lzma.bak
2023-07-05T21:06:48.757Z,1688591208.757 [DataOverHttps](INFO): SBD MOMSN=18450912
2023-07-05T21:07:04.958Z,1688591224.958 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230705T180740/Express0098.lzma
2023-07-05T21:07:05.961Z,1688591225.961 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0098.lzma.bak
2023-07-05T21:07:05.961Z,1688591225.961 [DataOverHttps](INFO): SBD MOMSN=18450915
2023-07-05T21:07:07.883Z,1688591227.883 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:07:07.883Z,1688591227.883 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:07:07.883Z,1688591227.883 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:09:59.953Z,1688591399.953 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:09:59.953Z,1688591399.953 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:10:07.638Z,1688591407.638 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2023-07-05T21:10:24.193Z,1688591424.193 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:10:24.194Z,1688591424.194 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:11:17.525Z,1688591477.525 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:11:17.526Z,1688591477.526 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:11:42.973Z,1688591502.973 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T21:12:08.439Z,1688591528.439 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:12:08.439Z,1688591528.439 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:12:08.440Z,1688591528.440 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:12:08.440Z,1688591528.440 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:12:08.838Z,1688591528.838 [Default:CheckIn:D] Stopped
2023-07-05T21:12:08.838Z,1688591528.838 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:12:09.280Z,1688591529.280 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 180.540495 min 
2023-07-05T21:12:09.280Z,1688591529.280 [Default:CheckIn:E] Stopped
2023-07-05T21:12:09.281Z,1688591529.281 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:12:09.281Z,1688591529.281 [Default:CheckIn] Stopped
2023-07-05T21:12:09.281Z,1688591529.281 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:12:09.282Z,1688591529.282 [Default:CheckIn](INFO): Running loop #33
2023-07-05T21:12:09.282Z,1688591529.282 [Default:CheckIn] Running Loop=33
2023-07-05T21:12:09.282Z,1688591529.282 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:12:09.282Z,1688591529.282 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:12:11.281Z,1688591531.281 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211222.00,A,3648.16712,N,12147.28012,W,1.089,133.76,050723,,,A*7D
2023-07-05T21:12:11.288Z,1688591531.288 [NAL9602](INFO): GPS fix at 20230705T211222: (36.802785, -121.788002)
2023-07-05T21:12:11.384Z,1688591531.384 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:12:11.384Z,1688591531.384 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:12:18.658Z,1688591538.658 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0100.lzma
2023-07-05T21:12:19.661Z,1688591539.661 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0100.lzma.bak
2023-07-05T21:12:19.661Z,1688591539.661 [DataOverHttps](INFO): SBD MOMSN=18450918
2023-07-05T21:12:35.870Z,1688591555.870 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230705T180740/Express0101.lzma
2023-07-05T21:12:36.873Z,1688591556.873 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0101.lzma.bak
2023-07-05T21:12:36.873Z,1688591556.873 [DataOverHttps](INFO): SBD MOMSN=18450921
2023-07-05T21:12:38.759Z,1688591558.759 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:12:38.759Z,1688591558.759 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:12:38.760Z,1688591558.760 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:12:43.988Z,1688591563.988 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T21:17:39.350Z,1688591859.350 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:17:39.351Z,1688591859.351 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:17:39.351Z,1688591859.351 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:17:39.351Z,1688591859.351 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:17:39.747Z,1688591859.747 [Default:CheckIn:D] Stopped
2023-07-05T21:17:39.748Z,1688591859.748 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:17:40.134Z,1688591860.134 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 186.055648 min 
2023-07-05T21:17:40.134Z,1688591860.134 [Default:CheckIn:E] Stopped
2023-07-05T21:17:40.135Z,1688591860.135 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:17:40.135Z,1688591860.135 [Default:CheckIn] Stopped
2023-07-05T21:17:40.135Z,1688591860.135 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:17:40.135Z,1688591860.135 [Default:CheckIn](INFO): Running loop #34
2023-07-05T21:17:40.135Z,1688591860.135 [Default:CheckIn] Running Loop=34
2023-07-05T21:17:40.135Z,1688591860.135 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:17:40.135Z,1688591860.135 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:17:42.146Z,1688591862.146 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211753.00,A,3648.16936,N,12147.27537,W,0.758,338.53,050723,,,A*7F
2023-07-05T21:17:42.148Z,1688591862.148 [NAL9602](INFO): GPS fix at 20230705T211753: (36.802823, -121.787923)
2023-07-05T21:17:42.182Z,1688591862.182 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:17:42.182Z,1688591862.182 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:17:49.602Z,1688591869.602 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0103.lzma
2023-07-05T21:17:50.605Z,1688591870.605 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0103.lzma.bak
2023-07-05T21:17:50.605Z,1688591870.605 [DataOverHttps](INFO): SBD MOMSN=18450925
2023-07-05T21:18:06.907Z,1688591886.907 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230705T180740/Express0104.lzma
2023-07-05T21:18:07.909Z,1688591887.909 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0104.lzma.bak
2023-07-05T21:18:07.909Z,1688591887.909 [DataOverHttps](INFO): SBD MOMSN=18450928
2023-07-05T21:18:09.698Z,1688591889.698 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:18:09.699Z,1688591889.699 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:18:09.699Z,1688591889.699 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:18:33.114Z,1688591913.114 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:18:33.114Z,1688591913.114 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:19:04.225Z,1688591944.225 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:19:04.225Z,1688591944.225 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:19:50.276Z,1688591990.276 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:19:50.276Z,1688591990.276 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:20:30.685Z,1688592030.685 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:20:30.685Z,1688592030.685 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:21:21.585Z,1688592081.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:21:21.586Z,1688592081.586 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:21:38.553Z,1688592098.553 [NAL9602](INFO): SBD MO Status=2, MOMSN=27526, MT Status=2, MTMSN=0
2023-07-05T21:21:38.554Z,1688592098.554 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:22:44.808Z,1688592164.808 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T21:23:10.270Z,1688592190.270 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:23:10.270Z,1688592190.270 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:23:10.271Z,1688592190.271 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:23:10.271Z,1688592190.271 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:23:10.674Z,1688592190.674 [Default:CheckIn:D] Stopped
2023-07-05T21:23:10.674Z,1688592190.674 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:23:11.076Z,1688592191.076 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 191.571094 min 
2023-07-05T21:23:11.076Z,1688592191.076 [Default:CheckIn:E] Stopped
2023-07-05T21:23:11.076Z,1688592191.076 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:23:11.076Z,1688592191.076 [Default:CheckIn] Stopped
2023-07-05T21:23:11.076Z,1688592191.076 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:23:11.077Z,1688592191.077 [Default:CheckIn](INFO): Running loop #35
2023-07-05T21:23:11.077Z,1688592191.077 [Default:CheckIn] Running Loop=35
2023-07-05T21:23:11.077Z,1688592191.077 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:23:11.077Z,1688592191.077 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:23:13.099Z,1688592193.099 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212323.00,A,3648.16405,N,12147.27755,W,0.272,340.27,050723,,,A*75
2023-07-05T21:23:13.101Z,1688592193.101 [NAL9602](INFO): GPS fix at 20230705T212323: (36.802734, -121.787959)
2023-07-05T21:23:13.112Z,1688592193.112 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:23:13.112Z,1688592193.112 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:23:21.162Z,1688592201.162 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0106.lzma
2023-07-05T21:23:22.165Z,1688592202.165 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0106.lzma.bak
2023-07-05T21:23:22.165Z,1688592202.165 [DataOverHttps](INFO): SBD MOMSN=18450931
2023-07-05T21:23:39.111Z,1688592219.111 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230705T180740/Express0107.lzma
2023-07-05T21:23:40.113Z,1688592220.113 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0107.lzma.bak
2023-07-05T21:23:40.113Z,1688592220.113 [DataOverHttps](INFO): SBD MOMSN=18450934
2023-07-05T21:23:42.206Z,1688592222.206 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:23:42.206Z,1688592222.206 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:23:42.211Z,1688592222.211 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:23:45.815Z,1688592225.815 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T21:28:42.776Z,1688592522.776 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:28:42.776Z,1688592522.776 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:28:42.776Z,1688592522.776 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:28:42.776Z,1688592522.776 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:28:43.174Z,1688592523.174 [Default:CheckIn:D] Stopped
2023-07-05T21:28:43.174Z,1688592523.174 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:28:43.615Z,1688592523.615 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 197.112760 min 
2023-07-05T21:28:43.615Z,1688592523.615 [Default:CheckIn:E] Stopped
2023-07-05T21:28:43.615Z,1688592523.615 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:28:43.615Z,1688592523.615 [Default:CheckIn] Stopped
2023-07-05T21:28:43.615Z,1688592523.615 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:28:43.615Z,1688592523.615 [Default:CheckIn](INFO): Running loop #36
2023-07-05T21:28:43.615Z,1688592523.615 [Default:CheckIn] Running Loop=36
2023-07-05T21:28:43.616Z,1688592523.616 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:28:43.616Z,1688592523.616 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:28:45.604Z,1688592525.604 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212856.00,A,3648.16452,N,12147.27875,W,1.069,340.27,050723,,,A*7A
2023-07-05T21:28:45.608Z,1688592525.608 [NAL9602](INFO): GPS fix at 20230705T212856: (36.802742, -121.787979)
2023-07-05T21:28:45.673Z,1688592525.673 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:28:45.673Z,1688592525.673 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:28:51.970Z,1688592531.970 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230705T180740/Courier0109.lzma
2023-07-05T21:28:52.973Z,1688592532.973 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0109.lzma.bak
2023-07-05T21:28:52.973Z,1688592532.973 [DataOverHttps](INFO): SBD MOMSN=18450938
2023-07-05T21:29:09.311Z,1688592549.311 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230705T180740/Express0110.lzma
2023-07-05T21:29:10.309Z,1688592550.309 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0110.lzma.bak
2023-07-05T21:29:10.309Z,1688592550.309 [DataOverHttps](INFO): SBD MOMSN=18450942
2023-07-05T21:29:12.263Z,1688592552.263 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:29:12.263Z,1688592552.263 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:29:12.264Z,1688592552.264 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:29:16.288Z,1688592556.288 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T21:29:16.367Z,1688592556.367 [NAL9602](ERROR): received: 
+CSQ:1

OK526, 2, 0, 0, 0

OK
2023-07-05T21:29:57.103Z,1688592597.103 [NAL9602](INFO): SBD MO Status=0, MOMSN=27526, MT Status=0, MTMSN=0
2023-07-05T21:29:57.103Z,1688592597.103 [NAL9602](INFO): No messages in MT queue
2023-07-05T21:30:27.812Z,1688592627.812 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T21:34:12.898Z,1688592852.898 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:34:12.898Z,1688592852.898 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:34:12.898Z,1688592852.898 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:34:12.898Z,1688592852.898 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:34:13.334Z,1688592853.334 [Default:CheckIn:D] Stopped
2023-07-05T21:34:13.334Z,1688592853.334 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:34:13.700Z,1688592853.700 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 202.615413 min 
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn:E] Stopped
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn] Stopped
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn](INFO): Running loop #37
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn] Running Loop=37
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:34:13.701Z,1688592853.701 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:34:15.730Z,1688592855.730 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213426.00,A,3648.16346,N,12147.27941,W,0.039,195.06,050723,,,A*79
2023-07-05T21:34:15.732Z,1688592855.732 [NAL9602](INFO): GPS fix at 20230705T213426: (36.802724, -121.787990)
2023-07-05T21:34:15.743Z,1688592855.743 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:34:15.743Z,1688592855.743 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:34:23.706Z,1688592863.706 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0112.lzma
2023-07-05T21:34:24.709Z,1688592864.709 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0112.lzma.bak
2023-07-05T21:34:24.709Z,1688592864.709 [DataOverHttps](INFO): SBD MOMSN=18450946
2023-07-05T21:34:41.205Z,1688592881.205 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230705T180740/Express0113.lzma
2023-07-05T21:34:42.205Z,1688592882.205 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0113.lzma.bak
2023-07-05T21:34:42.205Z,1688592882.205 [DataOverHttps](INFO): SBD MOMSN=18450949
2023-07-05T21:34:43.996Z,1688592883.996 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:34:43.996Z,1688592883.996 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:34:43.997Z,1688592883.997 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:37:41.624Z,1688593061.624 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:37:41.624Z,1688593061.624 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:38:14.753Z,1688593094.753 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:38:14.753Z,1688593094.753 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:38:19.203Z,1688593099.203 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-07-05T21:38:19.205Z,1688593099.205 [BPC1](INFO): Received data from all battery sticks.
2023-07-05T21:38:53.533Z,1688593133.533 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:38:53.533Z,1688593133.533 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:39:17.780Z,1688593157.780 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T21:39:44.457Z,1688593184.457 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:39:44.457Z,1688593184.457 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:39:44.457Z,1688593184.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:39:44.458Z,1688593184.458 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:39:44.855Z,1688593184.855 [Default:CheckIn:D] Stopped
2023-07-05T21:39:44.855Z,1688593184.855 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:39:45.350Z,1688593185.350 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 208.140755 min 
2023-07-05T21:39:45.350Z,1688593185.350 [Default:CheckIn:E] Stopped
2023-07-05T21:39:45.351Z,1688593185.351 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:39:45.351Z,1688593185.351 [Default:CheckIn] Stopped
2023-07-05T21:39:45.351Z,1688593185.351 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:39:45.351Z,1688593185.351 [Default:CheckIn](INFO): Running loop #38
2023-07-05T21:39:45.351Z,1688593185.351 [Default:CheckIn] Running Loop=38
2023-07-05T21:39:45.351Z,1688593185.351 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:39:45.351Z,1688593185.351 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:39:47.289Z,1688593187.289 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213958.00,A,3648.16904,N,12147.27793,W,1.011,195.06,050723,,,A*7B
2023-07-05T21:39:47.296Z,1688593187.296 [NAL9602](INFO): GPS fix at 20230705T213958: (36.802817, -121.787965)
2023-07-05T21:39:47.349Z,1688593187.349 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:39:47.349Z,1688593187.349 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:39:55.264Z,1688593195.264 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230705T180740/Courier0115.lzma
2023-07-05T21:39:56.261Z,1688593196.261 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0115.lzma.bak
2023-07-05T21:39:56.261Z,1688593196.261 [DataOverHttps](INFO): SBD MOMSN=18450952
2023-07-05T21:40:12.486Z,1688593212.486 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20230705T180740/Express0116.lzma
2023-07-05T21:40:13.489Z,1688593213.489 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0116.lzma.bak
2023-07-05T21:40:13.489Z,1688593213.489 [DataOverHttps](INFO): SBD MOMSN=18450955
2023-07-05T21:40:15.167Z,1688593215.167 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:40:15.167Z,1688593215.167 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:40:15.167Z,1688593215.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:40:19.988Z,1688593219.988 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-05T21:45:15.747Z,1688593515.747 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-05T21:45:15.747Z,1688593515.747 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:45:15.747Z,1688593515.747 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:45:15.748Z,1688593515.748 [Default:CheckIn:D] Running Loop=1
2023-07-05T21:45:16.134Z,1688593516.134 [Default:CheckIn:D] Stopped
2023-07-05T21:45:16.134Z,1688593516.134 [Default:CheckIn:E] Running Loop=1
2023-07-05T21:45:16.536Z,1688593516.536 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 213.662093 min 
2023-07-05T21:45:16.536Z,1688593516.536 [Default:CheckIn:E] Stopped
2023-07-05T21:45:16.536Z,1688593516.536 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-05T21:45:16.536Z,1688593516.536 [Default:CheckIn] Stopped
2023-07-05T21:45:16.537Z,1688593516.537 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:45:16.537Z,1688593516.537 [Default:CheckIn](INFO): Running loop #39
2023-07-05T21:45:16.537Z,1688593516.537 [Default:CheckIn] Running Loop=39
2023-07-05T21:45:16.537Z,1688593516.537 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-05T21:45:16.537Z,1688593516.537 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-05T21:45:18.548Z,1688593518.548 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214529.00,A,3648.16712,N,12147.27683,W,0.000,336.36,050723,,,A*76
2023-07-05T21:45:18.550Z,1688593518.550 [NAL9602](INFO): GPS fix at 20230705T214529: (36.802785, -121.787947)
2023-07-05T21:45:18.583Z,1688593518.583 [Default:CheckIn:Read_GPS] Stopped
2023-07-05T21:45:18.583Z,1688593518.583 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-05T21:45:25.894Z,1688593525.894 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230705T180740/Courier0118.lzma
2023-07-05T21:45:26.897Z,1688593526.897 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Courier0118.lzma.bak
2023-07-05T21:45:26.898Z,1688593526.898 [DataOverHttps](INFO): SBD MOMSN=18450959
2023-07-05T21:45:43.690Z,1688593543.690 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230705T180740/Express0119.lzma
2023-07-05T21:45:44.693Z,1688593544.693 [DataOverHttps](INFO): Moved sent file to Logs/20230705T180740/Express0119.lzma.bak
2023-07-05T21:45:44.693Z,1688593544.693 [DataOverHttps](INFO): SBD MOMSN=18450962
2023-07-05T21:45:46.451Z,1688593546.451 [Default:CheckIn:Read_Iridium] Stopped
2023-07-05T21:45:46.451Z,1688593546.451 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-05T21:45:46.451Z,1688593546.451 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-05T21:45:49.284Z,1688593549.284 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-05T21:45:49.367Z,1688593549.367 [NAL9602](ERROR): received: 
+CSQ:0

OK527, 2, 0, 0, 0

OK
2023-07-05T21:46:39.753Z,1688593599.753 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:46:39.753Z,1688593599.753 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:47:31.465Z,1688593651.465 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:47:31.466Z,1688593651.466 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:48:29.261Z,1688593709.261 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T21:48:29.359Z,1688593709.359 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T21:48:40.177Z,1688593720.177 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.001353
CHAN A1 (24V): 0.049305
CHAN A2 (12V): -0.000940
CHAN A3 (5V): -0.000680
CHAN B0 (3.3V): 0.001576
CHAN B1 (3.15aV): 0.001499
CHAN B2 (3.15bV): 0.001510
CHAN B3 (GND): 0.002191
OPEN: 0.005995
Full Scale: +/- 1 mA
2023-07-05T21:48:49.033Z,1688593729.033 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:48:49.033Z,1688593729.033 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:49:02.368Z,1688593742.368 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:49:02.368Z,1688593742.368 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:49:13.434Z,1688593753.434 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T21:49:13.712Z,1688593753.712 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T21:49:24.654Z,1688593764.654 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.001366
CHAN A1 (24V): 0.049204
CHAN A2 (12V): -0.001321
CHAN A3 (5V): 0.000762
CHAN B0 (3.3V): 0.001674
CHAN B1 (3.15aV): 0.001360
CHAN B2 (3.15bV): 0.001793
CHAN B3 (GND): 0.002116
OPEN: 0.006036
Full Scale: +/- 1 mA
2023-07-05T21:49:56.906Z,1688593796.906 [NAL9602](INFO): SBD MO Status=2, MOMSN=27527, MT Status=2, MTMSN=0
2023-07-05T21:49:56.906Z,1688593796.906 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-05T21:50:18.576Z,1688593818.576 [CommandExec](IMPORTANT): got command configSet PowerOnly.sampleTime1 0 second
2023-07-05T21:50:18.721Z,1688593818.721 [PowerOnly](INFO): Powering up loadControl
2023-07-05T21:50:20.744Z,1688593820.744 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-05T21:50:23.688Z,1688593823.688 [CommandExec](IMPORTANT): got command gfscan
2023-07-05T21:50:23.996Z,1688593823.996 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-05T21:50:34.962Z,1688593834.962 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.000680
CHAN A1 (24V): 0.049561
CHAN A2 (12V): -0.001350
CHAN A3 (5V): 0.000195
CHAN B0 (3.3V): 0.002409
CHAN B1 (3.15aV): 0.002267
CHAN B2 (3.15bV): 0.001770
CHAN B3 (GND): 0.001939
OPEN: 0.006303
Full Scale: +/- 1 mA
2023-07-05T21:50:39.960Z,1688593839.960 [CommandExec](IMPORTANT): got command restart system
2023-07-05T21:50:42.067Z,1688593842.067 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:42.067Z,1688593842.067 [CommandExec](INFO): Uninitializing the command executive.
2023-07-05T21:50:42.067Z,1688593842.067 [CommandExec](INFO): Uninitializing the command scheduler.
2023-07-05T21:50:42.068Z,1688593842.068 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:42.120Z,1688593842.120 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-07-05T21:50:42.120Z,1688593842.120 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-07-05T21:50:42.121Z,1688593842.121 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:42.121Z,1688593842.121 [NavChartDb](INFO): Join timeout helper Thread ID is 991
2023-07-05T21:50:42.503Z,1688593842.503 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:42.503Z,1688593842.503 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:42.519Z,1688593842.519 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2023-07-05T21:50:42.519Z,1688593842.519 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:42.519Z,1688593842.519 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 992
2023-07-05T21:50:42.859Z,1688593842.859 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:42.859Z,1688593842.859 [WetLabsUBAT](INFO): Powering down
2023-07-05T21:50:42.860Z,1688593842.860 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:42.871Z,1688593842.871 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-07-05T21:50:42.871Z,1688593842.871 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:42.871Z,1688593842.871 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 993
2023-07-05T21:50:43.075Z,1688593843.075 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.075Z,1688593843.075 [WetLabsBB2FL](INFO): Powering down
2023-07-05T21:50:43.076Z,1688593843.076 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.101Z,1688593843.101 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-07-05T21:50:43.101Z,1688593843.101 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.101Z,1688593843.101 [CTD_Seabird](INFO): Join timeout helper Thread ID is 994
2023-07-05T21:50:43.143Z,1688593843.143 [CTD_Seabird](INFO): Powering down
2023-07-05T21:50:43.155Z,1688593843.155 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.155Z,1688593843.155 [CTD_Seabird](INFO): Powering down
2023-07-05T21:50:43.167Z,1688593843.167 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.171Z,1688593843.171 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-07-05T21:50:43.171Z,1688593843.171 [DAT ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.171Z,1688593843.171 [DAT](INFO): Join timeout helper Thread ID is 995
2023-07-05T21:50:43.224Z,1688593843.224 [DAT](INFO): Powering down
2023-07-05T21:50:43.295Z,1688593843.295 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.296Z,1688593843.296 [DAT](INFO): Powering down
2023-07-05T21:50:43.297Z,1688593843.297 [DAT ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.304Z,1688593843.304 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-07-05T21:50:43.304Z,1688593843.304 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.304Z,1688593843.304 [Radio_Surface](INFO): Join timeout helper Thread ID is 996
2023-07-05T21:50:43.355Z,1688593843.355 [Radio_Surface](INFO): Powering down
2023-07-05T21:50:43.356Z,1688593843.356 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.356Z,1688593843.356 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.377Z,1688593843.377 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-07-05T21:50:43.377Z,1688593843.377 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.377Z,1688593843.377 [Onboard](INFO): Join timeout helper Thread ID is 997
2023-07-05T21:50:43.399Z,1688593843.399 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.399Z,1688593843.399 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.404Z,1688593843.404 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-07-05T21:50:43.404Z,1688593843.404 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.404Z,1688593843.404 [DataOverHttps](INFO): Join timeout helper Thread ID is 998
2023-07-05T21:50:43.715Z,1688593843.715 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.715Z,1688593843.715 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.727Z,1688593843.727 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-07-05T21:50:43.727Z,1688593843.727 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.728Z,1688593843.728 [BackseatComponent](INFO): Join timeout helper Thread ID is 999
2023-07-05T21:50:43.903Z,1688593843.903 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.903Z,1688593843.903 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.907Z,1688593843.907 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-07-05T21:50:43.908Z,1688593843.908 [logger ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.908Z,1688593843.908 [logger](INFO): Join timeout helper Thread ID is 1000
2023-07-05T21:50:43.931Z,1688593843.931 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.931Z,1688593843.931 [logger ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.947Z,1688593843.947 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-07-05T21:50:43.948Z,1688593843.948 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.948Z,1688593843.948 [CommandLine](INFO): Join timeout helper Thread ID is 1001
2023-07-05T21:50:43.975Z,1688593843.975 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:43.975Z,1688593843.975 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.987Z,1688593843.987 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-07-05T21:50:43.987Z,1688593843.987 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.988Z,1688593843.988 [CommandExec](INFO): Join timeout helper Thread ID is 1002
2023-07-05T21:50:43.989Z,1688593843.989 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-07-05T21:50:43.989Z,1688593843.989 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:43.990Z,1688593843.990 [controlThread](INFO): Join timeout helper Thread ID is 1003
2023-07-05T21:50:44.155Z,1688593844.155 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-05T21:50:44.155Z,1688593844.155 [controlThread](DEBUG): Uninitializing ControlThread
2023-07-05T21:50:44.156Z,1688593844.156 [AHRS_M2](INFO): Powering down
2023-07-05T21:50:44.228Z,1688593844.228 [NAL9602](INFO): Powering down
2023-07-05T21:50:44.299Z,1688593844.299 [RDI_Pathfinder](INFO): Powering down
2023-07-05T21:50:44.300Z,1688593844.300 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-07-05T21:50:44.301Z,1688593844.301 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-07-05T21:50:44.302Z,1688593844.302 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-07-05T21:50:44.302Z,1688593844.302 [MissionManager](INFO): Uninitializing Mission Default
2023-07-05T21:50:44.302Z,1688593844.302 [Default] Stopped
2023-07-05T21:50:44.302Z,1688593844.302 [Default](DEBUG): Aggregate::uninitialize Default
2023-07-05T21:50:44.303Z,1688593844.303 [Default:B.GoToSurface] Stopped
2023-07-05T21:50:44.303Z,1688593844.303 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-07-05T21:50:44.303Z,1688593844.303 [Default:CheckIn] Stopped
2023-07-05T21:50:44.303Z,1688593844.303 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-05T21:50:44.303Z,1688593844.303 [Default:CheckIn:C.Wait] Stopped
2023-07-05T21:50:44.303Z,1688593844.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-05T21:50:44.306Z,1688593844.306 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-07-05T21:50:44.306Z,1688593844.306 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-07-05T21:50:44.307Z,1688593844.307 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-07-05T21:50:44.307Z,1688593844.307 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-07-05T21:50:44.307Z,1688593844.307 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-07-05T21:50:44.308Z,1688593844.308 [BuoyancyServo](INFO): Powering down
2023-07-05T21:50:44.323Z,1688593844.323 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-07-05T21:50:44.323Z,1688593844.323 [ElevatorServo](INFO): Powering down
2023-07-05T21:50:44.324Z,1688593844.324 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-07-05T21:50:44.324Z,1688593844.324 [MassServo](INFO): Powering down
2023-07-05T21:50:44.325Z,1688593844.325 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-07-05T21:50:44.325Z,1688593844.325 [RudderServo](INFO): Powering down
2023-07-05T21:50:44.326Z,1688593844.326 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2023-07-05T21:50:44.326Z,1688593844.326 [ThrusterServo](INFO): Powering down
2023-07-05T21:50:44.327Z,1688593844.327 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-07-05T21:50:44.328Z,1688593844.328 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-07-05T21:50:44.328Z,1688593844.328 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-07-05T21:50:44.328Z,1688593844.328 [CBIT](DEBUG): Powering off loads.
2023-07-05T21:50:44.339Z,1688593844.339 [CBIT](DEBUG): Disabling WDT.
2023-07-05T21:50:44.351Z,1688593844.351 [CBIT](DEBUG): Opening all GF detection circuits.
2023-07-05T21:50:44.352Z,1688593844.352 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.414Z,1688593844.414 [DAT ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.422Z,1688593844.422 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.424Z,1688593844.424 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.431Z,1688593844.431 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.478Z,1688593844.478 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.539Z,1688593844.539 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.541Z,1688593844.541 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.545Z,1688593844.545 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.553Z,1688593844.553 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-07-05T21:50:44.629Z,1688593844.629 [logger ThreadHandler](INFO): Thread cancelled.