2023-06-05T22:06:12.857Z,1686002772.857 [Supervisor](DEBUG): Initializing supervisor.
2023-06-05T22:06:12.862Z,1686002772.862 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-06-05T22:06:12.863Z,1686002772.863 [SyncHandler](INFO): Protected caller Thread ID is 2377
2023-06-05T22:06:12.864Z,1686002772.864 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-06-05T22:06:12.865Z,1686002772.865 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-06-05T22:06:12.865Z,1686002772.865 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2378
2023-06-05T22:06:12.869Z,1686002772.869 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-06-05T22:06:12.887Z,1686002772.887 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-06-05T22:06:12.888Z,1686002772.888 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-06-05T22:06:12.889Z,1686002772.889 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 2379
2023-06-05T22:06:12.893Z,1686002772.893 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-06-05T22:06:12.894Z,1686002772.894 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-06-05T22:06:12.894Z,1686002772.894 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2380
2023-06-05T22:06:12.896Z,1686002772.896 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-06-05T22:06:12.897Z,1686002772.897 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-06-05T22:06:12.898Z,1686002772.898 [logger ThreadHandler](INFO): Protected caller Thread ID is 2381
2023-06-05T22:06:12.901Z,1686002772.901 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-06-05T22:06:12.902Z,1686002772.902 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-06-05T22:06:12.903Z,1686002772.903 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-06-05T22:06:13.385Z,1686002773.385 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-06-05T22:06:13.386Z,1686002773.386 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-06-05T22:06:13.598Z,1686002773.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-06-05T22:06:13.599Z,1686002773.599 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-06-05T22:06:13.680Z,1686002773.680 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-06-05T22:06:13.903Z,1686002773.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-06-05T22:06:13.904Z,1686002773.904 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-06-05T22:06:13.984Z,1686002773.984 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-06-05T22:06:14.082Z,1686002774.082 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-06-05T22:06:14.082Z,1686002774.082 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-06-05T22:06:14.437Z,1686002774.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-06-05T22:06:14.438Z,1686002774.438 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-06-05T22:06:14.574Z,1686002774.574 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-06-05T22:06:14.575Z,1686002774.575 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-06-05T22:06:15.073Z,1686002775.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-06-05T22:06:15.074Z,1686002775.074 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-06-05T22:06:15.402Z,1686002775.402 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-06-05T22:06:15.402Z,1686002775.402 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-06-05T22:06:15.810Z,1686002775.810 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-06-05T22:06:15.811Z,1686002775.811 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-06-05T22:06:16.107Z,1686002776.107 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-06-05T22:06:16.107Z,1686002776.107 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-06-05T22:06:16.219Z,1686002776.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-06-05T22:06:16.219Z,1686002776.219 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-06-05T22:06:17.020Z,1686002777.020 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-06-05T22:06:17.021Z,1686002777.021 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-06-05T22:06:17.359Z,1686002777.359 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-06-05T22:06:17.360Z,1686002777.360 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-06-05T22:06:17.588Z,1686002777.588 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-06-05T22:06:17.590Z,1686002777.590 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-06-05T22:06:17.591Z,1686002777.591 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-06-05T22:06:17.715Z,1686002777.715 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-06-05T22:06:17.799Z,1686002777.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-06-05T22:06:17.940Z,1686002777.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-06-05T22:06:18.027Z,1686002778.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-06-05T22:06:18.297Z,1686002778.297 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-06-05T22:06:18.297Z,1686002778.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-06-05T22:06:18.402Z,1686002778.402 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-06-05T22:06:18.509Z,1686002778.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-06-05T22:06:18.624Z,1686002778.624 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-06-05T22:06:18.771Z,1686002778.771 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-06-05T22:06:18.870Z,1686002778.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-06-05T22:06:18.965Z,1686002778.965 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-06-05T22:06:18.965Z,1686002778.965 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-06-05T22:06:18.978Z,1686002778.978 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-06-05T22:06:18.988Z,1686002778.988 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-06-05T22:06:18.989Z,1686002778.989 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-06-05T22:06:19.088Z,1686002779.088 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-06-05T22:06:19.089Z,1686002779.089 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-06-05T22:06:19.139Z,1686002779.139 [VerticalControl](DEBUG): Construct VerticalControl.
2023-06-05T22:06:19.200Z,1686002779.200 [VerticalControl] Loaded
2023-06-05T22:06:19.201Z,1686002779.201 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-06-05T22:06:19.204Z,1686002779.204 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-06-05T22:06:19.246Z,1686002779.246 [HorizontalControl] Loaded
2023-06-05T22:06:19.246Z,1686002779.246 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-06-05T22:06:19.248Z,1686002779.248 [SpeedControl](DEBUG): Construct SpeedControl.
2023-06-05T22:06:19.252Z,1686002779.252 [SpeedControl] Loaded
2023-06-05T22:06:19.252Z,1686002779.252 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-06-05T22:06:19.255Z,1686002779.255 [LoopControl](DEBUG): Construct LoopControl.
2023-06-05T22:06:19.255Z,1686002779.255 [LoopControl] Loaded
2023-06-05T22:06:19.255Z,1686002779.255 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-06-05T22:06:19.256Z,1686002779.256 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-06-05T22:06:19.256Z,1686002779.256 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-06-05T22:06:19.411Z,1686002779.411 [BuoyancyServo] Loaded
2023-06-05T22:06:19.411Z,1686002779.411 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-06-05T22:06:19.431Z,1686002779.431 [ElevatorServo] Loaded
2023-06-05T22:06:19.431Z,1686002779.431 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-06-05T22:06:19.451Z,1686002779.451 [MassServo] Loaded
2023-06-05T22:06:19.451Z,1686002779.451 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-06-05T22:06:19.469Z,1686002779.469 [RudderServo] Loaded
2023-06-05T22:06:19.469Z,1686002779.469 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-06-05T22:06:19.485Z,1686002779.485 [ThrusterHE] Loaded
2023-06-05T22:06:19.485Z,1686002779.485 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-06-05T22:06:19.485Z,1686002779.485 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-06-05T22:06:19.486Z,1686002779.486 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-06-05T22:06:19.536Z,1686002779.536 [DepthRateCalculator] Loaded
2023-06-05T22:06:19.536Z,1686002779.536 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-06-05T22:06:19.541Z,1686002779.541 [PitchRateCalculator] Loaded
2023-06-05T22:06:19.541Z,1686002779.541 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-06-05T22:06:19.552Z,1686002779.552 [SpeedCalculator] Loaded
2023-06-05T22:06:19.552Z,1686002779.552 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-06-05T22:06:19.556Z,1686002779.556 [YawRateCalculator] Loaded
2023-06-05T22:06:19.556Z,1686002779.556 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-06-05T22:06:19.575Z,1686002779.575 [ElevatorOffsetCalculator] Loaded
2023-06-05T22:06:19.575Z,1686002779.575 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-06-05T22:06:19.576Z,1686002779.576 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-06-05T22:06:19.576Z,1686002779.576 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-06-05T22:06:19.691Z,1686002779.691 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-06-05T22:06:19.691Z,1686002779.691 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-06-05T22:06:19.705Z,1686002779.705 [NavChart] Loaded
2023-06-05T22:06:19.705Z,1686002779.705 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-06-05T22:06:19.711Z,1686002779.711 [UniversalFixResidualReporter] Loaded
2023-06-05T22:06:19.711Z,1686002779.711 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-06-05T22:06:19.712Z,1686002779.712 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-06-05T22:06:19.712Z,1686002779.712 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-06-05T22:06:20.149Z,1686002780.149 [AHRS_M2] Loaded
2023-06-05T22:06:20.149Z,1686002780.149 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-06-05T22:06:20.184Z,1686002780.184 [BackseatComponent] Loaded
2023-06-05T22:06:20.184Z,1686002780.184 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-06-05T22:06:20.185Z,1686002780.185 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E54E0
2023-06-05T22:06:20.186Z,1686002780.186 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2463
2023-06-05T22:06:20.189Z,1686002780.189 [LcmUniversalReporter] Loaded
2023-06-05T22:06:20.189Z,1686002780.189 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-06-05T22:06:20.195Z,1686002780.195 [BioacousticsDataBridge] Loaded
2023-06-05T22:06:20.195Z,1686002780.195 [ComponentRegistry](DEBUG): SyncComponent "BioacousticsDataBridge" handled in the control thread.
2023-06-05T22:06:22.371Z,1686002782.371 [BPC1] Loaded
2023-06-05T22:06:22.372Z,1686002782.372 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-06-05T22:06:22.766Z,1686002782.766 [DataOverHttps] Loaded
2023-06-05T22:06:22.766Z,1686002782.766 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-06-05T22:06:22.767Z,1686002782.767 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409154E0
2023-06-05T22:06:22.767Z,1686002782.767 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2464
2023-06-05T22:06:22.788Z,1686002782.788 [Depth_Keller] Loaded
2023-06-05T22:06:22.789Z,1686002782.789 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-06-05T22:06:22.794Z,1686002782.794 [DropWeight] Loaded
2023-06-05T22:06:22.794Z,1686002782.794 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-06-05T22:06:22.857Z,1686002782.857 [NAL9602] Loaded
2023-06-05T22:06:22.857Z,1686002782.857 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-06-05T22:06:22.887Z,1686002782.887 [Onboard] Loaded
2023-06-05T22:06:22.887Z,1686002782.887 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-06-05T22:06:22.888Z,1686002782.888 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409454E0
2023-06-05T22:06:22.888Z,1686002782.888 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2465
2023-06-05T22:06:22.900Z,1686002782.900 [Power24vConverter] Loaded
2023-06-05T22:06:22.901Z,1686002782.901 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-06-05T22:06:22.914Z,1686002782.914 [Radio_Surface] Loaded
2023-06-05T22:06:22.914Z,1686002782.914 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-06-05T22:06:22.915Z,1686002782.915 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2023-06-05T22:06:22.916Z,1686002782.916 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2466
2023-06-05T22:06:22.930Z,1686002782.930 [Sonardyne_Nano] Loaded
2023-06-05T22:06:22.930Z,1686002782.930 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-06-05T22:06:22.931Z,1686002782.931 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-06-05T22:06:22.931Z,1686002782.931 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-06-05T22:06:22.987Z,1686002782.987 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-06-05T22:06:22.987Z,1686002782.987 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-06-05T22:06:23.134Z,1686002783.134 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-06-05T22:06:23.135Z,1686002783.135 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-06-05T22:06:23.162Z,1686002783.162 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-06-05T22:06:23.162Z,1686002783.162 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-06-05T22:06:23.330Z,1686002783.330 [CTD_Seabird] Loaded
2023-06-05T22:06:23.330Z,1686002783.330 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-06-05T22:06:23.331Z,1686002783.331 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AA94E0
2023-06-05T22:06:23.332Z,1686002783.332 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2467
2023-06-05T22:06:23.352Z,1686002783.352 [PAR_Licor] Loaded
2023-06-05T22:06:23.352Z,1686002783.352 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-06-05T22:06:23.384Z,1686002783.384 [WetLabsBB2FL] Loaded
2023-06-05T22:06:23.384Z,1686002783.384 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-06-05T22:06:23.385Z,1686002783.385 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AD94E0
2023-06-05T22:06:23.385Z,1686002783.385 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2468
2023-06-05T22:06:23.386Z,1686002783.386 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-06-05T22:06:23.387Z,1686002783.387 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-06-05T22:06:23.694Z,1686002783.694 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-06-05T22:06:23.694Z,1686002783.694 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-06-05T22:06:23.838Z,1686002783.838 [SBIT](DEBUG): Construct Startup Built In Test.
2023-06-05T22:06:23.847Z,1686002783.847 [SBIT] Loaded
2023-06-05T22:06:23.847Z,1686002783.847 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-06-05T22:06:23.850Z,1686002783.850 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-06-05T22:06:23.864Z,1686002783.864 [IBIT] Loaded
2023-06-05T22:06:23.864Z,1686002783.864 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-06-05T22:06:23.870Z,1686002783.870 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-06-05T22:06:23.977Z,1686002783.977 [CBIT] Loaded
2023-06-05T22:06:23.978Z,1686002783.978 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-06-05T22:06:23.978Z,1686002783.978 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-06-05T22:06:23.984Z,1686002783.984 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-06-05T22:06:23.987Z,1686002783.987 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-06-05T22:06:23.998Z,1686002783.998 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-06-05T22:06:23.999Z,1686002783.999 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BC44E0
2023-06-05T22:06:23.000Z,1686002784.000 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2469
2023-06-05T22:06:24.004Z,1686002784.004 [Supervisor](INFO): Main Thread ID is 829
2023-06-05T22:06:24.004Z,1686002784.004 [Supervisor](DEBUG): Running supervisor.
2023-06-05T22:06:24.005Z,1686002784.005 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2470
2023-06-05T22:06:24.006Z,1686002784.006 [CommandExec](INFO): Initializing the command executive.
2023-06-05T22:06:24.007Z,1686002784.007 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2471
2023-06-05T22:06:24.009Z,1686002784.009 [controlThread ThreadHandler](INFO): Handler Thread ID is 2472
2023-06-05T22:06:24.010Z,1686002784.010 [controlThread](DEBUG): Initializing ControlThread
2023-06-05T22:06:24.011Z,1686002784.011 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-06-05T22:06:24.012Z,1686002784.012 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-06-05T22:06:24.013Z,1686002784.013 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-06-05T22:06:24.014Z,1686002784.014 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-06-05T22:06:24.015Z,1686002784.015 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-06-05T22:06:24.015Z,1686002784.015 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-06-05T22:06:24.016Z,1686002784.016 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-06-05T22:06:24.016Z,1686002784.016 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-06-05T22:06:24.016Z,1686002784.016 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-06-05T22:06:24.018Z,1686002784.018 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-06-05T22:06:24.018Z,1686002784.018 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-06-05T22:06:24.027Z,1686002784.027 [SBIT](INFO): Initialize SBIT Component.
2023-06-05T22:06:24.027Z,1686002784.027 [SBIT](IMPORTANT): git: 2023-06-05-2-g3fb3aa6c8
2023-06-05T22:06:24.028Z,1686002784.028 [SBIT](INFO): git hash: 3fb3aa6c8a2d41313bedabdce073a42e1ae4db4f
2023-06-05T22:06:24.028Z,1686002784.028 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-06-05T22:06:24.029Z,1686002784.029 [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-06-05T22:06:24.030Z,1686002784.030 [SBIT](INFO): Beginning SBIT in 120.000000 seconds.
2023-06-05T22:06:24.031Z,1686002784.031 [IBIT](INFO): Initialize IBIT Component.
2023-06-05T22:06:24.032Z,1686002784.032 [CBIT](DEBUG): Initialize CBIT Component.
2023-06-05T22:06:24.033Z,1686002784.033 [logger ThreadHandler](INFO): Handler Thread ID is 2473
2023-06-05T22:06:24.043Z,1686002784.043 [CBIT](DEBUG): Initialized mux pins.
2023-06-05T22:06:24.043Z,1686002784.043 [CBIT](DEBUG): Initializing the watchdog timer.
2023-06-05T22:06:24.051Z,1686002784.051 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2474
2023-06-05T22:06:24.063Z,1686002784.063 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2475
2023-06-05T22:06:24.064Z,1686002784.064 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-06-05T22:06:24.067Z,1686002784.067 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-06-05T22:06:24.067Z,1686002784.067 [CBIT](DEBUG): Initializing heartbeat.
2023-06-05T22:06:24.075Z,1686002784.075 [Onboard ThreadHandler](INFO): Handler Thread ID is 2476
2023-06-05T22:06:24.092Z,1686002784.092 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2477
2023-06-05T22:06:24.115Z,1686002784.115 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2478
2023-06-05T22:06:24.116Z,1686002784.116 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-06-05T22:06:24.120Z,1686002784.120 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2480
2023-06-05T22:06:24.123Z,1686002784.123 [WetLabsBB2FL](INFO): Powering up
2023-06-05T22:06:24.124Z,1686002784.124 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2482
2023-06-05T22:06:24.127Z,1686002784.127 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-06-05T22:06:24.127Z,1686002784.127 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-06-05T22:06:24.127Z,1686002784.127 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-06-05T22:06:24.127Z,1686002784.127 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-06-05T22:06:24.128Z,1686002784.128 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-06-05T22:06:24.128Z,1686002784.128 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-06-05T22:06:24.128Z,1686002784.128 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-06-05T22:06:24.128Z,1686002784.128 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-06-05T22:06:24.139Z,1686002784.139 [CBIT](DEBUG): Deactivating GF circuits.
2023-06-05T22:06:24.139Z,1686002784.139 [CBIT](DEBUG): Deactivating emergency mode.
2023-06-05T22:06:24.179Z,1686002784.179 [CBIT](DEBUG): Backplane powered.
2023-06-05T22:06:24.180Z,1686002784.180 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-06-05T22:06:24.192Z,1686002784.192 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-05T22:06:24.220Z,1686002784.220 [MissionManager](DEBUG):
2023-06-05T22:06:24.220Z,1686002784.220 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-06-05T22:06:24.298Z,1686002784.298 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-06-05T22:06:24.299Z,1686002784.299 [Default:A.Wait](DEBUG): Construct Wait.
2023-06-05T22:06:24.301Z,1686002784.301 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-06-05T22:06:24.351Z,1686002784.351 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-06-05T22:06:24.353Z,1686002784.353 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-06-05T22:06:24.379Z,1686002784.379 [Default:E.Execute](DEBUG): Construct Execute.
2023-06-05T22:06:24.399Z,1686002784.399 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2023-06-05T22:06:24.404Z,1686002784.404 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BioacousticsDataBridge,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,Sonardyne_Nano,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-06-05T22:06:24.418Z,1686002784.418 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-06-05T22:06:24.481Z,1686002784.481 [Power24vConverter](INFO): Powering up.
2023-06-05T22:06:24.482Z,1686002784.482 [Sonardyne_Nano](INFO): Initializing.
2023-06-05T22:06:24.499Z,1686002784.499 [Radio_Surface](INFO): Powering up
2023-06-05T22:06:24.549Z,1686002784.549 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-06-05T22:06:24.555Z,1686002784.555 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-06-05T22:06:24.556Z,1686002784.556 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-06-05T22:06:24.563Z,1686002784.563 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-06-05T22:06:24.564Z,1686002784.564 [MassServo](DEBUG): Initializing EZServoServo.
2023-06-05T22:06:24.571Z,1686002784.571 [MassServo](DEBUG): Initializing MassServo.
2023-06-05T22:06:24.572Z,1686002784.572 [RudderServo](DEBUG): Initializing EZServoServo.
2023-06-05T22:06:24.583Z,1686002784.583 [RudderServo](DEBUG): Initializing RudderServo.
2023-06-05T22:06:24.584Z,1686002784.584 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-06-05T22:06:24.603Z,1686002784.603 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-06-05T22:06:24.861Z,1686002784.861 [Sonardyne_Nano](INFO): Starting
2023-06-05T22:06:25.220Z,1686002785.220 [Sonardyne_Nano](INFO): Starting
2023-06-05T22:06:25.624Z,1686002785.624 [Sonardyne_Nano](INFO): Starting
2023-06-05T22:06:26.028Z,1686002786.028 [Sonardyne_Nano](INFO): Starting
2023-06-05T22:06:26.231Z,1686002786.231 [WetLabsBB2FL](INFO): Powering down
2023-06-05T22:06:26.433Z,1686002786.433 [Sonardyne_Nano](INFO): Received response:>+++?
2023-06-05T22:06:26.433Z,1686002786.433 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2023-06-05T22:06:26.447Z,1686002786.447 [Sonardyne_Nano](INFO): Command indicated, sending CKHW
2023-06-05T22:06:26.837Z,1686002786.837 [Sonardyne_Nano](INFO): Command indicated, sending CKHW
2023-06-05T22:06:27.241Z,1686002787.241 [Sonardyne_Nano](INFO): Received response:>CKHW:PASS
2023-06-05T22:06:27.241Z,1686002787.241 [Sonardyne_Nano](INFO): Received self-test result
2023-06-05T22:06:27.242Z,1686002787.242 [Sonardyne_Nano](INFO): Command indicated, sending FS
2023-06-05T22:06:27.719Z,1686002787.719 [Sonardyne_Nano](INFO): Received response:>FS:2201,U006F43,FL0010,FV5.11.00.07,PV2.03,TDR;MF;OMNI;184;175;169,PR5000;SG;AC0.700,T-40;110;AC2.00,INC-90.00;+90.00;AC1.00
2023-06-05T22:06:27.720Z,1686002787.720 [Sonardyne_Nano](INFO): Read UUID: %x28483
2023-06-05T22:06:27.720Z,1686002787.720 [Sonardyne_Nano](INFO): Command indicated, sending VS
2023-06-05T22:06:28.074Z,1686002788.074 [Sonardyne_Nano](INFO): Received response:>VS:2201,HPR45,EXT,TILT,BT1;LI_ION;VLT4.0;IDC-12.5;CAP3.4/78;T21.6
2023-06-05T22:06:30.312Z,1686002790.312 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-06-05T22:06:53.100Z,1686002813.100 [NAL9602](INFO): Powering up NAL9602
2023-06-05T22:06:59.691Z,1686002819.691 [CommandExec](IMPORTANT): got command get Sonardyne_Nano.chargePercent
2023-06-05T22:06:59.691Z,1686002819.691 [CommandExec](IMPORTANT): Sonardyne_Nano.chargePercent 0.000000 %
2023-06-05T22:07:04.020Z,1686002824.020 [NAL9602](INFO): NAL9602 initialized
2023-06-05T22:08:24.895Z,1686002904.895 [SBIT](IMPORTANT): Beginning Startup BIT
2023-06-05T22:08:24.899Z,1686002904.899 [CBIT](IMPORTANT): Beginning ground fault scan
2023-06-05T22:08:35.749Z,1686002915.749 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004929
CHAN A1 (24V): -0.004847
CHAN A2 (12V): -0.004446
CHAN A3 (5V): -0.004006
CHAN B0 (3.3V): -0.000683
CHAN B1 (3.15aV): -0.001284
CHAN B2 (3.15bV): -0.001491
CHAN B3 (GND): -0.000837
OPEN: 0.003811
Full Scale: +/- 1 mA
2023-06-05T22:08:52.017Z,1686002932.017 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004753
2023-06-05T22:09:18.989Z,1686002958.989 [SBIT](IMPORTANT): SBIT PASSED
2023-06-05T22:09:18.989Z,1686002958.989 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-06-05T22:09:18.990Z,1686002958.990 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;
2023-06-05T22:09:18.990Z,1686002958.990 [SBIT](IMPORTANT): BioacousticsDataBridge.loadAtStartup=1 bool;
2023-06-05T22:09:18.990Z,1686002958.990 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;
2023-06-05T22:09:18.991Z,1686002958.991 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;
2023-06-05T22:09:18.991Z,1686002958.991 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.azimuth_to_contact_vehicle_frame 10.000000 angular_degree;
2023-06-05T22:09:18.991Z,1686002958.991 [SBIT](IMPORTANT): Express linearApproximation TrackAcousticContact.range_to_contact 10.000000 meter;
2023-06-05T22:09:18.991Z,1686002958.991 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;
2023-06-05T22:09:18.991Z,1686002958.991 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;
2023-06-05T22:09:18.991Z,1686002958.991 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;
2023-06-05T22:09:18.991Z,1686002958.991 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=184.896478 cubic_centimeter;
2023-06-05T22:09:18.992Z,1686002958.992 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;
2023-06-05T22:09:18.992Z,1686002958.992 [SBIT](IMPORTANT): VerticalControl.massDefault=2.5 centimeter;
2023-06-05T22:09:19.453Z,1686002959.453 [MissionManager](IMPORTANT): Started mission Startup
2023-06-05T22:09:19.453Z,1686002959.453 [Startup] Running Loop=1
2023-06-05T22:09:19.453Z,1686002959.453 [Startup](DEBUG): Aggregate::initialize Startup
2023-06-05T22:09:19.453Z,1686002959.453 [Startup:A.GoToSurface] Running Loop=1
2023-06-05T22:09:19.453Z,1686002959.453 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-05T22:09:19.454Z,1686002959.454 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-05T22:09:19.455Z,1686002959.455 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-05T22:09:19.455Z,1686002959.455 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-05T22:09:19.456Z,1686002959.456 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-05T22:09:19.456Z,1686002959.456 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-05T22:09:19.458Z,1686002959.458 [Startup:StartupSatComms] Running Loop=1
2023-06-05T22:09:19.458Z,1686002959.458 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-06-05T22:09:19.458Z,1686002959.458 [Startup:StartupSatComms:A] Running Loop=1
2023-06-05T22:09:19.803Z,1686002959.803 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-06-05T22:09:24.263Z,1686002964.263 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-06-05T22:09:24.263Z,1686002964.263 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T22:09:24.281Z,1686002964.281 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T22:09:24.648Z,1686002964.648 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T22:09:24.648Z,1686002964.648 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-06-05T22:10:19.568Z,1686003019.568 [Startup:StartupSatComms:A](INFO): Timed out from 2023-06-05T22:09:19.5Z
2023-06-05T22:10:19.568Z,1686003019.568 [Startup:StartupSatComms:A] Stopped
2023-06-05T22:10:19.569Z,1686003019.569 [Startup:StartupSatComms:B] Running Loop=1
2023-06-05T22:10:19.970Z,1686003019.970 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-05T22:10:26.738Z,1686003026.738 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230605T215533/Courier0007.lzma
2023-06-05T22:10:27.741Z,1686003027.741 [DataOverHttps](INFO): Moved sent file to Logs/20230605T215533/Courier0007.lzma.bak
2023-06-05T22:10:27.741Z,1686003027.741 [DataOverHttps](INFO): SBD MOMSN=18397952
2023-06-05T22:10:28.928Z,1686003028.928 [CommandExec](IMPORTANT): got command failComponent hardware Sonardyne_Nano
2023-06-05T22:10:28.928Z,1686003028.928 [Sonardyne_Nano] Hardware Fault, FailCount= 1
2023-06-05T22:10:28.928Z,1686003028.928 [Sonardyne_Nano](ERROR): Hardware Fault
2023-06-05T22:10:28.929Z,1686003028.929 [CommandExec](IMPORTANT): Sonardyne_Nano failureMode is Hardware Fault
2023-06-05T22:10:28.929Z,1686003028.929 [CommandExec](IMPORTANT): got command failComponent none Sonardyne_Nano
2023-06-05T22:10:28.929Z,1686003028.929 [Sonardyne_Nano] No Fault, FailCount= 1
2023-06-05T22:10:28.929Z,1686003028.929 [CommandExec](IMPORTANT): Sonardyne_Nano failureMode is No Fault
2023-06-05T22:10:43.298Z,1686003043.298 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230605T220612/Courier0000.lzma
2023-06-05T22:10:44.302Z,1686003044.302 [DataOverHttps](INFO): Moved sent file to Logs/20230605T220612/Courier0000.lzma.bak
2023-06-05T22:10:44.302Z,1686003044.302 [DataOverHttps](INFO): SBD MOMSN=18397955
2023-06-05T22:11:00.030Z,1686003060.030 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20230605T215533/Express0005.lzma
2023-06-05T22:11:01.035Z,1686003061.035 [DataOverHttps](INFO): Moved sent file to Logs/20230605T215533/Express0005.lzma.bak
2023-06-05T22:11:01.035Z,1686003061.035 [DataOverHttps](INFO): SBD MOMSN=18397959
2023-06-05T22:11:16.606Z,1686003076.606 [DataOverHttps](INFO): Sending 89 bytes from file Logs/20230605T215533/Express0008.lzma
2023-06-05T22:11:17.608Z,1686003077.608 [DataOverHttps](INFO): Moved sent file to Logs/20230605T215533/Express0008.lzma.bak
2023-06-05T22:11:17.609Z,1686003077.609 [DataOverHttps](INFO): SBD MOMSN=18397963
2023-06-05T22:11:19.759Z,1686003079.759 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:11:19.824Z,1686003079.824 [Startup:StartupSatComms:B](INFO): Timed out from 2023-06-05T22:10:19.6Z
2023-06-05T22:11:19.824Z,1686003079.824 [Startup:StartupSatComms:B] Stopped
2023-06-05T22:11:19.825Z,1686003079.825 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-06-05T22:11:19.825Z,1686003079.825 [Startup:StartupSatComms] Stopped
2023-06-05T22:11:19.825Z,1686003079.825 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-06-05T22:11:19.825Z,1686003079.825 [Startup](INFO): Completed Startup
2023-06-05T22:11:19.826Z,1686003079.826 [MissionManager](INFO): Startup is completed.
2023-06-05T22:11:19.826Z,1686003079.826 [MissionManager](INFO): Uninitializing Mission Startup
2023-06-05T22:11:19.826Z,1686003079.826 [Startup] Stopped
2023-06-05T22:11:19.826Z,1686003079.826 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-06-05T22:11:19.826Z,1686003079.826 [Startup:A.GoToSurface] Stopped
2023-06-05T22:11:19.826Z,1686003079.826 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-06-05T22:11:20.180Z,1686003080.180 [MissionManager](IMPORTANT): Started mission Default
2023-06-05T22:11:20.181Z,1686003080.181 [Default] Running Loop=1
2023-06-05T22:11:20.181Z,1686003080.181 [Default](DEBUG): Aggregate::initialize Default
2023-06-05T22:11:20.181Z,1686003080.181 [Default:B.GoToSurface] Running Loop=1
2023-06-05T22:11:20.181Z,1686003080.181 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-06-05T22:11:20.181Z,1686003080.181 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-06-05T22:11:20.181Z,1686003080.181 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-06-05T22:11:20.182Z,1686003080.182 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-06-05T22:11:20.182Z,1686003080.182 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-06-05T22:11:20.182Z,1686003080.182 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-06-05T22:11:20.183Z,1686003080.183 [Default:A.Wait] Running Loop=1
2023-06-05T22:11:20.183Z,1686003080.183 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:11:24.187Z,1686003084.187 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:11:26.613Z,1686003086.613 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:11:33.598Z,1686003093.598 [Default:A.Wait](INFO): Done Waiting.
2023-06-05T22:11:33.598Z,1686003093.598 [Default:A.Wait] Stopped
2023-06-05T22:11:33.598Z,1686003093.598 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:11:33.982Z,1686003093.982 [Default:CheckIn] Running Loop=1
2023-06-05T22:11:33.982Z,1686003093.982 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:11:33.982Z,1686003093.982 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:11:34.465Z,1686003094.465 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-06-05T22:11:35.660Z,1686003095.660 [DataOverHttps](INFO): Sending 1065 bytes from file Logs/20230605T220612/Express0001.lzma
2023-06-05T22:11:36.661Z,1686003096.661 [DataOverHttps](INFO): Moved sent file to Logs/20230605T220612/Express0001.lzma.bak
2023-06-05T22:11:36.661Z,1686003096.661 [DataOverHttps](INFO): SBD MOMSN=18397966
2023-06-05T22:11:39.601Z,1686003099.601 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:11:41.625Z,1686003101.625 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:11:54.953Z,1686003114.953 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:11:56.569Z,1686003116.569 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:07.884Z,1686003127.884 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-06-05T22:12:10.303Z,1686003130.303 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:11.515Z,1686003131.515 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:25.257Z,1686003145.257 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:25.272Z,1686003145.272 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-06-05T22:12:25.272Z,1686003145.272 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T22:12:25.284Z,1686003145.284 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T22:12:25.701Z,1686003145.701 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T22:12:25.701Z,1686003145.701 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-06-05T22:12:26.868Z,1686003146.868 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:40.200Z,1686003160.200 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:41.815Z,1686003161.815 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:55.956Z,1686003175.956 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:12:56.764Z,1686003176.764 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:13:12.119Z,1686003192.119 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:13:12.124Z,1686003192.124 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:13:27.064Z,1686003207.064 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7).
2023-06-05T22:13:27.479Z,1686003207.479 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-06-05T22:13:41.608Z,1686003221.608 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2023-06-05T22:13:48.081Z,1686003228.081 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 5.
2023-06-05T22:13:48.084Z,1686003228.084 [BPC1](INFO): Received data from all battery sticks.
2023-06-05T22:15:26.259Z,1686003326.259 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-06-05T22:15:26.259Z,1686003326.259 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T22:15:26.269Z,1686003326.269 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T22:15:26.681Z,1686003326.681 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T22:15:26.681Z,1686003326.681 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-06-05T22:16:25.649Z,1686003385.649 [Power24vConverter](INFO): Powering down.
2023-06-05T22:16:28.074Z,1686003388.074 [Sonardyne_Nano](INFO): Command indicated, sending VS
2023-06-05T22:16:28.484Z,1686003388.484 [Sonardyne_Nano](INFO): Received response:>VS:2201,HPR45,EXT,TILT,BT1;LI_ION;VLT4.0;IDC-18.0;CAP3.4/78;T21.6
2023-06-05T22:16:34.141Z,1686003394.141 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-06-05T22:11:33.0Z
2023-06-05T22:16:34.141Z,1686003394.141 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:16:34.141Z,1686003394.141 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:16:34.545Z,1686003394.545 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-06-05T22:16:41.714Z,1686003401.714 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230605T220612/Courier0004.lzma
2023-06-05T22:16:42.716Z,1686003402.716 [DataOverHttps](INFO): Moved sent file to Logs/20230605T220612/Courier0004.lzma.bak
2023-06-05T22:16:42.717Z,1686003402.717 [DataOverHttps](INFO): SBD MOMSN=18397993
2023-06-05T22:16:58.147Z,1686003418.147 [DataOverHttps](INFO): Sending 286 bytes from file Logs/20230605T220612/Express0005.lzma
2023-06-05T22:16:59.148Z,1686003419.148 [DataOverHttps](INFO): Moved sent file to Logs/20230605T220612/Express0005.lzma.bak
2023-06-05T22:16:59.149Z,1686003419.149 [DataOverHttps](INFO): SBD MOMSN=18397995
2023-06-05T22:17:00.414Z,1686003420.414 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:17:00.414Z,1686003420.414 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:17:00.414Z,1686003420.414 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:17:06.048Z,1686003426.048 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-06-05T22:17:06.048Z,1686003426.048 [NAL9602] Data Fault, FailCount= 1
2023-06-05T22:17:06.048Z,1686003426.048 [NAL9602](ERROR): Data Fault
2023-06-05T22:17:06.065Z,1686003426.065 [CBIT](ERROR): Data Fault in component: NAL9602
2023-06-05T22:17:06.448Z,1686003426.448 [NAL9602](INFO): Powering down
2023-06-05T22:17:07.289Z,1686003427.289 [CBIT](INFO): Clearing failed state for component NAL9602
2023-06-05T22:17:07.289Z,1686003427.289 [NAL9602] No Fault, FailCount= 1
2023-06-05T22:17:36.760Z,1686003456.760 [NAL9602](INFO): Powering up NAL9602
2023-06-05T22:17:47.668Z,1686003467.668 [NAL9602](INFO): NAL9602 initialized
2023-06-05T22:18:27.277Z,1686003507.277 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-06-05T22:18:27.277Z,1686003507.277 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T22:18:27.288Z,1686003507.288 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T22:18:27.689Z,1686003507.689 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T22:18:27.689Z,1686003507.689 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-06-05T22:21:28.273Z,1686003688.273 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-06-05T22:21:28.273Z,1686003688.273 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T22:21:28.303Z,1686003688.303 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T22:21:28.673Z,1686003688.673 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T22:21:28.673Z,1686003688.673 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-06-05T22:22:00.998Z,1686003720.998 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-06-05T22:22:00.998Z,1686003720.998 [Default:CheckIn:C.Wait] Stopped
2023-06-05T22:22:00.998Z,1686003720.998 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-06-05T22:22:00.998Z,1686003720.998 [Default:CheckIn:D] Running Loop=1
2023-06-05T22:22:01.416Z,1686003721.416 [Default:CheckIn:D] Stopped
2023-06-05T22:22:01.417Z,1686003721.417 [Default:CheckIn:E] Running Loop=1
2023-06-05T22:22:01.792Z,1686003721.792 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.687265 min
2023-06-05T22:22:01.792Z,1686003721.792 [Default:CheckIn:E] Stopped
2023-06-05T22:22:01.792Z,1686003721.792 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-06-05T22:22:01.793Z,1686003721.793 [Default:CheckIn] Stopped
2023-06-05T22:22:01.793Z,1686003721.793 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-06-05T22:22:01.793Z,1686003721.793 [Default:CheckIn](INFO): Running loop #2
2023-06-05T22:22:01.793Z,1686003721.793 [Default:CheckIn] Running Loop=2
2023-06-05T22:22:01.793Z,1686003721.793 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-06-05T22:22:01.793Z,1686003721.793 [Default:CheckIn:Read_GPS] Running Loop=1
2023-06-05T22:24:29.272Z,1686003869.272 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-06-05T22:24:29.272Z,1686003869.272 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T22:24:29.303Z,1686003869.303 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T22:24:29.670Z,1686003869.670 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T22:24:29.670Z,1686003869.670 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-06-05T22:26:28.425Z,1686003988.425 [Sonardyne_Nano](INFO): Command indicated, sending VS
2023-06-05T22:26:28.831Z,1686003988.831 [Sonardyne_Nano](INFO): Received response:>VS:2201,HPR45,EXT,TILT,BT1;LI_ION;VLT4.0;IDC-12.5;CAP3.4/77;T21.6
2023-06-05T22:27:01.972Z,1686004021.972 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-06-05T22:22:01.8Z
2023-06-05T22:27:01.973Z,1686004021.973 [Default:CheckIn:Read_GPS] Stopped
2023-06-05T22:27:01.973Z,1686004021.973 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-06-05T22:27:07.286Z,1686004027.286 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230605T220612/Courier0007.lzma
2023-06-05T22:27:08.288Z,1686004028.288 [DataOverHttps](INFO): Moved sent file to Logs/20230605T220612/Courier0007.lzma.bak
2023-06-05T22:27:08.289Z,1686004028.289 [DataOverHttps](INFO): SBD MOMSN=18398020
2023-06-05T22:27:23.643Z,1686004043.643 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20230605T220612/Express0008.lzma
2023-06-05T22:27:24.644Z,1686004044.644 [DataOverHttps](INFO): Moved sent file to Logs/20230605T220612/Express0008.lzma.bak
2023-06-05T22:27:24.645Z,1686004044.645 [DataOverHttps](INFO): SBD MOMSN=18398023
2023-06-05T22:27:25.801Z,1686004045.801 [Default:CheckIn:Read_Iridium] Stopped
2023-06-05T22:27:25.801Z,1686004045.801 [Default:CheckIn:C.Wait] Running Loop=1
2023-06-05T22:27:25.801Z,1686004045.801 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-06-05T22:27:30.266Z,1686004050.266 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-06-05T22:27:30.266Z,1686004050.266 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-06-05T22:27:30.284Z,1686004050.284 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-06-05T22:27:30.693Z,1686004050.693 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-06-05T22:27:30.693Z,1686004050.693 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-06-05T22:27:48.831Z,1686004068.831 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-06-05T22:27:48.831Z,1686004068.831 [NAL9602] Data Fault, FailCount= 2
2023-06-05T22:27:48.831Z,1686004068.831 [NAL9602](ERROR): Data Fault
2023-06-05T22:27:48.847Z,1686004068.847 [CBIT](ERROR): Data Fault in component: NAL9602
2023-06-05T22:27:49.228Z,1686004069.228 [NAL9602](INFO): Powering down
2023-06-05T22:27:50.052Z,1686004070.052 [CBIT](INFO): Clearing failed state for component NAL9602
2023-06-05T22:27:50.052Z,1686004070.052 [NAL9602] No Fault, FailCount= 2
2023-06-05T22:28:03.708Z,1686004083.708 [CommandExec](IMPORTANT): got command restart system
2023-06-05T22:28:05.811Z,1686004085.811 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-06-05T22:28:05.811Z,1686004085.811 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T22:28:05.811Z,1686004085.811 [CommandExec](INFO): Uninitializing the command executive.
2023-06-05T22:28:05.811Z,1686004085.811 [CommandExec](INFO): Uninitializing the command scheduler.
2023-06-05T22:28:05.812Z,1686004085.812 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-06-05T22:28:05.819Z,1686004085.819 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2023-06-05T22:28:05.819Z,1686004085.819 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-06-05T22:28:05.819Z,1686004085.819 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-05T22:28:05.820Z,1686004085.820 [NavChartDb](INFO): Join timeout helper Thread ID is 2532
2023-06-05T22:28:05.995Z,1686004085.995 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T22:28:05.996Z,1686004085.996 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-06-05T22:28:05.999Z,1686004085.999 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-06-05T22:28:05.999Z,1686004085.999 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-05T22:28:05.999Z,1686004085.999 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2533
2023-06-05T22:28:06.411Z,1686004086.411 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T22:28:06.411Z,1686004086.411 [WetLabsBB2FL](INFO): Powering down
2023-06-05T22:28:06.412Z,1686004086.412 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-06-05T22:28:06.423Z,1686004086.423 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-06-05T22:28:06.423Z,1686004086.423 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-06-05T22:28:06.423Z,1686004086.423 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2534
2023-06-05T22:28:06.499Z,1686004086.499 [CTD_Seabird](INFO): Powering down
2023-06-05T22:28:06.512Z,1686004086.512 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-06-05T22:28:06.512Z,1686004086.512 [CTD