2023-05-10T17:26:07.372Z,1683739567.372 [Supervisor](DEBUG): Initializing supervisor.
2023-05-10T17:26:07.377Z,1683739567.377 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-10T17:26:07.377Z,1683739567.377 [SyncHandler](INFO): Protected caller Thread ID is 4441
2023-05-10T17:26:07.378Z,1683739567.378 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-10T17:26:07.379Z,1683739567.379 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-10T17:26:07.379Z,1683739567.379 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4442
2023-05-10T17:26:07.384Z,1683739567.384 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-10T17:26:07.401Z,1683739567.401 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-10T17:26:07.402Z,1683739567.402 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-10T17:26:07.403Z,1683739567.403 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4443
2023-05-10T17:26:07.407Z,1683739567.407 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-10T17:26:07.408Z,1683739567.408 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-10T17:26:07.408Z,1683739567.408 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4444
2023-05-10T17:26:07.410Z,1683739567.410 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-10T17:26:07.411Z,1683739567.411 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-10T17:26:07.411Z,1683739567.411 [logger ThreadHandler](INFO): Protected caller Thread ID is 4445
2023-05-10T17:26:07.415Z,1683739567.415 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-10T17:26:07.415Z,1683739567.415 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-10T17:26:07.417Z,1683739567.417 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-10T17:26:07.865Z,1683739567.865 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-10T17:26:07.866Z,1683739567.866 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-10T17:26:08.071Z,1683739568.071 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-10T17:26:08.072Z,1683739568.072 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-10T17:26:08.150Z,1683739568.150 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-10T17:26:08.359Z,1683739568.359 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-10T17:26:08.360Z,1683739568.360 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-10T17:26:08.437Z,1683739568.437 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-10T17:26:08.530Z,1683739568.530 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-10T17:26:08.531Z,1683739568.531 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-10T17:26:08.855Z,1683739568.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-10T17:26:08.855Z,1683739568.855 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-10T17:26:08.983Z,1683739568.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-10T17:26:08.983Z,1683739568.983 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-10T17:26:09.464Z,1683739569.464 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-10T17:26:09.465Z,1683739569.465 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-10T17:26:09.640Z,1683739569.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-10T17:26:09.641Z,1683739569.641 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-10T17:26:10.022Z,1683739570.022 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-10T17:26:10.023Z,1683739570.023 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-10T17:26:10.293Z,1683739570.293 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-10T17:26:10.294Z,1683739570.294 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-10T17:26:10.400Z,1683739570.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-10T17:26:10.401Z,1683739570.401 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-10T17:26:11.161Z,1683739571.161 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-10T17:26:11.162Z,1683739571.162 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-10T17:26:11.553Z,1683739571.553 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-10T17:26:11.553Z,1683739571.553 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-10T17:26:11.961Z,1683739571.961 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-10T17:26:11.963Z,1683739571.963 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-05-10T17:26:11.964Z,1683739571.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-05-10T17:26:12.393Z,1683739572.393 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-05-10T17:26:12.680Z,1683739572.680 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-05-10T17:26:12.939Z,1683739572.939 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-05-10T17:26:13.227Z,1683739573.227 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-05-10T17:26:13.487Z,1683739573.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-10T17:26:13.487Z,1683739573.487 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-05-10T17:26:13.588Z,1683739573.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-05-10T17:26:13.697Z,1683739573.697 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-05-10T17:26:13.807Z,1683739573.807 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-05-10T17:26:13.950Z,1683739573.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-05-10T17:26:14.047Z,1683739574.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-05-10T17:26:14.140Z,1683739574.140 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-05-10T17:26:14.140Z,1683739574.140 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-10T17:26:14.152Z,1683739574.152 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-10T17:26:14.163Z,1683739574.163 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-10T17:26:14.164Z,1683739574.164 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-10T17:26:14.264Z,1683739574.264 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-10T17:26:14.264Z,1683739574.264 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-10T17:26:14.314Z,1683739574.314 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-10T17:26:14.373Z,1683739574.373 [VerticalControl] Loaded
2023-05-10T17:26:14.373Z,1683739574.373 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-10T17:26:14.376Z,1683739574.376 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-10T17:26:14.416Z,1683739574.416 [HorizontalControl] Loaded
2023-05-10T17:26:14.417Z,1683739574.417 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-10T17:26:14.419Z,1683739574.419 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-10T17:26:14.422Z,1683739574.422 [SpeedControl] Loaded
2023-05-10T17:26:14.422Z,1683739574.422 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-10T17:26:14.425Z,1683739574.425 [LoopControl](DEBUG): Construct LoopControl.
2023-05-10T17:26:14.425Z,1683739574.425 [LoopControl] Loaded
2023-05-10T17:26:14.426Z,1683739574.426 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-10T17:26:14.426Z,1683739574.426 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-10T17:26:14.426Z,1683739574.426 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-10T17:26:14.580Z,1683739574.580 [BuoyancyServo] Loaded
2023-05-10T17:26:14.580Z,1683739574.580 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-10T17:26:14.600Z,1683739574.600 [ElevatorServo] Loaded
2023-05-10T17:26:14.600Z,1683739574.600 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-10T17:26:14.619Z,1683739574.619 [MassServo] Loaded
2023-05-10T17:26:14.619Z,1683739574.619 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-10T17:26:14.637Z,1683739574.637 [RudderServo] Loaded
2023-05-10T17:26:14.638Z,1683739574.638 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-10T17:26:14.652Z,1683739574.652 [ThrusterHE] Loaded
2023-05-10T17:26:14.652Z,1683739574.652 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-10T17:26:14.653Z,1683739574.653 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-10T17:26:14.653Z,1683739574.653 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-10T17:26:14.703Z,1683739574.703 [DepthRateCalculator] Loaded
2023-05-10T17:26:14.704Z,1683739574.704 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-10T17:26:14.709Z,1683739574.709 [PitchRateCalculator] Loaded
2023-05-10T17:26:14.709Z,1683739574.709 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-10T17:26:14.718Z,1683739574.718 [SpeedCalculator] Loaded
2023-05-10T17:26:14.718Z,1683739574.718 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-10T17:26:14.723Z,1683739574.723 [YawRateCalculator] Loaded
2023-05-10T17:26:14.723Z,1683739574.723 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-10T17:26:14.741Z,1683739574.741 [ElevatorOffsetCalculator] Loaded
2023-05-10T17:26:14.741Z,1683739574.741 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-10T17:26:14.742Z,1683739574.742 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-10T17:26:14.742Z,1683739574.742 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-10T17:26:14.854Z,1683739574.854 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-10T17:26:14.855Z,1683739574.855 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-10T17:26:14.868Z,1683739574.868 [NavChart] Loaded
2023-05-10T17:26:14.868Z,1683739574.868 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-10T17:26:14.874Z,1683739574.874 [UniversalFixResidualReporter] Loaded
2023-05-10T17:26:14.874Z,1683739574.874 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-10T17:26:14.874Z,1683739574.874 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-10T17:26:14.875Z,1683739574.875 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-10T17:26:15.305Z,1683739575.305 [AHRS_M2] Loaded
2023-05-10T17:26:15.305Z,1683739575.305 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-10T17:26:15.341Z,1683739575.341 [BackseatComponent] Loaded
2023-05-10T17:26:15.341Z,1683739575.341 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-10T17:26:15.342Z,1683739575.342 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E74E0
2023-05-10T17:26:15.343Z,1683739575.343 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 4527
2023-05-10T17:26:15.345Z,1683739575.345 [LcmUniversalReporter] Loaded
2023-05-10T17:26:15.346Z,1683739575.346 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-10T17:26:16.176Z,1683739576.176 [BPC1] Loaded
2023-05-10T17:26:16.177Z,1683739576.177 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-10T17:26:16.250Z,1683739576.250 [DataOverHttps] Loaded
2023-05-10T17:26:16.250Z,1683739576.250 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-10T17:26:16.251Z,1683739576.251 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409174E0
2023-05-10T17:26:16.252Z,1683739576.252 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4528
2023-05-10T17:26:16.273Z,1683739576.273 [Depth_Keller] Loaded
2023-05-10T17:26:16.273Z,1683739576.273 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-10T17:26:16.335Z,1683739576.335 [NAL9602] Loaded
2023-05-10T17:26:16.335Z,1683739576.335 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-10T17:26:16.365Z,1683739576.365 [Onboard] Loaded
2023-05-10T17:26:16.365Z,1683739576.365 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-10T17:26:16.366Z,1683739576.366 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409474E0
2023-05-10T17:26:16.366Z,1683739576.366 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4529
2023-05-10T17:26:16.379Z,1683739576.379 [Power24vConverter] Loaded
2023-05-10T17:26:16.379Z,1683739576.379 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-10T17:26:16.393Z,1683739576.393 [Radio_Surface] Loaded
2023-05-10T17:26:16.393Z,1683739576.393 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-10T17:26:16.394Z,1683739576.394 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409774E0
2023-05-10T17:26:16.394Z,1683739576.394 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4530
2023-05-10T17:26:16.481Z,1683739576.481 [DATMMP] Loaded
2023-05-10T17:26:16.481Z,1683739576.481 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2023-05-10T17:26:16.482Z,1683739576.482 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409A84E0
2023-05-10T17:26:16.482Z,1683739576.482 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 4531
2023-05-10T17:26:16.483Z,1683739576.483 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-10T17:26:16.483Z,1683739576.483 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-10T17:26:16.557Z,1683739576.557 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-10T17:26:16.558Z,1683739576.558 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-10T17:26:16.999Z,1683739576.999 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-10T17:26:16.000Z,1683739577.000 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-10T17:26:17.339Z,1683739577.339 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-10T17:26:17.340Z,1683739577.340 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-10T17:26:17.508Z,1683739577.508 [CTD_Seabird] Loaded
2023-05-10T17:26:17.509Z,1683739577.509 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-10T17:26:17.510Z,1683739577.510 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ADE4E0
2023-05-10T17:26:17.510Z,1683739577.510 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4532
2023-05-10T17:26:17.543Z,1683739577.543 [ESPComponent] Loaded
2023-05-10T17:26:17.543Z,1683739577.543 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-10T17:26:17.563Z,1683739577.563 [PAR_Licor] Loaded
2023-05-10T17:26:17.563Z,1683739577.563 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-10T17:26:17.594Z,1683739577.594 [WetLabsBB2FL] Loaded
2023-05-10T17:26:17.594Z,1683739577.594 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-10T17:26:17.595Z,1683739577.595 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0
2023-05-10T17:26:17.596Z,1683739577.596 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4533
2023-05-10T17:26:17.596Z,1683739577.596 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-10T17:26:17.597Z,1683739577.597 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-10T17:26:17.903Z,1683739577.903 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-10T17:26:17.904Z,1683739577.904 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-10T17:26:18.044Z,1683739578.044 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-10T17:26:18.054Z,1683739578.054 [SBIT] Loaded
2023-05-10T17:26:18.054Z,1683739578.054 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-10T17:26:18.057Z,1683739578.057 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-10T17:26:18.069Z,1683739578.069 [IBIT] Loaded
2023-05-10T17:26:18.070Z,1683739578.070 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-10T17:26:18.076Z,1683739578.076 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-10T17:26:18.180Z,1683739578.180 [CBIT] Loaded
2023-05-10T17:26:18.181Z,1683739578.181 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-10T17:26:18.181Z,1683739578.181 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-10T17:26:18.187Z,1683739578.187 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-10T17:26:18.190Z,1683739578.190 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-10T17:26:18.201Z,1683739578.201 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-10T17:26:18.202Z,1683739578.202 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BF14E0
2023-05-10T17:26:18.202Z,1683739578.202 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4534
2023-05-10T17:26:18.207Z,1683739578.207 [Supervisor](INFO): Main Thread ID is 4122
2023-05-10T17:26:18.207Z,1683739578.207 [Supervisor](DEBUG): Running supervisor.
2023-05-10T17:26:18.207Z,1683739578.207 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4535
2023-05-10T17:26:18.208Z,1683739578.208 [CommandExec](INFO): Initializing the command executive.
2023-05-10T17:26:18.209Z,1683739578.209 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4536
2023-05-10T17:26:18.211Z,1683739578.211 [controlThread ThreadHandler](INFO): Handler Thread ID is 4537
2023-05-10T17:26:18.212Z,1683739578.212 [controlThread](DEBUG): Initializing ControlThread
2023-05-10T17:26:18.213Z,1683739578.213 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-10T17:26:18.214Z,1683739578.214 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-10T17:26:18.215Z,1683739578.215 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-10T17:26:18.216Z,1683739578.216 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-10T17:26:18.217Z,1683739578.217 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-10T17:26:18.217Z,1683739578.217 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-10T17:26:18.218Z,1683739578.218 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-10T17:26:18.218Z,1683739578.218 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-10T17:26:18.219Z,1683739578.219 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-10T17:26:18.220Z,1683739578.220 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-10T17:26:18.220Z,1683739578.220 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-10T17:26:18.229Z,1683739578.229 [SBIT](INFO): Initialize SBIT Component.
2023-05-10T17:26:18.229Z,1683739578.229 [SBIT](IMPORTANT): git: 2023-01-24-38-g3a865bb8c
2023-05-10T17:26:18.229Z,1683739578.229 [SBIT](INFO): git hash: 3a865bb8cac9b788bcd3aa40e502ce5ce0bbf34f
2023-05-10T17:26:18.230Z,1683739578.230 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-10T17:26:18.231Z,1683739578.231 [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-10T17:26:18.232Z,1683739578.232 [SBIT](INFO): Beginning SBIT in 81.000000 seconds.
2023-05-10T17:26:18.233Z,1683739578.233 [IBIT](INFO): Initialize IBIT Component.
2023-05-10T17:26:18.234Z,1683739578.234 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-10T17:26:18.234Z,1683739578.234 [logger ThreadHandler](INFO): Handler Thread ID is 4538
2023-05-10T17:26:18.245Z,1683739578.245 [CBIT](DEBUG): Initialized mux pins.
2023-05-10T17:26:18.245Z,1683739578.245 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-10T17:26:18.253Z,1683739578.253 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 4539
2023-05-10T17:26:18.265Z,1683739578.265 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4540
2023-05-10T17:26:18.266Z,1683739578.266 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-10T17:26:18.269Z,1683739578.269 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-10T17:26:18.269Z,1683739578.269 [CBIT](DEBUG): Initializing heartbeat.
2023-05-10T17:26:18.277Z,1683739578.277 [Onboard ThreadHandler](INFO): Handler Thread ID is 4541
2023-05-10T17:26:18.295Z,1683739578.295 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4542
2023-05-10T17:26:18.313Z,1683739578.313 [DATMMP ThreadHandler](INFO): Handler Thread ID is 4543
2023-05-10T17:26:18.314Z,1683739578.314 [DATMMP](INFO): Start
2023-05-10T17:26:18.314Z,1683739578.314 [DATMMP](INFO): Powering up
2023-05-10T17:26:18.314Z,1683739578.314 [DATMMP](DEBUG): Initializing DATMMP.
2023-05-10T17:26:18.318Z,1683739578.318 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4545
2023-05-10T17:26:18.318Z,1683739578.318 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-10T17:26:18.322Z,1683739578.322 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4547
2023-05-10T17:26:18.325Z,1683739578.325 [WetLabsBB2FL](INFO): Powering up
2023-05-10T17:26:18.326Z,1683739578.326 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4549
2023-05-10T17:26:18.329Z,1683739578.329 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-10T17:26:18.329Z,1683739578.329 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-10T17:26:18.330Z,1683739578.330 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-10T17:26:18.330Z,1683739578.330 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-10T17:26:18.330Z,1683739578.330 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-10T17:26:18.330Z,1683739578.330 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-10T17:26:18.330Z,1683739578.330 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-10T17:26:18.330Z,1683739578.330 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-10T17:26:18.341Z,1683739578.341 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-10T17:26:18.341Z,1683739578.341 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-10T17:26:18.377Z,1683739578.377 [CBIT](DEBUG): Backplane powered.
2023-05-10T17:26:18.378Z,1683739578.378 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-10T17:26:18.390Z,1683739578.390 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T17:26:18.409Z,1683739578.409 [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-10T17:26:18.410Z,1683739578.410 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-10T17:26:18.486Z,1683739578.486 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-10T17:26:18.487Z,1683739578.487 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-10T17:26:18.505Z,1683739578.505 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T17:26:18.542Z,1683739578.542 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-10T17:26:18.565Z,1683739578.565 [DATMMP](INFO): Starting
2023-05-10T17:26:18.573Z,1683739578.573 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-10T17:26:18.579Z,1683739578.579 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-10T17:26:18.598Z,1683739578.598 [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-10T17:26:18.603Z,1683739578.603 [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-10T17:26:18.621Z,1683739578.621 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-10T17:26:18.695Z,1683739578.695 [Power24vConverter](INFO): Powering up.
2023-05-10T17:26:18.701Z,1683739578.701 [Radio_Surface](INFO): Powering up
2023-05-10T17:26:18.745Z,1683739578.745 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-10T17:26:18.753Z,1683739578.753 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-10T17:26:18.754Z,1683739578.754 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-10T17:26:18.769Z,1683739578.769 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-10T17:26:18.770Z,1683739578.770 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-10T17:26:18.777Z,1683739578.777 [MassServo](DEBUG): Initializing MassServo.
2023-05-10T17:26:18.778Z,1683739578.778 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-10T17:26:18.785Z,1683739578.785 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-10T17:26:18.786Z,1683739578.786 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-10T17:26:18.793Z,1683739578.793 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-10T17:26:18.817Z,1683739578.817 [DATMMP](INFO): Starting
2023-05-10T17:26:19.069Z,1683739579.069 [DATMMP](INFO): Starting
2023-05-10T17:26:19.321Z,1683739579.321 [DATMMP](INFO): Starting
2023-05-10T17:26:19.573Z,1683739579.573 [DATMMP](INFO): Starting
2023-05-10T17:26:19.765Z,1683739579.765 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2023-05-10T17:26:19.765Z,1683739579.765 [RudderServo](FAULT): Rudder failed to initialize
2023-05-10T17:26:19.765Z,1683739579.765 [RudderServo] Communications Fault, FailCount= 1
2023-05-10T17:26:19.765Z,1683739579.765 [RudderServo](ERROR): Communications Fault
2023-05-10T17:26:19.769Z,1683739579.769 [CBIT](ERROR): Communications Fault in component: RudderServo
2023-05-10T17:26:19.825Z,1683739579.825 [DATMMP](INFO): Starting
2023-05-10T17:26:19.954Z,1683739579.954 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-10T17:26:19.954Z,1683739579.954 [RudderServo](INFO): Powering down
2023-05-10T17:26:20.077Z,1683739580.077 [DATMMP](INFO): Starting
2023-05-10T17:26:20.329Z,1683739580.329 [DATMMP](INFO): Starting
2023-05-10T17:26:20.433Z,1683739580.433 [WetLabsBB2FL](INFO): Powering down
2023-05-10T17:26:20.581Z,1683739580.581 [DATMMP](INFO): Starting
2023-05-10T17:26:20.642Z,1683739580.642 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-10T17:26:20.761Z,1683739580.761 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-10T17:26:20.765Z,1683739580.765 [CBIT](INFO): Clearing failed state for component RudderServo
2023-05-10T17:26:20.766Z,1683739580.766 [RudderServo] No Fault, FailCount= 1
2023-05-10T17:26:20.833Z,1683739580.833 [DATMMP](INFO): Starting
2023-05-10T17:26:21.085Z,1683739581.085 [DATMMP](INFO): Starting
2023-05-10T17:26:21.337Z,1683739581.337 [DATMMP](INFO): Starting
2023-05-10T17:26:21.589Z,1683739581.589 [DATMMP](INFO): Starting
2023-05-10T17:26:21.841Z,1683739581.841 [DATMMP](INFO): Starting
2023-05-10T17:26:22.093Z,1683739582.093 [DATMMP](INFO): Starting
2023-05-10T17:26:22.346Z,1683739582.346 [DATMMP](INFO): Starting
2023-05-10T17:26:22.597Z,1683739582.597 [DATMMP](INFO): Starting
2023-05-10T17:26:22.849Z,1683739582.849 [DATMMP](INFO): Starting
2023-05-10T17:26:23.101Z,1683739583.101 [DATMMP](INFO): Starting
2023-05-10T17:26:23.353Z,1683739583.353 [DATMMP](INFO): Starting
2023-05-10T17:26:23.605Z,1683739583.605 [DATMMP](INFO): Starting
2023-05-10T17:26:23.857Z,1683739583.857 [DATMMP](INFO): Starting
2023-05-10T17:26:24.109Z,1683739584.109 [DATMMP](INFO): Starting
2023-05-10T17:26:24.361Z,1683739584.361 [DATMMP](INFO): Starting
2023-05-10T17:26:24.613Z,1683739584.613 [DATMMP](INFO): Starting
2023-05-10T17:26:24.645Z,1683739584.645 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-10T17:26:24.865Z,1683739584.865 [DATMMP](INFO): Starting
2023-05-10T17:26:25.117Z,1683739585.117 [DATMMP](INFO): Starting
2023-05-10T17:26:25.369Z,1683739585.369 [DATMMP](INFO): Starting
2023-05-10T17:26:25.621Z,1683739585.621 [DATMMP](INFO): Starting
2023-05-10T17:26:25.873Z,1683739585.873 [DATMMP](INFO): Starting
2023-05-10T17:26:26.125Z,1683739586.125 [DATMMP](INFO): Starting
2023-05-10T17:26:26.377Z,1683739586.377 [DATMMP](INFO): Starting
2023-05-10T17:26:26.629Z,1683739586.629 [DATMMP](INFO): Starting
2023-05-10T17:26:26.881Z,1683739586.881 [DATMMP](INFO): Starting
2023-05-10T17:26:27.133Z,1683739587.133 [DATMMP](INFO): Starting
2023-05-10T17:26:27.385Z,1683739587.385 [DATMMP](INFO): Starting
2023-05-10T17:26:27.637Z,1683739587.637 [DATMMP](INFO): Starting
2023-05-10T17:26:27.889Z,1683739587.889 [DATMMP](INFO): Starting
2023-05-10T17:26:28.141Z,1683739588.141 [DATMMP](INFO): Starting
2023-05-10T17:26:28.393Z,1683739588.393 [DATMMP](INFO): Starting
2023-05-10T17:26:28.645Z,1683739588.645 [DATMMP](INFO): Starting
2023-05-10T17:26:28.897Z,1683739588.897 [DATMMP](INFO): Starting
2023-05-10T17:26:29.149Z,1683739589.149 [DATMMP](INFO): Starting
2023-05-10T17:26:29.401Z,1683739589.401 [DATMMP](INFO): Starting
2023-05-10T17:26:29.653Z,1683739589.653 [DATMMP](INFO): Starting
2023-05-10T17:26:29.905Z,1683739589.905 [DATMMP](INFO): Starting
2023-05-10T17:26:30.157Z,1683739590.157 [DATMMP](INFO): Starting
2023-05-10T17:26:30.409Z,1683739590.409 [DATMMP](INFO): Starting
2023-05-10T17:26:30.409Z,1683739590.409 [DATMMP](INFO): DAT read: 

2023-05-10T17:26:30.410Z,1683739590.410 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-10T17:26:30.661Z,1683739590.661 [DATMMP](INFO): Starting
2023-05-10T17:26:30.913Z,1683739590.913 [DATMMP](INFO): Starting
2023-05-10T17:26:31.165Z,1683739591.165 [DATMMP](INFO): Starting
2023-05-10T17:26:31.417Z,1683739591.417 [DATMMP](INFO): Starting
2023-05-10T17:26:31.669Z,1683739591.669 [DATMMP](INFO): Starting
2023-05-10T17:26:31.921Z,1683739591.921 [DATMMP](INFO): Starting
2023-05-10T17:26:32.173Z,1683739592.173 [DATMMP](INFO): Starting
2023-05-10T17:26:32.173Z,1683739592.173 [DATMMP](INFO): DAT read: MF Frequency Band

2023-05-10T17:26:32.174Z,1683739592.174 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-10T17:26:32.175Z,1683739592.175 [DATMMP](INFO): DAT read: Apr 10 2000 17:26:26 

2023-05-10T17:26:32.425Z,1683739592.425 [DATMMP](INFO): Starting
2023-05-10T17:26:32.677Z,1683739592.677 [DATMMP](INFO): Starting
2023-05-10T17:26:32.929Z,1683739592.929 [DATMMP](INFO): Starting
2023-05-10T17:26:33.181Z,1683739593.181 [DATMMP](INFO): Starting
2023-05-10T17:26:33.433Z,1683739593.433 [DATMMP](INFO): Starting
2023-05-10T17:26:33.433Z,1683739593.433 [DATMMP](INFO): DAT read: Features enabled [Bearing]

2023-05-10T17:26:33.435Z,1683739593.435 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T17:26:33.435Z,1683739593.435 [DATMMP](INFO): commRate: 800
2023-05-10T17:26:33.685Z,1683739593.685 [DATMMP](INFO): Starting
2023-05-10T17:26:33.937Z,1683739593.937 [DATMMP](INFO): Starting
2023-05-10T17:26:34.189Z,1683739594.189 [DATMMP](INFO): Starting
2023-05-10T17:26:34.441Z,1683739594.441 [DATMMP](INFO): Starting
2023-05-10T17:26:34.693Z,1683739594.693 [DATMMP](INFO): Starting
2023-05-10T17:26:34.945Z,1683739594.945 [DATMMP](INFO): Starting
2023-05-10T17:26:35.197Z,1683739595.197 [DATMMP](INFO): Starting
2023-05-10T17:26:35.449Z,1683739595.449 [DATMMP](INFO): Starting
2023-05-10T17:26:35.501Z,1683739595.501 [DATMMP](INFO): entering command mode
2023-05-10T17:26:35.701Z,1683739595.701 [DATMMP](INFO): Starting
2023-05-10T17:26:35.701Z,1683739595.701 [DATMMP](INFO): DAT read: 

2023-05-10T17:26:35.702Z,1683739595.702 [DATMMP](INFO): DAT read: user:1>

2023-05-10T17:26:35.702Z,1683739595.702 [DATMMP](DEBUG): read user prompt 1: user:1>

2023-05-10T17:26:35.702Z,1683739595.702 [DATMMP](INFO): entering MMP mode
2023-05-10T17:26:35.953Z,1683739595.953 [DATMMP](INFO): Starting
2023-05-10T17:26:35.953Z,1683739595.953 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:26:35.955Z,1683739595.955 [DATMMP](INFO): status rx: 	 x1
2023-05-10T17:26:35.956Z,1683739595.956 [DATMMP](INFO): MMP status: 1: started
2023-05-10T17:26:35.956Z,1683739595.956 [DATMMP](INFO): Received message type: status
2023-05-10T17:26:35.956Z,1683739595.956 [DATMMP](INFO): Handled
2023-05-10T17:26:36.205Z,1683739596.205 [DATMMP](INFO): Starting
2023-05-10T17:26:36.206Z,1683739596.206 [DATMMP](INFO): Sent Tx Power Config 8
2023-05-10T17:26:36.207Z,1683739596.207 [DATMMP](INFO): Setting local address: 5
2023-05-10T17:26:36.208Z,1683739596.208 [DATMMP](INFO): Setting time to: 17:26:36 And date to:5/10/2023
2023-05-10T17:26:36.457Z,1683739596.457 [DATMMP](INFO): Starting
2023-05-10T17:26:36.457Z,1683739596.457 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:26:36.458Z,1683739596.458 [DATMMP](INFO): mdmpower rx: 	 x8	 x0	 x5	 x0
2023-05-10T17:26:36.458Z,1683739596.458 [DATMMP](INFO): Received message type: mdmpower
2023-05-10T17:26:36.458Z,1683739596.458 [DATMMP](INFO): Handled
2023-05-10T17:26:36.709Z,1683739596.709 [DATMMP](INFO): Starting
2023-05-10T17:26:36.711Z,1683739596.711 [DATMMP](INFO): GSXN notify for xid: 10
2023-05-10T17:26:36.712Z,1683739596.712 [DATMMP](INFO): sreg_txpower rx: 	 x8
2023-05-10T17:26:36.712Z,1683739596.712 [DATMMP](INFO): Received message type: sreg_txpower
2023-05-10T17:26:36.713Z,1683739596.713 [DATMMP](INFO): Match for : sreg_txpower
2023-05-10T17:26:36.713Z,1683739596.713 [DATMMP](INFO): ACK
2023-05-10T17:26:36.961Z,1683739596.961 [DATMMP](INFO): Starting
2023-05-10T17:26:36.962Z,1683739596.962 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:26:36.962Z,1683739596.962 [DATMMP](INFO): mdmlocal rx: 	 x5	 x0	 x0	 x0
2023-05-10T17:26:36.963Z,1683739596.963 [DATMMP](INFO): Received message type: mdmlocal
2023-05-10T17:26:36.963Z,1683739596.963 [DATMMP](INFO): Handled
2023-05-10T17:26:37.213Z,1683739597.213 [DATMMP](INFO): Starting
2023-05-10T17:26:37.213Z,1683739597.213 [DATMMP](INFO): GSXN notify for xid: 11
2023-05-10T17:26:37.214Z,1683739597.214 [DATMMP](INFO): sreg_locaddr rx: 	 x5
2023-05-10T17:26:37.214Z,1683739597.214 [DATMMP](INFO): Received message type: sreg_locaddr
2023-05-10T17:26:37.214Z,1683739597.214 [DATMMP](INFO): Match for : sreg_locaddr
2023-05-10T17:26:37.214Z,1683739597.214 [DATMMP](INFO): ACK
2023-05-10T17:26:37.465Z,1683739597.465 [DATMMP](INFO): Starting
2023-05-10T17:26:37.465Z,1683739597.465 [DATMMP](INFO): GSXN notify for xid: 12
2023-05-10T17:26:37.466Z,1683739597.466 [DATMMP](INFO): timedate rx: 	 x0	 x11	 x1A	 x24	 x4	 xA	 x7B	 x0
2023-05-10T17:26:37.466Z,1683739597.466 [DATMMP](INFO): Received message type: timedate
2023-05-10T17:26:37.467Z,1683739597.467 [DATMMP](INFO): Match for : timedate
2023-05-10T17:26:37.467Z,1683739597.467 [DATMMP](INFO): ACK
2023-05-10T17:26:37.717Z,1683739597.717 [DATMMP](INFO): Starting
2023-05-10T17:26:37.717Z,1683739597.717 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:26:37.718Z,1683739597.718 [DATMMP](INFO): sys_verb rx: 	 x0	 x0	 x0	 x0
2023-05-10T17:26:37.718Z,1683739597.718 [DATMMP](INFO): Received message type: sys_verb
2023-05-10T17:26:37.718Z,1683739597.718 [DATMMP](INFO): Handled
2023-05-10T17:26:37.969Z,1683739597.969 [DATMMP](INFO): Starting
2023-05-10T17:26:37.969Z,1683739597.969 [DATMMP](INFO): GSXN notify for xid: 13
2023-05-10T17:26:37.970Z,1683739597.970 [DATMMP](INFO): sreg_verbosity rx: 	 x0
2023-05-10T17:26:37.970Z,1683739597.970 [DATMMP](INFO): Received message type: sreg_verbosity
2023-05-10T17:26:37.970Z,1683739597.970 [DATMMP](INFO): Match for : sreg_verbosity
2023-05-10T17:26:37.970Z,1683739597.970 [DATMMP](INFO): ACK
2023-05-10T17:26:38.221Z,1683739598.221 [DATMMP](INFO): Starting
2023-05-10T17:26:38.221Z,1683739598.221 [DATMMP](INFO): GSXN notify for xid: 14
2023-05-10T17:26:38.222Z,1683739598.222 [DATMMP](INFO): version rx: 	 x2	 x5
2023-05-10T17:26:38.222Z,1683739598.222 [DATMMP](INFO): DatMMPVersion: 2.5
2023-05-10T17:26:38.222Z,1683739598.222 [DATMMP](INFO): Received message type: version
2023-05-10T17:26:38.222Z,1683739598.222 [DATMMP](INFO): Match for : version
2023-05-10T17:26:38.223Z,1683739598.223 [DATMMP](INFO): ACK
2023-05-10T17:26:38.223Z,1683739598.223 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-05-10T17:26:46.538Z,1683739606.538 [NAL9602](INFO): Powering up NAL9602
2023-05-10T17:26:52.849Z,1683739612.849 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:26:52.850Z,1683739612.850 [DATMMP](INFO): timesync rx: 	 x0	 x1	 x1	 x0
2023-05-10T17:26:52.850Z,1683739612.850 [DATMMP](INFO): Received message type: timesync
2023-05-10T17:26:52.850Z,1683739612.850 [DATMMP](INFO): Handled
2023-05-10T17:26:57.451Z,1683739617.451 [NAL9602](INFO): NAL9602 initialized
2023-05-10T17:27:02.705Z,1683739622.705 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:27:02.706Z,1683739622.706 [DATMMP](INFO): timesync rx: 	 x1	 x0	 x1	 x0
2023-05-10T17:27:02.706Z,1683739622.706 [DATMMP](INFO): Received message type: timesync
2023-05-10T17:27:02.706Z,1683739622.706 [DATMMP](INFO): Handled
2023-05-10T17:27:39.916Z,1683739659.916 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-10T17:27:39.921Z,1683739659.921 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-10T17:27:50.838Z,1683739670.838 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.010055
CHAN A1 (24V): -0.007571
CHAN A2 (12V): -0.004484
CHAN A3 (5V): -0.003017
CHAN B0 (3.3V): -0.001102
CHAN B1 (3.15aV): -0.001259
CHAN B2 (3.15bV): -0.001209
CHAN B3 (GND): -0.000091
OPEN: 0.004044
Full Scale: +/- 1 mA
2023-05-10T17:28:34.018Z,1683739714.018 [SBIT](IMPORTANT): SBIT PASSED
2023-05-10T17:28:34.018Z,1683739714.018 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-10T17:28:34.020Z,1683739714.020 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-05-10T17:28:34.020Z,1683739714.020 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2023-05-10T17:28:34.021Z,1683739714.021 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2023-05-10T17:28:34.021Z,1683739714.021 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2023-05-10T17:28:34.021Z,1683739714.021 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-05-10T17:28:34.023Z,1683739714.023 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-05-10T17:28:34.023Z,1683739714.023 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-10T17:28:34.024Z,1683739714.024 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-10T17:28:34.024Z,1683739714.024 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2023-05-10T17:28:34.024Z,1683739714.024 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=184.896478 cubic_centimeter;

2023-05-10T17:28:34.024Z,1683739714.024 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-05-10T17:28:34.024Z,1683739714.024 [SBIT](IMPORTANT): VerticalControl.massDefault=15.484465 millimeter;

2023-05-10T17:28:34.424Z,1683739714.424 [MissionManager](IMPORTANT): Started mission Startup
2023-05-10T17:28:34.424Z,1683739714.424 [Startup] Running Loop=1
2023-05-10T17:28:34.424Z,1683739714.424 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-10T17:28:34.424Z,1683739714.424 [Startup:A.GoToSurface] Running Loop=1
2023-05-10T17:28:34.424Z,1683739714.424 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T17:28:34.425Z,1683739714.425 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T17:28:34.425Z,1683739714.425 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T17:28:34.426Z,1683739714.426 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T17:28:34.426Z,1683739714.426 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T17:28:34.426Z,1683739714.426 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T17:28:34.428Z,1683739714.428 [Startup:StartupSatComms] Running Loop=1
2023-05-10T17:28:34.428Z,1683739714.428 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-10T17:28:34.428Z,1683739714.428 [Startup:StartupSatComms:A] Running Loop=1
2023-05-10T17:28:34.831Z,1683739714.831 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-10T17:28:46.099Z,1683739726.099 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004755
2023-05-10T17:28:46.126Z,1683739726.126 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:28:59.463Z,1683739739.463 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:29:12.795Z,1683739752.795 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:29:18.467Z,1683739758.467 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-05-10T17:29:18.467Z,1683739758.467 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-10T17:29:18.521Z,1683739758.521 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-10T17:29:18.887Z,1683739758.887 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-10T17:29:18.887Z,1683739758.887 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-05-10T17:29:26.128Z,1683739766.128 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:29:34.619Z,1683739774.619 [Startup:StartupSatComms:A](INFO): Timed out from 2023-05-10T17:28:34.4Z
2023-05-10T17:29:34.619Z,1683739774.619 [Startup:StartupSatComms:A] Stopped
2023-05-10T17:29:34.619Z,1683739774.619 [Startup:StartupSatComms:B] Running Loop=1
2023-05-10T17:29:35.042Z,1683739775.042 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T17:29:39.059Z,1683739779.059 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:29:41.848Z,1683739781.848 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230510T165733/Courier0010.lzma
2023-05-10T17:29:42.850Z,1683739782.850 [DataOverHttps](INFO): Moved sent file to Logs/20230510T165733/Courier0010.lzma.bak
2023-05-10T17:29:42.851Z,1683739782.851 [DataOverHttps](INFO): SBD MOMSN=18286562
2023-05-10T17:29:51.995Z,1683739791.995 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:29:58.260Z,1683739798.260 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230510T172607/Courier0000.lzma
2023-05-10T17:29:59.270Z,1683739799.270 [DataOverHttps](INFO): Moved sent file to Logs/20230510T172607/Courier0000.lzma.bak
2023-05-10T17:29:59.271Z,1683739799.271 [DataOverHttps](INFO): SBD MOMSN=18286564
2023-05-10T17:30:05.314Z,1683739805.314 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:30:16.121Z,1683739816.121 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20230510T165733/Express0011.lzma
2023-05-10T17:30:17.122Z,1683739817.122 [DataOverHttps](INFO): Moved sent file to Logs/20230510T165733/Express0011.lzma.bak
2023-05-10T17:30:17.123Z,1683739817.123 [DataOverHttps](INFO): SBD MOMSN=18286567
2023-05-10T17:30:18.642Z,1683739818.642 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:30:31.975Z,1683739831.975 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:30:34.214Z,1683739834.214 [DataOverHttps](INFO): Sending 1014 bytes from file Logs/20230510T172607/Express0001.lzma
2023-05-10T17:30:34.814Z,1683739834.814 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-10T17:29:34.6Z
2023-05-10T17:30:34.814Z,1683739834.814 [Startup:StartupSatComms:B] Stopped
2023-05-10T17:30:34.814Z,1683739834.814 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-10T17:30:34.814Z,1683739834.814 [Startup:StartupSatComms] Stopped
2023-05-10T17:30:34.814Z,1683739834.814 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-10T17:30:34.815Z,1683739834.815 [Startup](INFO): Completed Startup
2023-05-10T17:30:34.815Z,1683739834.815 [MissionManager](INFO): Startup is completed.
2023-05-10T17:30:34.816Z,1683739834.816 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-10T17:30:34.816Z,1683739834.816 [Startup] Stopped
2023-05-10T17:30:34.816Z,1683739834.816 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-10T17:30:34.816Z,1683739834.816 [Startup:A.GoToSurface] Stopped
2023-05-10T17:30:34.816Z,1683739834.816 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T17:30:35.210Z,1683739835.210 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T17:30:35.211Z,1683739835.211 [Default] Running Loop=1
2023-05-10T17:30:35.211Z,1683739835.211 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T17:30:35.211Z,1683739835.211 [Default:B.GoToSurface] Running Loop=1
2023-05-10T17:30:35.211Z,1683739835.211 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T17:30:35.211Z,1683739835.211 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T17:30:35.211Z,1683739835.211 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T17:30:35.212Z,1683739835.212 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T17:30:35.212Z,1683739835.212 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T17:30:35.214Z,1683739835.214 [DataOverHttps](INFO): Moved sent file to Logs/20230510T172607/Express0001.lzma.bak
2023-05-10T17:30:35.214Z,1683739835.214 [DataOverHttps](INFO): SBD MOMSN=18286572
2023-05-10T17:30:35.234Z,1683739835.234 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T17:30:35.234Z,1683739835.234 [Default:A.Wait] Running Loop=1
2023-05-10T17:30:35.234Z,1683739835.234 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T17:30:45.311Z,1683739845.311 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:30:48.569Z,1683739848.569 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T17:30:48.569Z,1683739848.569 [Default:A.Wait] Stopped
2023-05-10T17:30:48.570Z,1683739848.570 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T17:30:48.981Z,1683739848.981 [Default:CheckIn] Running Loop=1
2023-05-10T17:30:48.982Z,1683739848.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T17:30:48.982Z,1683739848.982 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T17:30:49.371Z,1683739849.371 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-10T17:30:58.643Z,1683739858.643 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:31:12.379Z,1683739872.379 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-10T17:32:01.296Z,1683739921.296 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T17:32:19.492Z,1683739939.492 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-05-10T17:32:19.492Z,1683739939.492 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-10T17:32:19.519Z,1683739939.519 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-10T17:32:19.910Z,1683739939.910 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-10T17:32:19.910Z,1683739939.910 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-05-10T17:33:44.721Z,1683740024.721 [BPC1](INFO): Calculating totals. Valid battery stick count: 52. Valid reserve battery stick count: 5.
2023-05-10T17:33:44.724Z,1683740024.724 [BPC1](INFO): Received data from all battery sticks.
2023-05-10T17:35:20.498Z,1683740120.498 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-05-10T17:35:20.498Z,1683740120.498 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-10T17:35:20.509Z,1683740120.509 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-10T17:35:20.897Z,1683740120.897 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-10T17:35:20.897Z,1683740120.897 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-05-10T17:35:49.156Z,1683740149.156 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T17:30:48.0Z
2023-05-10T17:35:49.156Z,1683740149.156 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T17:35:49.157Z,1683740149.157 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T17:35:49.586Z,1683740149.586 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T17:35:56.724Z,1683740156.724 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230510T172607/Courier0004.lzma
2023-05-10T17:35:57.726Z,1683740157.726 [DataOverHttps](INFO): Moved sent file to Logs/20230510T172607/Courier0004.lzma.bak
2023-05-10T17:35:57.726Z,1683740157.726 [DataOverHttps](INFO): SBD MOMSN=18286604
2023-05-10T17:36:14.688Z,1683740174.688 [DataOverHttps](INFO): Sending 198 bytes from file Logs/20230510T172607/Express0005.lzma
2023-05-10T17:36:15.690Z,1683740175.690 [DataOverHttps](INFO): Moved sent file to Logs/20230510T172607/Express0005.lzma.bak
2023-05-10T17:36:15.691Z,1683740175.691 [DataOverHttps](INFO): SBD MOMSN=18286606
2023-05-10T17:36:18.263Z,1683740178.263 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T17:36:18.263Z,1683740178.263 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T17:36:18.263Z,1683740178.263 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T17:36:58.642Z,1683740218.642 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-10T17:36:58.642Z,1683740218.642 [NAL9602] Data Fault, FailCount= 1
2023-05-10T17:36:58.642Z,1683740218.642 [NAL9602](ERROR): Data Fault
2023-05-10T17:36:58.660Z,1683740218.660 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-10T17:36:59.050Z,1683740219.050 [NAL9602](INFO): Powering down
2023-05-10T17:36:59.870Z,1683740219.870 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-10T17:36:59.870Z,1683740219.870 [NAL9602] No Fault, FailCount= 1
2023-05-10T17:37:29.346Z,1683740249.346 [NAL9602](INFO): Powering up NAL9602
2023-05-10T17:37:40.250Z,1683740260.250 [NAL9602](INFO): NAL9602 initialized
2023-05-10T17:38:02.481Z,1683740282.481 [CommandExec](IMPORTANT): got command report
2023-05-10T17:38:21.475Z,1683740301.475 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-05-10T17:38:21.475Z,1683740301.475 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-10T17:38:21.543Z,1683740301.543 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-10T17:38:21.921Z,1683740301.921 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-10T17:38:21.921Z,1683740301.921 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-05-10T17:38:22.630Z,1683740302.630 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-10T17:38:22.646Z,1683740302.646 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2023-05-10T17:38:22.647Z,1683740302.647 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-10T17:38:22.651Z,1683740302.651 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2023-05-10T17:38:22.651Z,1683740302.651 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-10T17:38:22.654Z,1683740302.654 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2023-05-10T17:38:22.655Z,1683740302.655 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-05-10T17:38:22.656Z,1683740302.656 [CommandExec](IMPORTANT): got command report touch acoustic_contact_range
2023-05-10T17:38:22.751Z,1683740302.751 [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-10T17:38:28.685Z,1683740308.685 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683740302 second
2023-05-10T17:38:29.414Z,1683740309.414 [CommandExec](IMPORTANT): got command show stack
2023-05-10T17:38:29.414Z,1683740309.414 [CommandExec](IMPORTANT): Behavior Stack:

2023-05-10T17:38:29.414Z,1683740309.414 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2023-05-10T17:38:29.415Z,1683740309.415 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:C.Wait
2023-05-10T17:38:36.977Z,1683740316.977 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T17:38:36.977Z,1683740316.977 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T17:38:37.037Z,1683740317.037 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 9.000000 count
2023-05-10T17:38:37.040Z,1683740317.040 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-10T17:38:37.043Z,1683740317.043 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-10T17:38:37.046Z,1683740317.046 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-10T17:38:37.049Z,1683740317.049 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-10T17:38:37.053Z,1683740317.053 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-10T17:38:37.056Z,1683740317.056 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-10T17:38:37.060Z,1683740317.060 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-10T17:38:37.091Z,1683740317.091 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-10T17:38:37.110Z,1683740317.110 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-10T17:38:37.197Z,1683740317.197 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-10T17:38:37.267Z,1683740317.267 [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-10T17:38:37.269Z,1683740317.269 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T17:38:37.297Z,1683740317.297 [Default] Stopped
2023-05-10T17:38:37.297Z,1683740317.297 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T17:38:37.297Z,1683740317.297 [Default:B.GoToSurface] Stopped
2023-05-10T17:38:37.297Z,1683740317.297 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T17:38:37.297Z,1683740317.297 [Default:CheckIn] Stopped
2023-05-10T17:38:37.298Z,1683740317.298 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T17:38:37.298Z,1683740317.298 [Default:CheckIn:C.Wait] Stopped
2023-05-10T17:38:37.298Z,1683740317.298 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T17:38:37.298Z,1683740317.298 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-10T17:38:37.298Z,1683740317.298 [senddata_direct_and_track_test] Running Loop=1
2023-05-10T17:38:37.298Z,1683740317.298 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-10T17:38:37.298Z,1683740317.298 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T17:38:37.298Z,1683740317.298 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-10T17:38:37.299Z,1683740317.299 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-10T17:38:37.299Z,1683740317.299 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-10T17:38:37.299Z,1683740317.299 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-10T17:38:37.300Z,1683740317.300 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T17:38:37.300Z,1683740317.300 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T17:38:52.602Z,1683740332.602 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T17:38:52.665Z,1683740332.665 [DATMMP](INFO): ****** received valid address query ******
2023-05-10T17:38:52.665Z,1683740332.665 [DATMMP](INFO): ****** received valid ping request ******
2023-05-10T17:38:52.666Z,1683740332.666 [DATMMP](INFO): Querying Benthos address 9
2023-05-10T17:38:52.666Z,1683740332.666 [DATMMP](INFO): type: 1 tat: 1
2023-05-10T17:38:52.917Z,1683740332.917 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:52.918Z,1683740332.918 [DATMMP](INFO): timestamp rx: 	 x0	 x11	 x26	 x33	 x1741
2023-05-10T17:38:52.918Z,1683740332.918 [DATMMP](INFO): Received message type: timestamp
2023-05-10T17:38:52.918Z,1683740332.918 [DATMMP](INFO): Handled
2023-05-10T17:38:52.919Z,1683740332.919 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:53.169Z,1683740333.169 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:53.421Z,1683740333.421 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:53.673Z,1683740333.673 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:53.925Z,1683740333.925 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:54.177Z,1683740334.177 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:54.429Z,1683740334.429 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:54.681Z,1683740334.681 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:54.933Z,1683740334.933 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:55.010Z,1683740335.010 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T17:38:55.186Z,1683740335.186 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:55.186Z,1683740335.186 [DATMMP](INFO): doppler rx: 	 x0
2023-05-10T17:38:55.186Z,1683740335.186 [DATMMP](INFO): Received message type: doppler
2023-05-10T17:38:55.186Z,1683740335.186 [DATMMP](INFO): Handled
2023-05-10T17:38:55.187Z,1683740335.187 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:55.437Z,1683740335.437 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:55.438Z,1683740335.438 [DATMMP](INFO): timestamp rx: 	 x1	 x11	 x26	 x35	 x186F
2023-05-10T17:38:55.439Z,1683740335.439 [DATMMP](INFO): Rx dataTimestamp_ set to:1683740394.088064
2023-05-10T17:38:55.439Z,1683740335.439 [DATMMP](INFO): Rx ping set to:1683740335.438245
2023-05-10T17:38:55.439Z,1683740335.439 [DATMMP](INFO): Received message type: timestamp
2023-05-10T17:38:55.440Z,1683740335.440 [DATMMP](INFO): Handled
2023-05-10T17:38:55.440Z,1683740335.440 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:55.689Z,1683740335.689 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:55.941Z,1683740335.941 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:55.942Z,1683740335.942 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-10T17:38:55.942Z,1683740335.942 [DATMMP](INFO): Received message type: nav_stat
2023-05-10T17:38:55.942Z,1683740335.942 [DATMMP](INFO): Handled
2023-05-10T17:38:55.942Z,1683740335.942 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:56.193Z,1683740336.193 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:56.194Z,1683740336.194 [DATMMP](INFO): directional_debug rx: 	 xD43	 x284	 x25	 xDB	 x1250	 x1431	 x1392	 x1843
2023-05-10T17:38:56.196Z,1683740336.196 [DATMMP](INFO): Received message type: directional_debug
2023-05-10T17:38:56.196Z,1683740336.196 [DATMMP](INFO): Handled
2023-05-10T17:38:56.196Z,1683740336.196 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:56.445Z,1683740336.445 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:56.447Z,1683740336.447 [DATMMP](INFO): directional rx: 	 xD3C	 x25D	 x6A9	 xFD7C	 xC5E	 xFD7A	 x0	 x5DF	 x5	 xFFED	 x27B5966	 x-43569E0
2023-05-10T17:38:56.449Z,1683740336.449 [DATMMP](INFO): Received message type: directional
2023-05-10T17:38:56.449Z,1683740336.449 [DATMMP](INFO): Handled
2023-05-10T17:38:56.449Z,1683740336.449 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:56.697Z,1683740336.697 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:56.698Z,1683740336.698 [DATMMP](INFO): remote_header rx: 	 x0	 x7A	 x0	 x4D	 x99	 x5	 x9	 x0
2023-05-10T17:38:56.699Z,1683740336.699 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-10T17:38:56.699Z,1683740336.699 [DATMMP](INFO): Received message type: remote_header
2023-05-10T17:38:56.699Z,1683740336.699 [DATMMP](INFO): Handled
2023-05-10T17:38:56.699Z,1683740336.699 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:56.949Z,1683740336.949 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:38:56.951Z,1683740336.951 [DATMMP](INFO): acstats rx: 	 x9	 x0	 x0	 x2CA	 x23	 xA0	 xCA	 xCB	 xD	 xFFFF	 x0	 x25	 x0	 x0
2023-05-10T17:38:56.951Z,1683740336.951 [DATMMP](INFO): Received message type: acstats
2023-05-10T17:38:56.951Z,1683740336.951 [DATMMP](INFO): Handled
2023-05-10T17:38:56.951Z,1683740336.951 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:57.201Z,1683740337.201 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-10T17:38:57.202Z,1683740337.202 [DATMMP](INFO): cmd_result rx: 	 x2	 x20	 x0	 x4
2023-05-10T17:38:57.202Z,1683740337.202 [DATMMP](ERROR): 4:Command error: data
2023-05-10T17:38:57.203Z,1683740337.203 [DATMMP](ERROR): 4:COMPLETE
2023-05-10T17:38:57.203Z,1683740337.203 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:57.453Z,1683740337.453 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:57.705Z,1683740337.705 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:57.957Z,1683740337.957 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:58.209Z,1683740338.209 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:58.461Z,1683740338.461 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:58.713Z,1683740338.713 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:58.965Z,1683740338.965 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:59.217Z,1683740339.217 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:59.469Z,1683740339.469 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:59.724Z,1683740339.724 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:38:59.977Z,1683740339.977 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:00.229Z,1683740340.229 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:00.481Z,1683740340.481 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:00.733Z,1683740340.733 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:00.985Z,1683740340.985 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:01.237Z,1683740341.237 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:01.489Z,1683740341.489 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:01.741Z,1683740341.741 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:01.993Z,1683740341.993 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:02.245Z,1683740342.245 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:02.500Z,1683740342.500 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:02.749Z,1683740342.749 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:07.944Z,1683740347.944 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T17:39:08.053Z,1683740348.053 [DATMMP](INFO): ****** received valid address query ******
2023-05-10T17:39:08.053Z,1683740348.053 [DATMMP](INFO): ****** received valid ping request ******
2023-05-10T17:39:08.054Z,1683740348.054 [DATMMP](INFO): Querying Benthos address 9
2023-05-10T17:39:08.054Z,1683740348.054 [DATMMP](INFO): type: 1 tat: 1
2023-05-10T17:39:08.305Z,1683740348.305 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:08.306Z,1683740348.306 [DATMMP](INFO): timestamp rx: 	 x0	 x11	 x27	 x6	 x26E0
2023-05-10T17:39:08.306Z,1683740348.306 [DATMMP](INFO): Received message type: timestamp
2023-05-10T17:39:08.306Z,1683740348.306 [DATMMP](INFO): Handled
2023-05-10T17:39:08.306Z,1683740348.306 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:08.557Z,1683740348.557 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:08.810Z,1683740348.810 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:09.061Z,1683740349.061 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:09.313Z,1683740349.313 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:09.565Z,1683740349.565 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:09.817Z,1683740349.817 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:10.071Z,1683740350.071 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:10.321Z,1683740350.321 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:10.573Z,1683740350.573 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:10.574Z,1683740350.574 [DATMMP](INFO): doppler rx: 	 x0
2023-05-10T17:39:10.574Z,1683740350.574 [DATMMP](INFO): Received message type: doppler
2023-05-10T17:39:10.574Z,1683740350.574 [DATMMP](INFO): Handled
2023-05-10T17:39:10.574Z,1683740350.574 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:10.825Z,1683740350.825 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:10.826Z,1683740350.826 [DATMMP](INFO): timestamp rx: 	 x1	 x11	 x27	 x9	 xFF
2023-05-10T17:39:10.827Z,1683740350.827 [DATMMP](INFO): Rx dataTimestamp_ set to:1683740351.514048
2023-05-10T17:39:10.827Z,1683740350.827 [DATMMP](INFO): Rx ping set to:1683740350.826197
2023-05-10T17:39:10.827Z,1683740350.827 [DATMMP](INFO): Received message type: timestamp
2023-05-10T17:39:10.827Z,1683740350.827 [DATMMP](INFO): Handled
2023-05-10T17:39:10.827Z,1683740350.827 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:11.077Z,1683740351.077 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:11.329Z,1683740351.329 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:11.330Z,1683740351.330 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-10T17:39:11.330Z,1683740351.330 [DATMMP](INFO): Received message type: nav_stat
2023-05-10T17:39:11.330Z,1683740351.330 [DATMMP](INFO): Handled
2023-05-10T17:39:11.330Z,1683740351.330 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:11.581Z,1683740351.581 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:11.582Z,1683740351.582 [DATMMP](INFO): directional_debug rx: 	 x882	 x37	 x22	 x84A	 x11D0	 x1471	 x13A2	 x1793
2023-05-10T17:39:11.583Z,1683740351.583 [DATMMP](INFO): Received message type: directional_debug
2023-05-10T17:39:11.583Z,1683740351.583 [DATMMP](INFO): Handled
2023-05-10T17:39:11.584Z,1683740351.584 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:11.833Z,1683740351.833 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:11.835Z,1683740351.835 [DATMMP](INFO): directional rx: 	 x881	 x18	 xB6A	 xFFC9	 x32C	 xFFB8	 x0	 x5D2	 x2	 xFFEC	 x27B5966	 x-43569E0
2023-05-10T17:39:11.843Z,1683740351.843 [DATMMP](INFO): Received message type: directional
2023-05-10T17:39:11.843Z,1683740351.843 [DATMMP](INFO): Handled
2023-05-10T17:39:11.844Z,1683740351.844 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:12.085Z,1683740352.085 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:12.086Z,1683740352.086 [DATMMP](INFO): remote_header rx: 	 x0	 x7A	 x0	 x4D	 x99	 x5	 x9	 x0
2023-05-10T17:39:12.087Z,1683740352.087 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-10T17:39:12.087Z,1683740352.087 [DATMMP](INFO): Received message type: remote_header
2023-05-10T17:39:12.087Z,1683740352.087 [DATMMP](INFO): Handled
2023-05-10T17:39:12.087Z,1683740352.087 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:12.337Z,1683740352.337 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:12.339Z,1683740352.339 [DATMMP](INFO): acstats rx: 	 x9	 x0	 x0	 x29A	 x23	 x8D	 xC9	 xC5	 xD	 xFFFF	 x0	 x23	 x0	 x0
2023-05-10T17:39:12.339Z,1683740352.339 [DATMMP](INFO): Received message type: acstats
2023-05-10T17:39:12.339Z,1683740352.339 [DATMMP](INFO): Handled
2023-05-10T17:39:12.339Z,1683740352.339 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:12.589Z,1683740352.589 [DATMMP](INFO): GSXN notify for xid: 16
2023-05-10T17:39:12.590Z,1683740352.590 [DATMMP](INFO): cmd_result rx: 	 x2	 x20	 x0	 x4
2023-05-10T17:39:12.590Z,1683740352.590 [DATMMP](ERROR): 4:Command error: data
2023-05-10T17:39:12.591Z,1683740352.591 [DATMMP](ERROR): 4:COMPLETE
2023-05-10T17:39:12.591Z,1683740352.591 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:12.841Z,1683740352.841 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:13.093Z,1683740353.093 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:13.345Z,1683740353.345 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:13.597Z,1683740353.597 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:13.849Z,1683740353.849 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:14.101Z,1683740354.101 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:14.353Z,1683740354.353 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:14.605Z,1683740354.605 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:14.857Z,1683740354.857 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:15.109Z,1683740355.109 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:15.361Z,1683740355.361 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:15.613Z,1683740355.613 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:15.865Z,1683740355.865 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:16.117Z,1683740356.117 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:16.369Z,1683740356.369 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:16.621Z,1683740356.621 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:16.886Z,1683740356.886 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:17.137Z,1683740357.137 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:17.389Z,1683740357.389 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:17.641Z,1683740357.641 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:17.893Z,1683740357.893 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:18.145Z,1683740358.145 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:23.295Z,1683740363.295 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T17:39:23.453Z,1683740363.453 [DATMMP](INFO): ****** received valid address query ******
2023-05-10T17:39:23.453Z,1683740363.453 [DATMMP](INFO): ****** received valid ping request ******
2023-05-10T17:39:23.454Z,1683740363.454 [DATMMP](INFO): Querying Benthos address 9
2023-05-10T17:39:23.454Z,1683740363.454 [DATMMP](INFO): type: 1 tat: 1
2023-05-10T17:39:23.705Z,1683740363.705 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:23.706Z,1683740363.706 [DATMMP](INFO): timestamp rx: 	 x0	 x11	 x27	 x16	 xF6F
2023-05-10T17:39:23.706Z,1683740363.706 [DATMMP](INFO): Received message type: timestamp
2023-05-10T17:39:23.706Z,1683740363.706 [DATMMP](INFO): Handled
2023-05-10T17:39:23.707Z,1683740363.707 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:23.957Z,1683740363.957 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:24.209Z,1683740364.209 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:24.461Z,1683740364.461 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:24.713Z,1683740364.713 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:24.965Z,1683740364.965 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:25.217Z,1683740365.217 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:25.469Z,1683740365.469 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:25.721Z,1683740365.721 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:25.973Z,1683740365.973 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:25.974Z,1683740365.974 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-10T17:39:25.974Z,1683740365.974 [DATMMP](INFO): Received message type: doppler
2023-05-10T17:39:25.974Z,1683740365.974 [DATMMP](INFO): Handled
2023-05-10T17:39:25.974Z,1683740365.974 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:26.225Z,1683740366.225 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:26.226Z,1683740366.226 [DATMMP](INFO): timestamp rx: 	 x1	 x11	 x27	 x18	 x109F
2023-05-10T17:39:26.227Z,1683740366.227 [DATMMP](INFO): Rx dataTimestamp_ set to:1683740405.579584
2023-05-10T17:39:26.227Z,1683740366.227 [DATMMP](INFO): Rx ping set to:1683740366.226088
2023-05-10T17:39:26.227Z,1683740366.227 [DATMMP](INFO): Received message type: timestamp
2023-05-10T17:39:26.227Z,1683740366.227 [DATMMP](INFO): Handled
2023-05-10T17:39:26.227Z,1683740366.227 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:26.477Z,1683740366.477 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:26.729Z,1683740366.729 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:26.730Z,1683740366.730 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-10T17:39:26.730Z,1683740366.730 [DATMMP](INFO): Received message type: nav_stat
2023-05-10T17:39:26.730Z,1683740366.730 [DATMMP](INFO): Handled
2023-05-10T17:39:26.730Z,1683740366.730 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:26.981Z,1683740366.981 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:26.982Z,1683740366.982 [DATMMP](INFO): directional_debug rx: 	 xDCB	 x236	 x22	 xF0	 x11F0	 x1421	 x1352	 x1833
2023-05-10T17:39:26.983Z,1683740366.983 [DATMMP](INFO): Received message type: directional_debug
2023-05-10T17:39:26.983Z,1683740366.983 [DATMMP](INFO): Handled
2023-05-10T17:39:26.983Z,1683740366.983 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:27.233Z,1683740367.233 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:27.235Z,1683740367.235 [DATMMP](INFO): directional rx: 	 xDC4	 x200	 x621	 xFDCA	 xBCB	 xFDCE	 x0	 x5C5	 x5	 xFFEE	 x27B5966	 x-43569E0
2023-05-10T17:39:27.236Z,1683740367.236 [DATMMP](INFO): Received message type: directional
2023-05-10T17:39:27.236Z,1683740367.236 [DATMMP](INFO): Handled
2023-05-10T17:39:27.237Z,1683740367.237 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:27.485Z,1683740367.485 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:27.486Z,1683740367.486 [DATMMP](INFO): remote_header rx: 	 x0	 x7A	 x0	 x4C	 x2F	 x5	 x9	 x0
2023-05-10T17:39:27.487Z,1683740367.487 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-10T17:39:27.487Z,1683740367.487 [DATMMP](INFO): Received message type: remote_header
2023-05-10T17:39:27.487Z,1683740367.487 [DATMMP](INFO): Handled
2023-05-10T17:39:27.487Z,1683740367.487 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:27.737Z,1683740367.737 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-10T17:39:27.739Z,1683740367.739 [DATMMP](INFO): acstats rx: 	 x9	 x0	 xFFFF	 x282	 x22	 x8F	 xBD	 xB9	 xD	 xFFFF	 x0	 x24	 x0	 x0
2023-05-10T17:39:27.739Z,1683740367.739 [DATMMP](INFO): Received message type: acstats
2023-05-10T17:39:27.739Z,1683740367.739 [DATMMP](INFO): Handled
2023-05-10T17:39:27.739Z,1683740367.739 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:27.989Z,1683740367.989 [DATMMP](INFO): GSXN notify for xid: 17
2023-05-10T17:39:27.990Z,1683740367.990 [DATMMP](INFO): cmd_result rx: 	 x2	 x20	 x0	 x4
2023-05-10T17:39:27.990Z,1683740367.990 [DATMMP](ERROR): 4:Command error: data
2023-05-10T17:39:27.991Z,1683740367.991 [DATMMP](ERROR): 4:COMPLETE
2023-05-10T17:39:27.991Z,1683740367.991 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:28.241Z,1683740368.241 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:28.493Z,1683740368.493 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:28.745Z,1683740368.745 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:28.997Z,1683740368.997 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:29.249Z,1683740369.249 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:29.501Z,1683740369.501 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:29.753Z,1683740369.753 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:30.005Z,1683740370.005 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:30.257Z,1683740370.257 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:30.509Z,1683740370.509 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:30.761Z,1683740370.761 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:31.013Z,1683740371.013 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:31.265Z,1683740371.265 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:31.517Z,1683740371.517 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:31.769Z,1683740371.769 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:32.021Z,1683740372.021 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:32.273Z,1683740372.273 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:32.525Z,1683740372.525 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:32.779Z,1683740372.779 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:33.030Z,1683740373.030 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:33.281Z,1683740373.281 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:33.533Z,1683740373.533 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-10T17:39:36.442Z,1683740376.442 [CommandExec](IMPORTANT): got command stop
2023-05-10T17:39:36.442Z,1683740376.442 [CommandExec](IMPORTANT): Scheduling is paused
2023-05-10T17:39:36.442Z,1683740376.442 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-05-10T17:39:36.635Z,1683740376.635 [MissionManager](INFO): MissionManager is completed.
2023-05-10T17:39:36.635Z,1683740376.635 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-10T17:39:36.635Z,1683740376.635 [senddata_direct_and_track_test] Stopped
2023-05-10T17:39:36.636Z,1683740376.636 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-10T17:39:36.636Z,1683740376.636 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-10T17:39:36.636Z,1683740376.636 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-10T17:39:36.636Z,1683740376.636 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-10T17:39:36.636Z,1683740376.636 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-10T17:39:36.636Z,1683740376.636 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-10T17:39:36.636Z,1683740376.636 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T17:39:37.047Z,1683740377.047 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T17:39:37.048Z,1683740377.048 [Default] Running Loop=1
2023-05-10T17:39:37.048Z,1683740377.048 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T17:39:37.048Z,1683740377.048 [Default:B.GoToSurface] Running Loop=1
2023-05-10T17:39:37.048Z,1683740377.048 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T17:39:37.048Z,1683740377.048 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T17:39:37.049Z,1683740377.049 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T17:39:37.049Z,1683740377.049 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T17:39:37.049Z,1683740377.049 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T17:39:37.049Z,1683740377.049 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T17:39:37.050Z,1683740377.050 [Default:A.Wait] Running Loop=1
2023-05-10T17:39:37.050Z,1683740377.050 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T17:39:50.368Z,1683740390.368 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T17:39:50.368Z,1683740390.368 [Default:A.Wait] Stopped
2023-05-10T17:39:50.368Z,1683740390.368 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T17:39:50.768Z,1683740390.768 [Default:CheckIn] Running Loop=1
2023-05-10T17:39:50.768Z,1683740390.768 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T17:39:50.768Z,1683740390.768 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T17:43:45.181Z,1683740625.181 [CommandExec](IMPORTANT): got command failComponent
2023-05-10T17:43:45.182Z,1683740625.182 [CommandExec](IMPORTANT): Failed components:
2023-05-10T17:43:45.182Z,1683740625.182 [CommandExec](IMPORTANT): No failed Components.
2023-05-10T17:43:50.070Z,1683740630.070 [CommandExec](IMPORTANT): got command restart application
2023-05-10T17:43:51.073Z,1683740631.073 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:51.073Z,1683740631.073 [CommandExec](INFO): Uninitializing the command executive.
2023-05-10T17:43:51.073Z,1683740631.073 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-10T17:43:51.073Z,1683740631.073 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:51.113Z,1683740631.113 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-05-10T17:43:51.113Z,1683740631.113 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-10T17:43:51.113Z,1683740631.113 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:51.114Z,1683740631.114 [NavChartDb](INFO): Join timeout helper Thread ID is 4584
2023-05-10T17:43:51.409Z,1683740631.409 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:51.409Z,1683740631.409 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:51.429Z,1683740631.429 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-10T17:43:51.429Z,1683740631.429 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:51.429Z,1683740631.429 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4585
2023-05-10T17:43:51.669Z,1683740631.669 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:51.669Z,1683740631.669 [WetLabsBB2FL](INFO): Powering down
2023-05-10T17:43:51.670Z,1683740631.670 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:51.679Z,1683740631.679 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-10T17:43:51.679Z,1683740631.679 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:51.680Z,1683740631.680 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4586
2023-05-10T17:43:52.641Z,1683740632.641 [CTD_Seabird](INFO): Powering down
2023-05-10T17:43:52.653Z,1683740632.653 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:52.653Z,1683740632.653 [CTD_Seabird](INFO): Powering down
2023-05-10T17:43:52.664Z,1683740632.664 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:52.665Z,1683740632.665 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler
2023-05-10T17:43:52.665Z,1683740632.665 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:52.665Z,1683740632.665 [DATMMP](INFO): Join timeout helper Thread ID is 4587
2023-05-10T17:43:52.761Z,1683740632.761 [DATMMP](INFO): Stop
2023-05-10T17:43:52.761Z,1683740632.761 [DATMMP](INFO): uninitialize
2023-05-10T17:43:52.761Z,1683740632.761 [DATMMP](INFO): Powering down
2023-05-10T17:43:52.833Z,1683740632.833 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:52.834Z,1683740632.834 [DATMMP](INFO): uninitialize
2023-05-10T17:43:52.834Z,1683740632.834 [DATMMP](INFO): Powering down
2023-05-10T17:43:52.835Z,1683740632.835 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:52.853Z,1683740632.853 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-10T17:43:52.853Z,1683740632.853 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:52.853Z,1683740632.853 [Radio_Surface](INFO): Join timeout helper Thread ID is 4588
2023-05-10T17:43:52.901Z,1683740632.901 [Radio_Surface](INFO): Powering down
2023-05-10T17:43:52.902Z,1683740632.902 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:52.902Z,1683740632.902 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:52.918Z,1683740632.918 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-10T17:43:52.918Z,1683740632.918 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:52.918Z,1683740632.918 [Onboard](INFO): Join timeout helper Thread ID is 4589
2023-05-10T17:43:53.233Z,1683740633.233 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-05-10T17:43:54.177Z,1683740634.177 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:54.177Z,1683740634.177 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.194Z,1683740634.194 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-10T17:43:54.194Z,1683740634.194 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.194Z,1683740634.194 [DataOverHttps](INFO): Join timeout helper Thread ID is 4590
2023-05-10T17:43:54.237Z,1683740634.237 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:54.237Z,1683740634.237 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.241Z,1683740634.241 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-10T17:43:54.241Z,1683740634.241 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.242Z,1683740634.242 [BackseatComponent](INFO): Join timeout helper Thread ID is 4591
2023-05-10T17:43:54.317Z,1683740634.317 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:54.317Z,1683740634.317 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.321Z,1683740634.321 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-10T17:43:54.321Z,1683740634.321 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.322Z,1683740634.322 [logger](INFO): Join timeout helper Thread ID is 4592
2023-05-10T17:43:54.337Z,1683740634.337 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:54.337Z,1683740634.337 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.345Z,1683740634.345 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-10T17:43:54.345Z,1683740634.345 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.346Z,1683740634.346 [CommandLine](INFO): Join timeout helper Thread ID is 4593
2023-05-10T17:43:54.361Z,1683740634.361 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:54.361Z,1683740634.361 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.374Z,1683740634.374 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-10T17:43:54.374Z,1683740634.374 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.374Z,1683740634.374 [CommandExec](INFO): Join timeout helper Thread ID is 4594
2023-05-10T17:43:54.378Z,1683740634.378 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-10T17:43:54.378Z,1683740634.378 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.379Z,1683740634.379 [controlThread](INFO): Join timeout helper Thread ID is 4595
2023-05-10T17:43:54.415Z,1683740634.415 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T17:43:54.415Z,1683740634.415 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-10T17:43:54.415Z,1683740634.415 [AHRS_M2](INFO): Powering down
2023-05-10T17:43:54.485Z,1683740634.485 [NAL9602](INFO): Powering down
2023-05-10T17:43:54.488Z,1683740634.488 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-10T17:43:54.489Z,1683740634.489 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-10T17:43:54.489Z,1683740634.489 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-10T17:43:54.490Z,1683740634.490 [MissionManager](INFO): Uninitializing Mission Default
2023-05-10T17:43:54.490Z,1683740634.490 [Default] Stopped
2023-05-10T17:43:54.490Z,1683740634.490 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T17:43:54.490Z,1683740634.490 [Default:B.GoToSurface] Stopped
2023-05-10T17:43:54.490Z,1683740634.490 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T17:43:54.490Z,1683740634.490 [Default:CheckIn] Stopped
2023-05-10T17:43:54.490Z,1683740634.490 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T17:43:54.490Z,1683740634.490 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T17:43:54.493Z,1683740634.493 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-10T17:43:54.493Z,1683740634.493 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-10T17:43:54.494Z,1683740634.494 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-10T17:43:54.494Z,1683740634.494 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-10T17:43:54.494Z,1683740634.494 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-10T17:43:54.494Z,1683740634.494 [BuoyancyServo](INFO): Powering down
2023-05-10T17:43:54.509Z,1683740634.509 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-10T17:43:54.509Z,1683740634.509 [ElevatorServo](INFO): Powering down
2023-05-10T17:43:54.510Z,1683740634.510 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-10T17:43:54.510Z,1683740634.510 [MassServo](INFO): Powering down
2023-05-10T17:43:54.511Z,1683740634.511 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-10T17:43:54.511Z,1683740634.511 [RudderServo](INFO): Powering down
2023-05-10T17:43:54.511Z,1683740634.511 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-10T17:43:54.512Z,1683740634.512 [ThrusterHE](INFO): Powering down
2023-05-10T17:43:54.513Z,1683740634.513 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-10T17:43:54.513Z,1683740634.513 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-10T17:43:54.513Z,1683740634.513 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-10T17:43:54.513Z,1683740634.513 [CBIT](DEBUG): Powering off loads.
2023-05-10T17:43:54.524Z,1683740634.524 [CBIT](DEBUG): Disabling WDT.
2023-05-10T17:43:54.536Z,1683740634.536 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-10T17:43:54.537Z,1683740634.537 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.579Z,1683740634.579 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.585Z,1683740634.585 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.586Z,1683740634.586 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.592Z,1683740634.592 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.637Z,1683740634.637 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.683Z,1683740634.683 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.687Z,1683740634.687 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.720Z,1683740634.720 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T17:43:54.780Z,1683740634.780 [logger ThreadHandler](INFO): Thread cancelled.