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.