2023-08-15T18:51:38.554Z,1692125498.554 [Supervisor](DEBUG): Initializing supervisor.
2023-08-15T18:51:38.558Z,1692125498.558 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-08-15T18:51:38.559Z,1692125498.559 [SyncHandler](INFO): Protected caller Thread ID is 839
2023-08-15T18:51:38.559Z,1692125498.559 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-08-15T18:51:38.560Z,1692125498.560 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-08-15T18:51:38.560Z,1692125498.560 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 840
2023-08-15T18:51:38.564Z,1692125498.564 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-08-15T18:51:38.582Z,1692125498.582 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-08-15T18:51:38.583Z,1692125498.583 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-08-15T18:51:38.583Z,1692125498.583 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 841
2023-08-15T18:51:38.587Z,1692125498.587 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-08-15T18:51:38.588Z,1692125498.588 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-08-15T18:51:38.589Z,1692125498.589 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 842
2023-08-15T18:51:38.591Z,1692125498.591 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-08-15T18:51:38.592Z,1692125498.592 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-08-15T18:51:38.592Z,1692125498.592 [logger ThreadHandler](INFO): Protected caller Thread ID is 843
2023-08-15T18:51:38.596Z,1692125498.596 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-08-15T18:51:38.596Z,1692125498.596 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-08-15T18:51:38.600Z,1692125498.600 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-08-15T18:51:38.698Z,1692125498.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-08-15T18:51:38.699Z,1692125498.699 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-08-15T18:51:39.381Z,1692125499.381 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-08-15T18:51:39.383Z,1692125499.383 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-08-15T18:51:39.604Z,1692125499.604 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-08-15T18:51:39.606Z,1692125499.606 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-08-15T18:51:39.686Z,1692125499.686 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-08-15T18:51:39.815Z,1692125499.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-08-15T18:51:39.817Z,1692125499.817 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-08-15T18:51:39.899Z,1692125499.899 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-08-15T18:51:40.004Z,1692125500.004 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-08-15T18:51:40.005Z,1692125500.005 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-08-15T18:51:40.376Z,1692125500.376 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-08-15T18:51:40.377Z,1692125500.377 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-08-15T18:51:40.849Z,1692125500.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-08-15T18:51:40.850Z,1692125500.850 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-08-15T18:51:41.068Z,1692125501.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-08-15T18:51:41.068Z,1692125501.068 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-08-15T18:51:41.253Z,1692125501.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-08-15T18:51:41.254Z,1692125501.254 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-08-15T18:51:41.758Z,1692125501.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-08-15T18:51:42.280Z,1692125502.280 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-08-15T18:51:42.792Z,1692125502.792 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-08-15T18:51:42.793Z,1692125502.793 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-08-15T18:51:43.010Z,1692125503.010 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-08-15T18:51:43.011Z,1692125503.011 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-08-15T18:51:43.457Z,1692125503.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-08-15T18:51:43.458Z,1692125503.458 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-08-15T18:51:43.909Z,1692125503.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-08-15T18:51:43.911Z,1692125503.911 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2023-08-15T18:51:43.913Z,1692125503.913 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2023-08-15T18:51:44.012Z,1692125504.012 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2023-08-15T18:51:44.176Z,1692125504.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2023-08-15T18:51:44.279Z,1692125504.279 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2023-08-15T18:51:44.366Z,1692125504.366 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2023-08-15T18:51:44.461Z,1692125504.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2023-08-15T18:51:44.574Z,1692125504.574 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2023-08-15T18:51:44.841Z,1692125504.841 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-08-15T18:51:44.842Z,1692125504.842 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2023-08-15T18:51:44.935Z,1692125504.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2023-08-15T18:51:45.033Z,1692125505.033 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2023-08-15T18:51:45.171Z,1692125505.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2023-08-15T18:51:45.269Z,1692125505.269 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2023-08-15T18:51:45.275Z,1692125505.275 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-08-15T18:51:45.404Z,1692125505.404 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-08-15T18:51:45.404Z,1692125505.404 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-08-15T18:51:45.472Z,1692125505.472 [VerticalControl](DEBUG): Construct VerticalControl.
2023-08-15T18:51:45.533Z,1692125505.533 [VerticalControl] Loaded
2023-08-15T18:51:45.533Z,1692125505.533 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-08-15T18:51:45.536Z,1692125505.536 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-08-15T18:51:45.577Z,1692125505.577 [HorizontalControl] Loaded
2023-08-15T18:51:45.578Z,1692125505.578 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-08-15T18:51:45.580Z,1692125505.580 [SpeedControl](DEBUG): Construct SpeedControl.
2023-08-15T18:51:45.583Z,1692125505.583 [SpeedControl] Loaded
2023-08-15T18:51:45.583Z,1692125505.583 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-08-15T18:51:45.586Z,1692125505.586 [LoopControl](DEBUG): Construct LoopControl.
2023-08-15T18:51:45.587Z,1692125505.587 [LoopControl] Loaded
2023-08-15T18:51:45.587Z,1692125505.587 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-08-15T18:51:45.587Z,1692125505.587 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-08-15T18:51:45.588Z,1692125505.588 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-08-15T18:51:45.658Z,1692125505.658 [DepthRateCalculator] Loaded
2023-08-15T18:51:45.658Z,1692125505.658 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-08-15T18:51:45.663Z,1692125505.663 [PitchRateCalculator] Loaded
2023-08-15T18:51:45.663Z,1692125505.663 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-08-15T18:51:45.673Z,1692125505.673 [SpeedCalculator] Loaded
2023-08-15T18:51:45.674Z,1692125505.674 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-08-15T18:51:45.678Z,1692125505.678 [YawRateCalculator] Loaded
2023-08-15T18:51:45.678Z,1692125505.678 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-08-15T18:51:45.696Z,1692125505.696 [ElevatorOffsetCalculator] Loaded
2023-08-15T18:51:45.697Z,1692125505.697 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-08-15T18:51:45.697Z,1692125505.697 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-08-15T18:51:45.698Z,1692125505.698 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-08-15T18:51:45.741Z,1692125505.741 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-08-15T18:51:45.742Z,1692125505.742 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-08-15T18:51:45.824Z,1692125505.824 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-08-15T18:51:45.825Z,1692125505.825 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-08-15T18:51:46.187Z,1692125506.187 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-08-15T18:51:46.187Z,1692125506.187 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-08-15T18:51:46.370Z,1692125506.370 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-08-15T18:51:46.371Z,1692125506.371 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-08-15T18:51:47.140Z,1692125507.140 [AHRS_M2] Loaded
2023-08-15T18:51:47.140Z,1692125507.140 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-08-15T18:51:47.456Z,1692125507.456 [BackseatComponent] Loaded
2023-08-15T18:51:47.456Z,1692125507.456 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-08-15T18:51:47.457Z,1692125507.457 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4098F4E0
2023-08-15T18:51:47.457Z,1692125507.457 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925
2023-08-15T18:51:47.460Z,1692125507.460 [LcmUniversalReporter] Loaded
2023-08-15T18:51:47.460Z,1692125507.460 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-08-15T18:51:48.509Z,1692125508.509 [BPC1] Loaded
2023-08-15T18:51:48.509Z,1692125508.509 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-08-15T18:51:48.652Z,1692125508.652 [DataOverHttps] Loaded
2023-08-15T18:51:48.652Z,1692125508.652 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-08-15T18:51:48.653Z,1692125508.653 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409BF4E0
2023-08-15T18:51:48.653Z,1692125508.653 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926
2023-08-15T18:51:48.674Z,1692125508.674 [Depth_Keller] Loaded
2023-08-15T18:51:48.674Z,1692125508.674 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-08-15T18:51:48.679Z,1692125508.679 [DropWeight] Loaded
2023-08-15T18:51:48.680Z,1692125508.680 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-08-15T18:51:48.743Z,1692125508.743 [NAL9602] Loaded
2023-08-15T18:51:48.743Z,1692125508.743 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-08-15T18:51:48.773Z,1692125508.773 [Onboard] Loaded
2023-08-15T18:51:48.773Z,1692125508.773 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-08-15T18:51:48.774Z,1692125508.774 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409EF4E0
2023-08-15T18:51:48.775Z,1692125508.775 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927
2023-08-15T18:51:48.780Z,1692125508.780 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2023-08-15T18:51:48.792Z,1692125508.792 [PowerOnly] Loaded
2023-08-15T18:51:48.792Z,1692125508.792 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-08-15T18:51:48.804Z,1692125508.804 [Power24vConverter] Loaded
2023-08-15T18:51:48.804Z,1692125508.804 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-08-15T18:51:48.817Z,1692125508.817 [Radio_Surface] Loaded
2023-08-15T18:51:48.817Z,1692125508.817 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-08-15T18:51:48.818Z,1692125508.818 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1F4E0
2023-08-15T18:51:48.819Z,1692125508.819 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928
2023-08-15T18:51:48.864Z,1692125508.864 [RDI_Pathfinder] Loaded
2023-08-15T18:51:48.864Z,1692125508.864 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2023-08-15T18:51:48.957Z,1692125508.957 [DAT] Loaded
2023-08-15T18:51:48.957Z,1692125508.957 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-08-15T18:51:48.958Z,1692125508.958 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2023-08-15T18:51:48.958Z,1692125508.958 [DAT ThreadHandler](INFO): Protected caller Thread ID is 929
2023-08-15T18:51:48.959Z,1692125508.959 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-08-15T18:51:48.960Z,1692125508.960 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-08-15T18:51:49.096Z,1692125509.096 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-08-15T18:51:49.097Z,1692125509.097 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-08-15T18:51:49.110Z,1692125509.110 [NavChart] Loaded
2023-08-15T18:51:49.111Z,1692125509.111 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-08-15T18:51:49.116Z,1692125509.116 [UniversalFixResidualReporter] Loaded
2023-08-15T18:51:49.117Z,1692125509.117 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-08-15T18:51:49.117Z,1692125509.117 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-08-15T18:51:49.119Z,1692125509.119 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-08-15T18:51:49.289Z,1692125509.289 [SBIT](DEBUG): Construct Startup Built In Test.
2023-08-15T18:51:49.298Z,1692125509.298 [SBIT] Loaded
2023-08-15T18:51:49.299Z,1692125509.299 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-08-15T18:51:49.302Z,1692125509.302 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-08-15T18:51:49.314Z,1692125509.314 [IBIT] Loaded
2023-08-15T18:51:49.315Z,1692125509.315 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-08-15T18:51:49.320Z,1692125509.320 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-08-15T18:51:49.427Z,1692125509.427 [CBIT] Loaded
2023-08-15T18:51:49.427Z,1692125509.427 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-08-15T18:51:49.427Z,1692125509.427 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-08-15T18:51:49.428Z,1692125509.428 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-08-15T18:51:49.586Z,1692125509.586 [BuoyancyServo] Loaded
2023-08-15T18:51:49.586Z,1692125509.586 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-08-15T18:51:49.607Z,1692125509.607 [ElevatorServo] Loaded
2023-08-15T18:51:49.607Z,1692125509.607 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-08-15T18:51:49.627Z,1692125509.627 [MassServo] Loaded
2023-08-15T18:51:49.627Z,1692125509.627 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-08-15T18:51:49.646Z,1692125509.646 [RudderServo] Loaded
2023-08-15T18:51:49.646Z,1692125509.646 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-08-15T18:51:49.664Z,1692125509.664 [ThrusterServo] Loaded
2023-08-15T18:51:49.665Z,1692125509.665 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-08-15T18:51:49.665Z,1692125509.665 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-08-15T18:51:49.666Z,1692125509.666 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-08-15T18:51:49.682Z,1692125509.682 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-08-15T18:51:49.682Z,1692125509.682 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-08-15T18:51:49.905Z,1692125509.905 [CTD_Seabird] Loaded
2023-08-15T18:51:49.905Z,1692125509.905 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-08-15T18:51:49.906Z,1692125509.906 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B9A4E0
2023-08-15T18:51:49.907Z,1692125509.907 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 930
2023-08-15T18:51:49.927Z,1692125509.927 [PAR_Licor] Loaded
2023-08-15T18:51:49.927Z,1692125509.927 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-08-15T18:51:49.968Z,1692125509.968 [WetLabsBB2FL] Loaded
2023-08-15T18:51:49.969Z,1692125509.969 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-08-15T18:51:49.970Z,1692125509.970 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BCA4E0
2023-08-15T18:51:49.970Z,1692125509.970 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 931
2023-08-15T18:51:49.990Z,1692125509.990 [WetLabsUBAT] Loaded
2023-08-15T18:51:49.990Z,1692125509.990 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2023-08-15T18:51:49.991Z,1692125509.991 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BFA4E0
2023-08-15T18:51:49.992Z,1692125509.992 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 932
2023-08-15T18:51:49.992Z,1692125509.992 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-08-15T18:51:49.999Z,1692125509.999 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-08-15T18:51:50.002Z,1692125510.002 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-08-15T18:51:50.013Z,1692125510.013 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-08-15T18:51:50.014Z,1692125510.014 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C2A4E0
2023-08-15T18:51:50.014Z,1692125510.014 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 933
2023-08-15T18:51:50.019Z,1692125510.019 [Supervisor](INFO): Main Thread ID is 830
2023-08-15T18:51:50.019Z,1692125510.019 [Supervisor](DEBUG): Running supervisor.
2023-08-15T18:51:50.020Z,1692125510.020 [CommandExec ThreadHandler](INFO): Handler Thread ID is 934
2023-08-15T18:51:50.020Z,1692125510.020 [CommandExec](INFO): Initializing the command executive.
2023-08-15T18:51:50.021Z,1692125510.021 [CommandLine ThreadHandler](INFO): Handler Thread ID is 935
2023-08-15T18:51:50.024Z,1692125510.024 [controlThread ThreadHandler](INFO): Handler Thread ID is 936
2023-08-15T18:51:50.024Z,1692125510.024 [controlThread](DEBUG): Initializing ControlThread
2023-08-15T18:51:50.025Z,1692125510.025 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-08-15T18:51:50.027Z,1692125510.027 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-08-15T18:51:50.027Z,1692125510.027 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-08-15T18:51:50.028Z,1692125510.028 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-08-15T18:51:50.028Z,1692125510.028 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-08-15T18:51:50.029Z,1692125510.029 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-08-15T18:51:50.029Z,1692125510.029 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-08-15T18:51:50.029Z,1692125510.029 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-08-15T18:51:50.029Z,1692125510.029 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-08-15T18:51:50.036Z,1692125510.036 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-08-15T18:51:50.036Z,1692125510.036 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-08-15T18:51:50.036Z,1692125510.036 [SBIT](INFO): Initialize SBIT Component.
2023-08-15T18:51:50.037Z,1692125510.037 [SBIT](IMPORTANT): git: 2023-08-02-8-ga2b2183f7
2023-08-15T18:51:50.037Z,1692125510.037 [SBIT](INFO): git hash: a2b2183f71e07b707bfeaaf571c74c3561721119
2023-08-15T18:51:50.037Z,1692125510.037 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-08-15T18:51:50.038Z,1692125510.038 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-08-15T18:51:50.039Z,1692125510.039 [SBIT](INFO): Beginning SBIT in 49.000000 seconds.
2023-08-15T18:51:50.040Z,1692125510.040 [IBIT](INFO): Initialize IBIT Component.
2023-08-15T18:51:50.041Z,1692125510.041 [CBIT](DEBUG): Initialize CBIT Component.
2023-08-15T18:51:50.042Z,1692125510.042 [logger ThreadHandler](INFO): Handler Thread ID is 937
2023-08-15T18:51:50.053Z,1692125510.053 [CBIT](DEBUG): Initialized mux pins.
2023-08-15T18:51:50.053Z,1692125510.053 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2023-08-15T18:51:50.053Z,1692125510.053 [CBIT](DEBUG): Initializing the watchdog timer.
2023-08-15T18:51:50.061Z,1692125510.061 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 938
2023-08-15T18:51:50.073Z,1692125510.073 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 939
2023-08-15T18:51:50.074Z,1692125510.074 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-08-15T18:51:50.077Z,1692125510.077 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2023-08-15T18:51:50.077Z,1692125510.077 [CBIT](DEBUG): Initializing heartbeat.
2023-08-15T18:51:50.085Z,1692125510.085 [Onboard ThreadHandler](INFO): Handler Thread ID is 940
2023-08-15T18:51:50.103Z,1692125510.103 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 941
2023-08-15T18:51:50.125Z,1692125510.125 [DAT ThreadHandler](INFO): Handler Thread ID is 942
2023-08-15T18:51:50.126Z,1692125510.126 [DAT](INFO): Powering up
2023-08-15T18:51:50.126Z,1692125510.126 [DAT](DEBUG): Initializing DAT.
2023-08-15T18:51:50.130Z,1692125510.130 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 944
2023-08-15T18:51:50.131Z,1692125510.131 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-08-15T18:51:50.134Z,1692125510.134 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 946
2023-08-15T18:51:50.137Z,1692125510.137 [WetLabsBB2FL](INFO): Powering up
2023-08-15T18:51:50.139Z,1692125510.139 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 948
2023-08-15T18:51:50.142Z,1692125510.142 [WetLabsUBAT](INFO): Powering up
2023-08-15T18:51:50.143Z,1692125510.143 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 950
2023-08-15T18:51:50.149Z,1692125510.149 [CBIT](DEBUG): Deactivating GF circuits.
2023-08-15T18:51:50.149Z,1692125510.149 [CBIT](DEBUG): Deactivating emergency mode.
2023-08-15T18:51:50.152Z,1692125510.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-08-15T18:51:50.152Z,1692125510.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-08-15T18:51:50.152Z,1692125510.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-08-15T18:51:50.152Z,1692125510.152 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-08-15T18:51:50.152Z,1692125510.152 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-08-15T18:51:50.153Z,1692125510.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-08-15T18:51:50.153Z,1692125510.153 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-08-15T18:51:50.153Z,1692125510.153 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-08-15T18:51:50.189Z,1692125510.189 [CBIT](DEBUG): Backplane powered.
2023-08-15T18:51:50.194Z,1692125510.194 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-08-15T18:51:50.234Z,1692125510.234 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-08-15T18:51:50.266Z,1692125510.266 [MissionManager](DEBUG):
2023-08-15T18:51:50.266Z,1692125510.266 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-08-15T18:51:50.345Z,1692125510.345 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-08-15T18:51:50.347Z,1692125510.347 [Default:A.Wait](DEBUG): Construct Wait.
2023-08-15T18:51:50.361Z,1692125510.361 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-08-15T18:51:50.396Z,1692125510.396 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-08-15T18:51:50.399Z,1692125510.399 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-08-15T18:51:50.423Z,1692125510.423 [Default:E.Execute](DEBUG): Construct Execute.
2023-08-15T18:51:50.427Z,1692125510.427 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2023-08-15T18:51:50.445Z,1692125510.445 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-08-15T18:51:50.451Z,1692125510.451 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-08-15T18:51:50.509Z,1692125510.509 [Radio_Surface](INFO): Powering up
2023-08-15T18:51:50.651Z,1692125510.651 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m
2023-08-15T18:51:50.653Z,1692125510.653 [PowerOnly](INFO): Powering up loadControl
2023-08-15T18:51:50.669Z,1692125510.669 [Power24vConverter](INFO): Powering up.
2023-08-15T18:51:50.670Z,1692125510.670 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2023-08-15T18:51:50.691Z,1692125510.691 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-08-15T18:51:50.722Z,1692125510.722 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-08-15T18:51:50.729Z,1692125510.729 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-08-15T18:51:50.730Z,1692125510.730 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-08-15T18:51:50.737Z,1692125510.737 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-08-15T18:51:50.738Z,1692125510.738 [MassServo](DEBUG): Initializing EZServoServo.
2023-08-15T18:51:50.746Z,1692125510.746 [MassServo](DEBUG): Initializing MassServo.
2023-08-15T18:51:50.746Z,1692125510.746 [RudderServo](DEBUG): Initializing EZServoServo.
2023-08-15T18:51:50.753Z,1692125510.753 [RudderServo](DEBUG): Initializing RudderServo.
2023-08-15T18:51:50.754Z,1692125510.754 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-08-15T18:51:50.761Z,1692125510.761 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-08-15T18:51:50.763Z,1692125510.763 [CommandExec](FAULT): Scheduling is paused
2023-08-15T18:51:50.764Z,1692125510.764 [CBIT](INFO): Critical error at 20230815T185150
2023-08-15T18:51:50.764Z,1692125510.764 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2023-08-15T18:51:52.749Z,1692125512.749 [WetLabsBB2FL](INFO): Powering down
2023-08-15T18:51:58.737Z,1692125518.737 [MassServo](ERROR): getPosition uart error serial timeout
2023-08-15T18:51:58.737Z,1692125518.737 [MassServo](FAULT): Invalid EZ Servo response:""
2023-08-15T18:51:58.738Z,1692125518.738 [MassServo] Communications Fault, FailCount= 1
2023-08-15T18:51:58.738Z,1692125518.738 [MassServo](ERROR): Communications Fault
2023-08-15T18:51:58.742Z,1692125518.742 [CBIT](ERROR): Communications Fault in component: MassServo
2023-08-15T18:51:59.047Z,1692125519.047 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-08-15T18:51:59.047Z,1692125519.047 [MassServo](INFO): Powering down
2023-08-15T18:51:59.449Z,1692125519.449 [WetLabsUBAT](INFO): Powering down
2023-08-15T18:51:59.803Z,1692125519.803 [MassServo](DEBUG): Initializing EZServoServo.
2023-08-15T18:51:59.922Z,1692125519.922 [MassServo](DEBUG): Initializing MassServo.
2023-08-15T18:51:59.927Z,1692125519.927 [CBIT](INFO): Clearing failed state for component MassServo
2023-08-15T18:51:59.927Z,1692125519.927 [MassServo] No Fault, FailCount= 1
2023-08-15T18:52:02.977Z,1692125522.977 [DAT](INFO): DAT read:
2023-08-15T18:52:02.979Z,1692125522.979 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series
2023-08-15T18:52:04.742Z,1692125524.742 [DAT](INFO): DAT read: MF Frequency Band
2023-08-15T18:52:04.743Z,1692125524.743 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2023-08-15T18:52:04.744Z,1692125524.744 [DAT](INFO): DAT read: Aug 15 2023 18:52:00
2023-08-15T18:52:05.750Z,1692125525.750 [DAT](INFO): DAT read: Features enabled [Bearing]
2023-08-15T18:52:05.751Z,1692125525.751 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2023-08-15T18:52:05.751Z,1692125525.751 [DAT](INFO): commRate: 800
2023-08-15T18:52:07.817Z,1692125527.817 [DAT](INFO): entering command mode
2023-08-15T18:52:08.017Z,1692125528.017 [DAT](INFO): DAT read:
2023-08-15T18:52:08.018Z,1692125528.018 [DAT](INFO): DAT read: user:1>
2023-08-15T18:52:08.018Z,1692125528.018 [DAT](INFO): setting verbose to 3
2023-08-15T18:52:08.271Z,1692125528.271 [DAT](INFO): DAT read: user:1>
2023-08-15T18:52:08.274Z,1692125528.274 [DAT](INFO): DAT read: Verbose | 3
2023-08-15T18:52:08.275Z,1692125528.275 [DAT](INFO): set verbose to 3
2023-08-15T18:52:08.275Z,1692125528.275 [DAT](INFO): setting DatVerbose to 27440
2023-08-15T18:52:08.522Z,1692125528.522 [DAT](INFO): DAT read: user:2>
2023-08-15T18:52:08.523Z,1692125528.523 [DAT](INFO): DAT read: DatVerbose | 27440
2023-08-15T18:52:08.523Z,1692125528.523 [DAT](INFO): set DatVerbose to 27440
2023-08-15T18:52:08.523Z,1692125528.523 [DAT](INFO): setting transmit power to 8
2023-08-15T18:52:08.774Z,1692125528.774 [DAT](INFO): DAT read: user:3>
2023-08-15T18:52:08.775Z,1692125528.775 [DAT](INFO): DAT read: TxPower | 8 (Max)
2023-08-15T18:52:08.776Z,1692125528.776 [DAT](INFO): set transmit power to 8
2023-08-15T18:52:08.776Z,1692125528.776 [DAT](INFO): setting local address to 10
2023-08-15T18:52:09.026Z,1692125529.026 [DAT](INFO): DAT read: user:4>
2023-08-15T18:52:09.027Z,1692125529.027 [DAT](INFO): DAT read: LocalAddr | 10
2023-08-15T18:52:09.027Z,1692125529.027 [DAT](INFO): set local address to 10
2023-08-15T18:52:09.028Z,1692125529.028 [DAT](INFO): Setting time to: 18:52:9 And date to:8/15/2023
2023-08-15T18:52:09.278Z,1692125529.278 [DAT](INFO): DAT read: user:5>
2023-08-15T18:52:09.279Z,1692125529.279 [DAT](INFO): DAT read: Tue Aug 15, 2023 18:52:09
2023-08-15T18:52:09.279Z,1692125529.279 [DAT](INFO): Local DAT time set to Tue Aug 15, 2023 18:52:09
2023-08-15T18:52:18.751Z,1692125538.751 [NAL9602](INFO): Powering up NAL9602
2023-08-15T18:52:29.651Z,1692125549.651 [NAL9602](INFO): NAL9602 initialized
2023-08-15T18:52:39.791Z,1692125559.791 [SBIT](IMPORTANT): Beginning Startup BIT
2023-08-15T18:52:39.796Z,1692125559.796 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-15T18:52:44.596Z,1692125564.596 [NAL9602](INFO): SBD MO Status=0, MOMSN=30481, MT Status=0, MTMSN=0
2023-08-15T18:52:44.596Z,1692125564.596 [NAL9602](INFO): No messages in MT queue
2023-08-15T18:52:51.150Z,1692125571.150 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.042219
CHAN A1 (24V): 0.128179
CHAN A2 (12V): 0.035096
CHAN A3 (5V): 0.011775
CHAN B0 (3.3V): 0.008862
CHAN B1 (3.15aV): 0.007949
CHAN B2 (3.15bV): 0.008459
CHAN B3 (GND): -0.001896
OPEN: 0.008516
Full Scale: +/- 1 mA
2023-08-15T18:53:03.987Z,1692125583.987 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185200.00,A,3648.31717,N,12148.45677,W,23.501,88.79,150823,,,A*77
2023-08-15T18:53:03.990Z,1692125583.990 [NAL9602](INFO): GPS fix at 20230815T185200: (36.805286, -121.807613)
2023-08-15T18:53:33.908Z,1692125613.908 [SBIT](IMPORTANT): SBIT PASSED
2023-08-15T18:53:33.908Z,1692125613.908 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2023-08-15T18:53:34.346Z,1692125614.346 [MissionManager](IMPORTANT): Started mission Startup
2023-08-15T18:53:34.346Z,1692125614.346 [Startup] Running Loop=1
2023-08-15T18:53:34.346Z,1692125614.346 [Startup](DEBUG): Aggregate::initialize Startup
2023-08-15T18:53:34.347Z,1692125614.347 [Startup:A.GoToSurface] Running Loop=1
2023-08-15T18:53:34.347Z,1692125614.347 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-08-15T18:53:34.347Z,1692125614.347 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-08-15T18:53:34.348Z,1692125614.348 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-08-15T18:53:34.348Z,1692125614.348 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-08-15T18:53:34.348Z,1692125614.348 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-08-15T18:53:34.349Z,1692125614.349 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-08-15T18:53:34.350Z,1692125614.350 [Startup:StartupSatComms] Running Loop=1
2023-08-15T18:53:34.350Z,1692125614.350 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-08-15T18:53:34.350Z,1692125614.350 [Startup:StartupSatComms:A] Running Loop=1
2023-08-15T18:53:34.706Z,1692125614.706 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-08-15T18:53:36.321Z,1692125616.321 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185232.00,A,3648.30598,N,12148.17265,W,25.989,94.70,150823,,,D*79
2023-08-15T18:53:36.323Z,1692125616.323 [NAL9602](INFO): GPS fix at 20230815T185232: (36.805100, -121.802877)
2023-08-15T18:53:36.379Z,1692125616.379 [Startup:StartupSatComms:A] Stopped
2023-08-15T18:53:36.379Z,1692125616.379 [Startup:StartupSatComms:B] Running Loop=1
2023-08-15T18:53:36.757Z,1692125616.757 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-08-15T18:53:54.204Z,1692125634.204 [NAL9602](INFO): SBD MO Status=1, MOMSN=30482, MT Status=0, MTMSN=0
2023-08-15T18:53:54.461Z,1692125634.461 [NAL9602](INFO): Sent 18 bytes from file Logs/20230815T184707/Courier0006.lzma
2023-08-15T18:53:54.461Z,1692125634.461 [NAL9602](INFO): Packets left to send: 0
2023-08-15T18:54:04.428Z,1692125644.428 [NAL9602](INFO): SBD MO Status=1, MOMSN=30483, MT Status=0, MTMSN=0
2023-08-15T18:54:04.485Z,1692125644.485 [NAL9602](INFO): Sent 330 bytes from file Logs/20230815T185138/Courier0000.lzma
2023-08-15T18:54:04.485Z,1692125644.485 [NAL9602](INFO): Packets left to send: 0
2023-08-15T18:54:21.983Z,1692125661.983 [NAL9602](INFO): SBD MO Status=2, MOMSN=30484, MT Status=2, MTMSN=0
2023-08-15T18:54:21.983Z,1692125661.983 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-15T18:54:36.564Z,1692125676.564 [Startup:StartupSatComms:B](INFO): Timed out from 2023-08-15T18:53:36.4Z
2023-08-15T18:54:36.564Z,1692125676.564 [Startup:StartupSatComms:B] Stopped
2023-08-15T18:54:36.564Z,1692125676.564 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-08-15T18:54:36.564Z,1692125676.564 [Startup:StartupSatComms] Stopped
2023-08-15T18:54:36.564Z,1692125676.564 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-08-15T18:54:36.565Z,1692125676.565 [Startup](INFO): Completed Startup
2023-08-15T18:54:36.565Z,1692125676.565 [MissionManager](INFO): Startup is completed.
2023-08-15T18:54:36.565Z,1692125676.565 [MissionManager](INFO): Uninitializing Mission Startup
2023-08-15T18:54:36.565Z,1692125676.565 [Startup] Stopped
2023-08-15T18:54:36.566Z,1692125676.566 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-08-15T18:54:36.566Z,1692125676.566 [Startup:A.GoToSurface] Stopped
2023-08-15T18:54:36.566Z,1692125676.566 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-08-15T18:54:36.957Z,1692125676.957 [MissionManager](IMPORTANT): Started mission Default
2023-08-15T18:54:36.957Z,1692125676.957 [Default] Running Loop=1
2023-08-15T18:54:36.958Z,1692125676.958 [Default](DEBUG): Aggregate::initialize Default
2023-08-15T18:54:36.958Z,1692125676.958 [Default:B.GoToSurface] Running Loop=1
2023-08-15T18:54:36.958Z,1692125676.958 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-08-15T18:54:36.958Z,1692125676.958 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-08-15T18:54:36.958Z,1692125676.958 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-08-15T18:54:36.959Z,1692125676.959 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-08-15T18:54:36.959Z,1692125676.959 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-08-15T18:54:36.959Z,1692125676.959 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-08-15T18:54:36.959Z,1692125676.959 [Default:A.Wait] Running Loop=1
2023-08-15T18:54:36.959Z,1692125676.959 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-08-15T18:54:50.347Z,1692125690.347 [Default:A.Wait](INFO): Done Waiting.
2023-08-15T18:54:50.347Z,1692125690.347 [Default:A.Wait] Stopped
2023-08-15T18:54:50.347Z,1692125690.347 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T18:54:50.690Z,1692125690.690 [Default:CheckIn] Running Loop=1
2023-08-15T18:54:50.690Z,1692125690.690 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T18:54:50.690Z,1692125690.690 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T18:54:51.094Z,1692125691.094 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-08-15T18:54:52.688Z,1692125692.688 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185348.00,A,3648.35219,N,12147.49084,W,25.834,54.45,150823,,,D*7A
2023-08-15T18:54:52.690Z,1692125692.690 [NAL9602](INFO): GPS fix at 20230815T185348: (36.805870, -121.791514)
2023-08-15T18:54:52.723Z,1692125692.723 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T18:54:52.723Z,1692125692.723 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T18:54:53.133Z,1692125693.133 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-08-15T18:55:11.547Z,1692125711.547 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004521
2023-08-15T18:55:19.044Z,1692125719.044 [NAL9602](INFO): SBD MO Status=1, MOMSN=30484, MT Status=0, MTMSN=0
2023-08-15T18:55:19.097Z,1692125719.097 [NAL9602](INFO): Sent 72 bytes from file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:55:19.097Z,1692125719.097 [NAL9602](INFO): Packets left to send: 0
2023-08-15T18:55:19.146Z,1692125719.146 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T18:55:19.147Z,1692125719.147 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T18:55:19.147Z,1692125719.147 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T18:55:19.427Z,1692125719.427 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:55:19.427Z,1692125719.427 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:55:28.371Z,1692125728.371 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:55:28.371Z,1692125728.371 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:55:49.747Z,1692125749.747 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T18:56:03.327Z,1692125763.327 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:56:03.327Z,1692125763.327 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:56:39.328Z,1692125799.328 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:56:39.329Z,1692125799.329 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:57:14.215Z,1692125834.215 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:57:14.215Z,1692125834.215 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:57:49.927Z,1692125869.927 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:57:49.927Z,1692125869.927 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:58:25.759Z,1692125905.759 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:58:25.759Z,1692125905.759 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:59:01.787Z,1692125941.787 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:59:01.787Z,1692125941.787 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:59:36.603Z,1692125976.603 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:59:36.603Z,1692125976.603 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T18:59:57.896Z,1692125997.896 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2023-08-15T19:00:04.714Z,1692126004.714 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-08-15T19:00:04.718Z,1692126004.718 [BPC1](CRITICAL): Battery Capacity Below Threshold. 40.049000 Ah.
2023-08-15T19:00:04.718Z,1692126004.718 [BPC1](CRITICAL): Battery Voltage Below Threshold. 13.455964 V.
2023-08-15T19:00:04.718Z,1692126004.718 [BPC1](INFO): Received data from all battery sticks.
2023-08-15T19:00:04.739Z,1692126004.739 [CBIT](INFO): Critical error at 20230815T190004
2023-08-15T19:00:12.402Z,1692126012.402 [DataOverHttps](IMPORTANT): Could not stat file Logs/20230815T185138/Courier0004.lzma
2023-08-15T19:00:12.403Z,1692126012.403 [DataOverHttps](FAULT): Could not open file Logs/20230815T185138/Courier0004.lzma
2023-08-15T19:00:19.686Z,1692126019.686 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:00:19.686Z,1692126019.686 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:00:19.686Z,1692126019.686 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:00:19.686Z,1692126019.686 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:00:20.094Z,1692126020.094 [Default:CheckIn:D] Stopped
2023-08-15T19:00:20.094Z,1692126020.094 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:00:20.537Z,1692126020.537 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.718938 min
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn:E] Stopped
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn] Stopped
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn](INFO): Running loop #2
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn] Running Loop=2
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:00:20.538Z,1692126020.538 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:00:22.486Z,1692126022.486 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,185918.00,A,3648.26400,N,12147.14469,W,4.199,188.28,150823,,,D*70
2023-08-15T19:00:22.488Z,1692126022.488 [NAL9602](INFO): GPS fix at 20230815T185918: (36.804400, -121.785745)
2023-08-15T19:00:22.519Z,1692126022.519 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:00:22.519Z,1692126022.519 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:00:30.308Z,1692126030.308 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20230815T185138/Courier0007.lzma
2023-08-15T19:00:31.307Z,1692126031.307 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0007.lzma.bak
2023-08-15T19:00:31.307Z,1692126031.307 [DataOverHttps](INFO): SBD MOMSN=18562362
2023-08-15T19:00:47.664Z,1692126047.664 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20230815T141500/Express0043.lzma
2023-08-15T19:00:48.348Z,1692126048.348 [NAL9602](INFO): SBD MO Status=0, MOMSN=30485, MT Status=0, MTMSN=0
2023-08-15T19:00:48.348Z,1692126048.348 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:00:48.667Z,1692126048.667 [DataOverHttps](INFO): Moved sent file to Logs/20230815T141500/Express0043.lzma.bak
2023-08-15T19:00:48.667Z,1692126048.667 [DataOverHttps](INFO): SBD MOMSN=18562371
2023-08-15T19:01:05.570Z,1692126065.570 [DataOverHttps](INFO): Sending 323 bytes from file Logs/20230815T184707/Express0001.lzma
2023-08-15T19:01:06.571Z,1692126066.571 [DataOverHttps](INFO): Moved sent file to Logs/20230815T184707/Express0001.lzma.bak
2023-08-15T19:01:06.571Z,1692126066.571 [DataOverHttps](INFO): SBD MOMSN=18562374
2023-08-15T19:01:19.042Z,1692126079.042 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:01:22.962Z,1692126082.962 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230815T184707/Express0004.lzma
2023-08-15T19:01:23.963Z,1692126083.963 [DataOverHttps](INFO): Moved sent file to Logs/20230815T184707/Express0004.lzma.bak
2023-08-15T19:01:23.963Z,1692126083.963 [DataOverHttps](INFO): SBD MOMSN=18562378
2023-08-15T19:01:40.532Z,1692126100.532 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230815T184707/Express0007.lzma
2023-08-15T19:01:41.535Z,1692126101.535 [DataOverHttps](INFO): Moved sent file to Logs/20230815T184707/Express0007.lzma.bak
2023-08-15T19:01:41.535Z,1692126101.535 [DataOverHttps](INFO): SBD MOMSN=18562380
2023-08-15T19:01:57.978Z,1692126117.978 [DataOverHttps](INFO): Sending 776 bytes from file Logs/20230815T185138/Express0001.lzma
2023-08-15T19:01:58.979Z,1692126118.979 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0001.lzma.bak
2023-08-15T19:01:58.979Z,1692126118.979 [DataOverHttps](INFO): SBD MOMSN=18562382
2023-08-15T19:02:15.162Z,1692126135.162 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20230815T185138/Express0005.lzma
2023-08-15T19:02:16.163Z,1692126136.163 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0005.lzma.bak
2023-08-15T19:02:16.163Z,1692126136.163 [DataOverHttps](INFO): SBD MOMSN=18562397
2023-08-15T19:02:32.453Z,1692126152.453 [DataOverHttps](INFO): Sending 323 bytes from file Logs/20230815T185138/Express0008.lzma
2023-08-15T19:02:33.455Z,1692126153.455 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0008.lzma.bak
2023-08-15T19:02:33.455Z,1692126153.455 [DataOverHttps](INFO): SBD MOMSN=18562400
2023-08-15T19:02:35.024Z,1692126155.024 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:02:35.024Z,1692126155.024 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:02:35.024Z,1692126155.024 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:07:35.591Z,1692126455.591 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:07:35.591Z,1692126455.591 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:07:35.591Z,1692126455.591 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:07:35.591Z,1692126455.591 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:07:36.005Z,1692126456.005 [Default:CheckIn:D] Stopped
2023-08-15T19:07:36.005Z,1692126456.005 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:07:36.429Z,1692126456.429 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.983854 min
2023-08-15T19:07:36.429Z,1692126456.429 [Default:CheckIn:E] Stopped
2023-08-15T19:07:36.429Z,1692126456.429 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:07:36.429Z,1692126456.429 [Default:CheckIn] Stopped
2023-08-15T19:07:36.429Z,1692126456.429 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:07:36.430Z,1692126456.430 [Default:CheckIn](INFO): Running loop #3
2023-08-15T19:07:36.430Z,1692126456.430 [Default:CheckIn] Running Loop=3
2023-08-15T19:07:36.430Z,1692126456.430 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:07:36.430Z,1692126456.430 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:07:38.402Z,1692126458.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190635.00,A,3648.14927,N,12147.22241,W,0.019,223.57,150823,,,D*73
2023-08-15T19:07:38.404Z,1692126458.404 [NAL9602](INFO): GPS fix at 20230815T190635: (36.802488, -121.787040)
2023-08-15T19:07:38.437Z,1692126458.437 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:07:38.437Z,1692126458.437 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:07:45.736Z,1692126465.736 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0010.lzma
2023-08-15T19:07:46.740Z,1692126466.740 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0010.lzma.bak
2023-08-15T19:07:46.740Z,1692126466.740 [DataOverHttps](INFO): SBD MOMSN=18562432
2023-08-15T19:07:48.505Z,1692126468.505 [NAL9602](INFO): SBD MO Status=0, MOMSN=30486, MT Status=0, MTMSN=0
2023-08-15T19:07:48.505Z,1692126468.505 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:08:03.036Z,1692126483.036 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230815T185138/Express0011.lzma
2023-08-15T19:08:04.039Z,1692126484.039 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0011.lzma.bak
2023-08-15T19:08:04.039Z,1692126484.039 [DataOverHttps](INFO): SBD MOMSN=18562435
2023-08-15T19:08:05.498Z,1692126485.498 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:08:05.498Z,1692126485.498 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:08:05.498Z,1692126485.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:08:19.212Z,1692126499.212 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:11:26.340Z,1692126686.340 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD,7
2023-08-15T19:13:06.051Z,1692126786.051 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:13:06.051Z,1692126786.051 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:13:06.052Z,1692126786.052 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:13:06.052Z,1692126786.052 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:13:06.497Z,1692126786.497 [Default:CheckIn:D] Stopped
2023-08-15T19:13:06.497Z,1692126786.497 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:13:06.862Z,1692126786.862 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.492330 min
2023-08-15T19:13:06.862Z,1692126786.862 [Default:CheckIn:E] Stopped
2023-08-15T19:13:06.862Z,1692126786.862 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:13:06.862Z,1692126786.862 [Default:CheckIn] Stopped
2023-08-15T19:13:06.862Z,1692126786.862 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:13:06.862Z,1692126786.862 [Default:CheckIn](INFO): Running loop #4
2023-08-15T19:13:06.862Z,1692126786.862 [Default:CheckIn] Running Loop=4
2023-08-15T19:13:06.863Z,1692126786.863 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:13:06.863Z,1692126786.863 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:13:08.872Z,1692126788.872 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191206.00,A,3648.14892,N,12147.22358,W,1.283,223.57,150823,,,A*75
2023-08-15T19:13:08.874Z,1692126788.874 [NAL9602](INFO): GPS fix at 20230815T191206: (36.802482, -121.787060)
2023-08-15T19:13:08.908Z,1692126788.908 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:13:08.908Z,1692126788.908 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:13:16.468Z,1692126796.468 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0013.lzma
2023-08-15T19:13:17.471Z,1692126797.471 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0013.lzma.bak
2023-08-15T19:13:17.471Z,1692126797.471 [DataOverHttps](INFO): SBD MOMSN=18562447
2023-08-15T19:13:23.019Z,1692126803.019 [NAL9602](INFO): SBD MO Status=0, MOMSN=30487, MT Status=0, MTMSN=0
2023-08-15T19:13:23.020Z,1692126803.020 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:13:33.844Z,1692126813.844 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230815T185138/Express0014.lzma
2023-08-15T19:13:34.847Z,1692126814.847 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0014.lzma.bak
2023-08-15T19:13:34.847Z,1692126814.847 [DataOverHttps](INFO): SBD MOMSN=18562450
2023-08-15T19:13:36.389Z,1692126816.389 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:13:36.389Z,1692126816.389 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:13:36.389Z,1692126816.389 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:13:53.729Z,1692126833.729 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:14:16.359Z,1692126856.359 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,23081511141078,35.0, +18.0, 0.0,1515
2023-08-15T19:18:36.952Z,1692127116.952 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:18:36.952Z,1692127116.952 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:18:36.953Z,1692127116.953 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:18:36.953Z,1692127116.953 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:18:37.350Z,1692127117.350 [Default:CheckIn:D] Stopped
2023-08-15T19:18:37.350Z,1692127117.350 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:18:37.765Z,1692127117.765 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.006547 min
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn:E] Stopped
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn] Stopped
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn](INFO): Running loop #5
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn] Running Loop=5
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:18:37.766Z,1692127117.766 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:18:39.764Z,1692127119.764 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,191737.00,A,3648.13969,N,12147.23364,W,1.147,264.30,150823,,,A*77
2023-08-15T19:18:39.766Z,1692127119.766 [NAL9602](INFO): GPS fix at 20230815T191737: (36.802328, -121.787227)
2023-08-15T19:18:39.810Z,1692127119.810 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:18:39.810Z,1692127119.810 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:18:47.380Z,1692127127.380 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0016.lzma
2023-08-15T19:18:48.383Z,1692127128.383 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0016.lzma.bak
2023-08-15T19:18:48.383Z,1692127128.383 [DataOverHttps](INFO): SBD MOMSN=18562461
2023-08-15T19:19:03.599Z,1692127143.599 [NAL9602](INFO): SBD MO Status=0, MOMSN=30488, MT Status=0, MTMSN=0
2023-08-15T19:19:03.600Z,1692127143.600 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:19:04.764Z,1692127144.764 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230815T185138/Express0017.lzma
2023-08-15T19:19:05.767Z,1692127145.767 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0017.lzma.bak
2023-08-15T19:19:05.767Z,1692127145.767 [DataOverHttps](INFO): SBD MOMSN=18562464
2023-08-15T19:19:07.258Z,1692127147.258 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:19:07.258Z,1692127147.258 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:19:07.258Z,1692127147.258 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:19:34.314Z,1692127174.314 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:24:07.829Z,1692127447.829 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:24:07.829Z,1692127447.829 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:24:07.829Z,1692127447.829 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:24:07.829Z,1692127447.829 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:24:08.294Z,1692127448.294 [Default:CheckIn:D] Stopped
2023-08-15T19:24:08.294Z,1692127448.294 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.522270 min
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn:E] Stopped
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn] Stopped
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn](INFO): Running loop #6
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn] Running Loop=6
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:24:08.667Z,1692127448.667 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:24:10.648Z,1692127450.648 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192307.00,A,3648.17791,N,12147.28134,W,0.350,243.32,150823,,,D*75
2023-08-15T19:24:10.650Z,1692127450.650 [NAL9602](INFO): GPS fix at 20230815T192307: (36.802965, -121.788022)
2023-08-15T19:24:10.683Z,1692127450.683 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:24:10.683Z,1692127450.683 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:24:18.620Z,1692127458.620 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0019.lzma
2023-08-15T19:24:19.623Z,1692127459.623 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0019.lzma.bak
2023-08-15T19:24:19.623Z,1692127459.623 [DataOverHttps](INFO): SBD MOMSN=18562475
2023-08-15T19:24:24.783Z,1692127464.783 [NAL9602](INFO): SBD MO Status=0, MOMSN=30489, MT Status=0, MTMSN=0
2023-08-15T19:24:24.783Z,1692127464.783 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:24:35.948Z,1692127475.948 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230815T185138/Express0020.lzma
2023-08-15T19:24:36.951Z,1692127476.951 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0020.lzma.bak
2023-08-15T19:24:36.951Z,1692127476.951 [DataOverHttps](INFO): SBD MOMSN=18562478
2023-08-15T19:24:38.583Z,1692127478.583 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:24:38.583Z,1692127478.583 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:24:38.584Z,1692127478.584 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:24:55.481Z,1692127495.481 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:29:39.123Z,1692127779.123 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:29:39.124Z,1692127779.124 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:29:39.124Z,1692127779.124 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:29:39.124Z,1692127779.124 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:29:39.530Z,1692127779.530 [Default:CheckIn:D] Stopped
2023-08-15T19:29:39.530Z,1692127779.530 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:29:39.922Z,1692127779.922 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 35.042875 min
2023-08-15T19:29:39.922Z,1692127779.922 [Default:CheckIn:E] Stopped
2023-08-15T19:29:39.922Z,1692127779.922 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:29:39.922Z,1692127779.922 [Default:CheckIn] Stopped
2023-08-15T19:29:39.922Z,1692127779.922 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:29:39.922Z,1692127779.922 [Default:CheckIn](INFO): Running loop #7
2023-08-15T19:29:39.922Z,1692127779.922 [Default:CheckIn] Running Loop=7
2023-08-15T19:29:39.923Z,1692127779.923 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:29:39.923Z,1692127779.923 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:29:41.927Z,1692127781.927 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192839.00,A,3648.17531,N,12147.27646,W,0.272,213.72,150823,,,D*76
2023-08-15T19:29:41.929Z,1692127781.929 [NAL9602](INFO): GPS fix at 20230815T192839: (36.802922, -121.787941)
2023-08-15T19:29:41.941Z,1692127781.941 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:29:41.941Z,1692127781.941 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:29:50.004Z,1692127790.004 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0022.lzma
2023-08-15T19:29:51.007Z,1692127791.007 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0022.lzma.bak
2023-08-15T19:29:51.007Z,1692127791.007 [DataOverHttps](INFO): SBD MOMSN=18562492
2023-08-15T19:30:07.356Z,1692127807.356 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230815T185138/Express0023.lzma
2023-08-15T19:30:08.359Z,1692127808.359 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0023.lzma.bak
2023-08-15T19:30:08.359Z,1692127808.359 [DataOverHttps](INFO): SBD MOMSN=18562495
2023-08-15T19:30:09.815Z,1692127809.815 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:30:09.816Z,1692127809.816 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:30:09.816Z,1692127809.816 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:33:18.883Z,1692127998.883 [NAL9602](INFO): SBD MO Status=0, MOMSN=30490, MT Status=0, MTMSN=0
2023-08-15T19:33:18.883Z,1692127998.883 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:33:49.580Z,1692128029.580 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:34:11.302Z,1692128051.302 [DAT](INFO): DAT read: user:6>Rx Time:19:34:10.7745
2023-08-15T19:34:11.303Z,1692128051.303 [DAT](INFO): DAT read: $Low SNR acquisition
2023-08-15T19:34:11.303Z,1692128051.303 [DAT](INFO): Received low SNR in chirp
2023-08-15T19:35:10.426Z,1692128110.426 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:35:10.426Z,1692128110.426 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:35:10.426Z,1692128110.426 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:35:10.426Z,1692128110.426 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:35:10.804Z,1692128110.804 [Default:CheckIn:D] Stopped
2023-08-15T19:35:10.821Z,1692128110.821 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:35:11.200Z,1692128111.200 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.564115 min
2023-08-15T19:35:11.200Z,1692128111.200 [Default:CheckIn:E] Stopped
2023-08-15T19:35:11.200Z,1692128111.200 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:35:11.200Z,1692128111.200 [Default:CheckIn] Stopped
2023-08-15T19:35:11.200Z,1692128111.200 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:35:11.200Z,1692128111.200 [Default:CheckIn](INFO): Running loop #8
2023-08-15T19:35:11.200Z,1692128111.200 [Default:CheckIn] Running Loop=8
2023-08-15T19:35:11.201Z,1692128111.201 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:35:11.201Z,1692128111.201 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:35:13.217Z,1692128113.217 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193410.00,A,3648.17819,N,12147.27429,W,0.039,213.72,150823,,,A*74
2023-08-15T19:35:13.219Z,1692128113.219 [NAL9602](INFO): GPS fix at 20230815T193410: (36.802970, -121.787905)
2023-08-15T19:35:13.231Z,1692128113.231 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:35:13.231Z,1692128113.231 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:35:20.808Z,1692128120.808 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0025.lzma
2023-08-15T19:35:21.811Z,1692128121.811 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0025.lzma.bak
2023-08-15T19:35:21.811Z,1692128121.811 [DataOverHttps](INFO): SBD MOMSN=18562506
2023-08-15T19:35:38.329Z,1692128138.329 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230815T185138/Express0026.lzma
2023-08-15T19:35:39.331Z,1692128139.331 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0026.lzma.bak
2023-08-15T19:35:39.331Z,1692128139.331 [DataOverHttps](INFO): SBD MOMSN=18562510
2023-08-15T19:35:39.872Z,1692128139.872 [NAL9602](INFO): SBD MO Status=0, MOMSN=30491, MT Status=0, MTMSN=0
2023-08-15T19:35:39.872Z,1692128139.872 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:35:40.704Z,1692128140.704 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:35:40.705Z,1692128140.705 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:35:40.705Z,1692128140.705 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:36:10.576Z,1692128170.576 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:40:41.277Z,1692128441.277 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:40:41.278Z,1692128441.278 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:40:41.278Z,1692128441.278 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:40:41.278Z,1692128441.278 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:40:41.695Z,1692128441.695 [Default:CheckIn:D] Stopped
2023-08-15T19:40:41.695Z,1692128441.695 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 46.078963 min
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn:E] Stopped
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn] Stopped
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn](INFO): Running loop #9
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn] Running Loop=9
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:40:42.086Z,1692128442.086 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:40:44.096Z,1692128444.096 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193941.00,A,3648.17091,N,12147.27696,W,0.194,213.72,150823,,,A*75
2023-08-15T19:40:44.098Z,1692128444.098 [NAL9602](INFO): GPS fix at 20230815T193941: (36.802849, -121.787949)
2023-08-15T19:40:44.110Z,1692128444.110 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:40:44.110Z,1692128444.110 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:40:51.384Z,1692128451.384 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0028.lzma
2023-08-15T19:40:52.387Z,1692128452.387 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0028.lzma.bak
2023-08-15T19:40:52.387Z,1692128452.387 [DataOverHttps](INFO): SBD MOMSN=18562522
2023-08-15T19:41:08.773Z,1692128468.773 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230815T185138/Express0029.lzma
2023-08-15T19:41:09.775Z,1692128469.775 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0029.lzma.bak
2023-08-15T19:41:09.775Z,1692128469.775 [DataOverHttps](INFO): SBD MOMSN=18562525
2023-08-15T19:41:11.194Z,1692128471.194 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:41:11.194Z,1692128471.194 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:41:11.194Z,1692128471.194 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:42:25.907Z,1692128545.907 [NAL9602](INFO): SBD MO Status=0, MOMSN=30492, MT Status=0, MTMSN=0
2023-08-15T19:42:25.908Z,1692128545.908 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:42:56.603Z,1692128576.603 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:46:11.752Z,1692128771.752 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:46:11.752Z,1692128771.752 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:46:11.752Z,1692128771.752 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:46:11.752Z,1692128771.752 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:46:12.159Z,1692128772.159 [Default:CheckIn:D] Stopped
2023-08-15T19:46:12.159Z,1692128772.159 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:46:12.585Z,1692128772.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.586686 min
2023-08-15T19:46:12.585Z,1692128772.585 [Default:CheckIn:E] Stopped
2023-08-15T19:46:12.585Z,1692128772.585 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:46:12.585Z,1692128772.585 [Default:CheckIn] Stopped
2023-08-15T19:46:12.585Z,1692128772.585 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:46:12.586Z,1692128772.586 [Default:CheckIn](INFO): Running loop #10
2023-08-15T19:46:12.586Z,1692128772.586 [Default:CheckIn] Running Loop=10
2023-08-15T19:46:12.586Z,1692128772.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:46:12.586Z,1692128772.586 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:46:14.564Z,1692128774.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194511.00,A,3648.17195,N,12147.27845,W,0.019,0.92,150823,,,A*74
2023-08-15T19:46:14.566Z,1692128774.566 [NAL9602](INFO): GPS fix at 20230815T194511: (36.802866, -121.787974)
2023-08-15T19:46:14.626Z,1692128774.626 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:46:14.626Z,1692128774.626 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:46:22.252Z,1692128782.252 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0031.lzma
2023-08-15T19:46:23.247Z,1692128783.247 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0031.lzma.bak
2023-08-15T19:46:23.247Z,1692128783.247 [DataOverHttps](INFO): SBD MOMSN=18562536
2023-08-15T19:46:26.305Z,1692128786.305 [NAL9602](INFO): SBD MO Status=0, MOMSN=30493, MT Status=0, MTMSN=0
2023-08-15T19:46:26.306Z,1692128786.306 [NAL9602](INFO): No messages in MT queue
2023-08-15T19:46:39.600Z,1692128799.600 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230815T185138/Express0032.lzma
2023-08-15T19:46:40.603Z,1692128800.603 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0032.lzma.bak
2023-08-15T19:46:40.603Z,1692128800.603 [DataOverHttps](INFO): SBD MOMSN=18562539
2023-08-15T19:46:42.081Z,1692128802.081 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:46:42.081Z,1692128802.081 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:46:42.081Z,1692128802.081 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:46:56.986Z,1692128816.986 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:49:06.301Z,1692128946.301 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD, +0.0.75
2023-08-15T19:51:42.648Z,1692129102.648 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:51:42.648Z,1692129102.648 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:51:42.648Z,1692129102.648 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:51:42.648Z,1692129102.648 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:51:43.038Z,1692129103.038 [Default:CheckIn:D] Stopped
2023-08-15T19:51:43.038Z,1692129103.038 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:51:43.433Z,1692129103.433 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.101347 min
2023-08-15T19:51:43.433Z,1692129103.433 [Default:CheckIn:E] Stopped
2023-08-15T19:51:43.433Z,1692129103.433 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:51:43.434Z,1692129103.434 [Default:CheckIn] Stopped
2023-08-15T19:51:43.434Z,1692129103.434 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:51:43.434Z,1692129103.434 [Default:CheckIn](INFO): Running loop #11
2023-08-15T19:51:43.434Z,1692129103.434 [Default:CheckIn] Running Loop=11
2023-08-15T19:51:43.434Z,1692129103.434 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:51:43.434Z,1692129103.434 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:51:45.440Z,1692129105.440 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195042.00,A,3648.17051,N,12147.27197,W,0.447,147.06,150823,,,A*79
2023-08-15T19:51:45.443Z,1692129105.443 [NAL9602](INFO): GPS fix at 20230815T195042: (36.802842, -121.787866)
2023-08-15T19:51:45.454Z,1692129105.454 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:51:45.454Z,1692129105.454 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:51:53.452Z,1692129113.452 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230815T185138/Courier0034.lzma
2023-08-15T19:51:53.523Z,1692129113.523 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2023-08-15T19:51:53.523Z,1692129113.523 [DropWeight] Hardware Fault, FailCount= 1
2023-08-15T19:51:53.523Z,1692129113.523 [DropWeight](ERROR): Hardware Fault
2023-08-15T19:51:53.543Z,1692129113.543 [CBIT](INFO): Critical error at 20230815T195153
2023-08-15T19:51:53.545Z,1692129113.545 [CBIT](ERROR): Hardware Fault in component: DropWeight
2023-08-15T19:51:53.546Z,1692129113.546 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2023-08-15T19:51:53.949Z,1692129113.949 [CBIT](INFO): Critical error at 20230815T195153
2023-08-15T19:51:54.455Z,1692129114.455 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0034.lzma.bak
2023-08-15T19:51:54.455Z,1692129114.455 [DataOverHttps](INFO): SBD MOMSN=18562550
2023-08-15T19:52:11.196Z,1692129131.196 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230815T185138/Express0035.lzma
2023-08-15T19:52:12.199Z,1692129132.199 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0035.lzma.bak
2023-08-15T19:52:12.200Z,1692129132.200 [DataOverHttps](INFO): SBD MOMSN=18562553
2023-08-15T19:52:13.742Z,1692129133.742 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:52:13.742Z,1692129133.742 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:52:13.742Z,1692129133.742 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:53:57.959Z,1692129237.959 [NAL9602](INFO): SBD MO Status=2, MOMSN=30494, MT Status=2, MTMSN=0
2023-08-15T19:53:57.960Z,1692129237.960 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-15T19:54:27.044Z,1692129267.044 [NAL9602](INFO): SBD MO Status=2, MOMSN=30494, MT Status=2, MTMSN=0
2023-08-15T19:54:27.044Z,1692129267.044 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-15T19:56:47.234Z,1692129407.234 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-15T19:57:14.352Z,1692129434.352 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-15T19:57:14.352Z,1692129434.352 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:57:14.352Z,1692129434.352 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:57:14.352Z,1692129434.352 [Default:CheckIn:D] Running Loop=1
2023-08-15T19:57:14.715Z,1692129434.715 [Default:CheckIn:D] Stopped
2023-08-15T19:57:14.715Z,1692129434.715 [Default:CheckIn:E] Running Loop=1
2023-08-15T19:57:15.126Z,1692129435.126 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.629285 min
2023-08-15T19:57:15.126Z,1692129435.126 [Default:CheckIn:E] Stopped
2023-08-15T19:57:15.127Z,1692129435.127 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-15T19:57:15.127Z,1692129435.127 [Default:CheckIn] Stopped
2023-08-15T19:57:15.127Z,1692129435.127 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:57:15.127Z,1692129435.127 [Default:CheckIn](INFO): Running loop #12
2023-08-15T19:57:15.127Z,1692129435.127 [Default:CheckIn] Running Loop=12
2023-08-15T19:57:15.127Z,1692129435.127 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-15T19:57:15.127Z,1692129435.127 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-15T19:57:17.131Z,1692129437.131 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195614.00,A,3648.16771,N,12147.28747,W,0.661,184.52,150823,,,A*74
2023-08-15T19:57:17.134Z,1692129437.134 [NAL9602](INFO): GPS fix at 20230815T195614: (36.802795, -121.788124)
2023-08-15T19:57:17.146Z,1692129437.146 [Default:CheckIn:Read_GPS] Stopped
2023-08-15T19:57:17.146Z,1692129437.146 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-15T19:57:25.172Z,1692129445.172 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20230815T185138/Courier0037.lzma
2023-08-15T19:57:26.175Z,1692129446.175 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Courier0037.lzma.bak
2023-08-15T19:57:26.175Z,1692129446.175 [DataOverHttps](INFO): SBD MOMSN=18562564
2023-08-15T19:57:42.569Z,1692129462.569 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20230815T185138/Express0038.lzma
2023-08-15T19:57:43.571Z,1692129463.571 [DataOverHttps](INFO): Moved sent file to Logs/20230815T185138/Express0038.lzma.bak
2023-08-15T19:57:43.571Z,1692129463.571 [DataOverHttps](INFO): SBD MOMSN=18562569
2023-08-15T19:57:45.042Z,1692129465.042 [Default:CheckIn:Read_Iridium] Stopped
2023-08-15T19:57:45.042Z,1692129465.042 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-15T19:57:45.042Z,1692129465.042 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-15T19:57:49.470Z,1692129469.470 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-15T19:57:59.692Z,1692129479.692 [CommandExec](IMPORTANT): got command quit
2023-08-15T19:58:00.697Z,1692129480.697 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:00.697Z,1692129480.697 [CommandExec](INFO): Uninitializing the command executive.
2023-08-15T19:58:00.697Z,1692129480.697 [CommandExec](INFO): Uninitializing the command scheduler.
2023-08-15T19:58:00.697Z,1692129480.697 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:00.897Z,1692129480.897 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2023-08-15T19:58:00.897Z,1692129480.897 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-08-15T19:58:00.897Z,1692129480.897 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:00.898Z,1692129480.898 [NavChartDb](INFO): Join timeout helper Thread ID is 979
2023-08-15T19:58:00.937Z,1692129480.937 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:00.937Z,1692129480.937 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:00.957Z,1692129480.957 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2023-08-15T19:58:00.957Z,1692129480.957 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:00.957Z,1692129480.957 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 980
2023-08-15T19:58:00.973Z,1692129480.973 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:00.974Z,1692129480.974 [WetLabsUBAT](INFO): Powering down
2023-08-15T19:58:00.974Z,1692129480.974 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:00.977Z,1692129480.977 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-08-15T19:58:00.977Z,1692129480.977 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:00.977Z,1692129480.977 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 981
2023-08-15T19:58:01.277Z,1692129481.277 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:01.277Z,1692129481.277 [WetLabsBB2FL](INFO): Powering down
2023-08-15T19:58:01.278Z,1692129481.278 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:01.285Z,1692129481.285 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-08-15T19:58:01.285Z,1692129481.285 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:01.285Z,1692129481.285 [CTD_Seabird](INFO): Join timeout helper Thread ID is 982
2023-08-15T19:58:01.853Z,1692129481.853 [CTD_Seabird](INFO): Powering down
2023-08-15T19:58:01.867Z,1692129481.867 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:01.877Z,1692129481.877 [CTD_Seabird](INFO): Powering down
2023-08-15T19:58:01.889Z,1692129481.889 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:01.897Z,1692129481.897 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-08-15T19:58:01.897Z,1692129481.897 [DAT ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:01.897Z,1692129481.897 [DAT](INFO): Join timeout helper Thread ID is 983
2023-08-15T19:58:02.041Z,1692129482.041 [DAT](INFO): Powering down
2023-08-15T19:58:02.114Z,1692129482.114 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:02.114Z,1692129482.114 [DAT](INFO): Powering down
2023-08-15T19:58:02.115Z,1692129482.115 [DAT ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:02.130Z,1692129482.130 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-08-15T19:58:02.130Z,1692129482.130 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:02.130Z,1692129482.130 [Radio_Surface](INFO): Join timeout helper Thread ID is 984
2023-08-15T19:58:02.341Z,1692129482.341 [Radio_Surface](INFO): Powering down
2023-08-15T19:58:02.342Z,1692129482.342 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:02.342Z,1692129482.342 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:02.362Z,1692129482.362 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-08-15T19:58:02.362Z,1692129482.362 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:02.362Z,1692129482.362 [Onboard](INFO): Join timeout helper Thread ID is 985
2023-08-15T19:58:03.221Z,1692129483.221 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-08-15T19:58:03.381Z,1692129483.381 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:03.382Z,1692129483.382 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:03.393Z,1692129483.393 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-08-15T19:58:03.394Z,1692129483.394 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:03.394Z,1692129483.394 [DataOverHttps](INFO): Join timeout helper Thread ID is 986
2023-08-15T19:58:04.226Z,1692129484.226 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:04.226Z,1692129484.226 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.238Z,1692129484.238 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-08-15T19:58:04.239Z,1692129484.239 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.239Z,1692129484.239 [BackseatComponent](INFO): Join timeout helper Thread ID is 987
2023-08-15T19:58:04.273Z,1692129484.273 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:04.274Z,1692129484.274 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.280Z,1692129484.280 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-08-15T19:58:04.281Z,1692129484.281 [logger ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.281Z,1692129484.281 [logger](INFO): Join timeout helper Thread ID is 988
2023-08-15T19:58:04.318Z,1692129484.318 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:04.318Z,1692129484.318 [logger ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.325Z,1692129484.325 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-08-15T19:58:04.326Z,1692129484.326 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.326Z,1692129484.326 [CommandLine](INFO): Join timeout helper Thread ID is 989
2023-08-15T19:58:04.349Z,1692129484.349 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:04.349Z,1692129484.349 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.366Z,1692129484.366 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-08-15T19:58:04.366Z,1692129484.366 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.366Z,1692129484.366 [CommandExec](INFO): Join timeout helper Thread ID is 990
2023-08-15T19:58:04.367Z,1692129484.367 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-08-15T19:58:04.367Z,1692129484.367 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.368Z,1692129484.368 [controlThread](INFO): Join timeout helper Thread ID is 991
2023-08-15T19:58:04.409Z,1692129484.409 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-15T19:58:04.409Z,1692129484.409 [controlThread](DEBUG): Uninitializing ControlThread
2023-08-15T19:58:04.410Z,1692129484.410 [AHRS_M2](INFO): Powering down
2023-08-15T19:58:04.482Z,1692129484.482 [NAL9602](INFO): Powering down
2023-08-15T19:58:04.553Z,1692129484.553 [RDI_Pathfinder](INFO): Powering down
2023-08-15T19:58:04.554Z,1692129484.554 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-08-15T19:58:04.555Z,1692129484.555 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-08-15T19:58:04.556Z,1692129484.556 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-08-15T19:58:04.556Z,1692129484.556 [MissionManager](INFO): Uninitializing Mission Default
2023-08-15T19:58:04.556Z,1692129484.556 [Default] Stopped
2023-08-15T19:58:04.556Z,1692129484.556 [Default](DEBUG): Aggregate::uninitialize Default
2023-08-15T19:58:04.556Z,1692129484.556 [Default:B.GoToSurface] Stopped
2023-08-15T19:58:04.557Z,1692129484.557 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-08-15T19:58:04.557Z,1692129484.557 [Default:CheckIn] Stopped
2023-08-15T19:58:04.557Z,1692129484.557 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-15T19:58:04.557Z,1692129484.557 [Default:CheckIn:C.Wait] Stopped
2023-08-15T19:58:04.557Z,1692129484.557 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-15T19:58:04.560Z,1692129484.560 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-08-15T19:58:04.560Z,1692129484.560 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-08-15T19:58:04.560Z,1692129484.560 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-08-15T19:58:04.561Z,1692129484.561 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-08-15T19:58:04.561Z,1692129484.561 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-08-15T19:58:04.561Z,1692129484.561 [BuoyancyServo](INFO): Powering down
2023-08-15T19:58:04.573Z,1692129484.573 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-08-15T19:58:04.573Z,1692129484.573 [ElevatorServo](INFO): Powering down
2023-08-15T19:58:04.574Z,1692129484.574 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-08-15T19:58:04.574Z,1692129484.574 [MassServo](INFO): Powering down
2023-08-15T19:58:04.575Z,1692129484.575 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-08-15T19:58:04.575Z,1692129484.575 [RudderServo](INFO): Powering down
2023-08-15T19:58:04.576Z,1692129484.576 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2023-08-15T19:58:04.576Z,1692129484.576 [ThrusterServo](INFO): Powering down
2023-08-15T19:58:04.577Z,1692129484.577 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-08-15T19:58:04.577Z,1692129484.577 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-08-15T19:58:04.577Z,1692129484.577 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-08-15T19:58:04.578Z,1692129484.578 [CBIT](DEBUG): Powering off loads.
2023-08-15T19:58:04.589Z,1692129484.589 [CBIT](DEBUG): Disabling WDT.
2023-08-15T19:58:04.601Z,1692129484.601 [CBIT](DEBUG): Opening all GF detection circuits.
2023-08-15T19:58:04.602Z,1692129484.602 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.661Z,1692129484.661 [DAT ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.668Z,1692129484.668 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.671Z,1692129484.671 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.677Z,1692129484.677 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.721Z,1692129484.721 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.783Z,1692129484.783 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.785Z,1692129484.785 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.789Z,1692129484.789 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.798Z,1692129484.798 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-08-15T19:58:04.871Z,1692129484.871 [logger ThreadHandler](INFO): Thread cancelled.