2023-06-25T01:25:28.143Z,1687656328.143 [Supervisor](DEBUG): Initializing supervisor.
2023-06-25T01:25:28.147Z,1687656328.147 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-06-25T01:25:28.148Z,1687656328.148 [SyncHandler](INFO): Protected caller Thread ID is 2214
2023-06-25T01:25:28.148Z,1687656328.148 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-06-25T01:25:28.149Z,1687656328.149 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-06-25T01:25:28.150Z,1687656328.150 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2215
2023-06-25T01:25:28.153Z,1687656328.153 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-06-25T01:25:28.171Z,1687656328.171 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-06-25T01:25:28.172Z,1687656328.172 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-06-25T01:25:28.172Z,1687656328.172 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2216
2023-06-25T01:25:28.176Z,1687656328.176 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-06-25T01:25:28.177Z,1687656328.177 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-06-25T01:25:28.177Z,1687656328.177 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2217
2023-06-25T01:25:28.179Z,1687656328.179 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-06-25T01:25:28.180Z,1687656328.180 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-06-25T01:25:28.181Z,1687656328.181 [logger ThreadHandler](INFO): Protected caller Thread ID is 2218
2023-06-25T01:25:28.184Z,1687656328.184 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-06-25T01:25:28.185Z,1687656328.185 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-06-25T01:25:28.186Z,1687656328.186 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-06-25T01:25:28.285Z,1687656328.285 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-06-25T01:25:28.285Z,1687656328.285 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-06-25T01:25:28.504Z,1687656328.504 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-06-25T01:25:28.504Z,1687656328.504 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-06-25T01:25:28.760Z,1687656328.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-06-25T01:25:28.761Z,1687656328.761 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-06-25T01:25:28.870Z,1687656328.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-06-25T01:25:28.871Z,1687656328.871 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-06-25T01:25:29.586Z,1687656329.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-06-25T01:25:29.587Z,1687656329.587 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-06-25T01:25:30.072Z,1687656330.072 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-06-25T01:25:30.073Z,1687656330.073 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-06-25T01:25:30.683Z,1687656330.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-06-25T01:25:30.684Z,1687656330.684 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-06-25T01:25:31.100Z,1687656331.100 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-06-25T01:25:31.100Z,1687656331.100 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-06-25T01:25:31.445Z,1687656331.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-06-25T01:25:31.445Z,1687656331.445 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-06-25T01:25:31.807Z,1687656331.807 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-06-25T01:25:31.807Z,1687656331.807 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-06-25T01:25:32.028Z,1687656332.028 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-06-25T01:25:32.028Z,1687656332.028 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-06-25T01:25:32.169Z,1687656332.169 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-06-25T01:25:32.169Z,1687656332.169 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-06-25T01:25:32.252Z,1687656332.252 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-06-25T01:25:32.333Z,1687656332.333 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-06-25T01:25:32.520Z,1687656332.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-06-25T01:25:32.520Z,1687656332.520 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-06-25T01:25:32.744Z,1687656332.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-06-25T01:25:32.746Z,1687656332.746 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-06-25T01:25:32.747Z,1687656332.747 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-06-25T01:25:32.832Z,1687656332.832 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-06-25T01:25:33.093Z,1687656333.093 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-06-25T01:25:33.093Z,1687656333.093 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-06-25T01:25:33.194Z,1687656333.194 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-06-25T01:25:33.355Z,1687656333.355 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-06-25T01:25:33.457Z,1687656333.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-06-25T01:25:33.545Z,1687656333.545 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-06-25T01:25:33.657Z,1687656333.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-06-25T01:25:33.762Z,1687656333.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-06-25T01:25:33.922Z,1687656333.922 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-06-25T01:25:34.019Z,1687656334.019 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-06-25T01:25:34.125Z,1687656334.125 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2023-06-25T01:25:34.125Z,1687656334.125 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-06-25T01:25:34.139Z,1687656334.139 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-06-25T01:25:34.280Z,1687656334.280 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-06-25T01:25:34.281Z,1687656334.281 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-06-25T01:25:34.433Z,1687656334.433 [BuoyancyServo] Loaded
2023-06-25T01:25:34.433Z,1687656334.433 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-06-25T01:25:34.453Z,1687656334.453 [ElevatorServo] Loaded
2023-06-25T01:25:34.454Z,1687656334.454 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-06-25T01:25:34.474Z,1687656334.474 [MassServo] Loaded
2023-06-25T01:25:34.474Z,1687656334.474 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-06-25T01:25:34.494Z,1687656334.494 [RudderServo] Loaded
2023-06-25T01:25:34.494Z,1687656334.494 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-06-25T01:25:34.510Z,1687656334.510 [ThrusterHE] Loaded
2023-06-25T01:25:34.510Z,1687656334.510 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-06-25T01:25:34.510Z,1687656334.510 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-06-25T01:25:34.511Z,1687656334.511 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-06-25T01:25:34.647Z,1687656334.647 [SBIT](DEBUG): Construct Startup Built In Test.
2023-06-25T01:25:34.662Z,1687656334.662 [SBIT] Loaded
2023-06-25T01:25:34.662Z,1687656334.662 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-06-25T01:25:34.665Z,1687656334.665 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-06-25T01:25:34.686Z,1687656334.686 [IBIT] Loaded
2023-06-25T01:25:34.686Z,1687656334.686 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-06-25T01:25:34.692Z,1687656334.692 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-06-25T01:25:34.910Z,1687656334.910 [CBIT] Loaded
2023-06-25T01:25:34.910Z,1687656334.910 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-06-25T01:25:34.911Z,1687656334.911 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-06-25T01:25:34.911Z,1687656334.911 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-06-25T01:25:35.072Z,1687656335.072 [CTD_Seabird] Loaded
2023-06-25T01:25:35.072Z,1687656335.072 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-06-25T01:25:35.073Z,1687656335.073 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0
2023-06-25T01:25:35.074Z,1687656335.074 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2300
2023-06-25T01:25:35.105Z,1687656335.105 [ESPComponent] Loaded
2023-06-25T01:25:35.105Z,1687656335.105 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-06-25T01:25:35.124Z,1687656335.124 [PAR_Licor] Loaded
2023-06-25T01:25:35.125Z,1687656335.125 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-06-25T01:25:35.155Z,1687656335.155 [WetLabsBB2FL] Loaded
2023-06-25T01:25:35.155Z,1687656335.155 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-06-25T01:25:35.156Z,1687656335.156 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0
2023-06-25T01:25:35.156Z,1687656335.156 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2301
2023-06-25T01:25:35.157Z,1687656335.157 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-06-25T01:25:35.158Z,1687656335.158 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-06-25T01:25:35.364Z,1687656335.364 [DepthRateCalculator] Loaded
2023-06-25T01:25:35.364Z,1687656335.364 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-06-25T01:25:35.400Z,1687656335.400 [PitchRateCalculator] Loaded
2023-06-25T01:25:35.401Z,1687656335.401 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-06-25T01:25:35.431Z,1687656335.431 [SpeedCalculator] Loaded
2023-06-25T01:25:35.431Z,1687656335.431 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-06-25T01:25:35.465Z,1687656335.465 [YawRateCalculator] Loaded
2023-06-25T01:25:35.465Z,1687656335.465 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-06-25T01:25:35.492Z,1687656335.492 [ElevatorOffsetCalculator] Loaded
2023-06-25T01:25:35.493Z,1687656335.493 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-06-25T01:25:35.493Z,1687656335.493 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-06-25T01:25:35.494Z,1687656335.494 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-06-25T01:25:35.719Z,1687656335.719 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-06-25T01:25:35.719Z,1687656335.719 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-06-25T01:25:35.745Z,1687656335.745 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-06-25T01:25:35.746Z,1687656335.746 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-06-25T01:25:35.859Z,1687656335.859 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-06-25T01:25:35.859Z,1687656335.859 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-06-25T01:25:35.873Z,1687656335.873 [NavChart] Loaded
2023-06-25T01:25:35.873Z,1687656335.873 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-06-25T01:25:35.879Z,1687656335.879 [UniversalFixResidualReporter] Loaded
2023-06-25T01:25:35.879Z,1687656335.879 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-06-25T01:25:35.880Z,1687656335.880 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-06-25T01:25:35.880Z,1687656335.880 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-06-25T01:25:36.286Z,1687656336.286 [AHRS_M2] Loaded
2023-06-25T01:25:36.286Z,1687656336.286 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-06-25T01:25:36.320Z,1687656336.320 [BackseatComponent] Loaded
2023-06-25T01:25:36.321Z,1687656336.321 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-06-25T01:25:36.322Z,1687656336.322 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A294E0
2023-06-25T01:25:36.322Z,1687656336.322 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2302
2023-06-25T01:25:36.325Z,1687656336.325 [LcmUniversalReporter] Loaded
2023-06-25T01:25:36.325Z,1687656336.325 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-06-25T01:25:37.055Z,1687656337.055 [BPC1] Loaded
2023-06-25T01:25:37.056Z,1687656337.056 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-06-25T01:25:37.133Z,1687656337.133 [DataOverHttps] Loaded
2023-06-25T01:25:37.133Z,1687656337.133 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-06-25T01:25:37.134Z,1687656337.134 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A594E0
2023-06-25T01:25:37.135Z,1687656337.135 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2303
2023-06-25T01:25:37.155Z,1687656337.155 [Depth_Keller] Loaded
2023-06-25T01:25:37.155Z,1687656337.155 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-06-25T01:25:37.160Z,1687656337.160 [DropWeight] Loaded
2023-06-25T01:25:37.161Z,1687656337.161 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-06-25T01:25:37.198Z,1687656337.198 [DVL_micro] Loaded
2023-06-25T01:25:37.199Z,1687656337.199 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-06-25T01:25:37.258Z,1687656337.258 [NAL9602] Loaded
2023-06-25T01:25:37.259Z,1687656337.259 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-06-25T01:25:37.285Z,1687656337.285 [Onboard] Loaded
2023-06-25T01:25:37.285Z,1687656337.285 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-06-25T01:25:37.286Z,1687656337.286 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A894E0
2023-06-25T01:25:37.287Z,1687656337.287 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2304
2023-06-25T01:25:37.299Z,1687656337.299 [Power24vConverter] Loaded
2023-06-25T01:25:37.299Z,1687656337.299 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-06-25T01:25:37.312Z,1687656337.312 [Radio_Surface] Loaded
2023-06-25T01:25:37.312Z,1687656337.312 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-06-25T01:25:37.313Z,1687656337.313 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB94E0
2023-06-25T01:25:37.314Z,1687656337.314 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2305
2023-06-25T01:25:37.327Z,1687656337.327 [Sonardyne_Nano] Loaded
2023-06-25T01:25:37.328Z,1687656337.328 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-06-25T01:25:37.328Z,1687656337.328 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-06-25T01:25:37.329Z,1687656337.329 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-06-25T01:25:37.383Z,1687656337.383 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-06-25T01:25:37.383Z,1687656337.383 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-06-25T01:25:37.431Z,1687656337.431 [VerticalControl](DEBUG): Construct VerticalControl.
2023-06-25T01:25:37.481Z,1687656337.481 [VerticalControl] Loaded
2023-06-25T01:25:37.481Z,1687656337.481 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-06-25T01:25:37.484Z,1687656337.484 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-06-25T01:25:37.520Z,1687656337.520 [HorizontalControl] Loaded
2023-06-25T01:25:37.521Z,1687656337.521 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-06-25T01:25:37.523Z,1687656337.523 [SpeedControl](DEBUG): Construct SpeedControl.
2023-06-25T01:25:37.525Z,1687656337.525 [SpeedControl] Loaded
2023-06-25T01:25:37.525Z,1687656337.525 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-06-25T01:25:37.528Z,1687656337.528 [LoopControl](DEBUG): Construct LoopControl.
2023-06-25T01:25:37.528Z,1687656337.528 [LoopControl] Loaded
2023-06-25T01:25:37.529Z,1687656337.529 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-06-25T01:25:37.529Z,1687656337.529 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-06-25T01:25:37.530Z,1687656337.530 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-06-25T01:25:37.540Z,1687656337.540 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-06-25T01:25:37.540Z,1687656337.540 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-06-25T01:25:37.836Z,1687656337.836 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-06-25T01:25:37.842Z,1687656337.842 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-06-25T01:25:37.845Z,1687656337.845 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-06-25T01:25:37.856Z,1687656337.856 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-06-25T01:25:37.857Z,1687656337.857 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC44E0
2023-06-25T01:25:37.858Z,1687656337.858 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2306
2023-06-25T01:25:37.862Z,1687656337.862 [Supervisor](INFO): Main Thread ID is 2080
2023-06-25T01:25:37.862Z,1687656337.862 [Supervisor](DEBUG): Running supervisor.
2023-06-25T01:25:37.863Z,1687656337.863 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2307
2023-06-25T01:25:37.863Z,1687656337.863 [CommandExec](INFO): Initializing the command executive.
2023-06-25T01:25:37.865Z,1687656337.865 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2308
2023-06-25T01:25:37.868Z,1687656337.868 [controlThread ThreadHandler](INFO): Handler Thread ID is 2309
2023-06-25T01:25:37.869Z,1687656337.869 [controlThread](DEBUG): Initializing ControlThread
2023-06-25T01:25:37.870Z,1687656337.870 [SBIT](INFO): Initialize SBIT Component.
2023-06-25T01:25:37.871Z,1687656337.871 [SBIT](IMPORTANT): git: 2023-06-23
2023-06-25T01:25:37.871Z,1687656337.871 [SBIT](INFO): git hash: 7a60da20fabe8c9ff022aa19d24605a06cff26a2
2023-06-25T01:25:37.872Z,1687656337.872 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-06-25T01:25:37.873Z,1687656337.873 [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-06-25T01:25:37.874Z,1687656337.874 [SBIT](INFO): Beginning SBIT in 75.000000 seconds.
2023-06-25T01:25:37.875Z,1687656337.875 [IBIT](INFO): Initialize IBIT Component.
2023-06-25T01:25:37.875Z,1687656337.875 [CBIT](DEBUG): Initialize CBIT Component.
2023-06-25T01:25:37.876Z,1687656337.876 [logger ThreadHandler](INFO): Handler Thread ID is 2310
2023-06-25T01:25:37.887Z,1687656337.887 [CBIT](DEBUG): Initialized mux pins.
2023-06-25T01:25:37.887Z,1687656337.887 [CBIT](DEBUG): Initializing the watchdog timer.
2023-06-25T01:25:37.896Z,1687656337.896 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2311
2023-06-25T01:25:37.896Z,1687656337.896 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-06-25T01:25:37.901Z,1687656337.901 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2313
2023-06-25T01:25:37.904Z,1687656337.904 [WetLabsBB2FL](INFO): Powering up
2023-06-25T01:25:37.905Z,1687656337.905 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2315
2023-06-25T01:25:37.911Z,1687656337.911 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-06-25T01:25:37.912Z,1687656337.912 [CBIT](DEBUG): Initializing heartbeat.
2023-06-25T01:25:37.913Z,1687656337.913 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2316
2023-06-25T01:25:37.914Z,1687656337.914 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-06-25T01:25:37.924Z,1687656337.924 [Onboard ThreadHandler](INFO): Handler Thread ID is 2317
2023-06-25T01:25:37.941Z,1687656337.941 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2318
2023-06-25T01:25:37.964Z,1687656337.964 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2319
2023-06-25T01:25:37.966Z,1687656337.966 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-06-25T01:25:37.967Z,1687656337.967 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000
2023-06-25T01:25:37.967Z,1687656337.967 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2023-06-25T01:25:37.967Z,1687656337.967 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000
2023-06-25T01:25:37.968Z,1687656337.968 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000
2023-06-25T01:25:37.968Z,1687656337.968 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000
2023-06-25T01:25:37.968Z,1687656337.968 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000
2023-06-25T01:25:37.969Z,1687656337.969 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000
2023-06-25T01:25:37.969Z,1687656337.969 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000
2023-06-25T01:25:37.969Z,1687656337.969 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000
2023-06-25T01:25:37.969Z,1687656337.969 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000
2023-06-25T01:25:37.969Z,1687656337.969 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000
2023-06-25T01:25:37.983Z,1687656337.983 [CBIT](DEBUG): Deactivating GF circuits.
2023-06-25T01:25:37.983Z,1687656337.983 [CBIT](DEBUG): Deactivating emergency mode.
2023-06-25T01:25:38.023Z,1687656338.023 [CBIT](DEBUG): Backplane powered.
2023-06-25T01:25:38.028Z,1687656338.028 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-06-25T01:25:38.028Z,1687656338.028 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-06-25T01:25:38.028Z,1687656338.028 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-06-25T01:25:38.029Z,1687656338.029 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-06-25T01:25:38.029Z,1687656338.029 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-06-25T01:25:38.030Z,1687656338.030 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-06-25T01:25:38.031Z,1687656338.031 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-06-25T01:25:38.042Z,1687656338.042 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-06-25T01:25:38.044Z,1687656338.044 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-06-25T01:25:38.044Z,1687656338.044 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-06-25T01:25:38.045Z,1687656338.045 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-06-25T01:25:38.046Z,1687656338.046 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-06-25T01:25:38.083Z,1687656338.083 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-25T01:25:38.123Z,1687656338.123 [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-06-25T01:25:38.124Z,1687656338.124 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-06-25T01:25:38.214Z,1687656338.214 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-06-25T01:25:38.231Z,1687656338.231 [Default:A.Wait](DEBUG): Construct Wait.
2023-06-25T01:25:38.234Z,1687656338.234 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-25T01:25:38.257Z,1687656338.257 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-06-25T01:25:38.295Z,1687656338.295 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-06-25T01:25:38.301Z,1687656338.301 [Default:E.Execute](DEBUG): Construct Execute.
2023-06-25T01:25:38.320Z,1687656338.320 [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-06-25T01:25:38.325Z,1687656338.325 [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,
2023-06-25T01:25:38.353Z,1687656338.353 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-06-25T01:25:38.356Z,1687656338.356 [Radio_Surface](INFO): Powering up
2023-06-25T01:25:38.436Z,1687656338.436 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.894409 decibar, 0.000000 m
2023-06-25T01:25:38.445Z,1687656338.445 [Power24vConverter](INFO): Powering up.
2023-06-25T01:25:38.445Z,1687656338.445 [Sonardyne_Nano](INFO): Initializing.
2023-06-25T01:25:38.472Z,1687656338.472 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-06-25T01:25:38.485Z,1687656338.485 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-06-25T01:25:38.492Z,1687656338.492 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-06-25T01:25:38.493Z,1687656338.493 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-06-25T01:25:38.500Z,1687656338.500 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-06-25T01:25:38.501Z,1687656338.501 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-25T01:25:38.516Z,1687656338.516 [MassServo](DEBUG): Initializing MassServo.
2023-06-25T01:25:38.517Z,1687656338.517 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-25T01:25:38.524Z,1687656338.524 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-25T01:25:38.525Z,1687656338.525 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-06-25T01:25:38.532Z,1687656338.532 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-06-25T01:25:40.012Z,1687656340.012 [WetLabsBB2FL](INFO): Powering down
2023-06-25T01:25:40.762Z,1687656340.762 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-06-25T01:25:44.284Z,1687656344.284 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-06-25T01:26:07.430Z,1687656367.430 [NAL9602](INFO): Powering up NAL9602
2023-06-25T01:26:18.356Z,1687656378.356 [NAL9602](INFO): NAL9602 initialized
2023-06-25T01:26:23.592Z,1687656383.592 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-06-25T01:26:23.593Z,1687656383.593 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+29.1,00000,000
2023-06-25T01:26:53.546Z,1687656413.546 [SBIT](IMPORTANT): Beginning Startup BIT
2023-06-25T01:26:53.551Z,1687656413.551 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-25T01:27:04.478Z,1687656424.478 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005494
CHAN A1 (24V): 0.002293
CHAN A2 (12V): -0.006623
CHAN A3 (5V): -0.003828
CHAN B0 (3.3V): -0.001611
CHAN B1 (3.15aV): -0.001367
CHAN B2 (3.15bV): -0.001308
CHAN B3 (GND): -0.000425
OPEN: 0.000959
Full Scale: +/- 1 mA
2023-06-25T01:27:46.846Z,1687656466.846 [SBIT](IMPORTANT): SBIT PASSED
2023-06-25T01:27:46.847Z,1687656466.847 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-25T01:27:46.848Z,1687656466.848 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2023-06-25T01:27:46.848Z,1687656466.848 [SBIT](IMPORTANT): Depth_Keller.offset=-0.35 decibar;

2023-06-25T01:27:46.848Z,1687656466.848 [SBIT](IMPORTANT): DropWeight.loadAtStartup=1 bool;

2023-06-25T01:27:46.848Z,1687656466.848 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=3 minute;

2023-06-25T01:27:46.848Z,1687656466.848 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool;

2023-06-25T01:27:46.848Z,1687656466.848 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.05 celsius;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): VerticalControl.massDefault=1.4 centimeter;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-06-25T01:27:46.849Z,1687656466.849 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-06-25T01:27:46.850Z,1687656466.850 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=0 bool;

2023-06-25T01:27:47.248Z,1687656467.248 [MissionManager](IMPORTANT): Started mission Startup
2023-06-25T01:27:47.249Z,1687656467.249 [Startup] Running Loop=1
2023-06-25T01:27:47.249Z,1687656467.249 [Startup](DEBUG): Aggregate::initialize Startup
2023-06-25T01:27:47.249Z,1687656467.249 [Startup:A.GoToSurface] Running Loop=1
2023-06-25T01:27:47.249Z,1687656467.249 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-25T01:27:47.250Z,1687656467.250 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-25T01:27:47.250Z,1687656467.250 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-25T01:27:47.250Z,1687656467.250 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-25T01:27:47.251Z,1687656467.251 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-25T01:27:47.275Z,1687656467.275 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-25T01:27:47.277Z,1687656467.277 [Startup:StartupSatComms] Running Loop=1
2023-06-25T01:27:47.277Z,1687656467.277 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-06-25T01:27:47.277Z,1687656467.277 [Startup:StartupSatComms:A] Running Loop=1
2023-06-25T01:27:47.653Z,1687656467.653 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-06-25T01:28:38.176Z,1687656518.176 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-06-25T01:28:38.176Z,1687656518.176 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-25T01:28:38.187Z,1687656518.187 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-25T01:28:38.653Z,1687656518.653 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-25T01:28:38.653Z,1687656518.653 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-06-25T01:28:47.452Z,1687656527.452 [Startup:StartupSatComms:A](INFO): Timed out from 2023-06-25T01:27:47.3Z
2023-06-25T01:28:47.452Z,1687656527.452 [Startup:StartupSatComms:A] Stopped
2023-06-25T01:28:47.452Z,1687656527.452 [Startup:StartupSatComms:B] Running Loop=1
2023-06-25T01:28:47.849Z,1687656527.849 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-25T01:29:13.078Z,1687656553.078 [DataOverHttps](IMPORTANT): SBD MTMSN=20230625T012912
2023-06-25T01:29:13.082Z,1687656553.082 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004591
2023-06-25T01:29:23.191Z,1687656563.191 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230624T030956/Courier0004.lzma
2023-06-25T01:29:23.194Z,1687656563.194 [DataOverHttps](INFO): Received command: sched asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1p822 1 2
2023-06-25T01:29:23.240Z,1687656563.240 [CommandExec](IMPORTANT): got command schedule asap "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m" 1p822 1 2.000000
2023-06-25T01:29:23.240Z,1687656563.240 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=1p822
2023-06-25T01:29:23.241Z,1687656563.241 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='1p822'): "load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 12 min;set transit.Latitude 43.20017 degree;set transit.Longitude -86.3649 degree;set transit.Depth 1 m;set transit.MaxDepth 2 m", ASAP
2023-06-25T01:29:24.554Z,1687656564.554 [DataOverHttps](INFO): Moved sent file to Logs/20230624T030956/Courier0004.lzma.bak
2023-06-25T01:29:24.554Z,1687656564.554 [DataOverHttps](IMPORTANT): SBD MOMSN=18425224, MTMSN=20230625T012923
2023-06-25T01:29:31.887Z,1687656571.887 [DataOverHttps](INFO): Received command: sched asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1p822 2 2
2023-06-25T01:29:31.891Z,1687656571.891 [CommandExec](IMPORTANT): got command schedule asap "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run" 1p822 2 2.000000
2023-06-25T01:29:31.891Z,1687656571.891 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=1p822
2023-06-25T01:29:31.892Z,1687656571.892 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='1p822'): "set transit.MinOffshore 0.00001 km;set transit.MinAltitude 2 m;run", ASAP
2023-06-25T01:29:32.005Z,1687656572.005 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl
2023-06-25T01:29:32.006Z,1687656572.006 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl
2023-06-25T01:29:32.006Z,1687656572.006 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Transport/transit.tx
2023-06-25T01:29:32.193Z,1687656572.193 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min
2023-06-25T01:29:32.200Z,1687656572.200 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min
2023-06-25T01:29:32.203Z,1687656572.203 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg
2023-06-25T01:29:32.210Z,1687656572.210 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg
2023-06-25T01:29:32.217Z,1687656572.217 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m
2023-06-25T01:29:32.224Z,1687656572.224 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m
2023-06-25T01:29:32.227Z,1687656572.227 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m
2023-06-25T01:29:32.262Z,1687656572.262 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s
2023-06-25T01:29:32.269Z,1687656572.269 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m
2023-06-25T01:29:32.284Z,1687656572.284 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km
2023-06-25T01:29:32.287Z,1687656572.287 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m
2023-06-25T01:29:32.302Z,1687656572.302 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool
2023-06-25T01:29:32.310Z,1687656572.310 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool
2023-06-25T01:29:32.310Z,1687656572.310 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.xml
2023-06-25T01:29:32.618Z,1687656572.618 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 3.000000 h
2023-06-25T01:29:32.637Z,1687656572.637 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min
2023-06-25T01:29:32.660Z,1687656572.660 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2023-06-25T01:29:32.663Z,1687656572.663 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s
2023-06-25T01:29:32.682Z,1687656572.682 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2023-06-25T01:29:32.701Z,1687656572.701 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s
2023-06-25T01:29:32.724Z,1687656572.724 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min
2023-06-25T01:29:32.736Z,1687656572.736 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min
2023-06-25T01:29:32.758Z,1687656572.758 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-25T01:29:32.939Z,1687656572.939 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.xml
2023-06-25T01:29:33.088Z,1687656573.088 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m
2023-06-25T01:29:33.094Z,1687656573.094 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2023-06-25T01:29:33.109Z,1687656573.109 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m
2023-06-25T01:29:33.164Z,1687656573.164 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2023-06-25T01:29:33.216Z,1687656573.216 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2023-06-25T01:29:33.285Z,1687656573.285 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2023-06-25T01:29:33.338Z,1687656573.338 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2023-06-25T01:29:33.426Z,1687656573.426 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2023-06-25T01:29:33.446Z,1687656573.446 [transit:MassHold.Pitch](DEBUG): Construct.
2023-06-25T01:29:33.494Z,1687656573.494 [transit:Transit:A.Pitch](DEBUG): Construct.
2023-06-25T01:29:33.524Z,1687656573.524 [transit:Transit:B.SetSpeed](DEBUG): Construct.
2023-06-25T01:29:33.527Z,1687656573.527 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2023-06-25T01:29:33.618Z,1687656573.618 [MissionManager](DEBUG): 
mission transit {
  """
  Vehicle transits to desired waypoint and can be commanded to use/hold
  mass or buoyancy.
  """

  arguments {
    MissionTimeout = 60 minute
      """
      Maximum duration of mission
      """

    NeedCommsTime = 30 minute
      """
      How often to surface for commumications
      """

    Latitude = NaN degree
      """
      Latitude of waypoint to seek. If set to NaN, uses latitude at mission
      initialization.
      """

    Longitude = NaN degree
      """
      Longitude of waypoint to seek. If set to NaN, uses longitude at mission
      initialization.
      """

    Northings = 0 meter
      """
      Northward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Eastings = 0 meter
      """
      Eastward distance of the waypoint to seek. If combined with Latitude
      and/or Longitude, this is an offset from the specified Latitude and/or
      Longitude.
      """

    Depth = 10 meter
      """
      Depth of flat and level flight during the mission.
      """

    Speed = 1 meter_per_second
      """
      Speed of vehicle (relative to water) during the mission.
      """

    MaxDepth = 20 meter
      """
      Maximum depth for the entire mission.
      """

    MinOffshore = 1 kilometer
      """
      Minimum distance offshore for the entire mission.
      """

    MinAltitude = 7 meter
      """
      Minimum height above the sea floor for the entire mission.
      """

    MassHold = true
      """
      Set to True in order to hold mass at default position, False to allow
      mass to run on its own.
      """

    BuoyancyHold = true
      """
      Set to True in order to hold buoyancy at neutral position, False to
      allow buoyancy to run on its own.
      """
  }

  timeout duration=MissionTimeout

  insert id="NeedComms" Insert/NeedComms.xml

  assign in sequence NeedComms:DiveInterval = NeedCommsTime

  assign in sequence NeedComms:WaitForPitchUp = 1 second

  insert Insert/StandardEnvelopes.xml

  assign in sequence StandardEnvelopes:MinAltitude = MinAltitude

  assign in sequence StandardEnvelopes:MaxDepth = MaxDepth

  assign in sequence StandardEnvelopes:MinOffshore = MinOffshore

  behavior Guidance:Buoyancy id="BuoyancyHold" {
    run while ( BuoyancyHold )

    set position = Control:VerticalControl.buoyancyNeutral
  }

  behavior Guidance:Pitch id="MassHold" {
    run while ( MassHold )

    set massPosition = Control:VerticalControl.massDefault
  }

  aggregate Transit {
    run in sequence

    behavior Guidance:Pitch {
      run in parallel

      set depth = Depth
    }

    behavior Guidance:SetSpeed {
      run in parallel

      set speed = Speed
    }

    behavior Guidance:Waypoint id="Wpt1" {
      run in sequence

      set latitude = Latitude
      set longitude = Longitude
      set northingsDelta = Northings
      set eastingsDelta = Eastings
    }

    call id="PhoneHome" refId="NeedComms"
  }
}


2023-06-25T01:29:33.618Z,1687656573.618 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl
2023-06-25T01:29:47.557Z,1687656587.557 [Startup:StartupSatComms:B](INFO): Timed out from 2023-06-25T01:28:47.5Z
2023-06-25T01:29:47.557Z,1687656587.557 [Startup:StartupSatComms:B] Stopped
2023-06-25T01:29:47.557Z,1687656587.557 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-06-25T01:29:47.557Z,1687656587.557 [Startup:StartupSatComms] Stopped
2023-06-25T01:29:47.557Z,1687656587.557 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-06-25T01:29:47.558Z,1687656587.558 [Startup](INFO): Completed Startup
2023-06-25T01:29:47.558Z,1687656587.558 [MissionManager](INFO): Startup is completed.
2023-06-25T01:29:47.559Z,1687656587.559 [MissionManager](INFO): Uninitializing Mission Startup
2023-06-25T01:29:47.559Z,1687656587.559 [Startup] Stopped
2023-06-25T01:29:47.559Z,1687656587.559 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-06-25T01:29:47.559Z,1687656587.559 [Startup:A.GoToSurface] Stopped
2023-06-25T01:29:47.559Z,1687656587.559 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-25T01:29:47.993Z,1687656587.993 [MissionManager](IMPORTANT): Started mission Default
2023-06-25T01:29:47.993Z,1687656587.993 [Default] Running Loop=1
2023-06-25T01:29:47.993Z,1687656587.993 [Default](DEBUG): Aggregate::initialize Default
2023-06-25T01:29:47.993Z,1687656587.993 [Default:B.GoToSurface] Running Loop=1
2023-06-25T01:29:47.994Z,1687656587.994 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-25T01:29:47.994Z,1687656587.994 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-25T01:29:47.994Z,1687656587.994 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-25T01:29:47.994Z,1687656587.994 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-25T01:29:47.995Z,1687656587.995 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-25T01:29:48.011Z,1687656588.011 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-25T01:29:48.012Z,1687656588.012 [Default:A.Wait] Running Loop=1
2023-06-25T01:29:48.012Z,1687656588.012 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-25T01:29:49.443Z,1687656589.443 [DataOverHttps](INFO): Sending 184 bytes from file Logs/20230624T031543/Courier0000.lzma
2023-06-25T01:29:50.445Z,1687656590.445 [DataOverHttps](INFO): Moved sent file to Logs/20230624T031543/Courier0000.lzma.bak
2023-06-25T01:29:50.445Z,1687656590.445 [DataOverHttps](INFO): SBD MOMSN=18425228
2023-06-25T01:29:53.905Z,1687656593.905 [CommandExec](IMPORTANT): got command set transit.MissionTimeout 30 minute
2023-06-25T01:29:53.906Z,1687656593.906 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 12 minute
2023-06-25T01:29:53.907Z,1687656593.907 [CommandExec](IMPORTANT): got command set transit.Latitude 43.20017 degree
2023-06-25T01:29:53.908Z,1687656593.908 [CommandExec](IMPORTANT): got command set transit.Longitude -86.3649 degree
2023-06-25T01:29:53.909Z,1687656593.909 [CommandExec](IMPORTANT): got command set transit.Depth 1 meter
2023-06-25T01:29:53.910Z,1687656593.910 [CommandExec](IMPORTANT): got command set transit.MaxDepth 2 meter
2023-06-25T01:29:53.987Z,1687656593.987 [CommandExec](IMPORTANT): got command stop
2023-06-25T01:29:53.988Z,1687656593.988 [CommandExec](IMPORTANT): Scheduling is paused
2023-06-25T01:29:53.988Z,1687656593.988 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-06-25T01:29:59.523Z,1687656599.523 [CommandExec](IMPORTANT): got command set transit.MinOffshore 0.00001 kilometer
2023-06-25T01:29:59.528Z,1687656599.528 [CommandExec](IMPORTANT): got command set transit.MinAltitude 2 meter
2023-06-25T01:29:59.529Z,1687656599.529 [CommandExec](IMPORTANT): got command run
2023-06-25T01:29:59.530Z,1687656599.530 [CommandExec](IMPORTANT): Running 
2023-06-25T01:29:59.709Z,1687656599.709 [Default] Stopped
2023-06-25T01:29:59.709Z,1687656599.709 [Default](DEBUG): Aggregate::uninitialize Default
2023-06-25T01:29:59.709Z,1687656599.709 [Default:A.Wait] Stopped
2023-06-25T01:29:59.709Z,1687656599.709 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-25T01:29:59.709Z,1687656599.709 [Default:B.GoToSurface] Stopped
2023-06-25T01:29:59.709Z,1687656599.709 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-25T01:29:59.709Z,1687656599.709 [MissionManager](IMPORTANT): Started mission transit
2023-06-25T01:29:59.710Z,1687656599.710 [transit] Running Loop=1
2023-06-25T01:29:59.710Z,1687656599.710 [transit](DEBUG): Aggregate::initialize transit
2023-06-25T01:29:59.710Z,1687656599.710 [transit:StandardEnvelopes] Running Loop=1
2023-06-25T01:29:59.710Z,1687656599.710 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes
2023-06-25T01:29:59.710Z,1687656599.710 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-25T01:29:59.710Z,1687656599.710 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2023-06-25T01:29:59.710Z,1687656599.710 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-25T01:29:59.710Z,1687656599.710 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2023-06-25T01:29:59.711Z,1687656599.711 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-25T01:29:59.711Z,1687656599.711 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2023-06-25T01:29:59.711Z,1687656599.711 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-25T01:29:59.711Z,1687656599.711 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-06-25T01:29:59.711Z,1687656599.711 [transit:MassHold.Pitch] Running Loop=1
2023-06-25T01:29:59.711Z,1687656599.711 [transit:MassHold.Pitch](DEBUG): Initialize.
2023-06-25T01:29:59.720Z,1687656599.720 [transit:B] Running Loop=1
2023-06-25T01:29:59.720Z,1687656599.720 [transit:MassHold.Pitch] Running Loop=1
2023-06-25T01:29:59.721Z,1687656599.721 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2023-06-25T01:29:59.721Z,1687656599.721 [transit:StandardEnvelopes] Running Loop=1
2023-06-25T01:29:59.721Z,1687656599.721 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2023-06-25T01:29:59.721Z,1687656599.721 [transit:StandardEnvelopes:C.OffshoreEnvelope](ERROR): Location Measurement is not Active.
2023-06-25T01:29:59.721Z,1687656599.721 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2023-06-25T01:29:59.722Z,1687656599.722 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2023-06-25T01:29:59.723Z,1687656599.723 [transit:B] Stopped
2023-06-25T01:29:59.723Z,1687656599.723 [transit:C] Running Loop=1
2023-06-25T01:29:59.723Z,1687656599.723 [transit:NeedComms] Running Loop=1
2023-06-25T01:29:59.723Z,1687656599.723 [transit:NeedComms](DEBUG): Aggregate::initialize transit:NeedComms
2023-06-25T01:29:59.723Z,1687656599.723 [transit:NeedComms:B.GoToSurface] Running Loop=1
2023-06-25T01:29:59.723Z,1687656599.723 [transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-25T01:29:59.732Z,1687656599.732 [transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2023-06-25T01:29:59.732Z,1687656599.732 [transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2023-06-25T01:29:59.732Z,1687656599.732 [transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2023-06-25T01:29:59.733Z,1687656599.733 [transit:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2023-06-25T01:29:59.733Z,1687656599.733 [transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-25T01:29:59.733Z,1687656599.733 [transit:NeedComms:A] Running Loop=1
2023-06-25T01:29:59.734Z,1687656599.734 [transit:NeedComms:A](ERROR): data element is not active.
2023-06-25T01:29:59.734Z,1687656599.734 [transit:NeedComms:A](INFO): last time_fix was: nan second since 1970/01/01T00:00:00Z 
2023-06-25T01:29:59.734Z,1687656599.734 [transit:NeedComms:A] Stopped
2023-06-25T01:29:59.735Z,1687656599.735 [MissionManager](INFO): MissionManager is completed.
2023-06-25T01:29:59.735Z,1687656599.735 [MissionManager](INFO): Uninitializing Mission transit
2023-06-25T01:29:59.735Z,1687656599.735 [transit] Stopped
2023-06-25T01:29:59.735Z,1687656599.735 [transit](DEBUG): Aggregate::uninitialize transit
2023-06-25T01:29:59.735Z,1687656599.735 [transit:NeedComms] Stopped
2023-06-25T01:29:59.743Z,1687656599.743 [transit:NeedComms](DEBUG): Aggregate::uninitialize transit:NeedComms
2023-06-25T01:29:59.744Z,1687656599.744 [transit:NeedComms:B.GoToSurface] Stopped
2023-06-25T01:29:59.744Z,1687656599.744 [transit:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-25T01:29:59.744Z,1687656599.744 [transit:C] Stopped
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes] Stopped
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2023-06-25T01:29:59.744Z,1687656599.744 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2023-06-25T01:29:59.744Z,1687656599.744 [transit:BuoyancyHold.Buoyancy] Stopped
2023-06-25T01:29:59.744Z,1687656599.744 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-06-25T01:29:59.745Z,1687656599.745 [transit:MassHold.Pitch] Stopped
2023-06-25T01:30:00.065Z,1687656600.065 [MissionManager](IMPORTANT): Started mission Default
2023-06-25T01:30:00.065Z,1687656600.065 [Default] Running Loop=1
2023-06-25T01:30:00.065Z,1687656600.065 [Default](DEBUG): Aggregate::initialize Default
2023-06-25T01:30:00.065Z,1687656600.065 [Default:B.GoToSurface] Running Loop=1
2023-06-25T01:30:00.066Z,1687656600.066 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-25T01:30:00.066Z,1687656600.066 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-25T01:30:00.066Z,1687656600.066 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-25T01:30:00.066Z,1687656600.066 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-25T01:30:00.067Z,1687656600.067 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-25T01:30:00.067Z,1687656600.067 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-25T01:30:00.076Z,1687656600.076 [Default:A.Wait] Running Loop=1
2023-06-25T01:30:00.076Z,1687656600.076 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-25T01:30:13.389Z,1687656613.389 [Default:A.Wait](INFO): Done Waiting.
2023-06-25T01:30:13.389Z,1687656613.389 [Default:A.Wait] Stopped
2023-06-25T01:30:13.390Z,1687656613.390 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-25T01:30:13.793Z,1687656613.793 [Default:CheckIn] Running Loop=1
2023-06-25T01:30:13.794Z,1687656613.794 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-25T01:30:13.794Z,1687656613.794 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-25T01:30:14.174Z,1687656614.174 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-25T01:30:15.040Z,1687656615.040 [CommandExec](IMPORTANT): got command failComponent
2023-06-25T01:30:15.040Z,1687656615.040 [CommandExec](IMPORTANT): Failed components:
2023-06-25T01:30:15.041Z,1687656615.041 [CommandExec](IMPORTANT): No failed Components.
2023-06-25T01:31:22.086Z,1687656682.086 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-25T01:31:39.068Z,1687656699.068 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-06-25T01:31:39.068Z,1687656699.068 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-25T01:31:39.079Z,1687656699.079 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-25T01:31:39.481Z,1687656699.481 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-25T01:31:39.482Z,1687656699.482 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-06-25T01:32:14.760Z,1687656734.760 [CommandExec](IMPORTANT): got command ibit
2023-06-25T01:32:14.000Z,1687656735.000 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-06-25T01:32:14.000Z,1687656735.000 [IBIT](IMPORTANT): Beginning control surface checks.
2023-06-25T01:32:15.003Z,1687656735.003 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-25T01:32:25.937Z,1687656745.937 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005273
CHAN A1 (24V): 0.002741
CHAN A2 (12V): -0.006720
CHAN A3 (5V): -0.003143
CHAN B0 (3.3V): -0.001422
CHAN B1 (3.15aV): -0.001284
CHAN B2 (3.15bV): -0.000976
CHAN B3 (GND): -0.000804
OPEN: 0.000922
Full Scale: +/- 1 mA
2023-06-25T01:33:51.152Z,1687656831.152 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-06-25T01:33:51.152Z,1687656831.152 [DVL_micro](ERROR): Failed to parse: