2020-10-21T21:56:39.941Z,1603317399.941 [Supervisor](DEBUG): Initializing supervisor.
2020-10-21T21:56:39.946Z,1603317399.946 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-10-21T21:56:39.947Z,1603317399.947 [SyncHandler](INFO): Protected caller Thread ID is 2763
2020-10-21T21:56:39.947Z,1603317399.947 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-10-21T21:56:39.948Z,1603317399.948 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-10-21T21:56:39.948Z,1603317399.948 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2764
2020-10-21T21:56:39.953Z,1603317399.953 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-10-21T21:56:39.972Z,1603317399.972 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-10-21T21:56:39.973Z,1603317399.973 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-10-21T21:56:39.974Z,1603317399.974 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2765
2020-10-21T21:56:39.976Z,1603317399.976 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-10-21T21:56:39.977Z,1603317399.977 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-10-21T21:56:39.977Z,1603317399.977 [logger ThreadHandler](INFO): Protected caller Thread ID is 2766
2020-10-21T21:56:39.981Z,1603317399.981 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-10-21T21:56:39.981Z,1603317399.981 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-10-21T21:56:39.983Z,1603317399.983 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-10-21T21:56:40.143Z,1603317400.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-10-21T21:56:40.143Z,1603317400.143 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-10-21T21:56:40.694Z,1603317400.694 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-10-21T21:56:40.695Z,1603317400.695 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-10-21T21:56:40.890Z,1603317400.890 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-10-21T21:56:40.891Z,1603317400.891 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-10-21T21:56:40.969Z,1603317400.969 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-10-21T21:56:41.077Z,1603317401.077 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-10-21T21:56:41.077Z,1603317401.077 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-10-21T21:56:41.162Z,1603317401.162 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-10-21T21:56:41.260Z,1603317401.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-10-21T21:56:41.261Z,1603317401.261 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-10-21T21:56:41.548Z,1603317401.548 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-10-21T21:56:41.549Z,1603317401.549 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-10-21T21:56:42.059Z,1603317402.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-10-21T21:56:42.060Z,1603317402.060 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-10-21T21:56:42.202Z,1603317402.202 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-10-21T21:56:42.202Z,1603317402.202 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-10-21T21:56:42.383Z,1603317402.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-10-21T21:56:42.384Z,1603317402.384 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-10-21T21:56:42.788Z,1603317402.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-10-21T21:56:42.789Z,1603317402.789 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-10-21T21:56:43.001Z,1603317403.001 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-10-21T21:56:43.002Z,1603317403.002 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-10-21T21:56:43.283Z,1603317403.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-10-21T21:56:43.284Z,1603317403.284 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-10-21T21:56:43.647Z,1603317403.647 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-10-21T21:56:43.647Z,1603317403.647 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-10-21T21:56:44.558Z,1603317404.558 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-10-21T21:56:44.560Z,1603317404.560 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-10-21T21:56:44.561Z,1603317404.561 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-10-21T21:56:44.644Z,1603317404.644 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-10-21T21:56:44.794Z,1603317404.794 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-10-21T21:56:44.900Z,1603317404.900 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-10-21T21:56:44.984Z,1603317404.984 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-10-21T21:56:45.078Z,1603317405.078 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-10-21T21:56:45.263Z,1603317405.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-10-21T21:56:45.520Z,1603317405.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-10-21T21:56:45.521Z,1603317405.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-10-21T21:56:45.613Z,1603317405.613 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-10-21T21:56:45.710Z,1603317405.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-10-21T21:56:45.832Z,1603317405.832 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-10-21T21:56:45.931Z,1603317405.931 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2020-10-21T21:56:45.931Z,1603317405.931 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-10-21T21:56:45.946Z,1603317405.946 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-10-21T21:56:46.034Z,1603317406.034 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-10-21T21:56:46.034Z,1603317406.034 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-10-21T21:56:46.092Z,1603317406.092 [VerticalControl](DEBUG): Construct VerticalControl.
2020-10-21T21:56:46.150Z,1603317406.150 [VerticalControl] Loaded
2020-10-21T21:56:46.151Z,1603317406.151 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-10-21T21:56:46.153Z,1603317406.153 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-10-21T21:56:46.191Z,1603317406.191 [HorizontalControl] Loaded
2020-10-21T21:56:46.191Z,1603317406.191 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-10-21T21:56:46.193Z,1603317406.193 [SpeedControl](DEBUG): Construct SpeedControl.
2020-10-21T21:56:46.196Z,1603317406.196 [SpeedControl] Loaded
2020-10-21T21:56:46.197Z,1603317406.197 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-10-21T21:56:46.199Z,1603317406.199 [LoopControl](DEBUG): Construct LoopControl.
2020-10-21T21:56:46.199Z,1603317406.199 [LoopControl] Loaded
2020-10-21T21:56:46.200Z,1603317406.200 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-10-21T21:56:46.200Z,1603317406.200 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-10-21T21:56:46.201Z,1603317406.201 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-10-21T21:56:46.246Z,1603317406.246 [DepthRateCalculator] Loaded
2020-10-21T21:56:46.246Z,1603317406.246 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-10-21T21:56:46.251Z,1603317406.251 [PitchRateCalculator] Loaded
2020-10-21T21:56:46.251Z,1603317406.251 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-10-21T21:56:46.261Z,1603317406.261 [SpeedCalculator] Loaded
2020-10-21T21:56:46.261Z,1603317406.261 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-10-21T21:56:46.274Z,1603317406.274 [TempGradientCalculator] Loaded
2020-10-21T21:56:46.274Z,1603317406.274 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-10-21T21:56:46.278Z,1603317406.278 [YawRateCalculator] Loaded
2020-10-21T21:56:46.278Z,1603317406.278 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-10-21T21:56:46.295Z,1603317406.295 [ElevatorOffsetCalculator] Loaded
2020-10-21T21:56:46.295Z,1603317406.295 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-10-21T21:56:46.295Z,1603317406.295 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-10-21T21:56:46.296Z,1603317406.296 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-10-21T21:56:46.325Z,1603317406.325 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-10-21T21:56:46.326Z,1603317406.326 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-10-21T21:56:46.387Z,1603317406.387 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-10-21T21:56:46.388Z,1603317406.388 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-10-21T21:56:46.727Z,1603317406.727 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-10-21T21:56:46.728Z,1603317406.728 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-10-21T21:56:46.836Z,1603317406.836 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-10-21T21:56:46.837Z,1603317406.837 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-10-21T21:56:47.425Z,1603317407.425 [AHRS_M2] Loaded
2020-10-21T21:56:47.425Z,1603317407.425 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-10-21T21:56:47.671Z,1603317407.671 [BackseatComponent] Loaded
2020-10-21T21:56:47.672Z,1603317407.672 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2020-10-21T21:56:47.673Z,1603317407.673 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408F94E0
2020-10-21T21:56:47.673Z,1603317407.673 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2849
2020-10-21T21:56:47.676Z,1603317407.676 [LcmUniversalReporter] Loaded
2020-10-21T21:56:47.676Z,1603317407.676 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2020-10-21T21:56:48.456Z,1603317408.456 [BPC1] Loaded
2020-10-21T21:56:48.456Z,1603317408.456 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-10-21T21:56:48.552Z,1603317408.552 [DataOverHttps] Loaded
2020-10-21T21:56:48.552Z,1603317408.552 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-10-21T21:56:48.557Z,1603317408.557 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409294E0
2020-10-21T21:56:48.557Z,1603317408.557 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2850
2020-10-21T21:56:48.577Z,1603317408.577 [Depth_Keller] Loaded
2020-10-21T21:56:48.577Z,1603317408.577 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-10-21T21:56:48.581Z,1603317408.581 [DropWeight] Loaded
2020-10-21T21:56:48.581Z,1603317408.581 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-10-21T21:56:48.641Z,1603317408.641 [NAL9602] Loaded
2020-10-21T21:56:48.641Z,1603317408.641 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-10-21T21:56:48.670Z,1603317408.670 [Onboard] Loaded
2020-10-21T21:56:48.670Z,1603317408.670 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-10-21T21:56:48.671Z,1603317408.671 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409594E0
2020-10-21T21:56:48.671Z,1603317408.671 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2851
2020-10-21T21:56:48.684Z,1603317408.684 [Radio_Surface] Loaded
2020-10-21T21:56:48.684Z,1603317408.684 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-10-21T21:56:48.685Z,1603317408.685 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409894E0
2020-10-21T21:56:48.686Z,1603317408.686 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2852
2020-10-21T21:56:48.761Z,1603317408.761 [DAT] Loaded
2020-10-21T21:56:48.762Z,1603317408.762 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-10-21T21:56:48.762Z,1603317408.762 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-10-21T21:56:48.763Z,1603317408.763 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-10-21T21:56:48.878Z,1603317408.878 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-10-21T21:56:48.893Z,1603317408.893 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-10-21T21:56:48.953Z,1603317408.953 [NavChart] Loaded
2020-10-21T21:56:48.953Z,1603317408.953 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-10-21T21:56:48.978Z,1603317408.978 [UniversalFixResidualReporter] Loaded
2020-10-21T21:56:48.978Z,1603317408.978 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-10-21T21:56:48.979Z,1603317408.979 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-10-21T21:56:48.980Z,1603317408.980 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-10-21T21:56:49.481Z,1603317409.481 [SBIT](DEBUG): Construct Startup Built In Test.
2020-10-21T21:56:49.490Z,1603317409.490 [SBIT] Loaded
2020-10-21T21:56:49.491Z,1603317409.491 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-10-21T21:56:49.493Z,1603317409.493 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-10-21T21:56:49.506Z,1603317409.506 [IBIT] Loaded
2020-10-21T21:56:49.506Z,1603317409.506 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-10-21T21:56:49.512Z,1603317409.512 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-10-21T21:56:49.608Z,1603317409.608 [CBIT] Loaded
2020-10-21T21:56:49.609Z,1603317409.609 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-10-21T21:56:49.609Z,1603317409.609 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-10-21T21:56:49.609Z,1603317409.609 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-10-21T21:56:49.733Z,1603317409.733 [BuoyancyServo] Loaded
2020-10-21T21:56:49.733Z,1603317409.733 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-10-21T21:56:49.752Z,1603317409.752 [ElevatorServo] Loaded
2020-10-21T21:56:49.752Z,1603317409.752 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-10-21T21:56:49.771Z,1603317409.771 [MassServo] Loaded
2020-10-21T21:56:49.771Z,1603317409.771 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-10-21T21:56:49.789Z,1603317409.789 [RudderServo] Loaded
2020-10-21T21:56:49.789Z,1603317409.789 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-10-21T21:56:49.809Z,1603317409.809 [ThrusterServo] Loaded
2020-10-21T21:56:49.810Z,1603317409.810 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-10-21T21:56:49.810Z,1603317409.810 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-10-21T21:56:49.811Z,1603317409.811 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-10-21T21:56:49.822Z,1603317409.822 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-10-21T21:56:49.823Z,1603317409.823 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-10-21T21:56:50.005Z,1603317410.005 [CTD_Seabird] Loaded
2020-10-21T21:56:50.005Z,1603317410.005 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-10-21T21:56:50.008Z,1603317410.008 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AB94E0
2020-10-21T21:56:50.008Z,1603317410.008 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2853
2020-10-21T21:56:50.028Z,1603317410.028 [PAR_Licor] Loaded
2020-10-21T21:56:50.028Z,1603317410.028 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-10-21T21:56:50.059Z,1603317410.059 [WetLabsBB2FL] Loaded
2020-10-21T21:56:50.059Z,1603317410.059 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-10-21T21:56:50.060Z,1603317410.060 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AE94E0
2020-10-21T21:56:50.061Z,1603317410.061 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2854
2020-10-21T21:56:50.079Z,1603317410.079 [WetLabsUBAT] Loaded
2020-10-21T21:56:50.079Z,1603317410.079 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2020-10-21T21:56:50.080Z,1603317410.080 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40B194E0
2020-10-21T21:56:50.080Z,1603317410.080 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 2855
2020-10-21T21:56:50.081Z,1603317410.081 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-10-21T21:56:50.087Z,1603317410.087 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-10-21T21:56:50.090Z,1603317410.090 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-10-21T21:56:50.102Z,1603317410.102 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-10-21T21:56:50.103Z,1603317410.103 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B494E0
2020-10-21T21:56:50.103Z,1603317410.103 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2856
2020-10-21T21:56:50.108Z,1603317410.108 [Supervisor](INFO): Main Thread ID is 2762
2020-10-21T21:56:50.108Z,1603317410.108 [Supervisor](DEBUG): Running supervisor.
2020-10-21T21:56:50.109Z,1603317410.109 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2857
2020-10-21T21:56:50.113Z,1603317410.113 [controlThread ThreadHandler](INFO): Handler Thread ID is 2858
2020-10-21T21:56:50.113Z,1603317410.113 [controlThread](DEBUG): Initializing ControlThread
2020-10-21T21:56:50.114Z,1603317410.114 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-10-21T21:56:50.116Z,1603317410.116 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-10-21T21:56:50.117Z,1603317410.117 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-10-21T21:56:50.117Z,1603317410.117 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-10-21T21:56:50.117Z,1603317410.117 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-10-21T21:56:50.118Z,1603317410.118 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-10-21T21:56:50.118Z,1603317410.118 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-10-21T21:56:50.118Z,1603317410.118 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-10-21T21:56:50.119Z,1603317410.119 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-10-21T21:56:50.119Z,1603317410.119 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-10-21T21:56:50.123Z,1603317410.123 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-10-21T21:56:50.124Z,1603317410.124 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-10-21T21:56:50.124Z,1603317410.124 [SBIT](INFO): Initialize SBIT Component.
2020-10-21T21:56:50.124Z,1603317410.124 [SBIT](IMPORTANT): git: 2020-10-08-5-g1ffba19
2020-10-21T21:56:50.125Z,1603317410.125 [SBIT](INFO): git hash: 1ffba195703c453f49a6abcf4d6c8ad0714fad2c
2020-10-21T21:56:50.125Z,1603317410.125 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-10-21T21:56:50.126Z,1603317410.126 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-10-21T21:56:50.127Z,1603317410.127 [SBIT](INFO): Beginning SBIT in 26.000000 seconds.
2020-10-21T21:56:50.128Z,1603317410.128 [IBIT](INFO): Initialize IBIT Component.
2020-10-21T21:56:50.129Z,1603317410.129 [CBIT](DEBUG): Initialize CBIT Component.
2020-10-21T21:56:50.130Z,1603317410.130 [logger ThreadHandler](INFO): Handler Thread ID is 2859
2020-10-21T21:56:50.141Z,1603317410.141 [CBIT](DEBUG): Initialized mux pins.
2020-10-21T21:56:50.141Z,1603317410.141 [CBIT](DEBUG): Initializing the watchdog timer.
2020-10-21T21:56:50.149Z,1603317410.149 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2860
2020-10-21T21:56:50.161Z,1603317410.161 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2861
2020-10-21T21:56:50.162Z,1603317410.162 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-10-21T21:56:50.165Z,1603317410.165 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-10-21T21:56:50.165Z,1603317410.165 [CBIT](DEBUG): Initializing heartbeat.
2020-10-21T21:56:50.173Z,1603317410.173 [Onboard ThreadHandler](INFO): Handler Thread ID is 2862
2020-10-21T21:56:50.199Z,1603317410.199 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2863
2020-10-21T21:56:50.209Z,1603317410.209 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2864
2020-10-21T21:56:50.210Z,1603317410.210 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-10-21T21:56:50.214Z,1603317410.214 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2866
2020-10-21T21:56:50.217Z,1603317410.217 [WetLabsBB2FL](INFO): Powering up
2020-10-21T21:56:50.218Z,1603317410.218 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 2868
2020-10-21T21:56:50.221Z,1603317410.221 [WetLabsUBAT](INFO): Powering up
2020-10-21T21:56:50.222Z,1603317410.222 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2870
2020-10-21T21:56:50.230Z,1603317410.230 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-10-21T21:56:50.231Z,1603317410.231 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-10-21T21:56:50.231Z,1603317410.231 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-10-21T21:56:50.231Z,1603317410.231 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-10-21T21:56:50.231Z,1603317410.231 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-10-21T21:56:50.231Z,1603317410.231 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-10-21T21:56:50.231Z,1603317410.231 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-10-21T21:56:50.231Z,1603317410.231 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-10-21T21:56:50.232Z,1603317410.232 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-10-21T21:56:50.232Z,1603317410.232 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-10-21T21:56:50.232Z,1603317410.232 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-10-21T21:56:50.232Z,1603317410.232 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-10-21T21:56:50.232Z,1603317410.232 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-10-21T21:56:50.232Z,1603317410.232 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-10-21T21:56:50.233Z,1603317410.233 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-10-21T21:56:50.233Z,1603317410.233 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-10-21T21:56:50.237Z,1603317410.237 [CBIT](DEBUG): Deactivating GF circuits.
2020-10-21T21:56:50.237Z,1603317410.237 [CBIT](DEBUG): Deactivating emergency mode.
2020-10-21T21:56:50.273Z,1603317410.273 [CBIT](DEBUG): Backplane powered.
2020-10-21T21:56:50.278Z,1603317410.278 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-10-21T21:56:50.318Z,1603317410.318 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-10-21T21:56:50.354Z,1603317410.354 [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>


2020-10-21T21:56:50.355Z,1603317410.355 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-10-21T21:56:50.423Z,1603317410.423 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-10-21T21:56:50.424Z,1603317410.424 [Default:A.Wait](DEBUG): Construct Wait.
2020-10-21T21:56:50.446Z,1603317410.446 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-10-21T21:56:50.474Z,1603317410.474 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-10-21T21:56:50.497Z,1603317410.497 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-10-21T21:56:50.503Z,1603317410.503 [Default:E.Execute](DEBUG): Construct Execute.
2020-10-21T21:56:50.511Z,1603317410.511 [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>


2020-10-21T21:56:50.521Z,1603317410.521 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2020-10-21T21:56:50.533Z,1603317410.533 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-10-21T21:56:50.601Z,1603317410.601 [Radio_Surface](INFO): Powering up
2020-10-21T21:56:50.662Z,1603317410.662 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-10-21T21:56:50.662Z,1603317410.662 [DAT](INFO): Powering up
2020-10-21T21:56:50.662Z,1603317410.662 [DAT](DEBUG): Initializing DAT.
2020-10-21T21:56:50.709Z,1603317410.709 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-10-21T21:56:50.806Z,1603317410.806 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-10-21T21:56:50.813Z,1603317410.813 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-10-21T21:56:50.815Z,1603317410.815 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-10-21T21:56:50.821Z,1603317410.821 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-10-21T21:56:50.822Z,1603317410.822 [MassServo](DEBUG): Initializing EZServoServo.
2020-10-21T21:56:50.833Z,1603317410.833 [MassServo](DEBUG): Initializing MassServo.
2020-10-21T21:56:50.834Z,1603317410.834 [RudderServo](DEBUG): Initializing EZServoServo.
2020-10-21T21:56:50.845Z,1603317410.845 [RudderServo](DEBUG): Initializing RudderServo.
2020-10-21T21:56:50.846Z,1603317410.846 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-10-21T21:56:50.857Z,1603317410.857 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-10-21T21:56:50.950Z,1603317410.950 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2020-10-21T21:56:50.950Z,1603317410.950 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-10-21T21:56:50.950Z,1603317410.950 [DropWeight] Hardware Fault, FailCount= 1
2020-10-21T21:56:50.950Z,1603317410.950 [DropWeight](ERROR): Hardware Fault
2020-10-21T21:56:50.999Z,1603317410.999 [CommandLine](FAULT): Scheduling is paused
2020-10-21T21:56:50.999Z,1603317410.999 [CBIT](INFO): Critical error at 20201021T215650
2020-10-21T21:56:50.000Z,1603317411.000 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-10-21T21:56:51.002Z,1603317411.002 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-10-21T21:56:51.003Z,1603317411.003 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-10-21T21:56:51.673Z,1603317411.673 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-10-21T21:56:51.673Z,1603317411.673 [RudderServo](FAULT): Rudder failed to initialize
2020-10-21T21:56:51.673Z,1603317411.673 [RudderServo] Communications Fault, FailCount= 1
2020-10-21T21:56:51.673Z,1603317411.673 [RudderServo](ERROR): Communications Fault
2020-10-21T21:56:51.818Z,1603317411.818 [CBIT](INFO): Critical error at 20201021T215651
2020-10-21T21:56:51.821Z,1603317411.821 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-10-21T21:56:51.990Z,1603317411.990 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-10-21T21:56:51.990Z,1603317411.990 [RudderServo](INFO): Powering down
2020-10-21T21:56:52.686Z,1603317412.686 [RudderServo](DEBUG): Initializing EZServoServo.
2020-10-21T21:56:52.808Z,1603317412.808 [RudderServo](DEBUG): Initializing RudderServo.
2020-10-21T21:56:52.813Z,1603317412.813 [CBIT](INFO): Clearing failed state for component RudderServo
2020-10-21T21:56:52.813Z,1603317412.813 [RudderServo] No Fault, FailCount= 1
2020-10-21T21:56:52.833Z,1603317412.833 [WetLabsBB2FL](INFO): Powering down
2020-10-21T21:56:57.241Z,1603317417.241 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-10-21T21:56:59.465Z,1603317419.465 [WetLabsUBAT](INFO): Powering down
2020-10-21T21:57:04.776Z,1603317424.776 [DAT](INFO): commRate: 800
2020-10-21T21:57:05.895Z,1603317425.895 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004858
2020-10-21T21:57:06.782Z,1603317426.782 [DAT](INFO): entering command mode
2020-10-21T21:57:07.187Z,1603317427.187 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:07.594Z,1603317427.594 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:07.998Z,1603317427.998 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:08.402Z,1603317428.402 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:08.802Z,1603317428.802 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:09.206Z,1603317429.206 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:09.610Z,1603317429.610 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:10.014Z,1603317430.014 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:10.418Z,1603317430.418 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:10.822Z,1603317430.822 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:11.226Z,1603317431.226 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:11.630Z,1603317431.630 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:12.034Z,1603317432.034 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:12.438Z,1603317432.438 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:12.842Z,1603317432.842 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:13.246Z,1603317433.246 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:13.654Z,1603317433.654 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:14.054Z,1603317434.054 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:14.458Z,1603317434.458 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:14.866Z,1603317434.866 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:15.266Z,1603317435.266 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:15.695Z,1603317435.695 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:16.074Z,1603317436.074 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:16.478Z,1603317436.478 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:16.893Z,1603317436.893 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:16.912Z,1603317436.912 [SBIT](IMPORTANT): Beginning Startup BIT
2020-10-21T21:57:16.916Z,1603317436.916 [CBIT](IMPORTANT): Beginning ground fault scan
2020-10-21T21:57:17.294Z,1603317437.294 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:17.702Z,1603317437.702 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:18.094Z,1603317438.094 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:18.504Z,1603317438.504 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:18.902Z,1603317438.902 [NAL9602](INFO): Powering up NAL9602
2020-10-21T21:57:18.904Z,1603317438.904 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:19.306Z,1603317439.306 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:19.717Z,1603317439.717 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:20.118Z,1603317440.118 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:20.518Z,1603317440.518 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:20.926Z,1603317440.926 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:21.326Z,1603317441.326 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:21.730Z,1603317441.730 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:22.134Z,1603317442.134 [DAT](DEBUG): checking for command mode acknowledgment
2020-10-21T21:57:22.134Z,1603317442.134 [DAT](FAULT): failed to enter command mode
2020-10-21T21:57:22.538Z,1603317442.538 [DAT](INFO): entering command mode
2020-10-21T21:57:22.950Z,1603317442.950 [DAT](INFO): setting verbose to 3
2020-10-21T21:57:23.351Z,1603317443.351 [DAT](INFO): set verbose to 3
2020-10-21T21:57:23.352Z,1603317443.352 [DAT](INFO): setting DatVerbose to 27440
2020-10-21T21:57:23.751Z,1603317443.751 [DAT](INFO): set DatVerbose to 27440
2020-10-21T21:57:23.752Z,1603317443.752 [DAT](INFO): setting transmit power to 8
2020-10-21T21:57:24.155Z,1603317444.155 [DAT](INFO): set transmit power to 8
2020-10-21T21:57:24.156Z,1603317444.156 [DAT](INFO): setting local address to 9
2020-10-21T21:57:24.563Z,1603317444.563 [DAT](INFO): set local address to 9
2020-10-21T21:57:27.865Z,1603317447.865 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.002533
CHAN A1 (24V): -0.001231
CHAN A2 (12V): -0.007427
CHAN A3 (5V): -0.002545
CHAN B0 (3.3V): 0.000655
CHAN B1 (3.15aV): -0.000022
CHAN B2 (3.15bV): -0.000378
CHAN B3 (GND): 0.001298
OPEN: 0.005235
Full Scale Calc: 4.765 mA, -1.589 mA
2020-10-21T21:57:29.810Z,1603317449.810 [NAL9602](INFO): NAL9602 initialized
2020-10-21T21:58:10.693Z,1603317490.693 [SBIT](IMPORTANT): SBIT PASSED
2020-10-21T21:58:10.694Z,1603317490.694 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-10-21T21:58:10.694Z,1603317490.694 [SBIT](IMPORTANT): AMEcho.loadAtStartup=0 bool;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): DAT.surfaceThreshold=100 meter;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): DAT.verbosity=0 count;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-10-21T21:58:10.695Z,1603317490.695 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-10-21T21:58:10.696Z,1603317490.696 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2020-10-21T21:58:10.696Z,1603317490.696 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-10-21T21:58:10.696Z,1603317490.696 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=256.318046 cubic_centimeter;

2020-10-21T21:58:10.696Z,1603317490.696 [SBIT](IMPORTANT): VerticalControl.massDefault=1.572083 millimeter;

2020-10-21T21:58:10.696Z,1603317490.696 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2020-10-21T21:58:11.116Z,1603317491.116 [MissionManager](IMPORTANT): Started mission Startup
2020-10-21T21:58:11.116Z,1603317491.116 [Startup] Running Loop=1
2020-10-21T21:58:11.116Z,1603317491.116 [Startup](DEBUG): Aggregate::initialize Startup
2020-10-21T21:58:11.116Z,1603317491.116 [Startup:A.GoToSurface] Running Loop=1
2020-10-21T21:58:11.116Z,1603317491.116 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-21T21:58:11.117Z,1603317491.117 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-21T21:58:11.117Z,1603317491.117 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-21T21:58:11.118Z,1603317491.118 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-21T21:58:11.118Z,1603317491.118 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-21T21:58:11.119Z,1603317491.118 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-21T21:58:11.120Z,1603317491.120 [Startup:StartupSatComms] Running Loop=1
2020-10-21T21:58:11.120Z,1603317491.120 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-10-21T21:58:11.120Z,1603317491.120 [Startup:StartupSatComms:A] Running Loop=1
2020-10-21T21:58:11.458Z,1603317491.458 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-10-21T21:59:11.236Z,1603317551.236 [Startup:StartupSatComms:A](INFO): Timed out from 2020-10-21T21:58:11.1Z
2020-10-21T21:59:11.236Z,1603317551.236 [Startup:StartupSatComms:A] Stopped
2020-10-21T21:59:11.236Z,1603317551.236 [Startup:StartupSatComms:B] Running Loop=1
2020-10-21T21:59:11.670Z,1603317551.670 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-10-21T21:59:18.066Z,1603317558.066 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201017T001315/Courier0045.lzma
2020-10-21T21:59:19.067Z,1603317559.067 [DataOverHttps](INFO): Moved sent file to Logs/20201017T001315/Courier0045.lzma.bak
2020-10-21T21:59:19.067Z,1603317559.067 [DataOverHttps](INFO): SBD MOMSN=12951612
2020-10-21T21:59:34.725Z,1603317574.725 [DataOverHttps](INFO): Sending 241 bytes from file Logs/20201021T215639/Courier0000.lzma
2020-10-21T21:59:35.727Z,1603317575.727 [DataOverHttps](INFO): Moved sent file to Logs/20201021T215639/Courier0000.lzma.bak
2020-10-21T21:59:35.727Z,1603317575.727 [DataOverHttps](INFO): SBD MOMSN=12951614
2020-10-21T21:59:50.428Z,1603317590.428 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-10-21T21:59:50.428Z,1603317590.428 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T21:59:50.439Z,1603317590.439 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T21:59:50.854Z,1603317590.854 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T21:59:50.855Z,1603317590.855 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-10-21T21:59:51.176Z,1603317591.176 [DataOverHttps](INFO): Sending 141 bytes from file Logs/20201017T001315/Express0046.lzma
2020-10-21T21:59:52.131Z,1603317592.131 [DataOverHttps](INFO): Moved sent file to Logs/20201017T001315/Express0046.lzma.bak
2020-10-21T21:59:52.131Z,1603317592.131 [DataOverHttps](INFO): SBD MOMSN=12951619
2020-10-21T22:00:07.606Z,1603317607.606 [DataOverHttps](INFO): Sending 1041 bytes from file Logs/20201021T215639/Express0001.lzma
2020-10-21T22:00:08.607Z,1603317608.607 [DataOverHttps](INFO): Moved sent file to Logs/20201021T215639/Express0001.lzma.bak
2020-10-21T22:00:08.607Z,1603317608.607 [DataOverHttps](INFO): SBD MOMSN=12951623
2020-10-21T22:00:10.259Z,1603317610.259 [Startup:StartupSatComms:B] Stopped
2020-10-21T22:00:10.260Z,1603317610.260 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-10-21T22:00:10.260Z,1603317610.260 [Startup:StartupSatComms] Stopped
2020-10-21T22:00:10.260Z,1603317610.260 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-10-21T22:00:10.261Z,1603317610.261 [Startup](INFO): Completed Startup
2020-10-21T22:00:10.261Z,1603317610.261 [MissionManager](INFO): Startup is completed.
2020-10-21T22:00:10.261Z,1603317610.261 [MissionManager](INFO): Uninitializing Mission Startup
2020-10-21T22:00:10.261Z,1603317610.261 [Startup] Stopped
2020-10-21T22:00:10.261Z,1603317610.261 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-10-21T22:00:10.261Z,1603317610.261 [Startup:A.GoToSurface] Stopped
2020-10-21T22:00:10.262Z,1603317610.262 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-21T22:00:10.626Z,1603317610.626 [MissionManager](IMPORTANT): Started mission Default
2020-10-21T22:00:10.626Z,1603317610.626 [Default] Running Loop=1
2020-10-21T22:00:10.626Z,1603317610.626 [Default](DEBUG): Aggregate::initialize Default
2020-10-21T22:00:10.626Z,1603317610.626 [Default:B.GoToSurface] Running Loop=1
2020-10-21T22:00:10.626Z,1603317610.626 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-21T22:00:10.627Z,1603317610.627 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-21T22:00:10.627Z,1603317610.627 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-21T22:00:10.628Z,1603317610.628 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-21T22:00:10.628Z,1603317610.628 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-21T22:00:10.628Z,1603317610.628 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-21T22:00:10.629Z,1603317610.629 [Default:A.Wait] Running Loop=1
2020-10-21T22:00:10.629Z,1603317610.629 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-10-21T22:00:23.957Z,1603317623.957 [Default:A.Wait](INFO): Done Waiting.
2020-10-21T22:00:23.957Z,1603317623.957 [Default:A.Wait] Stopped
2020-10-21T22:00:23.957Z,1603317623.957 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-10-21T22:00:24.373Z,1603317624.373 [Default:CheckIn] Running Loop=1
2020-10-21T22:00:24.373Z,1603317624.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-10-21T22:00:24.373Z,1603317624.373 [Default:CheckIn:Read_GPS] Running Loop=1
2020-10-21T22:00:24.791Z,1603317624.791 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-10-21T22:01:56.390Z,1603317716.390 [CommandLine](IMPORTANT): got command run ./Missions/bsd.xml
2020-10-21T22:01:56.390Z,1603317716.390 [MissionManager](INFO): Loading Mission: ./Missions/bsd.xml
2020-10-21T22:01:56.437Z,1603317716.437 [MissionManager](INFO): DefineArg bsd.ElapsedSinceDefaultStarted = 0.000000 min
2020-10-21T22:01:56.438Z,1603317716.438 [bsd:A.Wait](DEBUG): Construct Wait.
2020-10-21T22:01:56.442Z,1603317716.442 [bsd:B.BackseatDriver](DEBUG): Construct BackseatDriver.
2020-10-21T22:01:56.490Z,1603317716.490 [bsd:C.GoToSurface](DEBUG): Construct GoToSurface.
2020-10-21T22:01:56.529Z,1603317716.529 [bsd:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-10-21T22:01:56.532Z,1603317716.532 [bsd:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-10-21T22:01:56.542Z,1603317716.542 [bsd:F.Execute](DEBUG): Construct Execute.
2020-10-21T22:01:56.545Z,1603317716.545 [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="bsd">

    <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: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="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>


2020-10-21T22:01:56.547Z,1603317716.547 [CommandLine](IMPORTANT): Running ./Missions/bsd.xml
2020-10-21T22:01:56.887Z,1603317716.887 [Default] Stopped
2020-10-21T22:01:56.887Z,1603317716.887 [Default](DEBUG): Aggregate::uninitialize Default
2020-10-21T22:01:56.887Z,1603317716.887 [Default:B.GoToSurface] Stopped
2020-10-21T22:01:56.888Z,1603317716.888 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-21T22:01:56.888Z,1603317716.888 [Default:CheckIn] Stopped
2020-10-21T22:01:56.888Z,1603317716.888 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-10-21T22:01:56.888Z,1603317716.888 [Default:CheckIn:Read_GPS] Stopped
2020-10-21T22:01:56.888Z,1603317716.888 [MissionManager](IMPORTANT): Started mission bsd
2020-10-21T22:01:56.888Z,1603317716.888 [bsd] Running Loop=1
2020-10-21T22:01:56.888Z,1603317716.888 [bsd](DEBUG): Aggregate::initialize bsd
2020-10-21T22:01:56.888Z,1603317716.888 [bsd:B.BackseatDriver] Running Loop=1
2020-10-21T22:01:56.889Z,1603317716.889 [bsd:B.BackseatDriver](DEBUG): Initialize.
2020-10-21T22:01:56.973Z,1603317716.973 [bsd:C.GoToSurface] Running Loop=1
2020-10-21T22:01:56.973Z,1603317716.973 [bsd:C.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-21T22:01:56.974Z,1603317716.974 [bsd:C.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-21T22:01:56.974Z,1603317716.974 [bsd:C.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-21T22:01:56.974Z,1603317716.974 [bsd:C.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-21T22:01:56.975Z,1603317716.975 [bsd:C.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-21T22:01:56.975Z,1603317716.975 [bsd:C.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-21T22:01:56.975Z,1603317716.975 [bsd:A.Wait] Running Loop=1
2020-10-21T22:01:56.975Z,1603317716.975 [bsd:A.Wait](DEBUG): Initialize Wait Component.
2020-10-21T22:01:56.976Z,1603317716.976 [bsd:B.BackseatDriver] Running Loop=1
2020-10-21T22:01:57.016Z,1603317717.016 [LcmUniversalReporter](ERROR): Failed to copy LcmUniversalReporter.enableBroadcast's data value to LCM message.
2020-10-21T22:01:57.016Z,1603317717.016 [LcmUniversalReporter](INFO): Activating messaging.
2020-10-21T22:01:57.073Z,1603317717.073 [BackseatComponent](INFO): Powering up
2020-10-21T22:01:57.074Z,1603317717.074 [BackseatComponent](INFO): Subscribing to LCM channels.
2020-10-21T22:02:10.037Z,1603317730.037 [bsd:A.Wait](INFO): Done Waiting.
2020-10-21T22:02:10.037Z,1603317730.037 [bsd:A.Wait] Stopped
2020-10-21T22:02:10.037Z,1603317730.037 [bsd:A.Wait](DEBUG): Uninitialize Wait Component.
2020-10-21T22:02:10.404Z,1603317730.404 [bsd:CheckIn] Running Loop=1
2020-10-21T22:02:10.404Z,1603317730.404 [bsd:CheckIn](DEBUG): Aggregate::initialize bsd:CheckIn
2020-10-21T22:02:10.404Z,1603317730.404 [bsd:CheckIn:Read_GPS] Running Loop=1
2020-10-21T22:02:10.794Z,1603317730.794 [bsd:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-10-21T22:02:12.402Z,1603317732.402 [BackseatComponent](IMPORTANT): jetson: running backseat application.
2020-10-21T22:02:12.815Z,1603317732.815 [BackseatComponent](INFO): Created data reader for Depth_Keller.enableBroadcast with code: 1442
2020-10-21T22:02:12.816Z,1603317732.816 [BackseatComponent](INFO): Requesting data from Depth_Keller.enableBroadcast (1442). Requested size is: 1
2020-10-21T22:02:12.825Z,1603317732.825 [Depth_Keller](ERROR): Failed to copy Depth_Keller.enableBroadcast's data value to LCM message.
2020-10-21T22:02:12.826Z,1603317732.826 [Depth_Keller](INFO): Activating messaging.
2020-10-21T22:02:32.999Z,1603317752.999 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-10-21T22:02:51.602Z,1603317771.602 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-10-21T22:02:51.602Z,1603317771.602 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T22:02:51.637Z,1603317771.637 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T22:02:52.053Z,1603317772.053 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T22:02:52.053Z,1603317772.053 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-10-21T22:04:16.424Z,1603317856.424 [BPC1](ERROR): Battery stick #23 (s/n: 0227) reported OVER_TEMP_ALARM. Status code: 0x1717.
2020-10-21T22:04:16.425Z,1603317856.425 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 6.
2020-10-21T22:04:16.428Z,1603317856.428 [BPC1](INFO): Received data from all battery sticks.
2020-10-21T22:05:52.579Z,1603317952.579 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-10-21T22:05:52.579Z,1603317952.579 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T22:05:52.622Z,1603317952.622 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T22:05:53.029Z,1603317953.029 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T22:05:53.029Z,1603317953.029 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-10-21T22:07:10.580Z,1603318030.580 [bsd:CheckIn:Read_GPS](INFO): Timed out from 2020-10-21T22:02:10.4Z
2020-10-21T22:07:10.580Z,1603318030.580 [bsd:CheckIn:Read_GPS] Stopped
2020-10-21T22:07:10.580Z,1603318030.580 [bsd:CheckIn:Read_Iridium] Running Loop=1
2020-10-21T22:07:11.008Z,1603318031.008 [bsd:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-10-21T22:07:14.669Z,1603318034.669 [CommandLine](IMPORTANT): got command report touch controlThread.durationOfLastRun
2020-10-21T22:07:15.167Z,1603318035.167 [Reporter](INFO): controlThread.durationOfLastRun 0.132734 s
2020-10-21T22:07:15.563Z,1603318035.563 [Reporter](INFO): controlThread.durationOfLastRun 0.086425 s
2020-10-21T22:07:15.974Z,1603318035.974 [Reporter](INFO): controlThread.durationOfLastRun 0.078664 s
2020-10-21T22:07:16.362Z,1603318036.362 [Reporter](INFO): controlThread.durationOfLastRun 0.085397 s
2020-10-21T22:07:16.777Z,1603318036.777 [Reporter](INFO): controlThread.durationOfLastRun 0.069613 s
2020-10-21T22:07:17.187Z,1603318037.187 [Reporter](INFO): controlThread.durationOfLastRun 0.080221 s
2020-10-21T22:07:17.602Z,1603318037.602 [Reporter](INFO): controlThread.durationOfLastRun 0.087249 s
2020-10-21T22:07:17.836Z,1603318037.836 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20201021T215639/Courier0004.lzma
2020-10-21T22:07:18.006Z,1603318038.006 [Reporter](INFO): controlThread.durationOfLastRun 0.098018 s
2020-10-21T22:07:18.394Z,1603318038.394 [Reporter](INFO): controlThread.durationOfLastRun 0.097928 s
2020-10-21T22:07:18.802Z,1603318038.802 [Reporter](INFO): controlThread.durationOfLastRun 0.081459 s
2020-10-21T22:07:18.838Z,1603318038.838 [DataOverHttps](INFO): Moved sent file to Logs/20201021T215639/Courier0004.lzma.bak
2020-10-21T22:07:18.839Z,1603318038.839 [DataOverHttps](INFO): SBD MOMSN=12951701
2020-10-21T22:07:19.206Z,1603318039.206 [Reporter](INFO): controlThread.durationOfLastRun 0.085742 s
2020-10-21T22:07:19.590Z,1603318039.590 [Reporter](INFO): controlThread.durationOfLastRun 0.086128 s
2020-10-21T22:07:20.018Z,1603318040.018 [Reporter](INFO): controlThread.durationOfLastRun 0.065545 s
2020-10-21T22:07:20.426Z,1603318040.426 [Reporter](INFO): controlThread.durationOfLastRun 0.089599 s
2020-10-21T22:07:20.838Z,1603318040.838 [Reporter](INFO): controlThread.durationOfLastRun 0.093135 s
2020-10-21T22:07:21.245Z,1603318041.245 [Reporter](INFO): controlThread.durationOfLastRun 0.102081 s
2020-10-21T22:07:21.618Z,1603318041.618 [Reporter](INFO): controlThread.durationOfLastRun 0.104897 s
2020-10-21T22:07:22.037Z,1603318042.037 [Reporter](INFO): controlThread.durationOfLastRun 0.073759 s
2020-10-21T22:07:22.437Z,1603318042.437 [Reporter](INFO): controlThread.durationOfLastRun 0.088894 s
2020-10-21T22:07:22.829Z,1603318042.829 [Reporter](INFO): controlThread.durationOfLastRun 0.084951 s
2020-10-21T22:07:23.277Z,1603318043.277 [Reporter](INFO): controlThread.durationOfLastRun 0.073207 s
2020-10-21T22:07:23.660Z,1603318043.660 [Reporter](INFO): controlThread.durationOfLastRun 0.116594 s
2020-10-21T22:07:24.067Z,1603318044.067 [Reporter](INFO): controlThread.durationOfLastRun 0.095439 s
2020-10-21T22:07:24.487Z,1603318044.487 [Reporter](INFO): controlThread.durationOfLastRun 0.098547 s
2020-10-21T22:07:24.853Z,1603318044.853 [Reporter](INFO): controlThread.durationOfLastRun 0.114282 s
2020-10-21T22:07:25.270Z,1603318045.270 [Reporter](INFO): controlThread.durationOfLastRun 0.076640 s
2020-10-21T22:07:25.673Z,1603318045.673 [Reporter](INFO): controlThread.durationOfLastRun 0.089699 s
2020-10-21T22:07:26.066Z,1603318046.066 [Reporter](INFO): controlThread.durationOfLastRun 0.088637 s
2020-10-21T22:07:26.477Z,1603318046.477 [Reporter](INFO): controlThread.durationOfLastRun 0.077576 s
2020-10-21T22:07:26.887Z,1603318046.887 [Reporter](INFO): controlThread.durationOfLastRun 0.084554 s
2020-10-21T22:07:27.266Z,1603318047.266 [Reporter](INFO): controlThread.durationOfLastRun 0.090509 s
2020-10-21T22:07:27.675Z,1603318047.675 [Reporter](INFO): controlThread.durationOfLastRun 0.065855 s
2020-10-21T22:07:28.102Z,1603318048.102 [Reporter](INFO): controlThread.durationOfLastRun 0.070631 s
2020-10-21T22:07:28.478Z,1603318048.478 [Reporter](INFO): controlThread.durationOfLastRun 0.093969 s
2020-10-21T22:07:28.894Z,1603318048.894 [Reporter](INFO): controlThread.durationOfLastRun 0.066047 s
2020-10-21T22:07:29.314Z,1603318049.314 [Reporter](INFO): controlThread.durationOfLastRun 0.077496 s
2020-10-21T22:07:29.719Z,1603318049.719 [Reporter](INFO): controlThread.durationOfLastRun 0.093362 s
2020-10-21T22:07:30.090Z,1603318050.090 [Reporter](INFO): controlThread.durationOfLastRun 0.094463 s
2020-10-21T22:07:30.509Z,1603318050.509 [Reporter](INFO): controlThread.durationOfLastRun 0.061618 s
2020-10-21T22:07:30.970Z,1603318050.970 [Reporter](INFO): controlThread.durationOfLastRun 0.077115 s
2020-10-21T22:07:31.337Z,1603318051.337 [Reporter](INFO): controlThread.durationOfLastRun 0.113692 s
2020-10-21T22:07:31.760Z,1603318051.760 [Reporter](INFO): controlThread.durationOfLastRun 0.076958 s
2020-10-21T22:07:32.080Z,1603318052.080 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-10-21T22:07:32.080Z,1603318052.080 [NAL9602] Data Fault, FailCount= 1
2020-10-21T22:07:32.080Z,1603318052.080 [NAL9602](ERROR): Data Fault
2020-10-21T22:07:32.169Z,1603318052.169 [CBIT](ERROR): Data Fault in component: NAL9602
2020-10-21T22:07:32.174Z,1603318052.174 [Reporter](INFO): controlThread.durationOfLastRun 0.095295 s
2020-10-21T22:07:32.482Z,1603318052.482 [NAL9602](INFO): Powering down
2020-10-21T22:07:32.558Z,1603318052.558 [Reporter](INFO): controlThread.durationOfLastRun 0.105904 s
2020-10-21T22:07:32.953Z,1603318052.953 [Reporter](INFO): controlThread.durationOfLastRun 0.085900 s
2020-10-21T22:07:33.356Z,1603318053.356 [CBIT](INFO): Clearing failed state for component NAL9602
2020-10-21T22:07:33.357Z,1603318053.357 [NAL9602] No Fault, FailCount= 1
2020-10-21T22:07:33.361Z,1603318053.361 [Reporter](INFO): controlThread.durationOfLastRun 0.076872 s
2020-10-21T22:07:33.774Z,1603318053.774 [Reporter](INFO): controlThread.durationOfLastRun 0.081069 s
2020-10-21T22:07:34.165Z,1603318054.165 [Reporter](INFO): controlThread.durationOfLastRun 0.089744 s
2020-10-21T22:07:34.582Z,1603318054.582 [Reporter](INFO): controlThread.durationOfLastRun 0.076306 s
2020-10-21T22:07:34.979Z,1603318054.979 [Reporter](INFO): controlThread.durationOfLastRun 0.089270 s
2020-10-21T22:07:35.385Z,1603318055.385 [Reporter](INFO): controlThread.durationOfLastRun 0.083239 s
2020-10-21T22:07:35.473Z,1603318055.473 [DataOverHttps](INFO): Sending 295 bytes from file Logs/20201021T215639/Express0005.lzma
2020-10-21T22:07:35.800Z,1603318055.800 [Reporter](INFO): controlThread.durationOfLastRun 0.084852 s
2020-10-21T22:07:36.185Z,1603318056.185 [Reporter](INFO): controlThread.durationOfLastRun 0.095359 s
2020-10-21T22:07:36.474Z,1603318056.474 [DataOverHttps](INFO): Moved sent file to Logs/20201021T215639/Express0005.lzma.bak
2020-10-21T22:07:36.475Z,1603318056.475 [DataOverHttps](INFO): SBD MOMSN=12951703
2020-10-21T22:07:36.602Z,1603318056.602 [Reporter](INFO): controlThread.durationOfLastRun 0.076729 s
2020-10-21T22:07:36.998Z,1603318056.998 [Reporter](INFO): controlThread.durationOfLastRun 0.089421 s
2020-10-21T22:07:37.382Z,1603318057.382 [Reporter](INFO): controlThread.durationOfLastRun 0.081552 s
2020-10-21T22:07:37.767Z,1603318057.767 [bsd:CheckIn:Read_Iridium] Stopped
2020-10-21T22:07:37.767Z,1603318057.767 [bsd:CheckIn:C.Wait] Running Loop=1
2020-10-21T22:07:37.767Z,1603318057.767 [bsd:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-10-21T22:07:37.817Z,1603318057.817 [Reporter](INFO): controlThread.durationOfLastRun 0.062165 s
2020-10-21T22:07:38.206Z,1603318058.206 [Reporter](INFO): controlThread.durationOfLastRun 0.119780 s
2020-10-21T22:07:38.614Z,1603318058.614 [Reporter](INFO): controlThread.durationOfLastRun 0.078077 s
2020-10-21T22:07:38.998Z,1603318058.998 [Reporter](INFO): controlThread.durationOfLastRun 0.081849 s
2020-10-21T22:07:39.417Z,1603318059.417 [Reporter](INFO): controlThread.durationOfLastRun 0.061790 s
2020-10-21T22:07:39.834Z,1603318059.834 [Reporter](INFO): controlThread.durationOfLastRun 0.077146 s
2020-10-21T22:07:40.226Z,1603318060.226 [Reporter](INFO): controlThread.durationOfLastRun 0.090075 s
2020-10-21T22:07:40.642Z,1603318060.642 [Reporter](INFO): controlThread.durationOfLastRun 0.077473 s
2020-10-21T22:07:41.066Z,1603318061.066 [Reporter](INFO): controlThread.durationOfLastRun 0.089458 s
2020-10-21T22:07:41.446Z,1603318061.446 [Reporter](INFO): controlThread.durationOfLastRun 0.109180 s
2020-10-21T22:07:41.857Z,1603318061.857 [Reporter](INFO): controlThread.durationOfLastRun 0.085369 s
2020-10-21T22:07:42.246Z,1603318062.246 [Reporter](INFO): controlThread.durationOfLastRun 0.093324 s
2020-10-21T22:07:42.662Z,1603318062.662 [Reporter](INFO): controlThread.durationOfLastRun 0.077577 s
2020-10-21T22:07:43.058Z,1603318063.058 [Reporter](INFO): controlThread.durationOfLastRun 0.089304 s
2020-10-21T22:07:43.466Z,1603318063.466 [Reporter](INFO): controlThread.durationOfLastRun 0.081393 s
2020-10-21T22:07:43.853Z,1603318063.853 [Reporter](INFO): controlThread.durationOfLastRun 0.086167 s
2020-10-21T22:07:44.266Z,1603318064.266 [Reporter](INFO): controlThread.durationOfLastRun 0.068523 s
2020-10-21T22:07:44.671Z,1603318064.671 [Reporter](INFO): controlThread.durationOfLastRun 0.077855 s
2020-10-21T22:07:45.082Z,1603318065.082 [Reporter](INFO): controlThread.durationOfLastRun 0.079101 s
2020-10-21T22:07:45.466Z,1603318065.466 [Reporter](INFO): controlThread.durationOfLastRun 0.085776 s
2020-10-21T22:07:45.883Z,1603318065.883 [Reporter](INFO): controlThread.durationOfLastRun 0.065881 s
2020-10-21T22:07:46.294Z,1603318066.294 [Reporter](INFO): controlThread.durationOfLastRun 0.078592 s
2020-10-21T22:07:46.694Z,1603318066.694 [Reporter](INFO): controlThread.durationOfLastRun 0.085411 s
2020-10-21T22:07:47.078Z,1603318067.078 [Reporter](INFO): controlThread.durationOfLastRun 0.081999 s
2020-10-21T22:07:47.101Z,1603318067.101 [CommandLine](IMPORTANT): got command stop
2020-10-21T22:07:47.101Z,1603318067.101 [CommandLine](IMPORTANT): Scheduling is paused
2020-10-21T22:07:47.101Z,1603318067.101 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2020-10-21T22:07:47.509Z,1603318067.509 [MissionManager](INFO): MissionManager is completed.
2020-10-21T22:07:47.509Z,1603318067.509 [MissionManager](INFO): Uninitializing Mission bsd
2020-10-21T22:07:47.509Z,1603318067.509 [bsd] Stopped
2020-10-21T22:07:47.509Z,1603318067.509 [bsd](DEBUG): Aggregate::uninitialize bsd
2020-10-21T22:07:47.509Z,1603318067.509 [bsd:B.BackseatDriver] Stopped
2020-10-21T22:07:47.509Z,1603318067.509 [bsd:B.BackseatDriver](DEBUG): Uninitialize.
2020-10-21T22:07:47.510Z,1603318067.510 [bsd:C.GoToSurface] Stopped
2020-10-21T22:07:47.510Z,1603318067.510 [bsd:C.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-21T22:07:47.510Z,1603318067.510 [bsd:CheckIn] Stopped
2020-10-21T22:07:47.510Z,1603318067.510 [bsd:CheckIn](DEBUG): Aggregate::uninitialize bsd:CheckIn
2020-10-21T22:07:47.510Z,1603318067.510 [bsd:CheckIn:C.Wait] Stopped
2020-10-21T22:07:47.510Z,1603318067.510 [bsd:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-10-21T22:07:47.528Z,1603318067.528 [BackseatComponent](INFO): Sent LCM shutdown request.
2020-10-21T22:07:47.569Z,1603318067.569 [LcmUniversalReporter](INFO): Deactivating messaging.
2020-10-21T22:07:47.573Z,1603318067.573 [Reporter](INFO): controlThread.durationOfLastRun 0.061705 s
2020-10-21T22:07:47.855Z,1603318067.855 [MissionManager](IMPORTANT): Started mission Default
2020-10-21T22:07:47.855Z,1603318067.855 [Default] Running Loop=1
2020-10-21T22:07:47.855Z,1603318067.855 [Default](DEBUG): Aggregate::initialize Default
2020-10-21T22:07:47.855Z,1603318067.855 [Default:B.GoToSurface] Running Loop=1
2020-10-21T22:07:47.855Z,1603318067.855 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-21T22:07:47.856Z,1603318067.856 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-21T22:07:47.856Z,1603318067.856 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-21T22:07:47.856Z,1603318067.856 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-21T22:07:47.857Z,1603318067.857 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-21T22:07:47.857Z,1603318067.857 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-21T22:07:47.858Z,1603318067.858 [Default:A.Wait] Running Loop=1
2020-10-21T22:07:47.858Z,1603318067.858 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-10-21T22:07:47.868Z,1603318067.868 [Reporter](INFO): controlThread.durationOfLastRun 0.160317 s
2020-10-21T22:07:48.277Z,1603318068.277 [Reporter](INFO): controlThread.durationOfLastRun 0.044393 s
2020-10-21T22:07:48.666Z,1603318068.666 [Reporter](INFO): controlThread.durationOfLastRun 0.049003 s
2020-10-21T22:07:49.065Z,1603318069.065 [Reporter](INFO): controlThread.durationOfLastRun 0.033825 s
2020-10-21T22:07:49.479Z,1603318069.479 [Reporter](INFO): controlThread.durationOfLastRun 0.029215 s
2020-10-21T22:07:49.893Z,1603318069.893 [Reporter](INFO): controlThread.durationOfLastRun 0.038425 s
2020-10-21T22:07:50.282Z,1603318070.282 [Reporter](INFO): controlThread.durationOfLastRun 0.049228 s
2020-10-21T22:07:50.725Z,1603318070.725 [Reporter](INFO): controlThread.durationOfLastRun 0.033684 s
2020-10-21T22:07:51.110Z,1603318071.110 [Reporter](INFO): controlThread.durationOfLastRun 0.072720 s
2020-10-21T22:07:51.494Z,1603318071.494 [Reporter](INFO): controlThread.durationOfLastRun 0.053801 s
2020-10-21T22:07:51.898Z,1603318071.898 [Reporter](INFO): controlThread.durationOfLastRun 0.033569 s
2020-10-21T22:07:52.310Z,1603318072.310 [Reporter](INFO): controlThread.durationOfLastRun 0.033460 s
2020-10-21T22:07:52.726Z,1603318072.726 [Reporter](INFO): controlThread.durationOfLastRun 0.041478 s
2020-10-21T22:07:53.106Z,1603318073.106 [Reporter](INFO): controlThread.durationOfLastRun 0.053623 s
2020-10-21T22:07:53.518Z,1603318073.518 [Reporter](INFO): controlThread.durationOfLastRun 0.029384 s
2020-10-21T22:07:53.947Z,1603318073.947 [Reporter](INFO): controlThread.durationOfLastRun 0.037722 s
2020-10-21T22:07:54.338Z,1603318074.338 [Reporter](INFO): controlThread.durationOfLastRun 0.062535 s
2020-10-21T22:07:54.726Z,1603318074.726 [Reporter](INFO): controlThread.durationOfLastRun 0.049378 s
2020-10-21T22:07:55.130Z,1603318075.130 [Reporter](INFO): controlThread.durationOfLastRun 0.033333 s
2020-10-21T22:07:55.546Z,1603318075.546 [Reporter](INFO): controlThread.durationOfLastRun 0.034052 s
2020-10-21T22:07:55.953Z,1603318075.953 [Reporter](INFO): controlThread.durationOfLastRun 0.046042 s
2020-10-21T22:07:56.342Z,1603318076.342 [Reporter](INFO): controlThread.durationOfLastRun 0.049056 s
2020-10-21T22:07:56.746Z,1603318076.746 [Reporter](INFO): controlThread.durationOfLastRun 0.034292 s
2020-10-21T22:07:57.195Z,1603318077.195 [Reporter](INFO): controlThread.durationOfLastRun 0.033866 s
2020-10-21T22:07:57.553Z,1603318077.553 [Reporter](INFO): controlThread.durationOfLastRun 0.078924 s
2020-10-21T22:07:57.958Z,1603318077.958 [Reporter](INFO): controlThread.durationOfLastRun 0.032926 s
2020-10-21T22:07:58.374Z,1603318078.374 [Reporter](INFO): controlThread.durationOfLastRun 0.033734 s
2020-10-21T22:07:58.782Z,1603318078.782 [Reporter](INFO): controlThread.durationOfLastRun 0.045607 s
2020-10-21T22:07:59.166Z,1603318079.166 [Reporter](INFO): controlThread.durationOfLastRun 0.050281 s
2020-10-21T22:07:59.574Z,1603318079.574 [Reporter](INFO): controlThread.durationOfLastRun 0.030066 s
2020-10-21T22:07:59.983Z,1603318079.983 [Reporter](INFO): controlThread.durationOfLastRun 0.034190 s
2020-10-21T22:08:00.420Z,1603318080.420 [Reporter](INFO): controlThread.durationOfLastRun 0.038786 s
2020-10-21T22:08:00.821Z,1603318080.821 [Reporter](INFO): controlThread.durationOfLastRun 0.104150 s
2020-10-21T22:08:01.176Z,1603318081.176 [Default:A.Wait](INFO): Done Waiting.
2020-10-21T22:08:01.176Z,1603318081.176 [Default:A.Wait] Stopped
2020-10-21T22:08:01.176Z,1603318081.176 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-10-21T22:08:01.186Z,1603318081.186 [Reporter](INFO): controlThread.durationOfLastRun 0.068529 s
2020-10-21T22:08:01.591Z,1603318081.591 [Default:CheckIn] Running Loop=1
2020-10-21T22:08:01.591Z,1603318081.591 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-10-21T22:08:01.591Z,1603318081.591 [Default:CheckIn:Read_GPS] Running Loop=1
2020-10-21T22:08:01.602Z,1603318081.602 [Reporter](INFO): controlThread.durationOfLastRun 0.029654 s
2020-10-21T22:08:02.014Z,1603318082.014 [Reporter](INFO): controlThread.durationOfLastRun 0.041168 s
2020-10-21T22:08:02.403Z,1603318082.403 [Reporter](INFO): controlThread.durationOfLastRun 0.050219 s
2020-10-21T22:08:02.641Z,1603318082.641 [BackseatComponent](INFO): Powering down
2020-10-21T22:08:02.783Z,1603318082.783 [NAL9602](INFO): Powering up NAL9602
2020-10-21T22:08:02.810Z,1603318082.810 [Reporter](INFO): controlThread.durationOfLastRun 0.034456 s
2020-10-21T22:08:02.845Z,1603318082.845 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2020-10-21T22:08:03.193Z,1603318083.193 [Depth_Keller](INFO): Deactivating messaging.
2020-10-21T22:08:03.231Z,1603318083.231 [Reporter](INFO): controlThread.durationOfLastRun 0.037487 s
2020-10-21T22:08:03.643Z,1603318083.643 [Reporter](INFO): controlThread.durationOfLastRun 0.054357 s
2020-10-21T22:08:04.045Z,1603318084.045 [Reporter](INFO): controlThread.durationOfLastRun 0.061611 s
2020-10-21T22:08:04.426Z,1603318084.426 [Reporter](INFO): controlThread.durationOfLastRun 0.060946 s
2020-10-21T22:08:04.833Z,1603318084.833 [Reporter](INFO): controlThread.durationOfLastRun 0.037250 s
2020-10-21T22:08:05.244Z,1603318085.244 [Reporter](INFO): controlThread.durationOfLastRun 0.041196 s
2020-10-21T22:08:05.632Z,1603318085.632 [Reporter](INFO): controlThread.durationOfLastRun 0.048340 s
2020-10-21T22:08:06.032Z,1603318086.032 [Reporter](INFO): controlThread.durationOfLastRun 0.032051 s
2020-10-21T22:08:06.448Z,1603318086.448 [Reporter](INFO): controlThread.durationOfLastRun 0.028800 s
2020-10-21T22:08:06.874Z,1603318086.874 [Reporter](INFO): controlThread.durationOfLastRun 0.040351 s
2020-10-21T22:08:07.246Z,1603318087.246 [Reporter](INFO): controlThread.durationOfLastRun 0.062021 s
2020-10-21T22:08:07.654Z,1603318087.654 [Reporter](INFO): controlThread.durationOfLastRun 0.029656 s
2020-10-21T22:08:08.070Z,1603318088.070 [Reporter](INFO): controlThread.durationOfLastRun 0.033491 s
2020-10-21T22:08:08.477Z,1603318088.477 [Reporter](INFO): controlThread.durationOfLastRun 0.046039 s
2020-10-21T22:08:08.864Z,1603318088.864 [Reporter](INFO): controlThread.durationOfLastRun 0.048956 s
2020-10-21T22:08:09.270Z,1603318089.270 [Reporter](INFO): controlThread.durationOfLastRun 0.031755 s
2020-10-21T22:08:09.678Z,1603318089.678 [Reporter](INFO): controlThread.durationOfLastRun 0.033421 s
2020-10-21T22:08:10.106Z,1603318090.106 [Reporter](INFO): controlThread.durationOfLastRun 0.037347 s
2020-10-21T22:08:10.506Z,1603318090.506 [Reporter](INFO): controlThread.durationOfLastRun 0.062160 s
2020-10-21T22:08:10.882Z,1603318090.882 [Reporter](INFO): controlThread.durationOfLastRun 0.057268 s
2020-10-21T22:08:11.293Z,1603318091.293 [Reporter](INFO): controlThread.durationOfLastRun 0.029973 s
2020-10-21T22:08:11.706Z,1603318091.706 [Reporter](INFO): controlThread.durationOfLastRun 0.036886 s
2020-10-21T22:08:12.092Z,1603318092.092 [Reporter](INFO): controlThread.durationOfLastRun 0.046212 s
2020-10-21T22:08:12.502Z,1603318092.502 [Reporter](INFO): controlThread.durationOfLastRun 0.028083 s
2020-10-21T22:08:12.910Z,1603318092.910 [Reporter](INFO): controlThread.durationOfLastRun 0.033549 s
2020-10-21T22:08:13.395Z,1603318093.395 [Reporter](INFO): controlThread.durationOfLastRun 0.038206 s
2020-10-21T22:08:13.690Z,1603318093.690 [NAL9602](INFO): NAL9602 initialized
2020-10-21T22:08:13.738Z,1603318093.738 [Reporter](INFO): controlThread.durationOfLastRun 0.118394 s
2020-10-21T22:08:14.121Z,1603318094.121 [Reporter](INFO): controlThread.durationOfLastRun 0.058053 s
2020-10-21T22:08:14.563Z,1603318094.563 [Reporter](INFO): controlThread.durationOfLastRun 0.036627 s
2020-10-21T22:08:14.939Z,1603318094.939 [Reporter](INFO): controlThread.durationOfLastRun 0.075263 s
2020-10-21T22:08:15.373Z,1603318095.373 [Reporter](INFO): controlThread.durationOfLastRun 0.047240 s
2020-10-21T22:08:15.781Z,1603318095.781 [Reporter](INFO): controlThread.durationOfLastRun 0.076776 s
2020-10-21T22:08:16.154Z,1603318096.154 [Reporter](INFO): controlThread.durationOfLastRun 0.080969 s
2020-10-21T22:08:16.630Z,1603318096.630 [Reporter](INFO): controlThread.durationOfLastRun 0.050180 s
2020-10-21T22:08:16.983Z,1603318096.983 [Reporter](INFO): controlThread.durationOfLastRun 0.121693 s
2020-10-21T22:08:17.390Z,1603318097.390 [Reporter](INFO): controlThread.durationOfLastRun 0.070664 s
2020-10-21T22:08:17.805Z,1603318097.805 [Reporter](INFO): controlThread.durationOfLastRun 0.073362 s
2020-10-21T22:08:18.182Z,1603318098.182 [Reporter](INFO): controlThread.durationOfLastRun 0.084544 s
2020-10-21T22:08:18.590Z,1603318098.590 [Reporter](INFO): controlThread.durationOfLastRun 0.057795 s
2020-10-21T22:08:18.966Z,1603318098.966 [Reporter](INFO): controlThread.durationOfLastRun 0.061749 s
2020-10-21T22:08:19.377Z,1603318099.377 [Reporter](INFO): controlThread.durationOfLastRun 0.033879 s
2020-10-21T22:08:19.808Z,1603318099.808 [Reporter](INFO): controlThread.durationOfLastRun 0.040561 s
2020-10-21T22:08:20.207Z,1603318100.207 [Reporter](INFO): controlThread.durationOfLastRun 0.067294 s
2020-10-21T22:08:20.639Z,1603318100.639 [Reporter](INFO): controlThread.durationOfLastRun 0.063127 s
2020-10-21T22:08:21.009Z,1603318101.009 [Reporter](INFO): controlThread.durationOfLastRun 0.090808 s
2020-10-21T22:08:21.392Z,1603318101.392 [Reporter](INFO): controlThread.durationOfLastRun 0.056619 s
2020-10-21T22:08:21.802Z,1603318101.802 [Reporter](INFO): controlThread.durationOfLastRun 0.035485 s
2020-10-21T22:08:22.213Z,1603318102.213 [Reporter](INFO): controlThread.durationOfLastRun 0.042042 s
2020-10-21T22:08:22.600Z,1603318102.600 [Reporter](INFO): controlThread.durationOfLastRun 0.049198 s
2020-10-21T22:08:23.050Z,1603318103.050 [Reporter](INFO): controlThread.durationOfLastRun 0.032088 s
2020-10-21T22:08:23.438Z,1603318103.438 [Reporter](INFO): controlThread.durationOfLastRun 0.077206 s
2020-10-21T22:08:23.841Z,1603318103.841 [Reporter](INFO): controlThread.durationOfLastRun 0.061903 s
2020-10-21T22:08:24.217Z,1603318104.217 [Reporter](INFO): controlThread.durationOfLastRun 0.060985 s
2020-10-21T22:08:24.622Z,1603318104.622 [Reporter](INFO): controlThread.durationOfLastRun 0.032838 s
2020-10-21T22:08:25.033Z,1603318105.033 [Reporter](INFO): controlThread.durationOfLastRun 0.033448 s
2020-10-21T22:08:25.445Z,1603318105.445 [Reporter](INFO): controlThread.durationOfLastRun 0.040905 s
2020-10-21T22:08:25.864Z,1603318105.864 [Reporter](INFO): controlThread.durationOfLastRun 0.048820 s
2020-10-21T22:08:26.294Z,1603318106.294 [Reporter](INFO): controlThread.durationOfLastRun 0.064155 s
2020-10-21T22:08:26.654Z,1603318106.654 [Reporter](INFO): controlThread.durationOfLastRun 0.088926 s
2020-10-21T22:08:27.060Z,1603318107.060 [Reporter](INFO): controlThread.durationOfLastRun 0.045398 s
2020-10-21T22:08:27.448Z,1603318107.448 [Reporter](INFO): controlThread.durationOfLastRun 0.047858 s
2020-10-21T22:08:27.854Z,1603318107.854 [Reporter](INFO): controlThread.durationOfLastRun 0.032063 s
2020-10-21T22:08:28.263Z,1603318108.263 [Reporter](INFO): controlThread.durationOfLastRun 0.033618 s
2020-10-21T22:08:28.677Z,1603318108.677 [Reporter](INFO): controlThread.durationOfLastRun 0.038698 s
2020-10-21T22:08:29.100Z,1603318109.100 [Reporter](INFO): controlThread.durationOfLastRun 0.049137 s
2020-10-21T22:08:29.515Z,1603318109.515 [Reporter](INFO): controlThread.durationOfLastRun 0.067378 s
2020-10-21T22:08:29.902Z,1603318109.902 [Reporter](INFO): controlThread.durationOfLastRun 0.078770 s
2020-10-21T22:08:30.294Z,1603318110.294 [Reporter](INFO): controlThread.durationOfLastRun 0.061978 s
2020-10-21T22:08:30.682Z,1603318110.682 [Reporter](INFO): controlThread.durationOfLastRun 0.049661 s
2020-10-21T22:08:31.094Z,1603318111.094 [Reporter](INFO): controlThread.durationOfLastRun 0.033835 s
2020-10-21T22:08:31.503Z,1603318111.503 [Reporter](INFO): controlThread.durationOfLastRun 0.041609 s
2020-10-21T22:08:31.918Z,1603318111.918 [Reporter](INFO): controlThread.durationOfLastRun 0.046788 s
2020-10-21T22:08:32.334Z,1603318112.334 [Reporter](INFO): controlThread.durationOfLastRun 0.057867 s
2020-10-21T22:08:32.746Z,1603318112.746 [Reporter](INFO): controlThread.durationOfLastRun 0.070097 s
2020-10-21T22:08:33.116Z,1603318113.116 [Reporter](INFO): controlThread.durationOfLastRun 0.077832 s
2020-10-21T22:08:33.529Z,1603318113.529 [Reporter](INFO): controlThread.durationOfLastRun 0.044237 s
2020-10-21T22:08:33.914Z,1603318113.914 [Reporter](INFO): controlThread.durationOfLastRun 0.052663 s
2020-10-21T22:08:34.322Z,1603318114.322 [Reporter](INFO): controlThread.durationOfLastRun 0.033492 s
2020-10-21T22:08:34.742Z,1603318114.742 [Reporter](INFO): controlThread.durationOfLastRun 0.038159 s
2020-10-21T22:08:35.164Z,1603318115.164 [Reporter](INFO): controlThread.durationOfLastRun 0.053262 s
2020-10-21T22:08:35.545Z,1603318115.545 [Reporter](INFO): controlThread.durationOfLastRun 0.073231 s
2020-10-21T22:08:35.983Z,1603318115.983 [Reporter](INFO): controlThread.durationOfLastRun 0.048299 s
2020-10-21T22:08:36.373Z,1603318116.373 [Reporter](INFO): controlThread.durationOfLastRun 0.082334 s
2020-10-21T22:08:36.778Z,1603318116.778 [Reporter](INFO): controlThread.durationOfLastRun 0.068891 s
2020-10-21T22:08:37.171Z,1603318117.171 [Reporter](INFO): controlThread.durationOfLastRun 0.069694 s
2020-10-21T22:08:37.574Z,1603318117.574 [Reporter](INFO): controlThread.durationOfLastRun 0.058268 s
2020-10-21T22:08:37.979Z,1603318117.979 [Reporter](INFO): controlThread.durationOfLastRun 0.058078 s
2020-10-21T22:08:38.360Z,1603318118.360 [Reporter](INFO): controlThread.durationOfLastRun 0.059243 s
2020-10-21T22:08:38.780Z,1603318118.780 [Reporter](INFO): controlThread.durationOfLastRun 0.034733 s
2020-10-21T22:08:39.202Z,1603318119.202 [Reporter](INFO): controlThread.durationOfLastRun 0.051413 s
2020-10-21T22:08:39.568Z,1603318119.568 [Reporter](INFO): controlThread.durationOfLastRun 0.068618 s
2020-10-21T22:08:39.986Z,1603318119.986 [Reporter](INFO): controlThread.durationOfLastRun 0.032083 s
2020-10-21T22:08:40.398Z,1603318120.398 [Reporter](INFO): controlThread.durationOfLastRun 0.045840 s
2020-10-21T22:08:40.834Z,1603318120.834 [Reporter](INFO): controlThread.durationOfLastRun 0.053564 s
2020-10-21T22:08:41.202Z,1603318121.202 [Reporter](INFO): controlThread.durationOfLastRun 0.085923 s
2020-10-21T22:08:41.590Z,1603318121.590 [Reporter](INFO): controlThread.durationOfLastRun 0.049505 s
2020-10-21T22:08:41.998Z,1603318121.998 [Reporter](INFO): controlThread.durationOfLastRun 0.034278 s
2020-10-21T22:08:42.414Z,1603318122.414 [Reporter](INFO): controlThread.durationOfLastRun 0.037416 s
2020-10-21T22:08:42.826Z,1603318122.826 [Reporter](INFO): controlThread.durationOfLastRun 0.049718 s
2020-10-21T22:08:43.241Z,1603318123.241 [Reporter](INFO): controlThread.durationOfLastRun 0.057433 s
2020-10-21T22:08:43.634Z,1603318123.634 [Reporter](INFO): controlThread.durationOfLastRun 0.069203 s
2020-10-21T22:08:44.025Z,1603318124.025 [Reporter](INFO): controlThread.durationOfLastRun 0.058001 s
2020-10-21T22:08:44.416Z,1603318124.416 [Reporter](INFO): controlThread.durationOfLastRun 0.044830 s
2020-10-21T22:08:44.822Z,1603318124.822 [Reporter](INFO): controlThread.durationOfLastRun 0.048073 s
2020-10-21T22:08:45.234Z,1603318125.234 [Reporter](INFO): controlThread.durationOfLastRun 0.033416 s
2020-10-21T22:08:45.645Z,1603318125.645 [Reporter](INFO): controlThread.durationOfLastRun 0.041502 s
2020-10-21T22:08:46.066Z,1603318126.066 [Reporter](INFO): controlThread.durationOfLastRun 0.048967 s
2020-10-21T22:08:46.476Z,1603318126.476 [Reporter](INFO): controlThread.durationOfLastRun 0.066114 s
2020-10-21T22:08:46.866Z,1603318126.866 [Reporter](INFO): controlThread.durationOfLastRun 0.072150 s
2020-10-21T22:08:47.261Z,1603318127.261 [Reporter](INFO): controlThread.durationOfLastRun 0.057972 s
2020-10-21T22:08:47.644Z,1603318127.644 [Reporter](INFO): controlThread.durationOfLastRun 0.049007 s
2020-10-21T22:08:48.053Z,1603318128.053 [Reporter](INFO): controlThread.durationOfLastRun 0.028467 s
2020-10-21T22:08:48.490Z,1603318128.490 [Reporter](INFO): controlThread.durationOfLastRun 0.033196 s
2020-10-21T22:08:48.885Z,1603318128.885 [Reporter](INFO): controlThread.durationOfLastRun 0.066160 s
2020-10-21T22:08:49.298Z,1603318129.298 [Reporter](INFO): controlThread.durationOfLastRun 0.057303 s
2020-10-21T22:08:49.686Z,1603318129.686 [Reporter](INFO): controlThread.durationOfLastRun 0.066194 s
2020-10-21T22:08:50.076Z,1603318130.076 [Reporter](INFO): controlThread.durationOfLastRun 0.049111 s
2020-10-21T22:08:50.496Z,1603318130.496 [Reporter](INFO): controlThread.durationOfLastRun 0.036324 s
2020-10-21T22:08:50.892Z,1603318130.892 [Reporter](INFO): controlThread.durationOfLastRun 0.052341 s
2020-10-21T22:08:51.311Z,1603318131.311 [Reporter](INFO): controlThread.durationOfLastRun 0.064414 s
2020-10-21T22:08:51.787Z,1603318131.787 [Reporter](INFO): controlThread.durationOfLastRun 0.058607 s
2020-10-21T22:08:52.131Z,1603318132.131 [Reporter](INFO): controlThread.durationOfLastRun 0.130669 s
2020-10-21T22:08:52.547Z,1603318132.547 [Reporter](INFO): controlThread.durationOfLastRun 0.071336 s
2020-10-21T22:08:52.953Z,1603318132.953 [Reporter](INFO): controlThread.durationOfLastRun 0.083345 s
2020-10-21T22:08:53.338Z,1603318133.338 [Reporter](INFO): controlThread.durationOfLastRun 0.084525 s
2020-10-21T22:08:53.705Z,1603318133.705 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-10-21T22:08:53.705Z,1603318133.705 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T22:08:53.765Z,1603318133.765 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T22:08:53.766Z,1603318133.766 [Reporter](INFO): controlThread.durationOfLastRun 0.065753 s
2020-10-21T22:08:54.148Z,1603318134.148 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T22:08:54.148Z,1603318134.148 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-10-21T22:08:54.149Z,1603318134.149 [Reporter](INFO): controlThread.durationOfLastRun 0.089796 s
2020-10-21T22:08:54.539Z,1603318134.539 [Reporter](INFO): controlThread.durationOfLastRun 0.069050 s
2020-10-21T22:08:54.942Z,1603318134.942 [Reporter](INFO): controlThread.durationOfLastRun 0.055122 s
2020-10-21T22:08:55.358Z,1603318135.358 [Reporter](INFO): controlThread.durationOfLastRun 0.053666 s
2020-10-21T22:08:55.766Z,1603318135.766 [Reporter](INFO): controlThread.durationOfLastRun 0.065859 s
2020-10-21T22:08:56.142Z,1603318136.142 [Reporter](INFO): controlThread.durationOfLastRun 0.069147 s
2020-10-21T22:08:56.550Z,1603318136.550 [Reporter](INFO): controlThread.durationOfLastRun 0.041766 s
2020-10-21T22:08:56.938Z,1603318136.938 [Reporter](INFO): controlThread.durationOfLastRun 0.046036 s
2020-10-21T22:08:57.346Z,1603318137.346 [Reporter](INFO): controlThread.durationOfLastRun 0.029669 s
2020-10-21T22:08:57.766Z,1603318137.766 [Reporter](INFO): controlThread.durationOfLastRun 0.034035 s
2020-10-21T22:08:58.216Z,1603318138.216 [Reporter](INFO): controlThread.durationOfLastRun 0.049556 s
2020-10-21T22:08:58.582Z,1603318138.582 [Reporter](INFO): controlThread.durationOfLastRun 0.100240 s
2020-10-21T22:08:58.960Z,1603318138.960 [Reporter](INFO): controlThread.durationOfLastRun 0.057023 s
2020-10-21T22:08:59.374Z,1603318139.374 [Reporter](INFO): controlThread.durationOfLastRun 0.032039 s
2020-10-21T22:08:59.781Z,1603318139.781 [Reporter](INFO): controlThread.durationOfLastRun 0.040885 s
2020-10-21T22:09:00.189Z,1603318140.189 [Reporter](INFO): controlThread.durationOfLastRun 0.044902 s
2020-10-21T22:09:00.578Z,1603318140.578 [Reporter](INFO): controlThread.durationOfLastRun 0.049030 s
2020-10-21T22:09:00.987Z,1603318140.987 [Reporter](INFO): controlThread.durationOfLastRun 0.033507 s
2020-10-21T22:09:01.442Z,1603318141.442 [Reporter](INFO): controlThread.durationOfLastRun 0.038775 s
2020-10-21T22:09:01.819Z,1603318141.819 [Reporter](INFO): controlThread.durationOfLastRun 0.090222 s
2020-10-21T22:09:02.194Z,1603318142.194 [Reporter](INFO): controlThread.durationOfLastRun 0.062759 s
2020-10-21T22:09:02.601Z,1603318142.601 [Reporter](INFO): controlThread.durationOfLastRun 0.033496 s
2020-10-21T22:09:03.015Z,1603318143.015 [Reporter](INFO): controlThread.durationOfLastRun 0.037150 s
2020-10-21T22:09:03.422Z,1603318143.422 [Reporter](INFO): controlThread.durationOfLastRun 0.046456 s
2020-10-21T22:09:03.842Z,1603318143.842 [Reporter](INFO): controlThread.durationOfLastRun 0.049497 s
2020-10-21T22:09:04.239Z,1603318144.239 [Reporter](INFO): controlThread.durationOfLastRun 0.065572 s
2020-10-21T22:09:04.687Z,1603318144.687 [Reporter](INFO): controlThread.durationOfLastRun 0.058361 s
2020-10-21T22:09:05.028Z,1603318145.028 [Reporter](INFO): controlThread.durationOfLastRun 0.103016 s
2020-10-21T22:09:05.426Z,1603318145.426 [Reporter](INFO): controlThread.durationOfLastRun 0.039371 s
2020-10-21T22:09:05.855Z,1603318145.855 [Reporter](INFO): controlThread.durationOfLastRun 0.034218 s
2020-10-21T22:09:06.249Z,1603318146.249 [Reporter](INFO): controlThread.durationOfLastRun 0.058373 s
2020-10-21T22:09:06.638Z,1603318146.638 [Reporter](INFO): controlThread.durationOfLastRun 0.049147 s
2020-10-21T22:09:07.055Z,1603318147.055 [Reporter](INFO): controlThread.durationOfLastRun 0.033528 s
2020-10-21T22:09:07.465Z,1603318147.465 [Reporter](INFO): controlThread.durationOfLastRun 0.047334 s
2020-10-21T22:09:07.887Z,1603318147.887 [Reporter](INFO): controlThread.durationOfLastRun 0.053196 s
2020-10-21T22:09:08.258Z,1603318148.258 [Reporter](INFO): controlThread.durationOfLastRun 0.070211 s
2020-10-21T22:09:08.665Z,1603318148.665 [Reporter](INFO): controlThread.durationOfLastRun 0.037346 s
2020-10-21T22:09:09.084Z,1603318149.084 [Reporter](INFO): controlThread.durationOfLastRun 0.041204 s
2020-10-21T22:09:09.466Z,1603318149.466 [Reporter](INFO): controlThread.durationOfLastRun 0.055400 s
2020-10-21T22:09:09.912Z,1603318149.912 [Reporter](INFO): controlThread.durationOfLastRun 0.033437 s
2020-10-21T22:09:10.298Z,1603318150.298 [Reporter](INFO): controlThread.durationOfLastRun 0.076170 s
2020-10-21T22:09:10.702Z,1603318150.702 [Reporter](INFO): controlThread.durationOfLastRun 0.057771 s
2020-10-21T22:09:11.123Z,1603318151.123 [Reporter](INFO): controlThread.durationOfLastRun 0.057967 s
2020-10-21T22:09:11.514Z,1603318151.514 [Reporter](INFO): controlThread.durationOfLastRun 0.078007 s
2020-10-21T22:09:11.900Z,1603318151.900 [Reporter](INFO): controlThread.durationOfLastRun 0.065477 s
2020-10-21T22:09:12.306Z,1603318152.306 [Reporter](INFO): controlThread.durationOfLastRun 0.048092 s
2020-10-21T22:09:12.723Z,1603318152.723 [CommandLine](IMPORTANT): got command report clear
2020-10-21T22:09:47.243Z,1603318187.243 [CommandLine](IMPORTANT): got command run ./Missions/bsd.xml
2020-10-21T22:09:47.243Z,1603318187.243 [MissionManager](INFO): Loading Mission: ./Missions/bsd.xml
2020-10-21T22:09:47.268Z,1603318187.268 [MissionManager](INFO): DefineArg bsd.ElapsedSinceDefaultStarted = 0.000000 min
2020-10-21T22:09:47.268Z,1603318187.268 [bsd:A.Wait](DEBUG): Construct Wait.
2020-10-21T22:09:47.296Z,1603318187.296 [bsd:B.BackseatDriver](DEBUG): Construct BackseatDriver.
2020-10-21T22:09:47.300Z,1603318187.300 [bsd:C.GoToSurface](DEBUG): Construct GoToSurface.
2020-10-21T22:09:47.308Z,1603318187.308 [bsd:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-10-21T22:09:47.310Z,1603318187.310 [bsd:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-10-21T22:09:47.315Z,1603318187.315 [bsd:F.Execute](DEBUG): Construct Execute.
2020-10-21T22:09:47.318Z,1603318187.318 [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="bsd">

    <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: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="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>


2020-10-21T22:09:47.320Z,1603318187.320 [CommandLine](IMPORTANT): Running ./Missions/bsd.xml
2020-10-21T22:09:47.451Z,1603318187.451 [Default] Stopped
2020-10-21T22:09:47.451Z,1603318187.451 [Default](DEBUG): Aggregate::uninitialize Default
2020-10-21T22:09:47.451Z,1603318187.451 [Default:B.GoToSurface] Stopped
2020-10-21T22:09:47.451Z,1603318187.451 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-21T22:09:47.451Z,1603318187.451 [Default:CheckIn] Stopped
2020-10-21T22:09:47.451Z,1603318187.451 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-10-21T22:09:47.452Z,1603318187.452 [Default:CheckIn:Read_GPS] Stopped
2020-10-21T22:09:47.452Z,1603318187.452 [MissionManager](IMPORTANT): Started mission bsd
2020-10-21T22:09:47.452Z,1603318187.452 [bsd] Running Loop=1
2020-10-21T22:09:47.452Z,1603318187.452 [bsd](DEBUG): Aggregate::initialize bsd
2020-10-21T22:09:47.452Z,1603318187.452 [bsd:B.BackseatDriver] Running Loop=1
2020-10-21T22:09:47.452Z,1603318187.452 [bsd:B.BackseatDriver](DEBUG): Initialize.
2020-10-21T22:09:47.470Z,1603318187.470 [bsd:C.GoToSurface] Running Loop=1
2020-10-21T22:09:47.470Z,1603318187.470 [bsd:C.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-21T22:09:47.470Z,1603318187.470 [bsd:C.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-21T22:09:47.471Z,1603318187.471 [bsd:C.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-21T22:09:47.471Z,1603318187.471 [bsd:C.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-21T22:09:47.471Z,1603318187.471 [bsd:C.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-21T22:09:47.471Z,1603318187.471 [bsd:C.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-21T22:09:47.472Z,1603318187.472 [bsd:A.Wait] Running Loop=1
2020-10-21T22:09:47.472Z,1603318187.472 [bsd:A.Wait](DEBUG): Initialize Wait Component.
2020-10-21T22:09:47.473Z,1603318187.473 [bsd:B.BackseatDriver] Running Loop=1
2020-10-21T22:09:47.521Z,1603318187.521 [LcmUniversalReporter](ERROR): Failed to copy LcmUniversalReporter.enableBroadcast's data value to LCM message.
2020-10-21T22:09:47.521Z,1603318187.521 [LcmUniversalReporter](INFO): Activating messaging.
2020-10-21T22:09:47.609Z,1603318187.609 [BackseatComponent](INFO): Powering up
2020-10-21T22:09:47.609Z,1603318187.609 [BackseatComponent](INFO): Subscribing to LCM channels.
2020-10-21T22:10:00.785Z,1603318200.785 [bsd:A.Wait](INFO): Done Waiting.
2020-10-21T22:10:00.785Z,1603318200.785 [bsd:A.Wait] Stopped
2020-10-21T22:10:00.785Z,1603318200.785 [bsd:A.Wait](DEBUG): Uninitialize Wait Component.
2020-10-21T22:10:01.168Z,1603318201.168 [bsd:CheckIn] Running Loop=1
2020-10-21T22:10:01.168Z,1603318201.168 [bsd:CheckIn](DEBUG): Aggregate::initialize bsd:CheckIn
2020-10-21T22:10:01.168Z,1603318201.168 [bsd:CheckIn:Read_GPS] Running Loop=1
2020-10-21T22:10:01.576Z,1603318201.576 [bsd:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-10-21T22:10:22.882Z,1603318222.882 [BackseatComponent](IMPORTANT): jetson: running backseat application.
2020-10-21T22:10:25.796Z,1603318225.796 [Depth_Keller](ERROR): Failed to copy Depth_Keller.enableBroadcast's data value to LCM message.
2020-10-21T22:10:25.796Z,1603318225.796 [Depth_Keller](INFO): Activating messaging.
2020-10-21T22:11:23.936Z,1603318283.936 [CommandLine](INFO): End of History
2020-10-21T22:11:24.577Z,1603318284.577 [CommandLine](INFO): End of History
2020-10-21T22:11:29.487Z,1603318289.487 [CommandLine](IMPORTANT): got command report touch controlThread.durationOfLastRun
2020-10-21T22:11:30.104Z,1603318290.104 [Reporter](INFO): controlThread.durationOfLastRun 0.087360 s
2020-10-21T22:11:30.486Z,1603318290.486 [Reporter](INFO): controlThread.durationOfLastRun 0.083910 s
2020-10-21T22:11:30.956Z,1603318290.956 [Reporter](INFO): controlThread.durationOfLastRun 0.061438 s
2020-10-21T22:11:31.322Z,1603318291.322 [Reporter](INFO): controlThread.durationOfLastRun 0.128327 s
2020-10-21T22:11:31.730Z,1603318291.730 [Reporter](INFO): controlThread.durationOfLastRun 0.089498 s
2020-10-21T22:11:32.110Z,1603318292.110 [Reporter](INFO): controlThread.durationOfLastRun 0.093931 s
2020-10-21T22:11:32.526Z,1603318292.526 [Reporter](INFO): controlThread.durationOfLastRun 0.068898 s
2020-10-21T22:11:32.935Z,1603318292.935 [Reporter](INFO): controlThread.durationOfLastRun 0.081757 s
2020-10-21T22:11:33.337Z,1603318293.337 [Reporter](INFO): controlThread.durationOfLastRun 0.086279 s
2020-10-21T22:11:33.722Z,1603318293.722 [Reporter](INFO): controlThread.durationOfLastRun 0.085157 s
2020-10-21T22:11:34.142Z,1603318294.142 [Reporter](INFO): controlThread.durationOfLastRun 0.065258 s
2020-10-21T22:11:34.547Z,1603318294.547 [Reporter](INFO): controlThread.durationOfLastRun 0.081278 s
2020-10-21T22:11:34.962Z,1603318294.962 [Reporter](INFO): controlThread.durationOfLastRun 0.082730 s
2020-10-21T22:11:35.338Z,1603318295.338 [Reporter](INFO): controlThread.durationOfLastRun 0.093945 s
2020-10-21T22:11:35.787Z,1603318295.787 [Reporter](INFO): controlThread.durationOfLastRun 0.065801 s
2020-10-21T22:11:36.170Z,1603318296.170 [Reporter](INFO): controlThread.durationOfLastRun 0.110562 s
2020-10-21T22:11:36.550Z,1603318296.550 [Reporter](INFO): controlThread.durationOfLastRun 0.089600 s
2020-10-21T22:11:36.970Z,1603318296.970 [Reporter](INFO): controlThread.durationOfLastRun 0.065710 s
2020-10-21T22:11:37.378Z,1603318297.378 [Reporter](INFO): controlThread.durationOfLastRun 0.081252 s
2020-10-21T22:11:37.794Z,1603318297.794 [Reporter](INFO): controlThread.durationOfLastRun 0.085952 s
2020-10-21T22:11:38.170Z,1603318298.170 [Reporter](INFO): controlThread.durationOfLastRun 0.097883 s
2020-10-21T22:11:38.584Z,1603318298.584 [Reporter](INFO): controlThread.durationOfLastRun 0.069769 s
2020-10-21T22:11:38.998Z,1603318298.998 [Reporter](INFO): controlThread.durationOfLastRun 0.080064 s
2020-10-21T22:11:39.406Z,1603318299.406 [Reporter](INFO): controlThread.durationOfLastRun 0.089568 s
2020-10-21T22:11:39.819Z,1603318299.819 [Reporter](INFO): controlThread.durationOfLastRun 0.093419 s
2020-10-21T22:11:40.202Z,1603318300.202 [Reporter](INFO): controlThread.durationOfLastRun 0.102827 s
2020-10-21T22:11:40.614Z,1603318300.614 [Reporter](INFO): controlThread.durationOfLastRun 0.081691 s
2020-10-21T22:11:41.018Z,1603318301.018 [Reporter](INFO): controlThread.durationOfLastRun 0.089516 s
2020-10-21T22:11:41.398Z,1603318301.398 [Reporter](INFO): controlThread.durationOfLastRun 0.089705 s
2020-10-21T22:11:41.814Z,1603318301.814 [Reporter](INFO): controlThread.durationOfLastRun 0.065024 s
2020-10-21T22:11:42.228Z,1603318302.228 [Reporter](INFO): controlThread.durationOfLastRun 0.077718 s
2020-10-21T22:11:42.634Z,1603318302.634 [Reporter](INFO): controlThread.durationOfLastRun 0.092643 s
2020-10-21T22:11:43.054Z,1603318303.054 [Reporter](INFO): controlThread.durationOfLastRun 0.089686 s
2020-10-21T22:11:43.434Z,1603318303.434 [Reporter](INFO): controlThread.durationOfLastRun 0.105833 s
2020-10-21T22:11:43.846Z,1603318303.846 [Reporter](INFO): controlThread.durationOfLastRun 0.081429 s
2020-10-21T22:11:44.249Z,1603318304.249 [Reporter](INFO): controlThread.durationOfLastRun 0.089400 s
2020-10-21T22:11:44.634Z,1603318304.634 [Reporter](INFO): controlThread.durationOfLastRun 0.088657 s
2020-10-21T22:11:45.046Z,1603318305.046 [Reporter](INFO): controlThread.durationOfLastRun 0.069552 s
2020-10-21T22:11:45.495Z,1603318305.495 [Reporter](INFO): controlThread.durationOfLastRun 0.077470 s
2020-10-21T22:11:45.870Z,1603318305.870 [Reporter](INFO): controlThread.durationOfLastRun 0.122286 s
2020-10-21T22:11:46.284Z,1603318306.284 [Reporter](INFO): controlThread.durationOfLastRun 0.093622 s
2020-10-21T22:11:46.666Z,1603318306.666 [Reporter](INFO): controlThread.durationOfLastRun 0.103424 s
2020-10-21T22:11:47.071Z,1603318307.071 [Reporter](INFO): controlThread.durationOfLastRun 0.082239 s
2020-10-21T22:11:47.478Z,1603318307.478 [Reporter](INFO): controlThread.durationOfLastRun 0.082856 s
2020-10-21T22:11:47.862Z,1603318307.862 [Reporter](INFO): controlThread.durationOfLastRun 0.085433 s
2020-10-21T22:11:48.312Z,1603318308.312 [Reporter](INFO): controlThread.durationOfLastRun 0.065654 s
2020-10-21T22:11:48.750Z,1603318308.750 [Reporter](INFO): controlThread.durationOfLastRun 0.112108 s
2020-10-21T22:11:49.098Z,1603318309.098 [Reporter](INFO): controlThread.durationOfLastRun 0.145525 s
2020-10-21T22:11:49.522Z,1603318309.522 [Reporter](INFO): controlThread.durationOfLastRun 0.090122 s
2020-10-21T22:11:49.921Z,1603318309.921 [Reporter](INFO): controlThread.durationOfLastRun 0.109159 s
2020-10-21T22:11:50.302Z,1603318310.302 [Reporter](INFO): controlThread.durationOfLastRun 0.104604 s
2020-10-21T22:11:50.706Z,1603318310.706 [Reporter](INFO): controlThread.durationOfLastRun 0.081207 s
2020-10-21T22:11:51.117Z,1603318311.117 [CBIT](INFO): Clearing failed state for component DropWeight
2020-10-21T22:11:51.117Z,1603318311.117 [DropWeight] No Fault, FailCount= 1
2020-10-21T22:11:51.122Z,1603318311.122 [Reporter](INFO): controlThread.durationOfLastRun 0.082127 s
2020-10-21T22:11:51.193Z,1603318311.193 [CommandLine](IMPORTANT): got command stop
2020-10-21T22:11:51.193Z,1603318311.193 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2020-10-21T22:11:51.485Z,1603318311.485 [MissionManager](INFO): MissionManager is completed.
2020-10-21T22:11:51.485Z,1603318311.485 [MissionManager](INFO): Uninitializing Mission bsd
2020-10-21T22:11:51.485Z,1603318311.485 [bsd] Stopped
2020-10-21T22:11:51.485Z,1603318311.485 [bsd](DEBUG): Aggregate::uninitialize bsd
2020-10-21T22:11:51.485Z,1603318311.485 [bsd:B.BackseatDriver] Stopped
2020-10-21T22:11:51.485Z,1603318311.485 [bsd:B.BackseatDriver](DEBUG): Uninitialize.
2020-10-21T22:11:51.485Z,1603318311.485 [bsd:C.GoToSurface] Stopped
2020-10-21T22:11:51.486Z,1603318311.486 [bsd:C.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-21T22:11:51.486Z,1603318311.486 [bsd:CheckIn] Stopped
2020-10-21T22:11:51.486Z,1603318311.486 [bsd:CheckIn](DEBUG): Aggregate::uninitialize bsd:CheckIn
2020-10-21T22:11:51.486Z,1603318311.486 [bsd:CheckIn:Read_GPS] Stopped
2020-10-21T22:11:51.510Z,1603318311.510 [LcmUniversalReporter](INFO): Deactivating messaging.
2020-10-21T22:11:51.518Z,1603318311.518 [Reporter](INFO): controlThread.durationOfLastRun 0.093554 s
2020-10-21T22:11:51.879Z,1603318311.879 [MissionManager](IMPORTANT): Started mission Default
2020-10-21T22:11:51.879Z,1603318311.879 [Default] Running Loop=1
2020-10-21T22:11:51.879Z,1603318311.879 [Default](DEBUG): Aggregate::initialize Default
2020-10-21T22:11:51.879Z,1603318311.879 [Default:B.GoToSurface] Running Loop=1
2020-10-21T22:11:51.879Z,1603318311.879 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-21T22:11:51.880Z,1603318311.880 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-21T22:11:51.880Z,1603318311.880 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-21T22:11:51.880Z,1603318311.880 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-21T22:11:51.930Z,1603318311.930 [BackseatComponent](INFO): Sent LCM shutdown request.
2020-10-21T22:11:51.950Z,1603318311.950 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-21T22:11:51.951Z,1603318311.951 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-21T22:11:51.952Z,1603318311.952 [Default:A.Wait] Running Loop=1
2020-10-21T22:11:51.952Z,1603318311.952 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-10-21T22:11:51.982Z,1603318311.982 [Reporter](INFO): controlThread.durationOfLastRun 0.085513 s
2020-10-21T22:11:52.302Z,1603318312.302 [Reporter](INFO): controlThread.durationOfLastRun 0.145885 s
2020-10-21T22:11:52.706Z,1603318312.706 [Reporter](INFO): controlThread.durationOfLastRun 0.061782 s
2020-10-21T22:11:53.086Z,1603318313.086 [Reporter](INFO): controlThread.durationOfLastRun 0.061969 s
2020-10-21T22:11:53.494Z,1603318313.494 [Reporter](INFO): controlThread.durationOfLastRun 0.037687 s
2020-10-21T22:11:53.903Z,1603318313.903 [Reporter](INFO): controlThread.durationOfLastRun 0.041408 s
2020-10-21T22:11:54.310Z,1603318314.310 [Reporter](INFO): controlThread.durationOfLastRun 0.046779 s
2020-10-21T22:11:54.703Z,1603318314.703 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-10-21T22:11:54.703Z,1603318314.703 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T22:11:54.741Z,1603318314.741 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T22:11:54.743Z,1603318314.743 [Reporter](INFO): controlThread.durationOfLastRun 0.050138 s
2020-10-21T22:11:55.124Z,1603318315.124 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T22:11:55.124Z,1603318315.124 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-10-21T22:11:55.126Z,1603318315.126 [Reporter](INFO): controlThread.durationOfLastRun 0.078414 s
2020-10-21T22:11:55.528Z,1603318315.528 [Reporter](INFO): controlThread.durationOfLastRun 0.057464 s
2020-10-21T22:11:55.911Z,1603318315.911 [Reporter](INFO): controlThread.durationOfLastRun 0.056222 s
2020-10-21T22:11:56.327Z,1603318316.327 [Reporter](INFO): controlThread.durationOfLastRun 0.034475 s
2020-10-21T22:11:56.746Z,1603318316.746 [Reporter](INFO): controlThread.durationOfLastRun 0.046625 s
2020-10-21T22:11:57.150Z,1603318317.150 [Reporter](INFO): controlThread.durationOfLastRun 0.061542 s
2020-10-21T22:11:57.562Z,1603318317.562 [Reporter](INFO): controlThread.durationOfLastRun 0.061758 s
2020-10-21T22:11:57.938Z,1603318317.938 [Reporter](INFO): controlThread.durationOfLastRun 0.069791 s
2020-10-21T22:11:58.392Z,1603318318.392 [Reporter](INFO): controlThread.durationOfLastRun 0.041653 s
2020-10-21T22:11:58.615Z,1603318318.615 [CommandLine](IMPORTANT): got command report clear
2020-10-21T22:12:05.236Z,1603318325.236 [Default:A.Wait](INFO): Done Waiting.
2020-10-21T22:12:05.236Z,1603318325.236 [Default:A.Wait] Stopped
2020-10-21T22:12:05.236Z,1603318325.236 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-10-21T22:12:05.641Z,1603318325.641 [Default:CheckIn] Running Loop=1
2020-10-21T22:12:05.642Z,1603318325.642 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-10-21T22:12:05.642Z,1603318325.642 [Default:CheckIn:Read_GPS] Running Loop=1
2020-10-21T22:12:07.033Z,1603318327.033 [BackseatComponent](INFO): Powering down
2020-10-21T22:12:07.237Z,1603318327.237 [BackseatComponent](INFO): Unsubscribing from LCM channels.
2020-10-21T22:12:07.624Z,1603318327.624 [Depth_Keller](INFO): Deactivating messaging.
2020-10-21T22:14:55.734Z,1603318495.734 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-10-21T22:14:55.734Z,1603318495.734 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T22:14:55.744Z,1603318495.744 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T22:14:56.153Z,1603318496.153 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T22:14:56.153Z,1603318496.153 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-10-21T22:17:05.829Z,1603318625.829 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-10-21T22:12:05.6Z
2020-10-21T22:17:05.829Z,1603318625.829 [Default:CheckIn:Read_GPS] Stopped
2020-10-21T22:17:05.830Z,1603318625.830 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-10-21T22:17:06.232Z,1603318626.232 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-10-21T22:17:13.044Z,1603318633.044 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20201021T215639/Courier0007.lzma
2020-10-21T22:17:14.047Z,1603318634.047 [DataOverHttps](INFO): Moved sent file to Logs/20201021T215639/Courier0007.lzma.bak
2020-10-21T22:17:14.047Z,1603318634.047 [DataOverHttps](INFO): SBD MOMSN=12951757
2020-10-21T22:17:29.945Z,1603318649.945 [DataOverHttps](INFO): Sending 333 bytes from file Logs/20201021T215639/Express0008.lzma
2020-10-21T22:17:30.947Z,1603318650.947 [DataOverHttps](INFO): Moved sent file to Logs/20201021T215639/Express0008.lzma.bak
2020-10-21T22:17:30.947Z,1603318650.947 [DataOverHttps](INFO): SBD MOMSN=12951759
2020-10-21T22:17:32.512Z,1603318652.512 [Default:CheckIn:Read_Iridium] Stopped
2020-10-21T22:17:32.512Z,1603318652.512 [Default:CheckIn:C.Wait] Running Loop=1
2020-10-21T22:17:32.512Z,1603318652.512 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-10-21T22:17:56.742Z,1603318676.742 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-10-21T22:17:56.742Z,1603318676.742 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T22:17:56.753Z,1603318676.753 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T22:17:57.168Z,1603318677.168 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T22:17:57.168Z,1603318677.168 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-10-21T22:18:14.890Z,1603318694.890 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-10-21T22:18:14.891Z,1603318694.891 [NAL9602] Data Fault, FailCount= 2
2020-10-21T22:18:14.891Z,1603318694.891 [NAL9602](ERROR): Data Fault
2020-10-21T22:18:14.949Z,1603318694.949 [CBIT](ERROR): Data Fault in component: NAL9602
2020-10-21T22:18:15.294Z,1603318695.294 [NAL9602](INFO): Powering down
2020-10-21T22:18:16.129Z,1603318696.129 [CBIT](INFO): Clearing failed state for component NAL9602
2020-10-21T22:18:16.129Z,1603318696.129 [NAL9602] No Fault, FailCount= 2
2020-10-21T22:18:45.631Z,1603318725.631 [NAL9602](INFO): Powering up NAL9602
2020-10-21T22:18:56.531Z,1603318736.531 [NAL9602](INFO): NAL9602 initialized
2020-10-21T22:20:57.774Z,1603318857.774 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-10-21T22:20:57.774Z,1603318857.774 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-10-21T22:20:57.784Z,1603318857.784 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-10-21T22:20:58.183Z,1603318858.183 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-10-21T22:20:58.183Z,1603318858.183 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-10-21T22:21:48.582Z,1603318908.582 [CommandLine](IMPORTANT): got command quit
2020-10-21T22:21:49.589Z,1603318909.589 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:49.589Z,1603318909.589 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:49.673Z,1603318909.673 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-10-21T22:21:49.673Z,1603318909.673 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:49.673Z,1603318909.673 [CommandLine](INFO): Join timeout helper Thread ID is 2941
2020-10-21T22:21:49.674Z,1603318909.674 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-10-21T22:21:49.674Z,1603318909.674 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:49.674Z,1603318909.674 [NavChartDb](INFO): Join timeout helper Thread ID is 2942
2020-10-21T22:21:49.985Z,1603318909.985 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:49.985Z,1603318909.985 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:49.993Z,1603318909.993 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2020-10-21T22:21:49.993Z,1603318909.993 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:49.993Z,1603318909.993 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 2943
2020-10-21T22:21:49.994Z,1603318909.994 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:49.994Z,1603318909.994 [WetLabsUBAT](INFO): Powering down
2020-10-21T22:21:49.995Z,1603318909.995 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:49.995Z,1603318909.995 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-10-21T22:21:49.995Z,1603318909.995 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:49.996Z,1603318909.996 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2944
2020-10-21T22:21:50.253Z,1603318910.253 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:50.253Z,1603318910.253 [WetLabsBB2FL](INFO): Powering down
2020-10-21T22:21:50.254Z,1603318910.254 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:50.257Z,1603318910.257 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-10-21T22:21:50.257Z,1603318910.257 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:50.257Z,1603318910.257 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2945
2020-10-21T22:21:50.485Z,1603318910.485 [CTD_Seabird](INFO): Powering down
2020-10-21T22:21:50.501Z,1603318910.501 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:50.502Z,1603318910.502 [CTD_Seabird](INFO): Powering down
2020-10-21T22:21:50.513Z,1603318910.513 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:50.522Z,1603318910.522 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-10-21T22:21:50.522Z,1603318910.522 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:50.522Z,1603318910.522 [Radio_Surface](INFO): Join timeout helper Thread ID is 2946
2020-10-21T22:21:50.873Z,1603318910.873 [Radio_Surface](INFO): Powering down
2020-10-21T22:21:50.874Z,1603318910.874 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:50.874Z,1603318910.874 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:50.881Z,1603318910.881 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-10-21T22:21:50.882Z,1603318910.882 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:50.882Z,1603318910.882 [Onboard](INFO): Join timeout helper Thread ID is 2947
2020-10-21T22:21:50.961Z,1603318910.961 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-10-21T22:21:51.417Z,1603318911.417 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:51.417Z,1603318911.417 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:51.429Z,1603318911.429 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-10-21T22:21:51.430Z,1603318911.430 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:51.430Z,1603318911.430 [DataOverHttps](INFO): Join timeout helper Thread ID is 2948
2020-10-21T22:21:51.965Z,1603318911.965 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:51.965Z,1603318911.965 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:51.970Z,1603318911.970 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2020-10-21T22:21:51.970Z,1603318911.970 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:51.970Z,1603318911.970 [BackseatComponent](INFO): Join timeout helper Thread ID is 2949
2020-10-21T22:21:52.077Z,1603318912.077 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:52.077Z,1603318912.077 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.085Z,1603318912.085 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-10-21T22:21:52.086Z,1603318912.086 [logger ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.086Z,1603318912.086 [logger](INFO): Join timeout helper Thread ID is 2950
2020-10-21T22:21:52.113Z,1603318912.113 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:52.113Z,1603318912.113 [logger ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.125Z,1603318912.125 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-10-21T22:21:52.126Z,1603318912.126 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.126Z,1603318912.126 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-10-21T22:21:52.126Z,1603318912.126 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.126Z,1603318912.126 [controlThread](INFO): Join timeout helper Thread ID is 2951
2020-10-21T22:21:52.317Z,1603318912.317 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-21T22:21:52.317Z,1603318912.317 [controlThread](DEBUG): Uninitializing ControlThread
2020-10-21T22:21:52.318Z,1603318912.318 [AHRS_M2](INFO): Powering down
2020-10-21T22:21:52.390Z,1603318912.390 [NAL9602](INFO): Powering down
2020-10-21T22:21:52.391Z,1603318912.391 [DAT](INFO): Powering down
2020-10-21T22:21:52.510Z,1603318912.510 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-10-21T22:21:52.511Z,1603318912.511 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-10-21T22:21:52.511Z,1603318912.511 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-10-21T22:21:52.512Z,1603318912.512 [MissionManager](INFO): Uninitializing Mission Default
2020-10-21T22:21:52.512Z,1603318912.512 [Default] Stopped
2020-10-21T22:21:52.512Z,1603318912.512 [Default](DEBUG): Aggregate::uninitialize Default
2020-10-21T22:21:52.512Z,1603318912.512 [Default:B.GoToSurface] Stopped
2020-10-21T22:21:52.512Z,1603318912.512 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-21T22:21:52.512Z,1603318912.512 [Default:CheckIn] Stopped
2020-10-21T22:21:52.512Z,1603318912.512 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-10-21T22:21:52.512Z,1603318912.512 [Default:CheckIn:C.Wait] Stopped
2020-10-21T22:21:52.512Z,1603318912.512 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-10-21T22:21:52.515Z,1603318912.515 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-10-21T22:21:52.515Z,1603318912.515 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-10-21T22:21:52.516Z,1603318912.516 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-10-21T22:21:52.516Z,1603318912.516 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-10-21T22:21:52.516Z,1603318912.516 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-10-21T22:21:52.516Z,1603318912.516 [BuoyancyServo](INFO): Powering down
2020-10-21T22:21:52.529Z,1603318912.529 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-10-21T22:21:52.529Z,1603318912.529 [ElevatorServo](INFO): Powering down
2020-10-21T22:21:52.530Z,1603318912.530 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-10-21T22:21:52.530Z,1603318912.530 [MassServo](INFO): Powering down
2020-10-21T22:21:52.531Z,1603318912.531 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-10-21T22:21:52.531Z,1603318912.531 [RudderServo](INFO): Powering down
2020-10-21T22:21:52.532Z,1603318912.532 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-10-21T22:21:52.532Z,1603318912.532 [ThrusterServo](INFO): Powering down
2020-10-21T22:21:52.533Z,1603318912.533 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-10-21T22:21:52.533Z,1603318912.533 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-10-21T22:21:52.533Z,1603318912.533 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-10-21T22:21:52.533Z,1603318912.533 [CBIT](DEBUG): Powering off loads.
2020-10-21T22:21:52.545Z,1603318912.545 [CBIT](DEBUG): Disabling WDT.
2020-10-21T22:21:52.557Z,1603318912.557 [CBIT](DEBUG): Opening all GF detection circuits.
2020-10-21T22:21:52.558Z,1603318912.558 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.628Z,1603318912.628 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.630Z,1603318912.630 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.636Z,1603318912.636 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.679Z,1603318912.679 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.732Z,1603318912.732 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.734Z,1603318912.734 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.737Z,1603318912.737 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.745Z,1603318912.745 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-10-21T22:21:52.802Z,1603318912.802 [logger ThreadHandler](INFO): Thread cancelled.