2023-05-16T21:57:51.271Z,1684274271.271 [Supervisor](DEBUG): Initializing supervisor.
2023-05-16T21:57:51.275Z,1684274271.275 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-16T21:57:51.276Z,1684274271.276 [SyncHandler](INFO): Protected caller Thread ID is 837
2023-05-16T21:57:51.277Z,1684274271.277 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-16T21:57:51.277Z,1684274271.277 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-16T21:57:51.278Z,1684274271.278 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 838
2023-05-16T21:57:51.282Z,1684274271.282 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-16T21:57:51.299Z,1684274271.299 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-16T21:57:51.300Z,1684274271.300 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-16T21:57:51.300Z,1684274271.300 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 839
2023-05-16T21:57:51.304Z,1684274271.304 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-16T21:57:51.305Z,1684274271.305 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-16T21:57:51.306Z,1684274271.306 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 840
2023-05-16T21:57:51.308Z,1684274271.308 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-16T21:57:51.309Z,1684274271.309 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-16T21:57:51.309Z,1684274271.309 [logger ThreadHandler](INFO): Protected caller Thread ID is 841
2023-05-16T21:57:51.313Z,1684274271.313 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-16T21:57:51.313Z,1684274271.313 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-16T21:57:51.317Z,1684274271.317 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-16T21:57:51.529Z,1684274271.529 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-16T21:57:51.531Z,1684274271.531 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-16T21:57:51.636Z,1684274271.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-16T21:57:51.638Z,1684274271.638 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-16T21:57:51.732Z,1684274271.732 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-16T21:57:51.734Z,1684274271.734 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-16T21:57:52.200Z,1684274272.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-16T21:57:52.202Z,1684274272.202 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-16T21:57:52.545Z,1684274272.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-16T21:57:52.546Z,1684274272.546 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-16T21:57:52.878Z,1684274272.878 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-16T21:57:52.879Z,1684274272.879 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-16T21:57:53.063Z,1684274273.063 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-16T21:57:53.065Z,1684274273.065 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-16T21:57:53.143Z,1684274273.143 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-16T21:57:53.224Z,1684274273.224 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-16T21:57:53.611Z,1684274273.611 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-16T21:57:53.613Z,1684274273.613 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-16T21:57:53.885Z,1684274273.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-16T21:57:53.885Z,1684274273.885 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-16T21:57:54.382Z,1684274274.382 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-16T21:57:54.471Z,1684274274.471 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-16T21:57:54.928Z,1684274274.928 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-16T21:57:54.928Z,1684274274.928 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-16T21:57:55.301Z,1684274275.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-16T21:57:55.302Z,1684274275.302 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-16T21:57:55.440Z,1684274275.440 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-16T21:57:55.441Z,1684274275.441 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-16T21:57:56.219Z,1684274276.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-16T21:57:56.221Z,1684274276.221 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2023-05-16T21:57:56.224Z,1684274276.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2023-05-16T21:57:56.308Z,1684274276.308 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2023-05-16T21:57:56.486Z,1684274276.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2023-05-16T21:57:56.746Z,1684274276.746 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-16T21:57:56.746Z,1684274276.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2023-05-16T21:57:56.867Z,1684274276.867 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2023-05-16T21:57:56.965Z,1684274276.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2023-05-16T21:57:57.059Z,1684274277.059 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2023-05-16T21:57:57.165Z,1684274277.165 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2023-05-16T21:57:57.258Z,1684274277.258 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2023-05-16T21:57:57.343Z,1684274277.343 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2023-05-16T21:57:57.441Z,1684274277.441 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2023-05-16T21:57:57.599Z,1684274277.599 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-16T21:57:57.618Z,1684274277.618 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-16T21:57:57.691Z,1684274277.691 [DepthRateCalculator] Loaded
2023-05-16T21:57:57.691Z,1684274277.691 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-16T21:57:57.697Z,1684274277.697 [PitchRateCalculator] Loaded
2023-05-16T21:57:57.697Z,1684274277.697 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-16T21:57:57.707Z,1684274277.707 [SpeedCalculator] Loaded
2023-05-16T21:57:57.707Z,1684274277.707 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-16T21:57:57.722Z,1684274277.722 [VerticalHomogeneityIndexCalculator] Loaded
2023-05-16T21:57:57.723Z,1684274277.723 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2023-05-16T21:57:57.727Z,1684274277.727 [YawRateCalculator] Loaded
2023-05-16T21:57:57.728Z,1684274277.728 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-16T21:57:57.749Z,1684274277.749 [ElevatorOffsetCalculator] Loaded
2023-05-16T21:57:57.750Z,1684274277.750 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-16T21:57:57.750Z,1684274277.750 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-16T21:57:57.752Z,1684274277.752 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-16T21:57:57.795Z,1684274277.795 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-16T21:57:57.796Z,1684274277.796 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-16T21:57:57.810Z,1684274277.810 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-16T21:57:57.811Z,1684274277.811 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-16T21:57:58.562Z,1684274278.562 [AHRS_M2] Loaded
2023-05-16T21:57:58.562Z,1684274278.562 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-16T21:57:58.810Z,1684274278.810 [BackseatComponent] Loaded
2023-05-16T21:57:58.810Z,1684274278.810 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-16T21:57:58.811Z,1684274278.811 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408474E0
2023-05-16T21:57:58.812Z,1684274278.812 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923
2023-05-16T21:57:58.814Z,1684274278.814 [LcmUniversalReporter] Loaded
2023-05-16T21:57:58.815Z,1684274278.815 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-16T21:57:59.601Z,1684274279.601 [BPC1] Loaded
2023-05-16T21:57:59.602Z,1684274279.602 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-16T21:57:59.741Z,1684274279.741 [DataOverHttps] Loaded
2023-05-16T21:57:59.742Z,1684274279.742 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-16T21:57:59.743Z,1684274279.743 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408774E0
2023-05-16T21:57:59.743Z,1684274279.743 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 924
2023-05-16T21:57:59.764Z,1684274279.764 [Depth_Keller] Loaded
2023-05-16T21:57:59.764Z,1684274279.764 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-16T21:57:59.769Z,1684274279.769 [DropWeight] Loaded
2023-05-16T21:57:59.769Z,1684274279.769 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-05-16T21:57:59.830Z,1684274279.830 [NAL9602] Loaded
2023-05-16T21:57:59.830Z,1684274279.830 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-16T21:57:59.859Z,1684274279.859 [Onboard] Loaded
2023-05-16T21:57:59.859Z,1684274279.859 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-16T21:57:59.860Z,1684274279.860 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408A74E0
2023-05-16T21:57:59.861Z,1684274279.861 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 925
2023-05-16T21:57:59.867Z,1684274279.867 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3
2023-05-16T21:57:59.878Z,1684274279.878 [PowerOnly] Loaded
2023-05-16T21:57:59.878Z,1684274279.878 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-05-16T21:57:59.889Z,1684274279.889 [Power24vConverter] Loaded
2023-05-16T21:57:59.890Z,1684274279.890 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-16T21:57:59.903Z,1684274279.903 [Radio_Surface] Loaded
2023-05-16T21:57:59.903Z,1684274279.903 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-16T21:57:59.904Z,1684274279.904 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408D74E0
2023-05-16T21:57:59.905Z,1684274279.905 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 926
2023-05-16T21:57:59.927Z,1684274279.927 [Waterlinked] Loaded
2023-05-16T21:57:59.928Z,1684274279.928 [ComponentRegistry](DEBUG): SyncComponent "Waterlinked" handled in the control thread.
2023-05-16T21:57:59.928Z,1684274279.928 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-16T21:57:59.929Z,1684274279.929 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-16T21:58:00.135Z,1684274280.135 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-16T21:58:00.135Z,1684274280.135 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-16T21:58:00.357Z,1684274280.357 [DeadReckonUsingSpeedCalculator] Loaded
2023-05-16T21:58:00.357Z,1684274280.357 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2023-05-16T21:58:00.379Z,1684274280.379 [NavChart] Loaded
2023-05-16T21:58:00.379Z,1684274280.379 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-16T21:58:00.415Z,1684274280.415 [UniversalFixResidualReporter] Loaded
2023-05-16T21:58:00.415Z,1684274280.415 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-16T21:58:00.416Z,1684274280.416 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-16T21:58:00.501Z,1684274280.501 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-16T21:58:00.771Z,1684274280.771 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-16T21:58:00.785Z,1684274280.785 [SBIT] Loaded
2023-05-16T21:58:00.786Z,1684274280.786 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-16T21:58:00.789Z,1684274280.789 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-16T21:58:00.801Z,1684274280.801 [IBIT] Loaded
2023-05-16T21:58:00.801Z,1684274280.801 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-16T21:58:00.807Z,1684274280.807 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-16T21:58:00.909Z,1684274280.909 [CBIT] Loaded
2023-05-16T21:58:00.909Z,1684274280.909 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-16T21:58:00.910Z,1684274280.910 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-16T21:58:00.910Z,1684274280.910 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-16T21:58:01.124Z,1684274281.124 [CTD_Seabird] Loaded
2023-05-16T21:58:01.125Z,1684274281.125 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-16T21:58:01.126Z,1684274281.126 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2023-05-16T21:58:01.126Z,1684274281.126 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 927
2023-05-16T21:58:01.146Z,1684274281.146 [PAR_Licor] Loaded
2023-05-16T21:58:01.146Z,1684274281.146 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-16T21:58:01.177Z,1684274281.177 [WetLabsBB2FL] Loaded
2023-05-16T21:58:01.177Z,1684274281.177 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-16T21:58:01.178Z,1684274281.178 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0B4E0
2023-05-16T21:58:01.179Z,1684274281.179 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 928
2023-05-16T21:58:01.179Z,1684274281.179 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-16T21:58:01.180Z,1684274281.180 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-16T21:58:01.341Z,1684274281.341 [BuoyancyServo] Loaded
2023-05-16T21:58:01.341Z,1684274281.341 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-16T21:58:01.363Z,1684274281.363 [ElevatorServo] Loaded
2023-05-16T21:58:01.364Z,1684274281.364 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-16T21:58:01.385Z,1684274281.385 [MassServo] Loaded
2023-05-16T21:58:01.385Z,1684274281.385 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-16T21:58:01.405Z,1684274281.405 [RudderServo] Loaded
2023-05-16T21:58:01.406Z,1684274281.406 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-16T21:58:01.421Z,1684274281.421 [ThrusterHE] Loaded
2023-05-16T21:58:01.422Z,1684274281.422 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-16T21:58:01.422Z,1684274281.422 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-16T21:58:01.423Z,1684274281.423 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-16T21:58:01.489Z,1684274281.489 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-16T21:58:01.539Z,1684274281.539 [VerticalControl] Loaded
2023-05-16T21:58:01.539Z,1684274281.539 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-16T21:58:01.542Z,1684274281.542 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-16T21:58:01.579Z,1684274281.579 [HorizontalControl] Loaded
2023-05-16T21:58:01.580Z,1684274281.580 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-16T21:58:01.582Z,1684274281.582 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-16T21:58:01.584Z,1684274281.584 [SpeedControl] Loaded
2023-05-16T21:58:01.584Z,1684274281.584 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-16T21:58:01.587Z,1684274281.587 [LoopControl](DEBUG): Construct LoopControl.
2023-05-16T21:58:01.587Z,1684274281.587 [LoopControl] Loaded
2023-05-16T21:58:01.588Z,1684274281.588 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-16T21:58:01.588Z,1684274281.588 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-16T21:58:01.589Z,1684274281.589 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-16T21:58:01.713Z,1684274281.713 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-16T21:58:01.713Z,1684274281.713 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-16T21:58:01.893Z,1684274281.893 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-16T21:58:01.894Z,1684274281.894 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-16T21:58:02.249Z,1684274282.249 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-16T21:58:02.250Z,1684274282.250 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-16T21:58:02.347Z,1684274282.347 [StratificationFrontDetector](INFO): thresholdVTHI set to: 0.399988 degC
2023-05-16T21:58:02.347Z,1684274282.347 [StratificationFrontDetector](DEBUG): (re)initializing
2023-05-16T21:58:02.347Z,1684274282.347 [StratificationFrontDetector] Loaded
2023-05-16T21:58:02.347Z,1684274282.347 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2023-05-16T21:58:02.348Z,1684274282.348 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-16T21:58:02.354Z,1684274282.354 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-16T21:58:02.357Z,1684274282.357 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-16T21:58:02.368Z,1684274282.368 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-16T21:58:02.369Z,1684274282.369 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BB74E0
2023-05-16T21:58:02.369Z,1684274282.369 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929
2023-05-16T21:58:02.374Z,1684274282.374 [Supervisor](INFO): Main Thread ID is 830
2023-05-16T21:58:02.374Z,1684274282.374 [Supervisor](DEBUG): Running supervisor.
2023-05-16T21:58:02.374Z,1684274282.374 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930
2023-05-16T21:58:02.375Z,1684274282.375 [CommandExec](INFO): Initializing the command executive.
2023-05-16T21:58:02.376Z,1684274282.376 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931
2023-05-16T21:58:02.378Z,1684274282.378 [controlThread ThreadHandler](INFO): Handler Thread ID is 932
2023-05-16T21:58:02.379Z,1684274282.379 [controlThread](DEBUG): Initializing ControlThread
2023-05-16T21:58:02.380Z,1684274282.380 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-16T21:58:02.380Z,1684274282.380 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-16T21:58:02.381Z,1684274282.381 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-16T21:58:02.381Z,1684274282.381 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2023-05-16T21:58:02.382Z,1684274282.382 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-16T21:58:02.382Z,1684274282.382 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-16T21:58:02.387Z,1684274282.387 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T21:58:02.387Z,1684274282.387 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-16T21:58:02.388Z,1684274282.388 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-16T21:58:02.388Z,1684274282.388 [SBIT](INFO): Initialize SBIT Component.
2023-05-16T21:58:02.389Z,1684274282.389 [SBIT](IMPORTANT): git: 2023-05-11-1-g0756d5a45
2023-05-16T21:58:02.389Z,1684274282.389 [SBIT](INFO): git hash: 0756d5a45b55fc759b5de63a78c860713c4b2bf5
2023-05-16T21:58:02.389Z,1684274282.389 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-16T21:58:02.390Z,1684274282.390 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-05-16T21:58:02.391Z,1684274282.391 [SBIT](INFO): Beginning SBIT in 83.000000 seconds.
2023-05-16T21:58:02.392Z,1684274282.392 [IBIT](INFO): Initialize IBIT Component.
2023-05-16T21:58:02.393Z,1684274282.393 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-16T21:58:02.394Z,1684274282.394 [logger ThreadHandler](INFO): Handler Thread ID is 933
2023-05-16T21:58:02.404Z,1684274282.404 [CBIT](DEBUG): Initialized mux pins.
2023-05-16T21:58:02.404Z,1684274282.404 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-16T21:58:02.412Z,1684274282.412 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 934
2023-05-16T21:58:02.424Z,1684274282.424 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 935
2023-05-16T21:58:02.425Z,1684274282.425 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-16T21:58:02.428Z,1684274282.428 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-16T21:58:02.428Z,1684274282.428 [CBIT](DEBUG): Initializing heartbeat.
2023-05-16T21:58:02.436Z,1684274282.436 [Onboard ThreadHandler](INFO): Handler Thread ID is 936
2023-05-16T21:58:02.472Z,1684274282.472 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 937
2023-05-16T21:58:02.473Z,1684274282.473 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 938
2023-05-16T21:58:02.474Z,1684274282.474 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-16T21:58:02.478Z,1684274282.478 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 940
2023-05-16T21:58:02.480Z,1684274282.480 [WetLabsBB2FL](INFO): Powering up
2023-05-16T21:58:02.481Z,1684274282.481 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 942
2023-05-16T21:58:02.489Z,1684274282.489 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-16T21:58:02.489Z,1684274282.489 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-16T21:58:02.489Z,1684274282.489 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-16T21:58:02.489Z,1684274282.489 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-16T21:58:02.489Z,1684274282.489 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-16T21:58:02.489Z,1684274282.489 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-16T21:58:02.490Z,1684274282.490 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-16T21:58:02.490Z,1684274282.490 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-16T21:58:02.500Z,1684274282.500 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-16T21:58:02.500Z,1684274282.500 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-16T21:58:02.540Z,1684274282.540 [CBIT](DEBUG): Backplane powered.
2023-05-16T21:58:02.545Z,1684274282.545 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-16T21:58:02.547Z,1684274282.547 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-16T21:58:02.548Z,1684274282.548 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-16T21:58:02.548Z,1684274282.548 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-16T21:58:02.550Z,1684274282.550 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-16T21:58:02.581Z,1684274282.581 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-16T21:58:02.608Z,1684274282.608 [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-05-16T21:58:02.609Z,1684274282.609 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-16T21:58:02.664Z,1684274282.664 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-16T21:58:02.665Z,1684274282.665 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-16T21:58:02.667Z,1684274282.667 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-16T21:58:02.694Z,1684274282.694 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-16T21:58:02.697Z,1684274282.697 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-16T21:58:02.721Z,1684274282.721 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-16T21:58:02.725Z,1684274282.725 [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-05-16T21:58:02.744Z,1684274282.744 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Waterlinked,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-16T21:58:02.751Z,1684274282.751 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-16T21:58:02.865Z,1684274282.865 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1629.131348 decibar, 0.000000 m
2023-05-16T21:58:02.866Z,1684274282.866 [Power24vConverter](INFO): Powering up.
2023-05-16T21:58:02.876Z,1684274282.876 [Radio_Surface](INFO): Powering up
2023-05-16T21:58:02.890Z,1684274282.890 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-05-16T21:58:02.911Z,1684274282.911 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-16T21:58:02.916Z,1684274282.916 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-16T21:58:02.917Z,1684274282.917 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-16T21:58:02.924Z,1684274282.924 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-16T21:58:02.925Z,1684274282.925 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-16T21:58:02.932Z,1684274282.932 [MassServo](DEBUG): Initializing MassServo.
2023-05-16T21:58:02.933Z,1684274282.933 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-16T21:58:02.940Z,1684274282.940 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-16T21:58:02.941Z,1684274282.941 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-16T21:58:02.948Z,1684274282.948 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-16T21:58:05.092Z,1684274285.092 [WetLabsBB2FL](INFO): Powering down
2023-05-16T21:58:08.665Z,1684274288.665 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-16T21:58:30.233Z,1684274310.233 [NAL9602](INFO): Powering up NAL9602
2023-05-16T21:58:39.608Z,1684274319.608 [Waterlinked](INFO): Powering down
2023-05-16T21:58:41.142Z,1684274321.142 [NAL9602](INFO): NAL9602 initialized
2023-05-16T21:59:26.015Z,1684274366.015 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-16T21:59:26.019Z,1684274366.019 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T21:59:36.953Z,1684274376.953 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.002047
CHAN A1 (24V): 0.002874
CHAN A2 (12V): -0.005197
CHAN A3 (5V): -0.003064
CHAN B0 (3.3V): -0.000683
CHAN B1 (3.15aV): -0.000997
CHAN B2 (3.15bV): -0.000937
CHAN B3 (GND): -0.000715
OPEN: 0.004506
Full Scale: +/- 1 mA
2023-05-16T21:59:42.622Z,1684274382.622 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T21:59:48.046Z,1684274388.046 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadB2; echo 1 > /dev/loadC3
2023-05-16T22:00:06.838Z,1684274406.838 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T22:00:20.173Z,1684274420.173 [SBIT](IMPORTANT): SBIT PASSED
2023-05-16T22:00:20.173Z,1684274420.173 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-16T22:00:20.174Z,1684274420.174 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-05-16T22:00:20.174Z,1684274420.174 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=2 minute;

2023-05-16T22:00:20.174Z,1684274420.174 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_salinity_homogeneity_index 0.050000 practical_salinity_unit;

2023-05-16T22:00:20.174Z,1684274420.174 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-05-16T22:00:20.174Z,1684274420.174 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_disk_space 100.000000 gigabyte;

2023-05-16T22:00:20.174Z,1684274420.174 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 300.000000 count_per_second;

2023-05-16T22:00:20.174Z,1684274420.174 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_shape 10.000000 count_per_second;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_slope 0.200000 count_per_millimeter;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=281.701195 cubic_centimeter;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): VerticalControl.massDefault=15.762392 millimeter;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-05-16T22:00:20.175Z,1684274420.175 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-05-16T22:00:20.552Z,1684274420.552 [MissionManager](IMPORTANT): Started mission Startup
2023-05-16T22:00:20.553Z,1684274420.553 [Startup] Running Loop=1
2023-05-16T22:00:20.553Z,1684274420.553 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-16T22:00:20.553Z,1684274420.553 [Startup:A.GoToSurface] Running Loop=1
2023-05-16T22:00:20.553Z,1684274420.553 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-16T22:00:20.554Z,1684274420.554 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-16T22:00:20.554Z,1684274420.554 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-16T22:00:20.554Z,1684274420.554 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-16T22:00:20.555Z,1684274420.555 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-16T22:00:20.555Z,1684274420.555 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-16T22:00:20.557Z,1684274420.557 [Startup:StartupSatComms] Running Loop=1
2023-05-16T22:00:20.557Z,1684274420.557 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-16T22:00:20.557Z,1684274420.557 [Startup:StartupSatComms:A] Running Loop=1
2023-05-16T22:00:20.955Z,1684274420.955 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-16T22:00:34.319Z,1684274434.319 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005101
2023-05-16T22:01:02.598Z,1684274462.598 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-05-16T22:01:02.598Z,1684274462.598 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:01:02.599Z,1684274462.599 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2023-05-16T22:01:02.599Z,1684274462.599 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:01:02.610Z,1684274462.610 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:01:02.610Z,1684274462.610 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:01:02.999Z,1684274462.999 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:01:02.000Z,1684274463.000 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-05-16T22:01:03.000Z,1684274463.000 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:01:03.000Z,1684274463.000 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2023-05-16T22:01:03.394Z,1684274463.394 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:01:16.442Z,1684274476.442 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T22:01:20.767Z,1684274480.767 [Startup:StartupSatComms:A](INFO): Timed out from 2023-05-16T22:00:20.6Z
2023-05-16T22:01:20.768Z,1684274480.768 [Startup:StartupSatComms:A] Stopped
2023-05-16T22:01:20.768Z,1684274480.768 [Startup:StartupSatComms:B] Running Loop=1
2023-05-16T22:01:21.176Z,1684274481.176 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-16T22:01:26.897Z,1684274486.897 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230516T213208/Courier0010.lzma
2023-05-16T22:01:27.887Z,1684274487.887 [DataOverHttps](INFO): Moved sent file to Logs/20230516T213208/Courier0010.lzma.bak
2023-05-16T22:01:27.887Z,1684274487.887 [DataOverHttps](INFO): SBD MOMSN=18318495
2023-05-16T22:01:28.485Z,1684274488.485 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T22:01:43.348Z,1684274503.348 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20230516T215558/Courier0000.lzma
2023-05-16T22:01:44.351Z,1684274504.351 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215558/Courier0000.lzma.bak
2023-05-16T22:01:44.351Z,1684274504.351 [DataOverHttps](INFO): SBD MOMSN=18318497
2023-05-16T22:01:52.315Z,1684274512.315 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T22:02:00.488Z,1684274520.488 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230516T215751/Courier0000.lzma
2023-05-16T22:02:01.490Z,1684274521.490 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0000.lzma.bak
2023-05-16T22:02:01.491Z,1684274521.491 [DataOverHttps](INFO): SBD MOMSN=18318501
2023-05-16T22:02:16.585Z,1684274536.585 [BPC1](ERROR): BPC1B failed to parse battery stick message.
2023-05-16T22:02:16.956Z,1684274536.956 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230516T213208/Express0011.lzma
2023-05-16T22:02:17.959Z,1684274537.959 [DataOverHttps](INFO): Moved sent file to Logs/20230516T213208/Express0011.lzma.bak
2023-05-16T22:02:17.959Z,1684274537.959 [DataOverHttps](INFO): SBD MOMSN=18318504
2023-05-16T22:02:20.963Z,1684274540.963 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-16T22:01:20.8Z
2023-05-16T22:02:20.964Z,1684274540.964 [Startup:StartupSatComms:B] Stopped
2023-05-16T22:02:20.964Z,1684274540.964 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-16T22:02:20.964Z,1684274540.964 [Startup:StartupSatComms] Stopped
2023-05-16T22:02:20.964Z,1684274540.964 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-16T22:02:21.018Z,1684274541.018 [Startup](INFO): Completed Startup
2023-05-16T22:02:21.018Z,1684274541.018 [MissionManager](INFO): Startup is completed.
2023-05-16T22:02:21.018Z,1684274541.018 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-16T22:02:21.018Z,1684274541.018 [Startup] Stopped
2023-05-16T22:02:21.018Z,1684274541.018 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-16T22:02:21.018Z,1684274541.018 [Startup:A.GoToSurface] Stopped
2023-05-16T22:02:21.018Z,1684274541.018 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-16T22:02:21.376Z,1684274541.376 [MissionManager](IMPORTANT): Started mission Default
2023-05-16T22:02:21.376Z,1684274541.376 [Default] Running Loop=1
2023-05-16T22:02:21.376Z,1684274541.376 [Default](DEBUG): Aggregate::initialize Default
2023-05-16T22:02:21.376Z,1684274541.376 [Default:B.GoToSurface] Running Loop=1
2023-05-16T22:02:21.376Z,1684274541.376 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-16T22:02:21.377Z,1684274541.377 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-16T22:02:21.377Z,1684274541.377 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-16T22:02:21.377Z,1684274541.377 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-16T22:02:21.378Z,1684274541.378 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-16T22:02:21.378Z,1684274541.378 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-16T22:02:21.378Z,1684274541.378 [Default:A.Wait] Running Loop=1
2023-05-16T22:02:21.378Z,1684274541.378 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:02:33.585Z,1684274553.585 [DataOverHttps](INFO): Sending 575 bytes from file Logs/20230516T215558/Express0001.lzma
2023-05-16T22:02:34.586Z,1684274554.586 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215558/Express0001.lzma.bak
2023-05-16T22:02:34.587Z,1684274554.587 [DataOverHttps](INFO): SBD MOMSN=18318506
2023-05-16T22:02:34.711Z,1684274554.711 [Default:A.Wait](INFO): Done Waiting.
2023-05-16T22:02:34.711Z,1684274554.711 [Default:A.Wait] Stopped
2023-05-16T22:02:34.711Z,1684274554.711 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T22:02:35.125Z,1684274555.125 [Default:CheckIn] Running Loop=1
2023-05-16T22:02:35.125Z,1684274555.125 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T22:02:35.125Z,1684274555.125 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T22:02:35.524Z,1684274555.524 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-16T22:03:07.654Z,1684274587.654 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:03:07.883Z,1684274587.883 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:03:18.762Z,1684274598.762 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.309994
CHAN A1 (24V): 0.677125
CHAN A2 (12V): 0.225190
CHAN A3 (5V): 0.048597
CHAN B0 (3.3V): 0.025781
CHAN B1 (3.15aV): 0.022819
CHAN B2 (3.15bV): 0.020409
CHAN B3 (GND): -0.029396
OPEN: 0.009060
Full Scale: +/- 1 mA
2023-05-16T22:03:44.583Z,1684274624.583 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T22:04:03.580Z,1684274643.580 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-05-16T22:04:03.580Z,1684274643.580 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:04:03.581Z,1684274643.581 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2023-05-16T22:04:03.581Z,1684274643.581 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:04:03.593Z,1684274643.593 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:04:03.593Z,1684274643.593 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:04:04.039Z,1684274644.039 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T22:04:04.060Z,1684274644.060 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:04:04.060Z,1684274644.060 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-05-16T22:04:04.061Z,1684274644.061 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:04:04.061Z,1684274644.061 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2023-05-16T22:04:04.405Z,1684274644.405 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:04:33.519Z,1684274673.519 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T22:04:36.166Z,1684274676.166 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:04:36.329Z,1684274676.329 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:04:47.266Z,1684274687.266 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.281326
CHAN A1 (24V): 0.642528
CHAN A2 (12V): 0.227762
CHAN A3 (5V): 0.047805
CHAN B0 (3.3V): 0.018848
CHAN B1 (3.15aV): 0.019953
CHAN B2 (3.15bV): 0.020024
CHAN B3 (GND): -0.027786
OPEN: 0.004103
Full Scale: +/- 1 mA
2023-05-16T22:04:58.165Z,1684274698.165 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T22:05:11.091Z,1684274711.091 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T22:05:23.615Z,1684274723.615 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T22:06:21.770Z,1684274781.770 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-05-16T22:06:21.773Z,1684274781.773 [BPC1](INFO): Received data from all battery sticks.
2023-05-16T22:06:43.518Z,1684274803.518 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:06:43.588Z,1684274803.588 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:06:54.484Z,1684274814.484 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.314559
CHAN A1 (24V): 0.623102
CHAN A2 (12V): 0.223665
CHAN A3 (5V): 0.046560
CHAN B0 (3.3V): 0.022082
CHAN B1 (3.15aV): 0.020110
CHAN B2 (3.15bV): 0.018565
CHAN B3 (GND): -0.030563
OPEN: 0.008499
Full Scale: +/- 1 mA
2023-05-16T22:07:04.583Z,1684274824.583 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-05-16T22:07:04.583Z,1684274824.583 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:07:04.584Z,1684274824.584 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2023-05-16T22:07:04.584Z,1684274824.584 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:07:04.595Z,1684274824.595 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:07:04.595Z,1684274824.595 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:07:05.001Z,1684274825.001 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:07:05.002Z,1684274825.002 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-05-16T22:07:05.002Z,1684274825.002 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:07:05.002Z,1684274825.002 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2023-05-16T22:07:05.405Z,1684274825.405 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:07:35.301Z,1684274855.301 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-16T22:02:35.1Z
2023-05-16T22:07:35.301Z,1684274855.301 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T22:07:35.301Z,1684274855.301 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T22:07:35.676Z,1684274855.676 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-16T22:07:43.520Z,1684274863.520 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230516T215751/Courier0004.lzma
2023-05-16T22:07:44.522Z,1684274864.522 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0004.lzma.bak
2023-05-16T22:07:44.523Z,1684274864.523 [DataOverHttps](INFO): SBD MOMSN=18318527
2023-05-16T22:07:59.922Z,1684274879.922 [DataOverHttps](INFO): Sending 1044 bytes from file Logs/20230516T215751/Express0001.lzma
2023-05-16T22:08:00.923Z,1684274880.923 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0001.lzma.bak
2023-05-16T22:08:00.923Z,1684274880.923 [DataOverHttps](INFO): SBD MOMSN=18318529
2023-05-16T22:08:40.729Z,1684274920.729 [Power24vConverter](INFO): Powering down.
2023-05-16T22:08:43.542Z,1684274923.542 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-16T22:08:43.542Z,1684274923.542 [NAL9602] Data Fault, FailCount= 1
2023-05-16T22:08:43.542Z,1684274923.542 [NAL9602](ERROR): Data Fault
2023-05-16T22:08:43.561Z,1684274923.561 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-16T22:08:43.946Z,1684274923.946 [NAL9602](INFO): Powering down
2023-05-16T22:08:44.772Z,1684274924.772 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-16T22:08:44.772Z,1684274924.772 [NAL9602] No Fault, FailCount= 1
2023-05-16T22:09:09.545Z,1684274949.545 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.387497
2023-05-16T22:09:14.244Z,1684274954.244 [NAL9602](INFO): Powering up NAL9602
2023-05-16T22:09:25.154Z,1684274965.154 [NAL9602](INFO): NAL9602 initialized
2023-05-16T22:09:40.677Z,1684274980.677 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:10:05.891Z,1684275005.891 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-05-16T22:10:05.891Z,1684275005.891 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:10:05.892Z,1684275005.892 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2023-05-16T22:10:05.892Z,1684275005.892 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:10:05.926Z,1684275005.926 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:10:05.926Z,1684275005.926 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:10:05.989Z,1684275005.989 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:10:05.989Z,1684275005.989 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-05-16T22:10:05.989Z,1684275005.989 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:10:05.989Z,1684275005.989 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2023-05-16T22:10:06.386Z,1684275006.386 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:10:15.817Z,1684275015.817 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:10:50.957Z,1684275050.957 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:11:26.125Z,1684275086.125 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:11:41.530Z,1684275101.530 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:11:41.752Z,1684275101.752 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:11:45.006Z,1684275105.006 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T22:11:53.508Z,1684275113.508 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.379862
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.215650
CHAN A3 (5V): 0.046433
CHAN B0 (3.3V): 0.022088
CHAN B1 (3.15aV): 0.020548
CHAN B2 (3.15bV): 0.021219
CHAN B3 (GND): -0.020226
OPEN: 0.009467
Full Scale: +/- 1 mA
2023-05-16T22:12:01.277Z,1684275121.277 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:12:15.837Z,1684275135.837 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003106
2023-05-16T22:12:24.033Z,1684275144.033 [DataOverHttps](INFO): Sending 495 bytes from file Logs/20230516T215751/Express0005.lzma
2023-05-16T22:12:25.035Z,1684275145.035 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0005.lzma.bak
2023-05-16T22:12:25.035Z,1684275145.035 [DataOverHttps](INFO): SBD MOMSN=18318573
2023-05-16T22:12:26.512Z,1684275146.512 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T22:12:26.512Z,1684275146.512 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T22:12:26.512Z,1684275146.512 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:13:06.523Z,1684275186.523 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-05-16T22:13:06.523Z,1684275186.523 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:13:06.524Z,1684275186.524 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2023-05-16T22:13:06.524Z,1684275186.524 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:13:06.576Z,1684275186.576 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:13:06.576Z,1684275186.576 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:13:06.943Z,1684275186.943 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:13:06.943Z,1684275186.943 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-05-16T22:13:06.943Z,1684275186.943 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:13:06.943Z,1684275186.943 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2023-05-16T22:13:07.334Z,1684275187.334 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:14:20.122Z,1684275260.122 [DataOverHttps](IMPORTANT): SBD MTMSN=20230516T221419
2023-05-16T22:14:27.281Z,1684275267.281 [DataOverHttps](INFO): Received command: gfscan
2023-05-16T22:14:27.282Z,1684275267.282 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:14:27.309Z,1684275267.309 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:14:30.161Z,1684275270.161 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T22:14:38.236Z,1684275278.236 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.368014
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.207398
CHAN A3 (5V): 0.043489
CHAN B0 (3.3V): 0.018311
CHAN B1 (3.15aV): 0.017329
CHAN B2 (3.15bV): 0.017373
CHAN B3 (GND): -0.014349
OPEN: 0.008885
Full Scale: +/- 1 mA
2023-05-16T22:15:44.947Z,1684275344.947 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadC3
2023-05-16T22:16:07.231Z,1684275367.231 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadB2; echo 1 > /dev/loadC3
2023-05-16T22:16:07.503Z,1684275367.503 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-05-16T22:16:07.503Z,1684275367.503 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:16:07.505Z,1684275367.505 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2023-05-16T22:16:07.505Z,1684275367.505 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:16:07.517Z,1684275367.517 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:16:07.517Z,1684275367.517 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:16:07.927Z,1684275367.927 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:16:07.927Z,1684275367.927 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-05-16T22:16:07.928Z,1684275367.928 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:16:07.928Z,1684275367.928 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2023-05-16T22:16:08.303Z,1684275368.303 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:17:27.080Z,1684275447.080 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T22:17:27.081Z,1684275447.081 [Default:CheckIn:C.Wait] Stopped
2023-05-16T22:17:27.081Z,1684275447.081 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T22:17:27.081Z,1684275447.081 [Default:CheckIn:D] Running Loop=1
2023-05-16T22:17:27.492Z,1684275447.492 [Default:CheckIn:D] Stopped
2023-05-16T22:17:27.492Z,1684275447.492 [Default:CheckIn:E] Running Loop=1
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.101935 min 
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn:E] Stopped
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn] Stopped
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn](INFO): Running loop #2
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn] Running Loop=2
2023-05-16T22:17:27.888Z,1684275447.888 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T22:17:27.889Z,1684275447.889 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T22:19:08.491Z,1684275548.491 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-05-16T22:19:08.491Z,1684275548.491 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:19:08.492Z,1684275548.492 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2023-05-16T22:19:08.492Z,1684275548.492 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:19:08.535Z,1684275548.535 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:19:08.536Z,1684275548.536 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:19:08.899Z,1684275548.899 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:19:08.899Z,1684275548.899 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-05-16T22:19:08.900Z,1684275548.900 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:19:08.900Z,1684275548.900 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2023-05-16T22:19:09.300Z,1684275549.300 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:19:28.271Z,1684275568.271 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-16T22:19:28.271Z,1684275568.271 [NAL9602] Data Fault, FailCount= 2
2023-05-16T22:19:28.271Z,1684275568.271 [NAL9602](ERROR): Data Fault
2023-05-16T22:19:28.290Z,1684275568.290 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-16T22:19:28.667Z,1684275568.667 [NAL9602](INFO): Powering down
2023-05-16T22:19:29.499Z,1684275569.499 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-16T22:19:29.499Z,1684275569.499 [NAL9602] No Fault, FailCount= 2
2023-05-16T22:19:58.976Z,1684275598.976 [NAL9602](INFO): Powering up NAL9602
2023-05-16T22:20:09.882Z,1684275609.882 [NAL9602](INFO): NAL9602 initialized
2023-05-16T22:21:54.869Z,1684275714.869 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:21:56.877Z,1684275716.877 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.242966
2023-05-16T22:22:09.474Z,1684275729.474 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-05-16T22:22:09.474Z,1684275729.474 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:22:09.476Z,1684275729.476 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2023-05-16T22:22:09.476Z,1684275729.476 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:22:09.487Z,1684275729.487 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:22:09.487Z,1684275729.487 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:22:09.900Z,1684275729.900 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:22:09.900Z,1684275729.900 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-05-16T22:22:09.901Z,1684275729.901 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:22:09.901Z,1684275729.901 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2023-05-16T22:22:10.275Z,1684275730.275 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:22:28.065Z,1684275748.065 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-16T22:17:27.9Z
2023-05-16T22:22:28.065Z,1684275748.065 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T22:22:28.065Z,1684275748.065 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T22:22:30.021Z,1684275750.021 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:23:05.161Z,1684275785.161 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:23:40.305Z,1684275820.305 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:24:15.457Z,1684275855.457 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:24:50.605Z,1684275890.605 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:25:10.373Z,1684275910.373 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-05-16T22:25:10.373Z,1684275910.373 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-16T22:25:10.375Z,1684275910.375 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2023-05-16T22:25:10.375Z,1684275910.375 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-05-16T22:25:10.385Z,1684275910.385 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-16T22:25:10.386Z,1684275910.386 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-05-16T22:25:10.799Z,1684275910.799 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-16T22:25:10.800Z,1684275910.800 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-05-16T22:25:10.800Z,1684275910.800 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-05-16T22:25:10.800Z,1684275910.800 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2023-05-16T22:25:11.355Z,1684275911.355 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-05-16T22:25:25.769Z,1684275925.769 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:25:39.492Z,1684275939.492 [NAL9602](INFO): SBD MO Status=2, MOMSN=11818, MT Status=2, MTMSN=0
2023-05-16T22:25:39.492Z,1684275939.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-16T22:26:00.909Z,1684275960.909 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:26:36.053Z,1684275996.053 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:27:11.193Z,1684276031.193 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:27:35.037Z,1684276055.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222733.00,A,3648.16428,N,12147.27885,W,0.194,0.00,160523,,,A*77
2023-05-16T22:27:35.040Z,1684276055.040 [NAL9602](INFO): GPS fix at 20230516T222733: (36.802738, -121.787981)
2023-05-16T22:27:46.337Z,1684276066.337 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:28:21.489Z,1684276101.489 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:28:56.629Z,1684276136.629 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:29:31.770Z,1684276171.770 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:29:58.498Z,1684276198.498 [NAL9602](INFO): SBD MO Status=1, MOMSN=11818, MT Status=0, MTMSN=0
2023-05-16T22:29:58.549Z,1684276198.549 [NAL9602](INFO): Sent 39 bytes from file Logs/20230516T215751/Courier0007.lzma
2023-05-16T22:29:58.549Z,1684276198.549 [NAL9602](INFO): Packets left to send: 0
2023-05-16T22:30:06.925Z,1684276206.925 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:30:18.392Z,1684276218.392 [NAL9602](INFO): SBD MO Status=1, MOMSN=11819, MT Status=0, MTMSN=0
2023-05-16T22:30:18.445Z,1684276218.445 [NAL9602](INFO): Sent 332 bytes from file Logs/20230516T215751/Express0008.lzma
2023-05-16T22:30:18.445Z,1684276218.445 [NAL9602](INFO): Packets left to send: 1
2023-05-16T22:30:37.484Z,1684276237.484 [NAL9602](INFO): SBD MO Status=1, MOMSN=11820, MT Status=0, MTMSN=0
2023-05-16T22:30:37.545Z,1684276237.545 [NAL9602](INFO): Sent 232 bytes from file Logs/20230516T215751/Express0008.lzma
2023-05-16T22:30:37.545Z,1684276237.545 [NAL9602](INFO): Packets left to send: 0
2023-05-16T22:30:42.073Z,1684276242.073 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:30:44.768Z,1684276244.768 [NAL9602](INFO): SBD MO Status=0, MOMSN=11821, MT Status=0, MTMSN=0
2023-05-16T22:30:44.847Z,1684276244.847 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T22:30:44.847Z,1684276244.847 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T22:30:44.847Z,1684276244.847 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:31:15.462Z,1684276275.462 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T22:31:17.237Z,1684276277.237 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:31:52.377Z,1684276312.377 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:32:27.517Z,1684276347.517 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:33:02.657Z,1684276382.657 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:33:37.797Z,1684276417.797 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:33:52.609Z,1684276432.609 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003136
2023-05-16T22:34:38.734Z,1684276478.734 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:34:38.763Z,1684276478.763 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:34:41.591Z,1684276481.591 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T22:34:49.664Z,1684276489.664 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.803731
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.577180
CHAN A3 (5V): 0.091843
CHAN B0 (3.3V): 0.034882
CHAN B1 (3.15aV): 0.032689
CHAN B2 (3.15bV): 0.037410
CHAN B3 (GND): -0.041199
OPEN: 0.004921
Full Scale: +/- 1 mA
2023-05-16T22:35:14.190Z,1684276514.190 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC3
2023-05-16T22:35:37.726Z,1684276537.726 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:35:37.742Z,1684276537.742 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:35:40.566Z,1684276540.566 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T22:35:45.405Z,1684276545.405 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T22:35:45.405Z,1684276545.405 [Default:CheckIn:C.Wait] Stopped
2023-05-16T22:35:45.405Z,1684276545.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T22:35:45.405Z,1684276545.405 [Default:CheckIn:D] Running Loop=1
2023-05-16T22:35:45.814Z,1684276545.814 [Default:CheckIn:D] Stopped
2023-05-16T22:35:45.814Z,1684276545.814 [Default:CheckIn:E] Running Loop=1
2023-05-16T22:35:46.240Z,1684276546.240 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.407302 min 
2023-05-16T22:35:46.240Z,1684276546.240 [Default:CheckIn:E] Stopped
2023-05-16T22:35:46.240Z,1684276546.240 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T22:35:46.240Z,1684276546.240 [Default:CheckIn] Stopped
2023-05-16T22:35:46.240Z,1684276546.240 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T22:35:46.241Z,1684276546.241 [Default:CheckIn](INFO): Running loop #3
2023-05-16T22:35:46.241Z,1684276546.241 [Default:CheckIn] Running Loop=3
2023-05-16T22:35:46.241Z,1684276546.241 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T22:35:46.241Z,1684276546.241 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T22:35:48.224Z,1684276548.224 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223547.00,A,3648.17616,N,12147.28397,W,0.019,12.94,160523,,,A*44
2023-05-16T22:35:48.226Z,1684276548.226 [NAL9602](INFO): GPS fix at 20230516T223547: (36.802936, -121.788066)
2023-05-16T22:35:48.298Z,1684276548.298 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T22:35:48.298Z,1684276548.298 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T22:35:48.718Z,1684276548.718 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005416
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.005167
CHAN A3 (5V): -0.003087
CHAN B0 (3.3V): -0.001538
CHAN B1 (3.15aV): -0.001655
CHAN B2 (3.15bV): -0.001035
CHAN B3 (GND): -0.000542
OPEN: 0.004368
Full Scale: +/- 1 mA
2023-05-16T22:35:59.060Z,1684276559.060 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20230516T215751/Courier0010.lzma
2023-05-16T22:36:00.062Z,1684276560.062 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0010.lzma.bak
2023-05-16T22:36:00.063Z,1684276560.063 [DataOverHttps](INFO): SBD MOMSN=18318729
2023-05-16T22:36:08.282Z,1684276568.282 [NAL9602](INFO): SBD MO Status=0, MOMSN=11822, MT Status=0, MTMSN=0
2023-05-16T22:36:08.282Z,1684276568.282 [NAL9602](INFO): No messages in MT queue
2023-05-16T22:36:16.406Z,1684276576.406 [DataOverHttps](INFO): Sending 578 bytes from file Logs/20230516T215751/Express0011.lzma
2023-05-16T22:36:17.406Z,1684276577.406 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0011.lzma.bak
2023-05-16T22:36:17.407Z,1684276577.407 [DataOverHttps](INFO): SBD MOMSN=18318735
2023-05-16T22:36:18.799Z,1684276578.799 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T22:36:18.799Z,1684276578.799 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T22:36:18.800Z,1684276578.800 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:36:30.742Z,1684276590.742 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadC3
2023-05-16T22:36:38.984Z,1684276598.984 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T22:36:52.526Z,1684276612.526 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:36:52.751Z,1684276612.751 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:36:55.577Z,1684276615.577 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T22:37:03.658Z,1684276623.658 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.804840
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.601511
CHAN A3 (5V): 0.090831
CHAN B0 (3.3V): 0.038334
CHAN B1 (3.15aV): 0.037450
CHAN B2 (3.15bV): 0.039166
CHAN B3 (GND): -0.048612
OPEN: 0.010162
Full Scale: +/- 1 mA
2023-05-16T22:38:07.822Z,1684276687.822 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC3
2023-05-16T22:38:15.246Z,1684276695.246 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T22:38:15.565Z,1684276695.565 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T22:38:18.390Z,1684276698.390 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T22:38:26.504Z,1684276706.504 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005664
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.005387
CHAN A3 (5V): -0.003070
CHAN B0 (3.3V): -0.000720
CHAN B1 (3.15aV): -0.001547
CHAN B2 (3.15bV): -0.001261
CHAN B3 (GND): -0.000572
OPEN: 0.004367
Full Scale: +/- 1 mA
2023-05-16T22:41:19.382Z,1684276879.382 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T22:41:19.382Z,1684276879.382 [Default:CheckIn:C.Wait] Stopped
2023-05-16T22:41:19.382Z,1684276879.382 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T22:41:19.382Z,1684276879.382 [Default:CheckIn:D] Running Loop=1
2023-05-16T22:41:19.802Z,1684276879.802 [Default:CheckIn:D] Stopped
2023-05-16T22:41:19.802Z,1684276879.802 [Default:CheckIn:E] Running Loop=1
2023-05-16T22:41:20.181Z,1684276880.181 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.973771 min 
2023-05-16T22:41:20.181Z,1684276880.181 [Default:CheckIn:E] Stopped
2023-05-16T22:41:20.181Z,1684276880.181 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T22:41:20.181Z,1684276880.181 [Default:CheckIn] Stopped
2023-05-16T22:41:20.182Z,1684276880.182 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T22:41:20.182Z,1684276880.182 [Default:CheckIn](INFO): Running loop #4
2023-05-16T22:41:20.182Z,1684276880.182 [Default:CheckIn] Running Loop=4
2023-05-16T22:41:20.182Z,1684276880.182 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T22:41:20.182Z,1684276880.182 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T22:41:22.193Z,1684276882.193 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224121.00,A,3648.17045,N,12147.34378,W,3.324,271.37,160523,,,D*7E
2023-05-16T22:41:22.195Z,1684276882.195 [NAL9602](INFO): GPS fix at 20230516T224121: (36.802841, -121.789063)
2023-05-16T22:41:22.208Z,1684276882.208 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T22:41:22.208Z,1684276882.208 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T22:41:56.721Z,1684276916.721 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.523483
2023-05-16T22:42:27.853Z,1684276947.853 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-05-16T22:42:42.274Z,1684276962.274 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003576
2023-05-16T22:42:49.612Z,1684276969.612 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230516T215751/Courier0015.lzma
2023-05-16T22:42:50.615Z,1684276970.615 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0015.lzma.bak
2023-05-16T22:42:50.615Z,1684276970.615 [DataOverHttps](INFO): SBD MOMSN=18318751
2023-05-16T22:43:06.905Z,1684276986.905 [DataOverHttps](INFO): Sending 462 bytes from file Logs/20230516T215751/Express0014.lzma
2023-05-16T22:43:07.907Z,1684276987.907 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0014.lzma.bak
2023-05-16T22:43:07.907Z,1684276987.907 [DataOverHttps](INFO): SBD MOMSN=18318754
2023-05-16T22:43:09.274Z,1684276989.274 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T22:43:09.274Z,1684276989.274 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T22:43:09.274Z,1684276989.274 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:46:24.405Z,1684277184.405 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T22:46:55.114Z,1684277215.114 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T22:48:09.861Z,1684277289.861 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T22:48:09.861Z,1684277289.861 [Default:CheckIn:C.Wait] Stopped
2023-05-16T22:48:09.861Z,1684277289.861 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T22:48:09.861Z,1684277289.861 [Default:CheckIn:D] Running Loop=1
2023-05-16T22:48:10.271Z,1684277290.271 [Default:CheckIn:D] Stopped
2023-05-16T22:48:10.271Z,1684277290.271 [Default:CheckIn:E] Running Loop=1
2023-05-16T22:48:10.678Z,1684277290.678 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.814921 min 
2023-05-16T22:48:10.678Z,1684277290.678 [Default:CheckIn:E] Stopped
2023-05-16T22:48:10.678Z,1684277290.678 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T22:48:10.679Z,1684277290.679 [Default:CheckIn] Stopped
2023-05-16T22:48:10.679Z,1684277290.679 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T22:48:10.679Z,1684277290.679 [Default:CheckIn](INFO): Running loop #5
2023-05-16T22:48:10.679Z,1684277290.679 [Default:CheckIn] Running Loop=5
2023-05-16T22:48:10.679Z,1684277290.679 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T22:48:10.679Z,1684277290.679 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T22:48:12.680Z,1684277292.680 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224811.00,A,3648.18778,N,12147.27480,W,1.769,15.96,160523,,,A*41
2023-05-16T22:48:12.682Z,1684277292.682 [NAL9602](INFO): GPS fix at 20230516T224811: (36.803130, -121.787913)
2023-05-16T22:48:12.716Z,1684277292.716 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T22:48:12.716Z,1684277292.716 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T22:48:20.300Z,1684277300.300 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230516T215751/Courier0019.lzma
2023-05-16T22:48:21.302Z,1684277301.302 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0019.lzma.bak
2023-05-16T22:48:21.303Z,1684277301.303 [DataOverHttps](INFO): SBD MOMSN=18318773
2023-05-16T22:48:36.924Z,1684277316.924 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230516T215751/Express0020.lzma
2023-05-16T22:48:37.927Z,1684277317.927 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0020.lzma.bak
2023-05-16T22:48:37.927Z,1684277317.927 [DataOverHttps](INFO): SBD MOMSN=18318776
2023-05-16T22:48:39.355Z,1684277319.355 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T22:48:39.355Z,1684277319.355 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T22:48:39.355Z,1684277319.355 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:48:43.386Z,1684277323.386 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-16T22:48:43.465Z,1684277323.465 [NAL9602](ERROR): received: 
+CSQ:0

OK822, 0, 0, 0, 0

OK
2023-05-16T22:53:15.274Z,1684277595.274 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T22:53:39.933Z,1684277619.933 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T22:53:39.933Z,1684277619.933 [Default:CheckIn:C.Wait] Stopped
2023-05-16T22:53:39.933Z,1684277619.933 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T22:53:39.933Z,1684277619.933 [Default:CheckIn:D] Running Loop=1
2023-05-16T22:53:40.338Z,1684277620.338 [Default:CheckIn:D] Stopped
2023-05-16T22:53:40.338Z,1684277620.338 [Default:CheckIn:E] Running Loop=1
2023-05-16T22:53:40.747Z,1684277620.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.316028 min 
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn:E] Stopped
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn] Stopped
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn](INFO): Running loop #6
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn] Running Loop=6
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T22:53:40.748Z,1684277620.748 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T22:53:42.752Z,1684277622.752 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225342.00,A,3648.15256,N,12147.29946,W,1.944,219.56,160523,,,A*73
2023-05-16T22:53:42.754Z,1684277622.754 [NAL9602](INFO): GPS fix at 20230516T225342: (36.802543, -121.788324)
2023-05-16T22:53:42.800Z,1684277622.800 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T22:53:42.800Z,1684277622.800 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T22:53:49.632Z,1684277629.632 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230516T215751/Courier0022.lzma
2023-05-16T22:53:50.635Z,1684277630.635 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0022.lzma.bak
2023-05-16T22:53:50.635Z,1684277630.635 [DataOverHttps](INFO): SBD MOMSN=18318811
2023-05-16T22:54:06.636Z,1684277646.636 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230516T215751/Express0023.lzma
2023-05-16T22:54:07.639Z,1684277647.639 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0023.lzma.bak
2023-05-16T22:54:07.639Z,1684277647.639 [DataOverHttps](INFO): SBD MOMSN=18318814
2023-05-16T22:54:09.021Z,1684277649.021 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T22:54:09.021Z,1684277649.021 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T22:54:09.021Z,1684277649.021 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:54:15.471Z,1684277655.471 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T22:59:09.598Z,1684277949.598 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T22:59:09.599Z,1684277949.599 [Default:CheckIn:C.Wait] Stopped
2023-05-16T22:59:09.599Z,1684277949.599 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T22:59:09.599Z,1684277949.599 [Default:CheckIn:D] Running Loop=1
2023-05-16T22:59:10.014Z,1684277950.014 [Default:CheckIn:D] Stopped
2023-05-16T22:59:10.014Z,1684277950.014 [Default:CheckIn:E] Running Loop=1
2023-05-16T22:59:10.401Z,1684277950.401 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.810624 min 
2023-05-16T22:59:10.401Z,1684277950.401 [Default:CheckIn:E] Stopped
2023-05-16T22:59:10.401Z,1684277950.401 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T22:59:10.401Z,1684277950.401 [Default:CheckIn] Stopped
2023-05-16T22:59:10.401Z,1684277950.401 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T22:59:10.401Z,1684277950.401 [Default:CheckIn](INFO): Running loop #7
2023-05-16T22:59:10.401Z,1684277950.401 [Default:CheckIn] Running Loop=7
2023-05-16T22:59:10.402Z,1684277950.402 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T22:59:10.402Z,1684277950.402 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T22:59:12.416Z,1684277952.416 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225911.00,A,3648.15930,N,12147.28740,W,0.389,206.92,160523,,,A*71
2023-05-16T22:59:12.418Z,1684277952.418 [NAL9602](INFO): GPS fix at 20230516T225911: (36.802655, -121.788123)
2023-05-16T22:59:12.430Z,1684277952.430 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T22:59:12.430Z,1684277952.430 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T22:59:19.672Z,1684277959.672 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230516T215751/Courier0025.lzma
2023-05-16T22:59:20.675Z,1684277960.675 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0025.lzma.bak
2023-05-16T22:59:20.675Z,1684277960.675 [DataOverHttps](INFO): SBD MOMSN=18318826
2023-05-16T22:59:37.844Z,1684277977.844 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230516T215751/Express0026.lzma
2023-05-16T22:59:38.847Z,1684277978.847 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0026.lzma.bak
2023-05-16T22:59:38.847Z,1684277978.847 [DataOverHttps](INFO): SBD MOMSN=18318829
2023-05-16T22:59:40.701Z,1684277980.701 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T22:59:40.701Z,1684277980.701 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T22:59:40.701Z,1684277980.701 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T22:59:43.114Z,1684277983.114 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-16T22:59:43.197Z,1684277983.197 [NAL9602](ERROR): received: 
+CSQ:0

OK822, 0, 0, 0, 0

OK
2023-05-16T23:04:14.202Z,1684278254.202 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T23:04:41.285Z,1684278281.285 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:04:41.285Z,1684278281.285 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:04:41.285Z,1684278281.285 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:04:41.285Z,1684278281.285 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:04:41.682Z,1684278281.682 [Default:CheckIn:D] Stopped
2023-05-16T23:04:41.682Z,1684278281.682 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:04:42.085Z,1684278282.085 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.338424 min 
2023-05-16T23:04:42.085Z,1684278282.085 [Default:CheckIn:E] Stopped
2023-05-16T23:04:42.085Z,1684278282.085 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:04:42.085Z,1684278282.085 [Default:CheckIn] Stopped
2023-05-16T23:04:42.085Z,1684278282.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:04:42.086Z,1684278282.086 [Default:CheckIn](INFO): Running loop #8
2023-05-16T23:04:42.086Z,1684278282.086 [Default:CheckIn] Running Loop=8
2023-05-16T23:04:42.086Z,1684278282.086 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:04:42.086Z,1684278282.086 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:04:44.096Z,1684278284.096 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230443.00,A,3648.15880,N,12147.28547,W,2.605,40.23,160523,,,A*49
2023-05-16T23:04:44.098Z,1684278284.098 [NAL9602](INFO): GPS fix at 20230516T230443: (36.802647, -121.788091)
2023-05-16T23:04:44.111Z,1684278284.111 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:04:44.111Z,1684278284.111 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:04:51.332Z,1684278291.332 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230516T215751/Courier0028.lzma
2023-05-16T23:04:52.335Z,1684278292.335 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0028.lzma.bak
2023-05-16T23:04:52.335Z,1684278292.335 [DataOverHttps](INFO): SBD MOMSN=18318832
2023-05-16T23:05:07.953Z,1684278307.953 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230516T215751/Express0029.lzma
2023-05-16T23:05:08.955Z,1684278308.955 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0029.lzma.bak
2023-05-16T23:05:08.955Z,1684278308.955 [DataOverHttps](INFO): SBD MOMSN=18318836
2023-05-16T23:05:10.373Z,1684278310.373 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:05:10.373Z,1684278310.373 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:05:10.373Z,1684278310.373 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:05:16.412Z,1684278316.412 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T23:07:29.362Z,1684278449.362 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:07:56.396Z,1684278476.396 [BPC1](ERROR): BPC1B failed to parse battery stick message.
2023-05-16T23:08:09.417Z,1684278489.417 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:08:37.663Z,1684278517.663 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T23:09:31.803Z,1684278571.803 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T23:09:44.325Z,1684278584.325 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T23:09:44.391Z,1684278584.391 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:09:57.843Z,1684278597.843 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:10:10.587Z,1684278610.587 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:10:10.979Z,1684278610.979 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:10:10.979Z,1684278610.979 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:10:10.979Z,1684278610.979 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:10:10.979Z,1684278610.979 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:10:11.346Z,1684278611.346 [Default:CheckIn:D] Stopped
2023-05-16T23:10:11.346Z,1684278611.346 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:10:11.827Z,1684278611.827 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.832829 min 
2023-05-16T23:10:11.827Z,1684278611.827 [Default:CheckIn:E] Stopped
2023-05-16T23:10:11.827Z,1684278611.827 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:10:11.827Z,1684278611.827 [Default:CheckIn] Stopped
2023-05-16T23:10:11.827Z,1684278611.827 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:10:11.827Z,1684278611.827 [Default:CheckIn](INFO): Running loop #9
2023-05-16T23:10:11.828Z,1684278611.828 [Default:CheckIn] Running Loop=9
2023-05-16T23:10:11.828Z,1684278611.828 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:10:11.828Z,1684278611.828 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:10:13.764Z,1684278613.764 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231013.00,A,3648.16177,N,12147.30699,W,0.816,161.60,160523,,,A*79
2023-05-16T23:10:13.766Z,1684278613.766 [NAL9602](INFO): GPS fix at 20230516T231013: (36.802696, -121.788450)
2023-05-16T23:10:13.798Z,1684278613.798 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:10:13.799Z,1684278613.799 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:10:21.536Z,1684278621.536 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230516T215751/Courier0031.lzma
2023-05-16T23:10:22.539Z,1684278622.539 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0031.lzma.bak
2023-05-16T23:10:22.539Z,1684278622.539 [DataOverHttps](INFO): SBD MOMSN=18318908
2023-05-16T23:10:23.515Z,1684278623.515 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:10:42.048Z,1684278642.048 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230516T215751/Express0032.lzma
2023-05-16T23:10:43.051Z,1684278643.051 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0032.lzma.bak
2023-05-16T23:10:43.051Z,1684278643.051 [DataOverHttps](INFO): SBD MOMSN=18318915
2023-05-16T23:10:44.530Z,1684278644.530 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-16T23:10:44.605Z,1684278644.605 [NAL9602](ERROR): received: 
+CSQ:0

OK822, 0, 0, 0, 0

OK
2023-05-16T23:10:45.043Z,1684278645.043 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:10:45.043Z,1684278645.043 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:10:45.043Z,1684278645.043 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:11:44.790Z,1684278704.790 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:11:47.217Z,1684278707.217 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T23:13:26.997Z,1684278806.997 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:13:42.754Z,1684278822.754 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-05-16T23:14:54.669Z,1684278894.669 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2023-05-16T23:15:01.891Z,1684278901.891 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-05-16T23:15:01.894Z,1684278901.894 [BPC1](INFO): Received data from all battery sticks.
2023-05-16T23:15:16.429Z,1684278916.429 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T23:15:45.528Z,1684278945.528 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:15:45.528Z,1684278945.528 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:15:45.528Z,1684278945.528 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:15:45.529Z,1684278945.529 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:15:45.937Z,1684278945.937 [Default:CheckIn:D] Stopped
2023-05-16T23:15:45.937Z,1684278945.937 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:15:46.338Z,1684278946.338 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.409351 min 
2023-05-16T23:15:46.338Z,1684278946.338 [Default:CheckIn:E] Stopped
2023-05-16T23:15:46.339Z,1684278946.339 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:15:46.339Z,1684278946.339 [Default:CheckIn] Stopped
2023-05-16T23:15:46.339Z,1684278946.339 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:15:46.339Z,1684278946.339 [Default:CheckIn](INFO): Running loop #10
2023-05-16T23:15:46.339Z,1684278946.339 [Default:CheckIn] Running Loop=10
2023-05-16T23:15:46.339Z,1684278946.339 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:15:46.339Z,1684278946.339 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:15:48.356Z,1684278948.356 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231547.00,A,3648.20397,N,12147.26462,W,1.886,31.63,160523,,,A*4A
2023-05-16T23:15:48.358Z,1684278948.358 [NAL9602](INFO): GPS fix at 20230516T231547: (36.803399, -121.787744)
2023-05-16T23:15:48.371Z,1684278948.371 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:15:48.371Z,1684278948.371 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:15:55.540Z,1684278955.540 [DataOverHttps](INFO): Sending 85 bytes from file Logs/20230516T215751/Courier0034.lzma
2023-05-16T23:15:56.543Z,1684278956.543 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0034.lzma.bak
2023-05-16T23:15:56.543Z,1684278956.543 [DataOverHttps](INFO): SBD MOMSN=18318929
2023-05-16T23:16:12.292Z,1684278972.292 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230516T215751/Express0035.lzma
2023-05-16T23:16:13.295Z,1684278973.295 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0035.lzma.bak
2023-05-16T23:16:13.295Z,1684278973.295 [DataOverHttps](INFO): SBD MOMSN=18318932
2023-05-16T23:16:14.623Z,1684278974.623 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:16:14.624Z,1684278974.624 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:16:14.624Z,1684278974.624 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:16:20.270Z,1684278980.270 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T23:21:15.202Z,1684279275.202 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:21:15.202Z,1684279275.202 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:21:15.202Z,1684279275.202 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:21:15.202Z,1684279275.202 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:21:15.598Z,1684279275.598 [Default:CheckIn:D] Stopped
2023-05-16T23:21:15.598Z,1684279275.598 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.903703 min 
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn:E] Stopped
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn] Stopped
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn](INFO): Running loop #11
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn] Running Loop=11
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:21:16.006Z,1684279276.006 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:21:18.016Z,1684279278.016 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232117.00,A,3648.17591,N,12147.25118,W,1.613,31.63,160523,,,A*45
2023-05-16T23:21:18.027Z,1684279278.027 [NAL9602](INFO): GPS fix at 20230516T232117: (36.802932, -121.787520)
2023-05-16T23:21:18.039Z,1684279278.039 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:21:18.039Z,1684279278.039 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:21:25.448Z,1684279285.448 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230516T215751/Courier0037.lzma
2023-05-16T23:21:26.451Z,1684279286.451 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0037.lzma.bak
2023-05-16T23:21:26.451Z,1684279286.451 [DataOverHttps](INFO): SBD MOMSN=18318942
2023-05-16T23:21:42.204Z,1684279302.204 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230516T215751/Express0038.lzma
2023-05-16T23:21:43.207Z,1684279303.207 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0038.lzma.bak
2023-05-16T23:21:43.207Z,1684279303.207 [DataOverHttps](INFO): SBD MOMSN=18318945
2023-05-16T23:21:44.727Z,1684279304.727 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:21:44.727Z,1684279304.727 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:21:44.727Z,1684279304.727 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:21:48.746Z,1684279308.746 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-16T23:21:48.821Z,1684279308.821 [NAL9602](ERROR): received: 
+CSQ:0

OK822, 0, 0, 0, 0

OK
2023-05-16T23:26:20.234Z,1684279580.234 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T23:26:45.301Z,1684279605.301 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:26:45.301Z,1684279605.301 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:26:45.301Z,1684279605.301 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:26:45.301Z,1684279605.301 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:26:45.697Z,1684279605.697 [Default:CheckIn:D] Stopped
2023-05-16T23:26:45.697Z,1684279605.697 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:26:46.097Z,1684279606.097 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.405355 min 
2023-05-16T23:26:46.097Z,1684279606.097 [Default:CheckIn:E] Stopped
2023-05-16T23:26:46.097Z,1684279606.097 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:26:46.097Z,1684279606.097 [Default:CheckIn] Stopped
2023-05-16T23:26:46.098Z,1684279606.098 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:26:46.098Z,1684279606.098 [Default:CheckIn](INFO): Running loop #12
2023-05-16T23:26:46.098Z,1684279606.098 [Default:CheckIn] Running Loop=12
2023-05-16T23:26:46.098Z,1684279606.098 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:26:46.098Z,1684279606.098 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:26:59.828Z,1684279619.828 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232659.00,A,3648.14788,N,12147.26438,W,2.683,0.00,160523,,,A*78
2023-05-16T23:26:59.830Z,1684279619.830 [NAL9602](INFO): GPS fix at 20230516T232659: (36.802465, -121.787740)
2023-05-16T23:26:59.842Z,1684279619.842 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:26:59.842Z,1684279619.842 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:27:06.600Z,1684279626.600 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230516T215751/Courier0040.lzma
2023-05-16T23:27:07.603Z,1684279627.603 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0040.lzma.bak
2023-05-16T23:27:07.603Z,1684279627.603 [DataOverHttps](INFO): SBD MOMSN=18318948
2023-05-16T23:27:23.200Z,1684279643.200 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230516T215751/Express0041.lzma
2023-05-16T23:27:24.203Z,1684279644.203 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0041.lzma.bak
2023-05-16T23:27:24.203Z,1684279644.203 [DataOverHttps](INFO): SBD MOMSN=18318951
2023-05-16T23:27:25.726Z,1684279645.726 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:27:25.726Z,1684279645.726 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:27:25.726Z,1684279645.726 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:27:32.558Z,1684279652.558 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T23:32:26.306Z,1684279946.306 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:32:26.306Z,1684279946.306 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:32:26.306Z,1684279946.306 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:32:26.306Z,1684279946.306 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:32:26.696Z,1684279946.696 [Default:CheckIn:D] Stopped
2023-05-16T23:32:26.696Z,1684279946.696 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:32:27.106Z,1684279947.106 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.088672 min 
2023-05-16T23:32:27.106Z,1684279947.106 [Default:CheckIn:E] Stopped
2023-05-16T23:32:27.106Z,1684279947.106 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:32:27.106Z,1684279947.106 [Default:CheckIn] Stopped
2023-05-16T23:32:27.106Z,1684279947.106 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:32:27.106Z,1684279947.106 [Default:CheckIn](INFO): Running loop #13
2023-05-16T23:32:27.107Z,1684279947.107 [Default:CheckIn] Running Loop=13
2023-05-16T23:32:27.107Z,1684279947.107 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:32:27.107Z,1684279947.107 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:32:29.116Z,1684279949.116 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233228.00,A,3648.16532,N,12147.29014,W,1.283,0.00,160523,,,A*78
2023-05-16T23:32:29.118Z,1684279949.118 [NAL9602](INFO): GPS fix at 20230516T233228: (36.802755, -121.788169)
2023-05-16T23:32:29.131Z,1684279949.131 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:32:29.131Z,1684279949.131 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:32:36.388Z,1684279956.388 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230516T215751/Courier0043.lzma
2023-05-16T23:32:37.391Z,1684279957.391 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0043.lzma.bak
2023-05-16T23:32:37.391Z,1684279957.391 [DataOverHttps](INFO): SBD MOMSN=18318965
2023-05-16T23:32:53.672Z,1684279973.672 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230516T215751/Express0044.lzma
2023-05-16T23:32:54.677Z,1684279974.677 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0044.lzma.bak
2023-05-16T23:32:54.677Z,1684279974.677 [DataOverHttps](INFO): SBD MOMSN=18318968
2023-05-16T23:32:56.197Z,1684279976.197 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:32:56.198Z,1684279976.198 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:32:56.198Z,1684279976.198 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:32:59.814Z,1684279979.814 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-16T23:32:59.889Z,1684279979.889 [NAL9602](ERROR): received: 
+CSQ:0

OK822, 0, 0, 0, 0

OK
2023-05-16T23:37:31.323Z,1684280251.323 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T23:37:56.774Z,1684280276.774 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:37:56.774Z,1684280276.774 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:37:56.774Z,1684280276.774 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:37:56.775Z,1684280276.775 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:37:57.195Z,1684280277.195 [Default:CheckIn:D] Stopped
2023-05-16T23:37:57.195Z,1684280277.195 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:37:57.573Z,1684280277.573 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.596989 min 
2023-05-16T23:37:57.573Z,1684280277.573 [Default:CheckIn:E] Stopped
2023-05-16T23:37:57.573Z,1684280277.573 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:37:57.573Z,1684280277.573 [Default:CheckIn] Stopped
2023-05-16T23:37:57.573Z,1684280277.573 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:37:57.574Z,1684280277.574 [Default:CheckIn](INFO): Running loop #14
2023-05-16T23:37:57.574Z,1684280277.574 [Default:CheckIn] Running Loop=14
2023-05-16T23:37:57.574Z,1684280277.574 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:37:57.574Z,1684280277.574 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:37:59.592Z,1684280279.592 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233758.00,A,3648.18128,N,12147.27143,W,1.536,143.71,160523,,,A*7F
2023-05-16T23:37:59.594Z,1684280279.594 [NAL9602](INFO): GPS fix at 20230516T233758: (36.803021, -121.787857)
2023-05-16T23:37:59.606Z,1684280279.606 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:37:59.606Z,1684280279.606 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:38:07.244Z,1684280287.244 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20230516T215751/Courier0046.lzma
2023-05-16T23:38:08.247Z,1684280288.247 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0046.lzma.bak
2023-05-16T23:38:08.247Z,1684280288.247 [DataOverHttps](INFO): SBD MOMSN=18319002
2023-05-16T23:38:23.884Z,1684280303.884 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230516T215751/Express0047.lzma
2023-05-16T23:38:24.887Z,1684280304.887 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0047.lzma.bak
2023-05-16T23:38:24.887Z,1684280304.887 [DataOverHttps](INFO): SBD MOMSN=18319005
2023-05-16T23:38:26.263Z,1684280306.263 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:38:26.263Z,1684280306.263 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:38:26.263Z,1684280306.263 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:38:31.507Z,1684280311.507 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T23:43:26.840Z,1684280606.840 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-16T23:43:26.840Z,1684280606.840 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:43:26.840Z,1684280606.840 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:43:26.840Z,1684280606.840 [Default:CheckIn:D] Running Loop=1
2023-05-16T23:43:27.252Z,1684280607.252 [Default:CheckIn:D] Stopped
2023-05-16T23:43:27.252Z,1684280607.252 [Default:CheckIn:E] Running Loop=1
2023-05-16T23:43:27.671Z,1684280607.671 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.097933 min 
2023-05-16T23:43:27.671Z,1684280607.671 [Default:CheckIn:E] Stopped
2023-05-16T23:43:27.671Z,1684280607.671 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-16T23:43:27.671Z,1684280607.671 [Default:CheckIn] Stopped
2023-05-16T23:43:27.671Z,1684280607.671 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:43:27.672Z,1684280607.672 [Default:CheckIn](INFO): Running loop #15
2023-05-16T23:43:27.672Z,1684280607.672 [Default:CheckIn] Running Loop=15
2023-05-16T23:43:27.672Z,1684280607.672 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-16T23:43:27.672Z,1684280607.672 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-16T23:44:00.362Z,1684280640.362 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-16T23:44:00.445Z,1684280640.445 [NAL9602](ERROR): received: 
+CSQ:0

OK822, 0, 0, 0, 0

OK
2023-05-16T23:44:56.014Z,1684280696.014 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T23:44:56.135Z,1684280696.135 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T23:44:59.039Z,1684280699.039 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T23:45:07.075Z,1684280707.075 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.005387
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.005085
CHAN A3 (5V): -0.004226
CHAN B0 (3.3V): -0.001558
CHAN B1 (3.15aV): -0.001003
CHAN B2 (3.15bV): -0.001312
CHAN B3 (GND): -0.001275
OPEN: 0.004264
Full Scale: +/- 1 mA
2023-05-16T23:45:21.886Z,1684280721.886 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadC3
2023-05-16T23:45:56.366Z,1684280756.366 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T23:45:56.788Z,1684280756.788 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T23:45:59.583Z,1684280759.583 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T23:46:07.668Z,1684280767.668 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.004453
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.005582
CHAN A3 (5V): -0.004105
CHAN B0 (3.3V): -0.001473
CHAN B1 (3.15aV): -0.001141
CHAN B2 (3.15bV): -0.001497
CHAN B3 (GND): -0.000950
OPEN: 0.004309
Full Scale: +/- 1 mA
2023-05-16T23:46:47.938Z,1684280807.938 [CommandExec](IMPORTANT): got command ! echo 0 > /dev/loadC3
2023-05-16T23:47:18.754Z,1684280838.754 [CommandExec](IMPORTANT): got command ! echo 1 > /dev/loadC3
2023-05-16T23:47:28.426Z,1684280848.426 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T23:47:28.450Z,1684280848.450 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T23:47:31.281Z,1684280851.281 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T23:47:39.351Z,1684280859.351 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.812106
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.703407
CHAN A3 (5V): 0.133985
CHAN B0 (3.3V): 0.055182
CHAN B1 (3.15aV): 0.057085
CHAN B2 (3.15bV): 0.057246
CHAN B3 (GND): -0.038241
OPEN: 0.011492
Full Scale: +/- 1 mA
2023-05-16T23:48:09.703Z,1684280889.703 [CommandExec](IMPORTANT): got command ! echo 0 > /dev/loadC3
2023-05-16T23:48:18.038Z,1684280898.038 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T23:48:18.160Z,1684280898.160 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T23:48:20.967Z,1684280900.967 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T23:48:27.817Z,1684280907.817 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-16T23:43:27.7Z
2023-05-16T23:48:27.817Z,1684280907.817 [Default:CheckIn:Read_GPS] Stopped
2023-05-16T23:48:27.817Z,1684280907.817 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-16T23:48:29.064Z,1684280909.064 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.819857
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.725025
CHAN A3 (5V): 0.140797
CHAN B0 (3.3V): 0.058172
CHAN B1 (3.15aV): 0.058683
CHAN B2 (3.15bV): 0.059121
CHAN B3 (GND): -0.036961
OPEN: 0.011200
Full Scale: +/- 1 mA
2023-05-16T23:48:32.250Z,1684280912.250 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-16T23:48:35.020Z,1684280915.020 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230516T215751/Courier0049.lzma
2023-05-16T23:48:36.023Z,1684280916.023 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Courier0049.lzma.bak
2023-05-16T23:48:36.023Z,1684280916.023 [DataOverHttps](INFO): SBD MOMSN=18319056
2023-05-16T23:48:50.773Z,1684280930.773 [DataOverHttps](INFO): Sending 510 bytes from file Logs/20230516T215751/Express0050.lzma
2023-05-16T23:48:51.775Z,1684280931.775 [DataOverHttps](INFO): Moved sent file to Logs/20230516T215751/Express0050.lzma.bak
2023-05-16T23:48:51.775Z,1684280931.775 [DataOverHttps](INFO): SBD MOMSN=18319058
2023-05-16T23:48:53.284Z,1684280933.284 [Default:CheckIn:Read_Iridium] Stopped
2023-05-16T23:48:53.284Z,1684280933.284 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-16T23:48:53.284Z,1684280933.284 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-16T23:48:55.683Z,1684280935.683 [CommandExec](IMPORTANT): got command ! echo i > /dev/loadC4
2023-05-16T23:49:02.952Z,1684280942.952 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-16T23:49:08.942Z,1684280948.942 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T23:49:09.051Z,1684280949.051 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T23:49:11.874Z,1684280951.874 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T23:49:19.961Z,1684280959.961 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.817330
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): 0.736537
CHAN A3 (5V): 0.134996
CHAN B0 (3.3V): 0.052819
CHAN B1 (3.15aV): 0.053250
CHAN B2 (3.15bV): 0.052844
CHAN B3 (GND): -0.033883
OPEN: 0.011033
Full Scale: +/- 1 mA
2023-05-16T23:50:29.278Z,1684281029.278 [CommandExec](IMPORTANT): got command gfscan
2023-05-16T23:50:29.441Z,1684281029.441 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-16T23:50:32.261Z,1684281032.261 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2023-05-16T23:50:40.378Z,1684281040.378 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.005524
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.005603
CHAN A3 (5V): -0.004511
CHAN B0 (3.3V): -0.001242
CHAN B1 (3.15aV): -0.001372
CHAN B2 (3.15bV): -0.001624
CHAN B3 (GND): -0.001546
OPEN: 0.004035
Full Scale: +/- 1 mA
2023-05-16T23:52:47.938Z,1684281167.938 [CommandExec](IMPORTANT): got command restart system
2023-05-16T23:52:49.997Z,1684281169.997 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-05-16T23:52:49.997Z,1684281169.997 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:49.997Z,1684281169.997 [CommandExec](INFO): Uninitializing the command executive.
2023-05-16T23:52:49.998Z,1684281169.998 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-16T23:52:49.998Z,1684281169.998 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.161Z,1684281170.161 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-05-16T23:52:50.161Z,1684281170.161 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-16T23:52:50.161Z,1684281170.161 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.162Z,1684281170.162 [NavChartDb](INFO): Join timeout helper Thread ID is 1075
2023-05-16T23:52:50.181Z,1684281170.181 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:50.181Z,1684281170.181 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.214Z,1684281170.214 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-16T23:52:50.214Z,1684281170.214 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.215Z,1684281170.215 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1076
2023-05-16T23:52:50.601Z,1684281170.601 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:50.601Z,1684281170.601 [WetLabsBB2FL](INFO): Powering down
2023-05-16T23:52:50.602Z,1684281170.602 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.621Z,1684281170.621 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-16T23:52:50.621Z,1684281170.621 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.622Z,1684281170.622 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1077
2023-05-16T23:52:50.725Z,1684281170.725 [CTD_Seabird](INFO): Powering down
2023-05-16T23:52:50.737Z,1684281170.737 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:50.737Z,1684281170.737 [CTD_Seabird](INFO): Powering down
2023-05-16T23:52:50.749Z,1684281170.749 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.753Z,1684281170.753 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-16T23:52:50.753Z,1684281170.753 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:50.753Z,1684281170.753 [Radio_Surface](INFO): Join timeout helper Thread ID is 1078
2023-05-16T23:52:51.033Z,1684281171.033 [Radio_Surface](INFO): Powering down
2023-05-16T23:52:51.034Z,1684281171.034 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:51.034Z,1684281171.034 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:51.049Z,1684281171.049 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-16T23:52:51.049Z,1684281171.049 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:51.049Z,1684281171.049 [Onboard](INFO): Join timeout helper Thread ID is 1079
2023-05-16T23:52:51.977Z,1684281171.977 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-05-16T23:52:52.065Z,1684281172.065 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:52.066Z,1684281172.066 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:52.086Z,1684281172.086 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-16T23:52:52.086Z,1684281172.086 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:52.086Z,1684281172.086 [DataOverHttps](INFO): Join timeout helper Thread ID is 1080
2023-05-16T23:52:52.981Z,1684281172.981 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:52.981Z,1684281172.981 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:52.993Z,1684281172.993 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-16T23:52:52.994Z,1684281172.994 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:52.994Z,1684281172.994 [BackseatComponent](INFO): Join timeout helper Thread ID is 1081
2023-05-16T23:52:53.165Z,1684281173.165 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:53.165Z,1684281173.165 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.186Z,1684281173.186 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-16T23:52:53.186Z,1684281173.186 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.187Z,1684281173.187 [logger](INFO): Join timeout helper Thread ID is 1082
2023-05-16T23:52:53.187Z,1684281173.187 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:53.187Z,1684281173.187 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.188Z,1684281173.188 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-16T23:52:53.188Z,1684281173.188 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.189Z,1684281173.189 [CommandLine](INFO): Join timeout helper Thread ID is 1083
2023-05-16T23:52:53.253Z,1684281173.253 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:53.253Z,1684281173.253 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.269Z,1684281173.269 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-16T23:52:53.270Z,1684281173.270 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.270Z,1684281173.270 [CommandExec](INFO): Join timeout helper Thread ID is 1084
2023-05-16T23:52:53.271Z,1684281173.271 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-16T23:52:53.271Z,1684281173.271 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.272Z,1684281173.272 [controlThread](INFO): Join timeout helper Thread ID is 1085
2023-05-16T23:52:53.621Z,1684281173.621 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-16T23:52:53.621Z,1684281173.621 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-16T23:52:53.622Z,1684281173.622 [AHRS_M2](INFO): Powering down
2023-05-16T23:52:53.694Z,1684281173.694 [NAL9602](INFO): Powering down
2023-05-16T23:52:53.695Z,1684281173.695 [Waterlinked](INFO): Powering down
2023-05-16T23:52:53.697Z,1684281173.697 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-16T23:52:53.698Z,1684281173.698 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-16T23:52:53.699Z,1684281173.699 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-16T23:52:53.699Z,1684281173.699 [MissionManager](INFO): Uninitializing Mission Default
2023-05-16T23:52:53.699Z,1684281173.699 [Default] Stopped
2023-05-16T23:52:53.699Z,1684281173.699 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-16T23:52:53.699Z,1684281173.699 [Default:B.GoToSurface] Stopped
2023-05-16T23:52:53.699Z,1684281173.699 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-16T23:52:53.699Z,1684281173.699 [Default:CheckIn] Stopped
2023-05-16T23:52:53.700Z,1684281173.700 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-16T23:52:53.700Z,1684281173.700 [Default:CheckIn:C.Wait] Stopped
2023-05-16T23:52:53.700Z,1684281173.700 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-16T23:52:53.703Z,1684281173.703 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-16T23:52:53.703Z,1684281173.703 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-16T23:52:53.703Z,1684281173.703 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-16T23:52:53.703Z,1684281173.703 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-16T23:52:53.704Z,1684281173.704 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-16T23:52:53.704Z,1684281173.704 [BuoyancyServo](INFO): Powering down
2023-05-16T23:52:53.717Z,1684281173.717 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-16T23:52:53.717Z,1684281173.717 [ElevatorServo](INFO): Powering down
2023-05-16T23:52:53.718Z,1684281173.718 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-16T23:52:53.718Z,1684281173.718 [MassServo](INFO): Powering down
2023-05-16T23:52:53.719Z,1684281173.719 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-16T23:52:53.719Z,1684281173.719 [RudderServo](INFO): Powering down
2023-05-16T23:52:53.720Z,1684281173.720 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-16T23:52:53.720Z,1684281173.720 [ThrusterHE](INFO): Powering down
2023-05-16T23:52:53.721Z,1684281173.721 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-16T23:52:53.722Z,1684281173.722 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-16T23:52:53.722Z,1684281173.722 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-16T23:52:53.722Z,1684281173.722 [CBIT](DEBUG): Powering off loads.
2023-05-16T23:52:53.733Z,1684281173.733 [CBIT](DEBUG): Disabling WDT.
2023-05-16T23:52:53.745Z,1684281173.745 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-16T23:52:53.746Z,1684281173.746 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.768Z,1684281173.768 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.772Z,1684281173.772 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.778Z,1684281173.778 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.825Z,1684281173.825 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.881Z,1684281173.881 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.885Z,1684281173.885 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.949Z,1684281173.949 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-16T23:52:53.995Z,1684281173.995 [logger ThreadHandler](INFO): Thread cancelled.