2022-11-07T22:55:42.753Z,1667861742.753 [Supervisor](DEBUG): Initializing supervisor. 2022-11-07T22:55:42.758Z,1667861742.758 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2022-11-07T22:55:42.758Z,1667861742.758 [SyncHandler](INFO): Protected caller Thread ID is 836 2022-11-07T22:55:42.759Z,1667861742.759 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2022-11-07T22:55:42.759Z,1667861742.759 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2022-11-07T22:55:42.760Z,1667861742.760 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837 2022-11-07T22:55:42.778Z,1667861742.778 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2022-11-07T22:55:42.796Z,1667861742.796 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2022-11-07T22:55:42.796Z,1667861742.796 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2022-11-07T22:55:42.797Z,1667861742.797 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838 2022-11-07T22:55:42.801Z,1667861742.801 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2022-11-07T22:55:42.802Z,1667861742.802 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2022-11-07T22:55:42.802Z,1667861742.802 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839 2022-11-07T22:55:42.804Z,1667861742.804 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2022-11-07T22:55:42.805Z,1667861742.805 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2022-11-07T22:55:42.806Z,1667861742.806 [logger ThreadHandler](INFO): Protected caller Thread ID is 840 2022-11-07T22:55:42.809Z,1667861742.809 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2022-11-07T22:55:42.810Z,1667861742.810 [Supervisor](INFO): Looking for Config files in directory: Config/ 2022-11-07T22:55:42.814Z,1667861742.814 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2022-11-07T22:55:43.278Z,1667861743.278 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2022-11-07T22:55:43.280Z,1667861743.280 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2022-11-07T22:55:43.511Z,1667861743.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2022-11-07T22:55:43.512Z,1667861743.512 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2022-11-07T22:55:43.708Z,1667861743.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2022-11-07T22:55:43.709Z,1667861743.709 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2022-11-07T22:55:43.814Z,1667861743.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2022-11-07T22:55:43.814Z,1667861743.814 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2022-11-07T22:55:44.172Z,1667861744.172 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2022-11-07T22:55:44.174Z,1667861744.174 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2022-11-07T22:55:44.485Z,1667861744.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2022-11-07T22:55:44.487Z,1667861744.487 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2022-11-07T22:55:44.582Z,1667861744.582 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2022-11-07T22:55:44.584Z,1667861744.584 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2022-11-07T22:55:44.797Z,1667861744.797 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2022-11-07T22:55:44.799Z,1667861744.799 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2022-11-07T22:55:45.297Z,1667861745.297 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2022-11-07T22:55:45.298Z,1667861745.298 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2022-11-07T22:55:45.642Z,1667861745.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2022-11-07T22:55:45.644Z,1667861745.644 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2022-11-07T22:55:45.724Z,1667861745.724 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2022-11-07T22:55:45.932Z,1667861745.932 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2022-11-07T22:55:45.933Z,1667861745.933 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2022-11-07T22:55:46.852Z,1667861746.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2022-11-07T22:55:46.853Z,1667861746.853 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2022-11-07T22:55:47.562Z,1667861747.562 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2022-11-07T22:55:47.563Z,1667861747.563 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2022-11-07T22:55:47.642Z,1667861747.642 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2022-11-07T22:55:47.922Z,1667861747.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2022-11-07T22:55:47.924Z,1667861747.924 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/ 2022-11-07T22:55:47.927Z,1667861747.927 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg 2022-11-07T22:55:48.101Z,1667861748.101 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg 2022-11-07T22:55:48.194Z,1667861748.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg 2022-11-07T22:55:48.304Z,1667861748.304 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg 2022-11-07T22:55:48.403Z,1667861748.403 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg 2022-11-07T22:55:48.487Z,1667861748.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg 2022-11-07T22:55:48.571Z,1667861748.571 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg 2022-11-07T22:55:48.682Z,1667861748.682 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg 2022-11-07T22:55:48.779Z,1667861748.779 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg 2022-11-07T22:55:48.930Z,1667861748.930 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg 2022-11-07T22:55:49.188Z,1667861749.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2022-11-07T22:55:49.189Z,1667861749.189 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg 2022-11-07T22:55:49.281Z,1667861749.281 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2022-11-07T22:55:49.300Z,1667861749.300 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2022-11-07T22:55:49.651Z,1667861749.651 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2022-11-07T22:55:49.653Z,1667861749.653 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2022-11-07T22:55:49.788Z,1667861749.788 [DeadReckonUsingMultipleVelocitySources] Loaded 2022-11-07T22:55:49.789Z,1667861749.789 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2022-11-07T22:55:49.827Z,1667861749.827 [DeadReckonUsingSpeedCalculator] Loaded 2022-11-07T22:55:49.828Z,1667861749.828 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2022-11-07T22:55:49.841Z,1667861749.841 [NavChart] Loaded 2022-11-07T22:55:49.841Z,1667861749.841 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2022-11-07T22:55:49.846Z,1667861749.846 [UniversalFixResidualReporter] Loaded 2022-11-07T22:55:49.846Z,1667861749.846 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2022-11-07T22:55:49.847Z,1667861749.847 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2022-11-07T22:55:49.848Z,1667861749.848 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2022-11-07T22:55:49.863Z,1667861749.863 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2022-11-07T22:55:49.864Z,1667861749.864 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2022-11-07T22:55:50.065Z,1667861750.065 [PAR_Licor] Loaded 2022-11-07T22:55:50.065Z,1667861750.065 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2022-11-07T22:55:50.096Z,1667861750.096 [WetLabsBB2FL] Loaded 2022-11-07T22:55:50.096Z,1667861750.096 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2022-11-07T22:55:50.098Z,1667861750.098 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065A4E0 2022-11-07T22:55:50.098Z,1667861750.098 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 922 2022-11-07T22:55:50.099Z,1667861750.099 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2022-11-07T22:55:50.100Z,1667861750.100 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2022-11-07T22:55:50.167Z,1667861750.167 [VerticalControl](DEBUG): Construct VerticalControl. 2022-11-07T22:55:50.228Z,1667861750.228 [VerticalControl] Loaded 2022-11-07T22:55:50.229Z,1667861750.229 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2022-11-07T22:55:50.232Z,1667861750.232 [HorizontalControl](DEBUG): Construct HorizontalControl. 2022-11-07T22:55:50.272Z,1667861750.272 [HorizontalControl] Loaded 2022-11-07T22:55:50.273Z,1667861750.273 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2022-11-07T22:55:50.275Z,1667861750.275 [SpeedControl](DEBUG): Construct SpeedControl. 2022-11-07T22:55:50.278Z,1667861750.278 [SpeedControl] Loaded 2022-11-07T22:55:50.278Z,1667861750.278 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2022-11-07T22:55:50.281Z,1667861750.281 [LoopControl](DEBUG): Construct LoopControl. 2022-11-07T22:55:50.282Z,1667861750.282 [LoopControl] Loaded 2022-11-07T22:55:50.282Z,1667861750.282 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2022-11-07T22:55:50.282Z,1667861750.282 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2022-11-07T22:55:50.284Z,1667861750.284 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2022-11-07T22:55:50.352Z,1667861750.352 [DepthRateCalculator] Loaded 2022-11-07T22:55:50.353Z,1667861750.353 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2022-11-07T22:55:50.358Z,1667861750.358 [PitchRateCalculator] Loaded 2022-11-07T22:55:50.358Z,1667861750.358 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2022-11-07T22:55:50.367Z,1667861750.367 [SpeedCalculator] Loaded 2022-11-07T22:55:50.367Z,1667861750.367 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2022-11-07T22:55:50.371Z,1667861750.371 [YawRateCalculator] Loaded 2022-11-07T22:55:50.372Z,1667861750.372 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2022-11-07T22:55:50.390Z,1667861750.390 [ElevatorOffsetCalculator] Loaded 2022-11-07T22:55:50.390Z,1667861750.390 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2022-11-07T22:55:50.390Z,1667861750.390 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2022-11-07T22:55:50.392Z,1667861750.392 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2022-11-07T22:55:50.510Z,1667861750.510 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2022-11-07T22:55:50.511Z,1667861750.511 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2022-11-07T22:55:50.594Z,1667861750.594 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2022-11-07T22:55:50.594Z,1667861750.594 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2022-11-07T22:55:50.742Z,1667861750.742 [BuoyancyServo] Loaded 2022-11-07T22:55:50.743Z,1667861750.743 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2022-11-07T22:55:50.762Z,1667861750.762 [ElevatorServo] Loaded 2022-11-07T22:55:50.763Z,1667861750.763 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2022-11-07T22:55:50.782Z,1667861750.782 [MassServo] Loaded 2022-11-07T22:55:50.782Z,1667861750.782 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2022-11-07T22:55:50.800Z,1667861750.800 [RudderServo] Loaded 2022-11-07T22:55:50.800Z,1667861750.800 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2022-11-07T22:55:50.815Z,1667861750.815 [ThrusterHE] Loaded 2022-11-07T22:55:50.815Z,1667861750.815 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2022-11-07T22:55:50.815Z,1667861750.815 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2022-11-07T22:55:50.816Z,1667861750.816 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2022-11-07T22:55:50.000Z,1667861751.000 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2022-11-07T22:55:51.001Z,1667861751.001 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2022-11-07T22:55:52.540Z,1667861752.540 [AHRS_M2] Loaded 2022-11-07T22:55:52.540Z,1667861752.540 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2022-11-07T22:55:52.789Z,1667861752.789 [BackseatComponent] Loaded 2022-11-07T22:55:52.789Z,1667861752.789 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2022-11-07T22:55:52.790Z,1667861752.790 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0 2022-11-07T22:55:52.790Z,1667861752.790 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 925 2022-11-07T22:55:52.793Z,1667861752.793 [LcmUniversalReporter] Loaded 2022-11-07T22:55:52.793Z,1667861752.793 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2022-11-07T22:55:53.598Z,1667861753.598 [BPC1] Loaded 2022-11-07T22:55:53.598Z,1667861753.598 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2022-11-07T22:55:53.925Z,1667861753.925 [DataOverHttps] Loaded 2022-11-07T22:55:53.925Z,1667861753.925 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2022-11-07T22:55:53.926Z,1667861753.926 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0 2022-11-07T22:55:53.926Z,1667861753.926 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926 2022-11-07T22:55:53.947Z,1667861753.947 [Depth_Keller] Loaded 2022-11-07T22:55:53.947Z,1667861753.947 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2022-11-07T22:55:53.952Z,1667861753.952 [DropWeight] Loaded 2022-11-07T22:55:53.952Z,1667861753.952 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2022-11-07T22:55:53.970Z,1667861753.970 [MultiRay] Loaded 2022-11-07T22:55:53.970Z,1667861753.970 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2022-11-07T22:55:54.031Z,1667861754.031 [NAL9602] Loaded 2022-11-07T22:55:54.031Z,1667861754.031 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2022-11-07T22:55:54.061Z,1667861754.061 [Onboard] Loaded 2022-11-07T22:55:54.061Z,1667861754.061 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2022-11-07T22:55:54.062Z,1667861754.062 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0 2022-11-07T22:55:54.063Z,1667861754.063 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927 2022-11-07T22:55:54.069Z,1667861754.069 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3 2022-11-07T22:55:54.080Z,1667861754.080 [PowerOnly] Loaded 2022-11-07T22:55:54.080Z,1667861754.080 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2022-11-07T22:55:54.092Z,1667861754.092 [Power24vConverter] Loaded 2022-11-07T22:55:54.092Z,1667861754.092 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2022-11-07T22:55:54.105Z,1667861754.105 [Radio_Surface] Loaded 2022-11-07T22:55:54.105Z,1667861754.105 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2022-11-07T22:55:54.106Z,1667861754.106 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0 2022-11-07T22:55:54.107Z,1667861754.107 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928 2022-11-07T22:55:54.201Z,1667861754.201 [DAT] Loaded 2022-11-07T22:55:54.201Z,1667861754.201 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2022-11-07T22:55:54.202Z,1667861754.202 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B154E0 2022-11-07T22:55:54.202Z,1667861754.202 [DAT ThreadHandler](INFO): Protected caller Thread ID is 929 2022-11-07T22:55:54.203Z,1667861754.203 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2022-11-07T22:55:54.203Z,1667861754.203 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2022-11-07T22:55:54.373Z,1667861754.373 [SBIT](DEBUG): Construct Startup Built In Test. 2022-11-07T22:55:54.382Z,1667861754.382 [SBIT] Loaded 2022-11-07T22:55:54.382Z,1667861754.382 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2022-11-07T22:55:54.385Z,1667861754.385 [IBIT](DEBUG): Construct Initiated Built In Test. 2022-11-07T22:55:54.399Z,1667861754.399 [IBIT] Loaded 2022-11-07T22:55:54.399Z,1667861754.399 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2022-11-07T22:55:54.404Z,1667861754.404 [CBIT](DEBUG): Construct Continuous Built In Test. 2022-11-07T22:55:54.507Z,1667861754.507 [CBIT] Loaded 2022-11-07T22:55:54.507Z,1667861754.507 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2022-11-07T22:55:54.508Z,1667861754.508 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2022-11-07T22:55:54.508Z,1667861754.508 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2022-11-07T22:55:54.550Z,1667861754.550 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2022-11-07T22:55:54.557Z,1667861754.557 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2022-11-07T22:55:54.560Z,1667861754.560 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2022-11-07T22:55:54.571Z,1667861754.571 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2022-11-07T22:55:54.572Z,1667861754.572 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA34E0 2022-11-07T22:55:54.573Z,1667861754.573 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 930 2022-11-07T22:55:54.577Z,1667861754.577 [Supervisor](INFO): Main Thread ID is 831 2022-11-07T22:55:54.577Z,1667861754.577 [Supervisor](DEBUG): Running supervisor. 2022-11-07T22:55:54.578Z,1667861754.578 [CommandExec ThreadHandler](INFO): Handler Thread ID is 931 2022-11-07T22:55:54.578Z,1667861754.578 [CommandExec](INFO): Initializing the command executive. 2022-11-07T22:55:54.580Z,1667861754.580 [CommandLine ThreadHandler](INFO): Handler Thread ID is 932 2022-11-07T22:55:54.582Z,1667861754.582 [controlThread ThreadHandler](INFO): Handler Thread ID is 933 2022-11-07T22:55:54.582Z,1667861754.582 [controlThread](DEBUG): Initializing ControlThread 2022-11-07T22:55:54.584Z,1667861754.584 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-07T22:55:54.584Z,1667861754.584 [NavChart](DEBUG): Initialize NavChart Navigation. 2022-11-07T22:55:54.584Z,1667861754.584 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2022-11-07T22:55:54.589Z,1667861754.589 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2022-11-07T22:55:54.591Z,1667861754.591 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2022-11-07T22:55:54.592Z,1667861754.592 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2022-11-07T22:55:54.592Z,1667861754.592 [LoopControl](DEBUG): Initialize LoopControlComponent. 2022-11-07T22:55:54.592Z,1667861754.592 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2022-11-07T22:55:54.593Z,1667861754.593 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2022-11-07T22:55:54.593Z,1667861754.593 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2022-11-07T22:55:54.594Z,1667861754.594 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2022-11-07T22:55:54.594Z,1667861754.594 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2022-11-07T22:55:54.600Z,1667861754.600 [SBIT](INFO): Initialize SBIT Component. 2022-11-07T22:55:54.600Z,1667861754.600 [SBIT](IMPORTANT): git: 2022-10-11-37-g3067145cf 2022-11-07T22:55:54.600Z,1667861754.600 [SBIT](INFO): git hash: 3067145cfe0a71a9d335ed48764d88f81a84ec20 2022-11-07T22:55:54.601Z,1667861754.601 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2022-11-07T22:55:54.602Z,1667861754.602 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2022-11-07T22:55:54.603Z,1667861754.603 [SBIT](INFO): Beginning SBIT in 109.000000 seconds. 2022-11-07T22:55:54.604Z,1667861754.604 [IBIT](INFO): Initialize IBIT Component. 2022-11-07T22:55:54.604Z,1667861754.604 [CBIT](DEBUG): Initialize CBIT Component. 2022-11-07T22:55:54.605Z,1667861754.605 [logger ThreadHandler](INFO): Handler Thread ID is 934 2022-11-07T22:55:54.617Z,1667861754.617 [CBIT](DEBUG): Initialized mux pins. 2022-11-07T22:55:54.617Z,1667861754.617 [CBIT](DEBUG): Initializing the watchdog timer. 2022-11-07T22:55:54.625Z,1667861754.625 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935 2022-11-07T22:55:54.630Z,1667861754.630 [WetLabsBB2FL](INFO): Powering up 2022-11-07T22:55:54.631Z,1667861754.631 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 937 2022-11-07T22:55:54.637Z,1667861754.637 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 938 2022-11-07T22:55:54.638Z,1667861754.638 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2022-11-07T22:55:54.641Z,1667861754.641 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2022-11-07T22:55:54.642Z,1667861754.642 [CBIT](DEBUG): Initializing heartbeat. 2022-11-07T22:55:54.649Z,1667861754.649 [Onboard ThreadHandler](INFO): Handler Thread ID is 939 2022-11-07T22:55:54.667Z,1667861754.667 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 940 2022-11-07T22:55:54.690Z,1667861754.690 [DAT ThreadHandler](INFO): Handler Thread ID is 941 2022-11-07T22:55:54.690Z,1667861754.690 [DAT](INFO): Powering up 2022-11-07T22:55:54.690Z,1667861754.690 [DAT](DEBUG): Initializing DAT. 2022-11-07T22:55:54.694Z,1667861754.694 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 943 2022-11-07T22:55:54.702Z,1667861754.702 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2022-11-07T22:55:54.702Z,1667861754.702 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2022-11-07T22:55:54.703Z,1667861754.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2022-11-07T22:55:54.703Z,1667861754.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2022-11-07T22:55:54.703Z,1667861754.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2022-11-07T22:55:54.703Z,1667861754.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2022-11-07T22:55:54.703Z,1667861754.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2022-11-07T22:55:54.703Z,1667861754.703 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2022-11-07T22:55:54.713Z,1667861754.713 [CBIT](DEBUG): Deactivating GF circuits. 2022-11-07T22:55:54.713Z,1667861754.713 [CBIT](DEBUG): Deactivating emergency mode. 2022-11-07T22:55:54.749Z,1667861754.749 [CBIT](DEBUG): Backplane powered. 2022-11-07T22:55:54.750Z,1667861754.750 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2022-11-07T22:55:54.780Z,1667861754.780 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-07T22:55:54.792Z,1667861754.792 [MissionManager](DEBUG): 2022-11-07T22:55:54.793Z,1667861754.793 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2022-11-07T22:55:54.887Z,1667861754.887 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2022-11-07T22:55:54.901Z,1667861754.901 [Default:A.Wait](DEBUG): Construct Wait. 2022-11-07T22:55:54.903Z,1667861754.903 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-07T22:55:54.923Z,1667861754.923 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2022-11-07T22:55:54.952Z,1667861754.952 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2022-11-07T22:55:54.978Z,1667861754.978 [Default:E.Execute](DEBUG): Construct Execute. 2022-11-07T22:55:54.990Z,1667861754.990 [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 2022-11-07T22:55:54.995Z,1667861754.995 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2022-11-07T22:55:55.019Z,1667861755.019 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2022-11-07T22:55:55.073Z,1667861755.073 [Radio_Surface](INFO): Powering up 2022-11-07T22:55:55.354Z,1667861755.354 [MultiRay](INFO): Powering up MultiRay Lights 2022-11-07T22:55:55.394Z,1667861755.394 [Power24vConverter](INFO): Powering up. 2022-11-07T22:55:55.423Z,1667861755.423 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2022-11-07T22:55:55.429Z,1667861755.429 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2022-11-07T22:55:55.430Z,1667861755.430 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-11-07T22:55:55.437Z,1667861755.437 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-11-07T22:55:55.438Z,1667861755.438 [MassServo](DEBUG): Initializing EZServoServo. 2022-11-07T22:55:55.447Z,1667861755.447 [MassServo](DEBUG): Initializing MassServo. 2022-11-07T22:55:55.448Z,1667861755.448 [RudderServo](DEBUG): Initializing EZServoServo. 2022-11-07T22:55:55.453Z,1667861755.453 [RudderServo](DEBUG): Initializing RudderServo. 2022-11-07T22:55:55.454Z,1667861755.454 [ThrusterHE](DEBUG): Initializing EZServoServo. 2022-11-07T22:55:55.461Z,1667861755.461 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2022-11-07T22:55:55.561Z,1667861755.561 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-11-07T22:55:55.561Z,1667861755.561 [DropWeight] Hardware Fault, FailCount= 1 2022-11-07T22:55:55.561Z,1667861755.561 [DropWeight](ERROR): Hardware Fault 2022-11-07T22:55:55.594Z,1667861755.594 [MultiRay](IMPORTANT): All lights off 2022-11-07T22:55:55.627Z,1667861755.627 [CommandExec](FAULT): Scheduling is paused 2022-11-07T22:55:55.628Z,1667861755.628 [CBIT](INFO): Critical error at 20221107T225555 2022-11-07T22:55:55.628Z,1667861755.628 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-11-07T22:55:55.639Z,1667861755.639 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-11-07T22:55:55.639Z,1667861755.639 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-11-07T22:55:55.898Z,1667861755.898 [CBIT](INFO): Critical error at 20221107T225555 2022-11-07T22:55:57.241Z,1667861757.241 [WetLabsBB2FL](INFO): Powering down 2022-11-07T22:56:00.998Z,1667861760.998 [ThrusterHE](ERROR): Zero Speed Commanded. 2022-11-07T22:56:10.315Z,1667861770.315 [DAT](INFO): commRate: 800 2022-11-07T22:56:12.381Z,1667861772.381 [DAT](INFO): entering command mode 2022-11-07T22:56:12.582Z,1667861772.582 [DAT](INFO): setting verbose to 3 2022-11-07T22:56:12.835Z,1667861772.835 [DAT](INFO): set verbose to 3 2022-11-07T22:56:12.835Z,1667861772.835 [DAT](INFO): setting DatVerbose to 27440 2022-11-07T22:56:13.087Z,1667861773.087 [DAT](INFO): set DatVerbose to 27440 2022-11-07T22:56:13.087Z,1667861773.087 [DAT](INFO): setting transmit power to 8 2022-11-07T22:56:13.340Z,1667861773.340 [DAT](INFO): set transmit power to 8 2022-11-07T22:56:13.340Z,1667861773.340 [DAT](INFO): setting local address to 10 2022-11-07T22:56:13.591Z,1667861773.591 [DAT](INFO): set local address to 10 2022-11-07T22:56:13.592Z,1667861773.592 [DAT](INFO): Setting time to: 22:56:13 And date to:11/7/2022 2022-11-07T22:56:13.843Z,1667861773.843 [DAT](INFO): Local DAT time set to Mon Nov 7, 2022 22:56:13 2022-11-07T22:56:24.180Z,1667861784.180 [NAL9602](INFO): Powering up NAL9602 2022-11-07T22:56:35.094Z,1667861795.094 [NAL9602](INFO): NAL9602 initialized 2022-11-07T22:57:44.181Z,1667861864.181 [SBIT](IMPORTANT): Beginning Startup BIT 2022-11-07T22:57:44.185Z,1667861864.185 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-07T22:57:55.144Z,1667861875.144 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006973 CHAN A1 (24V): 0.001011 CHAN A2 (12V): -0.006102 CHAN A3 (5V): -0.002717 CHAN B0 (3.3V): -0.001081 CHAN B1 (3.15aV): -0.001868 CHAN B2 (3.15bV): -0.001620 CHAN B3 (GND): -0.000286 OPEN: 0.004797 Full Scale: +/- 1 mA 2022-11-07T22:58:38.440Z,1667861918.440 [SBIT](IMPORTANT): SBIT PASSED 2022-11-07T22:58:38.440Z,1667861918.441 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): BackseatComponent.needs24v=1 bool; 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none; 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): CBIT.gf24Offset=149 microampere; 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour; 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter; 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): Express none _.ayeris_disk_space; 2022-11-07T22:58:38.442Z,1667861918.442 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 250.000000 count; 2022-11-07T22:58:38.443Z,1667861918.443 [SBIT](IMPORTANT): Express none _.ayeris_particle_size; 2022-11-07T22:58:38.443Z,1667861918.443 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour; 2022-11-07T22:58:38.443Z,1667861918.443 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt; 2022-11-07T22:58:38.443Z,1667861918.443 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=210.367112 cubic_centimeter; 2022-11-07T22:58:38.443Z,1667861918.443 [SBIT](IMPORTANT): VerticalControl.massDefault=22.333859 millimeter; 2022-11-07T22:58:38.722Z,1667861918.722 [MissionManager](IMPORTANT): Started mission Startup 2022-11-07T22:58:38.722Z,1667861918.722 [Startup] Running Loop=1 2022-11-07T22:58:38.722Z,1667861918.722 [Startup](DEBUG): Aggregate::initialize Startup 2022-11-07T22:58:38.723Z,1667861918.723 [Startup:A.GoToSurface] Running Loop=1 2022-11-07T22:58:38.723Z,1667861918.723 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-07T22:58:38.723Z,1667861918.723 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-07T22:58:38.724Z,1667861918.724 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-07T22:58:38.724Z,1667861918.724 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-07T22:58:38.724Z,1667861918.724 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-07T22:58:38.745Z,1667861918.745 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-07T22:58:38.746Z,1667861918.746 [Startup:StartupSatComms] Running Loop=1 2022-11-07T22:58:38.746Z,1667861918.746 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2022-11-07T22:58:38.747Z,1667861918.747 [Startup:StartupSatComms:A] Running Loop=1 2022-11-07T22:58:39.115Z,1667861919.115 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2022-11-07T22:58:54.060Z,1667861934.060 [NAL9602](INFO): SBD MO Status=2, MOMSN=9045, MT Status=2, MTMSN=0 2022-11-07T22:58:54.061Z,1667861934.061 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-07T22:58:54.931Z,1667861934.931 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2022-11-07T22:58:54.931Z,1667861934.931 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-07T22:58:54.932Z,1667861934.932 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2022-11-07T22:58:54.932Z,1667861934.932 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-07T22:58:54.942Z,1667861934.942 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-07T22:58:54.943Z,1667861934.943 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-07T22:58:55.326Z,1667861935.326 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-07T22:58:55.326Z,1667861935.326 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2022-11-07T22:58:55.327Z,1667861935.327 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-07T22:58:55.327Z,1667861935.327 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2022-11-07T22:58:55.692Z,1667861935.692 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-07T22:59:11.432Z,1667861951.432 [NAL9602](INFO): SBD MO Status=2, MOMSN=9045, MT Status=2, MTMSN=0 2022-11-07T22:59:11.432Z,1667861951.432 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-07T22:58:23.710Z,1667861903.710 [NAL9602](INFO): SBD MO Status=0, MOMSN=9045, MT Status=0, MTMSN=0 2022-11-07T22:58:23.710Z,1667861903.710 [NAL9602](INFO): No messages in MT queue 2022-11-07T22:58:24.915Z,1667861904.915 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225823.00,A,3648.17033,N,12147.28686,W,0.097,0.00,071122,,,A*75 2022-11-07T22:58:24.919Z,1667861904.919 [NAL9602](INFO): GPS fix at 20221107T225823: (36.802839, -121.788114) 2022-11-07T22:58:24.931Z,1667861904.931 [Startup:StartupSatComms:A] Stopped 2022-11-07T22:58:24.931Z,1667861904.931 [Startup:StartupSatComms:B] Running Loop=1 2022-11-07T22:58:25.359Z,1667861905.359 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-11-07T22:58:26.806Z,1667861906.806 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T22:58:26.807Z,1667861906.807 [DAT](INFO): setting remote address to 1 2022-11-07T22:58:27.059Z,1667861907.059 [DAT](INFO): set remote address to 1 2022-11-07T22:58:27.059Z,1667861907.059 [DAT](INFO): entering online mode 2022-11-07T22:58:27.312Z,1667861907.312 [DAT](INFO): commRate: 800 2022-11-07T22:58:27.312Z,1667861907.312 [DAT](INFO): online mode acknowledged 2022-11-07T22:58:27.312Z,1667861907.312 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T22:58:30.587Z,1667861910.587 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T22:58:40.897Z,1667861920.897 [NAL9602](INFO): SBD MO Status=1, MOMSN=9046, MT Status=0, MTMSN=0 2022-11-07T22:58:40.945Z,1667861920.945 [NAL9602](INFO): Sent 39 bytes from file Logs/20221103T234506/Courier0007.lzma 2022-11-07T22:58:40.946Z,1667861920.946 [NAL9602](INFO): Packets left to send: 0 2022-11-07T22:58:41.678Z,1667861921.678 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T22:58:42.644Z,1667861922.644 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T22:58:42.646Z,1667861922.646 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T22:58:45.922Z,1667861925.922 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T22:58:52.364Z,1667861932.364 [NAL9602](INFO): SBD MO Status=1, MOMSN=9047, MT Status=0, MTMSN=0 2022-11-07T22:58:52.419Z,1667861932.419 [NAL9602](INFO): Sent 244 bytes from file Logs/20221104T193517/Courier0000.lzma 2022-11-07T22:58:52.420Z,1667861932.420 [NAL9602](INFO): Packets left to send: 0 2022-11-07T22:59:02.605Z,1667861942.605 [NAL9602](INFO): SBD MO Status=1, MOMSN=9048, MT Status=0, MTMSN=0 2022-11-07T22:59:02.665Z,1667861942.665 [NAL9602](INFO): Sent 18 bytes from file Logs/20221107T225021/Courier0000.lzma 2022-11-07T22:59:02.665Z,1667861942.665 [NAL9602](INFO): Packets left to send: 0 2022-11-07T22:59:03.070Z,1667861943.070 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T22:59:04.423Z,1667861944.423 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T22:59:04.425Z,1667861944.425 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T22:59:07.702Z,1667861947.702 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T22:59:14.802Z,1667861954.802 [NAL9602](INFO): SBD MO Status=1, MOMSN=9049, MT Status=0, MTMSN=0 2022-11-07T22:59:14.849Z,1667861954.849 [NAL9602](INFO): Sent 332 bytes from file Logs/20221107T225542/Courier0000.lzma 2022-11-07T22:59:14.850Z,1667861954.850 [NAL9602](INFO): Packets left to send: 1 2022-11-07T22:59:25.303Z,1667861965.303 [Startup:StartupSatComms:B](INFO): Timed out from 2022-11-07T22:58:24.9Z 2022-11-07T22:59:25.303Z,1667861965.303 [Startup:StartupSatComms:B] Stopped 2022-11-07T22:59:25.303Z,1667861965.303 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2022-11-07T22:59:25.303Z,1667861965.303 [Startup:StartupSatComms] Stopped 2022-11-07T22:59:25.303Z,1667861965.303 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2022-11-07T22:59:25.304Z,1667861965.304 [Startup](INFO): Completed Startup 2022-11-07T22:59:25.304Z,1667861965.304 [MissionManager](INFO): Startup is completed. 2022-11-07T22:59:25.304Z,1667861965.304 [MissionManager](INFO): Uninitializing Mission Startup 2022-11-07T22:59:25.304Z,1667861965.304 [Startup] Stopped 2022-11-07T22:59:25.304Z,1667861965.304 [Startup](DEBUG): Aggregate::uninitialize Startup 2022-11-07T22:59:25.304Z,1667861965.304 [Startup:A.GoToSurface] Stopped 2022-11-07T22:59:25.304Z,1667861965.304 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-07T22:59:25.702Z,1667861965.702 [MissionManager](IMPORTANT): Started mission Default 2022-11-07T22:59:25.702Z,1667861965.702 [Default] Running Loop=1 2022-11-07T22:59:25.702Z,1667861965.702 [Default](DEBUG): Aggregate::initialize Default 2022-11-07T22:59:25.702Z,1667861965.702 [Default:B.GoToSurface] Running Loop=1 2022-11-07T22:59:25.702Z,1667861965.702 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-07T22:59:25.702Z,1667861965.702 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-07T22:59:25.703Z,1667861965.703 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-07T22:59:25.703Z,1667861965.703 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-07T22:59:25.703Z,1667861965.703 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-07T22:59:25.704Z,1667861965.704 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-07T22:59:25.704Z,1667861965.704 [Default:A.Wait] Running Loop=1 2022-11-07T22:59:25.704Z,1667861965.704 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-07T22:59:28.882Z,1667861968.882 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T22:59:29.134Z,1667861969.134 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T22:59:29.386Z,1667861969.386 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T22:59:30.526Z,1667861970.526 [NAL9602](INFO): SBD MO Status=2, MOMSN=9050, MT Status=2, MTMSN=0 2022-11-07T22:59:30.526Z,1667861970.526 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-07T22:59:31.900Z,1667861971.900 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004543 2022-11-07T22:59:32.663Z,1667861972.663 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T22:59:38.712Z,1667861978.712 [Default:A.Wait](INFO): Done Waiting. 2022-11-07T22:59:38.712Z,1667861978.712 [Default:A.Wait] Stopped 2022-11-07T22:59:38.712Z,1667861978.712 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T22:59:39.108Z,1667861979.108 [Default:CheckIn] Running Loop=1 2022-11-07T22:59:39.109Z,1667861979.109 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T22:59:39.109Z,1667861979.109 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T22:59:39.526Z,1667861979.526 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-11-07T22:59:41.124Z,1667861981.124 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225939.00,A,3648.17539,N,12147.28614,W,0.097,0.00,071122,,,D*7E 2022-11-07T22:59:41.127Z,1667861981.127 [NAL9602](INFO): GPS fix at 20221107T225939: (36.802923, -121.788102) 2022-11-07T22:59:41.139Z,1667861981.139 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T22:59:41.139Z,1667861981.139 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T22:59:41.553Z,1667861981.553 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-11-07T22:59:51.785Z,1667861991.785 [DataOverHttps](INFO): Sending 366 bytes from file Logs/20221107T225542/Courier0000.lzma 2022-11-07T22:59:52.787Z,1667861992.787 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0000.lzma.bak 2022-11-07T22:59:52.788Z,1667861992.788 [DataOverHttps](IMPORTANT): SBD MOMSN=17270902, MTMSN=20221107T225952 2022-11-07T22:59:53.854Z,1667861993.854 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T22:59:53.854Z,1667861993.854 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T22:59:54.110Z,1667861994.110 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T22:59:56.332Z,1667861996.332 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T22:59:56.347Z,1667861996.347 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T22:59:59.615Z,1667861999.615 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:00:07.058Z,1667862007.058 [DataOverHttps](INFO): Received command: ibit 2022-11-07T23:00:07.082Z,1667862007.082 [CommandExec](IMPORTANT): got command ibit 2022-11-07T23:00:07.124Z,1667862007.124 [IBIT](IMPORTANT): Beginning Initiated BIT 2022-11-07T23:00:07.124Z,1667862007.124 [IBIT](IMPORTANT): Beginning control surface checks. 2022-11-07T23:00:07.131Z,1667862007.131 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-07T23:00:08.648Z,1667862008.648 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230006.00,A,3648.17549,N,12147.28619,W,0.039,0.00,071122,,,D*71 2022-11-07T23:00:08.650Z,1667862008.650 [NAL9602](INFO): GPS fix at 20221107T230006: (36.802925, -121.788103) 2022-11-07T23:00:11.722Z,1667862011.722 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:00:11.920Z,1667862011.920 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230010.00,A,3648.17548,N,12147.28623,W,0.039,0.00,071122,,,D*7E 2022-11-07T23:00:11.942Z,1667862011.942 [NAL9602](INFO): GPS fix at 20221107T230010: (36.802925, -121.788104) 2022-11-07T23:00:13.820Z,1667862013.820 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:00:13.830Z,1667862013.830 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:00:14.764Z,1667862014.764 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230013.00,A,3648.17546,N,12147.28625,W,0.039,0.00,071122,,,D*75 2022-11-07T23:00:14.767Z,1667862014.767 [NAL9602](INFO): GPS fix at 20221107T230013: (36.802924, -121.788104) 2022-11-07T23:00:17.099Z,1667862017.099 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:00:17.865Z,1667862017.865 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221107T225542/Courier0004.lzma 2022-11-07T23:00:17.986Z,1667862017.986 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230016.00,A,3648.17545,N,12147.28625,W,0.019,0.00,071122,,,D*71 2022-11-07T23:00:17.989Z,1667862017.989 [NAL9602](INFO): GPS fix at 20221107T230016: (36.802924, -121.788104) 2022-11-07T23:00:18.014Z,1667862018.014 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006440 CHAN A1 (24V): 0.000368 CHAN A2 (12V): -0.005784 CHAN A3 (5V): -0.002663 CHAN B0 (3.3V): -0.001073 CHAN B1 (3.15aV): -0.001771 CHAN B2 (3.15bV): -0.001444 CHAN B3 (GND): -0.000768 OPEN: 0.004673 Full Scale: +/- 1 mA 2022-11-07T23:00:18.867Z,1667862018.867 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0004.lzma.bak 2022-11-07T23:00:18.867Z,1667862018.867 [DataOverHttps](INFO): SBD MOMSN=17270911 2022-11-07T23:00:20.832Z,1667862020.832 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230019.00,A,3648.17540,N,12147.28627,W,0.019,0.00,071122,,,D*79 2022-11-07T23:00:20.835Z,1667862020.835 [NAL9602](INFO): GPS fix at 20221107T230019: (36.802923, -121.788105) 2022-11-07T23:00:24.041Z,1667862024.041 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230022.00,A,3648.17540,N,12147.28632,W,0.039,0.00,071122,,,D*77 2022-11-07T23:00:24.043Z,1667862024.043 [NAL9602](INFO): GPS fix at 20221107T230022: (36.802923, -121.788105) 2022-11-07T23:00:26.879Z,1667862026.879 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230025.00,A,3648.17543,N,12147.28631,W,0.019,0.00,071122,,,D*72 2022-11-07T23:00:26.882Z,1667862026.882 [NAL9602](INFO): GPS fix at 20221107T230025: (36.802924, -121.788105) 2022-11-07T23:00:29.194Z,1667862029.194 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:00:30.108Z,1667862030.108 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230028.00,A,3648.17552,N,12147.28628,W,0.078,0.00,071122,,,D*70 2022-11-07T23:00:30.114Z,1667862030.114 [NAL9602](INFO): GPS fix at 20221107T230028: (36.802925, -121.788105) 2022-11-07T23:00:30.191Z,1667862030.191 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:00:30.194Z,1667862030.194 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:00:33.051Z,1667862033.051 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230031.00,A,3648.17557,N,12147.28628,W,0.039,0.00,071122,,,D*78 2022-11-07T23:00:33.059Z,1667862033.059 [NAL9602](INFO): GPS fix at 20221107T230031: (36.802926, -121.788105) 2022-11-07T23:00:33.470Z,1667862033.470 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:00:36.129Z,1667862036.129 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221107T225542/Courier0007.lzma 2022-11-07T23:00:36.166Z,1667862036.166 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230034.00,A,3648.17563,N,12147.28626,W,0.058,0.00,071122,,,D*73 2022-11-07T23:00:36.168Z,1667862036.168 [NAL9602](INFO): GPS fix at 20221107T230034: (36.802927, -121.788104) 2022-11-07T23:00:37.131Z,1667862037.131 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0007.lzma.bak 2022-11-07T23:00:37.131Z,1667862037.131 [DataOverHttps](INFO): SBD MOMSN=17270916 2022-11-07T23:00:38.988Z,1667862038.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230037.00,A,3648.17564,N,12147.28625,W,0.078,0.00,071122,,,D*76 2022-11-07T23:00:38.990Z,1667862038.990 [NAL9602](INFO): GPS fix at 20221107T230037: (36.802927, -121.788104) 2022-11-07T23:00:42.220Z,1667862042.220 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230040.00,A,3648.17560,N,12147.28625,W,0.058,0.00,071122,,,D*70 2022-11-07T23:00:42.223Z,1667862042.223 [NAL9602](INFO): GPS fix at 20221107T230040: (36.802927, -121.788104) 2022-11-07T23:00:44.562Z,1667862044.562 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:00:45.048Z,1667862045.048 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230043.00,A,3648.17561,N,12147.28629,W,0.097,0.00,071122,,,D*7D 2022-11-07T23:00:45.050Z,1667862045.050 [NAL9602](INFO): GPS fix at 20221107T230043: (36.802927, -121.788105) 2022-11-07T23:00:46.993Z,1667862046.993 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:00:46.995Z,1667862046.995 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:00:47.893Z,1667862047.893 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230046.00,A,3648.17554,N,12147.28635,W,0.039,0.00,071122,,,D*77 2022-11-07T23:00:47.895Z,1667862047.895 [NAL9602](INFO): GPS fix at 20221107T230046: (36.802926, -121.788106) 2022-11-07T23:00:50.270Z,1667862050.270 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:00:51.126Z,1667862051.126 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230049.00,A,3648.17554,N,12147.28637,W,0.039,0.00,071122,,,D*7A 2022-11-07T23:00:51.129Z,1667862051.129 [NAL9602](INFO): GPS fix at 20221107T230049: (36.802926, -121.788106) 2022-11-07T23:00:53.299Z,1667862053.299 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 1 Latitude: 36.802925 Longitude: -121.788109 2022-11-07T23:00:53.633Z,1667862053.633 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active. 2022-11-07T23:00:53.968Z,1667862053.968 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230052.00,A,3648.17562,N,12147.28640,W,0.019,0.00,071122,,,D*77 2022-11-07T23:00:53.976Z,1667862053.976 [NAL9602](INFO): GPS fix at 20221107T230052: (36.802927, -121.788107) 2022-11-07T23:00:54.061Z,1667862054.061 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2022-11-07T23:00:54.062Z,1667862054.062 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2022-11-07T23:00:54.062Z,1667862054.062 [IBIT](IMPORTANT): Pressure:8.842275 PSI 2022-11-07T23:00:54.062Z,1667862054.062 [IBIT](IMPORTANT): Humidity:20.540838 % 2022-11-07T23:00:54.433Z,1667862054.433 [IBIT](IMPORTANT): Vehicle Pitch:-0.080094 degrees 2022-11-07T23:00:54.434Z,1667862054.434 [IBIT](IMPORTANT): Vehicle Roll:-0.017952 degrees 2022-11-07T23:00:54.434Z,1667862054.434 [IBIT](IMPORTANT): Vehicle Heading:110.049797 degrees 2022-11-07T23:00:54.826Z,1667862054.826 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2022-11-07T23:00:54.827Z,1667862054.827 [IBIT](IMPORTANT): buoyancyNeutral: 210.367111 cc 2022-11-07T23:00:54.827Z,1667862054.827 [IBIT](IMPORTANT): massDefault: 2.233386 cm 2022-11-07T23:00:54.827Z,1667862054.827 [IBIT](IMPORTANT): stopDepth: 290.000000 m 2022-11-07T23:00:54.827Z,1667862054.827 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2022-11-07T23:00:54.827Z,1667862054.827 [IBIT](IMPORTANT): IBIT PASSED 2022-11-07T23:00:55.179Z,1667862055.179 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:00:55.179Z,1667862055.179 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:00:55.180Z,1667862055.180 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:00:57.192Z,1667862057.192 [DataOverHttps](INFO): Sending 1093 bytes from file Logs/20221102T171727/Express0001.lzma 2022-11-07T23:00:58.191Z,1667862058.191 [DataOverHttps](INFO): Moved sent file to Logs/20221102T171727/Express0001.lzma.bak 2022-11-07T23:00:58.191Z,1667862058.191 [DataOverHttps](INFO): SBD MOMSN=17270922 2022-11-07T23:01:01.374Z,1667862061.374 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:01:01.374Z,1667862061.374 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:01:01.626Z,1667862061.626 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:01:01.878Z,1667862061.878 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:01:02.130Z,1667862062.130 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:01:05.406Z,1667862065.406 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:01:16.514Z,1667862076.514 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:01:16.766Z,1667862076.766 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:01:17.018Z,1667862077.018 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:01:20.315Z,1667862080.315 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:01:26.745Z,1667862086.745 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:01:31.406Z,1667862091.406 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:01:31.658Z,1667862091.658 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:01:31.914Z,1667862091.914 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:01:35.191Z,1667862095.191 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:01:46.310Z,1667862106.310 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:01:46.565Z,1667862106.565 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:01:46.818Z,1667862106.818 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:01:50.119Z,1667862110.119 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:02:01.210Z,1667862121.210 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:02:01.210Z,1667862121.210 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:02:01.463Z,1667862121.463 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:02:01.714Z,1667862121.714 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:02:01.966Z,1667862121.966 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:02:05.244Z,1667862125.244 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:02:16.338Z,1667862136.338 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:02:16.590Z,1667862136.590 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:02:16.842Z,1667862136.842 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:02:20.123Z,1667862140.123 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:02:31.214Z,1667862151.214 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:02:31.466Z,1667862151.466 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:02:31.718Z,1667862151.718 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:02:34.994Z,1667862154.994 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:02:46.102Z,1667862166.102 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:02:46.354Z,1667862166.354 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:02:46.606Z,1667862166.606 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:02:49.886Z,1667862169.886 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:02:54.352Z,1667862174.352 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2022-11-07T23:02:54.355Z,1667862174.355 [BPC1](INFO): Received data from all battery sticks. 2022-11-07T23:03:00.978Z,1667862180.978 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:03:00.978Z,1667862180.978 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:03:01.230Z,1667862181.230 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:03:01.482Z,1667862181.482 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:03:01.734Z,1667862181.734 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:03:05.010Z,1667862185.010 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:03:16.098Z,1667862196.098 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:03:16.350Z,1667862196.350 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:03:16.602Z,1667862196.602 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:03:19.887Z,1667862199.887 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:03:30.978Z,1667862210.978 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:03:31.230Z,1667862211.230 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:03:31.482Z,1667862211.482 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:03:34.759Z,1667862214.759 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:03:45.858Z,1667862225.858 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:03:46.122Z,1667862226.122 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:03:46.374Z,1667862226.374 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:03:49.651Z,1667862229.651 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:04:00.754Z,1667862240.754 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:04:00.754Z,1667862240.754 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:04:01.006Z,1667862241.006 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:04:01.258Z,1667862241.258 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:04:01.510Z,1667862241.510 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:04:04.786Z,1667862244.786 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:04:15.874Z,1667862255.874 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:04:16.126Z,1667862256.126 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:04:16.378Z,1667862256.378 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:04:19.655Z,1667862259.655 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:04:30.754Z,1667862270.754 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:04:31.006Z,1667862271.006 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:04:31.258Z,1667862271.258 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:04:34.550Z,1667862274.550 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:04:45.646Z,1667862285.646 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:04:45.898Z,1667862285.898 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:04:46.150Z,1667862286.150 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:04:49.426Z,1667862289.426 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:05:00.514Z,1667862300.514 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:05:00.514Z,1667862300.514 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:05:00.766Z,1667862300.766 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:05:55.840Z,1667862355.840 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:05:55.840Z,1667862355.840 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:05:55.840Z,1667862355.840 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:05:55.840Z,1667862355.840 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:05:56.252Z,1667862356.252 [Default:CheckIn:D] Stopped 2022-11-07T23:05:56.252Z,1667862356.252 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:05:56.661Z,1667862356.661 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.509167 min 2022-11-07T23:05:56.661Z,1667862356.661 [Default:CheckIn:E] Stopped 2022-11-07T23:05:56.661Z,1667862356.661 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:05:56.661Z,1667862356.661 [Default:CheckIn] Stopped 2022-11-07T23:05:56.661Z,1667862356.661 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:05:56.661Z,1667862356.661 [Default:CheckIn](INFO): Running loop #2 2022-11-07T23:05:56.661Z,1667862356.661 [Default:CheckIn] Running Loop=2 2022-11-07T23:05:56.662Z,1667862356.662 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:05:56.662Z,1667862356.662 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:05:58.660Z,1667862358.660 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230557.00,A,3648.17460,N,12147.28707,W,0.058,0.00,071122,,,D*73 2022-11-07T23:05:58.663Z,1667862358.663 [NAL9602](INFO): GPS fix at 20221107T230557: (36.802910, -121.788118) 2022-11-07T23:05:58.708Z,1667862358.708 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:05:58.708Z,1667862358.708 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:06:01.820Z,1667862361.820 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:06:01.830Z,1667862361.830 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:06:05.107Z,1667862365.107 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:06:08.605Z,1667862368.605 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20221107T225542/Courier0010.lzma 2022-11-07T23:06:09.607Z,1667862369.607 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0010.lzma.bak 2022-11-07T23:06:09.607Z,1667862369.607 [DataOverHttps](INFO): SBD MOMSN=17270966 2022-11-07T23:06:21.238Z,1667862381.238 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:06:22.380Z,1667862382.380 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:06:22.390Z,1667862382.390 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:06:22.745Z,1667862382.745 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:06:22.746Z,1667862382.746 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:06:22.746Z,1667862382.746 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:06:24.743Z,1667862384.743 [NAL9602](INFO): SBD MO Status=1, MOMSN=9050, MT Status=0, MTMSN=0 2022-11-07T23:06:24.743Z,1667862384.743 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:06:25.666Z,1667862385.666 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:06:27.479Z,1667862387.479 [DataOverHttps](INFO): Sending 626 bytes from file Logs/20221102T171727/Express0005.lzma 2022-11-07T23:06:28.479Z,1667862388.479 [DataOverHttps](INFO): Moved sent file to Logs/20221102T171727/Express0005.lzma.bak 2022-11-07T23:06:28.479Z,1667862388.479 [DataOverHttps](INFO): SBD MOMSN=17270972 2022-11-07T23:06:41.826Z,1667862401.826 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:06:42.078Z,1667862402.078 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:06:42.330Z,1667862402.330 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:06:45.607Z,1667862405.607 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:06:55.439Z,1667862415.439 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:07:01.738Z,1667862421.738 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:07:01.990Z,1667862421.990 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:07:02.242Z,1667862422.242 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:07:05.522Z,1667862425.522 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:07:21.658Z,1667862441.658 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:07:21.658Z,1667862441.658 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:07:21.910Z,1667862441.910 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:10:55.838Z,1667862655.838 [CBIT](INFO): Clearing failed state for component DropWeight 2022-11-07T23:10:55.838Z,1667862655.838 [DropWeight] No Fault, FailCount= 1 2022-11-07T23:11:23.303Z,1667862683.303 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:11:23.303Z,1667862683.303 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:11:23.303Z,1667862683.303 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:11:23.304Z,1667862683.304 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:11:23.711Z,1667862683.711 [Default:CheckIn:D] Stopped 2022-11-07T23:11:23.711Z,1667862683.711 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.966811 min 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn:E] Stopped 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn] Stopped 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn](INFO): Running loop #3 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn] Running Loop=3 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:11:24.134Z,1667862684.134 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:11:26.123Z,1667862686.123 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231125.00,A,3648.17485,N,12147.28736,W,0.039,0.00,071122,,,D*7D 2022-11-07T23:11:26.125Z,1667862686.125 [NAL9602](INFO): GPS fix at 20221107T231125: (36.802914, -121.788123) 2022-11-07T23:11:26.137Z,1667862686.137 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:11:26.137Z,1667862686.137 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:11:28.229Z,1667862688.229 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:11:28.231Z,1667862688.231 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:11:31.509Z,1667862691.509 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:11:35.253Z,1667862695.253 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221107T225542/Courier0013.lzma 2022-11-07T23:11:36.255Z,1667862696.255 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0013.lzma.bak 2022-11-07T23:11:36.255Z,1667862696.255 [DataOverHttps](INFO): SBD MOMSN=17271082 2022-11-07T23:11:42.930Z,1667862702.930 [CommandExec](IMPORTANT): got command failComponent 2022-11-07T23:11:42.930Z,1667862702.930 [CommandExec](IMPORTANT): Failed components: 2022-11-07T23:11:42.930Z,1667862702.930 [CommandExec](IMPORTANT): No failed Components. 2022-11-07T23:11:43.602Z,1667862703.602 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:11:45.345Z,1667862705.345 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:11:45.347Z,1667862705.347 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:11:45.347Z,1667862705.347 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:11:45.347Z,1667862705.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:11:45.366Z,1667862705.366 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:11:46.678Z,1667862706.678 [CommandExec](IMPORTANT): got command failComponent 2022-11-07T23:11:46.678Z,1667862706.678 [CommandExec](IMPORTANT): Failed components: 2022-11-07T23:11:46.678Z,1667862706.678 [CommandExec](IMPORTANT): No failed Components. 2022-11-07T23:11:48.652Z,1667862708.652 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:11:56.547Z,1667862716.547 [CommandExec](IMPORTANT): got command get DropWeight.loadAtStartup 2022-11-07T23:11:56.548Z,1667862716.548 [CommandExec](IMPORTANT): DropWeight.loadAtStartup 1 bool 2022-11-07T23:12:00.736Z,1667862720.736 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221102T173055/Express0001.lzma 2022-11-07T23:12:00.826Z,1667862720.826 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:12:01.078Z,1667862721.078 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:12:01.330Z,1667862721.330 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:12:01.739Z,1667862721.739 [DataOverHttps](INFO): Moved sent file to Logs/20221102T173055/Express0001.lzma.bak 2022-11-07T23:12:01.739Z,1667862721.739 [DataOverHttps](INFO): SBD MOMSN=17271092 2022-11-07T23:12:04.618Z,1667862724.618 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:12:14.363Z,1667862734.363 [CommandExec](IMPORTANT): got command report mod NAL9602.sigQuality 2022-11-07T23:12:14.525Z,1667862734.525 [Reporter](INFO): NAL9602.sigQuality 2 count 2022-11-07T23:12:16.726Z,1667862736.726 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:12:16.978Z,1667862736.978 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:12:17.230Z,1667862737.230 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:12:20.506Z,1667862740.506 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:12:24.575Z,1667862744.575 [NAL9602](INFO): SBD MO Status=1, MOMSN=9051, MT Status=0, MTMSN=0 2022-11-07T23:12:24.575Z,1667862744.575 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:12:32.610Z,1667862752.610 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:12:32.610Z,1667862752.610 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:12:32.862Z,1667862752.862 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:12:36.218Z,1667862756.218 [CommandExec](IMPORTANT): got command ibit 2022-11-07T23:12:36.326Z,1667862756.326 [IBIT](IMPORTANT): Beginning Initiated BIT 2022-11-07T23:12:36.327Z,1667862756.327 [IBIT](IMPORTANT): Beginning control surface checks. 2022-11-07T23:12:36.330Z,1667862756.330 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-07T23:12:37.916Z,1667862757.916 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231237.00,A,3648.17562,N,12147.28657,W,0.019,0.00,071122,,,D*71 2022-11-07T23:12:37.930Z,1667862757.930 [NAL9602](INFO): GPS fix at 20221107T231237: (36.802927, -121.788110) 2022-11-07T23:12:41.143Z,1667862761.143 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231240.00,A,3648.17566,N,12147.28655,W,0.058,0.00,071122,,,D*72 2022-11-07T23:12:41.158Z,1667862761.158 [NAL9602](INFO): GPS fix at 20221107T231240: (36.802928, -121.788109) 2022-11-07T23:12:43.970Z,1667862763.970 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231243.00,A,3648.17570,N,12147.28654,W,0.039,0.00,071122,,,D*70 2022-11-07T23:12:43.973Z,1667862763.973 [NAL9602](INFO): GPS fix at 20221107T231243: (36.802928, -121.788109) 2022-11-07T23:12:47.206Z,1667862767.206 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231246.00,A,3648.17580,N,12147.28650,W,0.000,0.00,071122,,,D*74 2022-11-07T23:12:47.208Z,1667862767.208 [NAL9602](INFO): GPS fix at 20221107T231246: (36.802930, -121.788108) 2022-11-07T23:12:47.233Z,1667862767.233 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006359 CHAN A1 (24V): 0.000716 CHAN A2 (12V): -0.005414 CHAN A3 (5V): -0.002457 CHAN B0 (3.3V): -0.001488 CHAN B1 (3.15aV): -0.002200 CHAN B2 (3.15bV): -0.001471 CHAN B3 (GND): -0.000581 OPEN: 0.004843 Full Scale: +/- 1 mA 2022-11-07T23:12:50.028Z,1667862770.028 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231249.00,A,3648.17588,N,12147.28650,W,0.019,0.00,071122,,,D*7B 2022-11-07T23:12:50.031Z,1667862770.031 [NAL9602](INFO): GPS fix at 20221107T231249: (36.802931, -121.788108) 2022-11-07T23:12:52.860Z,1667862772.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231252.00,A,3648.17589,N,12147.28654,W,0.039,0.00,071122,,,D*76 2022-11-07T23:12:52.862Z,1667862772.862 [NAL9602](INFO): GPS fix at 20221107T231252: (36.802931, -121.788109) 2022-11-07T23:12:56.091Z,1667862776.091 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231255.00,A,3648.17588,N,12147.28661,W,0.039,0.00,071122,,,D*76 2022-11-07T23:12:56.093Z,1667862776.093 [NAL9602](INFO): GPS fix at 20221107T231255: (36.802931, -121.788110) 2022-11-07T23:12:58.919Z,1667862778.919 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231258.00,A,3648.17590,N,12147.28665,W,0.000,0.00,071122,,,D*7C 2022-11-07T23:12:58.922Z,1667862778.922 [NAL9602](INFO): GPS fix at 20221107T231258: (36.802932, -121.788111) 2022-11-07T23:13:02.148Z,1667862782.148 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231301.00,A,3648.17587,N,12147.28666,W,0.019,0.00,071122,,,D*7C 2022-11-07T23:13:02.150Z,1667862782.150 [NAL9602](INFO): GPS fix at 20221107T231301: (36.802931, -121.788111) 2022-11-07T23:13:04.999Z,1667862784.999 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231304.00,A,3648.17586,N,12147.28670,W,0.000,0.00,071122,,,D*77 2022-11-07T23:13:05.005Z,1667862785.005 [NAL9602](INFO): GPS fix at 20221107T231304: (36.802931, -121.788112) 2022-11-07T23:13:08.207Z,1667862788.207 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231307.00,A,3648.17586,N,12147.28677,W,0.078,0.00,071122,,,D*7C 2022-11-07T23:13:08.221Z,1667862788.221 [NAL9602](INFO): GPS fix at 20221107T231307: (36.802931, -121.788113) 2022-11-07T23:13:11.037Z,1667862791.037 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231310.00,A,3648.17585,N,12147.28683,W,0.019,0.00,071122,,,D*75 2022-11-07T23:13:11.040Z,1667862791.040 [NAL9602](INFO): GPS fix at 20221107T231310: (36.802931, -121.788114) 2022-11-07T23:13:13.895Z,1667862793.895 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231313.00,A,3648.17581,N,12147.28684,W,0.058,0.00,071122,,,D*70 2022-11-07T23:13:13.897Z,1667862793.897 [NAL9602](INFO): GPS fix at 20221107T231313: (36.802930, -121.788114) 2022-11-07T23:13:17.096Z,1667862797.096 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231316.00,A,3648.17582,N,12147.28688,W,0.039,0.00,071122,,,D*7D 2022-11-07T23:13:17.098Z,1667862797.098 [NAL9602](INFO): GPS fix at 20221107T231316: (36.802930, -121.788115) 2022-11-07T23:13:19.931Z,1667862799.931 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231319.00,A,3648.17578,N,12147.28689,W,0.019,0.00,071122,,,D*74 2022-11-07T23:13:19.933Z,1667862799.933 [NAL9602](INFO): GPS fix at 20221107T231319: (36.802930, -121.788115) 2022-11-07T23:13:22.795Z,1667862802.795 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 2 Latitude: 36.802929 Longitude: -121.788116 2022-11-07T23:13:23.160Z,1667862803.160 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231322.00,A,3648.17578,N,12147.28689,W,0.039,0.00,071122,,,D*7E 2022-11-07T23:13:23.163Z,1667862803.163 [NAL9602](INFO): GPS fix at 20221107T231322: (36.802930, -121.788115) 2022-11-07T23:13:23.206Z,1667862803.206 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.334000 2022-11-07T23:13:23.207Z,1667862803.207 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2022-11-07T23:13:23.207Z,1667862803.207 [IBIT](IMPORTANT): batteryVoltageThreshold: 11.000000 V 2022-11-07T23:13:23.614Z,1667862803.614 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2022-11-07T23:13:23.614Z,1667862803.614 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2022-11-07T23:13:23.614Z,1667862803.614 [IBIT](IMPORTANT): Pressure:8.803712 PSI 2022-11-07T23:13:23.614Z,1667862803.614 [IBIT](IMPORTANT): Humidity:20.876572 % 2022-11-07T23:13:23.993Z,1667862803.993 [IBIT](IMPORTANT): Vehicle Pitch:-0.090783 degrees 2022-11-07T23:13:23.994Z,1667862803.994 [IBIT](IMPORTANT): Vehicle Roll:-0.022663 degrees 2022-11-07T23:13:23.994Z,1667862803.994 [IBIT](IMPORTANT): Vehicle Heading:110.057091 degrees 2022-11-07T23:13:24.425Z,1667862804.425 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2022-11-07T23:13:24.425Z,1667862804.425 [IBIT](IMPORTANT): buoyancyNeutral: 210.367111 cc 2022-11-07T23:13:24.426Z,1667862804.426 [IBIT](IMPORTANT): massDefault: 2.233386 cm 2022-11-07T23:13:24.426Z,1667862804.426 [IBIT](IMPORTANT): stopDepth: 290.000000 m 2022-11-07T23:13:24.426Z,1667862804.426 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2022-11-07T23:13:24.426Z,1667862804.426 [IBIT](IMPORTANT): IBIT PASSED 2022-11-07T23:13:55.508Z,1667862835.508 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:13:55.610Z,1667862835.610 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:16:46.016Z,1667863006.016 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:16:46.016Z,1667863006.016 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:16:46.017Z,1667863006.017 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:16:46.017Z,1667863006.017 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:16:46.402Z,1667863006.402 [Default:CheckIn:D] Stopped 2022-11-07T23:16:46.402Z,1667863006.402 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:16:46.807Z,1667863006.807 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.344995 min 2022-11-07T23:16:46.807Z,1667863006.807 [Default:CheckIn:E] Stopped 2022-11-07T23:16:46.807Z,1667863006.807 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:16:46.807Z,1667863006.807 [Default:CheckIn] Stopped 2022-11-07T23:16:46.807Z,1667863006.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:16:46.808Z,1667863006.808 [Default:CheckIn](INFO): Running loop #4 2022-11-07T23:16:46.808Z,1667863006.808 [Default:CheckIn] Running Loop=4 2022-11-07T23:16:46.808Z,1667863006.808 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:16:46.808Z,1667863006.808 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:16:48.815Z,1667863008.815 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231648.00,A,3648.17602,N,12147.28673,W,0.000,0.00,071122,,,D*76 2022-11-07T23:16:48.830Z,1667863008.830 [NAL9602](INFO): GPS fix at 20221107T231648: (36.802934, -121.788112) 2022-11-07T23:16:48.844Z,1667863008.844 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:16:48.844Z,1667863008.844 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:16:50.998Z,1667863010.998 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:16:50.000Z,1667863011.000 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:16:54.275Z,1667863014.275 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:16:57.622Z,1667863017.622 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221107T225542/Courier0016.lzma 2022-11-07T23:16:58.492Z,1667863018.492 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-11-07T23:16:58.619Z,1667863018.619 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0016.lzma.bak 2022-11-07T23:16:58.619Z,1667863018.619 [DataOverHttps](INFO): SBD MOMSN=17271112 2022-11-07T23:17:02.526Z,1667863022.526 [Reporter](INFO): NAL9602.sigQuality 3 count 2022-11-07T23:17:06.370Z,1667863026.370 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:17:07.476Z,1667863027.476 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:17:07.478Z,1667863027.478 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:17:07.750Z,1667863027.750 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:17:07.751Z,1667863027.751 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:17:07.751Z,1667863027.751 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:17:10.755Z,1667863030.755 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:17:13.776Z,1667863033.776 [NAL9602](INFO): SBD MO Status=1, MOMSN=9052, MT Status=0, MTMSN=0 2022-11-07T23:17:13.776Z,1667863033.776 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:17:16.103Z,1667863036.103 [DataOverHttps](INFO): Sending 1126 bytes from file Logs/20221102T173510/Express0001.lzma 2022-11-07T23:17:17.103Z,1667863037.103 [DataOverHttps](INFO): Moved sent file to Logs/20221102T173510/Express0001.lzma.bak 2022-11-07T23:17:17.103Z,1667863037.103 [DataOverHttps](INFO): SBD MOMSN=17271118 2022-11-07T23:17:22.850Z,1667863042.850 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:17:23.102Z,1667863043.102 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:17:23.354Z,1667863043.354 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:17:26.646Z,1667863046.646 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:17:38.742Z,1667863058.742 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:17:38.994Z,1667863058.994 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:17:39.246Z,1667863059.246 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:17:42.522Z,1667863062.522 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:17:44.477Z,1667863064.477 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:17:44.501Z,1667863064.501 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:17:54.638Z,1667863074.638 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:17:54.638Z,1667863074.638 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:17:54.890Z,1667863074.890 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:22:08.378Z,1667863328.378 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:22:08.378Z,1667863328.378 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:22:08.378Z,1667863328.378 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:22:08.378Z,1667863328.378 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:22:08.769Z,1667863328.769 [Default:CheckIn:D] Stopped 2022-11-07T23:22:08.769Z,1667863328.769 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:22:09.174Z,1667863329.174 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.717782 min 2022-11-07T23:22:09.174Z,1667863329.174 [Default:CheckIn:E] Stopped 2022-11-07T23:22:09.174Z,1667863329.174 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:22:09.174Z,1667863329.174 [Default:CheckIn] Stopped 2022-11-07T23:22:09.174Z,1667863329.174 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:22:09.175Z,1667863329.175 [Default:CheckIn](INFO): Running loop #5 2022-11-07T23:22:09.175Z,1667863329.175 [Default:CheckIn] Running Loop=5 2022-11-07T23:22:09.175Z,1667863329.175 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:22:09.175Z,1667863329.175 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:22:11.186Z,1667863331.186 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232210.00,A,3648.17563,N,12147.28673,W,0.058,0.00,071122,,,D*75 2022-11-07T23:22:11.188Z,1667863331.188 [NAL9602](INFO): GPS fix at 20221107T232210: (36.802927, -121.788112) 2022-11-07T23:22:11.200Z,1667863331.200 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:22:11.200Z,1667863331.200 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:22:13.135Z,1667863333.135 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:22:13.141Z,1667863333.141 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:22:16.427Z,1667863336.427 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:22:18.998Z,1667863338.998 [Reporter](INFO): NAL9602.sigQuality 3 count 2022-11-07T23:22:20.112Z,1667863340.112 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221107T225542/Courier0019.lzma 2022-11-07T23:22:21.115Z,1667863341.115 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0019.lzma.bak 2022-11-07T23:22:21.115Z,1667863341.115 [DataOverHttps](INFO): SBD MOMSN=17271321 2022-11-07T23:22:23.764Z,1667863343.764 [NAL9602](INFO): SBD MO Status=1, MOMSN=9053, MT Status=0, MTMSN=0 2022-11-07T23:22:23.764Z,1667863343.764 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:22:28.542Z,1667863348.542 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:22:29.754Z,1667863349.754 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:22:29.756Z,1667863349.756 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:22:29.860Z,1667863349.860 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:22:29.860Z,1667863349.860 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:22:29.860Z,1667863349.860 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:22:33.035Z,1667863353.035 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:22:38.648Z,1667863358.648 [DataOverHttps](INFO): Sending 1007 bytes from file Logs/20221102T173510/Express0005.lzma 2022-11-07T23:22:39.647Z,1667863359.647 [DataOverHttps](INFO): Moved sent file to Logs/20221102T173510/Express0005.lzma.bak 2022-11-07T23:22:39.647Z,1667863359.647 [DataOverHttps](INFO): SBD MOMSN=17271327 2022-11-07T23:22:45.130Z,1667863365.130 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:22:45.382Z,1667863365.382 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:22:45.634Z,1667863365.634 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:22:48.911Z,1667863368.911 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:22:54.466Z,1667863374.466 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:22:54.511Z,1667863374.511 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:23:01.022Z,1667863381.022 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:23:01.274Z,1667863381.274 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:23:01.526Z,1667863381.526 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:23:04.806Z,1667863384.806 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:23:16.906Z,1667863396.906 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:23:16.906Z,1667863396.906 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:23:17.158Z,1667863397.158 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:27:30.432Z,1667863650.432 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:27:30.432Z,1667863650.432 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:27:30.432Z,1667863650.432 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:27:30.432Z,1667863650.432 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:27:30.850Z,1667863650.850 [Default:CheckIn:D] Stopped 2022-11-07T23:27:30.850Z,1667863650.850 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:27:31.241Z,1667863651.241 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.085793 min 2022-11-07T23:27:31.241Z,1667863651.241 [Default:CheckIn:E] Stopped 2022-11-07T23:27:31.241Z,1667863651.241 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:27:31.241Z,1667863651.241 [Default:CheckIn] Stopped 2022-11-07T23:27:31.241Z,1667863651.241 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:27:31.242Z,1667863651.242 [Default:CheckIn](INFO): Running loop #6 2022-11-07T23:27:31.242Z,1667863651.242 [Default:CheckIn] Running Loop=6 2022-11-07T23:27:31.242Z,1667863651.242 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:27:31.242Z,1667863651.242 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:27:33.252Z,1667863653.252 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232732.00,A,3648.17726,N,12147.28567,W,0.019,0.00,071122,,,D*70 2022-11-07T23:27:33.254Z,1667863653.254 [NAL9602](INFO): GPS fix at 20221107T232732: (36.802954, -121.788094) 2022-11-07T23:27:33.266Z,1667863653.266 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:27:33.266Z,1667863653.266 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:27:35.455Z,1667863655.455 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:27:35.457Z,1667863655.457 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:27:38.735Z,1667863658.735 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:27:39.586Z,1667863659.586 [Reporter](INFO): NAL9602.sigQuality 2 count 2022-11-07T23:27:42.313Z,1667863662.313 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221107T225542/Courier0022.lzma 2022-11-07T23:27:43.315Z,1667863663.315 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0022.lzma.bak 2022-11-07T23:27:43.315Z,1667863663.315 [DataOverHttps](INFO): SBD MOMSN=17271453 2022-11-07T23:27:50.850Z,1667863670.850 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:27:53.951Z,1667863673.951 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:27:53.957Z,1667863673.957 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:27:54.241Z,1667863674.241 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:27:54.241Z,1667863674.241 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:27:54.245Z,1667863674.245 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:27:57.255Z,1667863677.255 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:27:57.388Z,1667863677.388 [NAL9602](INFO): SBD MO Status=1, MOMSN=9054, MT Status=0, MTMSN=0 2022-11-07T23:27:57.388Z,1667863677.388 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:28:06.343Z,1667863686.343 [DataOverHttps](INFO): Sending 1080 bytes from file Logs/20221102T175003/Express0001.lzma 2022-11-07T23:28:07.343Z,1667863687.343 [DataOverHttps](INFO): Moved sent file to Logs/20221102T175003/Express0001.lzma.bak 2022-11-07T23:28:07.343Z,1667863687.343 [DataOverHttps](INFO): SBD MOMSN=17271456 2022-11-07T23:28:09.350Z,1667863689.350 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:28:09.602Z,1667863689.602 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:28:09.854Z,1667863689.854 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:28:13.131Z,1667863693.131 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:28:25.246Z,1667863705.246 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:28:25.498Z,1667863705.498 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:28:25.750Z,1667863705.750 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:28:28.100Z,1667863708.100 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:28:28.128Z,1667863708.128 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:28:29.026Z,1667863709.026 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:28:41.122Z,1667863721.122 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:28:41.122Z,1667863721.122 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:28:41.374Z,1667863721.374 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:32:54.751Z,1667863974.751 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:32:54.752Z,1667863974.752 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:32:54.752Z,1667863974.752 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:32:54.752Z,1667863974.752 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:32:55.148Z,1667863975.148 [Default:CheckIn:D] Stopped 2022-11-07T23:32:55.148Z,1667863975.148 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:32:55.549Z,1667863975.549 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.490767 min 2022-11-07T23:32:55.549Z,1667863975.549 [Default:CheckIn:E] Stopped 2022-11-07T23:32:55.549Z,1667863975.549 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:32:55.549Z,1667863975.549 [Default:CheckIn] Stopped 2022-11-07T23:32:55.550Z,1667863975.550 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:32:55.550Z,1667863975.550 [Default:CheckIn](INFO): Running loop #7 2022-11-07T23:32:55.550Z,1667863975.550 [Default:CheckIn] Running Loop=7 2022-11-07T23:32:55.550Z,1667863975.550 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:32:55.550Z,1667863975.550 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:32:57.564Z,1667863977.564 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233256.00,A,3648.17585,N,12147.28593,W,0.019,0.00,071122,,,D*76 2022-11-07T23:32:57.567Z,1667863977.567 [NAL9602](INFO): GPS fix at 20221107T233256: (36.802931, -121.788099) 2022-11-07T23:32:57.579Z,1667863977.579 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:32:57.579Z,1667863977.579 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:32:59.477Z,1667863979.477 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:32:59.490Z,1667863979.490 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:33:01.671Z,1667863981.671 [Reporter](INFO): NAL9602.sigQuality 5 count 2022-11-07T23:33:02.766Z,1667863982.766 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:33:06.584Z,1667863986.584 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20221107T225542/Courier0025.lzma 2022-11-07T23:33:07.587Z,1667863987.587 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0025.lzma.bak 2022-11-07T23:33:07.587Z,1667863987.587 [DataOverHttps](INFO): SBD MOMSN=17271496 2022-11-07T23:33:11.702Z,1667863991.702 [NAL9602](INFO): SBD MO Status=1, MOMSN=9055, MT Status=0, MTMSN=0 2022-11-07T23:33:11.702Z,1667863991.702 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:33:14.862Z,1667863994.862 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:33:16.251Z,1667863996.251 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:33:16.253Z,1667863996.253 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:33:16.563Z,1667863996.563 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:33:16.563Z,1667863996.563 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:33:16.563Z,1667863996.563 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:33:19.530Z,1667863999.530 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:33:25.392Z,1667864005.392 [DataOverHttps](INFO): Sending 1449 bytes from file Logs/20221102T175003/Express0005.lzma 2022-11-07T23:33:26.391Z,1667864006.391 [DataOverHttps](INFO): Moved sent file to Logs/20221102T175003/Express0005.lzma.bak 2022-11-07T23:33:26.391Z,1667864006.391 [DataOverHttps](INFO): SBD MOMSN=17271499 2022-11-07T23:33:31.626Z,1667864011.626 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:33:31.878Z,1667864011.878 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:33:32.130Z,1667864012.130 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:33:35.407Z,1667864015.407 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:33:42.397Z,1667864022.397 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:33:42.465Z,1667864022.465 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:33:47.510Z,1667864027.510 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:33:47.762Z,1667864027.762 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:33:48.014Z,1667864028.014 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:33:51.294Z,1667864031.294 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:34:02.030Z,1667864042.030 [DataOverHttps](IMPORTANT): SBD MTMSN=20221107T233401 2022-11-07T23:34:03.390Z,1667864043.390 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:34:03.390Z,1667864043.390 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:34:03.642Z,1667864043.642 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:34:09.633Z,1667864049.633 [DataOverHttps](INFO): Received command: ibit 2022-11-07T23:34:09.662Z,1667864049.662 [CommandExec](IMPORTANT): got command ibit 2022-11-07T23:34:09.901Z,1667864049.901 [IBIT](IMPORTANT): Beginning Initiated BIT 2022-11-07T23:34:09.902Z,1667864049.902 [IBIT](IMPORTANT): Beginning control surface checks. 2022-11-07T23:34:09.905Z,1667864049.905 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-07T23:34:11.487Z,1667864051.487 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233410.00,A,3648.17563,N,12147.28596,W,0.019,0.00,071122,,,D*7F 2022-11-07T23:34:11.489Z,1667864051.489 [NAL9602](INFO): GPS fix at 20221107T233410: (36.802927, -121.788099) 2022-11-07T23:34:17.622Z,1667864057.622 [Reporter](INFO): NAL9602.sigQuality 2 count 2022-11-07T23:34:20.817Z,1667864060.817 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.006806 CHAN A1 (24V): 0.000705 CHAN A2 (12V): -0.005119 CHAN A3 (5V): -0.003055 CHAN B0 (3.3V): -0.000725 CHAN B1 (3.15aV): -0.001732 CHAN B2 (3.15bV): -0.001971 CHAN B3 (GND): -0.000516 OPEN: 0.004902 Full Scale: +/- 1 mA 2022-11-07T23:34:22.000Z,1667864062.000 [NAL9602](INFO): SBD MO Status=1, MOMSN=9056, MT Status=0, MTMSN=0 2022-11-07T23:34:22.000Z,1667864062.000 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:34:23.211Z,1667864063.211 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233422.00,A,3648.17567,N,12147.28606,W,0.039,0.00,071122,,,D*72 2022-11-07T23:34:23.214Z,1667864063.214 [NAL9602](INFO): GPS fix at 20221107T233422: (36.802928, -121.788101) 2022-11-07T23:34:26.035Z,1667864066.035 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233425.00,A,3648.17567,N,12147.28608,W,0.000,0.00,071122,,,D*71 2022-11-07T23:34:26.037Z,1667864066.037 [NAL9602](INFO): GPS fix at 20221107T233425: (36.802928, -121.788101) 2022-11-07T23:34:28.867Z,1667864068.867 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233428.00,A,3648.17566,N,12147.28610,W,0.039,0.00,071122,,,D*7E 2022-11-07T23:34:28.870Z,1667864068.870 [NAL9602](INFO): GPS fix at 20221107T233428: (36.802928, -121.788102) 2022-11-07T23:34:31.698Z,1667864071.698 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233431.00,A,3648.17560,N,12147.28613,W,0.019,0.00,071122,,,D*71 2022-11-07T23:34:31.700Z,1667864071.700 [NAL9602](INFO): GPS fix at 20221107T233431: (36.802927, -121.788102) 2022-11-07T23:34:34.949Z,1667864074.949 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233434.00,A,3648.17562,N,12147.28611,W,0.019,0.00,071122,,,D*74 2022-11-07T23:34:34.955Z,1667864074.955 [NAL9602](INFO): GPS fix at 20221107T233434: (36.802927, -121.788102) 2022-11-07T23:34:37.755Z,1667864077.755 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233437.00,A,3648.17568,N,12147.28610,W,0.019,0.00,071122,,,D*7C 2022-11-07T23:34:37.757Z,1667864077.757 [NAL9602](INFO): GPS fix at 20221107T233437: (36.802928, -121.788102) 2022-11-07T23:34:41.015Z,1667864081.015 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233440.00,A,3648.17571,N,12147.28614,W,0.019,0.00,071122,,,D*70 2022-11-07T23:34:41.022Z,1667864081.022 [NAL9602](INFO): GPS fix at 20221107T233440: (36.802929, -121.788102) 2022-11-07T23:34:43.812Z,1667864083.812 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233443.00,A,3648.17578,N,12147.28611,W,0.039,0.00,071122,,,D*7D 2022-11-07T23:34:43.815Z,1667864083.815 [NAL9602](INFO): GPS fix at 20221107T233443: (36.802930, -121.788102) 2022-11-07T23:34:47.043Z,1667864087.043 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233446.00,A,3648.17582,N,12147.28612,W,0.019,0.00,071122,,,D*7C 2022-11-07T23:34:47.045Z,1667864087.045 [NAL9602](INFO): GPS fix at 20221107T233446: (36.802930, -121.788102) 2022-11-07T23:34:49.871Z,1667864089.871 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233449.00,A,3648.17587,N,12147.28613,W,0.019,0.00,071122,,,D*77 2022-11-07T23:34:49.874Z,1667864089.874 [NAL9602](INFO): GPS fix at 20221107T233449: (36.802931, -121.788102) 2022-11-07T23:34:52.711Z,1667864092.711 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233452.00,A,3648.17588,N,12147.28613,W,0.039,0.00,071122,,,D*70 2022-11-07T23:34:52.713Z,1667864092.713 [NAL9602](INFO): GPS fix at 20221107T233452: (36.802931, -121.788102) 2022-11-07T23:34:55.982Z,1667864095.982 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233455.00,A,3648.17588,N,12147.28616,W,0.039,0.00,071122,,,D*72 2022-11-07T23:34:55.984Z,1667864095.984 [NAL9602](INFO): GPS fix at 20221107T233455: (36.802931, -121.788103) 2022-11-07T23:34:56.023Z,1667864096.023 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 2 Latitude: 36.802933 Longitude: -121.788101 2022-11-07T23:34:56.389Z,1667864096.389 [IBIT](IMPORTANT): Battery Status: Battery Charge (AH): 0.000000 Voltage: 16.334000 2022-11-07T23:34:56.390Z,1667864096.390 [IBIT](IMPORTANT): batteryCapacityThreshold: 5.000000 Ah 2022-11-07T23:34:56.390Z,1667864096.390 [IBIT](IMPORTANT): batteryVoltageThreshold: 11.000000 V 2022-11-07T23:34:56.767Z,1667864096.767 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2022-11-07T23:34:56.767Z,1667864096.767 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2022-11-07T23:34:56.767Z,1667864096.767 [IBIT](IMPORTANT): Pressure:8.807149 PSI 2022-11-07T23:34:56.768Z,1667864096.768 [IBIT](IMPORTANT): Humidity:20.846050 % 2022-11-07T23:34:57.176Z,1667864097.176 [IBIT](IMPORTANT): Vehicle Pitch:-0.092560 degrees 2022-11-07T23:34:57.176Z,1667864097.176 [IBIT](IMPORTANT): Vehicle Roll:-0.016437 degrees 2022-11-07T23:34:57.177Z,1667864097.177 [IBIT](IMPORTANT): Vehicle Heading:110.102158 degrees 2022-11-07T23:34:57.593Z,1667864097.593 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2022-11-07T23:34:57.594Z,1667864097.594 [IBIT](IMPORTANT): buoyancyNeutral: 210.367111 cc 2022-11-07T23:34:57.594Z,1667864097.594 [IBIT](IMPORTANT): massDefault: 2.233386 cm 2022-11-07T23:34:57.594Z,1667864097.594 [IBIT](IMPORTANT): stopDepth: 290.000000 m 2022-11-07T23:34:57.595Z,1667864097.595 [IBIT](IMPORTANT): abortDepth: 300.000000 m 2022-11-07T23:34:57.595Z,1667864097.595 [IBIT](IMPORTANT): IBIT PASSED 2022-11-07T23:35:28.250Z,1667864128.250 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:35:28.338Z,1667864128.338 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:38:17.196Z,1667864297.196 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:38:17.196Z,1667864297.196 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:38:17.196Z,1667864297.196 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:38:17.196Z,1667864297.196 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:38:17.608Z,1667864297.608 [Default:CheckIn:D] Stopped 2022-11-07T23:38:17.608Z,1667864297.608 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:38:17.983Z,1667864297.983 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 38.865100 min 2022-11-07T23:38:17.983Z,1667864297.983 [Default:CheckIn:E] Stopped 2022-11-07T23:38:17.983Z,1667864297.983 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:38:17.983Z,1667864297.983 [Default:CheckIn] Stopped 2022-11-07T23:38:17.983Z,1667864297.983 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:38:17.984Z,1667864297.984 [Default:CheckIn](INFO): Running loop #8 2022-11-07T23:38:17.984Z,1667864297.984 [Default:CheckIn] Running Loop=8 2022-11-07T23:38:17.984Z,1667864297.984 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:38:17.984Z,1667864297.984 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:38:19.991Z,1667864299.991 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233819.00,A,3648.17499,N,12147.28738,W,0.039,0.00,071122,,,D*7A 2022-11-07T23:38:20.005Z,1667864300.005 [NAL9602](INFO): GPS fix at 20221107T233819: (36.802917, -121.788123) 2022-11-07T23:38:20.018Z,1667864300.018 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:38:20.018Z,1667864300.018 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:38:22.138Z,1667864302.138 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:38:22.140Z,1667864302.140 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:38:25.419Z,1667864305.419 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:38:29.232Z,1667864309.232 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20221107T225542/Courier0028.lzma 2022-11-07T23:38:30.235Z,1667864310.235 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0028.lzma.bak 2022-11-07T23:38:30.235Z,1667864310.235 [DataOverHttps](INFO): SBD MOMSN=17271706 2022-11-07T23:38:30.543Z,1667864310.543 [Reporter](INFO): NAL9602.sigQuality 2 count 2022-11-07T23:38:37.514Z,1667864317.514 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:38:38.932Z,1667864318.932 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:38:38.934Z,1667864318.934 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:38:39.000Z,1667864319.000 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:38:39.000Z,1667864319.000 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:38:39.000Z,1667864319.000 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:38:40.187Z,1667864320.187 [NAL9602](INFO): SBD MO Status=1, MOMSN=9057, MT Status=0, MTMSN=0 2022-11-07T23:38:40.187Z,1667864320.187 [NAL9602](INFO): No messages in MT queue 2022-11-07T23:38:42.230Z,1667864322.230 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:38:48.194Z,1667864328.194 [DataOverHttps](INFO): Sending 397 bytes from file Logs/20221102T204552/Express0001.lzma 2022-11-07T23:38:49.195Z,1667864329.195 [DataOverHttps](INFO): Moved sent file to Logs/20221102T204552/Express0001.lzma.bak 2022-11-07T23:38:49.195Z,1667864329.195 [DataOverHttps](INFO): SBD MOMSN=17271709 2022-11-07T23:38:54.330Z,1667864334.330 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:38:54.582Z,1667864334.582 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:38:54.834Z,1667864334.834 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:38:58.110Z,1667864338.110 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:39:10.222Z,1667864350.222 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:39:10.474Z,1667864350.474 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:39:10.726Z,1667864350.726 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:39:10.889Z,1667864350.889 [NAL9602](INFO): Not Powering down - fast GPS 2022-11-07T23:39:10.936Z,1667864350.936 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:39:14.008Z,1667864354.008 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:39:26.118Z,1667864366.118 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:39:26.118Z,1667864366.118 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:39:26.370Z,1667864366.370 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:40:57.143Z,1667864457.143 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-11-07T23:40:57.143Z,1667864457.143 [DropWeight] Hardware Fault, FailCount= 1 2022-11-07T23:40:57.143Z,1667864457.143 [DropWeight](ERROR): Hardware Fault 2022-11-07T23:40:57.163Z,1667864457.163 [CBIT](INFO): Critical error at 20221107T234057 2022-11-07T23:40:57.165Z,1667864457.165 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-11-07T23:40:57.166Z,1667864457.166 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-11-07T23:40:57.578Z,1667864457.578 [CBIT](INFO): Critical error at 20221107T234057 2022-11-07T23:43:39.610Z,1667864619.610 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:43:39.611Z,1667864619.611 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:43:39.611Z,1667864619.611 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:43:39.611Z,1667864619.611 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:43:40.023Z,1667864620.023 [Default:CheckIn:D] Stopped 2022-11-07T23:43:40.023Z,1667864620.023 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:43:40.440Z,1667864620.440 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.238684 min 2022-11-07T23:43:40.440Z,1667864620.440 [Default:CheckIn:E] Stopped 2022-11-07T23:43:40.440Z,1667864620.440 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:43:40.441Z,1667864620.441 [Default:CheckIn] Stopped 2022-11-07T23:43:40.441Z,1667864620.441 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:43:40.441Z,1667864620.441 [Default:CheckIn](INFO): Running loop #9 2022-11-07T23:43:40.441Z,1667864620.441 [Default:CheckIn] Running Loop=9 2022-11-07T23:43:40.441Z,1667864620.441 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:43:40.441Z,1667864620.441 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:43:42.428Z,1667864622.428 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234341.00,A,3648.17363,N,12147.28730,W,0.039,0.00,071122,,,D*71 2022-11-07T23:43:42.439Z,1667864622.439 [NAL9602](INFO): GPS fix at 20221107T234341: (36.802894, -121.788122) 2022-11-07T23:43:42.475Z,1667864622.475 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:43:42.476Z,1667864622.476 [Default:CheckIn:Read_Iridium] Running Loop=1 2022-11-07T23:43:45.620Z,1667864625.620 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:43:45.634Z,1667864625.634 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:43:48.915Z,1667864628.915 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:43:53.327Z,1667864633.327 [Reporter](INFO): NAL9602.sigQuality 1 count 2022-11-07T23:43:55.774Z,1667864635.774 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20221107T225542/Courier0034.lzma 2022-11-07T23:43:56.775Z,1667864636.775 [DataOverHttps](INFO): Moved sent file to Logs/20221107T225542/Courier0034.lzma.bak 2022-11-07T23:43:56.775Z,1667864636.775 [DataOverHttps](INFO): SBD MOMSN=17271730 2022-11-07T23:43:57.330Z,1667864637.330 [Reporter](INFO): NAL9602.sigQuality 2 count 2022-11-07T23:44:03.030Z,1667864643.030 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:44:04.724Z,1667864644.724 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:44:04.730Z,1667864644.730 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:44:04.925Z,1667864644.925 [Default:CheckIn:Read_Iridium] Stopped 2022-11-07T23:44:04.925Z,1667864644.925 [Default:CheckIn:C.Wait] Running Loop=1 2022-11-07T23:44:04.929Z,1667864644.929 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2022-11-07T23:44:08.006Z,1667864648.006 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:44:12.978Z,1667864652.978 [NAL9602](INFO): SBD MO Status=2, MOMSN=9058, MT Status=2, MTMSN=0 2022-11-07T23:44:12.979Z,1667864652.979 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2022-11-07T23:44:15.040Z,1667864655.040 [DataOverHttps](INFO): Sending 1012 bytes from file Logs/20221102T204734/Express0001.lzma 2022-11-07T23:44:16.039Z,1667864656.039 [DataOverHttps](INFO): Moved sent file to Logs/20221102T204734/Express0001.lzma.bak 2022-11-07T23:44:16.039Z,1667864656.039 [DataOverHttps](INFO): SBD MOMSN=17271735 2022-11-07T23:44:17.502Z,1667864657.502 [Reporter](INFO): NAL9602.sigQuality 0 count 2022-11-07T23:44:22.122Z,1667864662.122 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:44:22.374Z,1667864662.374 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:44:22.626Z,1667864662.626 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:44:25.914Z,1667864665.914 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:44:40.033Z,1667864680.033 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:44:40.286Z,1667864680.286 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-07T23:44:40.538Z,1667864680.538 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-07T23:44:43.814Z,1667864683.814 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-07T23:44:57.934Z,1667864697.934 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2022-11-07T23:44:57.934Z,1667864697.934 [DAT](ERROR): Ack receipt timeout failure. 2022-11-07T23:44:58.186Z,1667864698.186 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2022-11-07T23:48:15.023Z,1667864895.023 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.384789 2022-11-07T23:48:25.832Z,1667864905.832 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003696 2022-11-07T23:48:45.467Z,1667864925.467 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2022-11-07T23:49:05.670Z,1667864945.670 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2022-11-07T23:49:05.670Z,1667864945.670 [Default:CheckIn:C.Wait] Stopped 2022-11-07T23:49:05.670Z,1667864945.670 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2022-11-07T23:49:05.670Z,1667864945.670 [Default:CheckIn:D] Running Loop=1 2022-11-07T23:49:06.071Z,1667864946.071 [Default:CheckIn:D] Stopped 2022-11-07T23:49:06.071Z,1667864946.071 [Default:CheckIn:E] Running Loop=1 2022-11-07T23:49:06.482Z,1667864946.482 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 49.672823 min 2022-11-07T23:49:06.482Z,1667864946.482 [Default:CheckIn:E] Stopped 2022-11-07T23:49:06.482Z,1667864946.482 [Default:CheckIn](INFO): Completed Default:CheckIn 2022-11-07T23:49:06.482Z,1667864946.482 [Default:CheckIn] Stopped 2022-11-07T23:49:06.482Z,1667864946.482 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:49:06.482Z,1667864946.482 [Default:CheckIn](INFO): Running loop #10 2022-11-07T23:49:06.482Z,1667864946.482 [Default:CheckIn] Running Loop=10 2022-11-07T23:49:06.483Z,1667864946.483 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-07T23:49:06.483Z,1667864946.483 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-07T23:49:20.088Z,1667864960.088 [CommandExec](IMPORTANT): got command report clear 2022-11-07T23:49:22.386Z,1667864962.386 [CommandExec](IMPORTANT): got command maintain clear 2022-11-07T23:49:24.251Z,1667864964.251 [CommandExec](IMPORTANT): got command quit 2022-11-07T23:49:25.255Z,1667864965.255 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:25.255Z,1667864965.255 [CommandExec](INFO): Uninitializing the command executive. 2022-11-07T23:49:25.255Z,1667864965.255 [CommandExec](INFO): Uninitializing the command scheduler. 2022-11-07T23:49:25.255Z,1667864965.255 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.314Z,1667864965.314 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-11-07T23:49:25.315Z,1667864965.315 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-11-07T23:49:25.315Z,1667864965.315 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.315Z,1667864965.315 [NavChartDb](INFO): Join timeout helper Thread ID is 1134 2022-11-07T23:49:25.547Z,1667864965.547 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:25.547Z,1667864965.547 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.567Z,1667864965.567 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-11-07T23:49:25.567Z,1667864965.567 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.567Z,1667864965.567 [DAT](INFO): Join timeout helper Thread ID is 1135 2022-11-07T23:49:25.720Z,1667864965.720 [DAT](INFO): Powering down 2022-11-07T23:49:25.795Z,1667864965.795 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:25.795Z,1667864965.795 [DAT](INFO): Powering down 2022-11-07T23:49:25.796Z,1667864965.796 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.807Z,1667864965.807 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-11-07T23:49:25.807Z,1667864965.807 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.807Z,1667864965.807 [Radio_Surface](INFO): Join timeout helper Thread ID is 1136 2022-11-07T23:49:25.987Z,1667864965.987 [Radio_Surface](INFO): Powering down 2022-11-07T23:49:25.988Z,1667864965.988 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:25.988Z,1667864965.988 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.995Z,1667864965.995 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2022-11-07T23:49:25.995Z,1667864965.995 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:25.995Z,1667864965.995 [Onboard](INFO): Join timeout helper Thread ID is 1137 2022-11-07T23:49:26.651Z,1667864966.651 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2022-11-07T23:49:26.851Z,1667864966.851 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:26.851Z,1667864966.851 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:26.863Z,1667864966.863 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2022-11-07T23:49:26.863Z,1667864966.863 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:26.863Z,1667864966.863 [DataOverHttps](INFO): Join timeout helper Thread ID is 1138 2022-11-07T23:49:27.655Z,1667864967.655 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:27.655Z,1667864967.655 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.663Z,1667864967.663 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2022-11-07T23:49:27.664Z,1667864967.664 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.664Z,1667864967.664 [BackseatComponent](INFO): Join timeout helper Thread ID is 1139 2022-11-07T23:49:27.716Z,1667864967.716 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:27.716Z,1667864967.716 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.719Z,1667864967.719 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2022-11-07T23:49:27.720Z,1667864967.720 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.720Z,1667864967.720 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1140 2022-11-07T23:49:27.899Z,1667864967.899 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:27.899Z,1667864967.899 [WetLabsBB2FL](INFO): Powering down 2022-11-07T23:49:27.900Z,1667864967.900 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.911Z,1667864967.911 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2022-11-07T23:49:27.911Z,1667864967.911 [logger ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.912Z,1667864967.912 [logger](INFO): Join timeout helper Thread ID is 1141 2022-11-07T23:49:27.954Z,1667864967.954 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:27.954Z,1667864967.954 [logger ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.960Z,1667864967.960 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2022-11-07T23:49:27.960Z,1667864967.960 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.960Z,1667864967.960 [CommandLine](INFO): Join timeout helper Thread ID is 1142 2022-11-07T23:49:27.975Z,1667864967.975 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:27.976Z,1667864967.976 [CommandLine ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.979Z,1667864967.979 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2022-11-07T23:49:27.979Z,1667864967.979 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.980Z,1667864967.980 [CommandExec](INFO): Join timeout helper Thread ID is 1143 2022-11-07T23:49:27.981Z,1667864967.981 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2022-11-07T23:49:27.981Z,1667864967.981 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:27.982Z,1667864967.982 [controlThread](INFO): Join timeout helper Thread ID is 1144 2022-11-07T23:49:28.259Z,1667864968.259 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-07T23:49:28.259Z,1667864968.259 [controlThread](DEBUG): Uninitializing ControlThread 2022-11-07T23:49:28.260Z,1667864968.260 [AHRS_M2](INFO): Powering down 2022-11-07T23:49:28.571Z,1667864968.571 [MultiRay](INFO): Powering down. 2022-11-07T23:49:28.572Z,1667864968.572 [NAL9602](INFO): Powering down 2022-11-07T23:49:28.573Z,1667864968.573 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2022-11-07T23:49:28.574Z,1667864968.574 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2022-11-07T23:49:28.575Z,1667864968.575 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2022-11-07T23:49:28.576Z,1667864968.576 [MissionManager](INFO): Uninitializing Mission Default 2022-11-07T23:49:28.576Z,1667864968.576 [Default] Stopped 2022-11-07T23:49:28.576Z,1667864968.576 [Default](DEBUG): Aggregate::uninitialize Default 2022-11-07T23:49:28.576Z,1667864968.576 [Default:B.GoToSurface] Stopped 2022-11-07T23:49:28.576Z,1667864968.576 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-07T23:49:28.576Z,1667864968.576 [Default:CheckIn] Stopped 2022-11-07T23:49:28.576Z,1667864968.576 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2022-11-07T23:49:28.576Z,1667864968.576 [Default:CheckIn:Read_GPS] Stopped 2022-11-07T23:49:28.579Z,1667864968.579 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2022-11-07T23:49:28.579Z,1667864968.579 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2022-11-07T23:49:28.580Z,1667864968.580 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2022-11-07T23:49:28.580Z,1667864968.580 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2022-11-07T23:49:28.580Z,1667864968.580 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2022-11-07T23:49:28.580Z,1667864968.580 [BuoyancyServo](INFO): Powering down 2022-11-07T23:49:28.595Z,1667864968.595 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2022-11-07T23:49:28.595Z,1667864968.595 [ElevatorServo](INFO): Powering down 2022-11-07T23:49:28.596Z,1667864968.596 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-11-07T23:49:28.596Z,1667864968.596 [MassServo](INFO): Powering down 2022-11-07T23:49:28.597Z,1667864968.597 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-11-07T23:49:28.597Z,1667864968.597 [RudderServo](INFO): Powering down 2022-11-07T23:49:28.598Z,1667864968.598 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2022-11-07T23:49:28.598Z,1667864968.598 [ThrusterHE](INFO): Powering down 2022-11-07T23:49:28.599Z,1667864968.599 [SBIT](DEBUG): Uninitialize SBIT Component. 2022-11-07T23:49:28.599Z,1667864968.599 [IBIT](DEBUG): Uninitialize IBIT Component. 2022-11-07T23:49:28.599Z,1667864968.599 [CBIT](DEBUG): Uninitialize CBIT Component. 2022-11-07T23:49:28.599Z,1667864968.599 [CBIT](DEBUG): Powering off loads. 2022-11-07T23:49:28.610Z,1667864968.610 [CBIT](DEBUG): Disabling WDT. 2022-11-07T23:49:28.622Z,1667864968.622 [CBIT](DEBUG): Opening all GF detection circuits. 2022-11-07T23:49:28.623Z,1667864968.623 [controlThread ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.662Z,1667864968.662 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.708Z,1667864968.708 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.712Z,1667864968.712 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.715Z,1667864968.715 [Onboard ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.722Z,1667864968.722 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.765Z,1667864968.765 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.806Z,1667864968.806 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-07T23:49:28.874Z,1667864968.874 [logger ThreadHandler](INFO): Thread cancelled.