2024-08-29T19:39:46.318Z,1724960386.318 [Supervisor](DEBUG): Initializing supervisor. 2024-08-29T19:39:46.322Z,1724960386.322 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2024-08-29T19:39:46.323Z,1724960386.323 [SyncHandler](INFO): Protected caller Thread ID is 829 2024-08-29T19:39:46.323Z,1724960386.323 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2024-08-29T19:39:46.324Z,1724960386.324 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2024-08-29T19:39:46.324Z,1724960386.324 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 830 2024-08-29T19:39:46.328Z,1724960386.328 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2024-08-29T19:39:46.346Z,1724960386.346 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2024-08-29T19:39:46.347Z,1724960386.347 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2024-08-29T19:39:46.347Z,1724960386.347 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 831 2024-08-29T19:39:46.351Z,1724960386.351 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2024-08-29T19:39:46.352Z,1724960386.352 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2024-08-29T19:39:46.352Z,1724960386.352 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 832 2024-08-29T19:39:46.354Z,1724960386.354 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2024-08-29T19:39:46.355Z,1724960386.355 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2024-08-29T19:39:46.356Z,1724960386.356 [logger ThreadHandler](INFO): Protected caller Thread ID is 833 2024-08-29T19:39:46.359Z,1724960386.359 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2024-08-29T19:39:46.360Z,1724960386.360 [Supervisor](INFO): Looking for Config files in directory: Config/ 2024-08-29T19:39:46.365Z,1724960386.365 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2024-08-29T19:39:46.473Z,1724960386.473 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2024-08-29T19:39:46.475Z,1724960386.475 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2024-08-29T19:39:46.724Z,1724960386.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2024-08-29T19:39:46.726Z,1724960386.726 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2024-08-29T19:39:47.006Z,1724960387.006 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2024-08-29T19:39:47.007Z,1724960387.007 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2024-08-29T19:39:47.127Z,1724960387.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2024-08-29T19:39:47.128Z,1724960387.128 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2024-08-29T19:39:47.913Z,1724960387.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2024-08-29T19:39:47.913Z,1724960387.913 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2024-08-29T19:39:48.450Z,1724960388.450 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2024-08-29T19:39:48.452Z,1724960388.452 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2024-08-29T19:39:49.015Z,1724960389.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2024-08-29T19:39:49.017Z,1724960389.017 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2024-08-29T19:39:49.471Z,1724960389.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2024-08-29T19:39:49.471Z,1724960389.471 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2024-08-29T19:39:50.330Z,1724960390.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2024-08-29T19:39:50.330Z,1724960390.330 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2024-08-29T19:39:50.734Z,1724960390.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2024-08-29T19:39:50.735Z,1724960390.735 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2024-08-29T19:39:50.982Z,1724960390.982 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2024-08-29T19:39:50.982Z,1724960390.982 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2024-08-29T19:39:51.136Z,1724960391.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2024-08-29T19:39:51.137Z,1724960391.137 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2024-08-29T19:39:51.229Z,1724960391.229 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2024-08-29T19:39:51.320Z,1724960391.320 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2024-08-29T19:39:51.521Z,1724960391.521 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2024-08-29T19:39:51.523Z,1724960391.523 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2024-08-29T19:39:51.771Z,1724960391.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2024-08-29T19:39:51.773Z,1724960391.773 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2024-08-29T19:39:51.775Z,1724960391.775 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2024-08-29T19:39:51.870Z,1724960391.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2024-08-29T19:39:52.146Z,1724960392.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2024-08-29T19:39:52.146Z,1724960392.146 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2024-08-29T19:39:52.300Z,1724960392.300 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2024-08-29T19:39:52.478Z,1724960392.478 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2024-08-29T19:39:52.588Z,1724960392.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2024-08-29T19:39:52.711Z,1724960392.711 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2024-08-29T19:39:52.835Z,1724960392.835 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2024-08-29T19:39:52.953Z,1724960392.953 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2024-08-29T19:39:53.128Z,1724960393.128 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg 2024-08-29T19:39:53.237Z,1724960393.237 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg 2024-08-29T19:39:53.333Z,1724960393.333 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2024-08-29T19:39:53.442Z,1724960393.442 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2024-08-29T19:39:53.544Z,1724960393.544 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2024-08-29T19:39:53.550Z,1724960393.550 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2024-08-29T19:39:53.766Z,1724960393.766 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2024-08-29T19:39:53.767Z,1724960393.767 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2024-08-29T19:39:53.953Z,1724960393.953 [BuoyancyServo] Loaded 2024-08-29T19:39:53.954Z,1724960393.954 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2024-08-29T19:39:53.977Z,1724960393.977 [ElevatorServo] Loaded 2024-08-29T19:39:53.977Z,1724960393.977 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2024-08-29T19:39:53.999Z,1724960393.999 [MassServo] Loaded 2024-08-29T19:39:53.000Z,1724960394.000 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2024-08-29T19:39:54.021Z,1724960394.021 [RudderServo] Loaded 2024-08-29T19:39:54.021Z,1724960394.021 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2024-08-29T19:39:54.039Z,1724960394.039 [ThrusterHE] Loaded 2024-08-29T19:39:54.039Z,1724960394.039 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2024-08-29T19:39:54.039Z,1724960394.039 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2024-08-29T19:39:54.041Z,1724960394.041 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2024-08-29T19:39:54.211Z,1724960394.211 [SBIT](DEBUG): Construct Startup Built In Test. 2024-08-29T19:39:54.226Z,1724960394.226 [SBIT] Loaded 2024-08-29T19:39:54.226Z,1724960394.226 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2024-08-29T19:39:54.229Z,1724960394.229 [IBIT](DEBUG): Construct Initiated Built In Test. 2024-08-29T19:39:54.250Z,1724960394.250 [IBIT] Loaded 2024-08-29T19:39:54.250Z,1724960394.250 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2024-08-29T19:39:54.255Z,1724960394.255 [CBIT](DEBUG): Construct Continuous Built In Test. 2024-08-29T19:39:54.476Z,1724960394.476 [CBIT] Loaded 2024-08-29T19:39:54.476Z,1724960394.476 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2024-08-29T19:39:54.476Z,1724960394.476 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2024-08-29T19:39:54.477Z,1724960394.477 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2024-08-29T19:39:55.206Z,1724960395.206 [CTD_Seabird] Loaded 2024-08-29T19:39:55.206Z,1724960395.206 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2024-08-29T19:39:55.207Z,1724960395.207 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406784E0 2024-08-29T19:39:55.207Z,1724960395.207 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 922 2024-08-29T19:39:55.242Z,1724960395.242 [ESPComponent] Loaded 2024-08-29T19:39:55.243Z,1724960395.243 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2024-08-29T19:39:55.264Z,1724960395.264 [PAR_Licor] Loaded 2024-08-29T19:39:55.265Z,1724960395.265 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2024-08-29T19:39:55.308Z,1724960395.308 [WetLabsBB2FL] Loaded 2024-08-29T19:39:55.308Z,1724960395.308 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2024-08-29T19:39:55.309Z,1724960395.309 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406A84E0 2024-08-29T19:39:55.309Z,1724960395.309 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 923 2024-08-29T19:39:55.310Z,1724960395.310 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2024-08-29T19:39:55.311Z,1724960395.311 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2024-08-29T19:39:55.381Z,1724960395.381 [DepthRateCalculator] Loaded 2024-08-29T19:39:55.382Z,1724960395.382 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2024-08-29T19:39:55.387Z,1724960395.387 [PitchRateCalculator] Loaded 2024-08-29T19:39:55.387Z,1724960395.387 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2024-08-29T19:39:55.397Z,1724960395.397 [SpeedCalculator] Loaded 2024-08-29T19:39:55.397Z,1724960395.397 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2024-08-29T19:39:55.402Z,1724960395.402 [YawRateCalculator] Loaded 2024-08-29T19:39:55.402Z,1724960395.402 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2024-08-29T19:39:55.422Z,1724960395.422 [ElevatorOffsetCalculator] Loaded 2024-08-29T19:39:55.422Z,1724960395.422 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2024-08-29T19:39:55.422Z,1724960395.422 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2024-08-29T19:39:55.423Z,1724960395.423 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2024-08-29T19:39:55.563Z,1724960395.563 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2024-08-29T19:39:55.563Z,1724960395.563 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2024-08-29T19:39:55.606Z,1724960395.606 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2024-08-29T19:39:55.606Z,1724960395.606 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2024-08-29T19:39:55.742Z,1724960395.742 [DeadReckonUsingMultipleVelocitySources] Loaded 2024-08-29T19:39:55.742Z,1724960395.742 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2024-08-29T19:39:55.756Z,1724960395.756 [NavChart] Loaded 2024-08-29T19:39:55.756Z,1724960395.756 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2024-08-29T19:39:55.762Z,1724960395.762 [UniversalFixResidualReporter] Loaded 2024-08-29T19:39:55.762Z,1724960395.762 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2024-08-29T19:39:55.763Z,1724960395.763 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2024-08-29T19:39:55.763Z,1724960395.763 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2024-08-29T19:39:56.620Z,1724960396.620 [AHRS_M2] Loaded 2024-08-29T19:39:56.620Z,1724960396.620 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2024-08-29T19:39:56.873Z,1724960396.873 [BackseatComponent] Loaded 2024-08-29T19:39:56.873Z,1724960396.873 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2024-08-29T19:39:56.874Z,1724960396.874 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A694E0 2024-08-29T19:39:56.874Z,1724960396.874 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 924 2024-08-29T19:39:56.877Z,1724960396.877 [LcmUniversalReporter] Loaded 2024-08-29T19:39:56.877Z,1724960396.877 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2024-08-29T19:39:57.626Z,1724960397.626 [BPC1] Loaded 2024-08-29T19:39:57.626Z,1724960397.626 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2024-08-29T19:39:57.722Z,1724960397.722 [DAT] Loaded 2024-08-29T19:39:57.723Z,1724960397.723 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2024-08-29T19:39:57.724Z,1724960397.724 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A994E0 2024-08-29T19:39:57.724Z,1724960397.724 [DAT ThreadHandler](INFO): Protected caller Thread ID is 925 2024-08-29T19:39:57.865Z,1724960397.865 [DataOverHttps] Loaded 2024-08-29T19:39:57.865Z,1724960397.865 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2024-08-29T19:39:57.866Z,1724960397.866 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40AC94E0 2024-08-29T19:39:57.866Z,1724960397.866 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 926 2024-08-29T19:39:57.890Z,1724960397.890 [Depth_Keller] Loaded 2024-08-29T19:39:57.890Z,1724960397.890 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2024-08-29T19:39:57.895Z,1724960397.895 [DropWeight] Loaded 2024-08-29T19:39:57.895Z,1724960397.895 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2024-08-29T19:39:57.936Z,1724960397.936 [DVL_micro] Loaded 2024-08-29T19:39:57.936Z,1724960397.936 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2024-08-29T19:39:57.999Z,1724960397.999 [NAL9602] Loaded 2024-08-29T19:39:57.999Z,1724960397.999 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2024-08-29T19:39:58.025Z,1724960398.025 [Onboard] Loaded 2024-08-29T19:39:58.025Z,1724960398.025 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2024-08-29T19:39:58.026Z,1724960398.026 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AF94E0 2024-08-29T19:39:58.026Z,1724960398.026 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 927 2024-08-29T19:39:58.040Z,1724960398.040 [Power24vConverter] Loaded 2024-08-29T19:39:58.041Z,1724960398.041 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2024-08-29T19:39:58.056Z,1724960398.056 [Radio_Surface] Loaded 2024-08-29T19:39:58.056Z,1724960398.056 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2024-08-29T19:39:58.057Z,1724960398.057 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B294E0 2024-08-29T19:39:58.058Z,1724960398.058 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 928 2024-08-29T19:39:58.073Z,1724960398.073 [Sonardyne_Nano] Loaded 2024-08-29T19:39:58.074Z,1724960398.074 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread. 2024-08-29T19:39:58.074Z,1724960398.074 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2024-08-29T19:39:58.076Z,1724960398.076 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2024-08-29T19:39:58.173Z,1724960398.173 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2024-08-29T19:39:58.175Z,1724960398.175 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2024-08-29T19:39:58.246Z,1724960398.246 [VerticalControl](DEBUG): Construct VerticalControl. 2024-08-29T19:39:58.580Z,1724960398.580 [VerticalControl] Loaded 2024-08-29T19:39:58.580Z,1724960398.580 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2024-08-29T19:39:58.583Z,1724960398.583 [HorizontalControl](DEBUG): Construct HorizontalControl. 2024-08-29T19:39:58.740Z,1724960398.740 [HorizontalControl] Loaded 2024-08-29T19:39:58.740Z,1724960398.740 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2024-08-29T19:39:58.743Z,1724960398.743 [SpeedControl](DEBUG): Construct SpeedControl. 2024-08-29T19:39:58.744Z,1724960398.744 [SpeedControl] Loaded 2024-08-29T19:39:58.745Z,1724960398.745 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2024-08-29T19:39:58.747Z,1724960398.747 [LoopControl](DEBUG): Construct LoopControl. 2024-08-29T19:39:58.748Z,1724960398.748 [LoopControl] Loaded 2024-08-29T19:39:58.748Z,1724960398.748 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2024-08-29T19:39:58.749Z,1724960398.749 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2024-08-29T19:39:58.749Z,1724960398.749 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2024-08-29T19:39:58.877Z,1724960398.877 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2024-08-29T19:39:58.878Z,1724960398.878 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2024-08-29T19:39:59.276Z,1724960399.276 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2024-08-29T19:39:59.282Z,1724960399.282 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2024-08-29T19:39:59.285Z,1724960399.285 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2024-08-29T19:39:59.297Z,1724960399.297 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2024-08-29T19:39:59.298Z,1724960399.298 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C514E0 2024-08-29T19:39:59.298Z,1724960399.298 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 929 2024-08-29T19:39:59.302Z,1724960399.302 [Supervisor](INFO): Main Thread ID is 822 2024-08-29T19:39:59.303Z,1724960399.303 [Supervisor](DEBUG): Running supervisor. 2024-08-29T19:39:59.303Z,1724960399.303 [CommandExec ThreadHandler](INFO): Handler Thread ID is 930 2024-08-29T19:39:59.304Z,1724960399.304 [CommandExec](INFO): Initializing the command executive. 2024-08-29T19:39:59.305Z,1724960399.305 [CommandLine ThreadHandler](INFO): Handler Thread ID is 931 2024-08-29T19:39:59.307Z,1724960399.307 [controlThread ThreadHandler](INFO): Handler Thread ID is 932 2024-08-29T19:39:59.308Z,1724960399.308 [controlThread](DEBUG): Initializing ControlThread 2024-08-29T19:39:59.309Z,1724960399.309 [SBIT](INFO): Initialize SBIT Component. 2024-08-29T19:39:59.310Z,1724960399.310 [SBIT](IMPORTANT): git: 2024-08-12-95-g598b95f60 2024-08-29T19:39:59.310Z,1724960399.310 [SBIT](INFO): git hash: 598b95f6033d24136933a3d5d1ddac5d4570ac95 2024-08-29T19:39:59.310Z,1724960399.310 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2024-08-29T19:39:59.312Z,1724960399.312 [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 2024-08-29T19:39:59.313Z,1724960399.313 [SBIT](INFO): Beginning SBIT in 107.000000 seconds. 2024-08-29T19:39:59.313Z,1724960399.313 [IBIT](INFO): Initialize IBIT Component. 2024-08-29T19:39:59.314Z,1724960399.314 [CBIT](DEBUG): Initialize CBIT Component. 2024-08-29T19:39:59.315Z,1724960399.315 [logger ThreadHandler](INFO): Handler Thread ID is 933 2024-08-29T19:39:59.328Z,1724960399.328 [CBIT](DEBUG): Initialized mux pins. 2024-08-29T19:39:59.328Z,1724960399.328 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2024-08-29T19:39:59.328Z,1724960399.328 [CBIT](DEBUG): Initializing the watchdog timer. 2024-08-29T19:39:59.340Z,1724960399.340 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 934 2024-08-29T19:39:59.341Z,1724960399.341 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2024-08-29T19:39:59.345Z,1724960399.345 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 936 2024-08-29T19:39:59.348Z,1724960399.348 [WetLabsBB2FL](INFO): Powering up 2024-08-29T19:39:59.349Z,1724960399.349 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 938 2024-08-29T19:39:59.352Z,1724960399.352 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2024-08-29T19:39:59.352Z,1724960399.352 [CBIT](DEBUG): Initializing heartbeat. 2024-08-29T19:39:59.367Z,1724960399.367 [DAT ThreadHandler](INFO): Handler Thread ID is 939 2024-08-29T19:39:59.367Z,1724960399.367 [DAT](INFO): Powering up 2024-08-29T19:39:59.368Z,1724960399.368 [DAT](DEBUG): Initializing DAT. 2024-08-29T19:39:59.373Z,1724960399.373 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 941 2024-08-29T19:39:59.374Z,1724960399.374 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2024-08-29T19:39:59.384Z,1724960399.384 [Onboard ThreadHandler](INFO): Handler Thread ID is 942 2024-08-29T19:39:59.402Z,1724960399.402 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 943 2024-08-29T19:39:59.420Z,1724960399.420 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 944 2024-08-29T19:39:59.424Z,1724960399.424 [CBIT](DEBUG): Deactivating GF circuits. 2024-08-29T19:39:59.424Z,1724960399.424 [CBIT](DEBUG): Deactivating emergency mode. 2024-08-29T19:39:59.431Z,1724960399.431 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/DK1NORSO.000 2024-08-29T19:39:59.431Z,1724960399.431 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from DK1NORSO.000 2024-08-29T19:39:59.431Z,1724960399.431 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/DK2NORS.000 2024-08-29T19:39:59.431Z,1724960399.431 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from DK2NORS.000 2024-08-29T19:39:59.431Z,1724960399.431 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/DK3HORRO.000 2024-08-29T19:39:59.431Z,1724960399.431 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from DK3HORRO.000 2024-08-29T19:39:59.464Z,1724960399.464 [CBIT](DEBUG): Backplane powered. 2024-08-29T19:39:59.468Z,1724960399.468 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2024-08-29T19:39:59.468Z,1724960399.468 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2024-08-29T19:39:59.469Z,1724960399.469 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2024-08-29T19:39:59.469Z,1724960399.469 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2024-08-29T19:39:59.469Z,1724960399.469 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2024-08-29T19:39:59.471Z,1724960399.471 [NavChart](DEBUG): Initialize NavChart Navigation. 2024-08-29T19:39:59.471Z,1724960399.471 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2024-08-29T19:39:59.486Z,1724960399.486 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2024-08-29T19:39:59.488Z,1724960399.488 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2024-08-29T19:39:59.489Z,1724960399.489 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2024-08-29T19:39:59.489Z,1724960399.489 [LoopControl](DEBUG): Initialize LoopControlComponent. 2024-08-29T19:39:59.490Z,1724960399.490 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser 2024-08-29T19:39:59.491Z,1724960399.491 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl 2024-08-29T19:39:59.491Z,1724960399.491 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl 2024-08-29T19:39:59.497Z,1724960399.497 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl 2024-08-29T19:39:59.578Z,1724960399.578 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into: 2024-08-29T19:39:59.602Z,1724960399.602 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2024-08-29T19:39:59.634Z,1724960399.634 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Startup { behavior Guidance:GoToSurface { run in progression } aggregate StartupSatComms { run in sequence readDatum { timeout duration=P1M Universal:latitude_fix } readDatum { timeout duration=P1M Universal:platform_communications } } } 2024-08-29T19:39:59.635Z,1724960399.635 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl 2024-08-29T19:39:59.635Z,1724960399.635 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl 2024-08-29T19:39:59.654Z,1724960399.654 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl 2024-08-29T19:39:59.808Z,1724960399.808 [Radio_Surface](INFO): Powering up 2024-08-29T19:39:59.946Z,1724960399.946 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into: 0 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2024-08-29T19:39:59.968Z,1724960399.968 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2024-08-29T19:39:59.969Z,1724960399.969 [Default:A.Wait](DEBUG): Construct Wait. 2024-08-29T19:39:59.971Z,1724960399.971 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2024-08-29T19:40:00.005Z,1724960400.005 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2024-08-29T19:40:00.007Z,1724960400.007 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2024-08-29T19:40:00.029Z,1724960400.029 [Default:E.Execute](DEBUG): Construct Execute. 2024-08-29T19:40:00.046Z,1724960400.046 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission Default { arguments { ElapsedSinceDefaultStarted = 0 minute } behavior Guidance:Wait { """ Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. """ run in sequence set duration = 13 second } behavior Guidance:GoToSurface { run in progression } aggregate CheckIn { run in sequence repeat=288 readDatum id="Read_GPS" { timeout duration=P5M Universal:time_fix } readDatum id="Read_Iridium" { timeout duration=P4H { behavior Guidance:Execute { run in sequence set command = "Burn on" } syslog critical "Dropped weight due to communications timeout." } Universal:platform_communications } behavior Guidance:Wait { run in sequence set duration = 5 minute } assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started ) syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute } syslog important "Restarting logs and Default mission." behavior Guidance:Execute { run in sequence set command = "restart logs" } } 2024-08-29T19:40:00.060Z,1724960400.060 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-08-29T19:40:00.074Z,1724960400.074 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-08-29T19:40:00.349Z,1724960400.349 [Power24vConverter](INFO): Powering up. 2024-08-29T19:40:00.350Z,1724960400.350 [Sonardyne_Nano](INFO): Initializing. 2024-08-29T19:40:00.398Z,1724960400.398 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2024-08-29T19:40:00.400Z,1724960400.400 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2024-08-29T19:40:00.402Z,1724960400.402 [ElevatorServo](DEBUG): Initializing EZServoServo. 2024-08-29T19:40:00.411Z,1724960400.411 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2024-08-29T19:40:00.412Z,1724960400.412 [MassServo](DEBUG): Initializing EZServoServo. 2024-08-29T19:40:00.424Z,1724960400.424 [MassServo](DEBUG): Initializing MassServo. 2024-08-29T19:40:00.425Z,1724960400.425 [RudderServo](DEBUG): Initializing EZServoServo. 2024-08-29T19:40:00.432Z,1724960400.432 [RudderServo](DEBUG): Initializing RudderServo. 2024-08-29T19:40:00.433Z,1724960400.433 [ThrusterHE](DEBUG): Initializing EZServoServo. 2024-08-29T19:40:00.440Z,1724960400.440 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2024-08-29T19:40:01.464Z,1724960401.464 [WetLabsBB2FL](INFO): Powering down 2024-08-29T19:40:02.498Z,1724960402.498 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART 2024-08-29T19:40:03.741Z,1724960403.741 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213 2024-08-29T19:40:05.821Z,1724960405.821 [ThrusterHE](ERROR): Zero Speed Commanded. 2024-08-29T19:40:12.472Z,1724960412.472 [DAT](INFO): DAT read: 2024-08-29T19:40:12.474Z,1724960412.474 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2024-08-29T19:40:14.237Z,1724960414.237 [DAT](INFO): DAT read: MF Frequency Band 2024-08-29T19:40:14.238Z,1724960414.238 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2024-08-29T19:40:14.238Z,1724960414.238 [DAT](INFO): DAT read: Jul 29 2000 19:32:23 2024-08-29T19:40:15.246Z,1724960415.246 [DAT](INFO): DAT read: Features enabled [Bearing] 2024-08-29T19:40:15.248Z,1724960415.248 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC 2024-08-29T19:40:15.248Z,1724960415.248 [DAT](INFO): commRate: 1200 2024-08-29T19:40:17.312Z,1724960417.312 [DAT](INFO): entering command mode 2024-08-29T19:40:17.512Z,1724960417.512 [DAT](INFO): DAT read: user:1> 2024-08-29T19:40:17.513Z,1724960417.513 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:17.764Z,1724960417.764 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:18.016Z,1724960418.016 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:18.268Z,1724960418.268 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:18.520Z,1724960418.520 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:18.772Z,1724960418.772 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:19.024Z,1724960419.024 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:19.276Z,1724960419.276 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:19.528Z,1724960419.528 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:19.780Z,1724960419.780 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:20.032Z,1724960420.032 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:20.284Z,1724960420.284 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:20.537Z,1724960420.537 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:20.788Z,1724960420.788 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:21.040Z,1724960421.040 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:21.292Z,1724960421.292 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:21.544Z,1724960421.544 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:21.796Z,1724960421.796 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:22.048Z,1724960422.048 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:22.300Z,1724960422.300 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:22.552Z,1724960422.552 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:22.804Z,1724960422.804 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:23.056Z,1724960423.056 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:23.309Z,1724960423.309 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:23.560Z,1724960423.560 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:23.812Z,1724960423.812 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:24.064Z,1724960424.064 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:24.316Z,1724960424.316 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:24.568Z,1724960424.568 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:24.820Z,1724960424.820 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:25.072Z,1724960425.072 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:25.324Z,1724960425.324 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:25.576Z,1724960425.576 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:25.644Z,1724960425.644 [MassServo](ERROR): getPosition uart error serial timeout 2024-08-29T19:40:25.644Z,1724960425.644 [MassServo](FAULT): Invalid EZ Servo response:"" 2024-08-29T19:40:25.644Z,1724960425.644 [MassServo] Communications Fault, FailCount= 1 2024-08-29T19:40:25.644Z,1724960425.644 [MassServo](ERROR): Communications Fault 2024-08-29T19:40:25.656Z,1724960425.656 [CBIT](ERROR): Communications Fault in component: MassServo 2024-08-29T19:40:25.831Z,1724960425.831 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:25.958Z,1724960425.958 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-08-29T19:40:25.958Z,1724960425.958 [MassServo](INFO): Powering down 2024-08-29T19:40:26.080Z,1724960426.080 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:26.332Z,1724960426.332 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:26.584Z,1724960426.584 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:26.760Z,1724960426.760 [MassServo](DEBUG): Initializing EZServoServo. 2024-08-29T19:40:26.836Z,1724960426.836 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:26.877Z,1724960426.877 [MassServo](DEBUG): Initializing MassServo. 2024-08-29T19:40:26.881Z,1724960426.881 [CBIT](INFO): Clearing failed state for component MassServo 2024-08-29T19:40:26.881Z,1724960426.881 [MassServo] No Fault, FailCount= 1 2024-08-29T19:40:27.088Z,1724960427.088 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:27.340Z,1724960427.340 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:27.592Z,1724960427.592 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:27.844Z,1724960427.844 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:28.096Z,1724960428.096 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:28.348Z,1724960428.348 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:28.355Z,1724960428.355 [NAL9602](INFO): Powering up NAL9602 2024-08-29T19:40:28.600Z,1724960428.600 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:28.852Z,1724960428.852 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:29.104Z,1724960429.104 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:29.356Z,1724960429.356 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:29.608Z,1724960429.608 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:29.860Z,1724960429.860 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:30.112Z,1724960430.112 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:30.368Z,1724960430.368 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:30.620Z,1724960430.620 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:30.872Z,1724960430.872 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:31.124Z,1724960431.124 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:31.376Z,1724960431.376 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:31.629Z,1724960431.629 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:31.880Z,1724960431.880 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:32.132Z,1724960432.132 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:32.385Z,1724960432.385 [DAT](DEBUG): checking for command mode acknowledgment 2024-08-29T19:40:32.385Z,1724960432.385 [DAT](FAULT): failed to enter command mode 2024-08-29T19:40:32.688Z,1724960432.688 [DAT](INFO): entering command mode 2024-08-29T19:40:32.888Z,1724960432.888 [DAT](INFO): DAT read: user:1> 2024-08-29T19:40:32.889Z,1724960432.889 [DAT](INFO): DAT read: Command '+++' not found 2024-08-29T19:40:32.890Z,1724960432.890 [DAT](INFO): DAT read: Error 2024-08-29T19:40:32.890Z,1724960432.890 [DAT](INFO): setting verbose to 3 2024-08-29T19:40:33.140Z,1724960433.140 [DAT](INFO): DAT read: user:2> 2024-08-29T19:40:33.142Z,1724960433.142 [DAT](INFO): DAT read: Verbose | 3 2024-08-29T19:40:33.142Z,1724960433.142 [DAT](INFO): set verbose to 3 2024-08-29T19:40:33.142Z,1724960433.142 [DAT](INFO): setting DatVerbose to 27440 2024-08-29T19:40:33.392Z,1724960433.392 [DAT](INFO): DAT read: user:3> 2024-08-29T19:40:33.393Z,1724960433.393 [DAT](INFO): DAT read: DatVerbose | 27440 2024-08-29T19:40:33.394Z,1724960433.394 [DAT](INFO): set DatVerbose to 27440 2024-08-29T19:40:33.394Z,1724960433.394 [DAT](INFO): setting transmit power to 8 2024-08-29T19:40:33.645Z,1724960433.645 [DAT](INFO): DAT read: user:4> 2024-08-29T19:40:33.647Z,1724960433.647 [DAT](INFO): DAT read: TxPower | 8 (Max) 2024-08-29T19:40:33.647Z,1724960433.647 [DAT](INFO): set transmit power to 8 2024-08-29T19:40:33.648Z,1724960433.648 [DAT](INFO): setting local address to 5 2024-08-29T19:40:33.896Z,1724960433.896 [DAT](INFO): DAT read: user:5> 2024-08-29T19:40:33.897Z,1724960433.897 [DAT](INFO): DAT read: LocalAddr | 5 2024-08-29T19:40:33.898Z,1724960433.898 [DAT](INFO): set local address to 5 2024-08-29T19:40:33.899Z,1724960433.899 [DAT](INFO): Setting time to: 19:40:33 And date to:8/29/2024 2024-08-29T19:40:34.148Z,1724960434.148 [DAT](INFO): DAT read: user:6> 2024-08-29T19:40:34.149Z,1724960434.149 [DAT](INFO): DAT read: Thu Aug 29, 2024 19:40:33 2024-08-29T19:40:34.150Z,1724960434.150 [DAT](INFO): Local DAT time set to Thu Aug 29, 2024 19:40:33 2024-08-29T19:40:39.277Z,1724960439.277 [NAL9602](INFO): NAL9602 initialized 2024-08-29T19:41:46.750Z,1724960506.750 [SBIT](IMPORTANT): Beginning Startup BIT 2024-08-29T19:41:46.755Z,1724960506.755 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:41:57.692Z,1724960517.692 [CBIT](IMPORTANT): Low side ground fault detected mA: CHAN A0 (Batt): 0.657037 CHAN A1 (24V): 0.722619 CHAN A2 (12V): 0.422406 CHAN A3 (5V): 0.109960 CHAN B0 (3.3V): 0.061677 CHAN B1 (3.15aV): 0.064893 CHAN B2 (3.15bV): 0.066205 CHAN B3 (GND): -0.037621 OPEN: 0.019451 Full Scale: +/- 1 mA 2024-08-29T19:42:18.542Z,1724960538.542 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004613 2024-08-29T19:42:40.903Z,1724960560.903 [SBIT](IMPORTANT): SBIT PASSED 2024-08-29T19:42:40.903Z,1724960560.903 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2024-08-29T19:42:41.582Z,1724960561.582 [MissionManager](IMPORTANT): Started mission Startup 2024-08-29T19:42:41.582Z,1724960561.582 [Startup] Running Loop=1 2024-08-29T19:42:41.582Z,1724960561.582 [Startup](DEBUG): Aggregate::initialize Startup 2024-08-29T19:42:41.583Z,1724960561.583 [Startup:A.GoToSurface] Running Loop=1 2024-08-29T19:42:41.583Z,1724960561.583 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-08-29T19:42:41.583Z,1724960561.583 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-08-29T19:42:41.604Z,1724960561.604 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-08-29T19:42:41.604Z,1724960561.604 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-08-29T19:42:41.605Z,1724960561.605 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-08-29T19:42:41.605Z,1724960561.605 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-08-29T19:42:41.605Z,1724960561.605 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-08-29T19:42:41.607Z,1724960561.607 [Startup:StartupSatComms] Running Loop=1 2024-08-29T19:42:41.607Z,1724960561.607 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2024-08-29T19:42:41.607Z,1724960561.607 [Startup:StartupSatComms:A] Running Loop=1 2024-08-29T19:42:41.848Z,1724960561.848 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2024-08-29T19:42:59.860Z,1724960579.860 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2024-08-29T19:42:59.860Z,1724960579.860 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2024-08-29T19:42:59.871Z,1724960579.871 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2024-08-29T19:43:00.273Z,1724960580.273 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2024-08-29T19:43:00.273Z,1724960580.273 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2024-08-29T19:43:37.701Z,1724960617.701 [CommandExec](IMPORTANT): got command gfscan 2024-08-29T19:43:37.875Z,1724960617.875 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:43:41.908Z,1724960621.908 [Startup:StartupSatComms:A](INFO): Timed out from 2024-08-29T19:42:41.6Z 2024-08-29T19:43:41.908Z,1724960621.908 [Startup:StartupSatComms:A] Stopped 2024-08-29T19:43:41.908Z,1724960621.908 [Startup:StartupSatComms:B] Running Loop=1 2024-08-29T19:43:42.302Z,1724960622.302 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-08-29T19:43:48.848Z,1724960628.848 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.055567 CHAN A1 (24V): 0.092203 CHAN A2 (12V): 0.031271 CHAN A3 (5V): 0.004346 CHAN B0 (3.3V): 0.000853 CHAN B1 (3.15aV): 0.002730 CHAN B2 (3.15bV): 0.003174 CHAN B3 (GND): -0.007274 OPEN: 0.009614 Full Scale: +/- 1 mA 2024-08-29T19:43:49.719Z,1724960629.719 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20240829T190919/Courier0010.lzma 2024-08-29T19:43:50.722Z,1724960630.722 [DataOverHttps](INFO): Moved sent file to Logs/20240829T190919/Courier0010.lzma.bak 2024-08-29T19:43:50.722Z,1724960630.722 [DataOverHttps](INFO): SBD MOMSN=23090608 2024-08-29T19:44:06.471Z,1724960646.471 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20240829T193946/Courier0000.lzma 2024-08-29T19:44:07.474Z,1724960647.474 [DataOverHttps](INFO): Moved sent file to Logs/20240829T193946/Courier0000.lzma.bak 2024-08-29T19:44:07.474Z,1724960647.474 [DataOverHttps](INFO): SBD MOMSN=23090630 2024-08-29T19:44:20.301Z,1724960660.301 [CommandExec](IMPORTANT): got command strobe off 2024-08-29T19:44:20.301Z,1724960660.301 [CommandExec](IMPORTANT): Deactivating strobe 2024-08-29T19:44:22.801Z,1724960662.801 [CommandExec](IMPORTANT): got command gfscan 2024-08-29T19:44:23.180Z,1724960663.180 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:44:25.163Z,1724960665.163 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20240829T190919/Express0011.lzma 2024-08-29T19:44:26.166Z,1724960666.166 [DataOverHttps](INFO): Moved sent file to Logs/20240829T190919/Express0011.lzma.bak 2024-08-29T19:44:26.166Z,1724960666.166 [DataOverHttps](INFO): SBD MOMSN=23090637 2024-08-29T19:44:34.466Z,1724960674.466 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.055467 CHAN A1 (24V): 0.091290 CHAN A2 (12V): 0.031198 CHAN A3 (5V): 0.004282 CHAN B0 (3.3V): 0.001945 CHAN B1 (3.15aV): 0.002821 CHAN B2 (3.15bV): 0.003889 CHAN B3 (GND): -0.007820 OPEN: 0.009664 Full Scale: +/- 1 mA 2024-08-29T19:44:42.326Z,1724960682.326 [Startup:StartupSatComms:B](INFO): Timed out from 2024-08-29T19:43:41.9Z 2024-08-29T19:44:42.326Z,1724960682.326 [Startup:StartupSatComms:B] Stopped 2024-08-29T19:44:42.326Z,1724960682.326 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2024-08-29T19:44:42.326Z,1724960682.326 [Startup:StartupSatComms] Stopped 2024-08-29T19:44:42.326Z,1724960682.326 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2024-08-29T19:44:42.327Z,1724960682.327 [Startup](INFO): Completed Startup 2024-08-29T19:44:42.327Z,1724960682.327 [MissionManager](INFO): Startup is completed. 2024-08-29T19:44:42.327Z,1724960682.327 [MissionManager](INFO): Uninitializing Mission Startup 2024-08-29T19:44:42.327Z,1724960682.327 [Startup] Stopped 2024-08-29T19:44:42.327Z,1724960682.327 [Startup](DEBUG): Aggregate::uninitialize Startup 2024-08-29T19:44:42.327Z,1724960682.327 [Startup:A.GoToSurface] Stopped 2024-08-29T19:44:42.336Z,1724960682.336 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2024-08-29T19:44:42.566Z,1724960682.566 [MissionManager](IMPORTANT): Started mission Default 2024-08-29T19:44:42.566Z,1724960682.566 [Default] Running Loop=1 2024-08-29T19:44:42.566Z,1724960682.566 [Default](DEBUG): Aggregate::initialize Default 2024-08-29T19:44:42.566Z,1724960682.566 [Default:B.GoToSurface] Running Loop=1 2024-08-29T19:44:42.566Z,1724960682.566 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2024-08-29T19:44:42.566Z,1724960682.566 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2024-08-29T19:44:42.567Z,1724960682.567 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2024-08-29T19:44:42.567Z,1724960682.567 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2024-08-29T19:44:42.567Z,1724960682.567 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2024-08-29T19:44:42.576Z,1724960682.576 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2024-08-29T19:44:42.577Z,1724960682.577 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2024-08-29T19:44:42.577Z,1724960682.577 [Default:A.Wait] Running Loop=1 2024-08-29T19:44:42.577Z,1724960682.577 [Default:A.Wait](DEBUG): Initialize Wait Component. 2024-08-29T19:44:46.415Z,1724960686.415 [DataOverHttps](INFO): Sending 834 bytes from file Logs/20240829T193946/Express0001.lzma 2024-08-29T19:44:47.413Z,1724960687.413 [DataOverHttps](INFO): Moved sent file to Logs/20240829T193946/Express0001.lzma.bak 2024-08-29T19:44:47.414Z,1724960687.414 [DataOverHttps](INFO): SBD MOMSN=23090658 2024-08-29T19:44:55.583Z,1724960695.583 [Default:A.Wait](INFO): Done Waiting. 2024-08-29T19:44:55.583Z,1724960695.583 [Default:A.Wait] Stopped 2024-08-29T19:44:55.583Z,1724960695.583 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2024-08-29T19:44:55.893Z,1724960695.893 [Default:CheckIn] Running Loop=1 2024-08-29T19:44:55.893Z,1724960695.893 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-29T19:44:55.894Z,1724960695.894 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-29T19:44:56.297Z,1724960696.297 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2024-08-29T19:45:31.765Z,1724960731.765 [CommandExec](IMPORTANT): got command gfscan 2024-08-29T19:45:31.826Z,1724960731.826 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:45:42.307Z,1724960742.307 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2024-08-29T19:45:42.746Z,1724960742.746 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.055916 CHAN A1 (24V): 0.092376 CHAN A2 (12V): 0.032039 CHAN A3 (5V): 0.004323 CHAN B0 (3.3V): 0.001586 CHAN B1 (3.15aV): 0.002877 CHAN B2 (3.15bV): 0.003859 CHAN B3 (GND): -0.007679 OPEN: 0.009669 Full Scale: +/- 1 mA 2024-08-29T19:45:43.520Z,1724960743.520 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194534.00,A,3648.17491,N,12147.27793,W,0.156,0.00,290824,,,A*7F 2024-08-29T19:45:43.523Z,1724960743.523 [NAL9602](INFO): GPS fix at 20240829T194534: (36.802915, -121.787965) 2024-08-29T19:45:43.566Z,1724960743.566 [Default:CheckIn:Read_GPS] Stopped 2024-08-29T19:45:43.566Z,1724960743.566 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-29T19:45:43.963Z,1724960743.963 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2024-08-29T19:45:51.175Z,1724960751.175 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20240829T193946/Courier0004.lzma 2024-08-29T19:45:52.178Z,1724960752.178 [DataOverHttps](INFO): Moved sent file to Logs/20240829T193946/Courier0004.lzma.bak 2024-08-29T19:45:52.179Z,1724960752.179 [DataOverHttps](INFO): SBD MOMSN=23090717 2024-08-29T19:46:09.776Z,1724960769.776 [DataOverHttps](INFO): Sending 624 bytes from file Logs/20240829T193946/Express0005.lzma 2024-08-29T19:46:10.778Z,1724960770.778 [DataOverHttps](INFO): Moved sent file to Logs/20240829T193946/Express0005.lzma.bak 2024-08-29T19:46:10.778Z,1724960770.778 [DataOverHttps](INFO): SBD MOMSN=23090741 2024-08-29T19:46:13.877Z,1724960773.877 [Default:CheckIn:Read_Iridium] Stopped 2024-08-29T19:46:13.877Z,1724960773.877 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-29T19:46:13.877Z,1724960773.877 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-29T19:46:16.287Z,1724960776.287 [NAL9602](INFO): Not Powering down - fast GPS 2024-08-29T19:47:52.161Z,1724960872.161 [CommandExec](IMPORTANT): got command gfscan 2024-08-29T19:47:52.231Z,1724960872.231 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:48:03.114Z,1724960883.114 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.188918 CHAN A1 (24V): 0.293374 CHAN A2 (12V): 0.124006 CHAN A3 (5V): 0.034654 CHAN B0 (3.3V): 0.020898 CHAN B1 (3.15aV): 0.023400 CHAN B2 (3.15bV): 0.024912 CHAN B3 (GND): -0.010997 OPEN: 0.013364 Full Scale: +/- 1 mA 2024-08-29T19:48:30.308Z,1724960910.308 [BPC1](ERROR): Battery stick #4 (s/n: 017A) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2024-08-29T19:48:30.309Z,1724960910.309 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2024-08-29T19:48:30.343Z,1724960910.343 [BPC1](INFO): Received data from all battery sticks. 2024-08-29T19:48:54.857Z,1724960934.857 [CommandExec](IMPORTANT): got command gfscan 2024-08-29T19:48:54.899Z,1724960934.899 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:49:06.189Z,1724960946.189 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.177906 CHAN A1 (24V): 0.281840 CHAN A2 (12V): 0.117659 CHAN A3 (5V): 0.031219 CHAN B0 (3.3V): 0.019321 CHAN B1 (3.15aV): 0.020145 CHAN B2 (3.15bV): 0.022484 CHAN B3 (GND): -0.009973 OPEN: 0.013896 Full Scale: +/- 1 mA 2024-08-29T19:50:20.469Z,1724961020.469 [CommandExec](IMPORTANT): got command show variable limitFwd 2024-08-29T19:50:20.632Z,1724961020.632 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter) 2024-08-29T19:50:28.065Z,1724961028.065 [CommandExec](IMPORTANT): got command get VerticalControl.massPositionLimitFwd 2024-08-29T19:50:28.066Z,1724961028.066 [CommandExec](IMPORTANT): VerticalControl.massPositionLimitFwd 41.000000 mm 2024-08-29T19:50:35.362Z,1724961035.362 [CommandExec](IMPORTANT): got command report mod platform_mass_position 2024-08-29T19:50:35.507Z,1724961035.507 [Reporter](INFO): platform_mass_position 0.021994 m 2024-08-29T19:50:51.114Z,1724961051.114 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 40.9 millimeter 2024-08-29T19:50:51.117Z,1724961051.117 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2024-08-29T19:50:51.257Z,1724961051.257 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-08-29T19:50:53.693Z,1724961053.693 [Reporter](INFO): platform_mass_position 0.022273 m 2024-08-29T19:50:54.105Z,1724961054.105 [Reporter](INFO): platform_mass_position 0.022595 m 2024-08-29T19:50:54.514Z,1724961054.514 [Reporter](INFO): platform_mass_position 0.022928 m 2024-08-29T19:50:54.890Z,1724961054.890 [Reporter](INFO): platform_mass_position 0.023218 m 2024-08-29T19:50:55.313Z,1724961055.313 [Reporter](INFO): platform_mass_position 0.023542 m 2024-08-29T19:50:55.706Z,1724961055.706 [Reporter](INFO): platform_mass_position 0.023862 m 2024-08-29T19:50:56.105Z,1724961056.105 [Reporter](INFO): platform_mass_position 0.024171 m 2024-08-29T19:50:56.506Z,1724961056.506 [Reporter](INFO): platform_mass_position 0.024486 m 2024-08-29T19:50:56.924Z,1724961056.924 [Reporter](INFO): platform_mass_position 0.024806 m 2024-08-29T19:50:57.343Z,1724961057.343 [Reporter](INFO): platform_mass_position 0.025141 m 2024-08-29T19:50:57.725Z,1724961057.725 [Reporter](INFO): platform_mass_position 0.025438 m 2024-08-29T19:50:58.142Z,1724961058.142 [Reporter](INFO): platform_mass_position 0.025756 m 2024-08-29T19:50:58.634Z,1724961058.634 [Reporter](INFO): platform_mass_position 0.026156 m 2024-08-29T19:50:59.065Z,1724961059.065 [Reporter](INFO): platform_mass_position 0.026480 m 2024-08-29T19:50:59.394Z,1724961059.394 [Reporter](INFO): platform_mass_position 0.026745 m 2024-08-29T19:50:59.902Z,1724961059.902 [Reporter](INFO): platform_mass_position 0.027150 m 2024-08-29T19:51:00.162Z,1724961060.162 [Reporter](INFO): platform_mass_position 0.027342 m 2024-08-29T19:51:00.558Z,1724961060.558 [Reporter](INFO): platform_mass_position 0.027665 m 2024-08-29T19:51:00.956Z,1724961060.956 [Reporter](INFO): platform_mass_position 0.027971 m 2024-08-29T19:51:01.366Z,1724961061.366 [Reporter](INFO): platform_mass_position 0.028288 m 2024-08-29T19:51:01.797Z,1724961061.797 [Reporter](INFO): platform_mass_position 0.028629 m 2024-08-29T19:51:02.220Z,1724961062.220 [Reporter](INFO): platform_mass_position 0.028959 m 2024-08-29T19:51:02.637Z,1724961062.637 [Reporter](INFO): platform_mass_position 0.029293 m 2024-08-29T19:51:03.001Z,1724961063.001 [Reporter](INFO): platform_mass_position 0.029572 m 2024-08-29T19:51:03.403Z,1724961063.403 [Reporter](INFO): platform_mass_position 0.029893 m 2024-08-29T19:51:03.786Z,1724961063.786 [Reporter](INFO): platform_mass_position 0.030193 m 2024-08-29T19:51:04.217Z,1724961064.217 [Reporter](INFO): platform_mass_position 0.030527 m 2024-08-29T19:51:04.615Z,1724961064.615 [Reporter](INFO): platform_mass_position 0.030842 m 2024-08-29T19:51:05.083Z,1724961065.083 [Reporter](INFO): platform_mass_position 0.031211 m 2024-08-29T19:51:05.406Z,1724961065.406 [Reporter](INFO): platform_mass_position 0.031459 m 2024-08-29T19:51:05.814Z,1724961065.814 [Reporter](INFO): platform_mass_position 0.031776 m 2024-08-29T19:51:06.229Z,1724961066.229 [Reporter](INFO): platform_mass_position 0.032099 m 2024-08-29T19:51:06.626Z,1724961066.626 [Reporter](INFO): platform_mass_position 0.032419 m 2024-08-29T19:51:07.013Z,1724961067.013 [Reporter](INFO): platform_mass_position 0.032724 m 2024-08-29T19:51:07.426Z,1724961067.426 [Reporter](INFO): platform_mass_position 0.033040 m 2024-08-29T19:51:07.849Z,1724961067.849 [Reporter](INFO): platform_mass_position 0.033370 m 2024-08-29T19:51:08.242Z,1724961068.242 [Reporter](INFO): platform_mass_position 0.033688 m 2024-08-29T19:51:08.640Z,1724961068.640 [Reporter](INFO): platform_mass_position 0.033991 m 2024-08-29T19:51:09.049Z,1724961069.049 [Reporter](INFO): platform_mass_position 0.034308 m 2024-08-29T19:51:09.442Z,1724961069.442 [Reporter](INFO): platform_mass_position 0.034628 m 2024-08-29T19:51:09.863Z,1724961069.863 [Reporter](INFO): platform_mass_position 0.034953 m 2024-08-29T19:51:10.286Z,1724961070.286 [Reporter](INFO): platform_mass_position 0.035282 m 2024-08-29T19:51:10.661Z,1724961070.661 [Reporter](INFO): platform_mass_position 0.035570 m 2024-08-29T19:51:11.062Z,1724961071.062 [Reporter](INFO): platform_mass_position 0.035894 m 2024-08-29T19:51:11.476Z,1724961071.476 [Reporter](INFO): platform_mass_position 0.036218 m 2024-08-29T19:51:11.865Z,1724961071.865 [Reporter](INFO): platform_mass_position 0.036520 m 2024-08-29T19:51:12.277Z,1724961072.277 [Reporter](INFO): platform_mass_position 0.036839 m 2024-08-29T19:51:12.688Z,1724961072.688 [Reporter](INFO): platform_mass_position 0.037157 m 2024-08-29T19:51:13.106Z,1724961073.106 [Reporter](INFO): platform_mass_position 0.037487 m 2024-08-29T19:51:13.481Z,1724961073.481 [Reporter](INFO): platform_mass_position 0.037788 m 2024-08-29T19:51:13.886Z,1724961073.886 [Reporter](INFO): platform_mass_position 0.038101 m 2024-08-29T19:51:14.282Z,1724961074.282 [Reporter](INFO): platform_mass_position 0.038422 m 2024-08-29T19:51:14.664Z,1724961074.664 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2024-08-29T19:51:14.664Z,1724961074.664 [Default:CheckIn:C.Wait] Stopped 2024-08-29T19:51:14.664Z,1724961074.664 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2024-08-29T19:51:14.664Z,1724961074.664 [Default:CheckIn:D] Running Loop=1 2024-08-29T19:51:14.718Z,1724961074.718 [Reporter](INFO): platform_mass_position 0.038750 m 2024-08-29T19:51:15.052Z,1724961075.052 [Default:CheckIn:D] Stopped 2024-08-29T19:51:15.052Z,1724961075.052 [Default:CheckIn:E] Running Loop=1 2024-08-29T19:51:15.093Z,1724961075.093 [Reporter](INFO): platform_mass_position 0.039054 m 2024-08-29T19:51:15.467Z,1724961075.467 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.541427 min 2024-08-29T19:51:15.467Z,1724961075.467 [Default:CheckIn:E] Stopped 2024-08-29T19:51:15.467Z,1724961075.467 [Default:CheckIn](INFO): Completed Default:CheckIn 2024-08-29T19:51:15.467Z,1724961075.467 [Default:CheckIn] Stopped 2024-08-29T19:51:15.467Z,1724961075.467 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2024-08-29T19:51:15.467Z,1724961075.467 [Default:CheckIn](INFO): Running loop #2 2024-08-29T19:51:15.468Z,1724961075.468 [Default:CheckIn] Running Loop=2 2024-08-29T19:51:15.468Z,1724961075.468 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2024-08-29T19:51:15.468Z,1724961075.468 [Default:CheckIn:Read_GPS] Running Loop=1 2024-08-29T19:51:15.509Z,1724961075.509 [Reporter](INFO): platform_mass_position 0.039379 m 2024-08-29T19:51:15.906Z,1724961075.906 [Reporter](INFO): platform_mass_position 0.039693 m 2024-08-29T19:51:16.298Z,1724961076.298 [Reporter](INFO): platform_mass_position 0.040001 m 2024-08-29T19:51:16.706Z,1724961076.706 [Reporter](INFO): platform_mass_position 0.040316 m 2024-08-29T19:51:17.133Z,1724961077.133 [Reporter](INFO): platform_mass_position 0.040651 m 2024-08-29T19:51:17.475Z,1724961077.475 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195111.00,A,3648.16749,N,12147.27801,W,0.214,354.34,290824,,,A*7E 2024-08-29T19:51:17.477Z,1724961077.477 [NAL9602](INFO): GPS fix at 20240829T195111: (36.802791, -121.787967) 2024-08-29T19:51:17.486Z,1724961077.486 [Default:CheckIn:Read_GPS] Stopped 2024-08-29T19:51:17.486Z,1724961077.486 [Default:CheckIn:Read_Iridium] Running Loop=1 2024-08-29T19:51:17.550Z,1724961077.550 [Reporter](INFO): platform_mass_position 0.040672 m 2024-08-29T19:51:25.858Z,1724961085.858 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20240829T193946/Courier0007.lzma 2024-08-29T19:51:26.858Z,1724961086.858 [DataOverHttps](INFO): Moved sent file to Logs/20240829T193946/Courier0007.lzma.bak 2024-08-29T19:51:26.858Z,1724961086.858 [DataOverHttps](INFO): SBD MOMSN=23090990 2024-08-29T19:51:37.848Z,1724961097.848 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 41 millimeter 2024-08-29T19:51:46.157Z,1724961106.157 [DataOverHttps](INFO): Sending 572 bytes from file Logs/20240829T193946/Express0008.lzma 2024-08-29T19:51:47.158Z,1724961107.158 [DataOverHttps](INFO): Moved sent file to Logs/20240829T193946/Express0008.lzma.bak 2024-08-29T19:51:47.158Z,1724961107.158 [DataOverHttps](INFO): SBD MOMSN=23091014 2024-08-29T19:51:48.216Z,1724961108.216 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2024-08-29T19:51:48.300Z,1724961108.300 [NAL9602](ERROR): received: +CSQ:0 OK 2024-08-29T19:51:50.203Z,1724961110.203 [Default:CheckIn:Read_Iridium] Stopped 2024-08-29T19:51:50.203Z,1724961110.203 [Default:CheckIn:C.Wait] Running Loop=1 2024-08-29T19:51:50.203Z,1724961110.203 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2024-08-29T19:51:54.381Z,1724961114.381 [CommandExec](IMPORTANT): got command maintain clear 2024-08-29T19:51:54.774Z,1724961114.774 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-08-29T19:51:55.522Z,1724961115.522 [Reporter](INFO): platform_mass_position 0.040402 m 2024-08-29T19:51:55.933Z,1724961115.933 [Reporter](INFO): platform_mass_position 0.040079 m 2024-08-29T19:51:56.334Z,1724961116.334 [Reporter](INFO): platform_mass_position 0.039768 m 2024-08-29T19:51:56.736Z,1724961116.736 [Reporter](INFO): platform_mass_position 0.039455 m 2024-08-29T19:51:57.109Z,1724961117.109 [Reporter](INFO): platform_mass_position 0.039159 m 2024-08-29T19:51:57.572Z,1724961117.572 [Reporter](INFO): platform_mass_position 0.038796 m 2024-08-29T19:51:57.938Z,1724961117.938 [Reporter](INFO): platform_mass_position 0.038509 m 2024-08-29T19:51:58.358Z,1724961118.358 [Reporter](INFO): platform_mass_position 0.038188 m 2024-08-29T19:51:58.771Z,1724961118.771 [Reporter](INFO): platform_mass_position 0.037862 m 2024-08-29T19:51:59.179Z,1724961119.179 [Reporter](INFO): platform_mass_position 0.037536 m 2024-08-29T19:51:59.556Z,1724961119.556 [Reporter](INFO): platform_mass_position 0.037251 m 2024-08-29T19:52:00.008Z,1724961120.008 [Reporter](INFO): platform_mass_position 0.036919 m 2024-08-29T19:52:00.410Z,1724961120.410 [Reporter](INFO): platform_mass_position 0.036569 m 2024-08-29T19:52:00.762Z,1724961120.762 [Reporter](INFO): platform_mass_position 0.036293 m 2024-08-29T19:52:01.173Z,1724961121.173 [Reporter](INFO): platform_mass_position 0.035978 m 2024-08-29T19:52:01.386Z,1724961121.386 [CommandExec](IMPORTANT): got command maintain control VerticalControl.massPositionAction 41 millimeter 2024-08-29T19:52:01.389Z,1724961121.389 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread. 2024-08-29T19:52:01.569Z,1724961121.569 [Reporter](INFO): platform_mass_position 0.035662 m 2024-08-29T19:52:01.574Z,1724961121.574 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-08-29T19:52:02.025Z,1724961122.025 [Reporter](INFO): platform_mass_position 0.035330 m 2024-08-29T19:52:02.410Z,1724961122.410 [Reporter](INFO): platform_mass_position 0.035286 m 2024-08-29T19:52:02.805Z,1724961122.805 [Reporter](INFO): platform_mass_position 0.035568 m 2024-08-29T19:52:03.209Z,1724961123.209 [Reporter](INFO): platform_mass_position 0.035886 m 2024-08-29T19:52:03.597Z,1724961123.597 [Reporter](INFO): platform_mass_position 0.036190 m 2024-08-29T19:52:04.013Z,1724961124.013 [Reporter](INFO): platform_mass_position 0.036516 m 2024-08-29T19:52:04.417Z,1724961124.417 [Reporter](INFO): platform_mass_position 0.036833 m 2024-08-29T19:52:04.833Z,1724961124.833 [Reporter](INFO): platform_mass_position 0.037154 m 2024-08-29T19:52:05.295Z,1724961125.295 [Reporter](INFO): platform_mass_position 0.037524 m 2024-08-29T19:52:05.618Z,1724961125.618 [Reporter](INFO): platform_mass_position 0.037777 m 2024-08-29T19:52:06.010Z,1724961126.010 [Reporter](INFO): platform_mass_position 0.038087 m 2024-08-29T19:52:06.409Z,1724961126.409 [Reporter](INFO): platform_mass_position 0.038393 m 2024-08-29T19:52:06.810Z,1724961126.810 [Reporter](INFO): platform_mass_position 0.038707 m 2024-08-29T19:52:07.225Z,1724961127.225 [Reporter](INFO): platform_mass_position 0.039025 m 2024-08-29T19:52:07.622Z,1724961127.622 [Reporter](INFO): platform_mass_position 0.039350 m 2024-08-29T19:52:08.058Z,1724961128.058 [Reporter](INFO): platform_mass_position 0.039691 m 2024-08-29T19:52:08.422Z,1724961128.422 [Reporter](INFO): platform_mass_position 0.039973 m 2024-08-29T19:52:08.841Z,1724961128.841 [Reporter](INFO): platform_mass_position 0.040291 m 2024-08-29T19:52:09.256Z,1724961129.256 [Reporter](INFO): platform_mass_position 0.040617 m 2024-08-29T19:52:09.698Z,1724961129.698 [Reporter](INFO): platform_mass_position 0.040672 m 2024-08-29T19:52:19.862Z,1724961139.862 [CommandExec](IMPORTANT): got command maintain clear 2024-08-29T19:52:20.210Z,1724961140.210 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2024-08-29T19:52:20.973Z,1724961140.973 [Reporter](INFO): platform_mass_position 0.040411 m 2024-08-29T19:52:21.377Z,1724961141.377 [Reporter](INFO): platform_mass_position 0.040094 m 2024-08-29T19:52:21.757Z,1724961141.757 [Reporter](INFO): platform_mass_position 0.039793 m 2024-08-29T19:52:22.161Z,1724961142.161 [Reporter](INFO): platform_mass_position 0.039476 m 2024-08-29T19:52:22.578Z,1724961142.578 [Reporter](INFO): platform_mass_position 0.039158 m 2024-08-29T19:52:22.979Z,1724961142.979 [Reporter](INFO): platform_mass_position 0.038834 m 2024-08-29T19:52:23.377Z,1724961143.377 [Reporter](INFO): platform_mass_position 0.038526 m 2024-08-29T19:52:23.842Z,1724961143.842 [Reporter](INFO): platform_mass_position 0.038174 m 2024-08-29T19:52:24.174Z,1724961144.174 [Reporter](INFO): platform_mass_position 0.037894 m 2024-08-29T19:52:24.599Z,1724961144.599 [Reporter](INFO): platform_mass_position 0.037568 m 2024-08-29T19:52:25.026Z,1724961145.026 [Reporter](INFO): platform_mass_position 0.037242 m 2024-08-29T19:52:25.422Z,1724961145.422 [Reporter](INFO): platform_mass_position 0.036917 m 2024-08-29T19:52:25.838Z,1724961145.838 [Reporter](INFO): platform_mass_position 0.036590 m 2024-08-29T19:52:26.265Z,1724961146.265 [Reporter](INFO): platform_mass_position 0.036261 m 2024-08-29T19:52:26.634Z,1724961146.634 [Reporter](INFO): platform_mass_position 0.035969 m 2024-08-29T19:52:26.837Z,1724961146.837 [CommandExec](IMPORTANT): got command report clear 2024-08-29T19:52:44.656Z,1724961164.656 [MassServo](ERROR): getPosition uart error serial timeout 2024-08-29T19:52:44.656Z,1724961164.656 [MassServo](FAULT): Invalid EZ Servo response:"" 2024-08-29T19:52:44.656Z,1724961164.656 [MassServo] Communications Fault, FailCount= 1 2024-08-29T19:52:44.657Z,1724961164.657 [MassServo](ERROR): Communications Fault 2024-08-29T19:52:44.663Z,1724961164.663 [CBIT](ERROR): Communications Fault in component: MassServo 2024-08-29T19:52:44.782Z,1724961164.782 [MassServo](DEBUG): Uninitialize Mass Servo. 2024-08-29T19:52:44.782Z,1724961164.782 [MassServo](INFO): Powering down 2024-08-29T19:52:45.561Z,1724961165.561 [MassServo](DEBUG): Initializing EZServoServo. 2024-08-29T19:52:45.677Z,1724961165.677 [MassServo](DEBUG): Initializing MassServo. 2024-08-29T19:52:45.681Z,1724961165.681 [CBIT](INFO): Clearing failed state for component MassServo 2024-08-29T19:52:45.681Z,1724961165.681 [MassServo] No Fault, FailCount= 1 2024-08-29T19:53:01.933Z,1724961181.933 [CommandExec](IMPORTANT): got command gfscan 2024-08-29T19:53:02.201Z,1724961182.201 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:53:06.564Z,1724961186.564 [AHRS_M2](FAULT): Failed to acquire valid data within timeout. 2024-08-29T19:53:06.564Z,1724961186.564 [AHRS_M2] Data Fault, FailCount= 1 2024-08-29T19:53:06.564Z,1724961186.564 [AHRS_M2](ERROR): Data Fault 2024-08-29T19:53:06.660Z,1724961186.660 [CBIT](ERROR): Data Fault in component: AHRS_M2 2024-08-29T19:53:06.949Z,1724961186.949 [AHRS_M2](INFO): Powering down 2024-08-29T19:53:07.820Z,1724961187.820 [CBIT](INFO): Clearing failed state for component AHRS_M2 2024-08-29T19:53:07.820Z,1724961187.820 [AHRS_M2] No Fault, FailCount= 1 2024-08-29T19:53:08.152Z,1724961188.152 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2024-08-29T19:53:13.106Z,1724961193.106 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.167854 CHAN A1 (24V): 0.262912 CHAN A2 (12V): 0.109259 CHAN A3 (5V): 0.030410 CHAN B0 (3.3V): 0.018156 CHAN B1 (3.15aV): 0.019686 CHAN B2 (3.15bV): 0.021831 CHAN B3 (GND): -0.011228 OPEN: 0.012860 Full Scale: +/- 1 mA 2024-08-29T19:53:29.993Z,1724961209.993 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -13.00 mm (1 active estimators). 2024-08-29T19:53:34.725Z,1724961214.725 [CommandExec](IMPORTANT): got command gfscan 2024-08-29T19:53:35.024Z,1724961215.024 [CBIT](IMPORTANT): Beginning ground fault scan 2024-08-29T19:53:36.455Z,1724961216.455 [DVL_micro](ERROR): No DVL communication! Re-initializing 2024-08-29T19:53:36.455Z,1724961216.455 [DVL_micro] Communications Fault, FailCount= 1 2024-08-29T19:53:36.455Z,1724961216.455 [DVL_micro](ERROR): Communications Fault 2024-08-29T19:53:36.631Z,1724961216.631 [CBIT](ERROR): Communications Fault in component: DVL_micro 2024-08-29T19:53:36.944Z,1724961216.944 [DVL_micro](INFO): Powering down 2024-08-29T19:53:37.253Z,1724961217.253 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.637244 decibar, -0.632544 m 2024-08-29T19:53:37.948Z,1724961217.948 [CBIT](INFO): Clearing failed state for component DVL_micro 2024-08-29T19:53:37.949Z,1724961217.949 [DVL_micro] No Fault, FailCount= 1 2024-08-29T19:53:40.107Z,1724961220.107 [Depth_Keller](ERROR): Pressure or depth reading out of range: -0.628202 decibar, -0.623569 m 2024-08-29T19:53:42.113Z,1724961222.113 [Depth_Keller](FAULT): Pressure or depth reading out of range for max 5 samples 2024-08-29T19:53:42.113Z,1724961222.113 [Depth_Keller] Data Fault, FailCount= 1 2024-08-29T19:53:42.113Z,1724961222.113 [Depth_Keller](ERROR): Data Fault 2024-08-29T19:53:42.157Z,1724961222.157 [CBIT](ERRO