2023-07-31T22:30:19.701Z,1690842619.701 [Supervisor](DEBUG): Initializing supervisor.
2023-07-31T22:30:19.706Z,1690842619.706 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-07-31T22:30:19.707Z,1690842619.707 [SyncHandler](INFO): Protected caller Thread ID is 2064
2023-07-31T22:30:19.707Z,1690842619.707 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-07-31T22:30:19.708Z,1690842619.708 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-07-31T22:30:19.708Z,1690842619.708 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2065
2023-07-31T22:30:19.713Z,1690842619.713 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-07-31T22:30:19.730Z,1690842619.730 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-07-31T22:30:19.731Z,1690842619.731 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-07-31T22:30:19.731Z,1690842619.731 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2066
2023-07-31T22:30:19.735Z,1690842619.735 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-07-31T22:30:19.736Z,1690842619.736 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-07-31T22:30:19.737Z,1690842619.737 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2067
2023-07-31T22:30:19.739Z,1690842619.739 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-07-31T22:30:19.740Z,1690842619.740 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-07-31T22:30:19.740Z,1690842619.740 [logger ThreadHandler](INFO): Protected caller Thread ID is 2068
2023-07-31T22:30:19.744Z,1690842619.744 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-07-31T22:30:19.744Z,1690842619.744 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-07-31T22:30:19.746Z,1690842619.746 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-07-31T22:30:19.908Z,1690842619.908 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-07-31T22:30:19.909Z,1690842619.909 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-07-31T22:30:20.156Z,1690842620.156 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-07-31T22:30:20.157Z,1690842620.157 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-07-31T22:30:20.407Z,1690842620.407 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-07-31T22:30:20.408Z,1690842620.408 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-07-31T22:30:20.517Z,1690842620.517 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-07-31T22:30:20.518Z,1690842620.518 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-07-31T22:30:21.224Z,1690842621.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-07-31T22:30:21.224Z,1690842621.224 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-07-31T22:30:21.695Z,1690842621.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-07-31T22:30:21.696Z,1690842621.696 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-07-31T22:30:22.168Z,1690842622.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-07-31T22:30:22.169Z,1690842622.169 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-07-31T22:30:22.559Z,1690842622.559 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-07-31T22:30:22.560Z,1690842622.560 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-07-31T22:30:22.894Z,1690842622.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-07-31T22:30:22.895Z,1690842622.895 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-07-31T22:30:23.756Z,1690842623.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-07-31T22:30:23.757Z,1690842623.757 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-07-31T22:30:23.975Z,1690842623.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-07-31T22:30:23.975Z,1690842623.975 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-07-31T22:30:24.115Z,1690842624.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-07-31T22:30:24.116Z,1690842624.116 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-07-31T22:30:24.199Z,1690842624.199 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-07-31T22:30:24.281Z,1690842624.281 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-07-31T22:30:24.462Z,1690842624.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-07-31T22:30:24.463Z,1690842624.463 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-07-31T22:30:24.688Z,1690842624.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-07-31T22:30:24.690Z,1690842624.690 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-07-31T22:30:24.691Z,1690842624.691 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-07-31T22:30:24.777Z,1690842624.777 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-07-31T22:30:25.112Z,1690842625.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-07-31T22:30:25.113Z,1690842625.113 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-07-31T22:30:25.251Z,1690842625.251 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-07-31T22:30:25.409Z,1690842625.409 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-07-31T22:30:25.511Z,1690842625.511 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-07-31T22:30:25.623Z,1690842625.623 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-07-31T22:30:25.734Z,1690842625.734 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-07-31T22:30:25.839Z,1690842625.839 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-07-31T22:30:25.998Z,1690842625.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2023-07-31T22:30:26.095Z,1690842626.095 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-07-31T22:30:26.193Z,1690842626.193 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-07-31T22:30:26.295Z,1690842626.295 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2023-07-31T22:30:26.295Z,1690842626.295 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-07-31T22:30:26.316Z,1690842626.316 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-07-31T22:30:26.473Z,1690842626.473 [InternalEnvSim] Loaded
2023-07-31T22:30:26.474Z,1690842626.474 [ComponentRegistry](DEBUG): SyncComponent "InternalEnvSim" handled in the control thread.
2023-07-31T22:30:26.474Z,1690842626.474 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-07-31T22:30:26.475Z,1690842626.475 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-07-31T22:30:26.607Z,1690842626.607 [BuoyancyServo] Loaded
2023-07-31T22:30:26.608Z,1690842626.608 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-07-31T22:30:26.628Z,1690842626.628 [ElevatorServo] Loaded
2023-07-31T22:30:26.628Z,1690842626.628 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-07-31T22:30:26.648Z,1690842626.648 [MassServo] Loaded
2023-07-31T22:30:26.648Z,1690842626.648 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-07-31T22:30:26.668Z,1690842626.668 [RudderServo] Loaded
2023-07-31T22:30:26.668Z,1690842626.668 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-07-31T22:30:26.686Z,1690842626.686 [ThrusterHE] Loaded
2023-07-31T22:30:26.686Z,1690842626.686 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-07-31T22:30:26.687Z,1690842626.687 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-07-31T22:30:26.687Z,1690842626.687 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-07-31T22:30:26.826Z,1690842626.826 [SBIT](DEBUG): Construct Startup Built In Test.
2023-07-31T22:30:26.841Z,1690842626.841 [SBIT] Loaded
2023-07-31T22:30:26.841Z,1690842626.841 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-07-31T22:30:26.844Z,1690842626.844 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-07-31T22:30:26.864Z,1690842626.864 [IBIT] Loaded
2023-07-31T22:30:26.864Z,1690842626.864 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-07-31T22:30:26.870Z,1690842626.870 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-07-31T22:30:27.085Z,1690842627.085 [CBIT] Loaded
2023-07-31T22:30:27.085Z,1690842627.085 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-07-31T22:30:27.086Z,1690842627.086 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-07-31T22:30:27.086Z,1690842627.086 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-07-31T22:30:27.260Z,1690842627.260 [CTD_Seabird] Loaded
2023-07-31T22:30:27.260Z,1690842627.260 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-07-31T22:30:27.261Z,1690842627.261 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406674E0
2023-07-31T22:30:27.262Z,1690842627.262 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2153
2023-07-31T22:30:27.293Z,1690842627.293 [ESPComponent] Loaded
2023-07-31T22:30:27.293Z,1690842627.293 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-07-31T22:30:27.312Z,1690842627.312 [PAR_Licor] Loaded
2023-07-31T22:30:27.312Z,1690842627.312 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-07-31T22:30:27.357Z,1690842627.357 [WetLabsBB2FL] Loaded
2023-07-31T22:30:27.358Z,1690842627.358 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-07-31T22:30:27.359Z,1690842627.359 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406974E0
2023-07-31T22:30:27.359Z,1690842627.359 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2154
2023-07-31T22:30:27.388Z,1690842627.388 [WetLabsSeaOWL_UV_A] Loaded
2023-07-31T22:30:27.388Z,1690842627.388 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2023-07-31T22:30:27.389Z,1690842627.389 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406C74E0
2023-07-31T22:30:27.390Z,1690842627.390 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2155
2023-07-31T22:30:27.390Z,1690842627.390 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-07-31T22:30:27.391Z,1690842627.391 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-07-31T22:30:27.444Z,1690842627.444 [DepthRateCalculator] Loaded
2023-07-31T22:30:27.444Z,1690842627.444 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-07-31T22:30:27.449Z,1690842627.449 [PitchRateCalculator] Loaded
2023-07-31T22:30:27.449Z,1690842627.449 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-07-31T22:30:27.460Z,1690842627.460 [SpeedCalculator] Loaded
2023-07-31T22:30:27.460Z,1690842627.460 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-07-31T22:30:27.465Z,1690842627.465 [YawRateCalculator] Loaded
2023-07-31T22:30:27.465Z,1690842627.465 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-07-31T22:30:27.484Z,1690842627.484 [ElevatorOffsetCalculator] Loaded
2023-07-31T22:30:27.484Z,1690842627.484 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-07-31T22:30:27.500Z,1690842627.500 [ShortestDistanceToPolygonSidesCalculator] Loaded
2023-07-31T22:30:27.501Z,1690842627.501 [ComponentRegistry](DEBUG): SyncComponent "ShortestDistanceToPolygonSidesCalculator" handled in the control thread.
2023-07-31T22:30:27.501Z,1690842627.501 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-07-31T22:30:27.502Z,1690842627.502 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-07-31T22:30:27.600Z,1690842627.600 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-07-31T22:30:27.601Z,1690842627.601 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-07-31T22:30:27.629Z,1690842627.629 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-07-31T22:30:27.629Z,1690842627.629 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-07-31T22:30:27.736Z,1690842627.736 [DeadReckonUsingSpeedCalculator] Loaded
2023-07-31T22:30:27.736Z,1690842627.736 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2023-07-31T22:30:27.791Z,1690842627.791 [NavChart] Loaded
2023-07-31T22:30:27.816Z,1690842627.816 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-07-31T22:30:27.822Z,1690842627.822 [UniversalFixResidualReporter] Loaded
2023-07-31T22:30:27.822Z,1690842627.822 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-07-31T22:30:27.823Z,1690842627.823 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-07-31T22:30:27.823Z,1690842627.823 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-07-31T22:30:28.875Z,1690842628.875 [AHRS_M2] Loaded
2023-07-31T22:30:28.875Z,1690842628.875 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-07-31T22:30:29.244Z,1690842629.244 [BackseatComponent] Loaded
2023-07-31T22:30:29.245Z,1690842629.245 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-07-31T22:30:29.252Z,1690842629.252 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A5C4E0
2023-07-31T22:30:29.252Z,1690842629.252 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2159
2023-07-31T22:30:29.255Z,1690842629.255 [LcmUniversalReporter] Loaded
2023-07-31T22:30:29.255Z,1690842629.255 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-07-31T22:30:31.284Z,1690842631.284 [BPC1] Loaded
2023-07-31T22:30:31.284Z,1690842631.284 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-07-31T22:30:31.762Z,1690842631.762 [DataOverHttps] Loaded
2023-07-31T22:30:31.762Z,1690842631.762 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-07-31T22:30:31.763Z,1690842631.763 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A8C4E0
2023-07-31T22:30:31.772Z,1690842631.772 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2160
2023-07-31T22:30:31.801Z,1690842631.801 [Depth_Keller] Loaded
2023-07-31T22:30:31.801Z,1690842631.801 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-07-31T22:30:31.806Z,1690842631.806 [DropWeight] Loaded
2023-07-31T22:30:31.806Z,1690842631.806 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-07-31T22:30:31.869Z,1690842631.869 [DVL_micro] Loaded
2023-07-31T22:30:31.870Z,1690842631.870 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-07-31T22:30:31.955Z,1690842631.955 [NAL9602] Loaded
2023-07-31T22:30:31.955Z,1690842631.955 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-07-31T22:30:31.998Z,1690842631.998 [Onboard] Loaded
2023-07-31T22:30:31.998Z,1690842631.998 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-07-31T22:30:31.999Z,1690842631.999 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40ABC4E0
2023-07-31T22:30:31.999Z,1690842631.999 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2161
2023-07-31T22:30:32.020Z,1690842632.020 [Power24vConverter] Loaded
2023-07-31T22:30:32.020Z,1690842632.020 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-07-31T22:30:32.033Z,1690842632.033 [Radio_Surface] Loaded
2023-07-31T22:30:32.033Z,1690842632.033 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-07-31T22:30:32.040Z,1690842632.040 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AEC4E0
2023-07-31T22:30:32.040Z,1690842632.040 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2162
2023-07-31T22:30:32.054Z,1690842632.054 [Sonardyne_Nano] Loaded
2023-07-31T22:30:32.054Z,1690842632.054 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-07-31T22:30:32.055Z,1690842632.055 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-07-31T22:30:32.055Z,1690842632.055 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-07-31T22:30:32.146Z,1690842632.146 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-07-31T22:30:32.146Z,1690842632.146 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-07-31T22:30:32.232Z,1690842632.232 [VerticalControl](DEBUG): Construct VerticalControl.
2023-07-31T22:30:32.306Z,1690842632.306 [VerticalControl] Loaded
2023-07-31T22:30:32.307Z,1690842632.307 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-07-31T22:30:32.310Z,1690842632.310 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-07-31T22:30:32.363Z,1690842632.363 [HorizontalControl] Loaded
2023-07-31T22:30:32.363Z,1690842632.363 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-07-31T22:30:32.366Z,1690842632.366 [SpeedControl](DEBUG): Construct SpeedControl.
2023-07-31T22:30:32.376Z,1690842632.376 [SpeedControl] Loaded
2023-07-31T22:30:32.376Z,1690842632.376 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-07-31T22:30:32.379Z,1690842632.379 [LoopControl](DEBUG): Construct LoopControl.
2023-07-31T22:30:32.379Z,1690842632.379 [LoopControl] Loaded
2023-07-31T22:30:32.380Z,1690842632.380 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-07-31T22:30:32.380Z,1690842632.380 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-07-31T22:30:32.380Z,1690842632.380 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-07-31T22:30:32.391Z,1690842632.391 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-07-31T22:30:32.391Z,1690842632.391 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-07-31T22:30:32.852Z,1690842632.852 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-07-31T22:30:32.859Z,1690842632.859 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-07-31T22:30:32.862Z,1690842632.862 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-07-31T22:30:32.881Z,1690842632.881 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-07-31T22:30:32.882Z,1690842632.882 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BF84E0
2023-07-31T22:30:32.882Z,1690842632.882 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2163
2023-07-31T22:30:32.888Z,1690842632.888 [Supervisor](INFO): Main Thread ID is 2062
2023-07-31T22:30:32.888Z,1690842632.888 [Supervisor](DEBUG): Running supervisor.
2023-07-31T22:30:32.896Z,1690842632.896 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2164
2023-07-31T22:30:32.896Z,1690842632.896 [CommandExec](INFO): Initializing the command executive.
2023-07-31T22:30:32.898Z,1690842632.898 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2165
2023-07-31T22:30:32.901Z,1690842632.901 [controlThread ThreadHandler](INFO): Handler Thread ID is 2166
2023-07-31T22:30:32.902Z,1690842632.902 [controlThread](DEBUG): Initializing ControlThread
2023-07-31T22:30:32.903Z,1690842632.903 [InternalEnvSim](DEBUG):  InternaEnvlSim initializing...
2023-07-31T22:30:32.924Z,1690842632.924 [logger ThreadHandler](INFO): Handler Thread ID is 2167
2023-07-31T22:30:32.964Z,1690842632.964 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2168
2023-07-31T22:30:32.965Z,1690842632.965 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-07-31T22:30:32.972Z,1690842632.972 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2170
2023-07-31T22:30:32.990Z,1690842632.990 [WetLabsBB2FL](INFO): Powering up
2023-07-31T22:30:32.991Z,1690842632.991 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2172
2023-07-31T22:30:33.001Z,1690842633.001 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2173
2023-07-31T22:30:33.024Z,1690842633.024 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2174
2023-07-31T22:30:33.025Z,1690842633.025 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-07-31T22:30:33.044Z,1690842633.044 [Onboard ThreadHandler](INFO): Handler Thread ID is 2175
2023-07-31T22:30:33.072Z,1690842633.072 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2176
2023-07-31T22:30:33.096Z,1690842633.096 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2177
2023-07-31T22:30:33.115Z,1690842633.115 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-07-31T22:30:33.115Z,1690842633.115 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000
2023-07-31T22:30:33.116Z,1690842633.116 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI80M.000
2023-07-31T22:30:33.123Z,1690842633.123 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2023-07-31T22:30:33.214Z,1690842633.214 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-07-31T22:30:33.215Z,1690842633.215 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI01M.000
2023-07-31T22:30:33.216Z,1690842633.216 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI80M.000
2023-07-31T22:30:33.217Z,1690842633.217 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI80M.000
2023-07-31T22:30:33.217Z,1690842633.217 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI57M.000
2023-07-31T22:30:33.218Z,1690842633.218 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI57M.000
2023-07-31T22:30:33.219Z,1690842633.219 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI56M.000
2023-07-31T22:30:33.252Z,1690842633.252 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI56M.000
2023-07-31T22:30:33.252Z,1690842633.252 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI90M.000
2023-07-31T22:30:33.254Z,1690842633.254 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI90M.000
2023-07-31T22:30:33.254Z,1690842633.254 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2023-07-31T22:30:33.256Z,1690842633.256 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI89M.000
2023-07-31T22:30:33.256Z,1690842633.256 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH01M.000
2023-07-31T22:30:33.257Z,1690842633.257 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH01M.000
2023-07-31T22:30:33.258Z,1690842633.258 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH04M.000
2023-07-31T22:30:33.259Z,1690842633.259 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH04M.000
2023-07-31T22:30:33.259Z,1690842633.259 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH02M.000
2023-07-31T22:30:33.265Z,1690842633.265 [SBIT](INFO): Initialize SBIT Component.
2023-07-31T22:30:33.265Z,1690842633.265 [SBIT](IMPORTANT): git: 2023-07-31-1-gc2e44910c
2023-07-31T22:30:33.265Z,1690842633.265 [SBIT](INFO): git hash: c2e44910c6e56a8023a8b1a81178d1dbbd33b4c5
2023-07-31T22:30:33.266Z,1690842633.266 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-07-31T22:30:33.267Z,1690842633.267 [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
2023-07-31T22:30:33.268Z,1690842633.268 [SBIT](INFO): Beginning SBIT in 54.000000 seconds.
2023-07-31T22:30:33.284Z,1690842633.284 [IBIT](INFO): Initialize IBIT Component.
2023-07-31T22:30:33.285Z,1690842633.285 [CBIT](DEBUG): Initialize CBIT Component.
2023-07-31T22:30:33.286Z,1690842633.286 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH02M.000
2023-07-31T22:30:33.287Z,1690842633.287 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA20M.000
2023-07-31T22:30:33.304Z,1690842633.304 [CBIT](DEBUG): Initialized mux pins.
2023-07-31T22:30:33.304Z,1690842633.304 [CBIT](DEBUG): Initializing the watchdog timer.
2023-07-31T22:30:33.305Z,1690842633.305 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4PA20M.000
2023-07-31T22:30:33.305Z,1690842633.305 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA21M.000
2023-07-31T22:30:33.307Z,1690842633.307 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4PA21M.000
2023-07-31T22:30:33.325Z,1690842633.325 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4PA21M.000
2023-07-31T22:30:33.332Z,1690842633.332 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4PA21M.000
2023-07-31T22:30:33.332Z,1690842633.332 [NavChartDb](INFO): # of records loaded: 0
2023-07-31T22:30:33.334Z,1690842633.334 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4PA21M.000
2023-07-31T22:30:33.348Z,1690842633.348 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-07-31T22:30:33.348Z,1690842633.348 [CBIT](DEBUG): Initializing heartbeat.
2023-07-31T22:30:33.429Z,1690842633.429 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4PA20M.000
2023-07-31T22:30:33.432Z,1690842633.432 [CBIT](DEBUG): Deactivating GF circuits.
2023-07-31T22:30:33.432Z,1690842633.432 [CBIT](DEBUG): Deactivating emergency mode.
2023-07-31T22:30:33.432Z,1690842633.432 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4PA20M.000
2023-07-31T22:30:33.432Z,1690842633.432 [NavChartDb](INFO): # of records loaded: 0
2023-07-31T22:30:33.434Z,1690842633.434 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4PA20M.000
2023-07-31T22:30:33.472Z,1690842633.472 [CBIT](DEBUG): Backplane powered.
2023-07-31T22:30:33.476Z,1690842633.476 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-07-31T22:30:33.477Z,1690842633.477 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-07-31T22:30:33.477Z,1690842633.477 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-07-31T22:30:33.478Z,1690842633.478 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-07-31T22:30:33.478Z,1690842633.478 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-07-31T22:30:33.478Z,1690842633.478 [ShortestDistanceToPolygonSidesCalculator](DEBUG): Initializing.
2023-07-31T22:30:33.480Z,1690842633.480 [Radio_Surface](INFO): Powering up
2023-07-31T22:30:33.479Z,1690842633.479 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-07-31T22:30:33.482Z,1690842633.482 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-07-31T22:30:33.483Z,1690842633.483 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-07-31T22:30:33.506Z,1690842633.506 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-07-31T22:30:33.520Z,1690842633.520 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-07-31T22:30:33.520Z,1690842633.520 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-07-31T22:30:33.521Z,1690842633.521 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-07-31T22:30:33.522Z,1690842633.522 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-07-31T22:30:33.540Z,1690842633.540 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH02M.000
2023-07-31T22:30:33.543Z,1690842633.543 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4OH02M.000
2023-07-31T22:30:33.543Z,1690842633.543 [NavChartDb](INFO): # of records loaded: 0
2023-07-31T22:30:33.545Z,1690842633.545 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH02M.000
2023-07-31T22:30:33.622Z,1690842633.622 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-07-31T22:30:33.645Z,1690842633.645 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-07-31T22:30:33.645Z,1690842633.645 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4OH04M.000
2023-07-31T22:30:33.646Z,1690842633.646 [NavChartDb](INFO): # of records loaded: 0
2023-07-31T22:30:33.647Z,1690842633.647 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH04M.000
2023-07-31T22:30:33.666Z,1690842633.666 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2023-07-31T22:30:33.667Z,1690842633.667 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-07-31T22:30:33.756Z,1690842633.756 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH01M.000
2023-07-31T22:30:33.757Z,1690842633.757 [NavChartDb](FAULT): Error opening file: Resources/ElectronicNavigationCharts/US4OH01M.000
2023-07-31T22:30:33.757Z,1690842633.757 [NavChartDb](INFO): # of records loaded: 0
2023-07-31T22:30:33.759Z,1690842633.759 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH01M.000
2023-07-31T22:30:33.770Z,1690842633.770 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-07-31T22:30:33.771Z,1690842633.771 [Default:A.Wait](DEBUG): Construct Wait.
2023-07-31T22:30:33.774Z,1690842633.774 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-07-31T22:30:33.818Z,1690842633.818 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-07-31T22:30:33.821Z,1690842633.821 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-07-31T22:30:33.836Z,1690842633.836 [Default:E.Execute](DEBUG): Construct Execute.
2023-07-31T22:30:33.860Z,1690842633.860 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-07-31T22:30:33.861Z,1690842633.861 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P4H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2023-07-31T22:30:33.885Z,1690842633.885 [controlThread](DEBUG): Component order: CycleStarter,InternalEnvSim,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,ShortestDistanceToPolygonSidesCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-07-31T22:30:33.953Z,1690842633.953 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-07-31T22:30:34.161Z,1690842634.161 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.894409 decibar, 0.000000 m
2023-07-31T22:30:34.173Z,1690842634.173 [Power24vConverter](INFO): Powering up.
2023-07-31T22:30:34.173Z,1690842634.173 [Sonardyne_Nano](INFO): Initializing.
2023-07-31T22:30:34.225Z,1690842634.225 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-07-31T22:30:34.274Z,1690842634.274 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-07-31T22:30:34.276Z,1690842634.276 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-07-31T22:30:34.277Z,1690842634.277 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-07-31T22:30:34.280Z,1690842634.280 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-07-31T22:30:34.281Z,1690842634.281 [MassServo](DEBUG): Initializing EZServoServo.
2023-07-31T22:30:34.316Z,1690842634.316 [MassServo](DEBUG): Initializing MassServo.
2023-07-31T22:30:34.317Z,1690842634.317 [RudderServo](DEBUG): Initializing EZServoServo.
2023-07-31T22:30:34.344Z,1690842634.344 [RudderServo](DEBUG): Initializing RudderServo.
2023-07-31T22:30:34.345Z,1690842634.345 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-07-31T22:30:34.348Z,1690842634.348 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-07-31T22:30:34.632Z,1690842634.632 [DVL_micro](INFO): Powering down
2023-07-31T22:30:35.092Z,1690842635.092 [WetLabsBB2FL](INFO): Powering down
2023-07-31T22:30:36.334Z,1690842636.334 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-07-31T22:30:36.431Z,1690842636.431 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-07-31T22:30:37.685Z,1690842637.685 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2023-07-31T22:30:39.837Z,1690842639.837 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-07-31T22:30:51.919Z,1690842651.919 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005011
2023-07-31T22:30:59.089Z,1690842659.089 [NavChartDb](INFO): # of records loaded: 5000
2023-07-31T22:31:02.354Z,1690842662.354 [NAL9602](INFO): Powering up NAL9602
2023-07-31T22:31:11.122Z,1690842671.122 [NavChartDb](INFO): # of records loaded: 10000
2023-07-31T22:31:13.282Z,1690842673.282 [NAL9602](INFO): NAL9602 initialized
2023-07-31T22:31:16.280Z,1690842676.280 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-07-31T22:31:16.626Z,1690842676.626 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-07-31T22:31:21.032Z,1690842681.032 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI89M.000
2023-07-31T22:31:21.082Z,1690842681.082 [NavChartDb](INFO): # of records loaded: 14969
2023-07-31T22:31:21.085Z,1690842681.085 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI89M.000
2023-07-31T22:31:21.136Z,1690842681.136 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-07-31T22:31:24.256Z,1690842684.256 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-07-31T22:31:27.880Z,1690842687.880 [SBIT](IMPORTANT): Beginning Startup BIT
2023-07-31T22:31:27.904Z,1690842687.904 [CBIT](IMPORTANT): Beginning ground fault scan
2023-07-31T22:31:38.973Z,1690842698.973 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007652
CHAN A1 (24V): 0.002573
CHAN A2 (12V): -0.005605
CHAN A3 (5V): -0.003061
CHAN B0 (3.3V): -0.001620
CHAN B1 (3.15aV): -0.001285
CHAN B2 (3.15bV): -0.001864
CHAN B3 (GND): -0.000457
OPEN: 0.000453
Full Scale: +/- 1 mA
2023-07-31T22:31:44.137Z,1690842704.137 [NavChartDb](INFO): # of records loaded: 5000
2023-07-31T22:31:56.040Z,1690842716.040 [NavChartDb](INFO): # of records loaded: 10000
2023-07-31T22:32:05.701Z,1690842725.701 [NavChartDb](INFO): # of records loaded: 15000
2023-07-31T22:32:17.915Z,1690842737.915 [NavChartDb](INFO): # of records loaded: 20000
2023-07-31T22:32:21.698Z,1690842741.698 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-07-31T22:32:21.887Z,1690842741.887 [SBIT](IMPORTANT): SBIT PASSED
2023-07-31T22:32:21.887Z,1690842741.887 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-07-31T22:32:21.921Z,1690842741.921 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-07-31T22:32:21.921Z,1690842741.921 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=1 bool;

2023-07-31T22:32:21.921Z,1690842741.921 [SBIT](IMPORTANT): DeadReckonUsingMultipleVelocitySources.loadAtStartup=0 bool;

2023-07-31T22:32:21.921Z,1690842741.921 [SBIT](IMPORTANT): DeadReckonUsingSpeedCalculator.loadAtStartup=1 bool;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): Depth_Keller.offset=-0.35 decibar;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): DropWeight.loadAtStartup=1 bool;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=3 minute;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): Express linearApproximation WetLabsSeaOWL_UV_A.mass_concentration_of_petroleum_hydrocarbons_in_sea_water 1.000000 kilogram_per_cubic_meter;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.loadAtStartup=1 bool;

2023-07-31T22:32:21.922Z,1690842741.922 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.05 celsius;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=234.769539 cubic_centimeter;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): VerticalControl.massDefault=8.539099 millimeter;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-07-31T22:32:21.923Z,1690842741.923 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=0 bool;

2023-07-31T22:32:22.365Z,1690842742.365 [MissionManager](IMPORTANT): Started mission Startup
2023-07-31T22:32:22.365Z,1690842742.365 [Startup] Running Loop=1
2023-07-31T22:32:22.365Z,1690842742.365 [Startup](DEBUG): Aggregate::initialize Startup
2023-07-31T22:32:22.365Z,1690842742.365 [Startup:A.GoToSurface] Running Loop=1
2023-07-31T22:32:22.365Z,1690842742.365 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-07-31T22:32:22.366Z,1690842742.366 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-07-31T22:32:22.366Z,1690842742.366 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-07-31T22:32:22.367Z,1690842742.367 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-07-31T22:32:22.367Z,1690842742.367 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-07-31T22:32:22.392Z,1690842742.392 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-07-31T22:32:22.393Z,1690842742.393 [Startup:StartupSatComms] Running Loop=1
2023-07-31T22:32:22.394Z,1690842742.394 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-07-31T22:32:22.394Z,1690842742.394 [Startup:StartupSatComms:A] Running Loop=1
2023-07-31T22:32:22.586Z,1690842742.586 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-07-31T22:32:24.987Z,1690842744.987 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-07-31T22:32:27.623Z,1690842747.623 [NavChartDb](INFO): # of records loaded: 25000
2023-07-31T22:32:45.233Z,1690842765.233 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI90M.000
2023-07-31T22:32:46.144Z,1690842766.144 [NavChartDb](INFO): # of records loaded: 27984
2023-07-31T22:32:46.149Z,1690842766.149 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI90M.000
2023-07-31T22:32:46.150Z,1690842766.150 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-07-31T22:32:47.510Z,1690842767.510 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-07-31T22:32:56.401Z,1690842776.401 [NavChartDb](INFO): # of records loaded: 5000
2023-07-31T22:33:05.581Z,1690842785.581 [NavChartDb](INFO): # of records loaded: 10000
2023-07-31T22:33:17.257Z,1690842797.257 [NavChartDb](INFO): # of records loaded: 15000
2023-07-31T22:33:22.476Z,1690842802.476 [Startup:StartupSatComms:A](INFO): Timed out from 2023-07-31T22:32:22.4Z
2023-07-31T22:33:22.476Z,1690842802.476 [Startup:StartupSatComms:A] Stopped
2023-07-31T22:33:22.476Z,1690842802.476 [Startup:StartupSatComms:B] Running Loop=1
2023-07-31T22:33:22.851Z,1690842802.851 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-07-31T22:33:26.161Z,1690842806.161 [NavChartDb](INFO): # of records loaded: 20000
2023-07-31T22:33:33.505Z,1690842813.505 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2023-07-31T22:33:33.505Z,1690842813.505 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2023-07-31T22:33:33.603Z,1690842813.603 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2023-07-31T22:33:33.952Z,1690842813.952 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2023-07-31T22:33:33.952Z,1690842813.952 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2023-07-31T22:33:34.285Z,1690842814.285 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2023-07-31T22:33:37.921Z,1690842817.921 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230628T184929/Courier0021.lzma
2023-07-31T22:33:38.732Z,1690842818.732 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-07-31T22:33:38.922Z,1690842818.922 [DataOverHttps](INFO): Moved sent file to Logs/20230628T184929/Courier0021.lzma.bak
2023-07-31T22:33:38.922Z,1690842818.922 [DataOverHttps](INFO): SBD MOMSN=18504177
2023-07-31T22:33:39.368Z,1690842819.368 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-07-31T22:33:47.886Z,1690842827.886 [NavChartDb](INFO): # of records loaded: 25000
2023-07-31T22:33:54.006Z,1690842834.006 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI56M.000
2023-07-31T22:33:54.484Z,1690842834.484 [NavChartDb](INFO): # of records loaded: 26626
2023-07-31T22:33:54.487Z,1690842834.487 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI56M.000
2023-07-31T22:33:54.488Z,1690842834.488 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-07-31T22:34:01.170Z,1690842841.170 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-07-31T22:34:02.677Z,1690842842.677 [DataOverHttps](INFO): Sending 40 bytes from file Logs/20230628T184929/Courier0024.lzma
2023-07-31T22:34:03.677Z,1690842843.677 [DataOverHttps](INFO): Moved sent file to Logs/20230628T184929/Courier0024.lzma.bak
2023-07-31T22:34:03.678Z,1690842843.678 [DataOverHttps](INFO): SBD MOMSN=18504180
2023-07-31T22:34:11.787Z,1690842851.787 [NAL9602](INFO): SBD MO Status=2, MOMSN=7065, MT Status=2, MTMSN=0
2023-07-31T22:34:11.788Z,1690842851.788 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-31T22:34:18.483Z,1690842858.483 [NavChartDb](INFO): # of records loaded: 5000
2023-07-31T22:34:22.706Z,1690842862.706 [Startup:StartupSatComms:B](INFO): Timed out from 2023-07-31T22:33:22.5Z
2023-07-31T22:34:22.706Z,1690842862.706 [Startup:StartupSatComms:B] Stopped
2023-07-31T22:34:22.706Z,1690842862.706 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-07-31T22:34:22.706Z,1690842862.706 [Startup:StartupSatComms] Stopped
2023-07-31T22:34:22.707Z,1690842862.707 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-07-31T22:34:22.707Z,1690842862.707 [Startup](INFO): Completed Startup
2023-07-31T22:34:22.744Z,1690842862.744 [MissionManager](INFO): Startup is completed.
2023-07-31T22:34:22.744Z,1690842862.744 [MissionManager](INFO): Uninitializing Mission Startup
2023-07-31T22:34:22.744Z,1690842862.744 [Startup] Stopped
2023-07-31T22:34:22.744Z,1690842862.744 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-07-31T22:34:22.744Z,1690842862.744 [Startup:A.GoToSurface] Stopped
2023-07-31T22:34:22.744Z,1690842862.744 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-07-31T22:34:23.083Z,1690842863.083 [MissionManager](IMPORTANT): Started mission Default
2023-07-31T22:34:23.083Z,1690842863.083 [Default] Running Loop=1
2023-07-31T22:34:23.083Z,1690842863.083 [Default](DEBUG): Aggregate::initialize Default
2023-07-31T22:34:23.092Z,1690842863.092 [Default:B.GoToSurface] Running Loop=1
2023-07-31T22:34:23.092Z,1690842863.092 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-07-31T22:34:23.092Z,1690842863.092 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-07-31T22:34:23.092Z,1690842863.092 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-07-31T22:34:23.093Z,1690842863.093 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-07-31T22:34:23.093Z,1690842863.093 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-07-31T22:34:23.093Z,1690842863.093 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-07-31T22:34:23.094Z,1690842863.094 [Default:A.Wait] Running Loop=1
2023-07-31T22:34:23.094Z,1690842863.094 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-07-31T22:34:23.528Z,1690842863.528 [DVL_micro](INFO): Powering down
2023-07-31T22:34:26.799Z,1690842866.799 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20230731T223019/Courier0000.lzma
2023-07-31T22:34:27.801Z,1690842867.801 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Courier0000.lzma.bak
2023-07-31T22:34:27.802Z,1690842867.802 [DataOverHttps](INFO): SBD MOMSN=18504182
2023-07-31T22:34:30.027Z,1690842870.027 [NAL9602](INFO): SBD MO Status=2, MOMSN=7065, MT Status=2, MTMSN=0
2023-07-31T22:34:30.066Z,1690842870.066 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-07-31T22:34:36.254Z,1690842876.254 [Default:A.Wait](INFO): Done Waiting.
2023-07-31T22:34:36.254Z,1690842876.254 [Default:A.Wait] Stopped
2023-07-31T22:34:36.255Z,1690842876.255 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T22:34:36.530Z,1690842876.530 [NavChartDb](INFO): # of records loaded: 10000
2023-07-31T22:34:36.644Z,1690842876.644 [Default:CheckIn] Running Loop=1
2023-07-31T22:34:36.644Z,1690842876.644 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T22:34:36.644Z,1690842876.644 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T22:34:37.048Z,1690842877.048 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-07-31T22:34:51.620Z,1690842891.620 [NavChartDb](INFO): # of records loaded: 15000
2023-07-31T22:34:59.037Z,1690842899.037 [NavChartDb](INFO): # of records loaded: 20000
2023-07-31T22:35:09.635Z,1690842909.635 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-07-31T22:35:11.540Z,1690842911.540 [NavChartDb](INFO): # of records loaded: 25000
2023-07-31T22:35:21.180Z,1690842921.180 [NavChartDb](INFO): # of records loaded: 30000
2023-07-31T22:35:29.551Z,1690842929.551 [NavChartDb](INFO): # of records loaded: 35000
2023-07-31T22:35:48.540Z,1690842948.540 [NavChartDb](INFO): # of records loaded: 40000
2023-07-31T22:35:58.243Z,1690842958.243 [NavChartDb](INFO): # of records loaded: 45000
2023-07-31T22:36:10.843Z,1690842970.843 [NavChartDb](INFO): # of records loaded: 50000
2023-07-31T22:36:17.274Z,1690842977.274 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-31T22:36:17.401Z,1690842977.401 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-07-31T22:36:18.488Z,1690842978.488 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223621.00,A,4313.61633,N,08620.33749,W,0.156,39.19,310723,,,A*4C
2023-07-31T22:36:18.498Z,1690842978.498 [NAL9602](INFO): GPS fix at 20230731T223621: (43.226939, -86.338958)
2023-07-31T22:36:18.508Z,1690842978.508 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T22:36:18.508Z,1690842978.508 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T22:36:18.870Z,1690842978.870 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-07-31T22:36:18.957Z,1690842978.957 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-07-31T22:36:22.226Z,1690842982.226 [NavChartDb](INFO): # of records loaded: 55000
2023-07-31T22:36:29.767Z,1690842989.767 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20230731T223019/Courier0004.lzma
2023-07-31T22:36:30.770Z,1690842990.770 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Courier0004.lzma.bak
2023-07-31T22:36:30.770Z,1690842990.770 [DataOverHttps](INFO): SBD MOMSN=18504185
2023-07-31T22:36:50.333Z,1690843010.333 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T22:36:54.788Z,1690843014.788 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4MI57M.000
2023-07-31T22:36:56.197Z,1690843016.197 [NavChartDb](INFO): # of records loaded: 59244
2023-07-31T22:36:56.207Z,1690843016.207 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4MI57M.000
2023-07-31T22:36:56.208Z,1690843016.208 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-07-31T22:36:58.641Z,1690843018.641 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20230628T184929/Express0022.lzma
2023-07-31T22:36:59.641Z,1690843019.641 [DataOverHttps](INFO): Moved sent file to Logs/20230628T184929/Express0022.lzma.bak
2023-07-31T22:36:59.641Z,1690843019.641 [DataOverHttps](INFO): SBD MOMSN=18504188
2023-07-31T22:37:09.663Z,1690843029.663 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-07-31T22:37:22.973Z,1690843042.973 [DataOverHttps](INFO): Sending 304 bytes from file Logs/20230628T184929/Express0025.lzma
2023-07-31T22:37:23.974Z,1690843043.974 [DataOverHttps](INFO): Moved sent file to Logs/20230628T184929/Express0025.lzma.bak
2023-07-31T22:37:23.974Z,1690843043.974 [DataOverHttps](INFO): SBD MOMSN=18504192
2023-07-31T22:37:31.482Z,1690843051.482 [NavChartDb](INFO): # of records loaded: 5000
2023-07-31T22:37:55.089Z,1690843075.089 [NavChartDb](INFO): # of records loaded: 10000
2023-07-31T22:37:55.249Z,1690843075.249 [DataOverHttps](INFO): Sending 1381 bytes from file Logs/20230731T223019/Express0001.lzma
2023-07-31T22:37:56.249Z,1690843076.249 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Express0001.lzma.bak
2023-07-31T22:37:56.250Z,1690843076.250 [DataOverHttps](INFO): SBD MOMSN=18504202
2023-07-31T22:38:10.079Z,1690843090.079 [NavChartDb](INFO): # of records loaded: 15000
2023-07-31T22:38:12.229Z,1690843092.229 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-07-31T22:38:12.232Z,1690843092.232 [BPC1](INFO): Received data from all battery sticks.
2023-07-31T22:38:20.272Z,1690843100.272 [DataOverHttps](INFO): Sending 362 bytes from file Logs/20230731T223019/Express0005.lzma
2023-07-31T22:38:21.273Z,1690843101.273 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Express0005.lzma.bak
2023-07-31T22:38:21.273Z,1690843101.273 [DataOverHttps](INFO): SBD MOMSN=18504258
2023-07-31T22:38:24.382Z,1690843104.382 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T22:38:24.382Z,1690843104.382 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T22:38:24.382Z,1690843104.382 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T22:38:24.668Z,1690843104.668 [NavChartDb](INFO): # of records loaded: 20000
2023-07-31T22:38:48.208Z,1690843128.208 [NavChartDb](INFO): # of records loaded: 25000
2023-07-31T22:39:02.325Z,1690843142.325 [NavChartDb](INFO): # of records loaded: 30000
2023-07-31T22:39:13.393Z,1690843153.393 [NavChartDb](INFO): # of records loaded: 35000
2023-07-31T22:39:26.466Z,1690843166.466 [NavChartDb](INFO): # of records loaded: 40000
2023-07-31T22:39:42.674Z,1690843182.674 [NavChartDb](INFO): # of records loaded: 45000
2023-07-31T22:39:57.377Z,1690843197.377 [NavChartDb](INFO): # of records loaded: 50000
2023-07-31T22:40:08.088Z,1690843208.088 [NavChartDb](INFO): # of records loaded: 55000
2023-07-31T22:40:21.231Z,1690843221.231 [NavChartDb](INFO): # of records loaded: 60000
2023-07-31T22:40:34.355Z,1690843234.355 [NavChartDb](INFO): # of records loaded: 65000
2023-07-31T22:40:51.389Z,1690843251.389 [NavChartDb](INFO): # of records loaded: 70000
2023-07-31T22:40:59.401Z,1690843259.401 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-07-31T22:41:02.726Z,1690843262.726 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-07-31T22:41:16.099Z,1690843276.099 [NavChartDb](INFO): # of records loaded: 75000
2023-07-31T22:41:57.140Z,1690843317.140 [DVL_micro](ERROR): only read 3 of 4 data items
2023-07-31T22:41:57.140Z,1690843317.140 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.999,+9999.99
2023-07-31T22:42:06.346Z,1690843326.346 [NavChartDb](INFO): # of records loaded: 80000
2023-07-31T22:42:17.333Z,1690843337.333 [DVL_micro](ERROR): Failed to parse:
:SA,-02.58,+04.00,322.9
2023-07-31T22:42:21.706Z,1690843341.706 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2MI80M.000
2023-07-31T22:42:22.189Z,1690843342.189 [DVL_micro](ERROR): Failed to parse:
:B,+00056,+00451,+00000,I
2023-07-31T22:42:22.926Z,1690843342.926 [NavChartDb](INFO): # of records loaded: 83074
2023-07-31T22:42:22.945Z,1690843342.945 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2MI80M.000
2023-07-31T22:42:22.945Z,1690843342.945 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-07-31T22:42:23.921Z,1690843343.921 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-07-31T22:42:31.591Z,1690843351.591 [NavChartDb](INFO): # of records loaded: 5000
2023-07-31T22:42:35.481Z,1690843355.481 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-07-31T22:42:35.901Z,1690843355.901 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-07-31T22:42:38.954Z,1690843358.954 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2MI01M.000
2023-07-31T22:42:39.967Z,1690843359.967 [NavChartDb](INFO): # of records loaded: 7824
2023-07-31T22:42:39.970Z,1690843359.970 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2MI01M.000
2023-07-31T22:42:44.722Z,1690843364.722 [NavChartDb](INFO): Creating index for soundings
2023-07-31T22:42:56.280Z,1690843376.280 [NavChartDb](INFO): Creating index for 0p0
2023-07-31T22:42:58.732Z,1690843378.732 [NavChartDb](INFO): Creating index for 0p6
2023-07-31T22:42:58.833Z,1690843378.833 [NavChartDb](INFO): Creating index for 0p9
2023-07-31T22:43:04.761Z,1690843384.761 [NavChartDb](INFO): Creating index for 1p8
2023-07-31T22:43:11.373Z,1690843391.373 [NavChartDb](INFO): Creating index for 3p6
2023-07-31T22:43:18.998Z,1690843398.998 [NavChartDb](INFO): Creating index for 5p4
2023-07-31T22:43:24.946Z,1690843404.946 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T22:43:24.946Z,1690843404.946 [Default:CheckIn:C.Wait] Stopped
2023-07-31T22:43:24.946Z,1690843404.946 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T22:43:24.946Z,1690843404.946 [Default:CheckIn:D] Running Loop=1
2023-07-31T22:43:25.359Z,1690843405.359 [Default:CheckIn:D] Stopped
2023-07-31T22:43:25.359Z,1690843405.359 [Default:CheckIn:E] Running Loop=1
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.037924 min 
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn:E] Stopped
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn] Stopped
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn](INFO): Running loop #2
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn] Running Loop=2
2023-07-31T22:43:25.776Z,1690843405.776 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T22:43:25.777Z,1690843405.777 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T22:43:27.769Z,1690843407.769 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224330.00,A,4313.60829,N,08620.34325,W,0.233,39.19,310723,,,A*43
2023-07-31T22:43:27.771Z,1690843407.771 [NAL9602](INFO): GPS fix at 20230731T224330: (43.226805, -86.339054)
2023-07-31T22:43:27.805Z,1690843407.805 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T22:43:27.805Z,1690843407.805 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T22:43:30.725Z,1690843410.725 [NavChartDb](INFO): Creating index for 7p3
2023-07-31T22:43:34.344Z,1690843414.344 [DVL_micro](ERROR): Failed to parse:
:B,+00145,+00428,+00000,I
2023-07-31T22:43:45.812Z,1690843425.812 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230731T223019/Courier0007.lzma
2023-07-31T22:43:46.813Z,1690843426.813 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Courier0007.lzma.bak
2023-07-31T22:43:46.814Z,1690843426.814 [DataOverHttps](INFO): SBD MOMSN=18504263
2023-07-31T22:43:50.562Z,1690843430.562 [NavChartDb](INFO): Creating index for 9p1
2023-07-31T22:43:58.212Z,1690843438.212 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-31T22:43:58.296Z,1690843438.296 [NAL9602](ERROR): received: 
+CSQ:0

OK65, 2, 0, 0, 0

OK
2023-07-31T22:44:05.807Z,1690843445.807 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20230731T223019/Express0008.lzma
2023-07-31T22:44:06.809Z,1690843446.809 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Express0008.lzma.bak
2023-07-31T22:44:06.810Z,1690843446.810 [DataOverHttps](INFO): SBD MOMSN=18504266
2023-07-31T22:44:08.728Z,1690843448.728 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T22:44:08.728Z,1690843448.728 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T22:44:08.728Z,1690843448.728 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T22:44:09.135Z,1690843449.135 [DVL_micro](ERROR): only read 3 of 4 data items
2023-07-31T22:44:09.135Z,1690843449.135 [DVL_micro](ERROR): Failed to parse:
:BI,00030,+00428,+00000,I
2023-07-31T22:46:34.164Z,1690843594.164 [DVL_micro](ERROR): Failed to parse:
:T00000000,35.0,+25.0,0000.0,1489.0,000
2023-07-31T22:46:41.833Z,1690843601.833 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+.00,+00000009.99,000,+9999.99,+9999.99,+9999.99,+9999.99
2023-07-31T22:46:44.268Z,1690843604.268 [DVL_micro](ERROR): Failed to parse:
05,+00002,+00540,+00000,A
2023-07-31T22:46:46.673Z,1690843606.673 [DVL_micro](ERROR): No DVL communication! Re-initializing
2023-07-31T22:46:46.673Z,1690843606.673 [DVL_micro] Communications Fault, FailCount= 1
2023-07-31T22:46:46.673Z,1690843606.673 [DVL_micro](ERROR): Communications Fault
2023-07-31T22:46:46.744Z,1690843606.744 [CBIT](ERROR): Communications Fault in component: DVL_micro
2023-07-31T22:46:47.148Z,1690843607.148 [DVL_micro](INFO): Powering down
2023-07-31T22:46:47.500Z,1690843607.500 [Power24vConverter](INFO): Powering down.
2023-07-31T22:46:47.919Z,1690843607.919 [CBIT](INFO): Clearing failed state for component DVL_micro
2023-07-31T22:46:47.919Z,1690843607.919 [DVL_micro] No Fault, FailCount= 1
2023-07-31T22:46:48.295Z,1690843608.295 [Power24vConverter](INFO): Powering up.
2023-07-31T22:47:18.189Z,1690843638.189 [DVL_micro](ERROR): Failed to parse::SA,-02.58,+03.96,323.1
2023-07-31T22:48:30.522Z,1690843710.522 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-31T22:49:00.811Z,1690843740.811 [DVL_micro](ERROR): Failed to parse:
:000000000,35.0,+25.1,0000.0,1489.0,000
2023-07-31T22:49:01.205Z,1690843741.205 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T22:49:09.301Z,1690843749.301 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T22:49:09.302Z,1690843749.302 [Default:CheckIn:C.Wait] Stopped
2023-07-31T22:49:09.302Z,1690843749.302 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T22:49:09.302Z,1690843749.302 [Default:CheckIn:D] Running Loop=1
2023-07-31T22:49:09.698Z,1690843749.698 [Default:CheckIn:D] Stopped
2023-07-31T22:49:09.698Z,1690843749.698 [Default:CheckIn:E] Running Loop=1
2023-07-31T22:49:10.106Z,1690843750.106 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.776904 min 
2023-07-31T22:49:10.106Z,1690843750.106 [Default:CheckIn:E] Stopped
2023-07-31T22:49:10.106Z,1690843750.106 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T22:49:10.106Z,1690843750.106 [Default:CheckIn] Stopped
2023-07-31T22:49:10.106Z,1690843750.106 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T22:49:10.107Z,1690843750.107 [Default:CheckIn](INFO): Running loop #3
2023-07-31T22:49:10.107Z,1690843750.107 [Default:CheckIn] Running Loop=3
2023-07-31T22:49:10.107Z,1690843750.107 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T22:49:10.107Z,1690843750.107 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T22:49:12.119Z,1690843752.119 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224915.00,A,4313.61616,N,08620.34106,W,0.214,39.19,310723,,,A*4B
2023-07-31T22:49:12.122Z,1690843752.122 [NAL9602](INFO): GPS fix at 20230731T224915: (43.226936, -86.339018)
2023-07-31T22:49:12.132Z,1690843752.132 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T22:49:12.132Z,1690843752.132 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T22:49:19.864Z,1690843759.864 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20230731T223019/Courier0010.lzma
2023-07-31T22:49:20.865Z,1690843760.865 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Courier0010.lzma.bak
2023-07-31T22:49:20.866Z,1690843760.866 [DataOverHttps](INFO): SBD MOMSN=18504272
2023-07-31T22:49:40.912Z,1690843780.912 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20230731T223019/Express0011.lzma
2023-07-31T22:49:41.913Z,1690843781.913 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Express0011.lzma.bak
2023-07-31T22:49:41.914Z,1690843781.914 [DataOverHttps](INFO): SBD MOMSN=18504275
2023-07-31T22:49:42.867Z,1690843782.867 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-31T22:49:42.964Z,1690843782.964 [NAL9602](ERROR): received: 
+CSQ:0

OK65, 2, 0, 0, 0

OK
2023-07-31T22:49:44.137Z,1690843784.137 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T22:49:44.137Z,1690843784.137 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T22:49:44.137Z,1690843784.137 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T22:50:15.622Z,1690843815.622 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-07-31T22:50:15.622Z,1690843815.622 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+25.1,489.0,000
2023-07-31T22:54:14.475Z,1690844054.475 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-07-31T22:54:44.847Z,1690844084.847 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-07-31T22:54:44.847Z,1690844084.847 [Default:CheckIn:C.Wait] Stopped
2023-07-31T22:54:44.847Z,1690844084.847 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T22:54:44.847Z,1690844084.847 [Default:CheckIn:D] Running Loop=1
2023-07-31T22:54:45.247Z,1690844085.247 [NAL9602](INFO): Not Powering down - fast GPS
2023-07-31T22:54:45.259Z,1690844085.259 [Default:CheckIn:D] Stopped
2023-07-31T22:54:45.260Z,1690844085.260 [Default:CheckIn:E] Running Loop=1
2023-07-31T22:54:45.673Z,1690844085.673 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.369602 min 
2023-07-31T22:54:45.673Z,1690844085.673 [Default:CheckIn:E] Stopped
2023-07-31T22:54:45.673Z,1690844085.673 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-07-31T22:54:45.673Z,1690844085.673 [Default:CheckIn] Stopped
2023-07-31T22:54:45.673Z,1690844085.673 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T22:54:45.673Z,1690844085.673 [Default:CheckIn](INFO): Running loop #4
2023-07-31T22:54:45.673Z,1690844085.673 [Default:CheckIn] Running Loop=4
2023-07-31T22:54:45.674Z,1690844085.674 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-07-31T22:54:45.674Z,1690844085.674 [Default:CheckIn:Read_GPS] Running Loop=1
2023-07-31T22:54:47.667Z,1690844087.667 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225450.00,A,4313.62090,N,08620.33605,W,0.330,282.70,310723,,,A*74
2023-07-31T22:54:47.669Z,1690844087.669 [NAL9602](INFO): GPS fix at 20230731T225450: (43.227015, -86.338934)
2023-07-31T22:54:47.681Z,1690844087.681 [Default:CheckIn:Read_GPS] Stopped
2023-07-31T22:54:47.681Z,1690844087.681 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-07-31T22:54:55.155Z,1690844095.155 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230731T223019/Courier0013.lzma
2023-07-31T22:54:56.157Z,1690844096.157 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Courier0013.lzma.bak
2023-07-31T22:54:56.157Z,1690844096.157 [DataOverHttps](INFO): SBD MOMSN=18504283
2023-07-31T22:55:13.136Z,1690844113.136 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230731T223019/Express0014.lzma
2023-07-31T22:55:14.137Z,1690844114.137 [DataOverHttps](INFO): Moved sent file to Logs/20230731T223019/Express0014.lzma.bak
2023-07-31T22:55:14.138Z,1690844114.138 [DataOverHttps](INFO): SBD MOMSN=18504287
2023-07-31T22:55:16.369Z,1690844116.369 [Default:CheckIn:Read_Iridium] Stopped
2023-07-31T22:55:16.369Z,1690844116.369 [Default:CheckIn:C.Wait] Running Loop=1
2023-07-31T22:55:16.369Z,1690844116.369 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-07-31T22:55:18.384Z,1690844118.384 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-07-31T22:55:18.473Z,1690844118.473 [NAL9602](ERROR): received: 
+CSQ:0

OK65, 2, 0, 0, 0

OK
2023-07-31T22:55:18.798Z,1690844118.798 [DVL_micro](ERROR): only read 3 of 4 data items
2023-07-31T22:55:18.798Z,1690844118.798 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999..99
2023-07-31T22:57:11.215Z,1690844231.215 [DVL_micro](ERROR): only read 3 of 4 data items
2023-07-31T22:57:11.215Z,1690844231.215 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.999,+9999.99,+9999.99
2023-07-31T22:58:41.914Z,1690844321.914 [DVL_micro](ERROR): Failed to parse:
:WI,+00955,+00712,+00230,+00000,A
2023-07-31T22:59:15.945Z,1690844355.945 [CommandExec](IMPORTANT): got command restart system
2023-07-31T22:59:18.048Z,1690844358.048 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-07-31T22:59:18.048Z,1690844358.048 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:18.048Z,1690844358.048 [CommandExec](INFO): Uninitializing the command executive.
2023-07-31T22:59:18.048Z,1690844358.048 [CommandExec](INFO): Uninitializing the command scheduler.
2023-07-31T22:59:18.049Z,1690844358.049 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:18.232Z,1690844358.232 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-07-31T22:59:18.232Z,1690844358.232 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-07-31T22:59:18.232Z,1690844358.232 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:18.233Z,1690844358.233 [NavChartDb](INFO): Join timeout helper Thread ID is 2359
2023-07-31T22:59:18.388Z,1690844358.388 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:18.388Z,1690844358.388 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:18.408Z,1690844358.408 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-07-31T22:59:18.408Z,1690844358.408 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:18.408Z,1690844358.408 [Radio_Surface](INFO): Join timeout helper Thread ID is 2360
2023-07-31T22:59:18.460Z,1690844358.460 [Radio_Surface](INFO): Powering down
2023-07-31T22:59:18.461Z,1690844358.461 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:18.461Z,1690844358.461 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:18.476Z,1690844358.476 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-07-31T22:59:18.476Z,1690844358.476 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:18.476Z,1690844358.476 [Onboard](INFO): Join timeout helper Thread ID is 2361
2023-07-31T22:59:18.480Z,1690844358.480 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-07-31T22:59:19.560Z,1690844359.560 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:19.560Z,1690844359.560 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:19.564Z,1690844359.564 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-07-31T22:59:19.564Z,1690844359.564 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:19.564Z,1690844359.564 [DataOverHttps](INFO): Join timeout helper Thread ID is 2362
2023-07-31T22:59:20.488Z,1690844360.488 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:20.488Z,1690844360.488 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:20.508Z,1690844360.508 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-07-31T22:59:20.508Z,1690844360.508 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:20.508Z,1690844360.508 [BackseatComponent](INFO): Join timeout helper Thread ID is 2363
2023-07-31T22:59:20.564Z,1690844360.564 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:20.564Z,1690844360.564 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:20.566Z,1690844360.566 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2023-07-31T22:59:20.566Z,1690844360.566 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:20.566Z,1690844360.566 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2364
2023-07-31T22:59:20.625Z,1690844360.625 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:20.625Z,1690844360.625 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:20.636Z,1690844360.636 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-07-31T22:59:20.637Z,1690844360.637 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:20.637Z,1690844360.637 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2365
2023-07-31T22:59:21.080Z,1690844361.080 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:21.080Z,1690844361.080 [WetLabsBB2FL](INFO): Powering down
2023-07-31T22:59:21.081Z,1690844361.081 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:21.084Z,1690844361.084 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-07-31T22:59:21.084Z,1690844361.084 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:21.085Z,1690844361.085 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2366
2023-07-31T22:59:21.980Z,1690844361.980 [CTD_Seabird](INFO): Powering down
2023-07-31T22:59:21.996Z,1690844361.996 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:22.005Z,1690844362.005 [CTD_Seabird](INFO): Powering down
2023-07-31T22:59:22.020Z,1690844362.020 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.026Z,1690844362.026 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-07-31T22:59:22.026Z,1690844362.026 [logger ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.026Z,1690844362.026 [logger](INFO): Join timeout helper Thread ID is 2367
2023-07-31T22:59:22.039Z,1690844362.039 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:22.039Z,1690844362.039 [logger ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.052Z,1690844362.052 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-07-31T22:59:22.052Z,1690844362.052 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.053Z,1690844362.053 [CommandLine](INFO): Join timeout helper Thread ID is 2368
2023-07-31T22:59:22.144Z,1690844362.144 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:22.144Z,1690844362.144 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.152Z,1690844362.152 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-07-31T22:59:22.152Z,1690844362.152 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.153Z,1690844362.153 [CommandExec](INFO): Join timeout helper Thread ID is 2369
2023-07-31T22:59:22.154Z,1690844362.154 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-07-31T22:59:22.154Z,1690844362.154 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.154Z,1690844362.154 [controlThread](INFO): Join timeout helper Thread ID is 2370
2023-07-31T22:59:22.236Z,1690844362.236 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-07-31T22:59:22.236Z,1690844362.236 [controlThread](DEBUG): Uninitializing ControlThread
2023-07-31T22:59:22.239Z,1690844362.239 [AHRS_M2](INFO): Powering down
2023-07-31T22:59:22.384Z,1690844362.384 [DVL_micro](INFO): Powering down
2023-07-31T22:59:22.385Z,1690844362.385 [NAL9602](INFO): Powering down
2023-07-31T22:59:22.386Z,1690844362.386 [Sonardyne_Nano](INFO): Powering down
2023-07-31T22:59:22.504Z,1690844362.504 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-07-31T22:59:22.505Z,1690844362.505 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-07-31T22:59:22.506Z,1690844362.506 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-07-31T22:59:22.506Z,1690844362.506 [MissionManager](INFO): Uninitializing Mission Default
2023-07-31T22:59:22.506Z,1690844362.506 [Default] Stopped
2023-07-31T22:59:22.506Z,1690844362.506 [Default](DEBUG): Aggregate::uninitialize Default
2023-07-31T22:59:22.507Z,1690844362.507 [Default:B.GoToSurface] Stopped
2023-07-31T22:59:22.507Z,1690844362.507 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-07-31T22:59:22.507Z,1690844362.507 [Default:CheckIn] Stopped
2023-07-31T22:59:22.507Z,1690844362.507 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-07-31T22:59:22.507Z,1690844362.507 [Default:CheckIn:C.Wait] Stopped
2023-07-31T22:59:22.507Z,1690844362.507 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-07-31T22:59:22.510Z,1690844362.510 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-07-31T22:59:22.510Z,1690844362.510 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-07-31T22:59:22.510Z,1690844362.510 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-07-31T22:59:22.511Z,1690844362.511 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-07-31T22:59:22.511Z,1690844362.511 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-07-31T22:59:22.511Z,1690844362.511 [BuoyancyServo](INFO): Powering down
2023-07-31T22:59:22.524Z,1690844362.524 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-07-31T22:59:22.524Z,1690844362.524 [ElevatorServo](INFO): Powering down
2023-07-31T22:59:22.525Z,1690844362.525 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-07-31T22:59:22.525Z,1690844362.525 [MassServo](INFO): Powering down
2023-07-31T22:59:22.526Z,1690844362.526 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-07-31T22:59:22.526Z,1690844362.526 [RudderServo](INFO): Powering down
2023-07-31T22:59:22.527Z,1690844362.527 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-07-31T22:59:22.527Z,1690844362.527 [ThrusterHE](INFO): Powering down
2023-07-31T22:59:22.528Z,1690844362.528 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-07-31T22:59:22.528Z,1690844362.528 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-07-31T22:59:22.529Z,1690844362.529 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-07-31T22:59:22.529Z,1690844362.529 [CBIT](DEBUG): Powering off loads.
2023-07-31T22:59:22.539Z,1690844362.539 [CBIT](DEBUG): Disabling WDT.
2023-07-31T22:59:22.551Z,1690844362.551 [CBIT](DEBUG): Opening all GF detection circuits.
2023-07-31T22:59:22.553Z,1690844362.553 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.612Z,1690844362.612 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.615Z,1690844362.615 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.621Z,1690844362.621 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.662Z,1690844362.662 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.664Z,1690844362.664 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.672Z,1690844362.672 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.718Z,1690844362.718 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.783Z,1690844362.783 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-07-31T22:59:22.833Z,1690844362.833 [logger ThreadHandler](INFO): Thread cancelled.