2023-05-10T16:44:16.787Z,1683737056.787 [Supervisor](DEBUG): Initializing supervisor.
2023-05-10T16:44:16.792Z,1683737056.792 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-10T16:44:16.792Z,1683737056.792 [SyncHandler](INFO): Protected caller Thread ID is 4123
2023-05-10T16:44:16.793Z,1683737056.793 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-10T16:44:16.794Z,1683737056.794 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-10T16:44:16.794Z,1683737056.794 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4124
2023-05-10T16:44:16.798Z,1683737056.798 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-10T16:44:16.817Z,1683737056.817 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-10T16:44:16.818Z,1683737056.818 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-10T16:44:16.818Z,1683737056.818 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4125
2023-05-10T16:44:16.823Z,1683737056.823 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-10T16:44:16.824Z,1683737056.824 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-10T16:44:16.824Z,1683737056.824 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4126
2023-05-10T16:44:16.826Z,1683737056.826 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-10T16:44:16.827Z,1683737056.827 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-10T16:44:16.827Z,1683737056.827 [logger ThreadHandler](INFO): Protected caller Thread ID is 4127
2023-05-10T16:44:16.831Z,1683737056.831 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-10T16:44:16.832Z,1683737056.832 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-10T16:44:16.833Z,1683737056.833 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-10T16:44:17.277Z,1683737057.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-10T16:44:17.278Z,1683737057.278 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-10T16:44:17.483Z,1683737057.483 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-10T16:44:17.483Z,1683737057.483 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-10T16:44:17.561Z,1683737057.561 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-10T16:44:17.771Z,1683737057.771 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-10T16:44:17.772Z,1683737057.772 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-10T16:44:17.848Z,1683737057.848 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-10T16:44:17.941Z,1683737057.941 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-10T16:44:17.942Z,1683737057.942 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-10T16:44:18.265Z,1683737058.265 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-10T16:44:18.266Z,1683737058.266 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-10T16:44:18.393Z,1683737058.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-10T16:44:18.394Z,1683737058.394 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-10T16:44:18.874Z,1683737058.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-10T16:44:18.875Z,1683737058.875 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-10T16:44:19.051Z,1683737059.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-10T16:44:19.051Z,1683737059.051 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-10T16:44:19.507Z,1683737059.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-10T16:44:19.508Z,1683737059.508 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-10T16:44:19.775Z,1683737059.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-10T16:44:19.776Z,1683737059.776 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-10T16:44:19.881Z,1683737059.881 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-10T16:44:19.882Z,1683737059.882 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-10T16:44:20.628Z,1683737060.628 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-10T16:44:20.629Z,1683737060.629 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-10T16:44:20.944Z,1683737060.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-10T16:44:20.945Z,1683737060.945 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-10T16:44:21.158Z,1683737061.158 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-10T16:44:21.160Z,1683737061.160 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-05-10T16:44:21.161Z,1683737061.161 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-05-10T16:44:21.339Z,1683737061.339 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-05-10T16:44:21.420Z,1683737061.420 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-05-10T16:44:21.558Z,1683737061.558 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-05-10T16:44:21.866Z,1683737061.866 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-05-10T16:44:22.319Z,1683737062.319 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-10T16:44:22.320Z,1683737062.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-05-10T16:44:22.421Z,1683737062.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-05-10T16:44:22.529Z,1683737062.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-05-10T16:44:22.639Z,1683737062.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-05-10T16:44:22.782Z,1683737062.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-05-10T16:44:22.878Z,1683737062.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-05-10T16:44:22.969Z,1683737062.969 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-05-10T16:44:22.969Z,1683737062.969 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-10T16:44:22.981Z,1683737062.981 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-10T16:44:22.992Z,1683737062.992 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-10T16:44:22.993Z,1683737062.993 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-10T16:44:23.093Z,1683737063.093 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-10T16:44:23.094Z,1683737063.094 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-10T16:44:23.144Z,1683737063.144 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-10T16:44:23.204Z,1683737063.204 [VerticalControl] Loaded
2023-05-10T16:44:23.205Z,1683737063.205 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-10T16:44:23.208Z,1683737063.208 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-10T16:44:23.249Z,1683737063.249 [HorizontalControl] Loaded
2023-05-10T16:44:23.249Z,1683737063.249 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-10T16:44:23.252Z,1683737063.252 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-10T16:44:23.255Z,1683737063.255 [SpeedControl] Loaded
2023-05-10T16:44:23.255Z,1683737063.255 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-10T16:44:23.258Z,1683737063.258 [LoopControl](DEBUG): Construct LoopControl.
2023-05-10T16:44:23.258Z,1683737063.258 [LoopControl] Loaded
2023-05-10T16:44:23.258Z,1683737063.258 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-10T16:44:23.259Z,1683737063.259 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-10T16:44:23.259Z,1683737063.259 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-10T16:44:23.390Z,1683737063.390 [BuoyancyServo] Loaded
2023-05-10T16:44:23.390Z,1683737063.390 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-10T16:44:23.411Z,1683737063.411 [ElevatorServo] Loaded
2023-05-10T16:44:23.411Z,1683737063.411 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-10T16:44:23.430Z,1683737063.430 [MassServo] Loaded
2023-05-10T16:44:23.430Z,1683737063.430 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-10T16:44:23.449Z,1683737063.449 [RudderServo] Loaded
2023-05-10T16:44:23.449Z,1683737063.449 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-10T16:44:23.464Z,1683737063.464 [ThrusterHE] Loaded
2023-05-10T16:44:23.464Z,1683737063.464 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-10T16:44:23.465Z,1683737063.465 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-10T16:44:23.465Z,1683737063.465 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-10T16:44:23.515Z,1683737063.515 [DepthRateCalculator] Loaded
2023-05-10T16:44:23.516Z,1683737063.516 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-10T16:44:23.521Z,1683737063.521 [PitchRateCalculator] Loaded
2023-05-10T16:44:23.521Z,1683737063.521 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-10T16:44:23.531Z,1683737063.531 [SpeedCalculator] Loaded
2023-05-10T16:44:23.531Z,1683737063.531 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-10T16:44:23.535Z,1683737063.535 [YawRateCalculator] Loaded
2023-05-10T16:44:23.536Z,1683737063.536 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-10T16:44:23.554Z,1683737063.554 [ElevatorOffsetCalculator] Loaded
2023-05-10T16:44:23.555Z,1683737063.555 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-10T16:44:23.555Z,1683737063.555 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-10T16:44:23.556Z,1683737063.556 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-10T16:44:23.669Z,1683737063.669 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-10T16:44:23.670Z,1683737063.670 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-10T16:44:23.683Z,1683737063.683 [NavChart] Loaded
2023-05-10T16:44:23.684Z,1683737063.684 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-10T16:44:23.689Z,1683737063.689 [UniversalFixResidualReporter] Loaded
2023-05-10T16:44:23.690Z,1683737063.690 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-10T16:44:23.690Z,1683737063.690 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-10T16:44:23.691Z,1683737063.691 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-10T16:44:24.124Z,1683737064.124 [AHRS_M2] Loaded
2023-05-10T16:44:24.124Z,1683737064.124 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-10T16:44:24.160Z,1683737064.160 [BackseatComponent] Loaded
2023-05-10T16:44:24.160Z,1683737064.160 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-10T16:44:24.161Z,1683737064.161 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E74E0
2023-05-10T16:44:24.162Z,1683737064.162 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4210
2023-05-10T16:44:24.165Z,1683737064.165 [LcmUniversalReporter] Loaded
2023-05-10T16:44:24.165Z,1683737064.165 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-10T16:44:24.995Z,1683737064.995 [BPC1] Loaded
2023-05-10T16:44:24.996Z,1683737064.996 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-10T16:44:25.068Z,1683737065.068 [DataOverHttps] Loaded
2023-05-10T16:44:25.068Z,1683737065.068 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-10T16:44:25.069Z,1683737065.069 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409174E0
2023-05-10T16:44:25.070Z,1683737065.070 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4211
2023-05-10T16:44:25.091Z,1683737065.091 [Depth_Keller] Loaded
2023-05-10T16:44:25.091Z,1683737065.091 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-10T16:44:25.154Z,1683737065.154 [NAL9602] Loaded
2023-05-10T16:44:25.154Z,1683737065.154 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-10T16:44:25.185Z,1683737065.185 [Onboard] Loaded
2023-05-10T16:44:25.185Z,1683737065.185 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-10T16:44:25.186Z,1683737065.186 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409474E0
2023-05-10T16:44:25.187Z,1683737065.187 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4212
2023-05-10T16:44:25.199Z,1683737065.199 [Power24vConverter] Loaded
2023-05-10T16:44:25.199Z,1683737065.199 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-10T16:44:25.213Z,1683737065.213 [Radio_Surface] Loaded
2023-05-10T16:44:25.213Z,1683737065.213 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-10T16:44:25.214Z,1683737065.214 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409774E0
2023-05-10T16:44:25.215Z,1683737065.215 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4213
2023-05-10T16:44:25.303Z,1683737065.303 [DATMMP] Loaded
2023-05-10T16:44:25.303Z,1683737065.303 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2023-05-10T16:44:25.304Z,1683737065.304 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409A84E0
2023-05-10T16:44:25.305Z,1683737065.305 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 4214
2023-05-10T16:44:25.305Z,1683737065.305 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-10T16:44:25.306Z,1683737065.306 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-10T16:44:25.379Z,1683737065.379 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-10T16:44:25.380Z,1683737065.380 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-10T16:44:25.530Z,1683737065.530 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-10T16:44:25.531Z,1683737065.531 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-10T16:44:25.558Z,1683737065.558 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-10T16:44:25.559Z,1683737065.559 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-10T16:44:25.728Z,1683737065.728 [CTD_Seabird] Loaded
2023-05-10T16:44:25.728Z,1683737065.728 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-10T16:44:25.729Z,1683737065.729 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ADE4E0
2023-05-10T16:44:25.729Z,1683737065.729 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4215
2023-05-10T16:44:25.763Z,1683737065.763 [ESPComponent] Loaded
2023-05-10T16:44:25.763Z,1683737065.763 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-10T16:44:25.784Z,1683737065.784 [PAR_Licor] Loaded
2023-05-10T16:44:25.784Z,1683737065.784 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-10T16:44:25.815Z,1683737065.815 [WetLabsBB2FL] Loaded
2023-05-10T16:44:25.816Z,1683737065.816 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-10T16:44:25.817Z,1683737065.817 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0
2023-05-10T16:44:25.817Z,1683737065.817 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4216
2023-05-10T16:44:25.818Z,1683737065.818 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-10T16:44:25.819Z,1683737065.819 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-10T16:44:26.127Z,1683737066.127 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-10T16:44:26.128Z,1683737066.128 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-10T16:44:26.268Z,1683737066.268 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-10T16:44:26.278Z,1683737066.278 [SBIT] Loaded
2023-05-10T16:44:26.278Z,1683737066.278 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-10T16:44:26.281Z,1683737066.281 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-10T16:44:26.293Z,1683737066.293 [IBIT] Loaded
2023-05-10T16:44:26.294Z,1683737066.294 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-10T16:44:26.300Z,1683737066.300 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-10T16:44:26.406Z,1683737066.406 [CBIT] Loaded
2023-05-10T16:44:26.407Z,1683737066.407 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-10T16:44:26.407Z,1683737066.407 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-10T16:44:26.413Z,1683737066.413 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-10T16:44:26.416Z,1683737066.416 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-10T16:44:26.428Z,1683737066.428 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-10T16:44:26.429Z,1683737066.429 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BF14E0
2023-05-10T16:44:26.429Z,1683737066.429 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4217
2023-05-10T16:44:26.434Z,1683737066.434 [Supervisor](INFO): Main Thread ID is 4122
2023-05-10T16:44:26.434Z,1683737066.434 [Supervisor](DEBUG): Running supervisor.
2023-05-10T16:44:26.434Z,1683737066.434 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4218
2023-05-10T16:44:26.435Z,1683737066.435 [CommandExec](INFO): Initializing the command executive.
2023-05-10T16:44:26.436Z,1683737066.436 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4219
2023-05-10T16:44:26.439Z,1683737066.439 [controlThread ThreadHandler](INFO): Handler Thread ID is 4220
2023-05-10T16:44:26.439Z,1683737066.439 [controlThread](DEBUG): Initializing ControlThread
2023-05-10T16:44:26.440Z,1683737066.440 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-10T16:44:26.441Z,1683737066.441 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-10T16:44:26.442Z,1683737066.442 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-10T16:44:26.443Z,1683737066.443 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-10T16:44:26.444Z,1683737066.444 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-10T16:44:26.444Z,1683737066.444 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-10T16:44:26.445Z,1683737066.445 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-10T16:44:26.445Z,1683737066.445 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-10T16:44:26.445Z,1683737066.445 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-10T16:44:26.446Z,1683737066.446 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-10T16:44:26.447Z,1683737066.447 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-10T16:44:26.453Z,1683737066.453 [SBIT](INFO): Initialize SBIT Component.
2023-05-10T16:44:26.453Z,1683737066.453 [SBIT](IMPORTANT): git: 2023-01-24-38-g3a865bb8c
2023-05-10T16:44:26.454Z,1683737066.454 [SBIT](INFO): git hash: 3a865bb8cac9b788bcd3aa40e502ce5ce0bbf34f
2023-05-10T16:44:26.454Z,1683737066.454 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-10T16:44:26.455Z,1683737066.455 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-05-10T16:44:26.456Z,1683737066.456 [SBIT](INFO): Beginning SBIT in 81.000000 seconds.
2023-05-10T16:44:26.457Z,1683737066.457 [IBIT](INFO): Initialize IBIT Component.
2023-05-10T16:44:26.458Z,1683737066.458 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-10T16:44:26.458Z,1683737066.458 [logger ThreadHandler](INFO): Handler Thread ID is 4221
2023-05-10T16:44:26.469Z,1683737066.469 [CBIT](DEBUG): Initialized mux pins.
2023-05-10T16:44:26.469Z,1683737066.469 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-10T16:44:26.477Z,1683737066.477 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4222
2023-05-10T16:44:26.489Z,1683737066.489 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4223
2023-05-10T16:44:26.490Z,1683737066.490 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-10T16:44:26.493Z,1683737066.493 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-10T16:44:26.493Z,1683737066.493 [CBIT](DEBUG): Initializing heartbeat.
2023-05-10T16:44:26.501Z,1683737066.501 [Onboard ThreadHandler](INFO): Handler Thread ID is 4224
2023-05-10T16:44:26.519Z,1683737066.519 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4225
2023-05-10T16:44:26.541Z,1683737066.541 [DATMMP ThreadHandler](INFO): Handler Thread ID is 4226
2023-05-10T16:44:26.542Z,1683737066.542 [DATMMP](INFO): Start
2023-05-10T16:44:26.542Z,1683737066.542 [DATMMP](INFO): Powering up
2023-05-10T16:44:26.542Z,1683737066.542 [DATMMP](DEBUG): Initializing DATMMP.
2023-05-10T16:44:26.546Z,1683737066.546 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4228
2023-05-10T16:44:26.546Z,1683737066.546 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-10T16:44:26.550Z,1683737066.550 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4230
2023-05-10T16:44:26.553Z,1683737066.553 [WetLabsBB2FL](INFO): Powering up
2023-05-10T16:44:26.554Z,1683737066.554 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4232
2023-05-10T16:44:26.557Z,1683737066.557 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-10T16:44:26.557Z,1683737066.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-10T16:44:26.558Z,1683737066.558 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-10T16:44:26.558Z,1683737066.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-10T16:44:26.558Z,1683737066.558 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-10T16:44:26.558Z,1683737066.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-10T16:44:26.558Z,1683737066.558 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-10T16:44:26.558Z,1683737066.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-10T16:44:26.565Z,1683737066.565 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-10T16:44:26.565Z,1683737066.565 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-10T16:44:26.601Z,1683737066.601 [CBIT](DEBUG): Backplane powered.
2023-05-10T16:44:26.602Z,1683737066.602 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-10T16:44:26.615Z,1683737066.615 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T16:44:26.662Z,1683737066.662 [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-05-10T16:44:26.663Z,1683737066.663 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-10T16:44:26.793Z,1683737066.793 [DATMMP](INFO): Starting
2023-05-10T16:44:26.803Z,1683737066.803 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-10T16:44:26.804Z,1683737066.804 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-10T16:44:26.838Z,1683737066.838 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T16:44:26.892Z,1683737066.892 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-10T16:44:26.925Z,1683737066.925 [Radio_Surface](INFO): Powering up
2023-05-10T16:44:26.928Z,1683737066.928 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-10T16:44:26.954Z,1683737066.954 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-10T16:44:26.958Z,1683737066.958 [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-05-10T16:44:26.976Z,1683737066.976 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,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-05-10T16:44:26.982Z,1683737066.982 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-10T16:44:27.045Z,1683737067.045 [DATMMP](INFO): Starting
2023-05-10T16:44:27.055Z,1683737067.055 [Power24vConverter](INFO): Powering up.
2023-05-10T16:44:27.177Z,1683737067.177 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-10T16:44:27.189Z,1683737067.189 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-10T16:44:27.190Z,1683737067.190 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-10T16:44:27.197Z,1683737067.197 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-10T16:44:27.198Z,1683737067.198 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-10T16:44:27.205Z,1683737067.205 [MassServo](DEBUG): Initializing MassServo.
2023-05-10T16:44:27.206Z,1683737067.206 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-10T16:44:27.213Z,1683737067.213 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-10T16:44:27.214Z,1683737067.214 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-10T16:44:27.221Z,1683737067.221 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-10T16:44:27.297Z,1683737067.297 [DATMMP](INFO): Starting
2023-05-10T16:44:27.549Z,1683737067.549 [DATMMP](INFO): Starting
2023-05-10T16:44:27.801Z,1683737067.801 [DATMMP](INFO): Starting
2023-05-10T16:44:28.053Z,1683737068.053 [DATMMP](INFO): Starting
2023-05-10T16:44:28.141Z,1683737068.141 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2023-05-10T16:44:28.141Z,1683737068.141 [RudderServo](FAULT): Rudder failed to initialize
2023-05-10T16:44:28.141Z,1683737068.141 [RudderServo] Communications Fault, FailCount= 1
2023-05-10T16:44:28.141Z,1683737068.141 [RudderServo](ERROR): Communications Fault
2023-05-10T16:44:28.145Z,1683737068.145 [CBIT](ERROR): Communications Fault in component: RudderServo
2023-05-10T16:44:28.306Z,1683737068.306 [DATMMP](INFO): Starting
2023-05-10T16:44:28.346Z,1683737068.346 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-10T16:44:28.346Z,1683737068.346 [RudderServo](INFO): Powering down
2023-05-10T16:44:28.557Z,1683737068.557 [DATMMP](INFO): Starting
2023-05-10T16:44:28.657Z,1683737068.657 [WetLabsBB2FL](INFO): Powering down
2023-05-10T16:44:28.809Z,1683737068.809 [DATMMP](INFO): Starting
2023-05-10T16:44:29.033Z,1683737069.033 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-10T16:44:29.061Z,1683737069.061 [DATMMP](INFO): Starting
2023-05-10T16:44:29.154Z,1683737069.154 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-10T16:44:29.158Z,1683737069.158 [CBIT](INFO): Clearing failed state for component RudderServo
2023-05-10T16:44:29.158Z,1683737069.158 [RudderServo] No Fault, FailCount= 1
2023-05-10T16:44:29.313Z,1683737069.313 [DATMMP](INFO): Starting
2023-05-10T16:44:29.565Z,1683737069.565 [DATMMP](INFO): Starting
2023-05-10T16:44:29.817Z,1683737069.817 [DATMMP](INFO): Starting
2023-05-10T16:44:30.069Z,1683737070.069 [DATMMP](INFO): Starting
2023-05-10T16:44:30.321Z,1683737070.321 [DATMMP](INFO): Starting
2023-05-10T16:44:30.573Z,1683737070.573 [DATMMP](INFO): Starting
2023-05-10T16:44:30.825Z,1683737070.825 [DATMMP](INFO): Starting
2023-05-10T16:44:31.077Z,1683737071.077 [DATMMP](INFO): Starting
2023-05-10T16:44:31.329Z,1683737071.329 [DATMMP](INFO): Starting
2023-05-10T16:44:31.581Z,1683737071.581 [DATMMP](INFO): Starting
2023-05-10T16:44:31.833Z,1683737071.833 [DATMMP](INFO): Starting
2023-05-10T16:44:32.085Z,1683737072.085 [DATMMP](INFO): Starting
2023-05-10T16:44:32.337Z,1683737072.337 [DATMMP](INFO): Starting
2023-05-10T16:44:32.589Z,1683737072.589 [DATMMP](INFO): Starting
2023-05-10T16:44:32.841Z,1683737072.841 [DATMMP](INFO): Starting
2023-05-10T16:44:33.005Z,1683737073.005 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-10T16:44:33.093Z,1683737073.093 [DATMMP](INFO): Starting
2023-05-10T16:44:33.345Z,1683737073.345 [DATMMP](INFO): Starting
2023-05-10T16:44:33.577Z,1683737073.577 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-05-10T16:44:33.597Z,1683737073.597 [DATMMP](INFO): Starting
2023-05-10T16:44:33.849Z,1683737073.849 [DATMMP](INFO): Starting
2023-05-10T16:44:34.101Z,1683737074.101 [DATMMP](INFO): Starting
2023-05-10T16:44:34.353Z,1683737074.353 [DATMMP](INFO): Starting
2023-05-10T16:44:34.605Z,1683737074.605 [DATMMP](INFO): Starting
2023-05-10T16:44:34.857Z,1683737074.857 [DATMMP](INFO): Starting
2023-05-10T16:44:35.113Z,1683737075.113 [DATMMP](INFO): Starting
2023-05-10T16:44:35.365Z,1683737075.365 [DATMMP](INFO): Starting
2023-05-10T16:44:35.617Z,1683737075.617 [DATMMP](INFO): Starting
2023-05-10T16:44:35.869Z,1683737075.869 [DATMMP](INFO): Starting
2023-05-10T16:44:36.121Z,1683737076.121 [DATMMP](INFO): Starting
2023-05-10T16:44:36.373Z,1683737076.373 [DATMMP](INFO): Starting
2023-05-10T16:44:36.625Z,1683737076.625 [DATMMP](INFO): Starting
2023-05-10T16:44:36.877Z,1683737076.877 [DATMMP](INFO): Starting
2023-05-10T16:44:37.129Z,1683737077.129 [DATMMP](INFO): Starting
2023-05-10T16:44:37.381Z,1683737077.381 [DATMMP](INFO): Starting
2023-05-10T16:44:37.633Z,1683737077.633 [DATMMP](INFO): Starting
2023-05-10T16:44:37.885Z,1683737077.885 [DATMMP](INFO): Starting
2023-05-10T16:44:38.137Z,1683737078.137 [DATMMP](INFO): Starting
2023-05-10T16:44:38.389Z,1683737078.389 [DATMMP](INFO): Starting
2023-05-10T16:44:38.641Z,1683737078.641 [DATMMP](INFO): Starting
2023-05-10T16:44:38.893Z,1683737078.893 [DATMMP](INFO): Starting
2023-05-10T16:44:39.145Z,1683737079.145 [DATMMP](INFO): Starting
2023-05-10T16:44:39.397Z,1683737079.397 [DATMMP](INFO): Starting
2023-05-10T16:44:39.397Z,1683737079.397 [DATMMP](INFO): DAT read: 

2023-05-10T16:44:39.398Z,1683737079.398 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-10T16:44:39.649Z,1683737079.649 [DATMMP](INFO): Starting
2023-05-10T16:44:39.901Z,1683737079.901 [DATMMP](INFO): Starting
2023-05-10T16:44:40.153Z,1683737080.153 [DATMMP](INFO): Starting
2023-05-10T16:44:40.219Z,1683737080.219 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004525
2023-05-10T16:44:40.405Z,1683737080.405 [DATMMP](INFO): Starting
2023-05-10T16:44:40.657Z,1683737080.657 [DATMMP](INFO): Starting
2023-05-10T16:44:40.909Z,1683737080.909 [DATMMP](INFO): Starting
2023-05-10T16:44:40.909Z,1683737080.909 [DATMMP](INFO): DAT read: MF Frequency Band

2023-05-10T16:44:40.911Z,1683737080.911 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-10T16:44:40.911Z,1683737080.911 [DATMMP](INFO): DAT read: Apr 10 2000 01:15:49 

2023-05-10T16:44:41.161Z,1683737081.161 [DATMMP](INFO): Starting
2023-05-10T16:44:41.413Z,1683737081.413 [DATMMP](INFO): Starting
2023-05-10T16:44:41.665Z,1683737081.665 [DATMMP](INFO): Starting
2023-05-10T16:44:41.917Z,1683737081.917 [DATMMP](INFO): Starting
2023-05-10T16:44:42.169Z,1683737082.169 [DATMMP](INFO): Starting
2023-05-10T16:44:42.169Z,1683737082.169 [DATMMP](INFO): DAT read: Features enabled [Bearing]

2023-05-10T16:44:42.171Z,1683737082.171 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T16:44:42.171Z,1683737082.171 [DATMMP](INFO): commRate: 800
2023-05-10T16:44:42.421Z,1683737082.421 [DATMMP](INFO): Starting
2023-05-10T16:44:42.673Z,1683737082.673 [DATMMP](INFO): Starting
2023-05-10T16:44:42.925Z,1683737082.925 [DATMMP](INFO): Starting
2023-05-10T16:44:43.177Z,1683737083.177 [DATMMP](INFO): Starting
2023-05-10T16:44:43.429Z,1683737083.429 [DATMMP](INFO): Starting
2023-05-10T16:44:43.681Z,1683737083.681 [DATMMP](INFO): Starting
2023-05-10T16:44:43.933Z,1683737083.933 [DATMMP](INFO): Starting
2023-05-10T16:44:44.185Z,1683737084.185 [DATMMP](INFO): Starting
2023-05-10T16:44:44.237Z,1683737084.237 [DATMMP](INFO): entering command mode
2023-05-10T16:44:44.437Z,1683737084.437 [DATMMP](INFO): Starting
2023-05-10T16:44:44.437Z,1683737084.437 [DATMMP](INFO): DAT read: 

2023-05-10T16:44:44.438Z,1683737084.438 [DATMMP](INFO): DAT read: user:1>

2023-05-10T16:44:44.438Z,1683737084.438 [DATMMP](DEBUG): read user prompt 1: user:1>

2023-05-10T16:44:44.439Z,1683737084.439 [DATMMP](INFO): entering MMP mode
2023-05-10T16:44:44.689Z,1683737084.689 [DATMMP](INFO): Starting
2023-05-10T16:44:44.689Z,1683737084.689 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:44:44.691Z,1683737084.691 [DATMMP](INFO): status rx: 	 x1
2023-05-10T16:44:44.691Z,1683737084.691 [DATMMP](INFO): MMP status: 1: started
2023-05-10T16:44:44.691Z,1683737084.691 [DATMMP](INFO): Received message type: status
2023-05-10T16:44:44.692Z,1683737084.692 [DATMMP](INFO): Handled
2023-05-10T16:44:44.941Z,1683737084.941 [DATMMP](INFO): Starting
2023-05-10T16:44:44.942Z,1683737084.942 [DATMMP](INFO): Sent Tx Power Config 8
2023-05-10T16:44:44.943Z,1683737084.943 [DATMMP](INFO): Setting local address: 5
2023-05-10T16:44:44.944Z,1683737084.944 [DATMMP](INFO): Setting time to: 16:44:44 And date to:5/10/2023
2023-05-10T16:44:45.193Z,1683737085.193 [DATMMP](INFO): Starting
2023-05-10T16:44:45.193Z,1683737085.193 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:44:45.194Z,1683737085.194 [DATMMP](INFO): mdmpower rx: 	 x8	 x0	 x5	 x0
2023-05-10T16:44:45.194Z,1683737085.194 [DATMMP](INFO): Received message type: mdmpower
2023-05-10T16:44:45.194Z,1683737085.194 [DATMMP](INFO): Handled
2023-05-10T16:44:45.445Z,1683737085.445 [DATMMP](INFO): Starting
2023-05-10T16:44:45.445Z,1683737085.445 [DATMMP](INFO): GSXN notify for xid: 10
2023-05-10T16:44:45.446Z,1683737085.446 [DATMMP](INFO): sreg_txpower rx: 	 x8
2023-05-10T16:44:45.446Z,1683737085.446 [DATMMP](INFO): Received message type: sreg_txpower
2023-05-10T16:44:45.446Z,1683737085.446 [DATMMP](INFO): Match for : sreg_txpower
2023-05-10T16:44:45.446Z,1683737085.446 [DATMMP](INFO): ACK
2023-05-10T16:44:45.697Z,1683737085.697 [DATMMP](INFO): Starting
2023-05-10T16:44:45.697Z,1683737085.697 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:44:45.698Z,1683737085.698 [DATMMP](INFO): mdmlocal rx: 	 x5	 x0	 x0	 x0
2023-05-10T16:44:45.698Z,1683737085.698 [DATMMP](INFO): Received message type: mdmlocal
2023-05-10T16:44:45.698Z,1683737085.698 [DATMMP](INFO): Handled
2023-05-10T16:44:45.949Z,1683737085.949 [DATMMP](INFO): Starting
2023-05-10T16:44:45.949Z,1683737085.949 [DATMMP](INFO): GSXN notify for xid: 11
2023-05-10T16:44:45.950Z,1683737085.950 [DATMMP](INFO): sreg_locaddr rx: 	 x5
2023-05-10T16:44:45.950Z,1683737085.950 [DATMMP](INFO): Received message type: sreg_locaddr
2023-05-10T16:44:45.950Z,1683737085.950 [DATMMP](INFO): Match for : sreg_locaddr
2023-05-10T16:44:45.950Z,1683737085.950 [DATMMP](INFO): ACK
2023-05-10T16:44:46.201Z,1683737086.201 [DATMMP](INFO): Starting
2023-05-10T16:44:46.201Z,1683737086.201 [DATMMP](INFO): GSXN notify for xid: 12
2023-05-10T16:44:46.202Z,1683737086.202 [DATMMP](INFO): timedate rx: 	 x0	 x10	 x2C	 x2C	 x4	 xA	 x7B	 x0
2023-05-10T16:44:46.202Z,1683737086.202 [DATMMP](INFO): Received message type: timedate
2023-05-10T16:44:46.203Z,1683737086.203 [DATMMP](INFO): Match for : timedate
2023-05-10T16:44:46.203Z,1683737086.203 [DATMMP](INFO): ACK
2023-05-10T16:44:46.453Z,1683737086.453 [DATMMP](INFO): Starting
2023-05-10T16:44:46.453Z,1683737086.453 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:44:46.454Z,1683737086.454 [DATMMP](INFO): sys_verb rx: 	 x0	 x0	 x0	 x0
2023-05-10T16:44:46.454Z,1683737086.454 [DATMMP](INFO): Received message type: sys_verb
2023-05-10T16:44:46.454Z,1683737086.454 [DATMMP](INFO): Handled
2023-05-10T16:44:46.705Z,1683737086.705 [DATMMP](INFO): Starting
2023-05-10T16:44:46.705Z,1683737086.705 [DATMMP](INFO): GSXN notify for xid: 13
2023-05-10T16:44:46.706Z,1683737086.706 [DATMMP](INFO): sreg_verbosity rx: 	 x0
2023-05-10T16:44:46.706Z,1683737086.706 [DATMMP](INFO): Received message type: sreg_verbosity
2023-05-10T16:44:46.706Z,1683737086.706 [DATMMP](INFO): Match for : sreg_verbosity
2023-05-10T16:44:46.706Z,1683737086.706 [DATMMP](INFO): ACK
2023-05-10T16:44:46.957Z,1683737086.957 [DATMMP](INFO): Starting
2023-05-10T16:44:46.957Z,1683737086.957 [DATMMP](INFO): GSXN notify for xid: 14
2023-05-10T16:44:46.958Z,1683737086.958 [DATMMP](INFO): version rx: 	 x2	 x5
2023-05-10T16:44:46.958Z,1683737086.958 [DATMMP](INFO): DatMMPVersion: 2.5
2023-05-10T16:44:46.958Z,1683737086.958 [DATMMP](INFO): Received message type: version
2023-05-10T16:44:46.959Z,1683737086.959 [DATMMP](INFO): Match for : version
2023-05-10T16:44:46.959Z,1683737086.959 [DATMMP](INFO): ACK
2023-05-10T16:44:46.959Z,1683737086.959 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-05-10T16:44:55.294Z,1683737095.294 [NAL9602](INFO): Powering up NAL9602
2023-05-10T16:45:01.581Z,1683737101.581 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:45:01.582Z,1683737101.582 [DATMMP](INFO): timesync rx: 	 x0	 x1	 x1	 x0
2023-05-10T16:45:01.582Z,1683737101.582 [DATMMP](INFO): Received message type: timesync
2023-05-10T16:45:01.582Z,1683737101.582 [DATMMP](INFO): Handled
2023-05-10T16:45:06.214Z,1683737106.214 [NAL9602](INFO): NAL9602 initialized
2023-05-10T16:45:11.409Z,1683737111.409 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:45:11.410Z,1683737111.410 [DATMMP](INFO): timesync rx: 	 x1	 x0	 x1	 x0
2023-05-10T16:45:11.410Z,1683737111.410 [DATMMP](INFO): Received message type: timesync
2023-05-10T16:45:11.410Z,1683737111.410 [DATMMP](INFO): Handled
2023-05-10T16:45:29.251Z,1683737129.251 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-10T16:45:29.259Z,1683737129.259 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2023-05-10T16:45:29.259Z,1683737129.259 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-10T16:45:29.295Z,1683737129.295 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2023-05-10T16:45:29.295Z,1683737129.295 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-10T16:45:29.303Z,1683737129.303 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,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-05-10T16:45:29.314Z,1683737129.314 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2023-05-10T16:45:29.314Z,1683737129.314 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-05-10T16:45:29.315Z,1683737129.315 [CommandExec](IMPORTANT): got command report touch acoustic_contact_range
2023-05-10T16:45:29.670Z,1683737129.670 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-10T16:45:39.427Z,1683737139.427 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683737129 second
2023-05-10T16:45:47.916Z,1683737147.916 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-10T16:45:47.920Z,1683737147.920 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-10T16:45:58.768Z,1683737158.768 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.009611
CHAN A1 (24V): -0.007910
CHAN A2 (12V): -0.005205
CHAN A3 (5V): -0.002458
CHAN B0 (3.3V): -0.001620
CHAN B1 (3.15aV): -0.000681
CHAN B2 (3.15bV): -0.000711
CHAN B3 (GND): -0.000512
OPEN: 0.004487
Full Scale: +/- 1 mA
2023-05-10T16:46:41.977Z,1683737201.977 [SBIT](IMPORTANT): SBIT PASSED
2023-05-10T16:46:41.978Z,1683737201.978 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-10T16:46:41.978Z,1683737201.978 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-10T16:46:41.979Z,1683737201.979 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2023-05-10T16:46:41.980Z,1683737201.980 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=184.896478 cubic_centimeter;

2023-05-10T16:46:41.980Z,1683737201.980 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-05-10T16:46:41.980Z,1683737201.980 [SBIT](IMPORTANT): VerticalControl.massDefault=15.484465 millimeter;

2023-05-10T16:46:42.393Z,1683737202.393 [MissionManager](IMPORTANT): Started mission Startup
2023-05-10T16:46:42.393Z,1683737202.393 [Startup] Running Loop=1
2023-05-10T16:46:42.393Z,1683737202.393 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-10T16:46:42.393Z,1683737202.393 [Startup:A.GoToSurface] Running Loop=1
2023-05-10T16:46:42.393Z,1683737202.393 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T16:46:42.394Z,1683737202.394 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T16:46:42.394Z,1683737202.394 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T16:46:42.395Z,1683737202.395 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T16:46:42.395Z,1683737202.395 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T16:46:42.395Z,1683737202.395 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T16:46:42.397Z,1683737202.397 [Startup:StartupSatComms] Running Loop=1
2023-05-10T16:46:42.397Z,1683737202.397 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-10T16:46:42.397Z,1683737202.397 [Startup:StartupSatComms:A] Running Loop=1
2023-05-10T16:46:42.800Z,1683737202.800 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-10T16:46:42.801Z,1683737202.801 [Startup:StartupSatComms:A] Stopped
2023-05-10T16:46:42.801Z,1683737202.801 [Startup:StartupSatComms:B] Running Loop=1
2023-05-10T16:46:43.181Z,1683737203.181 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T16:46:49.000Z,1683737210.000 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20230509T234652/Courier0025.lzma
2023-05-10T16:46:51.003Z,1683737211.003 [DataOverHttps](INFO): Moved sent file to Logs/20230509T234652/Courier0025.lzma.bak
2023-05-10T16:46:51.003Z,1683737211.003 [DataOverHttps](INFO): SBD MOMSN=18286386
2023-05-10T16:46:55.695Z,1683737215.695 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:47:06.249Z,1683737226.249 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230510T164416/Courier0000.lzma
2023-05-10T16:47:07.246Z,1683737227.246 [DataOverHttps](INFO): Moved sent file to Logs/20230510T164416/Courier0000.lzma.bak
2023-05-10T16:47:07.246Z,1683737227.246 [DataOverHttps](INFO): SBD MOMSN=18286392
2023-05-10T16:47:09.425Z,1683737229.425 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:47:23.162Z,1683737243.162 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:47:24.516Z,1683737244.516 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20230509T234652/Express0026.lzma
2023-05-10T16:47:25.518Z,1683737245.518 [DataOverHttps](INFO): Moved sent file to Logs/20230509T234652/Express0026.lzma.bak
2023-05-10T16:47:25.519Z,1683737245.519 [DataOverHttps](INFO): SBD MOMSN=18286399
2023-05-10T16:47:36.493Z,1683737256.493 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:47:42.989Z,1683737262.989 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-10T16:46:42.8Z
2023-05-10T16:47:42.989Z,1683737262.989 [Startup:StartupSatComms:B] Stopped
2023-05-10T16:47:42.989Z,1683737262.989 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-10T16:47:42.989Z,1683737262.989 [Startup:StartupSatComms] Stopped
2023-05-10T16:47:42.990Z,1683737262.990 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-10T16:47:42.990Z,1683737262.990 [Startup](INFO): Completed Startup
2023-05-10T16:47:42.990Z,1683737262.990 [MissionManager](INFO): Startup is completed.
2023-05-10T16:47:42.991Z,1683737262.991 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-10T16:47:42.991Z,1683737262.991 [Startup] Stopped
2023-05-10T16:47:42.991Z,1683737262.991 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-10T16:47:42.991Z,1683737262.991 [Startup:A.GoToSurface] Stopped
2023-05-10T16:47:42.991Z,1683737262.991 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T16:47:43.399Z,1683737263.399 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T16:47:43.399Z,1683737263.399 [Default] Running Loop=1
2023-05-10T16:47:43.399Z,1683737263.399 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T16:47:43.399Z,1683737263.399 [Default:B.GoToSurface] Running Loop=1
2023-05-10T16:47:43.399Z,1683737263.399 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T16:47:43.400Z,1683737263.400 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T16:47:43.400Z,1683737263.400 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T16:47:43.401Z,1683737263.401 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T16:47:43.401Z,1683737263.401 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T16:47:43.401Z,1683737263.401 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T16:47:43.402Z,1683737263.402 [Default:A.Wait] Running Loop=1
2023-05-10T16:47:43.402Z,1683737263.402 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T16:47:44.266Z,1683737264.266 [DataOverHttps](INFO): Sending 1256 bytes from file Logs/20230510T164416/Express0001.lzma
2023-05-10T16:47:45.266Z,1683737265.266 [DataOverHttps](INFO): Moved sent file to Logs/20230510T164416/Express0001.lzma.bak
2023-05-10T16:47:45.266Z,1683737265.266 [DataOverHttps](INFO): SBD MOMSN=18286403
2023-05-10T16:47:49.421Z,1683737269.421 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:47:56.753Z,1683737276.753 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T16:47:56.753Z,1683737276.753 [Default:A.Wait] Stopped
2023-05-10T16:47:56.753Z,1683737276.753 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T16:47:57.130Z,1683737277.130 [Default:CheckIn] Running Loop=1
2023-05-10T16:47:57.130Z,1683737277.130 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T16:47:57.130Z,1683737277.130 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T16:47:57.528Z,1683737277.528 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-10T16:48:02.754Z,1683737282.754 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:48:16.087Z,1683737296.087 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:48:29.821Z,1683737309.821 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:48:43.153Z,1683737323.153 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:48:56.890Z,1683737336.890 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:49:10.625Z,1683737350.625 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T16:50:10.013Z,1683737410.013 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T16:51:53.899Z,1683737513.899 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 5.
2023-05-10T16:51:53.902Z,1683737513.902 [BPC1](INFO): Received data from all battery sticks.
2023-05-10T16:52:57.340Z,1683737577.340 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T16:47:57.1Z
2023-05-10T16:52:57.340Z,1683737577.340 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T16:52:57.340Z,1683737577.340 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T16:52:57.756Z,1683737577.756 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T16:53:04.148Z,1683737584.148 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230510T164416/Courier0004.lzma
2023-05-10T16:53:05.157Z,1683737585.157 [DataOverHttps](INFO): Moved sent file to Logs/20230510T164416/Courier0004.lzma.bak
2023-05-10T16:53:05.157Z,1683737585.157 [DataOverHttps](INFO): SBD MOMSN=18286461
2023-05-10T16:53:22.136Z,1683737602.136 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20230510T164416/Express0005.lzma
2023-05-10T16:53:23.138Z,1683737603.138 [DataOverHttps](INFO): Moved sent file to Logs/20230510T164416/Express0005.lzma.bak
2023-05-10T16:53:23.138Z,1683737603.138 [DataOverHttps](INFO): SBD MOMSN=18286467
2023-05-10T16:53:25.654Z,1683737605.654 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T16:53:25.654Z,1683737605.654 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T16:53:25.654Z,1683737605.654 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T16:53:28.049Z,1683737608.049 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T16:55:29.494Z,1683737729.494 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T16:55:29.494Z,1683737729.494 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T16:55:29.543Z,1683737729.543 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 9.000000 count
2023-05-10T16:55:29.546Z,1683737729.546 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-10T16:55:29.550Z,1683737729.550 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-10T16:55:29.553Z,1683737729.553 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-10T16:55:29.555Z,1683737729.555 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-10T16:55:29.558Z,1683737729.558 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-10T16:55:29.561Z,1683737729.561 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-10T16:55:29.564Z,1683737729.564 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-10T16:55:29.567Z,1683737729.567 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-10T16:55:29.570Z,1683737729.570 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-10T16:55:29.728Z,1683737729.728 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-10T16:55:29.758Z,1683737729.758 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
    Id="senddata_direct_and_track_test">


    <DefineArg Name="AcousticTargetContactLabel"><Description>
        The acoustic address of the asset to be tracked. 21 is waveglider Tiny
    </Description><Units:count/><Value>9</Value></DefineArg>

    <DefineArg Name="AcousticTargetDepth"><Description>
        Depth of acoustic target if known and fixed (or nearly fixed). For
        example, if the acoustic target is a Wave Glider, set it to zero. This
        will improve 2D projected position estimates in the Earth reference
        frame. Defaults to NaN.
    </Description><Units:meter/><Value>0</Value></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>15</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of return pings to request with each acoustic query (more than 1
        will activate oneway mode)
    </Description><Units:count/><Value>1</Value></DefineArg>    

    <DefineArg Name="NumberOfFixesLowPass"><Description>
        Number of fixes to average to produce smoothed lat/lon/dep output
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="NumberOfStartingFixesToIgnore"><Description>
        Number of fixes to ignore at the start of mission (as the vehicle just
        leaves surface, contact's location estimate especailly bearing can be
        erroneous. Initialized to 8, corresponding to 2 minutes if query
        interval TrackingUpdatePeriod = 15 s.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="AcommsInterval"><Description></Description><Units:minute/><Value>1</Value></DefineArg>    
    
    <DefineArg Name="modemId1"><Description>
        Modem ID1.
    </Description><Units:enum/><Value>9</Value></DefineArg>

    <DefineArg Name="modemId2"><Description>
        Modem ID2.
    </Description><Units:enum/><Value>5</Value></DefineArg>

    <DefineOutput Name="ModemID"><Description>
        Modem ID. Set to modemId1 or modemId2. Initialized to 1.
    </Description><Units:enum/><Value>1</Value></DefineOutput>            


    <Estimation:TrackAcousticContact Id="TrackAC">
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="AcousticTargetContactLabel"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>



    <Aggregate Id="DirectData">
    <Sequence Repeat="4"/>
    
      <Guidance:Wait>
          <Sequence/>
          <Setting><Guidance:Wait.duration/><Arg Name="AcommsInterval"/></Setting>
      </Guidance:Wait>
                  
      <SendData Service="Direct" Destination="modem:9:_.pressure">
          <Sensor:Onboard.Pressure/><Units:atmosphere/>
      </SendData>
    
      <SendData Service="Direct" Destination="modem:9:_.temperature">
          <Sensor:Onboard.Temperature/><Units:celsius/>
      </SendData>
    
      <SendData Service="Direct" Destination="modem:9:_.humidity">
          <Sensor:Onboard.Humidity/><Units:percent/>
      </SendData>
    
    </Aggregate>

</Mission>


2023-05-10T16:55:29.760Z,1683737729.760 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T16:55:30.080Z,1683737730.080 [Default] Stopped
2023-05-10T16:55:30.080Z,1683737730.080 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T16:55:30.080Z,1683737730.080 [Default:B.GoToSurface] Stopped
2023-05-10T16:55:30.080Z,1683737730.080 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T16:55:30.081Z,1683737730.081 [Default:CheckIn] Stopped
2023-05-10T16:55:30.081Z,1683737730.081 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T16:55:30.081Z,1683737730.081 [Default:CheckIn:C.Wait] Stopped
2023-05-10T16:55:30.081Z,1683737730.081 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T16:55:30.081Z,1683737730.081 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-10T16:55:30.081Z,1683737730.081 [senddata_direct_and_track_test] Running Loop=1
2023-05-10T16:55:30.081Z,1683737730.081 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-10T16:55:30.081Z,1683737730.081 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T16:55:30.082Z,1683737730.082 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-10T16:55:30.082Z,1683737730.082 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-10T16:55:30.082Z,1683737730.082 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-10T16:55:30.082Z,1683737730.082 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-10T16:55:30.082Z,1683737730.082 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T16:55:30.082Z,1683737730.082 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T16:55:45.419Z,1683737745.419 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T16:55:45.445Z,1683737745.445 [DATMMP](INFO): ****** received valid address query ******
2023-05-10T16:55:45.445Z,1683737745.445 [DATMMP](INFO): ****** received valid ping request ******
2023-05-10T16:55:45.446Z,1683737745.446 [DATMMP](INFO): Querying Benthos address 9
2023-05-10T16:55:45.446Z,1683737745.446 [DATMMP](INFO): type: 1 tat: 1
2023-05-10T16:55:45.697Z,1683737745.697 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:45.698Z,1683737745.698 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x37	 x2B	 x1A60
2023-05-10T16:55:45.698Z,1683737745.698 [DATMMP](INFO): Received message type: timestamp
2023-05-10T16:55:45.698Z,1683737745.698 [DATMMP](INFO): Handled
2023-05-10T16:55:45.699Z,1683737745.699 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:45.949Z,1683737745.949 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:46.201Z,1683737746.201 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:46.453Z,1683737746.453 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:46.705Z,1683737746.705 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:46.957Z,1683737746.957 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:47.209Z,1683737747.209 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:47.461Z,1683737747.461 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:47.713Z,1683737747.713 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:47.968Z,1683737747.968 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:47.970Z,1683737747.970 [DATMMP](INFO): doppler rx: 	 x0
2023-05-10T16:55:47.971Z,1683737747.971 [DATMMP](INFO): Received message type: doppler
2023-05-10T16:55:47.971Z,1683737747.971 [DATMMP](INFO): Handled
2023-05-10T16:55:47.971Z,1683737747.971 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:48.217Z,1683737748.217 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:48.218Z,1683737748.218 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x37	 x2D	 x1B90
2023-05-10T16:55:48.219Z,1683737748.219 [DATMMP](INFO): Rx dataTimestamp_ set to:1683737749.950272
2023-05-10T16:55:48.219Z,1683737748.219 [DATMMP](INFO): Rx ping set to:1683737748.218112
2023-05-10T16:55:48.219Z,1683737748.219 [DATMMP](INFO): Received message type: timestamp
2023-05-10T16:55:48.219Z,1683737748.219 [DATMMP](INFO): Handled
2023-05-10T16:55:48.220Z,1683737748.220 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:48.469Z,1683737748.469 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:48.721Z,1683737748.721 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:48.723Z,1683737748.723 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 x5	 x9	 x0
2023-05-10T16:55:48.723Z,1683737748.723 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-10T16:55:48.723Z,1683737748.723 [DATMMP](INFO): Received message type: remote_header
2023-05-10T16:55:48.723Z,1683737748.723 [DATMMP](INFO): Handled
2023-05-10T16:55:48.723Z,1683737748.723 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:48.973Z,1683737748.973 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:48.974Z,1683737748.974 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-10T16:55:48.974Z,1683737748.974 [DATMMP](INFO): Received message type: nav_stat
2023-05-10T16:55:48.974Z,1683737748.974 [DATMMP](INFO): Handled
2023-05-10T16:55:48.974Z,1683737748.974 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:49.225Z,1683737749.225 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:49.226Z,1683737749.226 [DATMMP](INFO): directional_debug rx: 	 xD7D	 x294	 x24	 xFD	 x1080	 x12A1	 x11E2	 x15C3
2023-05-10T16:55:49.228Z,1683737749.228 [DATMMP](INFO): Received message type: directional_debug
2023-05-10T16:55:49.228Z,1683737749.228 [DATMMP](INFO): Handled
2023-05-10T16:55:49.228Z,1683737749.228 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:49.477Z,1683737749.477 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:49.479Z,1683737749.479 [DATMMP](INFO): directional rx: 	 xD78	 x26E	 x66F	 xFD6C	 xB9D	 xFD6F	 x0	 x55A	 x4	 xFFEC	 x27B5966	 x-43569E0
2023-05-10T16:55:49.481Z,1683737749.481 [DATMMP](INFO): Received message type: directional
2023-05-10T16:55:49.481Z,1683737749.481 [DATMMP](INFO): Handled
2023-05-10T16:55:49.481Z,1683737749.481 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:49.729Z,1683737749.729 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:49.731Z,1683737749.731 [DATMMP](INFO): acstats rx: 	 x9	 x0	 x0	 x284	 x23	 x9E	 xDD	 xBB	 xD	 xFFFF	 xB1	 x22	 xC	 x0
2023-05-10T16:55:49.731Z,1683737749.731 [DATMMP](INFO): Received message type: acstats
2023-05-10T16:55:49.731Z,1683737749.731 [DATMMP](INFO): Handled
2023-05-10T16:55:49.731Z,1683737749.731 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:49.981Z,1683737749.981 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T16:55:49.982Z,1683737749.982 [DATMMP](INFO): range_update rx: 	 x9	 x2	 x9	 xC
2023-05-10T16:55:49.983Z,1683737749.983 [DATMMP](INFO): Received message type: range_update
2023-05-10T16:55:49.983Z,1683737749.983 [DATMMP](INFO): Handled
2023-05-10T16:55:49.983Z,1683737749.983 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:50.233Z,1683737750.233 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-10T16:55:50.234Z,1683737750.234 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-10T16:55:50.234Z,1683737750.234 [DATMMP](ERROR): 4:Command error: data
2023-05-10T16:55:50.235Z,1683737750.235 [DATMMP](ERROR): 4:COMPLETE
2023-05-10T16:55:50.235Z,1683737750.235 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:50.315Z,1683737750.315 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m
2023-05-10T16:55:50.316Z,1683737750.316 [Reporter](INFO): acoustic_contact_range 0.900000 m
2023-05-10T16:55:50.485Z,1683737750.485 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:50.737Z,1683737750.737 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:50.989Z,1683737750.989 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:51.241Z,1683737751.241 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:51.493Z,1683737751.493 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:51.745Z,1683737751.745 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:51.997Z,1683737751.997 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:52.249Z,1683737752.249 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:52.501Z,1683737752.501 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:52.754Z,1683737752.754 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:53.005Z,1683737753.005 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:53.257Z,1683737753.257 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:53.509Z,1683737753.509 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:53.761Z,1683737753.761 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:54.013Z,1683737754.013 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:54.265Z,1683737754.265 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:54.517Z,1683737754.517 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:54.769Z,1683737754.769 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:55.021Z,1683737755.021 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:55.273Z,1683737755.273 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:55.525Z,1683737755.525 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T16:55:58.125Z,1683737758.125 [CommandExec](IMPORTANT): got command stop
2023-05-10T16:55:58.125Z,1683737758.125 [CommandExec](IMPORTANT): Scheduling is paused
2023-05-10T16:55:58.126Z,1683737758.126 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-05-10T16:55:58.378Z,1683737758.378 [MissionManager](INFO): MissionManager is completed.
2023-05-10T16:55:58.378Z,1683737758.378 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-10T16:55:58.378Z,1683737758.378 [senddata_direct_and_track_test] Stopped
2023-05-10T16:55:58.378Z,1683737758.378 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-10T16:55:58.378Z,1683737758.378 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-10T16:55:58.378Z,1683737758.378 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-10T16:55:58.378Z,1683737758.378 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-10T16:55:58.379Z,1683737758.379 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-10T16:55:58.379Z,1683737758.379 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-10T16:55:58.379Z,1683737758.379 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T16:55:58.770Z,1683737758.770 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T16:55:58.770Z,1683737758.770 [Default] Running Loop=1
2023-05-10T16:55:58.770Z,1683737758.770 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T16:55:58.770Z,1683737758.770 [Default:B.GoToSurface] Running Loop=1
2023-05-10T16:55:58.770Z,1683737758.770 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T16:55:58.770Z,1683737758.770 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T16:55:58.771Z,1683737758.771 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T16:55:58.771Z,1683737758.771 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T16:55:58.771Z,1683737758.771 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T16:55:58.772Z,1683737758.772 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T16:55:58.772Z,1683737758.772 [Default:A.Wait] Running Loop=1
2023-05-10T16:55:58.772Z,1683737758.772 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T16:56:12.083Z,1683737772.083 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T16:56:12.083Z,1683737772.083 [Default:A.Wait] Stopped
2023-05-10T16:56:12.083Z,1683737772.083 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T16:56:12.492Z,1683737772.492 [Default:CheckIn] Running Loop=1
2023-05-10T16:56:12.492Z,1683737772.492 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T16:56:12.492Z,1683737772.492 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T16:56:14.098Z,1683737774.098 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-10T16:56:14.098Z,1683737774.098 [NAL9602] Data Fault, FailCount= 1
2023-05-10T16:56:14.098Z,1683737774.098 [NAL9602](ERROR): Data Fault
2023-05-10T16:56:14.138Z,1683737774.138 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-10T16:56:14.497Z,1683737774.497 [NAL9602](INFO): Powering down
2023-05-10T16:56:15.336Z,1683737775.336 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-10T16:56:15.336Z,1683737775.336 [NAL9602] No Fault, FailCount= 1
2023-05-10T16:56:44.796Z,1683737804.796 [NAL9602](INFO): Powering up NAL9602
2023-05-10T16:56:55.709Z,1683737815.709 [NAL9602](INFO): NAL9602 initialized
2023-05-10T16:57:26.443Z,1683737846.443 [CommandExec](IMPORTANT): got command restart application
2023-05-10T16:57:27.445Z,1683737847.445 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:27.445Z,1683737847.445 [CommandExec](INFO): Uninitializing the command executive.
2023-05-10T16:57:27.445Z,1683737847.445 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-10T16:57:27.445Z,1683737847.445 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:27.557Z,1683737847.557 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-05-10T16:57:27.558Z,1683737847.558 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-10T16:57:27.558Z,1683737847.558 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:27.558Z,1683737847.558 [NavChartDb](INFO): Join timeout helper Thread ID is 4262
2023-05-10T16:57:27.813Z,1683737847.813 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:27.813Z,1683737847.813 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:27.825Z,1683737847.825 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-10T16:57:27.825Z,1683737847.825 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:27.825Z,1683737847.825 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4263
2023-05-10T16:57:28.297Z,1683737848.297 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:28.297Z,1683737848.297 [WetLabsBB2FL](INFO): Powering down
2023-05-10T16:57:28.298Z,1683737848.298 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:28.319Z,1683737848.319 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-10T16:57:28.319Z,1683737848.319 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:28.319Z,1683737848.319 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4264
2023-05-10T16:57:28.861Z,1683737848.861 [CTD_Seabird](INFO): Powering down
2023-05-10T16:57:28.873Z,1683737848.873 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:28.873Z,1683737848.873 [CTD_Seabird](INFO): Powering down
2023-05-10T16:57:28.885Z,1683737848.885 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:28.899Z,1683737848.899 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler
2023-05-10T16:57:28.899Z,1683737848.899 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:28.899Z,1683737848.899 [DATMMP](INFO): Join timeout helper Thread ID is 4265
2023-05-10T16:57:29.073Z,1683737849.073 [DATMMP](INFO): Stop
2023-05-10T16:57:29.073Z,1683737849.073 [DATMMP](INFO): uninitialize
2023-05-10T16:57:29.073Z,1683737849.073 [DATMMP](INFO): Powering down
2023-05-10T16:57:29.145Z,1683737849.145 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:29.145Z,1683737849.145 [DATMMP](INFO): uninitialize
2023-05-10T16:57:29.146Z,1683737849.146 [DATMMP](INFO): Powering down
2023-05-10T16:57:29.146Z,1683737849.146 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:29.165Z,1683737849.165 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-10T16:57:29.165Z,1683737849.165 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:29.165Z,1683737849.165 [Radio_Surface](INFO): Join timeout helper Thread ID is 4266
2023-05-10T16:57:29.169Z,1683737849.169 [Radio_Surface](INFO): Powering down
2023-05-10T16:57:29.170Z,1683737849.170 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:29.170Z,1683737849.170 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:29.183Z,1683737849.183 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-10T16:57:29.183Z,1683737849.183 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:29.183Z,1683737849.183 [Onboard](INFO): Join timeout helper Thread ID is 4267
2023-05-10T16:57:29.241Z,1683737849.241 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-05-10T16:57:32.193Z,1683737852.193 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:32.193Z,1683737852.193 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.205Z,1683737852.205 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-10T16:57:32.205Z,1683737852.205 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.206Z,1683737852.206 [DataOverHttps](INFO): Join timeout helper Thread ID is 4268
2023-05-10T16:57:32.253Z,1683737852.253 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:32.253Z,1683737852.253 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.265Z,1683737852.265 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-10T16:57:32.265Z,1683737852.265 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.266Z,1683737852.266 [BackseatComponent](INFO): Join timeout helper Thread ID is 4269
2023-05-10T16:57:32.453Z,1683737852.453 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:32.453Z,1683737852.453 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.465Z,1683737852.465 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-10T16:57:32.465Z,1683737852.465 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.466Z,1683737852.466 [logger](INFO): Join timeout helper Thread ID is 4270
2023-05-10T16:57:32.481Z,1683737852.481 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:32.481Z,1683737852.481 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.485Z,1683737852.485 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-10T16:57:32.485Z,1683737852.485 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.486Z,1683737852.486 [CommandLine](INFO): Join timeout helper Thread ID is 4271
2023-05-10T16:57:32.513Z,1683737852.513 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:32.513Z,1683737852.513 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.515Z,1683737852.515 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-10T16:57:32.515Z,1683737852.515 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.515Z,1683737852.515 [CommandExec](INFO): Join timeout helper Thread ID is 4272
2023-05-10T16:57:32.521Z,1683737852.521 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-10T16:57:32.522Z,1683737852.522 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.522Z,1683737852.522 [controlThread](INFO): Join timeout helper Thread ID is 4273
2023-05-10T16:57:32.543Z,1683737852.543 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T16:57:32.543Z,1683737852.543 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-10T16:57:32.543Z,1683737852.543 [AHRS_M2](INFO): Powering down
2023-05-10T16:57:32.613Z,1683737852.613 [NAL9602](INFO): Powering down
2023-05-10T16:57:32.616Z,1683737852.616 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-10T16:57:32.617Z,1683737852.617 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-10T16:57:32.617Z,1683737852.617 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-10T16:57:32.618Z,1683737852.618 [MissionManager](INFO): Uninitializing Mission Default
2023-05-10T16:57:32.618Z,1683737852.618 [Default] Stopped
2023-05-10T16:57:32.618Z,1683737852.618 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T16:57:32.618Z,1683737852.618 [Default:B.GoToSurface] Stopped
2023-05-10T16:57:32.618Z,1683737852.618 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T16:57:32.618Z,1683737852.618 [Default:CheckIn] Stopped
2023-05-10T16:57:32.618Z,1683737852.618 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T16:57:32.618Z,1683737852.618 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T16:57:32.621Z,1683737852.621 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-10T16:57:32.621Z,1683737852.621 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-10T16:57:32.621Z,1683737852.621 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-10T16:57:32.622Z,1683737852.622 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-10T16:57:32.622Z,1683737852.622 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-10T16:57:32.622Z,1683737852.622 [BuoyancyServo](INFO): Powering down
2023-05-10T16:57:32.637Z,1683737852.637 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-10T16:57:32.637Z,1683737852.637 [ElevatorServo](INFO): Powering down
2023-05-10T16:57:32.638Z,1683737852.638 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-10T16:57:32.638Z,1683737852.638 [MassServo](INFO): Powering down
2023-05-10T16:57:32.639Z,1683737852.639 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-10T16:57:32.639Z,1683737852.639 [RudderServo](INFO): Powering down
2023-05-10T16:57:32.639Z,1683737852.639 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-10T16:57:32.640Z,1683737852.640 [ThrusterHE](INFO): Powering down
2023-05-10T16:57:32.640Z,1683737852.640 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-10T16:57:32.641Z,1683737852.641 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-10T16:57:32.641Z,1683737852.641 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-10T16:57:32.641Z,1683737852.641 [CBIT](DEBUG): Powering off loads.
2023-05-10T16:57:32.652Z,1683737852.652 [CBIT](DEBUG): Disabling WDT.
2023-05-10T16:57:32.664Z,1683737852.664 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-10T16:57:32.666Z,1683737852.666 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.724Z,1683737852.724 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.729Z,1683737852.729 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.731Z,1683737852.731 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.736Z,1683737852.736 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.780Z,1683737852.780 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.825Z,1683737852.825 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.830Z,1683737852.830 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.863Z,1683737852.863 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T16:57:32.924Z,1683737852.924 [logger ThreadHandler](INFO): Thread cancelled.