2023-05-11T22:43:35.738Z,1683845015.738 [Supervisor](DEBUG): Initializing supervisor. 2023-05-11T22:43:35.743Z,1683845015.743 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2023-05-11T22:43:35.744Z,1683845015.744 [SyncHandler](INFO): Protected caller Thread ID is 1520 2023-05-11T22:43:35.744Z,1683845015.744 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2023-05-11T22:43:35.746Z,1683845015.746 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2023-05-11T22:43:35.746Z,1683845015.746 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1521 2023-05-11T22:43:35.750Z,1683845015.750 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2023-05-11T22:43:35.769Z,1683845015.769 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2023-05-11T22:43:35.770Z,1683845015.770 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2023-05-11T22:43:35.770Z,1683845015.770 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1522 2023-05-11T22:43:35.774Z,1683845015.774 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2023-05-11T22:43:35.775Z,1683845015.775 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2023-05-11T22:43:35.776Z,1683845015.776 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1523 2023-05-11T22:43:35.778Z,1683845015.778 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2023-05-11T22:43:35.779Z,1683845015.779 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2023-05-11T22:43:35.779Z,1683845015.779 [logger ThreadHandler](INFO): Protected caller Thread ID is 1524 2023-05-11T22:43:35.783Z,1683845015.783 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2023-05-11T22:43:35.783Z,1683845015.783 [Supervisor](INFO): Looking for Config files in directory: Config/ 2023-05-11T22:43:35.785Z,1683845015.785 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2023-05-11T22:43:35.882Z,1683845015.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2023-05-11T22:43:35.883Z,1683845015.883 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2023-05-11T22:43:36.577Z,1683845016.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2023-05-11T22:43:36.577Z,1683845016.577 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2023-05-11T22:43:36.803Z,1683845016.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2023-05-11T22:43:36.804Z,1683845016.804 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2023-05-11T22:43:36.883Z,1683845016.883 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2023-05-11T22:43:37.016Z,1683845017.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2023-05-11T22:43:37.017Z,1683845017.017 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2023-05-11T22:43:37.098Z,1683845017.098 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2023-05-11T22:43:37.206Z,1683845017.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2023-05-11T22:43:37.206Z,1683845017.206 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2023-05-11T22:43:37.587Z,1683845017.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2023-05-11T22:43:37.587Z,1683845017.587 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2023-05-11T22:43:38.068Z,1683845018.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2023-05-11T22:43:38.069Z,1683845018.069 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2023-05-11T22:43:38.289Z,1683845018.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2023-05-11T22:43:38.290Z,1683845018.290 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2023-05-11T22:43:38.474Z,1683845018.474 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2023-05-11T22:43:38.475Z,1683845018.475 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2023-05-11T22:43:38.977Z,1683845018.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2023-05-11T22:43:38.978Z,1683845018.978 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2023-05-11T22:43:39.271Z,1683845019.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2023-05-11T22:43:39.271Z,1683845019.271 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2023-05-11T22:43:39.485Z,1683845019.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2023-05-11T22:43:39.485Z,1683845019.485 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2023-05-11T22:43:39.861Z,1683845019.861 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2023-05-11T22:43:39.862Z,1683845019.862 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2023-05-11T22:43:40.310Z,1683845020.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2023-05-11T22:43:40.312Z,1683845020.312 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2023-05-11T22:43:40.313Z,1683845020.313 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2023-05-11T22:43:40.486Z,1683845020.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2023-05-11T22:43:40.813Z,1683845020.813 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2023-05-11T22:43:40.984Z,1683845020.984 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2023-05-11T22:43:41.186Z,1683845021.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2023-05-11T22:43:41.282Z,1683845021.282 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2023-05-11T22:43:41.601Z,1683845021.601 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2023-05-11T22:43:41.866Z,1683845021.866 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2023-05-11T22:43:41.867Z,1683845021.867 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2023-05-11T22:43:41.961Z,1683845021.961 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2023-05-11T22:43:42.059Z,1683845022.059 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2023-05-11T22:43:42.197Z,1683845022.197 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2023-05-11T22:43:42.298Z,1683845022.298 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2023-05-11T22:43:42.298Z,1683845022.298 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2023-05-11T22:43:42.307Z,1683845022.307 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2023-05-11T22:43:42.406Z,1683845022.406 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2023-05-11T22:43:42.407Z,1683845022.407 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2023-05-11T22:43:42.458Z,1683845022.458 [VerticalControl](DEBUG): Construct VerticalControl. 2023-05-11T22:43:42.520Z,1683845022.520 [VerticalControl] Loaded 2023-05-11T22:43:42.520Z,1683845022.520 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2023-05-11T22:43:42.523Z,1683845022.523 [HorizontalControl](DEBUG): Construct HorizontalControl. 2023-05-11T22:43:42.565Z,1683845022.565 [HorizontalControl] Loaded 2023-05-11T22:43:42.565Z,1683845022.565 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2023-05-11T22:43:42.568Z,1683845022.568 [SpeedControl](DEBUG): Construct SpeedControl. 2023-05-11T22:43:42.571Z,1683845022.571 [SpeedControl] Loaded 2023-05-11T22:43:42.571Z,1683845022.571 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2023-05-11T22:43:42.574Z,1683845022.574 [LoopControl](DEBUG): Construct LoopControl. 2023-05-11T22:43:42.574Z,1683845022.574 [LoopControl] Loaded 2023-05-11T22:43:42.575Z,1683845022.575 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2023-05-11T22:43:42.575Z,1683845022.575 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2023-05-11T22:43:42.576Z,1683845022.576 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2023-05-11T22:43:42.624Z,1683845022.624 [DepthRateCalculator] Loaded 2023-05-11T22:43:42.625Z,1683845022.625 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2023-05-11T22:43:42.629Z,1683845022.629 [PitchRateCalculator] Loaded 2023-05-11T22:43:42.630Z,1683845022.630 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2023-05-11T22:43:42.640Z,1683845022.640 [SpeedCalculator] Loaded 2023-05-11T22:43:42.640Z,1683845022.640 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2023-05-11T22:43:42.644Z,1683845022.644 [YawRateCalculator] Loaded 2023-05-11T22:43:42.645Z,1683845022.645 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2023-05-11T22:43:42.663Z,1683845022.663 [ElevatorOffsetCalculator] Loaded 2023-05-11T22:43:42.664Z,1683845022.664 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2023-05-11T22:43:42.664Z,1683845022.664 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2023-05-11T22:43:42.665Z,1683845022.665 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2023-05-11T22:43:42.691Z,1683845022.691 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2023-05-11T22:43:42.692Z,1683845022.692 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2023-05-11T22:43:42.764Z,1683845022.764 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2023-05-11T22:43:42.765Z,1683845022.765 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2023-05-11T22:43:43.074Z,1683845023.074 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2023-05-11T22:43:43.075Z,1683845023.075 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2023-05-11T22:43:43.221Z,1683845023.221 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2023-05-11T22:43:43.222Z,1683845023.222 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2023-05-11T22:43:43.701Z,1683845023.701 [AHRS_M2] Loaded 2023-05-11T22:43:43.702Z,1683845023.702 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2023-05-11T22:43:43.737Z,1683845023.737 [BackseatComponent] Loaded 2023-05-11T22:43:43.737Z,1683845023.737 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2023-05-11T22:43:43.738Z,1683845023.738 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 409994E0 2023-05-11T22:43:43.738Z,1683845023.738 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1606 2023-05-11T22:43:43.741Z,1683845023.741 [LcmUniversalReporter] Loaded 2023-05-11T22:43:43.741Z,1683845023.741 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2023-05-11T22:43:44.553Z,1683845024.553 [BPC1] Loaded 2023-05-11T22:43:44.553Z,1683845024.553 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2023-05-11T22:43:44.637Z,1683845024.637 [DATMMP] Loaded 2023-05-11T22:43:44.638Z,1683845024.638 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread. 2023-05-11T22:43:44.639Z,1683845024.639 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409CA4E0 2023-05-11T22:43:44.639Z,1683845024.639 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 1607 2023-05-11T22:43:44.713Z,1683845024.713 [DataOverHttps] Loaded 2023-05-11T22:43:44.713Z,1683845024.713 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2023-05-11T22:43:44.714Z,1683845024.714 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409FA4E0 2023-05-11T22:43:44.714Z,1683845024.714 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1608 2023-05-11T22:43:44.735Z,1683845024.735 [Depth_Keller] Loaded 2023-05-11T22:43:44.736Z,1683845024.736 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2023-05-11T22:43:44.799Z,1683845024.799 [NAL9602] Loaded 2023-05-11T22:43:44.799Z,1683845024.799 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2023-05-11T22:43:44.828Z,1683845024.828 [Onboard] Loaded 2023-05-11T22:43:44.829Z,1683845024.829 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2023-05-11T22:43:44.830Z,1683845024.830 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A2A4E0 2023-05-11T22:43:44.830Z,1683845024.830 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1609 2023-05-11T22:43:44.843Z,1683845024.843 [Power24vConverter] Loaded 2023-05-11T22:43:44.843Z,1683845024.843 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2023-05-11T22:43:44.856Z,1683845024.856 [Radio_Surface] Loaded 2023-05-11T22:43:44.856Z,1683845024.856 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2023-05-11T22:43:44.857Z,1683845024.857 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A5A4E0 2023-05-11T22:43:44.858Z,1683845024.858 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1610 2023-05-11T22:43:44.903Z,1683845024.903 [RDI_Pathfinder] Loaded 2023-05-11T22:43:44.903Z,1683845024.903 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2023-05-11T22:43:44.904Z,1683845024.904 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2023-05-11T22:43:44.905Z,1683845024.905 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2023-05-11T22:43:45.015Z,1683845025.015 [DeadReckonUsingMultipleVelocitySources] Loaded 2023-05-11T22:43:45.015Z,1683845025.015 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2023-05-11T22:43:45.029Z,1683845025.029 [NavChart] Loaded 2023-05-11T22:43:45.029Z,1683845025.029 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2023-05-11T22:43:45.035Z,1683845025.035 [UniversalFixResidualReporter] Loaded 2023-05-11T22:43:45.035Z,1683845025.035 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2023-05-11T22:43:45.036Z,1683845025.036 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2023-05-11T22:43:45.036Z,1683845025.036 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2023-05-11T22:43:45.179Z,1683845025.179 [SBIT](DEBUG): Construct Startup Built In Test. 2023-05-11T22:43:45.218Z,1683845025.218 [SBIT] Loaded 2023-05-11T22:43:45.220Z,1683845025.220 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2023-05-11T22:43:45.262Z,1683845025.262 [IBIT](DEBUG): Construct Initiated Built In Test. 2023-05-11T22:43:45.275Z,1683845025.275 [IBIT] Loaded 2023-05-11T22:43:45.275Z,1683845025.275 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2023-05-11T22:43:45.281Z,1683845025.281 [CBIT](DEBUG): Construct Continuous Built In Test. 2023-05-11T22:43:45.664Z,1683845025.664 [CBIT] Loaded 2023-05-11T22:43:45.664Z,1683845025.664 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2023-05-11T22:43:45.664Z,1683845025.664 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2023-05-11T22:43:45.665Z,1683845025.665 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2023-05-11T22:43:46.165Z,1683845026.165 [BuoyancyServo] Loaded 2023-05-11T22:43:46.166Z,1683845026.166 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2023-05-11T22:43:46.186Z,1683845026.186 [ElevatorServo] Loaded 2023-05-11T22:43:46.187Z,1683845026.187 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2023-05-11T22:43:46.276Z,1683845026.276 [MassServo] Loaded 2023-05-11T22:43:46.276Z,1683845026.276 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2023-05-11T22:43:46.353Z,1683845026.353 [RudderServo] Loaded 2023-05-11T22:43:46.353Z,1683845026.353 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2023-05-11T22:43:46.370Z,1683845026.370 [ThrusterServo] Loaded 2023-05-11T22:43:46.370Z,1683845026.370 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2023-05-11T22:43:46.371Z,1683845026.371 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2023-05-11T22:43:46.372Z,1683845026.372 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2023-05-11T22:43:46.382Z,1683845026.382 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2023-05-11T22:43:46.382Z,1683845026.382 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2023-05-11T22:43:46.796Z,1683845026.796 [CTD_Seabird] Loaded 2023-05-11T22:43:46.797Z,1683845026.797 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2023-05-11T22:43:46.798Z,1683845026.798 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40BA24E0 2023-05-11T22:43:46.798Z,1683845026.798 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1611 2023-05-11T22:43:46.857Z,1683845026.857 [PAR_Licor] Loaded 2023-05-11T22:43:46.857Z,1683845026.857 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2023-05-11T22:43:46.889Z,1683845026.889 [WetLabsBB2FL] Loaded 2023-05-11T22:43:46.889Z,1683845026.889 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2023-05-11T22:43:46.890Z,1683845026.890 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BD24E0 2023-05-11T22:43:46.890Z,1683845026.890 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1612 2023-05-11T22:43:46.910Z,1683845026.910 [WetLabsUBAT] Loaded 2023-05-11T22:43:46.910Z,1683845026.910 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread. 2023-05-11T22:43:46.911Z,1683845026.911 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40C024E0 2023-05-11T22:43:46.912Z,1683845026.912 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 1613 2023-05-11T22:43:46.912Z,1683845026.912 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2023-05-11T22:43:46.919Z,1683845026.919 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2023-05-11T22:43:46.922Z,1683845026.922 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2023-05-11T22:43:46.933Z,1683845026.933 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2023-05-11T22:43:46.934Z,1683845026.934 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C324E0 2023-05-11T22:43:46.935Z,1683845026.935 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1614 2023-05-11T22:43:46.939Z,1683845026.939 [Supervisor](INFO): Main Thread ID is 830 2023-05-11T22:43:46.940Z,1683845026.940 [Supervisor](DEBUG): Running supervisor. 2023-05-11T22:43:46.940Z,1683845026.940 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1615 2023-05-11T22:43:46.941Z,1683845026.941 [CommandExec](INFO): Initializing the command executive. 2023-05-11T22:43:46.942Z,1683845026.942 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1616 2023-05-11T22:43:46.944Z,1683845026.944 [controlThread ThreadHandler](INFO): Handler Thread ID is 1617 2023-05-11T22:43:46.945Z,1683845026.945 [controlThread](DEBUG): Initializing ControlThread 2023-05-11T22:43:46.945Z,1683845026.945 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2023-05-11T22:43:46.947Z,1683845026.947 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2023-05-11T22:43:46.948Z,1683845026.948 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2023-05-11T22:43:46.948Z,1683845026.948 [LoopControl](DEBUG): Initialize LoopControlComponent. 2023-05-11T22:43:46.949Z,1683845026.949 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2023-05-11T22:43:46.949Z,1683845026.949 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2023-05-11T22:43:46.950Z,1683845026.950 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2023-05-11T22:43:46.950Z,1683845026.950 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2023-05-11T22:43:46.950Z,1683845026.950 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2023-05-11T22:43:46.957Z,1683845026.957 [NavChart](DEBUG): Initialize NavChart Navigation. 2023-05-11T22:43:46.958Z,1683845026.958 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2023-05-11T22:43:46.958Z,1683845026.958 [SBIT](INFO): Initialize SBIT Component. 2023-05-11T22:43:46.958Z,1683845026.958 [SBIT](IMPORTANT): git: 2023-04-26-68-gd8052d973 2023-05-11T22:43:46.959Z,1683845026.959 [SBIT](INFO): git hash: d8052d9734beefc1bd50265fa9cca972428f086c 2023-05-11T22:43:46.959Z,1683845026.959 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2023-05-11T22:43:46.960Z,1683845026.960 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2023-05-11T22:43:46.961Z,1683845026.961 [SBIT](INFO): Beginning SBIT in 51.000000 seconds. 2023-05-11T22:43:46.962Z,1683845026.962 [IBIT](INFO): Initialize IBIT Component. 2023-05-11T22:43:46.963Z,1683845026.963 [CBIT](DEBUG): Initialize CBIT Component. 2023-05-11T22:43:46.964Z,1683845026.964 [logger ThreadHandler](INFO): Handler Thread ID is 1618 2023-05-11T22:43:46.976Z,1683845026.976 [CBIT](DEBUG): Initialized mux pins. 2023-05-11T22:43:46.976Z,1683845026.976 [CBIT](DEBUG): Initializing the watchdog timer. 2023-05-11T22:43:46.984Z,1683845026.984 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1619 2023-05-11T22:43:46.996Z,1683845026.996 [DATMMP ThreadHandler](INFO): Handler Thread ID is 1620 2023-05-11T22:43:46.997Z,1683845026.997 [DATMMP](INFO): Start 2023-05-11T22:43:46.997Z,1683845026.997 [DATMMP](INFO): Powering up 2023-05-11T22:43:46.997Z,1683845026.997 [DATMMP](DEBUG): Initializing DATMMP. 2023-05-11T22:43:46.000Z,1683845027.000 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2023-05-11T22:43:47.000Z,1683845027.000 [CBIT](DEBUG): Initializing heartbeat. 2023-05-11T22:43:47.002Z,1683845027.002 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1622 2023-05-11T22:43:47.003Z,1683845027.003 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2023-05-11T22:43:47.012Z,1683845027.012 [Onboard ThreadHandler](INFO): Handler Thread ID is 1623 2023-05-11T22:43:47.030Z,1683845027.030 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1624 2023-05-11T22:43:47.048Z,1683845027.048 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1625 2023-05-11T22:43:47.049Z,1683845027.049 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2023-05-11T22:43:47.053Z,1683845027.053 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1627 2023-05-11T22:43:47.056Z,1683845027.056 [WetLabsBB2FL](INFO): Powering up 2023-05-11T22:43:47.057Z,1683845027.057 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 1629 2023-05-11T22:43:47.060Z,1683845027.060 [WetLabsUBAT](INFO): Powering up 2023-05-11T22:43:47.061Z,1683845027.061 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1631 2023-05-11T22:43:47.065Z,1683845027.065 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2023-05-11T22:43:47.065Z,1683845027.065 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2023-05-11T22:43:47.065Z,1683845027.065 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2023-05-11T22:43:47.065Z,1683845027.065 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2023-05-11T22:43:47.065Z,1683845027.065 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2023-05-11T22:43:47.066Z,1683845027.066 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2023-05-11T22:43:47.066Z,1683845027.066 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2023-05-11T22:43:47.066Z,1683845027.066 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2023-05-11T22:43:47.072Z,1683845027.072 [CBIT](DEBUG): Deactivating GF circuits. 2023-05-11T22:43:47.072Z,1683845027.072 [CBIT](DEBUG): Deactivating emergency mode. 2023-05-11T22:43:47.112Z,1683845027.112 [CBIT](DEBUG): Backplane powered. 2023-05-11T22:43:47.117Z,1683845027.117 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2023-05-11T22:43:47.146Z,1683845027.146 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2023-05-11T22:43:47.169Z,1683845027.169 [MissionManager](DEBUG): 2023-05-11T22:43:47.170Z,1683845027.170 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2023-05-11T22:43:47.248Z,1683845027.248 [DATMMP](INFO): Starting 2023-05-11T22:43:47.282Z,1683845027.282 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2023-05-11T22:43:47.284Z,1683845027.284 [Default:A.Wait](DEBUG): Construct Wait. 2023-05-11T22:43:47.286Z,1683845027.286 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2023-05-11T22:43:47.329Z,1683845027.329 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2023-05-11T22:43:47.332Z,1683845027.332 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2023-05-11T22:43:47.354Z,1683845027.354 [Default:E.Execute](DEBUG): Construct Execute. 2023-05-11T22:43:47.371Z,1683845027.371 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2023-05-11T22:43:47.376Z,1683845027.376 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-05-11T22:43:47.388Z,1683845027.388 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2023-05-11T22:43:47.436Z,1683845027.436 [Radio_Surface](INFO): Powering up 2023-05-11T22:43:47.462Z,1683845027.462 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m 2023-05-11T22:43:47.463Z,1683845027.463 [Power24vConverter](INFO): Powering up. 2023-05-11T22:43:47.468Z,1683845027.468 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2023-05-11T22:43:47.498Z,1683845027.498 [DepthRateCalculator](ERROR): Depth measurement is not active 2023-05-11T22:43:47.500Z,1683845027.500 [DATMMP](INFO): Starting 2023-05-11T22:43:47.521Z,1683845027.521 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2023-05-11T22:43:47.528Z,1683845027.528 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2023-05-11T22:43:47.529Z,1683845027.529 [ElevatorServo](DEBUG): Initializing EZServoServo. 2023-05-11T22:43:47.536Z,1683845027.536 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2023-05-11T22:43:47.537Z,1683845027.537 [MassServo](DEBUG): Initializing EZServoServo. 2023-05-11T22:43:47.544Z,1683845027.544 [MassServo](DEBUG): Initializing MassServo. 2023-05-11T22:43:47.545Z,1683845027.545 [RudderServo](DEBUG): Initializing EZServoServo. 2023-05-11T22:43:47.552Z,1683845027.552 [RudderServo](DEBUG): Initializing RudderServo. 2023-05-11T22:43:47.553Z,1683845027.553 [ThrusterServo](DEBUG): Initializing EZServoServo. 2023-05-11T22:43:47.560Z,1683845027.560 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2023-05-11T22:43:47.752Z,1683845027.752 [DATMMP](INFO): Starting 2023-05-11T22:43:48.005Z,1683845028.005 [DATMMP](INFO): Starting 2023-05-11T22:43:48.256Z,1683845028.256 [DATMMP](INFO): Starting 2023-05-11T22:43:48.508Z,1683845028.508 [DATMMP](INFO): Starting 2023-05-11T22:43:48.761Z,1683845028.761 [DATMMP](INFO): Starting 2023-05-11T22:43:49.012Z,1683845029.012 [DATMMP](INFO): Starting 2023-05-11T22:43:49.264Z,1683845029.264 [DATMMP](INFO): Starting 2023-05-11T22:43:49.516Z,1683845029.516 [DATMMP](INFO): Starting 2023-05-11T22:43:49.668Z,1683845029.668 [WetLabsBB2FL](INFO): Powering down 2023-05-11T22:43:49.768Z,1683845029.768 [DATMMP](INFO): Starting 2023-05-11T22:43:50.020Z,1683845030.020 [DATMMP](INFO): Starting 2023-05-11T22:43:50.272Z,1683845030.272 [DATMMP](INFO): Starting 2023-05-11T22:43:50.524Z,1683845030.524 [DATMMP](INFO): Starting 2023-05-11T22:43:50.776Z,1683845030.776 [DATMMP](INFO): Starting 2023-05-11T22:43:51.028Z,1683845031.028 [DATMMP](INFO): Starting 2023-05-11T22:43:51.280Z,1683845031.280 [DATMMP](INFO): Starting 2023-05-11T22:43:51.532Z,1683845031.532 [DATMMP](INFO): Starting 2023-05-11T22:43:51.784Z,1683845031.784 [DATMMP](INFO): Starting 2023-05-11T22:43:52.036Z,1683845032.036 [DATMMP](INFO): Starting 2023-05-11T22:43:52.288Z,1683845032.288 [DATMMP](INFO): Starting 2023-05-11T22:43:52.540Z,1683845032.540 [DATMMP](INFO): Starting 2023-05-11T22:43:52.792Z,1683845032.792 [DATMMP](INFO): Starting 2023-05-11T22:43:53.044Z,1683845033.044 [DATMMP](INFO): Starting 2023-05-11T22:43:53.296Z,1683845033.296 [DATMMP](INFO): Starting 2023-05-11T22:43:53.548Z,1683845033.548 [DATMMP](INFO): Starting 2023-05-11T22:43:53.800Z,1683845033.800 [DATMMP](INFO): Starting 2023-05-11T22:43:54.052Z,1683845034.052 [DATMMP](INFO): Starting 2023-05-11T22:43:54.304Z,1683845034.304 [DATMMP](INFO): Starting 2023-05-11T22:43:54.556Z,1683845034.556 [DATMMP](INFO): Starting 2023-05-11T22:43:54.808Z,1683845034.808 [DATMMP](INFO): Starting 2023-05-11T22:43:55.060Z,1683845035.060 [DATMMP](INFO): Starting 2023-05-11T22:43:55.313Z,1683845035.313 [DATMMP](INFO): Starting 2023-05-11T22:43:55.564Z,1683845035.564 [DATMMP](INFO): Starting 2023-05-11T22:43:55.816Z,1683845035.816 [DATMMP](INFO): Starting 2023-05-11T22:43:56.068Z,1683845036.068 [DATMMP](INFO): Starting 2023-05-11T22:43:56.308Z,1683845036.308 [WetLabsUBAT](INFO): Powering down 2023-05-11T22:43:56.320Z,1683845036.320 [DATMMP](INFO): Starting 2023-05-11T22:43:56.572Z,1683845036.572 [DATMMP](INFO): Starting 2023-05-11T22:43:56.824Z,1683845036.824 [DATMMP](INFO): Starting 2023-05-11T22:43:57.076Z,1683845037.076 [DATMMP](INFO): Starting 2023-05-11T22:43:57.328Z,1683845037.328 [DATMMP](INFO): Starting 2023-05-11T22:43:57.580Z,1683845037.580 [DATMMP](INFO): Starting 2023-05-11T22:43:57.832Z,1683845037.832 [DATMMP](INFO): Starting 2023-05-11T22:43:58.084Z,1683845038.084 [DATMMP](INFO): Starting 2023-05-11T22:43:58.340Z,1683845038.340 [DATMMP](INFO): Starting 2023-05-11T22:43:58.592Z,1683845038.592 [DATMMP](INFO): Starting 2023-05-11T22:43:58.844Z,1683845038.844 [DATMMP](INFO): Starting 2023-05-11T22:43:59.096Z,1683845039.096 [DATMMP](INFO): Starting 2023-05-11T22:43:59.096Z,1683845039.096 [DATMMP](INFO): DAT read: 2023-05-11T22:43:59.097Z,1683845039.097 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series 2023-05-11T22:43:59.348Z,1683845039.348 [DATMMP](INFO): Starting 2023-05-11T22:43:59.600Z,1683845039.600 [DATMMP](INFO): Starting 2023-05-11T22:43:59.852Z,1683845039.852 [DATMMP](INFO): Starting 2023-05-11T22:44:00.104Z,1683845040.104 [DATMMP](INFO): Starting 2023-05-11T22:44:00.357Z,1683845040.357 [DATMMP](INFO): Starting 2023-05-11T22:44:00.608Z,1683845040.608 [DATMMP](INFO): Starting 2023-05-11T22:44:00.860Z,1683845040.860 [DATMMP](INFO): Starting 2023-05-11T22:44:00.861Z,1683845040.861 [DATMMP](INFO): DAT read: MF Frequency Band 2023-05-11T22:44:00.862Z,1683845040.862 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2023-05-11T22:44:00.862Z,1683845040.862 [DATMMP](INFO): DAT read: Apr 11 2000 22:43:55 2023-05-11T22:44:01.112Z,1683845041.112 [DATMMP](INFO): Starting 2023-05-11T22:44:01.364Z,1683845041.364 [DATMMP](INFO): Starting 2023-05-11T22:44:01.616Z,1683845041.616 [DATMMP](INFO): Starting 2023-05-11T22:44:01.868Z,1683845041.868 [DATMMP](INFO): Starting 2023-05-11T22:44:01.869Z,1683845041.869 [DATMMP](INFO): DAT read: Features enabled [Bearing] 2023-05-11T22:44:01.870Z,1683845041.870 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2023-05-11T22:44:01.870Z,1683845041.870 [DATMMP](INFO): commRate: 800 2023-05-11T22:44:02.120Z,1683845042.120 [DATMMP](INFO): Starting 2023-05-11T22:44:02.372Z,1683845042.372 [DATMMP](INFO): Starting 2023-05-11T22:44:02.624Z,1683845042.624 [DATMMP](INFO): Starting 2023-05-11T22:44:02.876Z,1683845042.876 [DATMMP](INFO): Starting 2023-05-11T22:44:03.128Z,1683845043.128 [DATMMP](INFO): Starting 2023-05-11T22:44:03.381Z,1683845043.381 [DATMMP](INFO): Starting 2023-05-11T22:44:03.632Z,1683845043.632 [DATMMP](INFO): Starting 2023-05-11T22:44:03.884Z,1683845043.884 [DATMMP](INFO): Starting 2023-05-11T22:44:03.936Z,1683845043.936 [DATMMP](INFO): entering command mode 2023-05-11T22:44:04.136Z,1683845044.136 [DATMMP](INFO): Starting 2023-05-11T22:44:04.136Z,1683845044.136 [DATMMP](INFO): DAT read: 2023-05-11T22:44:04.137Z,1683845044.137 [DATMMP](INFO): DAT read: user:1> 2023-05-11T22:44:04.137Z,1683845044.137 [DATMMP](DEBUG): read user prompt 1: user:1> 2023-05-11T22:44:04.137Z,1683845044.137 [DATMMP](INFO): entering MMP mode 2023-05-11T22:44:04.388Z,1683845044.388 [DATMMP](INFO): Starting 2023-05-11T22:44:04.389Z,1683845044.389 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T22:44:04.391Z,1683845044.391 [DATMMP](INFO): status rx: x1 2023-05-11T22:44:04.391Z,1683845044.391 [DATMMP](INFO): MMP status: 1: started 2023-05-11T22:44:04.392Z,1683845044.392 [DATMMP](INFO): Received message type: status 2023-05-11T22:44:04.392Z,1683845044.392 [DATMMP](INFO): Handled 2023-05-11T22:44:04.640Z,1683845044.640 [DATMMP](INFO): Starting 2023-05-11T22:44:04.641Z,1683845044.641 [DATMMP](INFO): Sent Tx Power Config 8 2023-05-11T22:44:04.642Z,1683845044.642 [DATMMP](INFO): Setting local address: 10 2023-05-11T22:44:04.644Z,1683845044.644 [DATMMP](INFO): Setting time to: 22:44:4 And date to:5/11/2023 2023-05-11T22:44:04.892Z,1683845044.892 [DATMMP](INFO): Starting 2023-05-11T22:44:04.892Z,1683845044.892 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T22:44:04.893Z,1683845044.893 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0 2023-05-11T22:44:04.893Z,1683845044.893 [DATMMP](INFO): Received message type: mdmpower 2023-05-11T22:44:04.894Z,1683845044.894 [DATMMP](INFO): Handled 2023-05-11T22:44:05.144Z,1683845045.144 [DATMMP](INFO): Starting 2023-05-11T22:44:05.144Z,1683845045.144 [DATMMP](INFO): GSXN notify for xid: 10 2023-05-11T22:44:05.145Z,1683845045.145 [DATMMP](INFO): sreg_txpower rx: x8 2023-05-11T22:44:05.145Z,1683845045.145 [DATMMP](INFO): Received message type: sreg_txpower 2023-05-11T22:44:05.145Z,1683845045.145 [DATMMP](INFO): Match for : sreg_txpower 2023-05-11T22:44:05.146Z,1683845045.146 [DATMMP](INFO): ACK 2023-05-11T22:44:05.396Z,1683845045.396 [DATMMP](INFO): Starting 2023-05-11T22:44:05.396Z,1683845045.396 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T22:44:05.397Z,1683845045.397 [DATMMP](INFO): mdmlocal rx: xA x0 x0 x0 2023-05-11T22:44:05.397Z,1683845045.397 [DATMMP](INFO): Received message type: mdmlocal 2023-05-11T22:44:05.397Z,1683845045.397 [DATMMP](INFO): Handled 2023-05-11T22:44:05.648Z,1683845045.648 [DATMMP](INFO): Starting 2023-05-11T22:44:05.648Z,1683845045.648 [DATMMP](INFO): GSXN notify for xid: 11 2023-05-11T22:44:05.649Z,1683845045.649 [DATMMP](INFO): sreg_locaddr rx: xA 2023-05-11T22:44:05.649Z,1683845045.649 [DATMMP](INFO): Received message type: sreg_locaddr 2023-05-11T22:44:05.649Z,1683845045.649 [DATMMP](INFO): Match for : sreg_locaddr 2023-05-11T22:44:05.649Z,1683845045.649 [DATMMP](INFO): ACK 2023-05-11T22:44:05.900Z,1683845045.900 [DATMMP](INFO): Starting 2023-05-11T22:44:05.900Z,1683845045.900 [DATMMP](INFO): GSXN notify for xid: 12 2023-05-11T22:44:05.902Z,1683845045.902 [DATMMP](INFO): timedate rx: x0 x16 x2C x4 x4 xB x7B x0 2023-05-11T22:44:05.902Z,1683845045.902 [DATMMP](INFO): Received message type: timedate 2023-05-11T22:44:05.902Z,1683845045.902 [DATMMP](INFO): Match for : timedate 2023-05-11T22:44:05.902Z,1683845045.902 [DATMMP](INFO): ACK 2023-05-11T22:44:06.152Z,1683845046.152 [DATMMP](INFO): Starting 2023-05-11T22:44:06.152Z,1683845046.152 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T22:44:06.153Z,1683845046.153 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0 2023-05-11T22:44:06.153Z,1683845046.153 [DATMMP](INFO): Received message type: sys_verb 2023-05-11T22:44:06.154Z,1683845046.154 [DATMMP](INFO): Handled 2023-05-11T22:44:06.404Z,1683845046.404 [DATMMP](INFO): Starting 2023-05-11T22:44:06.404Z,1683845046.404 [DATMMP](INFO): GSXN notify for xid: 13 2023-05-11T22:44:06.405Z,1683845046.405 [DATMMP](INFO): sreg_verbosity rx: x0 2023-05-11T22:44:06.405Z,1683845046.405 [DATMMP](INFO): Received message type: sreg_verbosity 2023-05-11T22:44:06.405Z,1683845046.405 [DATMMP](INFO): Match for : sreg_verbosity 2023-05-11T22:44:06.405Z,1683845046.405 [DATMMP](INFO): ACK 2023-05-11T22:44:06.656Z,1683845046.656 [DATMMP](INFO): Starting 2023-05-11T22:44:06.656Z,1683845046.656 [DATMMP](INFO): GSXN notify for xid: 14 2023-05-11T22:44:06.657Z,1683845046.657 [DATMMP](INFO): version rx: x2 x5 2023-05-11T22:44:06.657Z,1683845046.657 [DATMMP](INFO): DatMMPVersion: 2.5 2023-05-11T22:44:06.657Z,1683845046.657 [DATMMP](INFO): Received message type: version 2023-05-11T22:44:06.658Z,1683845046.658 [DATMMP](INFO): Match for : version 2023-05-11T22:44:06.658Z,1683845046.658 [DATMMP](INFO): ACK 2023-05-11T22:44:06.658Z,1683845046.658 [DATMMP](INFO): in MMP mode: config complete going to runnable 2023-05-11T22:44:14.869Z,1683845054.869 [NAL9602](INFO): Powering up NAL9602 2023-05-11T22:44:20.772Z,1683845060.772 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T22:44:20.773Z,1683845060.773 [DATMMP](INFO): timesync rx: x0 x1 x1 x0 2023-05-11T22:44:20.773Z,1683845060.773 [DATMMP](INFO): Received message type: timesync 2023-05-11T22:44:20.774Z,1683845060.774 [DATMMP](INFO): Handled 2023-05-11T22:44:25.773Z,1683845065.773 [NAL9602](INFO): NAL9602 initialized 2023-05-11T22:44:30.892Z,1683845070.892 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T22:44:30.893Z,1683845070.893 [DATMMP](INFO): timesync rx: x1 x0 x1 x0 2023-05-11T22:44:30.893Z,1683845070.893 [DATMMP](INFO): Received message type: timesync 2023-05-11T22:44:30.894Z,1683845070.894 [DATMMP](INFO): Handled 2023-05-11T22:44:38.719Z,1683845078.719 [SBIT](IMPORTANT): Beginning Startup BIT 2023-05-11T22:44:38.724Z,1683845078.724 [CBIT](IMPORTANT): Beginning ground fault scan 2023-05-11T22:44:49.687Z,1683845089.687 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.002307 CHAN A1 (24V): 0.000212 CHAN A2 (12V): -0.007326 CHAN A3 (5V): -0.002552 CHAN B0 (3.3V): 0.000375 CHAN B1 (3.15aV): -0.000354 CHAN B2 (3.15bV): -0.000691 CHAN B3 (GND): 0.002356 OPEN: 0.004797 Full Scale: +/- 1 mA 2023-05-11T22:45:32.476Z,1683845132.476 [SBIT](IMPORTANT): SBIT PASSED 2023-05-11T22:45:32.476Z,1683845132.476 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2023-05-11T22:45:32.477Z,1683845132.477 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2023-05-11T22:45:32.477Z,1683845132.477 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere; 2023-05-11T22:45:32.480Z,1683845132.480 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2023-05-11T22:45:32.480Z,1683845132.480 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second; 2023-05-11T22:45:32.480Z,1683845132.480 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=279.582187 cubic_centimeter; 2023-05-11T22:45:32.480Z,1683845132.480 [SBIT](IMPORTANT): VerticalControl.massDefault=7.892016 millimeter; 2023-05-11T22:45:32.481Z,1683845132.481 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool; 2023-05-11T22:45:32.870Z,1683845132.870 [MissionManager](IMPORTANT): Started mission Startup 2023-05-11T22:45:32.870Z,1683845132.870 [Startup] Running Loop=1 2023-05-11T22:45:32.871Z,1683845132.871 [Startup](DEBUG): Aggregate::initialize Startup 2023-05-11T22:45:32.871Z,1683845132.871 [Startup:A.GoToSurface] Running Loop=1 2023-05-11T22:45:32.871Z,1683845132.871 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-05-11T22:45:32.871Z,1683845132.871 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-05-11T22:45:32.888Z,1683845132.888 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-05-11T22:45:32.888Z,1683845132.888 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-05-11T22:45:32.889Z,1683845132.889 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-05-11T22:45:32.889Z,1683845132.889 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-05-11T22:45:32.890Z,1683845132.890 [Startup:StartupSatComms] Running Loop=1 2023-05-11T22:45:32.890Z,1683845132.890 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2023-05-11T22:45:32.891Z,1683845132.891 [Startup:StartupSatComms:A] Running Loop=1 2023-05-11T22:45:33.276Z,1683845133.276 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2023-05-11T22:46:33.069Z,1683845193.069 [Startup:StartupSatComms:A](INFO): Timed out from 2023-05-11T22:45:32.9Z 2023-05-11T22:46:33.069Z,1683845193.069 [Startup:StartupSatComms:A] Stopped 2023-05-11T22:46:33.069Z,1683845193.069 [Startup:StartupSatComms:B] Running Loop=1 2023-05-11T22:46:33.467Z,1683845193.467 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-05-11T22:46:47.225Z,1683845207.225 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2023-05-11T22:46:47.225Z,1683845207.225 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T22:46:47.259Z,1683845207.259 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T22:46:47.615Z,1683845207.615 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T22:46:47.615Z,1683845207.615 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2023-05-11T22:47:33.266Z,1683845253.266 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-11T22:46:33.1Z 2023-05-11T22:47:33.266Z,1683845253.266 [Startup:StartupSatComms:B] Stopped 2023-05-11T22:47:33.266Z,1683845253.266 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2023-05-11T22:47:33.266Z,1683845253.266 [Startup:StartupSatComms] Stopped 2023-05-11T22:47:33.266Z,1683845253.266 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2023-05-11T22:47:33.267Z,1683845253.267 [Startup](INFO): Completed Startup 2023-05-11T22:47:33.267Z,1683845253.267 [MissionManager](INFO): Startup is completed. 2023-05-11T22:47:33.267Z,1683845253.267 [MissionManager](INFO): Uninitializing Mission Startup 2023-05-11T22:47:33.267Z,1683845253.267 [Startup] Stopped 2023-05-11T22:47:33.267Z,1683845253.267 [Startup](DEBUG): Aggregate::uninitialize Startup 2023-05-11T22:47:33.267Z,1683845253.267 [Startup:A.GoToSurface] Stopped 2023-05-11T22:47:33.268Z,1683845253.268 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-05-11T22:47:33.650Z,1683845253.650 [MissionManager](IMPORTANT): Started mission Default 2023-05-11T22:47:33.650Z,1683845253.650 [Default] Running Loop=1 2023-05-11T22:47:33.650Z,1683845253.650 [Default](DEBUG): Aggregate::initialize Default 2023-05-11T22:47:33.650Z,1683845253.650 [Default:B.GoToSurface] Running Loop=1 2023-05-11T22:47:33.650Z,1683845253.650 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-05-11T22:47:33.651Z,1683845253.651 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-05-11T22:47:33.651Z,1683845253.651 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-05-11T22:47:33.651Z,1683845253.651 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-05-11T22:47:33.652Z,1683845253.652 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-05-11T22:47:33.652Z,1683845253.652 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-05-11T22:47:33.652Z,1683845253.652 [Default:A.Wait] Running Loop=1 2023-05-11T22:47:33.652Z,1683845253.652 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-05-11T22:47:47.029Z,1683845267.029 [Default:A.Wait](INFO): Done Waiting. 2023-05-11T22:47:47.030Z,1683845267.030 [Default:A.Wait] Stopped 2023-05-11T22:47:47.030Z,1683845267.030 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-11T22:47:47.416Z,1683845267.416 [Default:CheckIn] Running Loop=1 2023-05-11T22:47:47.417Z,1683845267.417 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-11T22:47:47.417Z,1683845267.417 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-11T22:47:47.806Z,1683845267.806 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2023-05-11T22:49:29.186Z,1683845369.186 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-11T22:49:45.927Z,1683845385.927 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004946 2023-05-11T22:49:48.194Z,1683845388.194 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2023-05-11T22:49:48.194Z,1683845388.194 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T22:49:48.233Z,1683845388.233 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T22:49:48.610Z,1683845388.610 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T22:49:48.610Z,1683845388.610 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2023-05-11T22:51:16.649Z,1683845476.649 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2023-05-11T22:51:16.653Z,1683845476.653 [BPC1](INFO): Received data from all battery sticks. 2023-05-11T22:52:47.560Z,1683845567.560 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-11T22:47:47.4Z 2023-05-11T22:52:47.560Z,1683845567.560 [Default:CheckIn:Read_GPS] Stopped 2023-05-11T22:52:47.560Z,1683845567.560 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-11T22:52:47.970Z,1683845567.970 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-05-11T22:52:49.207Z,1683845569.207 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2023-05-11T22:52:49.207Z,1683845569.207 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T22:52:49.254Z,1683845569.254 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T22:52:49.603Z,1683845569.603 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T22:52:49.603Z,1683845569.603 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2023-05-11T22:52:54.451Z,1683845574.451 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T222032/Courier0003.lzma 2023-05-11T22:52:55.454Z,1683845575.454 [DataOverHttps](INFO): Moved sent file to Logs/20230511T222032/Courier0003.lzma.bak 2023-05-11T22:52:55.454Z,1683845575.454 [DataOverHttps](INFO): SBD MOMSN=18294269 2023-05-11T22:53:11.355Z,1683845591.355 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230511T224335/Courier0000.lzma 2023-05-11T22:53:12.358Z,1683845592.358 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Courier0000.lzma.bak 2023-05-11T22:53:12.358Z,1683845592.358 [DataOverHttps](INFO): SBD MOMSN=18294271 2023-05-11T22:53:28.124Z,1683845608.124 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230511T224335/Courier0004.lzma 2023-05-11T22:53:29.126Z,1683845609.126 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Courier0004.lzma.bak 2023-05-11T22:53:29.126Z,1683845609.126 [DataOverHttps](INFO): SBD MOMSN=18294276 2023-05-11T22:53:44.999Z,1683845624.999 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20230511T222032/Express0004.lzma 2023-05-11T22:53:45.993Z,1683845625.993 [DataOverHttps](INFO): Moved sent file to Logs/20230511T222032/Express0004.lzma.bak 2023-05-11T22:53:45.994Z,1683845625.994 [DataOverHttps](INFO): SBD MOMSN=18294282 2023-05-11T22:54:00.718Z,1683845640.718 [DataOverHttps](INFO): Sending 852 bytes from file Logs/20230511T224335/Express0001.lzma 2023-05-11T22:54:01.689Z,1683845641.689 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Express0001.lzma.bak 2023-05-11T22:54:01.690Z,1683845641.690 [DataOverHttps](INFO): SBD MOMSN=18294286 2023-05-11T22:54:17.531Z,1683845657.531 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20230511T224335/Express0005.lzma 2023-05-11T22:54:18.534Z,1683845658.534 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Express0005.lzma.bak 2023-05-11T22:54:18.534Z,1683845658.534 [DataOverHttps](INFO): SBD MOMSN=18294305 2023-05-11T22:54:20.090Z,1683845660.090 [Default:CheckIn:Read_Iridium] Stopped 2023-05-11T22:54:20.090Z,1683845660.090 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-11T22:54:20.090Z,1683845660.090 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-11T22:54:27.338Z,1683845667.338 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-11T22:54:27.338Z,1683845667.338 [NAL9602] Data Fault, FailCount= 1 2023-05-11T22:54:27.338Z,1683845667.338 [NAL9602](ERROR): Data Fault 2023-05-11T22:54:27.415Z,1683845667.415 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-11T22:54:27.737Z,1683845667.737 [NAL9602](INFO): Powering down 2023-05-11T22:54:28.583Z,1683845668.583 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-11T22:54:28.583Z,1683845668.583 [NAL9602] No Fault, FailCount= 1 2023-05-11T22:54:58.045Z,1683845698.045 [NAL9602](INFO): Powering up NAL9602 2023-05-11T22:55:08.956Z,1683845708.956 [NAL9602](INFO): NAL9602 initialized 2023-05-11T22:55:50.168Z,1683845750.168 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2023-05-11T22:55:50.168Z,1683845750.168 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T22:55:50.179Z,1683845750.179 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T22:55:50.599Z,1683845750.599 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T22:55:50.599Z,1683845750.599 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2023-05-11T22:58:51.197Z,1683845931.197 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2023-05-11T22:58:51.197Z,1683845931.197 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T22:58:51.208Z,1683845931.208 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T22:58:51.575Z,1683845931.575 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T22:58:51.575Z,1683845931.575 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2023-05-11T22:59:20.654Z,1683845960.654 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-11T22:59:20.654Z,1683845960.654 [Default:CheckIn:C.Wait] Stopped 2023-05-11T22:59:20.654Z,1683845960.654 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-11T22:59:20.655Z,1683845960.655 [Default:CheckIn:D] Running Loop=1 2023-05-11T22:59:21.073Z,1683845961.073 [Default:CheckIn:D] Stopped 2023-05-11T22:59:21.073Z,1683845961.073 [Default:CheckIn:E] Running Loop=1 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.790382 min 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn:E] Stopped 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn] Stopped 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn](INFO): Running loop #2 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn] Running Loop=2 2023-05-11T22:59:21.475Z,1683845961.475 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-11T22:59:21.476Z,1683845961.476 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-11T23:00:50.896Z,1683846050.896 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:00:50.897Z,1683846050.897 [DATMMP](INFO): timesync rx: x2 x0 x0 x0 2023-05-11T23:00:50.898Z,1683846050.898 [DATMMP](INFO): Received message type: timesync 2023-05-11T23:00:50.898Z,1683846050.898 [DATMMP](INFO): Handled 2023-05-11T23:01:00.982Z,1683846060.982 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:01:00.985Z,1683846060.985 [DATMMP](INFO): timesync rx: x2 x1 x1 x0 2023-05-11T23:01:00.986Z,1683846060.986 [DATMMP](INFO): Received message type: timesync 2023-05-11T23:01:00.986Z,1683846060.986 [DATMMP](INFO): Handled 2023-05-11T23:01:10.824Z,1683846070.824 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:01:10.825Z,1683846070.825 [DATMMP](INFO): timesync rx: x1 x0 x1 x0 2023-05-11T23:01:10.825Z,1683846070.825 [DATMMP](INFO): Received message type: timesync 2023-05-11T23:01:10.826Z,1683846070.826 [DATMMP](INFO): Handled 2023-05-11T23:01:52.209Z,1683846112.209 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2023-05-11T23:01:52.209Z,1683846112.209 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:01:52.220Z,1683846112.220 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:01:52.618Z,1683846112.618 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:01:52.618Z,1683846112.618 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2023-05-11T23:04:21.686Z,1683846261.686 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-11T22:59:21.5Z 2023-05-11T23:04:21.686Z,1683846261.686 [Default:CheckIn:Read_GPS] Stopped 2023-05-11T23:04:21.686Z,1683846261.686 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-11T23:04:29.027Z,1683846269.027 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T224335/Courier0007.lzma 2023-05-11T23:04:30.029Z,1683846270.029 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Courier0007.lzma.bak 2023-05-11T23:04:30.030Z,1683846270.030 [DataOverHttps](INFO): SBD MOMSN=18294344 2023-05-11T23:04:45.783Z,1683846285.783 [DataOverHttps](INFO): Sending 182 bytes from file Logs/20230511T224335/Express0008.lzma 2023-05-11T23:04:46.785Z,1683846286.785 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Express0008.lzma.bak 2023-05-11T23:04:46.786Z,1683846286.786 [DataOverHttps](INFO): SBD MOMSN=18294346 2023-05-11T23:04:47.957Z,1683846287.957 [Default:CheckIn:Read_Iridium] Stopped 2023-05-11T23:04:47.957Z,1683846287.957 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-11T23:04:47.957Z,1683846287.957 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-11T23:04:53.239Z,1683846293.239 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2023-05-11T23:04:53.240Z,1683846293.240 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:04:53.258Z,1683846293.258 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:04:53.649Z,1683846293.649 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:04:53.649Z,1683846293.649 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2023-05-11T23:05:10.157Z,1683846310.157 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-11T23:05:10.157Z,1683846310.157 [NAL9602] Data Fault, FailCount= 2 2023-05-11T23:05:10.157Z,1683846310.157 [NAL9602](ERROR): Data Fault 2023-05-11T23:05:10.174Z,1683846310.174 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-11T23:05:10.567Z,1683846310.567 [NAL9602](INFO): Powering down 2023-05-11T23:05:11.426Z,1683846311.426 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-11T23:05:11.426Z,1683846311.426 [NAL9602] No Fault, FailCount= 2 2023-05-11T23:05:40.874Z,1683846340.874 [NAL9602](INFO): Powering up NAL9602 2023-05-11T23:05:51.773Z,1683846351.773 [NAL9602](INFO): NAL9602 initialized 2023-05-11T23:07:54.196Z,1683846474.196 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2023-05-11T23:07:54.196Z,1683846474.196 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:07:54.206Z,1683846474.206 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:07:54.611Z,1683846474.611 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:07:54.611Z,1683846474.611 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2023-05-11T23:09:48.545Z,1683846588.545 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2023-05-11T23:09:48.546Z,1683846588.546 [Default:CheckIn:C.Wait] Stopped 2023-05-11T23:09:48.546Z,1683846588.546 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2023-05-11T23:09:48.546Z,1683846588.546 [Default:CheckIn:D] Running Loop=1 2023-05-11T23:09:48.967Z,1683846588.967 [Default:CheckIn:D] Stopped 2023-05-11T23:09:48.967Z,1683846588.967 [Default:CheckIn:E] Running Loop=1 2023-05-11T23:09:49.389Z,1683846589.389 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.255275 min 2023-05-11T23:09:49.389Z,1683846589.389 [Default:CheckIn:E] Stopped 2023-05-11T23:09:49.389Z,1683846589.389 [Default:CheckIn](INFO): Completed Default:CheckIn 2023-05-11T23:09:49.389Z,1683846589.389 [Default:CheckIn] Stopped 2023-05-11T23:09:49.389Z,1683846589.389 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-11T23:09:49.389Z,1683846589.389 [Default:CheckIn](INFO): Running loop #3 2023-05-11T23:09:49.390Z,1683846589.390 [Default:CheckIn] Running Loop=3 2023-05-11T23:09:49.390Z,1683846589.390 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-11T23:09:49.390Z,1683846589.390 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-11T23:10:55.241Z,1683846655.241 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2023-05-11T23:10:55.241Z,1683846655.241 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:10:55.252Z,1683846655.252 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:10:55.618Z,1683846655.618 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:10:55.618Z,1683846655.618 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2023-05-11T23:13:56.229Z,1683846836.229 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2023-05-11T23:13:56.229Z,1683846836.229 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:13:56.264Z,1683846836.264 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:13:56.625Z,1683846836.625 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:13:56.625Z,1683846836.625 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2023-05-11T23:14:49.542Z,1683846889.542 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-11T23:09:49.4Z 2023-05-11T23:14:49.542Z,1683846889.542 [Default:CheckIn:Read_GPS] Stopped 2023-05-11T23:14:49.542Z,1683846889.542 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-11T23:14:56.775Z,1683846896.775 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230511T224335/Courier0010.lzma 2023-05-11T23:14:57.777Z,1683846897.777 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Courier0010.lzma.bak 2023-05-11T23:14:57.778Z,1683846897.778 [DataOverHttps](INFO): SBD MOMSN=18294359 2023-05-11T23:15:12.643Z,1683846912.643 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20230511T224335/Express0011.lzma 2023-05-11T23:15:13.649Z,1683846913.649 [DataOverHttps](INFO): Moved sent file to Logs/20230511T224335/Express0011.lzma.bak 2023-05-11T23:15:13.649Z,1683846913.649 [DataOverHttps](INFO): SBD MOMSN=18294361 2023-05-11T23:15:15.045Z,1683846915.045 [Default:CheckIn:Read_Iridium] Stopped 2023-05-11T23:15:15.045Z,1683846915.045 [Default:CheckIn:C.Wait] Running Loop=1 2023-05-11T23:15:15.045Z,1683846915.045 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2023-05-11T23:15:54.169Z,1683846954.169 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-11T23:15:54.169Z,1683846954.169 [NAL9602] Data Fault, FailCount= 3 2023-05-11T23:15:54.169Z,1683846954.169 [NAL9602](ERROR): Data Fault 2023-05-11T23:15:54.220Z,1683846954.220 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-11T23:15:54.573Z,1683846954.573 [NAL9602](INFO): Powering down 2023-05-11T23:15:55.470Z,1683846955.470 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-11T23:15:55.470Z,1683846955.470 [NAL9602] No Fault, FailCount= 3 2023-05-11T23:16:24.877Z,1683846984.877 [NAL9602](INFO): Powering up NAL9602 2023-05-11T23:16:35.785Z,1683846995.785 [NAL9602](INFO): NAL9602 initialized 2023-05-11T23:16:57.249Z,1683847017.249 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2023-05-11T23:16:57.249Z,1683847017.249 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-05-11T23:16:57.259Z,1683847017.259 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-05-11T23:16:57.618Z,1683847017.618 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-05-11T23:16:57.618Z,1683847017.618 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2023-05-11T23:17:20.049Z,1683847040.049 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree 2023-05-11T23:17:20.058Z,1683847040.058 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread. 2023-05-11T23:17:20.058Z,1683847040.058 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree 2023-05-11T23:17:20.063Z,1683847040.063 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread. 2023-05-11T23:17:20.063Z,1683847040.063 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter 2023-05-11T23:17:20.067Z,1683847040.067 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2023-05-11T23:17:20.067Z,1683847040.067 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range 2023-05-11T23:17:20.068Z,1683847040.068 [CommandExec](IMPORTANT): got command report touch acoustic_contact_range 2023-05-11T23:17:20.292Z,1683847040.292 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2023-05-11T23:17:47.785Z,1683847067.785 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683847040 second 2023-05-11T23:17:52.958Z,1683847072.958 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-11T23:18:25.876Z,1683847105.876 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:25.877Z,1683847105.877 [DATMMP](INFO): doppler rx: x0 2023-05-11T23:18:25.877Z,1683847105.877 [DATMMP](INFO): Received message type: doppler 2023-05-11T23:18:25.877Z,1683847105.877 [DATMMP](INFO): Handled 2023-05-11T23:18:26.128Z,1683847106.128 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:26.129Z,1683847106.129 [DATMMP](INFO): timestamp rx: x1 x17 x12 x16 x1CC7 2023-05-11T23:18:26.130Z,1683847106.130 [DATMMP](INFO): Rx dataTimestamp_ set to:1683847109.989184 2023-05-11T23:18:26.130Z,1683847106.130 [DATMMP](INFO): Rx ping set to:1683847106.129416 2023-05-11T23:18:26.131Z,1683847106.131 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:18:26.131Z,1683847106.131 [DATMMP](INFO): Handled 2023-05-11T23:18:26.380Z,1683847106.380 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:26.381Z,1683847106.381 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-11T23:18:26.381Z,1683847106.381 [DATMMP](INFO): Received message type: nav_stat 2023-05-11T23:18:26.382Z,1683847106.382 [DATMMP](INFO): Handled 2023-05-11T23:18:26.632Z,1683847106.632 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:26.634Z,1683847106.634 [DATMMP](INFO): directional_debug rx: x18F x101 x21 x1AA x2AC0 x3F61 x67F2 x5BA3 2023-05-11T23:18:26.635Z,1683847106.635 [DATMMP](INFO): Received message type: directional_debug 2023-05-11T23:18:26.635Z,1683847106.635 [DATMMP](INFO): Handled 2023-05-11T23:18:26.884Z,1683847106.884 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:26.886Z,1683847106.886 [DATMMP](INFO): directional rx: x1B1 xF0 x44D xFEFF xB06 xFEFD x0 x6BB x4 x0 x27B5966 x-43569E0 2023-05-11T23:18:26.889Z,1683847106.889 [DATMMP](INFO): Received message type: directional 2023-05-11T23:18:26.889Z,1683847106.889 [DATMMP](INFO): Handled 2023-05-11T23:18:27.136Z,1683847107.136 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:27.138Z,1683847107.138 [DATMMP](INFO): remote_header rx: x0 x62 x1 xA1 x1 xA xC x0 2023-05-11T23:18:27.138Z,1683847107.138 [DATMMP](INFO): DATA Src=12, Dst=10 2023-05-11T23:18:27.138Z,1683847107.138 [DATMMP](INFO): Received message type: remote_header 2023-05-11T23:18:27.138Z,1683847107.138 [DATMMP](INFO): Handled 2023-05-11T23:18:27.388Z,1683847107.388 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:27.390Z,1683847107.390 [DATMMP](INFO): acstats rx: xC x0 x0 x2D0 x23 x7D xAD xAD xD xFFFF x0 x23 x0 x0 2023-05-11T23:18:27.390Z,1683847107.390 [DATMMP](INFO): Received message type: acstats 2023-05-11T23:18:27.391Z,1683847107.391 [DATMMP](INFO): Handled 2023-05-11T23:18:27.640Z,1683847107.640 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:27.641Z,1683847107.641 [DATMMP](INFO): timestamp rx: x0 x17 x12 x18 xD43 2023-05-11T23:18:27.641Z,1683847107.641 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:18:27.642Z,1683847107.642 [DATMMP](INFO): Handled 2023-05-11T23:18:41.268Z,1683847121.268 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:41.269Z,1683847121.269 [DATMMP](INFO): doppler rx: xFFFF 2023-05-11T23:18:41.269Z,1683847121.269 [DATMMP](INFO): Received message type: doppler 2023-05-11T23:18:41.269Z,1683847121.269 [DATMMP](INFO): Handled 2023-05-11T23:18:41.520Z,1683847121.520 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:41.521Z,1683847121.521 [DATMMP](INFO): timestamp rx: x1 x17 x12 x26 x546 2023-05-11T23:18:41.522Z,1683847121.522 [DATMMP](INFO): Rx dataTimestamp_ set to:1683847131.192512 2023-05-11T23:18:41.522Z,1683847121.522 [DATMMP](INFO): Rx ping set to:1683847121.521238 2023-05-11T23:18:41.522Z,1683847121.522 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:18:41.522Z,1683847121.522 [DATMMP](INFO): Handled 2023-05-11T23:18:41.772Z,1683847121.772 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:41.773Z,1683847121.773 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-11T23:18:41.773Z,1683847121.773 [DATMMP](INFO): Received message type: nav_stat 2023-05-11T23:18:41.773Z,1683847121.773 [DATMMP](INFO): Handled 2023-05-11T23:18:42.024Z,1683847122.024 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:42.026Z,1683847122.026 [DATMMP](INFO): directional_debug rx: x181 x10E x23 x1FF x30D0 x3D81 x3152 x6483 2023-05-11T23:18:42.027Z,1683847122.027 [DATMMP](INFO): Received message type: directional_debug 2023-05-11T23:18:42.027Z,1683847122.027 [DATMMP](INFO): Handled 2023-05-11T23:18:42.277Z,1683847122.277 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:42.278Z,1683847122.278 [DATMMP](INFO): directional rx: x1A0 xF9 x45B xFEF2 xB12 xFEF1 x0 x6B8 x3 x1 x27B5966 x-43569E0 2023-05-11T23:18:42.281Z,1683847122.281 [DATMMP](INFO): Received message type: directional 2023-05-11T23:18:42.281Z,1683847122.281 [DATMMP](INFO): Handled 2023-05-11T23:18:42.528Z,1683847122.528 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:42.530Z,1683847122.530 [DATMMP](INFO): remote_header rx: x0 x62 x1 xA1 x1 xA xC x0 2023-05-11T23:18:42.530Z,1683847122.530 [DATMMP](INFO): DATA Src=12, Dst=10 2023-05-11T23:18:42.530Z,1683847122.530 [DATMMP](INFO): Received message type: remote_header 2023-05-11T23:18:42.530Z,1683847122.530 [DATMMP](INFO): Handled 2023-05-11T23:18:42.781Z,1683847122.781 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:42.783Z,1683847122.783 [DATMMP](INFO): acstats rx: xC x0 xFFFF x2D0 x23 x8B xAE xAC xD xFFFF x0 x23 x0 x0 2023-05-11T23:18:42.783Z,1683847122.783 [DATMMP](INFO): Received message type: acstats 2023-05-11T23:18:42.783Z,1683847122.783 [DATMMP](INFO): Handled 2023-05-11T23:18:43.033Z,1683847123.033 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:43.034Z,1683847123.034 [DATMMP](INFO): timestamp rx: x0 x17 x12 x27 x1CD2 2023-05-11T23:18:43.034Z,1683847123.034 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:18:43.034Z,1683847123.034 [DATMMP](INFO): Handled 2023-05-11T23:18:56.648Z,1683847136.648 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:56.649Z,1683847136.649 [DATMMP](INFO): doppler rx: xFFFF 2023-05-11T23:18:56.649Z,1683847136.649 [DATMMP](INFO): Received message type: doppler 2023-05-11T23:18:56.649Z,1683847136.649 [DATMMP](INFO): Handled 2023-05-11T23:18:56.900Z,1683847136.900 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:56.901Z,1683847136.901 [DATMMP](INFO): timestamp rx: x1 x17 x12 x35 x12F1 2023-05-11T23:18:56.902Z,1683847136.902 [DATMMP](INFO): Rx dataTimestamp_ set to:1683847180.370688 2023-05-11T23:18:56.902Z,1683847136.902 [DATMMP](INFO): Rx ping set to:1683847136.901339 2023-05-11T23:18:56.902Z,1683847136.902 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:18:56.902Z,1683847136.902 [DATMMP](INFO): Handled 2023-05-11T23:18:57.152Z,1683847137.152 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:57.153Z,1683847137.153 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-11T23:18:57.154Z,1683847137.154 [DATMMP](INFO): Received message type: nav_stat 2023-05-11T23:18:57.154Z,1683847137.154 [DATMMP](INFO): Handled 2023-05-11T23:18:57.404Z,1683847137.404 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:57.406Z,1683847137.406 [DATMMP](INFO): directional_debug rx: x189 x107 x23 x1D1 x3260 x3A71 x6292 x5FF3 2023-05-11T23:18:57.407Z,1683847137.407 [DATMMP](INFO): Received message type: directional_debug 2023-05-11T23:18:57.407Z,1683847137.407 [DATMMP](INFO): Handled 2023-05-11T23:18:57.656Z,1683847137.656 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:57.658Z,1683847137.658 [DATMMP](INFO): directional rx: x1AA xF4 x453 xFEF9 xB0B xFEF8 x0 x6B8 x1 x0 x27B5966 x-43569E0 2023-05-11T23:18:57.660Z,1683847137.660 [DATMMP](INFO): Received message type: directional 2023-05-11T23:18:57.660Z,1683847137.660 [DATMMP](INFO): Handled 2023-05-11T23:18:57.909Z,1683847137.909 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:57.910Z,1683847137.910 [DATMMP](INFO): remote_header rx: x0 x62 x1 xA1 x1 xA xC x0 2023-05-11T23:18:57.910Z,1683847137.910 [DATMMP](INFO): DATA Src=12, Dst=10 2023-05-11T23:18:57.911Z,1683847137.911 [DATMMP](INFO): Received message type: remote_header 2023-05-11T23:18:57.911Z,1683847137.911 [DATMMP](INFO): Handled 2023-05-11T23:18:58.160Z,1683847138.160 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:58.162Z,1683847138.162 [DATMMP](INFO): acstats rx: xC x0 xFFFF x2D0 x23 x81 xAE xAD xD xFFFF x0 x23 x0 x0 2023-05-11T23:18:58.162Z,1683847138.162 [DATMMP](INFO): Received message type: acstats 2023-05-11T23:18:58.162Z,1683847138.162 [DATMMP](INFO): Handled 2023-05-11T23:18:58.412Z,1683847138.412 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:18:58.413Z,1683847138.413 [DATMMP](INFO): timestamp rx: x0 x17 x12 x37 x36D 2023-05-11T23:18:58.413Z,1683847138.413 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:18:58.414Z,1683847138.414 [DATMMP](INFO): Handled 2023-05-11T23:19:11.776Z,1683847151.776 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:11.777Z,1683847151.777 [DATMMP](INFO): doppler rx: x0 2023-05-11T23:19:11.777Z,1683847151.777 [DATMMP](INFO): Received message type: doppler 2023-05-11T23:19:11.777Z,1683847151.777 [DATMMP](INFO): Handled 2023-05-11T23:19:12.028Z,1683847152.028 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:12.029Z,1683847152.029 [DATMMP](INFO): timestamp rx: x1 x17 x13 x8 x1AB4 2023-05-11T23:19:12.030Z,1683847152.030 [DATMMP](INFO): Rx dataTimestamp_ set to:1683847150.794624 2023-05-11T23:19:12.030Z,1683847152.030 [DATMMP](INFO): Rx ping set to:1683847152.029414 2023-05-11T23:19:12.030Z,1683847152.030 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:19:12.030Z,1683847152.030 [DATMMP](INFO): Handled 2023-05-11T23:19:12.281Z,1683847152.281 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:12.282Z,1683847152.282 [DATMMP](INFO): remote_header rx: xF x4 x5 x22 x0 xA xC x0 2023-05-11T23:19:12.282Z,1683847152.282 [DATMMP](INFO): DATA Src=12, Dst=10 2023-05-11T23:19:12.283Z,1683847152.283 [DATMMP](INFO): Received message type: remote_header 2023-05-11T23:19:12.283Z,1683847152.283 [DATMMP](INFO): Handled 2023-05-11T23:19:12.786Z,1683847152.786 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:12.788Z,1683847152.788 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-11T23:19:12.788Z,1683847152.788 [DATMMP](INFO): Received message type: nav_stat 2023-05-11T23:19:12.788Z,1683847152.788 [DATMMP](INFO): Handled 2023-05-11T23:19:13.036Z,1683847153.036 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:13.038Z,1683847153.038 [DATMMP](INFO): directional_debug rx: x17F x100 x23 x1C9 x31C0 x38F1 x5822 x6063 2023-05-11T23:19:13.039Z,1683847153.039 [DATMMP](INFO): Received message type: directional_debug 2023-05-11T23:19:13.039Z,1683847153.039 [DATMMP](INFO): Handled 2023-05-11T23:19:13.288Z,1683847153.288 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:13.290Z,1683847153.290 [DATMMP](INFO): directional rx: x19F xEE x45D xFF00 xB15 xFF01 x0 x6B9 x4 xFFFE x27B5966 x-43569E0 2023-05-11T23:19:13.292Z,1683847153.292 [DATMMP](INFO): Received message type: directional 2023-05-11T23:19:13.292Z,1683847153.292 [DATMMP](INFO): Handled 2023-05-11T23:19:13.540Z,1683847153.540 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:13.542Z,1683847153.542 [DATMMP](INFO): acstats rx: xC x5 x0 x2D0 x22 x81 xB7 xBE xD xFFFF x98 x20 xB x0 2023-05-11T23:19:13.542Z,1683847153.542 [DATMMP](INFO): Received message type: acstats 2023-05-11T23:19:13.542Z,1683847153.542 [DATMMP](INFO): Handled 2023-05-11T23:19:13.792Z,1683847153.792 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:13.793Z,1683847153.793 [DATMMP](INFO): data_rx rx: xC x0 x0 x22 2023-05-11T23:19:13.794Z,1683847153.794 [DATMMP](INFO): Check CRC 2023-05-11T23:19:13.794Z,1683847153.794 [DATMMP](INFO): data rx parseDataResponse 34 2023-05-11T23:19:13.794Z,1683847153.794 [DATMMP](INFO): Got DATA: len 34 2023-05-11T23:19:13.794Z,1683847153.794 [DATMMP](INFO): Received command: set _.pressure 0.747294 atmosphere 2023-05-11T23:19:13.795Z,1683847153.795 [DATMMP](INFO): #Outgoing data=1 2023-05-11T23:19:13.795Z,1683847153.795 [DATMMP](INFO): Sending ack 2023-05-11T23:19:13.795Z,1683847153.795 [DATMMP](INFO): Received message type: data_rx 2023-05-11T23:19:13.795Z,1683847153.795 [DATMMP](INFO): Handled 2023-05-11T23:19:13.795Z,1683847153.795 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-11T23:19:13.796Z,1683847153.796 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-11T23:19:14.047Z,1683847154.047 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:14.048Z,1683847154.048 [DATMMP](INFO): doppler rx: x0 2023-05-11T23:19:14.048Z,1683847154.048 [DATMMP](INFO): Received message type: doppler 2023-05-11T23:19:14.048Z,1683847154.048 [DATMMP](INFO): Handled 2023-05-11T23:19:14.048Z,1683847154.048 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-11T23:19:14.048Z,1683847154.048 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-11T23:19:14.301Z,1683847154.301 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:14.302Z,1683847154.302 [DATMMP](INFO): timestamp rx: x1 x17 x13 xA xE7C 2023-05-11T23:19:14.302Z,1683847154.302 [DATMMP](INFO): Rx dataTimestamp_ set to:1683847186.221184 2023-05-11T23:19:14.303Z,1683847154.303 [DATMMP](INFO): Rx ping set to:1683847154.301724 2023-05-11T23:19:14.303Z,1683847154.303 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:19:14.303Z,1683847154.303 [DATMMP](INFO): Handled 2023-05-11T23:19:14.303Z,1683847154.303 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-11T23:19:14.304Z,1683847154.304 [DATMMP](INFO): Tx to 12 len 4 xid 15 2023-05-11T23:19:14.307Z,1683847154.307 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-11T23:19:14.307Z,1683847154.307 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-11T23:19:14.552Z,1683847154.552 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:14.553Z,1683847154.553 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-11T23:19:14.553Z,1683847154.553 [DATMMP](INFO): Received message type: nav_stat 2023-05-11T23:19:14.554Z,1683847154.554 [DATMMP](INFO): Handled 2023-05-11T23:19:14.555Z,1683847154.555 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-11T23:19:14.804Z,1683847154.804 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:14.806Z,1683847154.806 [DATMMP](INFO): directional_debug rx: x1A1 xC7 x21 x17A x34D0 x3FF1 x6E62 x5373 2023-05-11T23:19:14.807Z,1683847154.807 [DATMMP](INFO): Received message type: directional_debug 2023-05-11T23:19:14.807Z,1683847154.807 [DATMMP](INFO): Handled 2023-05-11T23:19:14.807Z,1683847154.807 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-11T23:19:14.942Z,1683847154.942 [CommandExec](IMPORTANT): got command set _.pressure 0.747294 atmosphere 2023-05-11T23:19:15.056Z,1683847155.056 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:15.058Z,1683847155.058 [DATMMP](INFO): directional rx: x1CA xC3 x43B xFF39 xAF3 xFF39 x0 x6B9 x4 xFFFE x27B5966 x-43569E0 2023-05-11T23:19:15.060Z,1683847155.060 [DATMMP](INFO): Received message type: directional 2023-05-11T23:19:15.060Z,1683847155.060 [DATMMP](INFO): Handled 2023-05-11T23:19:15.060Z,1683847155.060 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-11T23:19:15.308Z,1683847155.308 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:15.310Z,1683847155.310 [DATMMP](INFO): remote_header rx: x0 x62 x1 xA1 x1 xA xC x0 2023-05-11T23:19:15.310Z,1683847155.310 [DATMMP](INFO): DATA Src=12, Dst=10 2023-05-11T23:19:15.310Z,1683847155.310 [DATMMP](INFO): Received message type: remote_header 2023-05-11T23:19:15.310Z,1683847155.310 [DATMMP](INFO): Handled 2023-05-11T23:19:15.310Z,1683847155.310 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-11T23:19:15.561Z,1683847155.561 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:15.562Z,1683847155.562 [DATMMP](INFO): acstats rx: xC x0 x0 x2D0 x22 x7C xB0 xAE xD xFFFF x0 x1F x0 x0 2023-05-11T23:19:15.563Z,1683847155.563 [DATMMP](INFO): Received message type: acstats 2023-05-11T23:19:15.563Z,1683847155.563 [DATMMP](INFO): Handled 2023-05-11T23:19:15.563Z,1683847155.563 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-11T23:19:15.812Z,1683847155.812 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:15.813Z,1683847155.813 [DATMMP](INFO): timestamp rx: x0 x17 x13 xB x2608 2023-05-11T23:19:15.813Z,1683847155.813 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:19:15.814Z,1683847155.814 [DATMMP](INFO): Handled 2023-05-11T23:19:15.814Z,1683847155.814 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-11T23:19:16.064Z,1683847156.064 [DATMMP](INFO): GSXN notify for xid: 15 2023-05-11T23:19:16.065Z,1683847156.065 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-11T23:19:16.066Z,1683847156.066 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED 2023-05-11T23:19:16.066Z,1683847156.066 [DATMMP](DEBUG): Command complete send 2023-05-11T23:19:16.066Z,1683847156.066 [DATMMP](ERROR): 1:COMPLETE 2023-05-11T23:19:16.066Z,1683847156.066 [DATMMP](INFO): Received message type: cmd_result 2023-05-11T23:19:16.066Z,1683847156.066 [DATMMP](INFO): Handled 2023-05-11T23:19:16.067Z,1683847156.067 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-11T23:19:16.067Z,1683847156.067 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-11T23:19:16.316Z,1683847156.316 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-11T23:19:16.317Z,1683847156.317 [DATMMP](INFO): timestamp rx: x0 x17 x13 xB x2160 2023-05-11T23:19:16.317Z,1683847156.317 [DATMMP](INFO): Received message type: timestamp 2023-05-11T23:19:16.318Z,1683847156.318 [DATMMP](INFO): Handled