2021-12-14T21:44:44.936Z,1639518284.936 [Supervisor](DEBUG): Initializing supervisor.
2021-12-14T21:44:44.942Z,1639518284.942 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-12-14T21:44:44.942Z,1639518284.942 [SyncHandler](INFO): Protected caller Thread ID is 3517
2021-12-14T21:44:44.943Z,1639518284.943 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-12-14T21:44:44.944Z,1639518284.944 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-12-14T21:44:44.944Z,1639518284.944 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3518
2021-12-14T21:44:44.949Z,1639518284.949 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-12-14T21:44:44.967Z,1639518284.967 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-12-14T21:44:44.968Z,1639518284.968 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-12-14T21:44:44.968Z,1639518284.968 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 3519
2021-12-14T21:44:44.972Z,1639518284.972 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-12-14T21:44:44.973Z,1639518284.973 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-12-14T21:44:44.974Z,1639518284.974 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3520
2021-12-14T21:44:44.976Z,1639518284.976 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-12-14T21:44:44.977Z,1639518284.977 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-12-14T21:44:44.977Z,1639518284.977 [logger ThreadHandler](INFO): Protected caller Thread ID is 3521
2021-12-14T21:44:44.981Z,1639518284.981 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-12-14T21:44:44.981Z,1639518284.981 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-12-14T21:44:44.983Z,1639518284.983 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-12-14T21:44:45.408Z,1639518285.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-12-14T21:44:45.408Z,1639518285.408 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-12-14T21:44:45.620Z,1639518285.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-12-14T21:44:45.621Z,1639518285.621 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-12-14T21:44:45.809Z,1639518285.809 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-12-14T21:44:45.809Z,1639518285.809 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-12-14T21:44:45.918Z,1639518285.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-12-14T21:44:45.919Z,1639518285.919 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-12-14T21:44:46.274Z,1639518286.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-12-14T21:44:46.274Z,1639518286.274 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-12-14T21:44:46.607Z,1639518286.607 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-12-14T21:44:46.607Z,1639518286.607 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-12-14T21:44:46.707Z,1639518286.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-12-14T21:44:46.708Z,1639518286.708 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-12-14T21:44:46.860Z,1639518286.860 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-12-14T21:44:46.860Z,1639518286.860 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-12-14T21:44:47.386Z,1639518287.386 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-12-14T21:44:47.387Z,1639518287.387 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-12-14T21:44:47.749Z,1639518287.749 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-12-14T21:44:47.749Z,1639518287.749 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-12-14T21:44:47.833Z,1639518287.833 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-12-14T21:44:48.090Z,1639518288.090 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-12-14T21:44:48.090Z,1639518288.090 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-12-14T21:44:48.533Z,1639518288.533 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-12-14T21:44:48.533Z,1639518288.533 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-12-14T21:44:49.474Z,1639518289.474 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-12-14T21:44:49.475Z,1639518289.475 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-12-14T21:44:49.557Z,1639518289.557 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-12-14T21:44:49.803Z,1639518289.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-12-14T21:44:49.805Z,1639518289.805 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/
2021-12-14T21:44:49.806Z,1639518289.806 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg
2021-12-14T21:44:49.980Z,1639518289.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg
2021-12-14T21:44:50.077Z,1639518290.077 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg
2021-12-14T21:44:50.192Z,1639518290.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg
2021-12-14T21:44:50.295Z,1639518290.295 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg
2021-12-14T21:44:50.381Z,1639518290.381 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg
2021-12-14T21:44:50.470Z,1639518290.470 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg
2021-12-14T21:44:50.586Z,1639518290.586 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg
2021-12-14T21:44:50.687Z,1639518290.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg
2021-12-14T21:44:50.840Z,1639518290.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg
2021-12-14T21:44:51.104Z,1639518291.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-12-14T21:44:51.104Z,1639518291.104 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg
2021-12-14T21:44:51.202Z,1639518291.202 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/
2021-12-14T21:44:51.202Z,1639518291.202 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2021-12-14T21:44:51.214Z,1639518291.214 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-12-14T21:44:51.535Z,1639518291.535 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-12-14T21:44:51.536Z,1639518291.536 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-12-14T21:44:51.617Z,1639518291.617 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-12-14T21:44:51.617Z,1639518291.617 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-12-14T21:44:51.652Z,1639518291.652 [DeadReckonUsingSpeedCalculator] Loaded
2021-12-14T21:44:51.653Z,1639518291.653 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2021-12-14T21:44:51.665Z,1639518291.665 [NavChart] Loaded
2021-12-14T21:44:51.666Z,1639518291.666 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-12-14T21:44:51.671Z,1639518291.671 [UniversalFixResidualReporter] Loaded
2021-12-14T21:44:51.672Z,1639518291.672 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-12-14T21:44:51.672Z,1639518291.672 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-12-14T21:44:51.673Z,1639518291.673 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-12-14T21:44:51.683Z,1639518291.683 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-12-14T21:44:51.684Z,1639518291.684 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-12-14T21:44:51.879Z,1639518291.879 [CTD_Seabird] Loaded
2021-12-14T21:44:51.879Z,1639518291.879 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-12-14T21:44:51.880Z,1639518291.880 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406514E0
2021-12-14T21:44:51.881Z,1639518291.881 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3603
2021-12-14T21:44:51.900Z,1639518291.900 [PAR_Licor] Loaded
2021-12-14T21:44:51.901Z,1639518291.901 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-12-14T21:44:51.932Z,1639518291.932 [WetLabsBB2FL] Loaded
2021-12-14T21:44:51.932Z,1639518291.932 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-12-14T21:44:51.933Z,1639518291.933 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406814E0
2021-12-14T21:44:51.934Z,1639518291.934 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3604
2021-12-14T21:44:51.934Z,1639518291.934 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-12-14T21:44:51.935Z,1639518291.935 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-12-14T21:44:51.987Z,1639518291.987 [VerticalControl](DEBUG): Construct VerticalControl.
2021-12-14T21:44:52.048Z,1639518292.048 [VerticalControl] Loaded
2021-12-14T21:44:52.048Z,1639518292.048 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-12-14T21:44:52.051Z,1639518292.051 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-12-14T21:44:52.089Z,1639518292.089 [HorizontalControl] Loaded
2021-12-14T21:44:52.089Z,1639518292.089 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-12-14T21:44:52.092Z,1639518292.092 [SpeedControl](DEBUG): Construct SpeedControl.
2021-12-14T21:44:52.095Z,1639518292.095 [SpeedControl] Loaded
2021-12-14T21:44:52.095Z,1639518292.095 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-12-14T21:44:52.098Z,1639518292.098 [LoopControl](DEBUG): Construct LoopControl.
2021-12-14T21:44:52.098Z,1639518292.098 [LoopControl] Loaded
2021-12-14T21:44:52.099Z,1639518292.099 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-12-14T21:44:52.099Z,1639518292.099 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-12-14T21:44:52.100Z,1639518292.100 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-12-14T21:44:52.142Z,1639518292.142 [DepthRateCalculator] Loaded
2021-12-14T21:44:52.142Z,1639518292.142 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-12-14T21:44:52.147Z,1639518292.147 [PitchRateCalculator] Loaded
2021-12-14T21:44:52.147Z,1639518292.147 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-12-14T21:44:52.156Z,1639518292.156 [SpeedCalculator] Loaded
2021-12-14T21:44:52.157Z,1639518292.157 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-12-14T21:44:52.170Z,1639518292.170 [TempGradientCalculator] Loaded
2021-12-14T21:44:52.170Z,1639518292.170 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-12-14T21:44:52.174Z,1639518292.174 [YawRateCalculator] Loaded
2021-12-14T21:44:52.174Z,1639518292.174 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-12-14T21:44:52.192Z,1639518292.192 [ElevatorOffsetCalculator] Loaded
2021-12-14T21:44:52.192Z,1639518292.192 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-12-14T21:44:52.192Z,1639518292.192 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-12-14T21:44:52.193Z,1639518292.193 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-12-14T21:44:52.287Z,1639518292.287 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-12-14T21:44:52.287Z,1639518292.287 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-12-14T21:44:52.345Z,1639518292.345 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-12-14T21:44:52.346Z,1639518292.346 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-12-14T21:44:52.473Z,1639518292.473 [BuoyancyServo] Loaded
2021-12-14T21:44:52.473Z,1639518292.473 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-12-14T21:44:52.493Z,1639518292.493 [ElevatorServo] Loaded
2021-12-14T21:44:52.493Z,1639518292.493 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-12-14T21:44:52.512Z,1639518292.512 [MassServo] Loaded
2021-12-14T21:44:52.512Z,1639518292.512 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-12-14T21:44:52.530Z,1639518292.530 [RudderServo] Loaded
2021-12-14T21:44:52.531Z,1639518292.531 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-12-14T21:44:52.545Z,1639518292.545 [ThrusterHE] Loaded
2021-12-14T21:44:52.546Z,1639518292.546 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2021-12-14T21:44:52.546Z,1639518292.546 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-12-14T21:44:52.547Z,1639518292.547 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-12-14T21:44:52.651Z,1639518292.651 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-12-14T21:44:52.652Z,1639518292.652 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-12-14T21:44:53.038Z,1639518293.038 [AHRS_M2] Loaded
2021-12-14T21:44:53.039Z,1639518293.039 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-12-14T21:44:53.074Z,1639518293.074 [BackseatComponent] Loaded
2021-12-14T21:44:53.075Z,1639518293.075 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2021-12-14T21:44:53.076Z,1639518293.076 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0
2021-12-14T21:44:53.076Z,1639518293.076 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 3605
2021-12-14T21:44:53.079Z,1639518293.079 [LcmUniversalReporter] Loaded
2021-12-14T21:44:53.079Z,1639518293.079 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2021-12-14T21:44:54.288Z,1639518294.288 [BPC1] Loaded
2021-12-14T21:44:54.288Z,1639518294.288 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-12-14T21:44:54.308Z,1639518294.308 [Depth_Keller] Loaded
2021-12-14T21:44:54.308Z,1639518294.308 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-12-14T21:44:54.313Z,1639518294.313 [DropWeight] Loaded
2021-12-14T21:44:54.313Z,1639518294.313 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-12-14T21:44:54.374Z,1639518294.374 [NAL9602] Loaded
2021-12-14T21:44:54.374Z,1639518294.374 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-12-14T21:44:54.404Z,1639518294.404 [Onboard] Loaded
2021-12-14T21:44:54.404Z,1639518294.404 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-12-14T21:44:54.405Z,1639518294.405 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A854E0
2021-12-14T21:44:54.406Z,1639518294.406 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3606
2021-12-14T21:44:54.418Z,1639518294.418 [Power24vConverter] Loaded
2021-12-14T21:44:54.418Z,1639518294.418 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-12-14T21:44:54.432Z,1639518294.432 [Radio_Surface] Loaded
2021-12-14T21:44:54.433Z,1639518294.433 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-12-14T21:44:54.434Z,1639518294.434 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AB54E0
2021-12-14T21:44:54.434Z,1639518294.434 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3607
2021-12-14T21:44:54.518Z,1639518294.518 [DAT] Loaded
2021-12-14T21:44:54.519Z,1639518294.519 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2021-12-14T21:44:54.520Z,1639518294.520 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40AE54E0
2021-12-14T21:44:54.520Z,1639518294.520 [DAT ThreadHandler](INFO): Protected caller Thread ID is 3608
2021-12-14T21:44:54.521Z,1639518294.521 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-12-14T21:44:54.521Z,1639518294.521 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-12-14T21:44:54.668Z,1639518294.668 [SBIT](DEBUG): Construct Startup Built In Test.
2021-12-14T21:44:54.677Z,1639518294.677 [SBIT] Loaded
2021-12-14T21:44:54.677Z,1639518294.677 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-12-14T21:44:54.680Z,1639518294.680 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-12-14T21:44:54.693Z,1639518294.693 [IBIT] Loaded
2021-12-14T21:44:54.693Z,1639518294.693 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-12-14T21:44:54.699Z,1639518294.699 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-12-14T21:44:54.802Z,1639518294.802 [CBIT] Loaded
2021-12-14T21:44:54.802Z,1639518294.802 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-12-14T21:44:54.802Z,1639518294.802 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-12-14T21:44:54.803Z,1639518294.803 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-12-14T21:44:54.831Z,1639518294.831 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-12-14T21:44:54.837Z,1639518294.837 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-12-14T21:44:54.840Z,1639518294.840 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-12-14T21:44:54.850Z,1639518294.850 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-12-14T21:44:54.851Z,1639518294.851 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B704E0
2021-12-14T21:44:54.852Z,1639518294.852 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3609
2021-12-14T21:44:54.856Z,1639518294.856 [Supervisor](INFO): Main Thread ID is 2344
2021-12-14T21:44:54.856Z,1639518294.856 [Supervisor](DEBUG): Running supervisor.
2021-12-14T21:44:54.857Z,1639518294.857 [CommandExec ThreadHandler](INFO): Handler Thread ID is 3610
2021-12-14T21:44:54.857Z,1639518294.857 [CommandExec](INFO): Initializing the command executive.
2021-12-14T21:44:54.859Z,1639518294.859 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3611
2021-12-14T21:44:54.861Z,1639518294.861 [controlThread ThreadHandler](INFO): Handler Thread ID is 3612
2021-12-14T21:44:54.862Z,1639518294.862 [controlThread](DEBUG): Initializing ControlThread
2021-12-14T21:44:54.863Z,1639518294.863 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T21:44:54.864Z,1639518294.864 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-12-14T21:44:54.864Z,1639518294.864 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-12-14T21:44:54.868Z,1639518294.868 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-12-14T21:44:54.870Z,1639518294.870 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-12-14T21:44:54.870Z,1639518294.870 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-12-14T21:44:54.871Z,1639518294.871 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-12-14T21:44:54.871Z,1639518294.871 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-12-14T21:44:54.872Z,1639518294.872 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-12-14T21:44:54.872Z,1639518294.872 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-12-14T21:44:54.872Z,1639518294.872 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-12-14T21:44:54.873Z,1639518294.873 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-12-14T21:44:54.873Z,1639518294.873 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-12-14T21:44:54.880Z,1639518294.880 [logger ThreadHandler](INFO): Handler Thread ID is 3613
2021-12-14T21:44:54.898Z,1639518294.898 [SBIT](INFO): Initialize SBIT Component.
2021-12-14T21:44:54.898Z,1639518294.898 [SBIT](IMPORTANT): git: 2021-11-29_Tethys-86-g5bfe0b35a
2021-12-14T21:44:54.898Z,1639518294.898 [SBIT](INFO): git hash: 5bfe0b35a22e52a1b778416245ca6ed7187545f3
2021-12-14T21:44:54.899Z,1639518294.899 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-12-14T21:44:54.900Z,1639518294.900 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2021-12-14T21:44:54.901Z,1639518294.901 [SBIT](INFO): Beginning SBIT in 40.000000 seconds.
2021-12-14T21:44:54.904Z,1639518294.904 [IBIT](INFO): Initialize IBIT Component.
2021-12-14T21:44:54.905Z,1639518294.905 [CBIT](DEBUG): Initialize CBIT Component.
2021-12-14T21:44:54.906Z,1639518294.906 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3614
2021-12-14T21:44:54.906Z,1639518294.906 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-12-14T21:44:54.915Z,1639518294.915 [CBIT](DEBUG): Initialized mux pins.
2021-12-14T21:44:54.916Z,1639518294.916 [CBIT](DEBUG): Initializing the watchdog timer.
2021-12-14T21:44:54.920Z,1639518294.920 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3616
2021-12-14T21:44:54.924Z,1639518294.924 [WetLabsBB2FL](INFO): Powering up
2021-12-14T21:44:54.925Z,1639518294.925 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 3618
2021-12-14T21:44:54.939Z,1639518294.939 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2021-12-14T21:44:54.940Z,1639518294.940 [CBIT](DEBUG): Initializing heartbeat.
2021-12-14T21:44:54.941Z,1639518294.941 [Onboard ThreadHandler](INFO): Handler Thread ID is 3619
2021-12-14T21:44:54.961Z,1639518294.961 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3620
2021-12-14T21:44:54.972Z,1639518294.972 [DAT ThreadHandler](INFO): Handler Thread ID is 3621
2021-12-14T21:44:54.973Z,1639518294.973 [DAT](INFO): Powering up
2021-12-14T21:44:54.973Z,1639518294.973 [DAT](DEBUG): Initializing DAT.
2021-12-14T21:44:54.976Z,1639518294.976 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3623
2021-12-14T21:44:54.980Z,1639518294.980 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-12-14T21:44:54.980Z,1639518294.980 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-12-14T21:44:54.980Z,1639518294.980 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-12-14T21:44:54.981Z,1639518294.981 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-12-14T21:44:54.981Z,1639518294.981 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-12-14T21:44:54.981Z,1639518294.981 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-12-14T21:44:54.981Z,1639518294.981 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-12-14T21:44:54.981Z,1639518294.981 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-12-14T21:44:54.982Z,1639518294.982 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-12-14T21:44:54.982Z,1639518294.982 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-12-14T21:44:54.982Z,1639518294.982 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-12-14T21:44:54.982Z,1639518294.982 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-12-14T21:44:54.982Z,1639518294.982 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-12-14T21:44:54.983Z,1639518294.983 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-12-14T21:44:54.983Z,1639518294.983 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-12-14T21:44:54.983Z,1639518294.983 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-12-14T21:44:55.011Z,1639518295.011 [CBIT](DEBUG): Deactivating GF circuits.
2021-12-14T21:44:55.012Z,1639518295.012 [CBIT](DEBUG): Deactivating emergency mode.
2021-12-14T21:44:55.047Z,1639518295.047 [CBIT](DEBUG): Backplane powered.
2021-12-14T21:44:55.049Z,1639518295.049 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2021-12-14T21:44:55.062Z,1639518295.062 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-14T21:44:55.081Z,1639518295.081 [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>


2021-12-14T21:44:55.082Z,1639518295.082 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2021-12-14T21:44:55.162Z,1639518295.162 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-12-14T21:44:55.163Z,1639518295.163 [Default:A.Wait](DEBUG): Construct Wait.
2021-12-14T21:44:55.165Z,1639518295.165 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-14T21:44:55.226Z,1639518295.226 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-12-14T21:44:55.229Z,1639518295.229 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-12-14T21:44:55.246Z,1639518295.246 [Default:E.Execute](DEBUG): Construct Execute.
2021-12-14T21:44:55.250Z,1639518295.250 [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="P2H">
                <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>


2021-12-14T21:44:55.265Z,1639518295.265 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2021-12-14T21:44:55.297Z,1639518295.297 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-12-14T21:44:55.364Z,1639518295.364 [Radio_Surface](INFO): Powering up
2021-12-14T21:44:55.365Z,1639518295.365 [Depth_Keller](ERROR): Pressure reading out of range: 815.405518 decibar
2021-12-14T21:44:55.366Z,1639518295.366 [Power24vConverter](INFO): Powering up.
2021-12-14T21:44:55.372Z,1639518295.372 [DepthRateCalculator](ERROR): Depth measurement is not active
2021-12-14T21:44:55.401Z,1639518295.401 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-12-14T21:44:55.408Z,1639518295.408 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-12-14T21:44:55.409Z,1639518295.409 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-12-14T21:44:55.416Z,1639518295.416 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-12-14T21:44:55.417Z,1639518295.417 [MassServo](DEBUG): Initializing EZServoServo.
2021-12-14T21:44:55.432Z,1639518295.432 [MassServo](DEBUG): Initializing MassServo.
2021-12-14T21:44:55.433Z,1639518295.433 [RudderServo](DEBUG): Initializing EZServoServo.
2021-12-14T21:44:55.444Z,1639518295.444 [RudderServo](DEBUG): Initializing RudderServo.
2021-12-14T21:44:55.445Z,1639518295.445 [ThrusterHE](DEBUG): Initializing EZServoServo.
2021-12-14T21:44:55.452Z,1639518295.452 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2021-12-14T21:44:55.699Z,1639518295.699 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2021-12-14T21:44:55.699Z,1639518295.699 [DropWeight] Hardware Fault, FailCount= 1
2021-12-14T21:44:55.699Z,1639518295.699 [DropWeight](ERROR): Hardware Fault
2021-12-14T21:44:55.778Z,1639518295.778 [CommandExec](FAULT): Scheduling is paused
2021-12-14T21:44:55.778Z,1639518295.778 [CBIT](INFO): Critical error at 20211214T214455
2021-12-14T21:44:55.778Z,1639518295.778 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-12-14T21:44:55.781Z,1639518295.781 [CBIT](ERROR): Hardware Fault in component: DropWeight
2021-12-14T21:44:55.782Z,1639518295.782 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2021-12-14T21:44:56.432Z,1639518296.432 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-12-14T21:44:56.432Z,1639518296.432 [RudderServo](FAULT): Rudder failed to initialize
2021-12-14T21:44:56.432Z,1639518296.432 [RudderServo] Communications Fault, FailCount= 1
2021-12-14T21:44:56.432Z,1639518296.432 [RudderServo](ERROR): Communications Fault
2021-12-14T21:44:56.434Z,1639518296.434 [CBIT](INFO): Critical error at 20211214T214455
2021-12-14T21:44:56.436Z,1639518296.436 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-12-14T21:44:56.642Z,1639518296.642 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-12-14T21:44:56.643Z,1639518296.643 [RudderServo](INFO): Powering down
2021-12-14T21:44:57.329Z,1639518297.329 [RudderServo](DEBUG): Initializing EZServoServo.
2021-12-14T21:44:57.449Z,1639518297.449 [RudderServo](DEBUG): Initializing RudderServo.
2021-12-14T21:44:57.453Z,1639518297.453 [CBIT](INFO): Clearing failed state for component RudderServo
2021-12-14T21:44:57.453Z,1639518297.453 [RudderServo] No Fault, FailCount= 1
2021-12-14T21:44:57.540Z,1639518297.540 [WetLabsBB2FL](INFO): Powering down
2021-12-14T21:45:01.936Z,1639518301.936 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-12-14T21:45:06.567Z,1639518306.567 [DAT](INFO): DAT read: 

2021-12-14T21:45:06.568Z,1639518306.568 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2021-12-14T21:45:08.077Z,1639518308.077 [DAT](INFO): DAT read: MF Frequency Band

2021-12-14T21:45:08.078Z,1639518308.078 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2021-12-14T21:45:08.078Z,1639518308.078 [DAT](INFO): DAT read: Dec 14 2021 21:44:34 

2021-12-14T21:45:09.085Z,1639518309.085 [DAT](INFO): DAT read: Features enabled [Bearing]

2021-12-14T21:45:09.086Z,1639518309.086 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2021-12-14T21:45:09.086Z,1639518309.086 [DAT](INFO): commRate: 800
2021-12-14T21:45:11.100Z,1639518311.100 [DAT](INFO): entering command mode
2021-12-14T21:45:11.352Z,1639518311.352 [DAT](INFO): DAT read: 

2021-12-14T21:45:11.352Z,1639518311.352 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:11.604Z,1639518311.604 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:11.856Z,1639518311.856 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:12.108Z,1639518312.108 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:12.360Z,1639518312.360 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:12.612Z,1639518312.612 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:12.864Z,1639518312.864 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:13.116Z,1639518313.116 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:13.368Z,1639518313.368 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:13.620Z,1639518313.620 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:13.872Z,1639518313.872 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:14.124Z,1639518314.124 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:14.376Z,1639518314.376 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:14.628Z,1639518314.628 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:14.880Z,1639518314.880 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:15.132Z,1639518315.132 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:15.384Z,1639518315.384 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:15.636Z,1639518315.636 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:15.888Z,1639518315.888 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:16.140Z,1639518316.140 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:16.392Z,1639518316.392 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:16.644Z,1639518316.644 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:16.896Z,1639518316.896 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:17.148Z,1639518317.148 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:17.400Z,1639518317.400 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:17.652Z,1639518317.652 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:17.904Z,1639518317.904 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:18.156Z,1639518318.156 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:18.408Z,1639518318.408 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:18.660Z,1639518318.660 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:18.912Z,1639518318.912 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:19.164Z,1639518319.164 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:19.416Z,1639518319.416 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:19.668Z,1639518319.668 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:19.920Z,1639518319.920 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:20.172Z,1639518320.172 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:20.424Z,1639518320.424 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:20.676Z,1639518320.676 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:20.928Z,1639518320.928 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:21.180Z,1639518321.180 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:21.432Z,1639518321.432 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:21.684Z,1639518321.684 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:21.936Z,1639518321.936 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:22.188Z,1639518322.188 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:22.440Z,1639518322.440 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:22.692Z,1639518322.692 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:22.944Z,1639518322.944 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:23.177Z,1639518323.177 [CommandExec](IMPORTANT): got command strobe off
2021-12-14T21:45:23.177Z,1639518323.177 [CommandExec](IMPORTANT): Deactivating strobe
2021-12-14T21:45:23.196Z,1639518323.196 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:23.448Z,1639518323.448 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:23.700Z,1639518323.700 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:23.954Z,1639518323.954 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:24.208Z,1639518324.208 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:24.460Z,1639518324.460 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:24.712Z,1639518324.712 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:24.773Z,1639518324.773 [NAL9602](INFO): Powering up NAL9602
2021-12-14T21:45:24.964Z,1639518324.964 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:25.216Z,1639518325.216 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:25.468Z,1639518325.468 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:25.720Z,1639518325.720 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:25.974Z,1639518325.974 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:26.224Z,1639518326.224 [DAT](DEBUG): checking for command mode acknowledgment
2021-12-14T21:45:26.224Z,1639518326.224 [DAT](FAULT): failed to enter command mode
2021-12-14T21:45:26.476Z,1639518326.476 [DAT](INFO): entering command mode
2021-12-14T21:45:26.728Z,1639518326.728 [DAT](INFO): DAT read: user:1>

2021-12-14T21:45:26.729Z,1639518326.729 [DAT](INFO): DAT read: Command '+++' not found

2021-12-14T21:45:26.729Z,1639518326.729 [DAT](INFO): DAT read: Error

2021-12-14T21:45:26.730Z,1639518326.730 [DAT](INFO): setting verbose to 3
2021-12-14T21:45:26.980Z,1639518326.980 [DAT](INFO): DAT read: user:2>

2021-12-14T21:45:26.981Z,1639518326.981 [DAT](INFO): DAT read: Verbose         | 3           

2021-12-14T21:45:26.982Z,1639518326.982 [DAT](INFO): set verbose to 3
2021-12-14T21:45:26.982Z,1639518326.982 [DAT](INFO): setting DatVerbose to 27440
2021-12-14T21:45:27.232Z,1639518327.232 [DAT](INFO): DAT read: user:3>

2021-12-14T21:45:27.233Z,1639518327.233 [DAT](INFO): DAT read: DatVerbose      | 27440       

2021-12-14T21:45:27.233Z,1639518327.233 [DAT](INFO): set DatVerbose to 27440
2021-12-14T21:45:27.234Z,1639518327.234 [DAT](INFO): setting transmit power to 8
2021-12-14T21:45:27.484Z,1639518327.484 [DAT](INFO): DAT read: user:4>

2021-12-14T21:45:27.485Z,1639518327.485 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2021-12-14T21:45:27.486Z,1639518327.486 [DAT](INFO): set transmit power to 8
2021-12-14T21:45:27.486Z,1639518327.486 [DAT](INFO): setting local address to 10
2021-12-14T21:45:27.737Z,1639518327.737 [DAT](INFO): DAT read: user:5>

2021-12-14T21:45:27.738Z,1639518327.738 [DAT](INFO): DAT read: LocalAddr       | 10          

2021-12-14T21:45:27.738Z,1639518327.738 [DAT](INFO): set local address to 10
2021-12-14T21:45:35.324Z,1639518335.324 [SBIT](IMPORTANT): Beginning Startup BIT
2021-12-14T21:45:35.354Z,1639518335.354 [CBIT](IMPORTANT): Beginning ground fault scan
2021-12-14T21:45:35.689Z,1639518335.689 [NAL9602](INFO): NAL9602 initialized
2021-12-14T21:45:46.267Z,1639518346.267 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005571
CHAN A1 (24V): 0.001202
CHAN A2 (12V): -0.004533
CHAN A3 (5V): -0.003052
CHAN B0 (3.3V): -0.001049
CHAN B1 (3.15aV): -0.001700
CHAN B2 (3.15bV): -0.001093
CHAN B3 (GND): -0.000539
OPEN: 0.004643
Full Scale: +/- 1 mA
2021-12-14T21:46:08.461Z,1639518368.461 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T21:46:29.430Z,1639518389.430 [SBIT](IMPORTANT): SBIT PASSED
2021-12-14T21:46:29.431Z,1639518389.431 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): BackseatComponent.needs24v=1 bool;

2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none;

2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): CBIT.gf24Offset=149 microampere;

2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): DAT.sbdAddress=21 enum;

2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): DAT.surfaceThreshold=-2 meter;

2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=0 bool;

2021-12-14T21:46:29.432Z,1639518389.432 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour;

2021-12-14T21:46:29.433Z,1639518389.433 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt;

2021-12-14T21:46:29.433Z,1639518389.433 [SBIT](IMPORTANT): PowerOnly.loadAtStartup=0 bool;

2021-12-14T21:46:29.433Z,1639518389.433 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=126.383040 cubic_centimeter;

2021-12-14T21:46:29.433Z,1639518389.433 [SBIT](IMPORTANT): VerticalControl.massDefault=-5.157439 millimeter;

2021-12-14T21:46:29.841Z,1639518389.841 [MissionManager](IMPORTANT): Started mission Startup
2021-12-14T21:46:29.841Z,1639518389.841 [Startup] Running Loop=1
2021-12-14T21:46:29.841Z,1639518389.841 [Startup](DEBUG): Aggregate::initialize Startup
2021-12-14T21:46:29.841Z,1639518389.841 [Startup:A.GoToSurface] Running Loop=1
2021-12-14T21:46:29.841Z,1639518389.841 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T21:46:29.842Z,1639518389.842 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T21:46:29.842Z,1639518389.842 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T21:46:29.843Z,1639518389.843 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T21:46:29.843Z,1639518389.843 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T21:46:29.844Z,1639518389.844 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T21:46:29.845Z,1639518389.845 [Startup:StartupSatComms] Running Loop=1
2021-12-14T21:46:29.845Z,1639518389.845 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-12-14T21:46:29.845Z,1639518389.845 [Startup:StartupSatComms:A] Running Loop=1
2021-12-14T21:46:30.236Z,1639518390.236 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-12-14T21:47:30.030Z,1639518450.030 [Startup:StartupSatComms:A](INFO): Timed out from 2021-12-14T21:46:29.8Z
2021-12-14T21:47:30.030Z,1639518450.030 [Startup:StartupSatComms:A] Stopped
2021-12-14T21:47:30.030Z,1639518450.030 [Startup:StartupSatComms:B] Running Loop=1
2021-12-14T21:47:30.427Z,1639518450.427 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-12-14T21:47:31.576Z,1639518451.576 [DAT](INFO): #Outgoing data=1
2021-12-14T21:47:31.576Z,1639518451.576 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:47:31.578Z,1639518451.578 [DAT](INFO): setting remote address to 21
2021-12-14T21:47:31.828Z,1639518451.828 [DAT](INFO): DAT read: user:6>

2021-12-14T21:47:31.829Z,1639518451.829 [DAT](INFO): DAT read: RemoteAddr      | 21          

2021-12-14T21:47:31.829Z,1639518451.829 [DAT](INFO): set remote address to 21
2021-12-14T21:47:31.830Z,1639518451.830 [DAT](INFO): entering online mode
2021-12-14T21:47:32.080Z,1639518452.080 [DAT](INFO): DAT read: user:7>

2021-12-14T21:47:32.081Z,1639518452.081 [DAT](INFO): DAT read: 

2021-12-14T21:47:32.082Z,1639518452.082 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2021-12-14T21:47:32.082Z,1639518452.082 [DAT](INFO): commRate: 800
2021-12-14T21:47:32.082Z,1639518452.082 [DAT](INFO): online mode acknowledged
2021-12-14T21:47:32.083Z,1639518452.083 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:47:35.357Z,1639518455.357 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:47:04.2393

2021-12-14T21:47:35.357Z,1639518455.357 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:47:37.001Z,1639518457.001 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T21:47:39.403Z,1639518459.403 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:47:46.452Z,1639518466.452 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:47:46.452Z,1639518466.452 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:47:47.614Z,1639518467.614 [DAT](INFO): #Outgoing data=1
2021-12-14T21:47:47.615Z,1639518467.615 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:47:47.617Z,1639518467.617 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:47:49.106Z,1639518469.106 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T21:47:50.893Z,1639518470.893 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:47:19.7396

2021-12-14T21:47:50.893Z,1639518470.893 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:47:51.124Z,1639518471.124 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:47:54.301Z,1639518474.301 [CommandExec](IMPORTANT): got command show stack
2021-12-14T21:47:54.301Z,1639518474.301 [CommandExec](IMPORTANT): Behavior Stack:

2021-12-14T21:47:54.301Z,1639518474.301 [Startup](IMPORTANT): Priority 0: Startup:A.GoToSurface
2021-12-14T21:47:54.302Z,1639518474.302 [Startup:StartupSatComms](IMPORTANT): Priority 1: Startup:StartupSatComms:B
2021-12-14T21:47:55.163Z,1639518475.163 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-12-14T21:47:55.163Z,1639518475.163 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T21:47:55.164Z,1639518475.164 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2021-12-14T21:47:55.164Z,1639518475.164 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T21:47:55.176Z,1639518475.176 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T21:47:55.176Z,1639518475.176 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T21:47:55.547Z,1639518475.547 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T21:47:55.547Z,1639518475.547 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-12-14T21:47:55.547Z,1639518475.547 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T21:47:55.547Z,1639518475.547 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2021-12-14T21:47:55.949Z,1639518475.949 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T21:48:01.992Z,1639518481.992 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:48:01.992Z,1639518481.992 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:48:03.151Z,1639518483.151 [DAT](INFO): #Outgoing data=2
2021-12-14T21:48:03.151Z,1639518483.151 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:48:03.153Z,1639518483.153 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:48:06.437Z,1639518486.437 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:47:35.2898

2021-12-14T21:48:06.437Z,1639518486.437 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:48:17.524Z,1639518497.524 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:48:17.524Z,1639518497.524 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:48:18.693Z,1639518498.693 [DAT](INFO): #Outgoing data=3
2021-12-14T21:48:18.693Z,1639518498.693 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:48:18.695Z,1639518498.695 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:48:19.020Z,1639518499.020 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T21:48:21.989Z,1639518501.989 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:47:50.7900

2021-12-14T21:48:21.989Z,1639518501.989 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:48:30.273Z,1639518510.273 [Startup:StartupSatComms:B](INFO): Timed out from 2021-12-14T21:47:30.0Z
2021-12-14T21:48:30.273Z,1639518510.273 [Startup:StartupSatComms:B] Stopped
2021-12-14T21:48:30.273Z,1639518510.273 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-12-14T21:48:30.273Z,1639518510.273 [Startup:StartupSatComms] Stopped
2021-12-14T21:48:30.273Z,1639518510.273 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-12-14T21:48:30.274Z,1639518510.274 [Startup](INFO): Completed Startup
2021-12-14T21:48:30.274Z,1639518510.274 [MissionManager](INFO): Startup is completed.
2021-12-14T21:48:30.274Z,1639518510.274 [MissionManager](INFO): Uninitializing Mission Startup
2021-12-14T21:48:30.275Z,1639518510.275 [Startup] Stopped
2021-12-14T21:48:30.275Z,1639518510.275 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-12-14T21:48:30.275Z,1639518510.275 [Startup:A.GoToSurface] Stopped
2021-12-14T21:48:30.275Z,1639518510.275 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T21:48:30.688Z,1639518510.688 [MissionManager](IMPORTANT): Started mission Default
2021-12-14T21:48:30.688Z,1639518510.688 [Default] Running Loop=1
2021-12-14T21:48:30.688Z,1639518510.688 [Default](DEBUG): Aggregate::initialize Default
2021-12-14T21:48:30.688Z,1639518510.688 [Default:B.GoToSurface] Running Loop=1
2021-12-14T21:48:30.688Z,1639518510.688 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T21:48:30.689Z,1639518510.689 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T21:48:30.689Z,1639518510.689 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T21:48:30.689Z,1639518510.689 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T21:48:30.690Z,1639518510.690 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T21:48:30.690Z,1639518510.690 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T21:48:30.690Z,1639518510.690 [Default:A.Wait] Running Loop=1
2021-12-14T21:48:30.690Z,1639518510.690 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-12-14T21:48:33.104Z,1639518513.104 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:48:33.104Z,1639518513.104 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T21:48:33.357Z,1639518513.357 [DAT](INFO): Sent 39 bytes from file Logs/20211214T213152/Courier0007.lzma.parts
2021-12-14T21:48:33.357Z,1639518513.357 [DAT](INFO): Packets left to send: 0
2021-12-14T21:48:33.360Z,1639518513.360 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:48:33.608Z,1639518513.608 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:48:33.860Z,1639518513.860 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:48:35.585Z,1639518515.585 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:48:37.157Z,1639518517.157 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:48:05.9902

2021-12-14T21:48:37.157Z,1639518517.157 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:48:44.003Z,1639518524.003 [Default:A.Wait](INFO): Done Waiting.
2021-12-14T21:48:44.003Z,1639518524.003 [Default:A.Wait] Stopped
2021-12-14T21:48:44.003Z,1639518524.003 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T21:48:44.414Z,1639518524.414 [Default:CheckIn] Running Loop=1
2021-12-14T21:48:44.414Z,1639518524.414 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-14T21:48:44.414Z,1639518524.414 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-14T21:48:44.827Z,1639518524.827 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-12-14T21:48:48.252Z,1639518528.252 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:48:48.252Z,1639518528.252 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T21:48:48.504Z,1639518528.504 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:48:48.756Z,1639518528.756 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:48:49.008Z,1639518529.008 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:48:52.288Z,1639518532.288 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:48:21.1404

2021-12-14T21:48:52.288Z,1639518532.288 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:49:03.380Z,1639518543.380 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:49:03.380Z,1639518543.380 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T21:49:03.624Z,1639518543.624 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:49:03.876Z,1639518543.876 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:49:04.128Z,1639518544.128 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:49:07.405Z,1639518547.405 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:48:36.2406

2021-12-14T21:49:07.405Z,1639518547.405 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:49:18.496Z,1639518558.496 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:49:18.497Z,1639518558.497 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T21:49:18.748Z,1639518558.748 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:49:51.525Z,1639518591.525 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:50:13.524Z,1639518613.524 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T21:50:13.525Z,1639518613.525 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T21:50:13.549Z,1639518613.549 [MissionManager](INFO): DefineArg run_backseat_on_surface.ElapsedSinceMissionStarted = 0.000000 min
2021-12-14T21:50:13.552Z,1639518613.552 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2021-12-14T21:50:13.555Z,1639518613.555 [run_backseat_on_surface:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-14T21:50:13.566Z,1639518613.566 [run_backseat_on_surface:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-12-14T21:50:13.569Z,1639518613.569 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-12-14T21:50:13.616Z,1639518613.616 [run_backseat_on_surface:E.Execute](DEBUG): Construct Execute.
2021-12-14T21:50:13.620Z,1639518613.620 [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="run_backseat_on_surface">

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

    <!-- Power the science payload. -->

    <!-- Insert Filename="Insert/Science.xml" Id="Science"></Insert -->

    <!-- Power the Backseat payload. -->

    <Guidance:BackseatDriver>
        <Parallel/>
    </Guidance:BackseatDriver>

    <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="P2H">
                <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="ElapsedSinceMissionStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

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

    </Aggregate>

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

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

</Mission>


2021-12-14T21:50:13.622Z,1639518613.622 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T21:50:13.701Z,1639518613.701 [Default] Stopped
2021-12-14T21:50:13.701Z,1639518613.701 [Default](DEBUG): Aggregate::uninitialize Default
2021-12-14T21:50:13.701Z,1639518613.701 [Default:B.GoToSurface] Stopped
2021-12-14T21:50:13.701Z,1639518613.701 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T21:50:13.701Z,1639518613.701 [Default:CheckIn] Stopped
2021-12-14T21:50:13.701Z,1639518613.701 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-14T21:50:13.701Z,1639518613.701 [Default:CheckIn:Read_GPS] Stopped
2021-12-14T21:50:13.701Z,1639518613.701 [MissionManager](IMPORTANT): Started mission run_backseat_on_surface
2021-12-14T21:50:13.702Z,1639518613.702 [run_backseat_on_surface] Running Loop=1
2021-12-14T21:50:13.702Z,1639518613.702 [run_backseat_on_surface](DEBUG): Aggregate::initialize run_backseat_on_surface
2021-12-14T21:50:13.702Z,1639518613.702 [run_backseat_on_surface:A.BackseatDriver] Running Loop=1
2021-12-14T21:50:13.702Z,1639518613.702 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Initialize.
2021-12-14T21:50:13.752Z,1639518613.752 [run_backseat_on_surface:B.GoToSurface] Running Loop=1
2021-12-14T21:50:13.752Z,1639518613.752 [run_backseat_on_surface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T21:50:13.753Z,1639518613.753 [run_backseat_on_surface:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T21:50:13.753Z,1639518613.753 [run_backseat_on_surface:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T21:50:13.753Z,1639518613.753 [run_backseat_on_surface:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T21:50:13.754Z,1639518613.754 [run_backseat_on_surface:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T21:50:13.754Z,1639518613.754 [run_backseat_on_surface:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T21:50:13.755Z,1639518613.755 [run_backseat_on_surface:CheckIn] Running Loop=1
2021-12-14T21:50:13.755Z,1639518613.755 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2021-12-14T21:50:13.759Z,1639518613.759 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2021-12-14T21:50:13.760Z,1639518613.760 [run_backseat_on_surface:A.BackseatDriver] Running Loop=1
2021-12-14T21:50:13.892Z,1639518613.892 [BackseatComponent](INFO): Powering up
2021-12-14T21:50:13.892Z,1639518613.892 [BackseatComponent](INFO): Subscribing to LCM channels.
2021-12-14T21:50:14.104Z,1639518614.104 [run_backseat_on_surface:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-12-14T21:50:21.422Z,1639518621.422 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:50:30.330Z,1639518630.330 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T21:50:35.977Z,1639518635.977 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:50:38.745Z,1639518638.745 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2021-12-14T21:50:49.327Z,1639518649.327 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:50:56.113Z,1639518656.113 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2021-12-14T21:50:56.113Z,1639518656.113 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T21:50:56.115Z,1639518656.115 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2021-12-14T21:50:56.115Z,1639518656.115 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T21:50:56.128Z,1639518656.128 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T21:50:56.129Z,1639518656.129 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T21:50:56.532Z,1639518656.532 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T21:50:56.533Z,1639518656.533 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2021-12-14T21:50:56.533Z,1639518656.533 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T21:50:56.533Z,1639518656.533 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2021-12-14T21:50:56.934Z,1639518656.934 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T21:51:01.013Z,1639518661.013 [run_backseat_on_surface:A.BackseatDriver](INFO): Created data writer for _.ayeris_disk_space with code: 1755
2021-12-14T21:51:01.015Z,1639518661.015 [run_backseat_on_surface:A.BackseatDriver](INFO): Created data writer for _.ayeris_particle_counts with code: 1756
2021-12-14T21:51:01.018Z,1639518661.018 [run_backseat_on_surface:A.BackseatDriver](INFO): Created data writer for _.ayeris_particle_size with code: 1757
2021-12-14T21:51:03.443Z,1639518663.443 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:51:28.230Z,1639518688.230 [BackseatComponent](IMPORTANT): calanus: Running eyeris backseat app. Logging to: 20211214T215118
2021-12-14T21:51:45.225Z,1639518705.225 [BackseatComponent](INFO): Created data reader for Depth_Keller.enableBroadcast with code: 1628
2021-12-14T21:51:45.225Z,1639518705.225 [BackseatComponent](INFO): Requesting data from Depth_Keller.enableBroadcast (1628). Requested size is: 1
2021-12-14T21:51:45.226Z,1639518705.226 [BackseatComponent](INFO): Created universal data reader for depth with code: 6
2021-12-14T21:51:45.227Z,1639518705.227 [BackseatComponent](INFO): Requesting data from depth (6). Requested size is: 2
2021-12-14T21:51:45.407Z,1639518705.407 [Depth_Keller](ERROR): Failed to copy Depth_Keller.enableBroadcast's data value to LCM message.
2021-12-14T21:51:45.408Z,1639518705.408 [Depth_Keller](INFO): Activating messaging.
2021-12-14T21:52:03.776Z,1639518723.776 [CommandExec](IMPORTANT): got command stop
2021-12-14T21:52:03.777Z,1639518723.777 [CommandExec](IMPORTANT): Scheduling is paused
2021-12-14T21:52:03.777Z,1639518723.777 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2021-12-14T21:52:04.048Z,1639518724.048 [MissionManager](INFO): MissionManager is completed.
2021-12-14T21:52:04.048Z,1639518724.048 [MissionManager](INFO): Uninitializing Mission run_backseat_on_surface
2021-12-14T21:52:04.048Z,1639518724.048 [run_backseat_on_surface] Stopped
2021-12-14T21:52:04.048Z,1639518724.048 [run_backseat_on_surface](DEBUG): Aggregate::uninitialize run_backseat_on_surface
2021-12-14T21:52:04.048Z,1639518724.048 [run_backseat_on_surface:A.BackseatDriver] Stopped
2021-12-14T21:52:04.048Z,1639518724.048 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Uninitialize.
2021-12-14T21:52:04.048Z,1639518724.048 [run_backseat_on_surface:B.GoToSurface] Stopped
2021-12-14T21:52:04.049Z,1639518724.049 [run_backseat_on_surface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T21:52:04.049Z,1639518724.049 [run_backseat_on_surface:CheckIn] Stopped
2021-12-14T21:52:04.049Z,1639518724.049 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2021-12-14T21:52:04.049Z,1639518724.049 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2021-12-14T21:52:04.520Z,1639518724.520 [MissionManager](IMPORTANT): Started mission Default
2021-12-14T21:52:04.520Z,1639518724.520 [Default] Running Loop=1
2021-12-14T21:52:04.521Z,1639518724.521 [Default](DEBUG): Aggregate::initialize Default
2021-12-14T21:52:04.521Z,1639518724.521 [Default:B.GoToSurface] Running Loop=1
2021-12-14T21:52:04.521Z,1639518724.521 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T21:52:04.521Z,1639518724.521 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T21:52:04.521Z,1639518724.521 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T21:52:04.522Z,1639518724.522 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T21:52:04.522Z,1639518724.522 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T21:52:04.522Z,1639518724.522 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T21:52:04.523Z,1639518724.523 [Default:A.Wait] Running Loop=1
2021-12-14T21:52:04.523Z,1639518724.523 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-12-14T21:52:05.778Z,1639518725.778 [BackseatComponent](INFO): Sent LCM shutdown request.
2021-12-14T21:52:17.734Z,1639518737.734 [Default:A.Wait](INFO): Done Waiting.
2021-12-14T21:52:17.735Z,1639518737.735 [Default:A.Wait] Stopped
2021-12-14T21:52:17.735Z,1639518737.735 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T21:52:18.161Z,1639518738.161 [Default:CheckIn] Running Loop=1
2021-12-14T21:52:18.161Z,1639518738.161 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-14T21:52:18.161Z,1639518738.161 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-14T21:52:18.635Z,1639518738.635 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:52:20.892Z,1639518740.892 [BackseatComponent](INFO): Powering down and starting shutdown timer (15.00 sec).
2021-12-14T21:52:20.893Z,1639518740.893 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2021-12-14T21:52:20.893Z,1639518740.893 [LcmUniversalReporter](INFO): Deactivating messaging.
2021-12-14T21:52:20.976Z,1639518740.976 [Depth_Keller](INFO): Deactivating messaging.
2021-12-14T21:52:47.684Z,1639518767.684 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:53:15.148Z,1639518795.148 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T21:53:27.257Z,1639518807.257 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-12-14T21:53:28.773Z,1639518808.773 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T21:53:28.773Z,1639518808.773 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T21:53:28.796Z,1639518808.796 [MissionManager](INFO): DefineArg run_backseat_on_surface.ElapsedSinceMissionStarted = 0.000000 min
2021-12-14T21:53:28.798Z,1639518808.798 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2021-12-14T21:53:28.801Z,1639518808.801 [run_backseat_on_surface:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-12-14T21:53:28.857Z,1639518808.857 [run_backseat_on_surface:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-12-14T21:53:28.859Z,1639518808.859 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-12-14T21:53:28.883Z,1639518808.883 [run_backseat_on_surface:E.Execute](DEBUG): Construct Execute.
2021-12-14T21:53:28.886Z,1639518808.886 [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="run_backseat_on_surface">

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

    <!-- Power the science payload. -->

    <!-- Insert Filename="Insert/Science.xml" Id="Science"></Insert -->

    <!-- Power the Backseat payload. -->

    <Guidance:BackseatDriver>
        <Parallel/>
    </Guidance:BackseatDriver>

    <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="P2H">
                <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="ElapsedSinceMissionStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

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

    </Aggregate>

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

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

</Mission>


2021-12-14T21:53:28.890Z,1639518808.890 [Default] Stopped
2021-12-14T21:53:28.890Z,1639518808.890 [Default](DEBUG): Aggregate::uninitialize Default
2021-12-14T21:53:28.890Z,1639518808.890 [Default:B.GoToSurface] Stopped
2021-12-14T21:53:28.890Z,1639518808.890 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T21:53:28.890Z,1639518808.890 [Default:CheckIn] Stopped
2021-12-14T21:53:28.890Z,1639518808.890 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-14T21:53:28.890Z,1639518808.890 [Default:CheckIn:Read_GPS] Stopped
2021-12-14T21:53:28.891Z,1639518808.891 [MissionManager](IMPORTANT): Started mission run_backseat_on_surface
2021-12-14T21:53:28.891Z,1639518808.891 [run_backseat_on_surface] Running Loop=1
2021-12-14T21:53:28.891Z,1639518808.891 [run_backseat_on_surface](DEBUG): Aggregate::initialize run_backseat_on_surface
2021-12-14T21:53:28.891Z,1639518808.891 [run_backseat_on_surface:A.BackseatDriver] Running Loop=1
2021-12-14T21:53:28.891Z,1639518808.891 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Initialize.
2021-12-14T21:53:28.896Z,1639518808.896 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/run_backseat_on_surface.xml
2021-12-14T21:53:28.912Z,1639518808.912 [run_backseat_on_surface:B.GoToSurface] Running Loop=1
2021-12-14T21:53:28.912Z,1639518808.912 [run_backseat_on_surface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T21:53:28.912Z,1639518808.912 [run_backseat_on_surface:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T21:53:28.912Z,1639518808.912 [run_backseat_on_surface:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T21:53:28.913Z,1639518808.913 [run_backseat_on_surface:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T21:53:28.913Z,1639518808.913 [run_backseat_on_surface:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T21:53:28.913Z,1639518808.913 [run_backseat_on_surface:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T21:53:28.915Z,1639518808.915 [run_backseat_on_surface:CheckIn] Running Loop=1
2021-12-14T21:53:28.915Z,1639518808.915 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2021-12-14T21:53:28.915Z,1639518808.915 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2021-12-14T21:53:28.915Z,1639518808.915 [run_backseat_on_surface:A.BackseatDriver] Running Loop=1
2021-12-14T21:53:28.924Z,1639518808.924 [BackseatComponent](INFO): Powering up
2021-12-14T21:53:28.924Z,1639518808.924 [BackseatComponent](INFO): Subscribing to LCM channels.
2021-12-14T21:53:29.256Z,1639518809.256 [run_backseat_on_surface:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2021-12-14T21:53:32.518Z,1639518812.518 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-12-14T21:53:41.757Z,1639518821.757 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2021-12-14T21:53:41.761Z,1639518821.761 [BPC1](INFO): Received data from all battery sticks.
2021-12-14T21:53:57.113Z,1639518837.113 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2021-12-14T21:53:57.113Z,1639518837.113 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T21:53:57.114Z,1639518837.114 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2021-12-14T21:53:57.114Z,1639518837.114 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T21:53:57.129Z,1639518837.129 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T21:53:57.129Z,1639518837.129 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T21:53:57.528Z,1639518837.528 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T21:53:57.529Z,1639518837.529 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2021-12-14T21:53:57.529Z,1639518837.529 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T21:53:57.529Z,1639518837.529 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2021-12-14T21:53:57.919Z,1639518837.919 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T21:54:18.930Z,1639518858.930 [run_backseat_on_surface:A.BackseatDriver](INFO): Created data writer for _.ayeris_disk_space with code: 1755
2021-12-14T21:54:18.931Z,1639518858.931 [run_backseat_on_surface:A.BackseatDriver](INFO): Created data writer for _.ayeris_particle_counts with code: 1756
2021-12-14T21:54:18.933Z,1639518858.933 [run_backseat_on_surface:A.BackseatDriver](INFO): Created data writer for _.ayeris_particle_size with code: 1757
2021-12-14T21:54:50.329Z,1639518890.329 [BackseatComponent](IMPORTANT): calanus: Running eyeris backseat app. Logging to: 20211214T215436
2021-12-14T21:55:07.801Z,1639518907.801 [Depth_Keller](ERROR): Failed to copy Depth_Keller.enableBroadcast's data value to LCM message.
2021-12-14T21:55:07.801Z,1639518907.801 [Depth_Keller](INFO): Activating messaging.
2021-12-14T21:55:36.900Z,1639518936.900 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-12-14T21:55:36.900Z,1639518936.900 [NAL9602] Data Fault, FailCount= 1
2021-12-14T21:55:36.900Z,1639518936.900 [NAL9602](ERROR): Data Fault
2021-12-14T21:55:36.970Z,1639518936.970 [CBIT](ERROR): Data Fault in component: NAL9602
2021-12-14T21:55:37.308Z,1639518937.308 [NAL9602](INFO): Powering down
2021-12-14T21:55:38.145Z,1639518938.145 [CBIT](INFO): Clearing failed state for component NAL9602
2021-12-14T21:55:38.145Z,1639518938.145 [NAL9602] No Fault, FailCount= 1
2021-12-14T21:56:04.341Z,1639518964.341 [CommandExec](IMPORTANT): got command failComponent hardware BackseatComponent
2021-12-14T21:56:04.343Z,1639518964.343 [BackseatComponent] Hardware Fault, FailCount= 1
2021-12-14T21:56:04.343Z,1639518964.343 [BackseatComponent](ERROR): Hardware Fault
2021-12-14T21:56:04.343Z,1639518964.343 [CommandExec](IMPORTANT): BackseatComponent failureMode is Hardware Fault
2021-12-14T21:56:04.449Z,1639518964.449 [CBIT](ERROR): Hardware Fault in component: BackseatComponent
2021-12-14T21:56:05.340Z,1639518965.340 [BackseatComponent](INFO): Sent LCM shutdown request.
2021-12-14T21:56:07.612Z,1639518967.612 [NAL9602](INFO): Powering up NAL9602
2021-12-14T21:56:18.519Z,1639518978.519 [NAL9602](INFO): NAL9602 initialized
2021-12-14T21:56:20.692Z,1639518980.692 [BackseatComponent](INFO): Powering down and starting shutdown timer (15.00 sec).
2021-12-14T21:56:20.693Z,1639518980.693 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2021-12-14T21:56:20.693Z,1639518980.693 [LcmUniversalReporter](INFO): Deactivating messaging.
2021-12-14T21:56:20.928Z,1639518980.928 [Depth_Keller](INFO): Deactivating messaging.
2021-12-14T21:56:36.448Z,1639518996.448 [BackseatComponent](INFO): Powering up
2021-12-14T21:56:36.448Z,1639518996.448 [BackseatComponent](INFO): Subscribing to LCM channels.
2021-12-14T21:56:36.720Z,1639518996.720 [CBIT](INFO): Clearing failed state for component BackseatComponent
2021-12-14T21:56:36.721Z,1639518996.721 [BackseatComponent] No Fault, FailCount= 1
2021-12-14T21:56:58.100Z,1639519018.100 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2021-12-14T21:56:58.100Z,1639519018.100 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T21:56:58.101Z,1639519018.101 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2021-12-14T21:56:58.101Z,1639519018.101 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T21:56:58.149Z,1639519018.149 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T21:56:58.149Z,1639519018.149 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T21:56:58.553Z,1639519018.553 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T21:56:58.553Z,1639519018.553 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2021-12-14T21:56:58.553Z,1639519018.553 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T21:56:58.554Z,1639519018.554 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2021-12-14T21:56:58.932Z,1639519018.932 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T21:58:28.997Z,1639519108.997 [run_backseat_on_surface:CheckIn:Read_GPS](INFO): Timed out from 2021-12-14T21:53:28.9Z
2021-12-14T21:58:28.998Z,1639519108.998 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2021-12-14T21:58:28.998Z,1639519108.998 [run_backseat_on_surface:CheckIn:Read_Iridium] Running Loop=1
2021-12-14T21:58:29.419Z,1639519109.419 [run_backseat_on_surface:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-12-14T21:58:30.574Z,1639519110.574 [DAT](INFO): #Outgoing data=1
2021-12-14T21:58:30.575Z,1639519110.575 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:58:30.577Z,1639519110.577 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:58:33.857Z,1639519113.857 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:58:02.5500

2021-12-14T21:58:33.857Z,1639519113.857 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:58:50.000Z,1639519131.000 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:58:51.000Z,1639519131.000 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T21:58:51.252Z,1639519131.252 [DAT](INFO): Sent 244 bytes from file Logs/20211214T214444/Courier0000.lzma.parts
2021-12-14T21:58:51.252Z,1639519131.252 [DAT](INFO): Packets left to send: 0
2021-12-14T21:58:51.255Z,1639519131.255 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:58:52.405Z,1639519132.405 [DAT](INFO): #Outgoing data=1
2021-12-14T21:58:52.405Z,1639519132.405 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T21:58:52.407Z,1639519132.407 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T21:58:55.685Z,1639519135.685 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:58:24.3990

2021-12-14T21:58:55.685Z,1639519135.685 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T21:59:09.508Z,1639519149.508 [BackseatComponent](IMPORTANT): calanus: Running eyeris backseat app. Logging to: 20211214T215857
2021-12-14T21:59:10.808Z,1639519150.808 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T21:59:10.808Z,1639519150.808 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T21:59:11.060Z,1639519151.060 [DAT](INFO): Sent 169 bytes from file Logs/20211214T214444/Courier0004.lzma.parts
2021-12-14T21:59:11.060Z,1639519151.060 [DAT](INFO): Packets left to send: 0
2021-12-14T21:59:11.063Z,1639519151.063 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T21:59:14.400Z,1639519154.400 [run_backseat_on_surface:CheckIn:Read_Iridium] Stopped
2021-12-14T21:59:14.400Z,1639519154.400 [run_backseat_on_surface:CheckIn:C.Wait] Running Loop=1
2021-12-14T21:59:14.400Z,1639519154.400 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-14T21:59:26.560Z,1639519166.560 [Depth_Keller](ERROR): Failed to copy Depth_Keller.enableBroadcast's data value to LCM message.
2021-12-14T21:59:26.560Z,1639519166.560 [Depth_Keller](INFO): Activating messaging.
2021-12-14T21:59:56.097Z,1639519196.097 [CBIT](INFO): Clearing failed state for component DropWeight
2021-12-14T21:59:56.097Z,1639519196.097 [DropWeight] No Fault, FailCount= 1
2021-12-14T21:59:59.326Z,1639519199.326 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2021-12-14T21:59:59.327Z,1639519199.327 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T21:59:59.328Z,1639519199.328 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2021-12-14T21:59:59.328Z,1639519199.328 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T21:59:59.341Z,1639519199.341 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T21:59:59.341Z,1639519199.341 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T21:59:59.747Z,1639519199.747 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T21:59:59.747Z,1639519199.747 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2021-12-14T21:59:59.748Z,1639519199.748 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T21:59:59.748Z,1639519199.748 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2021-12-14T22:00:00.126Z,1639519200.126 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:03:00.329Z,1639519380.329 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2021-12-14T22:03:00.329Z,1639519380.329 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:03:00.330Z,1639519380.330 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2021-12-14T22:03:00.330Z,1639519380.330 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:03:00.345Z,1639519380.345 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:03:00.345Z,1639519380.345 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:03:00.760Z,1639519380.760 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:03:00.761Z,1639519380.761 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2021-12-14T22:03:00.761Z,1639519380.761 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:03:00.761Z,1639519380.761 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2021-12-14T22:03:01.135Z,1639519381.135 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:04:14.691Z,1639519454.691 [run_backseat_on_surface:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-14T22:04:14.691Z,1639519454.691 [run_backseat_on_surface:CheckIn:C.Wait] Stopped
2021-12-14T22:04:14.691Z,1639519454.691 [run_backseat_on_surface:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T22:04:14.692Z,1639519454.692 [run_backseat_on_surface:CheckIn:D] Running Loop=1
2021-12-14T22:04:15.079Z,1639519455.079 [run_backseat_on_surface:CheckIn:D] Stopped
2021-12-14T22:04:15.079Z,1639519455.079 [run_backseat_on_surface:CheckIn:E] Running Loop=1
2021-12-14T22:04:15.510Z,1639519455.510 [run_backseat_on_surface:CheckIn:E](IMPORTANT): run_backseat_on_surface mission has been running for 10.769794 min 
2021-12-14T22:04:15.510Z,1639519455.510 [run_backseat_on_surface:CheckIn:E] Stopped
2021-12-14T22:04:15.511Z,1639519455.511 [run_backseat_on_surface:CheckIn](INFO): Completed run_backseat_on_surface:CheckIn
2021-12-14T22:04:15.511Z,1639519455.511 [run_backseat_on_surface:CheckIn] Stopped
2021-12-14T22:04:15.511Z,1639519455.511 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2021-12-14T22:04:15.511Z,1639519455.511 [run_backseat_on_surface:CheckIn](INFO): Running loop #2
2021-12-14T22:04:15.511Z,1639519455.511 [run_backseat_on_surface:CheckIn] Running Loop=2
2021-12-14T22:04:15.511Z,1639519455.511 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::initialize run_backseat_on_surface:CheckIn
2021-12-14T22:04:15.512Z,1639519455.512 [run_backseat_on_surface:CheckIn:Read_GPS] Running Loop=1
2021-12-14T22:05:08.706Z,1639519508.706 [CommandExec](IMPORTANT): got command failComponent hardware BackseatComponent
2021-12-14T22:05:08.706Z,1639519508.706 [BackseatComponent] Hardware Fault, FailCount= 1
2021-12-14T22:05:08.706Z,1639519508.706 [BackseatComponent](ERROR): Hardware Fault
2021-12-14T22:05:08.706Z,1639519508.706 [CommandExec](IMPORTANT): BackseatComponent failureMode is Hardware Fault
2021-12-14T22:05:08.872Z,1639519508.872 [CBIT](ERROR): Hardware Fault in component: BackseatComponent
2021-12-14T22:05:10.896Z,1639519510.896 [BackseatComponent](INFO): Sent LCM shutdown request.
2021-12-14T22:05:26.260Z,1639519526.260 [BackseatComponent](INFO): Powering down and starting shutdown timer (15.00 sec).
2021-12-14T22:05:26.261Z,1639519526.261 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2021-12-14T22:05:26.261Z,1639519526.261 [LcmUniversalReporter](INFO): Deactivating messaging.
2021-12-14T22:05:26.556Z,1639519526.556 [Depth_Keller](INFO): Deactivating messaging.
2021-12-14T22:05:42.016Z,1639519542.016 [BackseatComponent](INFO): Powering up
2021-12-14T22:05:42.016Z,1639519542.016 [BackseatComponent](INFO): Subscribing to LCM channels.
2021-12-14T22:05:42.352Z,1639519542.352 [CBIT](INFO): Clearing failed state for component BackseatComponent
2021-12-14T22:05:42.353Z,1639519542.353 [BackseatComponent] No Fault, FailCount= 1
2021-12-14T22:06:01.300Z,1639519561.300 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2021-12-14T22:06:01.301Z,1639519561.301 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:06:01.302Z,1639519561.302 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2021-12-14T22:06:01.302Z,1639519561.302 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:06:01.316Z,1639519561.316 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:06:01.317Z,1639519561.317 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:06:01.732Z,1639519561.732 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:06:01.733Z,1639519561.733 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2021-12-14T22:06:01.733Z,1639519561.733 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:06:01.733Z,1639519561.733 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2021-12-14T22:06:02.128Z,1639519562.128 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:06:20.704Z,1639519580.704 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-12-14T22:06:20.704Z,1639519580.704 [NAL9602] Data Fault, FailCount= 2
2021-12-14T22:06:20.704Z,1639519580.704 [NAL9602](ERROR): Data Fault
2021-12-14T22:06:20.756Z,1639519580.756 [CBIT](ERROR): Data Fault in component: NAL9602
2021-12-14T22:06:21.097Z,1639519581.097 [NAL9602](INFO): Powering down
2021-12-14T22:06:21.932Z,1639519581.932 [CBIT](INFO): Clearing failed state for component NAL9602
2021-12-14T22:06:21.932Z,1639519581.932 [NAL9602] No Fault, FailCount= 2
2021-12-14T22:06:51.413Z,1639519611.413 [NAL9602](INFO): Powering up NAL9602
2021-12-14T22:07:02.312Z,1639519622.312 [NAL9602](INFO): NAL9602 initialized
2021-12-14T22:07:07.489Z,1639519627.489 [CommandExec](IMPORTANT): got command stop
2021-12-14T22:07:07.489Z,1639519627.489 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2021-12-14T22:07:07.576Z,1639519627.576 [MissionManager](INFO): MissionManager is completed.
2021-12-14T22:07:07.576Z,1639519627.576 [MissionManager](INFO): Uninitializing Mission run_backseat_on_surface
2021-12-14T22:07:07.576Z,1639519627.576 [run_backseat_on_surface] Stopped
2021-12-14T22:07:07.576Z,1639519627.576 [run_backseat_on_surface](DEBUG): Aggregate::uninitialize run_backseat_on_surface
2021-12-14T22:07:07.576Z,1639519627.576 [run_backseat_on_surface:A.BackseatDriver] Stopped
2021-12-14T22:07:07.576Z,1639519627.576 [run_backseat_on_surface:A.BackseatDriver](DEBUG): Uninitialize.
2021-12-14T22:07:07.576Z,1639519627.576 [run_backseat_on_surface:B.GoToSurface] Stopped
2021-12-14T22:07:07.576Z,1639519627.576 [run_backseat_on_surface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T22:07:07.577Z,1639519627.577 [run_backseat_on_surface:CheckIn] Stopped
2021-12-14T22:07:07.577Z,1639519627.577 [run_backseat_on_surface:CheckIn](DEBUG): Aggregate::uninitialize run_backseat_on_surface:CheckIn
2021-12-14T22:07:07.577Z,1639519627.577 [run_backseat_on_surface:CheckIn:Read_GPS] Stopped
2021-12-14T22:07:07.969Z,1639519627.969 [MissionManager](IMPORTANT): Started mission Default
2021-12-14T22:07:07.969Z,1639519627.969 [Default] Running Loop=1
2021-12-14T22:07:07.969Z,1639519627.969 [Default](DEBUG): Aggregate::initialize Default
2021-12-14T22:07:07.969Z,1639519627.969 [Default:B.GoToSurface] Running Loop=1
2021-12-14T22:07:07.969Z,1639519627.969 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-12-14T22:07:07.969Z,1639519627.969 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-12-14T22:07:07.970Z,1639519627.970 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-12-14T22:07:07.970Z,1639519627.970 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-12-14T22:07:07.970Z,1639519627.970 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-12-14T22:07:07.971Z,1639519627.971 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-12-14T22:07:07.971Z,1639519627.971 [Default:A.Wait] Running Loop=1
2021-12-14T22:07:07.972Z,1639519627.972 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-12-14T22:07:09.840Z,1639519629.840 [BackseatComponent](INFO): Sent LCM shutdown request.
2021-12-14T22:07:21.333Z,1639519641.333 [Default:A.Wait](INFO): Done Waiting.
2021-12-14T22:07:21.334Z,1639519641.334 [Default:A.Wait] Stopped
2021-12-14T22:07:21.334Z,1639519641.334 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T22:07:21.723Z,1639519641.723 [Default:CheckIn] Running Loop=1
2021-12-14T22:07:21.723Z,1639519641.723 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-14T22:07:21.723Z,1639519641.723 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-14T22:07:24.932Z,1639519644.932 [BackseatComponent](INFO): Powering down and starting shutdown timer (15.00 sec).
2021-12-14T22:07:24.933Z,1639519644.933 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2021-12-14T22:07:24.933Z,1639519644.933 [LcmUniversalReporter](INFO): Deactivating messaging.
2021-12-14T22:09:02.322Z,1639519742.322 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2021-12-14T22:09:02.322Z,1639519742.322 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:09:02.323Z,1639519742.323 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2021-12-14T22:09:02.323Z,1639519742.323 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:09:02.334Z,1639519742.334 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:09:02.334Z,1639519742.334 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:09:02.731Z,1639519742.731 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:09:02.731Z,1639519742.731 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2021-12-14T22:09:02.731Z,1639519742.731 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:09:02.732Z,1639519742.732 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2021-12-14T22:09:03.100Z,1639519743.100 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:12:03.313Z,1639519923.313 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2021-12-14T22:12:03.313Z,1639519923.313 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:12:03.314Z,1639519923.314 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2021-12-14T22:12:03.314Z,1639519923.314 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:12:03.330Z,1639519923.330 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:12:03.330Z,1639519923.330 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:12:03.727Z,1639519923.727 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:12:03.727Z,1639519923.727 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2021-12-14T22:12:03.728Z,1639519923.728 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:12:03.728Z,1639519923.728 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2021-12-14T22:12:04.096Z,1639519924.096 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:12:21.888Z,1639519941.888 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-14T22:07:21.7Z
2021-12-14T22:12:21.889Z,1639519941.889 [Default:CheckIn:Read_GPS] Stopped
2021-12-14T22:12:21.889Z,1639519941.889 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-14T22:12:22.282Z,1639519942.282 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-12-14T22:12:23.392Z,1639519943.392 [DAT](INFO): #Outgoing data=1
2021-12-14T22:12:23.393Z,1639519943.393 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T22:12:23.395Z,1639519943.395 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T22:12:26.673Z,1639519946.673 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:11:55.1617

2021-12-14T22:12:26.673Z,1639519946.673 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T22:12:37.772Z,1639519957.772 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T22:12:37.772Z,1639519957.772 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T22:12:38.024Z,1639519958.024 [DAT](INFO): Sent 39 bytes from file Logs/20211214T214444/Courier0007.lzma.parts
2021-12-14T22:12:38.025Z,1639519958.025 [DAT](INFO): Packets left to send: 0
2021-12-14T22:12:38.027Z,1639519958.027 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T22:12:39.956Z,1639519959.956 [Default:CheckIn:Read_Iridium] Stopped
2021-12-14T22:12:39.956Z,1639519959.956 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-14T22:12:39.956Z,1639519959.956 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-14T22:15:04.257Z,1639520104.257 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2021-12-14T22:15:04.257Z,1639520104.257 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:15:04.258Z,1639520104.258 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2021-12-14T22:15:04.258Z,1639520104.258 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:15:04.270Z,1639520104.270 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:15:04.270Z,1639520104.270 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:15:04.664Z,1639520104.664 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:15:04.665Z,1639520104.665 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2021-12-14T22:15:04.665Z,1639520104.665 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:15:04.665Z,1639520104.665 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2021-12-14T22:15:05.044Z,1639520105.044 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:17:05.426Z,1639520225.426 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-12-14T22:17:05.427Z,1639520225.427 [NAL9602] Data Fault, FailCount= 3
2021-12-14T22:17:05.427Z,1639520225.427 [NAL9602](ERROR): Data Fault
2021-12-14T22:17:05.473Z,1639520225.473 [CBIT](ERROR): Data Fault in component: NAL9602
2021-12-14T22:17:05.829Z,1639520225.829 [NAL9602](INFO): Powering down
2021-12-14T22:17:06.666Z,1639520226.666 [CBIT](INFO): Clearing failed state for component NAL9602
2021-12-14T22:17:06.666Z,1639520226.666 [NAL9602] No Fault, FailCount= 3
2021-12-14T22:17:36.126Z,1639520256.126 [NAL9602](INFO): Powering up NAL9602
2021-12-14T22:17:40.186Z,1639520260.186 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-14T22:17:40.186Z,1639520260.186 [Default:CheckIn:C.Wait] Stopped
2021-12-14T22:17:40.186Z,1639520260.186 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T22:17:40.186Z,1639520260.186 [Default:CheckIn:D] Running Loop=1
2021-12-14T22:17:40.581Z,1639520260.581 [Default:CheckIn:D] Stopped
2021-12-14T22:17:40.581Z,1639520260.581 [Default:CheckIn:E] Running Loop=1
2021-12-14T22:17:40.982Z,1639520260.982 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.543537 min 
2021-12-14T22:17:40.982Z,1639520260.982 [Default:CheckIn:E] Stopped
2021-12-14T22:17:40.982Z,1639520260.982 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-14T22:17:40.982Z,1639520260.982 [Default:CheckIn] Stopped
2021-12-14T22:17:40.982Z,1639520260.982 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-14T22:17:40.983Z,1639520260.983 [Default:CheckIn](INFO): Running loop #2
2021-12-14T22:17:40.983Z,1639520260.983 [Default:CheckIn] Running Loop=2
2021-12-14T22:17:40.983Z,1639520260.983 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-14T22:17:40.983Z,1639520260.983 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-14T22:17:47.034Z,1639520267.034 [NAL9602](INFO): NAL9602 initialized
2021-12-14T22:18:05.224Z,1639520285.224 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2021-12-14T22:18:05.224Z,1639520285.224 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:18:05.225Z,1639520285.225 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 11
2021-12-14T22:18:05.225Z,1639520285.225 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:18:05.251Z,1639520285.251 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:18:05.255Z,1639520285.255 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:18:05.639Z,1639520285.639 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:18:05.639Z,1639520285.639 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2021-12-14T22:18:05.639Z,1639520285.639 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:18:05.639Z,1639520285.639 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 11
2021-12-14T22:18:06.028Z,1639520286.028 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:21:06.219Z,1639520466.219 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2021-12-14T22:21:06.220Z,1639520466.220 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:21:06.221Z,1639520466.221 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 12
2021-12-14T22:21:06.221Z,1639520466.221 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:21:06.232Z,1639520466.232 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:21:06.232Z,1639520466.232 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:21:06.638Z,1639520466.638 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:21:06.638Z,1639520466.638 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2021-12-14T22:21:06.639Z,1639520466.639 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:21:06.639Z,1639520466.639 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 12
2021-12-14T22:21:07.052Z,1639520467.052 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:22:41.154Z,1639520561.154 [Default:CheckIn:Read_GPS](INFO): Timed out from 2021-12-14T22:17:40.0Z
2021-12-14T22:22:41.155Z,1639520561.155 [Default:CheckIn:Read_GPS] Stopped
2021-12-14T22:22:41.155Z,1639520561.155 [Default:CheckIn:Read_Iridium] Running Loop=1
2021-12-14T22:22:42.702Z,1639520562.702 [DAT](INFO): #Outgoing data=1
2021-12-14T22:22:42.702Z,1639520562.702 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2021-12-14T22:22:42.704Z,1639520562.704 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2021-12-14T22:22:45.981Z,1639520565.981 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:22:14.3219

2021-12-14T22:22:45.981Z,1639520565.981 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2021-12-14T22:22:57.088Z,1639520577.088 [DAT](FAULT): Ack receipt timeout failure.
2021-12-14T22:22:57.088Z,1639520577.088 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2021-12-14T22:22:57.340Z,1639520577.340 [DAT](INFO): Sent 39 bytes from file Logs/20211214T214444/Courier0010.lzma.parts
2021-12-14T22:22:57.340Z,1639520577.340 [DAT](INFO): Packets left to send: 0
2021-12-14T22:22:57.343Z,1639520577.343 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2021-12-14T22:22:59.158Z,1639520579.158 [Default:CheckIn:Read_Iridium] Stopped
2021-12-14T22:22:59.158Z,1639520579.158 [Default:CheckIn:C.Wait] Running Loop=1
2021-12-14T22:22:59.158Z,1639520579.158 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2021-12-14T22:24:07.104Z,1639520647.104 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2021-12-14T22:24:07.104Z,1639520647.104 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:24:07.105Z,1639520647.105 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 13
2021-12-14T22:24:07.105Z,1639520647.105 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:24:07.116Z,1639520647.116 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:24:07.116Z,1639520647.116 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:24:07.508Z,1639520647.508 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:24:07.508Z,1639520647.508 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2021-12-14T22:24:07.508Z,1639520647.508 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:24:07.509Z,1639520647.509 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 13
2021-12-14T22:24:07.887Z,1639520647.887 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:27:08.092Z,1639520828.092 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2021-12-14T22:27:08.093Z,1639520828.093 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-12-14T22:27:08.094Z,1639520828.094 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 14
2021-12-14T22:27:08.094Z,1639520828.094 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2021-12-14T22:27:08.121Z,1639520828.121 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-12-14T22:27:08.121Z,1639520828.121 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2021-12-14T22:27:08.514Z,1639520828.514 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-12-14T22:27:08.514Z,1639520828.514 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2021-12-14T22:27:08.515Z,1639520828.515 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2021-12-14T22:27:08.515Z,1639520828.515 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 14
2021-12-14T22:27:08.896Z,1639520828.896 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2021-12-14T22:27:49.280Z,1639520869.280 [NAL9602](FAULT): GPS failed to acquire within timeout.
2021-12-14T22:27:49.280Z,1639520869.280 [NAL9602] Data Fault, FailCount= 4
2021-12-14T22:27:49.280Z,1639520869.280 [NAL9602](ERROR): Data Fault
2021-12-14T22:27:49.303Z,1639520869.303 [CBIT](ERROR): Data Fault in component: NAL9602
2021-12-14T22:27:49.675Z,1639520869.675 [NAL9602](INFO): Powering down
2021-12-14T22:27:50.500Z,1639520870.500 [CBIT](INFO): Clearing failed state for component NAL9602
2021-12-14T22:27:50.500Z,1639520870.500 [NAL9602] No Fault, FailCount= 4
2021-12-14T22:27:59.387Z,1639520879.387 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2021-12-14T22:27:59.387Z,1639520879.387 [Default:CheckIn:C.Wait] Stopped
2021-12-14T22:27:59.387Z,1639520879.387 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2021-12-14T22:27:59.388Z,1639520879.388 [Default:CheckIn:D] Running Loop=1
2021-12-14T22:27:59.784Z,1639520879.784 [Default:CheckIn:D] Stopped
2021-12-14T22:27:59.785Z,1639520879.785 [Default:CheckIn:E] Running Loop=1
2021-12-14T22:28:00.186Z,1639520880.186 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.863593 min 
2021-12-14T22:28:00.186Z,1639520880.186 [Default:CheckIn:E] Stopped
2021-12-14T22:28:00.186Z,1639520880.186 [Default:CheckIn](INFO): Completed Default:CheckIn
2021-12-14T22:28:00.186Z,1639520880.186 [Default:CheckIn] Stopped
2021-12-14T22:28:00.186Z,1639520880.186 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-14T22:28:00.187Z,1639520880.187 [Default:CheckIn](INFO): Running loop #3
2021-12-14T22:28:00.187Z,1639520880.187 [Default:CheckIn] Running Loop=3
2021-12-14T22:28:00.187Z,1639520880.187 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2021-12-14T22:28:00.187Z,1639520880.187 [Default:CheckIn:Read_GPS] Running Loop=1
2021-12-14T22:28:19.974Z,1639520899.974 [NAL9602](INFO): Powering up NAL9602
2021-12-14T22:28:30.878Z,1639520910.878 [NAL9602](INFO): NAL9602 initialized
2021-12-14T22:29:09.933Z,1639520949.933 [CommandExec](IMPORTANT): got command restart application
2021-12-14T22:29:10.936Z,1639520950.936 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:10.936Z,1639520950.936 [CommandExec](INFO): Uninitializing the command executive.
2021-12-14T22:29:10.936Z,1639520950.936 [CommandExec](INFO): Uninitializing the command scheduler.
2021-12-14T22:29:10.936Z,1639520950.936 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:10.972Z,1639520950.972 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2021-12-14T22:29:10.972Z,1639520950.972 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2021-12-14T22:29:10.972Z,1639520950.972 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:10.972Z,1639520950.972 [NavChartDb](INFO): Join timeout helper Thread ID is 3716
2021-12-14T22:29:11.216Z,1639520951.216 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:11.216Z,1639520951.216 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:11.235Z,1639520951.235 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2021-12-14T22:29:11.236Z,1639520951.236 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:11.236Z,1639520951.236 [DAT](INFO): Join timeout helper Thread ID is 3717
2021-12-14T22:29:11.332Z,1639520951.332 [DAT](INFO): Powering down
2021-12-14T22:29:11.400Z,1639520951.400 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:11.400Z,1639520951.400 [DAT](INFO): Powering down
2021-12-14T22:29:11.401Z,1639520951.401 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:11.404Z,1639520951.404 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2021-12-14T22:29:11.404Z,1639520951.404 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:11.404Z,1639520951.404 [Radio_Surface](INFO): Join timeout helper Thread ID is 3718
2021-12-14T22:29:11.520Z,1639520951.520 [Radio_Surface](INFO): Powering down
2021-12-14T22:29:11.520Z,1639520951.520 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:11.521Z,1639520951.521 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:11.527Z,1639520951.527 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2021-12-14T22:29:11.528Z,1639520951.528 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:11.528Z,1639520951.528 [Onboard](INFO): Join timeout helper Thread ID is 3719
2021-12-14T22:29:12.148Z,1639520952.148 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:12.148Z,1639520952.148 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:12.160Z,1639520952.160 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2021-12-14T22:29:12.160Z,1639520952.160 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:12.160Z,1639520952.160 [BackseatComponent](INFO): Join timeout helper Thread ID is 3720
2021-12-14T22:29:12.161Z,1639520952.161 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:12.161Z,1639520952.161 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:12.162Z,1639520952.162 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2021-12-14T22:29:12.162Z,1639520952.162 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:12.163Z,1639520952.163 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3721
2021-12-14T22:29:12.249Z,1639520952.249 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:12.250Z,1639520952.250 [WetLabsBB2FL](INFO): Powering down
2021-12-14T22:29:12.252Z,1639520952.252 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:12.260Z,1639520952.260 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2021-12-14T22:29:12.260Z,1639520952.260 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:12.261Z,1639520952.261 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3722
2021-12-14T22:29:13.008Z,1639520953.008 [CTD_Seabird](INFO): Powering down
2021-12-14T22:29:13.020Z,1639520953.020 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:13.020Z,1639520953.020 [CTD_Seabird](INFO): Powering down
2021-12-14T22:29:13.031Z,1639520953.031 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.045Z,1639520953.045 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2021-12-14T22:29:13.045Z,1639520953.045 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.046Z,1639520953.046 [logger](INFO): Join timeout helper Thread ID is 3723
2021-12-14T22:29:13.052Z,1639520953.052 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:13.052Z,1639520953.052 [logger ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.064Z,1639520953.064 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2021-12-14T22:29:13.064Z,1639520953.064 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.065Z,1639520953.065 [CommandLine](INFO): Join timeout helper Thread ID is 3724
2021-12-14T22:29:13.128Z,1639520953.128 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:13.128Z,1639520953.128 [CommandLine ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.144Z,1639520953.144 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2021-12-14T22:29:13.144Z,1639520953.144 [CommandExec ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.145Z,1639520953.145 [CommandExec](INFO): Join timeout helper Thread ID is 3725
2021-12-14T22:29:13.146Z,1639520953.146 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2021-12-14T22:29:13.146Z,1639520953.146 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.146Z,1639520953.146 [controlThread](INFO): Join timeout helper Thread ID is 3726
2021-12-14T22:29:13.292Z,1639520953.292 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2021-12-14T22:29:13.292Z,1639520953.292 [controlThread](DEBUG): Uninitializing ControlThread
2021-12-14T22:29:13.293Z,1639520953.293 [AHRS_M2](INFO): Powering down
2021-12-14T22:29:13.364Z,1639520953.364 [NAL9602](INFO): Powering down
2021-12-14T22:29:13.366Z,1639520953.366 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2021-12-14T22:29:13.367Z,1639520953.367 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2021-12-14T22:29:13.368Z,1639520953.368 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2021-12-14T22:29:13.368Z,1639520953.368 [MissionManager](INFO): Uninitializing Mission Default
2021-12-14T22:29:13.369Z,1639520953.369 [Default] Stopped
2021-12-14T22:29:13.369Z,1639520953.369 [Default](DEBUG): Aggregate::uninitialize Default
2021-12-14T22:29:13.369Z,1639520953.369 [Default:B.GoToSurface] Stopped
2021-12-14T22:29:13.369Z,1639520953.369 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-12-14T22:29:13.369Z,1639520953.369 [Default:CheckIn] Stopped
2021-12-14T22:29:13.369Z,1639520953.369 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2021-12-14T22:29:13.369Z,1639520953.369 [Default:CheckIn:Read_GPS] Stopped
2021-12-14T22:29:13.372Z,1639520953.372 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2021-12-14T22:29:13.373Z,1639520953.373 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2021-12-14T22:29:13.373Z,1639520953.373 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2021-12-14T22:29:13.373Z,1639520953.373 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2021-12-14T22:29:13.374Z,1639520953.374 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2021-12-14T22:29:13.374Z,1639520953.374 [BuoyancyServo](INFO): Powering down
2021-12-14T22:29:13.388Z,1639520953.388 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2021-12-14T22:29:13.388Z,1639520953.388 [ElevatorServo](INFO): Powering down
2021-12-14T22:29:13.389Z,1639520953.389 [MassServo](DEBUG): Uninitialize Mass Servo.
2021-12-14T22:29:13.389Z,1639520953.389 [MassServo](INFO): Powering down
2021-12-14T22:29:13.390Z,1639520953.390 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-12-14T22:29:13.390Z,1639520953.390 [RudderServo](INFO): Powering down
2021-12-14T22:29:13.391Z,1639520953.391 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2021-12-14T22:29:13.391Z,1639520953.391 [ThrusterHE](INFO): Powering down
2021-12-14T22:29:13.392Z,1639520953.392 [SBIT](DEBUG): Uninitialize SBIT Component.
2021-12-14T22:29:13.392Z,1639520953.392 [IBIT](DEBUG): Uninitialize IBIT Component.
2021-12-14T22:29:13.392Z,1639520953.392 [CBIT](DEBUG): Uninitialize CBIT Component.
2021-12-14T22:29:13.393Z,1639520953.393 [CBIT](DEBUG): Powering off loads.
2021-12-14T22:29:13.403Z,1639520953.403 [CBIT](DEBUG): Disabling WDT.
2021-12-14T22:29:13.415Z,1639520953.415 [CBIT](DEBUG): Opening all GF detection circuits.
2021-12-14T22:29:13.416Z,1639520953.416 [controlThread ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.455Z,1639520953.455 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.460Z,1639520953.460 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.512Z,1639520953.512 [DAT ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.516Z,1639520953.516 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.518Z,1639520953.518 [Onboard ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.562Z,1639520953.562 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.607Z,1639520953.607 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2021-12-14T22:29:13.669Z,1639520953.669 [logger ThreadHandler](INFO): Thread cancelled.