2019-08-06T22:00:44.729Z,1565128844.729 [Supervisor](DEBUG): Initializing supervisor.
2019-08-06T22:00:44.733Z,1565128844.733 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-08-06T22:00:44.733Z,1565128844.733 [SyncHandler](INFO): Protected caller Thread ID is 806
2019-08-06T22:00:44.733Z,1565128844.733 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-08-06T22:00:44.734Z,1565128844.734 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-08-06T22:00:44.735Z,1565128844.735 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2019-08-06T22:00:44.737Z,1565128844.737 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-08-06T22:00:44.749Z,1565128844.749 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-08-06T22:00:44.750Z,1565128844.750 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-08-06T22:00:44.750Z,1565128844.750 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2019-08-06T22:00:44.751Z,1565128844.751 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-08-06T22:00:44.752Z,1565128844.752 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-08-06T22:00:44.752Z,1565128844.752 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2019-08-06T22:00:44.754Z,1565128844.754 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-08-06T22:00:44.755Z,1565128844.755 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-08-06T22:00:44.759Z,1565128844.759 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-08-06T22:00:44.959Z,1565128844.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-08-06T22:00:44.961Z,1565128844.961 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-08-06T22:00:45.044Z,1565128845.044 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-08-06T22:00:45.476Z,1565128845.476 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-08-06T22:00:45.478Z,1565128845.478 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-08-06T22:00:45.811Z,1565128845.811 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-08-06T22:00:45.812Z,1565128845.812 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-08-06T22:00:45.908Z,1565128845.908 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-08-06T22:00:45.910Z,1565128845.910 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-08-06T22:00:46.207Z,1565128846.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-08-06T22:00:46.208Z,1565128846.208 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-08-06T22:00:46.401Z,1565128846.401 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-08-06T22:00:46.402Z,1565128846.402 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-08-06T22:00:46.852Z,1565128846.852 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-08-06T22:00:46.854Z,1565128846.854 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-08-06T22:00:46.959Z,1565128846.959 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-08-06T22:00:46.961Z,1565128846.961 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-08-06T22:00:47.061Z,1565128847.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-08-06T22:00:47.062Z,1565128847.062 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-08-06T22:00:47.660Z,1565128847.660 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-08-06T22:00:47.661Z,1565128847.661 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-08-06T22:00:48.056Z,1565128848.056 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-08-06T22:00:48.057Z,1565128848.057 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-08-06T22:00:49.404Z,1565128849.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-08-06T22:00:49.406Z,1565128849.406 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-08-06T22:00:49.550Z,1565128849.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-08-06T22:00:49.552Z,1565128849.552 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-08-06T22:00:49.701Z,1565128849.701 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-08-06T22:00:49.703Z,1565128849.703 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-08-06T22:00:49.706Z,1565128849.706 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-08-06T22:00:49.797Z,1565128849.797 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-08-06T22:00:49.882Z,1565128849.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-08-06T22:00:49.985Z,1565128849.985 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-08-06T22:00:50.068Z,1565128850.068 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-08-06T22:00:50.164Z,1565128850.164 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-08-06T22:00:50.265Z,1565128850.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-08-06T22:00:50.478Z,1565128850.478 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-08-06T22:00:50.554Z,1565128850.554 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-08-06T22:00:50.722Z,1565128850.722 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-08-06T22:00:50.858Z,1565128850.858 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-08-06T22:00:50.976Z,1565128850.976 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-08-06T22:00:51.203Z,1565128851.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-08-06T22:00:51.204Z,1565128851.204 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-08-06T22:00:51.230Z,1565128851.230 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-08-06T22:00:51.317Z,1565128851.317 [VerticalControl](DEBUG): Construct VerticalControl.
2019-08-06T22:00:51.427Z,1565128851.427 [VerticalControl] Loaded
2019-08-06T22:00:51.427Z,1565128851.427 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-08-06T22:00:51.428Z,1565128851.428 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-08-06T22:00:51.495Z,1565128851.495 [HorizontalControl] Loaded
2019-08-06T22:00:51.495Z,1565128851.495 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-08-06T22:00:51.496Z,1565128851.496 [SpeedControl](DEBUG): Construct SpeedControl.
2019-08-06T22:00:51.501Z,1565128851.501 [SpeedControl] Loaded
2019-08-06T22:00:51.502Z,1565128851.502 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-08-06T22:00:51.502Z,1565128851.502 [LoopControl](DEBUG): Construct LoopControl.
2019-08-06T22:00:51.503Z,1565128851.503 [LoopControl] Loaded
2019-08-06T22:00:51.503Z,1565128851.503 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-08-06T22:00:51.504Z,1565128851.504 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-08-06T22:00:51.505Z,1565128851.505 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-08-06T22:00:51.529Z,1565128851.529 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-08-06T22:00:51.530Z,1565128851.530 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-08-06T22:00:51.652Z,1565128851.652 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-08-06T22:00:51.653Z,1565128851.653 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-08-06T22:00:51.800Z,1565128851.800 [BuoyancyServo] Loaded
2019-08-06T22:00:51.801Z,1565128851.801 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-08-06T22:00:51.812Z,1565128851.812 [ElevatorServo] Loaded
2019-08-06T22:00:51.812Z,1565128851.812 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-08-06T22:00:51.823Z,1565128851.823 [MassServo] Loaded
2019-08-06T22:00:51.823Z,1565128851.823 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-08-06T22:00:51.834Z,1565128851.834 [RudderServo] Loaded
2019-08-06T22:00:51.834Z,1565128851.834 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-08-06T22:00:51.845Z,1565128851.845 [ThrusterServo] Loaded
2019-08-06T22:00:51.845Z,1565128851.845 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-08-06T22:00:51.846Z,1565128851.846 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-08-06T22:00:51.846Z,1565128851.846 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-08-06T22:00:51.969Z,1565128851.969 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-08-06T22:00:51.969Z,1565128851.969 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-08-06T22:00:51.989Z,1565128851.989 [NavChart] Loaded
2019-08-06T22:00:51.990Z,1565128851.990 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-08-06T22:00:51.994Z,1565128851.994 [UniversalFixResidualReporter] Loaded
2019-08-06T22:00:51.994Z,1565128851.994 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-08-06T22:00:51.994Z,1565128851.994 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-08-06T22:00:51.995Z,1565128851.995 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-08-06T22:00:52.106Z,1565128852.106 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-08-06T22:00:52.107Z,1565128852.107 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-08-06T22:00:52.725Z,1565128852.725 [DataOverHttps] Loaded
2019-08-06T22:00:52.725Z,1565128852.725 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-08-06T22:00:52.726Z,1565128852.726 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2019-08-06T22:00:52.726Z,1565128852.726 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 891
2019-08-06T22:00:52.740Z,1565128852.740 [Depth_Keller] Loaded
2019-08-06T22:00:52.740Z,1565128852.740 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-08-06T22:00:52.835Z,1565128852.835 [NAL9602] Loaded
2019-08-06T22:00:52.836Z,1565128852.836 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-08-06T22:00:52.852Z,1565128852.852 [Onboard] Loaded
2019-08-06T22:00:52.852Z,1565128852.852 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-08-06T22:00:52.855Z,1565128852.855 [Radio_Surface] Loaded
2019-08-06T22:00:52.855Z,1565128852.855 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-08-06T22:00:52.856Z,1565128852.856 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2019-08-06T22:00:52.857Z,1565128852.857 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 892
2019-08-06T22:00:54.777Z,1565128854.777 [BPC1] Loaded
2019-08-06T22:00:54.777Z,1565128854.777 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-08-06T22:00:54.777Z,1565128854.777 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-08-06T22:00:54.778Z,1565128854.778 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-08-06T22:00:54.833Z,1565128854.833 [DepthRateCalculator] Loaded
2019-08-06T22:00:54.833Z,1565128854.833 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-08-06T22:00:54.838Z,1565128854.838 [PitchRateCalculator] Loaded
2019-08-06T22:00:54.839Z,1565128854.839 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-08-06T22:00:54.850Z,1565128854.850 [SpeedCalculator] Loaded
2019-08-06T22:00:54.850Z,1565128854.850 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-08-06T22:00:54.871Z,1565128854.871 [TempGradientCalculator] Loaded
2019-08-06T22:00:54.872Z,1565128854.872 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-08-06T22:00:54.877Z,1565128854.877 [YawRateCalculator] Loaded
2019-08-06T22:00:54.877Z,1565128854.877 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-08-06T22:00:54.906Z,1565128854.906 [ElevatorOffsetCalculator] Loaded
2019-08-06T22:00:54.907Z,1565128854.907 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-08-06T22:00:54.907Z,1565128854.907 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-08-06T22:00:54.908Z,1565128854.908 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-08-06T22:00:55.154Z,1565128855.154 [CANONSampler] Loaded
2019-08-06T22:00:55.154Z,1565128855.154 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2019-08-06T22:00:55.168Z,1565128855.168 [PAR_Licor] Loaded
2019-08-06T22:00:55.169Z,1565128855.169 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-08-06T22:00:55.170Z,1565128855.170 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-08-06T22:00:55.170Z,1565128855.170 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-08-06T22:00:55.218Z,1565128855.218 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-08-06T22:00:55.219Z,1565128855.219 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-08-06T22:00:55.552Z,1565128855.552 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-08-06T22:00:55.552Z,1565128855.552 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-08-06T22:00:55.708Z,1565128855.708 [SBIT](DEBUG): Construct Startup Built In Test.
2019-08-06T22:00:55.719Z,1565128855.719 [SBIT] Loaded
2019-08-06T22:00:55.719Z,1565128855.719 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-08-06T22:00:55.720Z,1565128855.720 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-08-06T22:00:55.732Z,1565128855.732 [IBIT] Loaded
2019-08-06T22:00:55.732Z,1565128855.732 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-08-06T22:00:55.735Z,1565128855.735 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-08-06T22:00:55.871Z,1565128855.871 [CBIT] Loaded
2019-08-06T22:00:55.872Z,1565128855.872 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-08-06T22:00:55.872Z,1565128855.872 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-08-06T22:00:55.876Z,1565128855.876 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-08-06T22:00:55.876Z,1565128855.876 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-08-06T22:00:55.883Z,1565128855.883 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-08-06T22:00:55.884Z,1565128855.884 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A7F4E0
2019-08-06T22:00:55.884Z,1565128855.884 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 894
2019-08-06T22:00:55.889Z,1565128855.889 [Supervisor](INFO): Main Thread ID is 802
2019-08-06T22:00:55.889Z,1565128855.889 [Supervisor](DEBUG): Running supervisor.
2019-08-06T22:00:55.890Z,1565128855.890 [CommandLine ThreadHandler](INFO): Handler Thread ID is 895
2019-08-06T22:00:55.892Z,1565128855.892 [controlThread ThreadHandler](INFO): Handler Thread ID is 896
2019-08-06T22:00:55.893Z,1565128855.893 [controlThread](DEBUG): Initializing ControlThread
2019-08-06T22:00:55.893Z,1565128855.893 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-08-06T22:00:55.895Z,1565128855.895 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-08-06T22:00:55.896Z,1565128855.896 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-08-06T22:00:55.896Z,1565128855.896 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-08-06T22:00:55.898Z,1565128855.898 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-08-06T22:00:55.898Z,1565128855.898 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-08-06T22:00:55.904Z,1565128855.904 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-08-06T22:00:55.904Z,1565128855.904 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-08-06T22:00:55.904Z,1565128855.904 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-08-06T22:00:55.905Z,1565128855.905 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-08-06T22:00:55.905Z,1565128855.905 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-08-06T22:00:55.905Z,1565128855.905 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-08-06T22:00:55.907Z,1565128855.907 [SBIT](INFO): Initialize SBIT Component.
2019-08-06T22:00:55.908Z,1565128855.908 [SBIT](IMPORTANT): git: 2019-07-26-1-g6ad825a
2019-08-06T22:00:55.908Z,1565128855.908 [SBIT](INFO): git hash: 6ad825a153e96bf2505e39e5df4d606652139ef6
2019-08-06T22:00:55.908Z,1565128855.908 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-08-06T22:00:55.909Z,1565128855.909 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-08-06T22:00:55.910Z,1565128855.910 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2019-08-06T22:00:55.911Z,1565128855.911 [IBIT](INFO): Initialize IBIT Component.
2019-08-06T22:00:55.912Z,1565128855.912 [CBIT](DEBUG): Initialize CBIT Component.
2019-08-06T22:00:55.913Z,1565128855.913 [logger ThreadHandler](INFO): Handler Thread ID is 897
2019-08-06T22:00:55.923Z,1565128855.923 [CBIT](DEBUG): Initialized mux pins.
2019-08-06T22:00:55.923Z,1565128855.923 [CBIT](DEBUG): Initializing the watchdog timer.
2019-08-06T22:00:55.931Z,1565128855.931 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 898
2019-08-06T22:00:55.932Z,1565128855.932 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-08-06T22:00:55.943Z,1565128855.943 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 899
2019-08-06T22:00:55.947Z,1565128855.947 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-08-06T22:00:55.947Z,1565128855.947 [CBIT](DEBUG): Initializing heartbeat.
2019-08-06T22:00:55.955Z,1565128855.955 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 900
2019-08-06T22:00:55.964Z,1565128855.964 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-08-06T22:00:55.964Z,1565128855.964 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-08-06T22:00:55.965Z,1565128855.965 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-08-06T22:00:55.965Z,1565128855.965 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-08-06T22:00:55.965Z,1565128855.965 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-08-06T22:00:55.965Z,1565128855.965 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-08-06T22:00:55.965Z,1565128855.965 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-08-06T22:00:55.965Z,1565128855.965 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-08-06T22:00:55.966Z,1565128855.966 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-08-06T22:00:55.966Z,1565128855.966 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-08-06T22:00:55.966Z,1565128855.966 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-08-06T22:00:55.966Z,1565128855.966 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-08-06T22:00:55.966Z,1565128855.966 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-08-06T22:00:55.967Z,1565128855.967 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-08-06T22:00:55.967Z,1565128855.967 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-08-06T22:00:55.967Z,1565128855.967 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-08-06T22:00:56.019Z,1565128856.019 [CBIT](DEBUG): Deactivating GF circuits.
2019-08-06T22:00:56.019Z,1565128856.019 [CBIT](DEBUG): Deactivating emergency mode.
2019-08-06T22:00:56.055Z,1565128856.055 [CBIT](DEBUG): Backplane powered.
2019-08-06T22:00:56.056Z,1565128856.056 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-08-06T22:00:56.079Z,1565128856.079 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-06T22:00:56.098Z,1565128856.098 [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>


2019-08-06T22:00:56.120Z,1565128856.120 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-08-06T22:00:56.192Z,1565128856.192 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-08-06T22:00:56.193Z,1565128856.193 [Default:A.Wait](DEBUG): Construct Wait.
2019-08-06T22:00:56.195Z,1565128856.195 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-08-06T22:00:56.222Z,1565128856.222 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-08-06T22:00:56.243Z,1565128856.243 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-08-06T22:00:56.265Z,1565128856.265 [Default:E.Execute](DEBUG): Construct Execute.
2019-08-06T22:00:56.268Z,1565128856.268 [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>


2019-08-06T22:00:56.286Z,1565128856.286 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,NAL9602,Onboard,BPC1,CANONSampler,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,Reporter,LogSplitter,
2019-08-06T22:00:56.293Z,1565128856.293 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-08-06T22:00:56.343Z,1565128856.343 [CANONSampler](INFO): Powering down
2019-08-06T22:00:56.347Z,1565128856.347 [Radio_Surface](INFO): Powering up
2019-08-06T22:00:56.485Z,1565128856.485 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-08-06T22:00:56.809Z,1565128856.809 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:00:56.815Z,1565128856.815 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-08-06T22:00:56.816Z,1565128856.816 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:00:56.823Z,1565128856.823 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-08-06T22:00:56.824Z,1565128856.824 [MassServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:00:56.831Z,1565128856.831 [MassServo](DEBUG): Initializing MassServo.
2019-08-06T22:00:56.832Z,1565128856.832 [RudderServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:00:56.839Z,1565128856.839 [RudderServo](DEBUG): Initializing RudderServo.
2019-08-06T22:00:56.840Z,1565128856.840 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-08-06T22:00:56.847Z,1565128856.847 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-08-06T22:01:23.124Z,1565128883.124 [NAL9602](INFO): Powering up NAL9602
2019-08-06T22:01:32.460Z,1565128892.460 [SBIT](IMPORTANT): Beginning Startup BIT
2019-08-06T22:01:32.468Z,1565128892.468 [CBIT](IMPORTANT): Beginning ground fault scan
2019-08-06T22:01:34.032Z,1565128894.032 [NAL9602](INFO): NAL9602 initialized
2019-08-06T22:01:34.967Z,1565128894.967 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:01:43.492Z,1565128903.492 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.005480
CHAN A1 (24V): -0.198599
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001651
CHAN B0 (3.3V): -0.000187
CHAN B1 (3.15aV): -0.000220
CHAN B2 (3.15bV): -0.000246
CHAN B3 (GND): 0.000038
OPEN: -0.000345
Full Scale Calc: 4.765 mA, -1.589 mA
2019-08-06T22:02:25.714Z,1565128945.714 [SBIT](IMPORTANT): SBIT PASSED
2019-08-06T22:02:25.744Z,1565128945.744 [CommandLine](IMPORTANT): got command configSet list
2019-08-06T22:02:25.744Z,1565128945.744 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-06T22:02:25.745Z,1565128945.745 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;

2019-08-06T22:02:25.745Z,1565128945.745 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-08-06T22:02:25.745Z,1565128945.745 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=0 count;

2019-08-06T22:02:25.745Z,1565128945.745 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=6 hour;

2019-08-06T22:02:25.745Z,1565128945.745 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): CBIT.abortDepth=296 meter;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): CBIT.stopDepth=288 meter;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-08-06T22:02:25.746Z,1565128945.746 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): Express linearApproximation DAT.range 5.000000 meter;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2019-08-06T22:02:25.747Z,1565128945.747 [CommandLine](IMPORTANT): VerticalControl.massDefault=-4 millimeter;

2019-08-06T22:02:25.748Z,1565128945.748 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-31 millimeter;

2019-08-06T22:02:25.748Z,1565128945.748 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=30 millimeter;

2019-08-06T22:02:25.748Z,1565128945.748 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;

2019-08-06T22:02:26.120Z,1565128946.120 [MissionManager](IMPORTANT): Started mission Startup
2019-08-06T22:02:26.120Z,1565128946.120 [Startup] Running Loop=1
2019-08-06T22:02:26.121Z,1565128946.121 [Startup](DEBUG): Aggregate::initialize Startup
2019-08-06T22:02:26.121Z,1565128946.121 [Startup:A.GoToSurface] Running Loop=1
2019-08-06T22:02:26.121Z,1565128946.121 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T22:02:26.121Z,1565128946.121 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T22:02:26.122Z,1565128946.122 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T22:02:26.122Z,1565128946.122 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T22:02:26.123Z,1565128946.123 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T22:02:26.123Z,1565128946.123 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T22:02:26.124Z,1565128946.124 [Startup:StartupSatComms] Running Loop=1
2019-08-06T22:02:26.125Z,1565128946.125 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-08-06T22:02:26.125Z,1565128946.125 [Startup:StartupSatComms:A] Running Loop=1
2019-08-06T22:02:26.532Z,1565128946.532 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-08-06T22:02:56.034Z,1565128976.034 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:02:56.034Z,1565128976.034 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-06T22:02:56.034Z,1565128976.034 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:02:56.073Z,1565128976.073 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:02:56.425Z,1565128976.425 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:02:56.425Z,1565128976.425 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-06T22:03:26.332Z,1565129006.332 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-06T22:02:26.1Z
2019-08-06T22:03:26.333Z,1565129006.333 [Startup:StartupSatComms:A] Stopped
2019-08-06T22:03:26.333Z,1565129006.333 [Startup:StartupSatComms:B] Running Loop=1
2019-08-06T22:03:26.729Z,1565129006.729 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-06T22:04:26.516Z,1565129066.516 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-06T22:03:26.3Z
2019-08-06T22:04:26.516Z,1565129066.516 [Startup:StartupSatComms:B] Stopped
2019-08-06T22:04:26.516Z,1565129066.516 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-08-06T22:04:26.516Z,1565129066.516 [Startup:StartupSatComms] Stopped
2019-08-06T22:04:26.516Z,1565129066.516 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-08-06T22:04:26.517Z,1565129066.517 [Startup](INFO): Completed Startup
2019-08-06T22:04:26.517Z,1565129066.517 [MissionManager](INFO): Startup is completed.
2019-08-06T22:04:26.517Z,1565129066.517 [MissionManager](INFO): Uninitializing Mission Startup
2019-08-06T22:04:26.517Z,1565129066.517 [Startup] Stopped
2019-08-06T22:04:26.518Z,1565129066.518 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-08-06T22:04:26.518Z,1565129066.518 [Startup:A.GoToSurface] Stopped
2019-08-06T22:04:26.518Z,1565129066.518 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-06T22:04:26.927Z,1565129066.927 [MissionManager](IMPORTANT): Started mission Default
2019-08-06T22:04:26.927Z,1565129066.927 [Default] Running Loop=1
2019-08-06T22:04:26.928Z,1565129066.928 [Default](DEBUG): Aggregate::initialize Default
2019-08-06T22:04:26.928Z,1565129066.928 [Default:B.GoToSurface] Running Loop=1
2019-08-06T22:04:26.928Z,1565129066.928 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T22:04:26.928Z,1565129066.928 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T22:04:26.928Z,1565129066.928 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T22:04:26.929Z,1565129066.929 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T22:04:26.929Z,1565129066.929 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T22:04:26.929Z,1565129066.929 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T22:04:26.929Z,1565129066.929 [Default:A.Wait] Running Loop=1
2019-08-06T22:04:26.930Z,1565129066.930 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:04:28.820Z,1565129068.820 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004793
2019-08-06T22:04:40.261Z,1565129080.261 [Default:A.Wait](INFO): Done Waiting.
2019-08-06T22:04:40.261Z,1565129080.261 [Default:A.Wait] Stopped
2019-08-06T22:04:40.261Z,1565129080.261 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:04:40.668Z,1565129080.668 [Default:CheckIn] Running Loop=1
2019-08-06T22:04:40.668Z,1565129080.668 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T22:04:40.668Z,1565129080.668 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T22:04:41.065Z,1565129081.065 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-08-06T22:04:57.213Z,1565129097.213 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:04:57.213Z,1565129097.213 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-08-06T22:04:57.213Z,1565129097.213 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:04:57.224Z,1565129097.224 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:04:57.689Z,1565129097.689 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:04:57.689Z,1565129097.689 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-08-06T22:06:37.412Z,1565129197.412 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-06T22:06:38.235Z,1565129198.235 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:06:38.630Z,1565129198.630 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220534.00,A,3648.16506,N,12147.28641,W,0.214,0.00,060819,,,A*7A
2019-08-06T22:06:38.633Z,1565129198.633 [NAL9602](INFO): GPS fix at 20190806T220534: (36.802751, -121.788107)
2019-08-06T22:06:38.656Z,1565129198.656 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T22:06:38.656Z,1565129198.656 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T22:06:39.065Z,1565129199.065 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-08-06T22:06:46.660Z,1565129206.660 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T202556/Courier0067.lzma
2019-08-06T22:06:47.465Z,1565129207.465 [DataOverHttps](INFO): Moved sent file to Logs/20190806T202556/Courier0067.lzma.bak
2019-08-06T22:06:47.465Z,1565129207.465 [DataOverHttps](INFO): SBD MOMSN=11529620
2019-08-06T22:06:58.106Z,1565129218.106 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:06:58.106Z,1565129218.106 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-06T22:06:58.106Z,1565129218.106 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:06:58.145Z,1565129218.145 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:06:58.495Z,1565129218.495 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:06:58.495Z,1565129218.495 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-06T22:06:59.767Z,1565129219.767 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190806T220044/Courier0004.lzma
2019-08-06T22:07:00.572Z,1565129220.572 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Courier0004.lzma.bak
2019-08-06T22:07:00.572Z,1565129220.572 [DataOverHttps](INFO): SBD MOMSN=11529622
2019-08-06T22:07:10.574Z,1565129230.574 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-08-06T22:07:10.577Z,1565129230.577 [BPC1](INFO): Received data from all battery sticks.
2019-08-06T22:07:10.947Z,1565129230.947 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T22:07:12.332Z,1565129232.332 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20190806T202556/Express0068.lzma
2019-08-06T22:07:13.136Z,1565129233.136 [DataOverHttps](INFO): Moved sent file to Logs/20190806T202556/Express0068.lzma.bak
2019-08-06T22:07:13.137Z,1565129233.137 [DataOverHttps](INFO): SBD MOMSN=11529626
2019-08-06T22:07:24.932Z,1565129244.932 [DataOverHttps](INFO): Sending 1129 bytes from file Logs/20190806T220044/Express0001.lzma
2019-08-06T22:07:25.736Z,1565129245.736 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Express0001.lzma.bak
2019-08-06T22:07:25.737Z,1565129245.737 [DataOverHttps](INFO): SBD MOMSN=11529632
2019-08-06T22:07:38.275Z,1565129258.275 [DataOverHttps](INFO): Sending 367 bytes from file Logs/20190806T220044/Express0005.lzma
2019-08-06T22:07:39.080Z,1565129259.080 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Express0005.lzma.bak
2019-08-06T22:07:39.081Z,1565129259.081 [DataOverHttps](INFO): SBD MOMSN=11529671
2019-08-06T22:07:40.882Z,1565129260.882 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T22:07:40.882Z,1565129260.882 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T22:07:40.882Z,1565129260.882 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:08:59.242Z,1565129339.242 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:08:59.242Z,1565129339.242 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-08-06T22:08:59.242Z,1565129339.242 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:08:59.253Z,1565129339.253 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:08:59.660Z,1565129339.660 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:08:59.660Z,1565129339.660 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-08-06T22:11:00.438Z,1565129460.438 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:11:00.438Z,1565129460.438 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-08-06T22:11:00.438Z,1565129460.438 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:11:00.449Z,1565129460.449 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:11:00.860Z,1565129460.860 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:11:00.860Z,1565129460.860 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-08-06T22:12:41.445Z,1565129561.445 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-06T22:12:41.445Z,1565129561.445 [Default:CheckIn:C.Wait] Stopped
2019-08-06T22:12:41.445Z,1565129561.445 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:12:41.446Z,1565129561.446 [Default:CheckIn:D] Running Loop=1
2019-08-06T22:12:41.849Z,1565129561.849 [Default:CheckIn:D] Stopped
2019-08-06T22:12:41.849Z,1565129561.849 [Default:CheckIn:E] Running Loop=1
2019-08-06T22:12:42.245Z,1565129562.245 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.248690 min 
2019-08-06T22:12:42.245Z,1565129562.245 [Default:CheckIn:E] Stopped
2019-08-06T22:12:42.245Z,1565129562.245 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-06T22:12:42.245Z,1565129562.245 [Default:CheckIn] Stopped
2019-08-06T22:12:42.245Z,1565129562.245 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T22:12:42.246Z,1565129562.246 [Default:CheckIn](INFO): Running loop #2
2019-08-06T22:12:42.246Z,1565129562.246 [Default:CheckIn] Running Loop=2
2019-08-06T22:12:42.246Z,1565129562.246 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T22:12:42.246Z,1565129562.246 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T22:12:43.858Z,1565129563.858 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:12:44.249Z,1565129564.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221140.00,A,3648.16295,N,12147.28555,W,0.292,292.86,060819,,,A*7E
2019-08-06T22:12:44.251Z,1565129564.251 [NAL9602](INFO): GPS fix at 20190806T221140: (36.802716, -121.788093)
2019-08-06T22:12:44.297Z,1565129564.297 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T22:12:44.298Z,1565129564.298 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T22:12:50.179Z,1565129570.179 [DataOverHttps](INFO): Sending 221 bytes from file Logs/20190806T220044/Courier0007.lzma
2019-08-06T22:12:50.888Z,1565129570.888 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Courier0007.lzma.bak
2019-08-06T22:12:50.888Z,1565129570.888 [DataOverHttps](INFO): SBD MOMSN=11529713
2019-08-06T22:13:01.268Z,1565129581.268 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:13:01.268Z,1565129581.268 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-06T22:13:01.268Z,1565129581.268 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:13:01.279Z,1565129581.279 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:13:01.695Z,1565129581.695 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:13:01.695Z,1565129581.695 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-06T22:13:02.402Z,1565129582.402 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20190806T220044/Express0008.lzma
2019-08-06T22:13:03.208Z,1565129583.208 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Express0008.lzma.bak
2019-08-06T22:13:03.208Z,1565129583.208 [DataOverHttps](INFO): SBD MOMSN=11529716
2019-08-06T22:13:04.908Z,1565129584.908 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T22:13:04.908Z,1565129584.908 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T22:13:04.908Z,1565129584.908 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:13:14.952Z,1565129594.952 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-06T22:13:15.031Z,1565129595.031 [NAL9602](FAULT): received: 
+CSQ:0

OK
2019-08-06T22:13:15.031Z,1565129595.031 [NAL9602] Data Fault, FailCount= 1
2019-08-06T22:13:15.031Z,1565129595.031 [NAL9602](ERROR): Data Fault
2019-08-06T22:13:15.153Z,1565129595.153 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-06T22:13:15.364Z,1565129595.364 [NAL9602](INFO): Powering down
2019-08-06T22:13:16.198Z,1565129596.198 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-06T22:13:16.198Z,1565129596.198 [NAL9602] No Fault, FailCount= 1
2019-08-06T22:13:45.660Z,1565129625.660 [NAL9602](INFO): Powering up NAL9602
2019-08-06T22:13:56.564Z,1565129636.564 [NAL9602](INFO): NAL9602 initialized
2019-08-06T22:14:27.668Z,1565129667.668 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T22:15:02.443Z,1565129702.443 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:15:02.443Z,1565129702.443 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-08-06T22:15:02.443Z,1565129702.443 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:15:02.454Z,1565129702.454 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:15:02.861Z,1565129702.861 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:15:02.861Z,1565129702.861 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-08-06T22:17:03.639Z,1565129823.639 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:17:03.639Z,1565129823.639 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-08-06T22:17:03.639Z,1565129823.639 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:17:03.650Z,1565129823.650 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:17:04.047Z,1565129824.047 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:17:04.047Z,1565129824.047 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-08-06T22:18:05.457Z,1565129885.457 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-06T22:18:05.457Z,1565129885.457 [Default:CheckIn:C.Wait] Stopped
2019-08-06T22:18:05.457Z,1565129885.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:18:05.457Z,1565129885.457 [Default:CheckIn:D] Running Loop=1
2019-08-06T22:18:05.865Z,1565129885.865 [Default:CheckIn:D] Stopped
2019-08-06T22:18:05.865Z,1565129885.865 [Default:CheckIn:E] Running Loop=1
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 13.648957 min 
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn:E] Stopped
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn] Stopped
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn](INFO): Running loop #3
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn] Running Loop=3
2019-08-06T22:18:06.270Z,1565129886.270 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T22:18:06.271Z,1565129886.271 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T22:18:07.863Z,1565129887.863 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:10.680Z,1565129890.680 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-06T22:18:11.499Z,1565129891.499 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:13.923Z,1565129893.923 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:17.155Z,1565129897.155 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:19.983Z,1565129899.983 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:22.811Z,1565129902.811 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:26.043Z,1565129906.043 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:28.875Z,1565129908.875 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:32.103Z,1565129912.103 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:34.931Z,1565129914.931 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:38.163Z,1565129918.163 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:40.991Z,1565129920.991 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:43.819Z,1565129923.819 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:47.087Z,1565129927.087 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:49.967Z,1565129929.967 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:53.159Z,1565129933.159 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:55.995Z,1565129935.995 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:18:59.219Z,1565129939.219 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:02.051Z,1565129942.051 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:04.483Z,1565129944.483 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:19:04.483Z,1565129944.483 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-08-06T22:19:04.483Z,1565129944.483 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:19:04.494Z,1565129944.494 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:19:04.875Z,1565129944.875 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:04.908Z,1565129944.908 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:19:04.908Z,1565129944.908 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-08-06T22:19:08.111Z,1565129948.111 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:10.935Z,1565129950.935 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:14.171Z,1565129954.171 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:16.995Z,1565129956.995 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:20.239Z,1565129960.239 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:23.055Z,1565129963.055 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:23.629Z,1565129963.629 [CommandLine](IMPORTANT): got command show variable canonsampler
2019-08-06T22:19:23.694Z,1565129963.694 [CommandLine](IMPORTANT): CANONSampler.loadControl (none)
2019-08-06T22:19:23.694Z,1565129963.694 [CommandLine](IMPORTANT): CANONSampler.uart (none)
2019-08-06T22:19:23.695Z,1565129963.695 [CommandLine](IMPORTANT): CANONSampler.baud (bit_per_second)
2019-08-06T22:19:23.713Z,1565129963.713 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup (bool)
2019-08-06T22:19:23.714Z,1565129963.714 [CommandLine](IMPORTANT): CANONSampler.simulateHardware (bool)
2019-08-06T22:19:23.714Z,1565129963.714 [CommandLine](IMPORTANT): CANONSampler.rotateOnly (bool)
2019-08-06T22:19:23.714Z,1565129963.714 [CommandLine](IMPORTANT): CANONSampler.sampleTimeout (minute)
2019-08-06T22:19:23.774Z,1565129963.774 [CommandLine](IMPORTANT): CANONSampler.sampling (bool)
2019-08-06T22:19:23.774Z,1565129963.774 [CommandLine](IMPORTANT): CANONSampler.sample_number (count)
2019-08-06T22:19:23.777Z,1565129963.777 [CommandLine](IMPORTANT): CANONSampler.component_voltage (volt)
2019-08-06T22:19:23.778Z,1565129963.778 [CommandLine](IMPORTANT): CANONSampler.component_avgVoltage (volt)
2019-08-06T22:19:23.778Z,1565129963.778 [CommandLine](IMPORTANT): CANONSampler.component_current (milliampere)
2019-08-06T22:19:23.779Z,1565129963.779 [CommandLine](IMPORTANT): CANONSampler.component_avgCurrent (milliampere)
2019-08-06T22:19:25.891Z,1565129965.891 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:29.115Z,1565129969.115 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:19:29.509Z,1565129969.509 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221824.00,A,3648.17246,N,12147.30638,W,1.186,316.25,060819,,,A*78
2019-08-06T22:19:29.512Z,1565129969.512 [NAL9602](INFO): GPS fix at 20190806T221824: (36.802874, -121.788440)
2019-08-06T22:19:29.567Z,1565129969.567 [CommandLine](IMPORTANT): got command get CANONSampler.loadControl
2019-08-06T22:19:29.567Z,1565129969.567 [CommandLine](IMPORTANT): CANONSampler.loadControl /dev/loadB1
2019-08-06T22:19:29.576Z,1565129969.576 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T22:19:29.576Z,1565129969.576 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T22:19:35.322Z,1565129975.322 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20190806T220044/Courier0010.lzma
2019-08-06T22:19:36.128Z,1565129976.128 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Courier0010.lzma.bak
2019-08-06T22:19:36.128Z,1565129976.128 [DataOverHttps](INFO): SBD MOMSN=11529722
2019-08-06T22:19:37.432Z,1565129977.432 [CommandLine](IMPORTANT): got command get CANONSampler.uart
2019-08-06T22:19:37.432Z,1565129977.432 [CommandLine](IMPORTANT): CANONSampler.uart /dev/ttyB1
2019-08-06T22:19:43.543Z,1565129983.543 [CommandLine](IMPORTANT): got command get CANONSampler.loadAtStartup
2019-08-06T22:19:43.544Z,1565129983.544 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup 1 bool
2019-08-06T22:19:49.203Z,1565129989.203 [DataOverHttps](INFO): Sending 576 bytes from file Logs/20190806T220044/Express0011.lzma
2019-08-06T22:19:49.888Z,1565129989.888 [CommandLine](IMPORTANT): got command get CANONSampler.simulateHardware
2019-08-06T22:19:49.888Z,1565129989.888 [CommandLine](IMPORTANT): CANONSampler.simulateHardware 0 bool
2019-08-06T22:19:50.008Z,1565129990.008 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Express0011.lzma.bak
2019-08-06T22:19:50.008Z,1565129990.008 [DataOverHttps](INFO): SBD MOMSN=11529725
2019-08-06T22:19:51.772Z,1565129991.772 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T22:19:51.773Z,1565129991.773 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T22:19:51.773Z,1565129991.773 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:20:01.835Z,1565130001.835 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T22:20:52.573Z,1565130052.573 [CommandLine](IMPORTANT): got command get latitude
2019-08-06T22:20:52.574Z,1565130052.574 [CommandLine](IMPORTANT): latitude 36.802874 arcdeg
2019-08-06T22:21:03.348Z,1565130063.348 [DataOverHttps](IMPORTANT): SBD MTMSN=20190806T221958
2019-08-06T22:21:05.322Z,1565130065.322 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:21:05.322Z,1565130065.322 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-06T22:21:05.322Z,1565130065.322 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:21:05.332Z,1565130065.332 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:21:05.723Z,1565130065.723 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:21:05.723Z,1565130065.723 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-06T22:21:08.175Z,1565130068.175 [DataOverHttps](INFO): Received command:load Maintenance/sample.xml;set sample.MissionTimeout 60 minute;set sample.NumberOfSamples 3 count;set sample.WaitBeforeSample 1 minute;run 
2019-08-06T22:21:08.189Z,1565130068.189 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2019-08-06T22:21:08.190Z,1565130068.190 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2019-08-06T22:21:08.301Z,1565130068.301 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2019-08-06T22:21:08.304Z,1565130068.304 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2019-08-06T22:21:08.306Z,1565130068.306 [MissionManager](INFO): DefineArg sample.CartridgeType = -1.000000 count
2019-08-06T22:21:08.341Z,1565130068.341 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2019-08-06T22:21:08.344Z,1565130068.344 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2019-08-06T22:21:08.346Z,1565130068.346 [sample:A.AbortSample](DEBUG): Construct.
2019-08-06T22:21:08.368Z,1565130068.368 [sample:B.Pitch](DEBUG): Construct.
2019-08-06T22:21:08.409Z,1565130068.409 [sample:C.SetSpeed](DEBUG): Construct.
2019-08-06T22:21:08.412Z,1565130068.412 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2019-08-06T22:21:08.630Z,1565130068.630 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2019-08-06T22:21:08.649Z,1565130068.649 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s
2019-08-06T22:21:08.652Z,1565130068.652 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2019-08-06T22:21:08.671Z,1565130068.671 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2019-08-06T22:21:08.674Z,1565130068.674 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 1.000000 bool
2019-08-06T22:21:08.677Z,1565130068.677 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 0.000000 bool
2019-08-06T22:21:08.700Z,1565130068.700 [MissionManager](INFO): DefineArg sample:SampleAtDepth.ESPCartridgeType = nan count
2019-08-06T22:21:08.703Z,1565130068.703 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2019-08-06T22:21:08.706Z,1565130068.706 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2019-08-06T22:21:08.726Z,1565130068.726 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 199.999995 cc
2019-08-06T22:21:08.729Z,1565130068.729 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Construct.
2019-08-06T22:21:08.779Z,1565130068.779 [sample:SampleAtDepth:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T22:21:08.782Z,1565130068.782 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Construct.
2019-08-06T22:21:08.813Z,1565130068.813 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2019-08-06T22:21:08.830Z,1565130068.830 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T22:21:08.833Z,1565130068.833 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2019-08-06T22:21:08.833Z,1565130068.833 [MissionManager](ERROR): Slate does not contain celsius
2019-08-06T22:21:08.833Z,1565130068.833 [MissionManager](ERROR): Slate does not contain WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-08-06T22:21:08.834Z,1565130068.834 [MissionManager](ERROR): Slate does not contain microgram_per_liter
2019-08-06T22:21:08.856Z,1565130068.856 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T22:21:08.860Z,1565130068.860 [MissionManager](CRITICAL): Slate does not contain ESPComponent.cartridge
2019-08-06T22:21:08.860Z,1565130068.860 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](CRITICAL): Error!!!! no component for child behavior.
2019-08-06T22:21:08.875Z,1565130068.875 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2019-08-06T22:21:08.875Z,1565130068.875 [MissionManager](ERROR): Slate does not contain celsius
2019-08-06T22:21:08.876Z,1565130068.876 [MissionManager](ERROR): Slate does not contain WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-08-06T22:21:08.876Z,1565130068.876 [MissionManager](ERROR): Slate does not contain microgram_per_liter
2019-08-06T22:21:08.942Z,1565130068.942 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="CartridgeType"><Description>
        Specifies ESP cartridge type code.
    </Description><Units:count/><Value>-1</Value></DefineArg>
    
    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

     <Trigger:AbortSample>
     	  <Parallel/>
     </Trigger:AbortSample>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    <Insert Filename="Insert/SampleAtDepth.xml"/>

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:ESPCartridgeType"/><Arg Name="CartridgeType"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2019-08-06T22:21:08.942Z,1565130068.942 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2019-08-06T22:21:13.003Z,1565130073.003 [CommandLine](FAULT): Scheduling is paused
2019-08-06T22:21:13.003Z,1565130073.003 [CBIT](INFO): Critical error at 20190806T222108
2019-08-06T22:21:13.003Z,1565130073.003 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-08-06T22:21:13.035Z,1565130073.035 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 60.000000 minute
2019-08-06T22:21:13.036Z,1565130073.036 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 3.000000 count
2019-08-06T22:21:13.037Z,1565130073.037 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 1.000000 minute
2019-08-06T22:21:13.037Z,1565130073.037 [CommandLine](IMPORTANT): got command run 
2019-08-06T22:21:13.090Z,1565130073.090 [CommandLine](IMPORTANT): Running 
2019-08-06T22:21:13.109Z,1565130073.109 [Default] Stopped
2019-08-06T22:21:13.109Z,1565130073.109 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-06T22:21:13.109Z,1565130073.109 [Default:B.GoToSurface] Stopped
2019-08-06T22:21:13.109Z,1565130073.109 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-06T22:21:13.110Z,1565130073.110 [Default:CheckIn] Stopped
2019-08-06T22:21:13.110Z,1565130073.110 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T22:21:13.110Z,1565130073.110 [Default:CheckIn:C.Wait] Stopped
2019-08-06T22:21:13.110Z,1565130073.110 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:21:13.110Z,1565130073.110 [MissionManager](IMPORTANT): Started mission sample
2019-08-06T22:21:13.110Z,1565130073.110 [sample] Running Loop=1
2019-08-06T22:21:13.110Z,1565130073.110 [sample](DEBUG): Aggregate::initialize sample
2019-08-06T22:21:13.110Z,1565130073.110 [sample:A.AbortSample] Running Loop=1
2019-08-06T22:21:13.110Z,1565130073.110 [sample:A.AbortSample](INFO): Initializing AbortSample.
2019-08-06T22:21:13.111Z,1565130073.111 [sample:B.Pitch] Running Loop=1
2019-08-06T22:21:13.111Z,1565130073.111 [sample:B.Pitch](DEBUG): Initialize.
2019-08-06T22:21:13.111Z,1565130073.111 [sample:C.SetSpeed] Running Loop=1
2019-08-06T22:21:13.111Z,1565130073.111 [sample:C.SetSpeed](DEBUG): Initialize.
2019-08-06T22:21:13.111Z,1565130073.111 [sample:E] Running Loop=1
2019-08-06T22:21:13.112Z,1565130073.112 [sample:E] Stopped
2019-08-06T22:21:13.112Z,1565130073.112 [sample:F] Running Loop=1
2019-08-06T22:21:13.112Z,1565130073.112 [sample:C.SetSpeed] Running Loop=1
2019-08-06T22:21:13.112Z,1565130073.112 [sample:B.Pitch] Running Loop=1
2019-08-06T22:21:13.113Z,1565130073.113 [sample:A.AbortSample] Running Loop=1
2019-08-06T22:21:13.113Z,1565130073.113 [MissionManager](INFO): MissionManager is completed.
2019-08-06T22:21:13.113Z,1565130073.113 [MissionManager](INFO): Uninitializing Mission sample
2019-08-06T22:21:13.113Z,1565130073.113 [sample] Stopped
2019-08-06T22:21:13.113Z,1565130073.113 [sample](DEBUG): Aggregate::uninitialize sample
2019-08-06T22:21:13.113Z,1565130073.113 [sample:A.AbortSample] Stopped
2019-08-06T22:21:13.113Z,1565130073.113 [sample:A.AbortSample](INFO): Uninitializing AbortSample.
2019-08-06T22:21:13.113Z,1565130073.113 [sample:B.Pitch] Stopped
2019-08-06T22:21:13.113Z,1565130073.113 [sample:C.SetSpeed] Stopped
2019-08-06T22:21:13.113Z,1565130073.113 [sample:C.SetSpeed](DEBUG): Uninitialize.
2019-08-06T22:21:13.114Z,1565130073.114 [sample:F] Stopped
2019-08-06T22:21:13.440Z,1565130073.440 [MissionManager](IMPORTANT): Started mission Default
2019-08-06T22:21:13.440Z,1565130073.440 [Default] Running Loop=1
2019-08-06T22:21:13.441Z,1565130073.441 [Default](DEBUG): Aggregate::initialize Default
2019-08-06T22:21:13.441Z,1565130073.441 [Default:B.GoToSurface] Running Loop=1
2019-08-06T22:21:13.441Z,1565130073.441 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T22:21:13.441Z,1565130073.441 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T22:21:13.441Z,1565130073.441 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T22:21:13.442Z,1565130073.442 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T22:21:13.442Z,1565130073.442 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T22:21:13.442Z,1565130073.442 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T22:21:13.443Z,1565130073.443 [Default:A.Wait] Running Loop=1
2019-08-06T22:21:13.443Z,1565130073.443 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:21:26.772Z,1565130086.772 [Default:A.Wait](INFO): Done Waiting.
2019-08-06T22:21:26.772Z,1565130086.772 [Default:A.Wait] Stopped
2019-08-06T22:21:26.772Z,1565130086.772 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:21:27.220Z,1565130087.220 [Default:CheckIn] Running Loop=1
2019-08-06T22:21:27.220Z,1565130087.220 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T22:21:27.220Z,1565130087.220 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T22:21:28.787Z,1565130088.787 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:21:29.181Z,1565130089.181 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222023.00,A,3648.16919,N,12147.28513,W,5.948,315.76,060819,,,A*7C
2019-08-06T22:21:29.184Z,1565130089.184 [NAL9602](INFO): GPS fix at 20190806T222023: (36.802820, -121.788085)
2019-08-06T22:21:29.213Z,1565130089.213 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T22:21:29.214Z,1565130089.214 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T22:21:35.126Z,1565130095.126 [DataOverHttps](INFO): Sending 225 bytes from file Logs/20190806T220044/Courier0013.lzma
2019-08-06T22:21:35.932Z,1565130095.932 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Courier0013.lzma.bak
2019-08-06T22:21:35.932Z,1565130095.932 [DataOverHttps](INFO): SBD MOMSN=11529752
2019-08-06T22:21:47.034Z,1565130107.034 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190806T220044/Courier0016.lzma
2019-08-06T22:21:47.840Z,1565130107.840 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Courier0016.lzma.bak
2019-08-06T22:21:47.840Z,1565130107.840 [DataOverHttps](INFO): SBD MOMSN=11529757
2019-08-06T22:21:59.439Z,1565130119.439 [DataOverHttps](INFO): Sending 551 bytes from file Logs/20190806T220044/Express0014.lzma
2019-08-06T22:22:00.244Z,1565130120.244 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Express0014.lzma.bak
2019-08-06T22:22:00.244Z,1565130120.244 [DataOverHttps](INFO): SBD MOMSN=11529759
2019-08-06T22:22:12.774Z,1565130132.774 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190806T220044/Express0018.lzma
2019-08-06T22:22:13.580Z,1565130133.580 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Express0018.lzma.bak
2019-08-06T22:22:13.581Z,1565130133.581 [DataOverHttps](INFO): SBD MOMSN=11529781
2019-08-06T22:22:15.296Z,1565130135.296 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T22:22:15.296Z,1565130135.296 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T22:22:15.296Z,1565130135.296 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:23:06.174Z,1565130186.174 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:23:06.174Z,1565130186.174 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-06T22:23:06.174Z,1565130186.174 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:23:06.222Z,1565130186.222 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:23:06.582Z,1565130186.582 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:23:06.582Z,1565130186.582 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-06T22:25:07.367Z,1565130307.367 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:25:07.367Z,1565130307.367 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-08-06T22:25:07.367Z,1565130307.367 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:25:07.378Z,1565130307.378 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:25:07.780Z,1565130307.780 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:25:07.780Z,1565130307.780 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-08-06T22:26:30.977Z,1565130390.977 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-08-06T22:26:59.464Z,1565130419.464 [CommandLine](IMPORTANT): got command get ESPComponent.loadAtStartup
2019-08-06T22:26:59.465Z,1565130419.465 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup 0 bool
2019-08-06T22:27:01.676Z,1565130421.676 [NAL9602](INFO): Not Powering down - fast GPS
2019-08-06T22:27:08.570Z,1565130428.570 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:27:08.571Z,1565130428.571 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-08-06T22:27:08.571Z,1565130428.571 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:27:08.581Z,1565130428.581 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:27:08.987Z,1565130428.987 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:27:08.988Z,1565130428.988 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-08-06T22:27:15.849Z,1565130435.849 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-08-06T22:27:15.849Z,1565130435.849 [Default:CheckIn:C.Wait] Stopped
2019-08-06T22:27:15.849Z,1565130435.849 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:27:15.850Z,1565130435.850 [Default:CheckIn:D] Running Loop=1
2019-08-06T22:27:16.244Z,1565130436.244 [Default:CheckIn:D] Stopped
2019-08-06T22:27:16.244Z,1565130436.244 [Default:CheckIn:E] Running Loop=1
2019-08-06T22:27:16.653Z,1565130436.653 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.046731 min 
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn:E] Stopped
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn] Stopped
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn](INFO): Running loop #2
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn] Running Loop=2
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T22:27:16.654Z,1565130436.654 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T22:27:18.255Z,1565130438.255 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:27:18.651Z,1565130438.651 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222613.00,A,3648.16775,N,12147.28307,W,0.369,307.44,060819,,,A*70
2019-08-06T22:27:18.653Z,1565130438.653 [NAL9602](INFO): GPS fix at 20190806T222613: (36.802796, -121.788051)
2019-08-06T22:27:18.681Z,1565130438.681 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T22:27:18.681Z,1565130438.681 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-08-06T22:27:24.438Z,1565130444.438 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T220044/Courier0017.lzma
2019-08-06T22:27:25.244Z,1565130445.244 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Courier0017.lzma.bak
2019-08-06T22:27:25.244Z,1565130445.244 [DataOverHttps](INFO): SBD MOMSN=11529814
2019-08-06T22:27:38.958Z,1565130458.958 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190806T220044/Express0019.lzma
2019-08-06T22:27:39.764Z,1565130459.764 [DataOverHttps](INFO): Moved sent file to Logs/20190806T220044/Express0019.lzma.bak
2019-08-06T22:27:39.764Z,1565130459.764 [DataOverHttps](INFO): SBD MOMSN=11529816
2019-08-06T22:27:42.124Z,1565130462.124 [Default:CheckIn:Read_Iridium] Stopped
2019-08-06T22:27:42.125Z,1565130462.125 [Default:CheckIn:C.Wait] Running Loop=1
2019-08-06T22:27:42.125Z,1565130462.125 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:27:49.360Z,1565130469.360 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-08-06T22:27:49.439Z,1565130469.439 [NAL9602](FAULT): received: 
+CSQ:0

OK
2019-08-06T22:27:49.439Z,1565130469.439 [NAL9602] Data Fault, FailCount= 1
2019-08-06T22:27:49.439Z,1565130469.439 [NAL9602](ERROR): Data Fault
2019-08-06T22:27:49.548Z,1565130469.548 [CBIT](ERROR): Data Fault in component: NAL9602
2019-08-06T22:27:49.764Z,1565130469.764 [NAL9602](INFO): Powering down
2019-08-06T22:27:50.629Z,1565130470.629 [CBIT](INFO): Clearing failed state for component NAL9602
2019-08-06T22:27:50.629Z,1565130470.629 [NAL9602] No Fault, FailCount= 1
2019-08-06T22:27:53.472Z,1565130473.472 [DataOverHttps](IMPORTANT): SBD MTMSN=20190806T222648
2019-08-06T22:27:58.410Z,1565130478.410 [DataOverHttps](INFO): Received command:load Maintenance/sample.xml;set sample.MissionTimeout 60 minute;set sample.CartridgeType NaN count;set sample.NumberOfSamples 3 count;set sample.WaitBeforeSample 1 minute;run 
2019-08-06T22:27:58.423Z,1565130478.423 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2019-08-06T22:27:58.424Z,1565130478.424 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2019-08-06T22:27:58.446Z,1565130478.446 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2019-08-06T22:27:58.448Z,1565130478.448 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2019-08-06T22:27:58.450Z,1565130478.450 [MissionManager](INFO): DefineArg sample.CartridgeType = -1.000000 count
2019-08-06T22:27:58.452Z,1565130478.452 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2019-08-06T22:27:58.454Z,1565130478.454 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2019-08-06T22:27:58.455Z,1565130478.455 [sample:A.AbortSample](DEBUG): Construct.
2019-08-06T22:27:58.456Z,1565130478.456 [sample:B.Pitch](DEBUG): Construct.
2019-08-06T22:27:58.507Z,1565130478.507 [sample:C.SetSpeed](DEBUG): Construct.
2019-08-06T22:27:58.509Z,1565130478.509 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2019-08-06T22:27:58.614Z,1565130478.614 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2019-08-06T22:27:58.617Z,1565130478.617 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 10.000000 s
2019-08-06T22:27:58.619Z,1565130478.619 [MissionManager](INFO): DefineArg sample:SampleAtDepth.MaxWaitNotReachingDepth = 3.000000 h
2019-08-06T22:27:58.621Z,1565130478.621 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2019-08-06T22:27:58.624Z,1565130478.624 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 1.000000 bool
2019-08-06T22:27:58.626Z,1565130478.626 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 0.000000 bool
2019-08-06T22:27:58.628Z,1565130478.628 [MissionManager](INFO): DefineArg sample:SampleAtDepth.ESPCartridgeType = nan count
2019-08-06T22:27:58.630Z,1565130478.630 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2019-08-06T22:27:58.632Z,1565130478.632 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2019-08-06T22:27:58.635Z,1565130478.635 [MissionManager](INFO): DefineArg sample:SampleAtDepth.BuoyancyNeutral = 199.999995 cc
2019-08-06T22:27:58.637Z,1565130478.637 [sample:SampleAtDepth:ApproachDepth:B.Pitch](DEBUG): Construct.
2019-08-06T22:27:58.642Z,1565130478.642 [sample:SampleAtDepth:ApproachDepth:B.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T22:27:58.662Z,1565130478.662 [sample:SampleAtDepth:SampleWrapper:A.Pitch](DEBUG): Construct.
2019-08-06T22:27:58.728Z,1565130478.728 [sample:SampleAtDepth:SampleWrapper:C.Wait](DEBUG): Construct Wait.
2019-08-06T22:27:58.760Z,1565130478.760 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T22:27:58.762Z,1565130478.762 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2019-08-06T22:27:58.762Z,1565130478.762 [MissionManager](ERROR): Slate does not contain celsius
2019-08-06T22:27:58.787Z,1565130478.787 [MissionManager](ERROR): Slate does not contain WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-08-06T22:27:58.787Z,1565130478.787 [MissionManager](ERROR): Slate does not contain microgram_per_liter
2019-08-06T22:27:58.790Z,1565130478.790 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2019-08-06T22:27:58.794Z,1565130478.794 [MissionManager](CRITICAL): Slate does not contain ESPComponent.cartridge
2019-08-06T22:27:58.794Z,1565130478.794 [sample:SampleAtDepth:SampleWrapper:SampleESP:SelectESPCartridge](CRITICAL): Error!!!! no component for child behavior.
2019-08-06T22:27:58.796Z,1565130478.796 [MissionManager](ERROR): Slate does not contain CTD_NeilBrown.bin_mean_sea_water_temperature
2019-08-06T22:27:58.797Z,1565130478.797 [MissionManager](ERROR): Slate does not contain celsius
2019-08-06T22:27:58.797Z,1565130478.797 [MissionManager](ERROR): Slate does not contain WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-08-06T22:27:58.797Z,1565130478.797 [MissionManager](ERROR): Slate does not contain microgram_per_liter
2019-08-06T22:27:58.847Z,1565130478.847 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Control="Tethys/Control"
         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/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="CartridgeType"><Description>
        Specifies ESP cartridge type code.
    </Description><Units:count/><Value>-1</Value></DefineArg>
    
    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

     <Trigger:AbortSample>
     	  <Parallel/>
     </Trigger:AbortSample>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

    <Guidance:SetSpeed>
        <Parallel/>
        <Setting><Guidance:SetSpeed.speed/><Units:meter_per_second/><Value>0</Value></Setting>
    </Guidance:SetSpeed>

    <Insert Filename="Insert/SampleAtDepth.xml"/>

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:ESPCartridgeType"/><Arg Name="CartridgeType"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2019-08-06T22:27:58.847Z,1565130478.847 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2019-08-06T22:28:03.836Z,1565130483.836 [CBIT](INFO): Critical error at 20190806T222758
2019-08-06T22:28:03.836Z,1565130483.836 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-08-06T22:28:03.856Z,1565130483.856 [CommandLine](IMPORTANT): got command set sample.MissionTimeout 60.000000 minute
2019-08-06T22:28:03.858Z,1565130483.858 [CommandLine](IMPORTANT): got command set sample.CartridgeType nan count
2019-08-06T22:28:03.859Z,1565130483.859 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 3.000000 count
2019-08-06T22:28:03.860Z,1565130483.860 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 1.000000 minute
2019-08-06T22:28:03.860Z,1565130483.860 [CommandLine](IMPORTANT): got command run 
2019-08-06T22:28:03.862Z,1565130483.862 [CommandLine](IMPORTANT): Running 
2019-08-06T22:28:03.889Z,1565130483.889 [Default] Stopped
2019-08-06T22:28:03.889Z,1565130483.889 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-06T22:28:03.889Z,1565130483.889 [Default:B.GoToSurface] Stopped
2019-08-06T22:28:03.889Z,1565130483.889 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-06T22:28:03.889Z,1565130483.889 [Default:CheckIn] Stopped
2019-08-06T22:28:03.890Z,1565130483.890 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T22:28:03.890Z,1565130483.890 [Default:CheckIn:C.Wait] Stopped
2019-08-06T22:28:03.890Z,1565130483.890 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:28:03.890Z,1565130483.890 [MissionManager](IMPORTANT): Started mission sample
2019-08-06T22:28:03.890Z,1565130483.890 [sample] Running Loop=1
2019-08-06T22:28:03.890Z,1565130483.890 [sample](DEBUG): Aggregate::initialize sample
2019-08-06T22:28:03.890Z,1565130483.890 [sample:A.AbortSample] Running Loop=1
2019-08-06T22:28:03.890Z,1565130483.890 [sample:A.AbortSample](INFO): Initializing AbortSample.
2019-08-06T22:28:03.927Z,1565130483.927 [sample:B.Pitch] Running Loop=1
2019-08-06T22:28:03.927Z,1565130483.927 [sample:B.Pitch](DEBUG): Initialize.
2019-08-06T22:28:03.927Z,1565130483.927 [sample:C.SetSpeed] Running Loop=1
2019-08-06T22:28:03.927Z,1565130483.927 [sample:C.SetSpeed](DEBUG): Initialize.
2019-08-06T22:28:03.927Z,1565130483.927 [sample:E] Running Loop=1
2019-08-06T22:28:03.928Z,1565130483.928 [sample:E] Stopped
2019-08-06T22:28:03.928Z,1565130483.928 [sample:F] Running Loop=1
2019-08-06T22:28:03.928Z,1565130483.928 [sample:C.SetSpeed] Running Loop=1
2019-08-06T22:28:03.928Z,1565130483.928 [sample:B.Pitch] Running Loop=1
2019-08-06T22:28:03.928Z,1565130483.928 [sample:A.AbortSample] Running Loop=1
2019-08-06T22:28:03.929Z,1565130483.929 [MissionManager](INFO): MissionManager is completed.
2019-08-06T22:28:03.929Z,1565130483.929 [MissionManager](INFO): Uninitializing Mission sample
2019-08-06T22:28:03.929Z,1565130483.929 [sample] Stopped
2019-08-06T22:28:03.929Z,1565130483.929 [sample](DEBUG): Aggregate::uninitialize sample
2019-08-06T22:28:03.929Z,1565130483.929 [sample:A.AbortSample] Stopped
2019-08-06T22:28:03.929Z,1565130483.929 [sample:A.AbortSample](INFO): Uninitializing AbortSample.
2019-08-06T22:28:03.929Z,1565130483.929 [sample:B.Pitch] Stopped
2019-08-06T22:28:03.929Z,1565130483.929 [sample:C.SetSpeed] Stopped
2019-08-06T22:28:03.929Z,1565130483.929 [sample:C.SetSpeed](DEBUG): Uninitialize.
2019-08-06T22:28:03.929Z,1565130483.929 [sample:F] Stopped
2019-08-06T22:28:04.276Z,1565130484.276 [MissionManager](IMPORTANT): Started mission Default
2019-08-06T22:28:04.276Z,1565130484.276 [Default] Running Loop=1
2019-08-06T22:28:04.276Z,1565130484.276 [Default](DEBUG): Aggregate::initialize Default
2019-08-06T22:28:04.276Z,1565130484.276 [Default:B.GoToSurface] Running Loop=1
2019-08-06T22:28:04.276Z,1565130484.276 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-08-06T22:28:04.276Z,1565130484.276 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-08-06T22:28:04.277Z,1565130484.277 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-08-06T22:28:04.277Z,1565130484.277 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-08-06T22:28:04.277Z,1565130484.277 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-08-06T22:28:04.278Z,1565130484.278 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-08-06T22:28:04.278Z,1565130484.278 [Default:A.Wait] Running Loop=1
2019-08-06T22:28:04.278Z,1565130484.278 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-08-06T22:28:10.649Z,1565130490.649 [CommandLine](IMPORTANT): got command show variable neilbrown
2019-08-06T22:28:10.702Z,1565130490.702 [CommandLine](IMPORTANT): CTD_NeilBrown.loadControl (none)
2019-08-06T22:28:10.702Z,1565130490.702 [CommandLine](IMPORTANT): CTD_NeilBrown.uart (none)
2019-08-06T22:28:10.703Z,1565130490.703 [CommandLine](IMPORTANT): CTD_NeilBrown.baud (bit_per_second)
2019-08-06T22:28:10.745Z,1565130490.745 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup (bool)
2019-08-06T22:28:10.746Z,1565130490.746 [CommandLine](IMPORTANT): CTD_NeilBrown.simulateHardware (bool)
2019-08-06T22:28:10.746Z,1565130490.746 [CommandLine](IMPORTANT): CTD_NeilBrown.maxPressBound (decibar)
2019-08-06T22:28:10.746Z,1565130490.746 [CommandLine](IMPORTANT): CTD_NeilBrown.minPressBound (decibar)
2019-08-06T22:28:10.756Z,1565130490.756 [CommandLine](IMPORTANT): CTD_NeilBrown.maxSalinityBound (practical_salinity_unit)
2019-08-06T22:28:10.756Z,1565130490.756 [CommandLine](IMPORTANT): CTD_NeilBrown.minSalinityBound (practical_salinity_unit)
2019-08-06T22:28:10.756Z,1565130490.756 [CommandLine](IMPORTANT): CTD_NeilBrown.offset (decibar)
2019-08-06T22:28:10.757Z,1565130490.757 [CommandLine](IMPORTANT): CTD_NeilBrown.power (watt)
2019-08-06T22:28:16.154Z,1565130496.154 [CommandLine](IMPORTANT): got command get CTD_NeilBrown.loadAtStartup
2019-08-06T22:28:16.155Z,1565130496.155 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup 0 bool
2019-08-06T22:28:17.610Z,1565130497.610 [Default:A.Wait](INFO): Done Waiting.
2019-08-06T22:28:17.610Z,1565130497.610 [Default:A.Wait] Stopped
2019-08-06T22:28:17.610Z,1565130497.610 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-08-06T22:28:18.014Z,1565130498.014 [Default:CheckIn] Running Loop=1
2019-08-06T22:28:18.014Z,1565130498.014 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-08-06T22:28:18.014Z,1565130498.014 [Default:CheckIn:Read_GPS] Running Loop=1
2019-08-06T22:28:20.012Z,1565130500.012 [NAL9602](INFO): Powering up NAL9602
2019-08-06T22:28:30.916Z,1565130510.916 [NAL9602](INFO): NAL9602 initialized
2019-08-06T22:28:31.739Z,1565130511.739 [NAL9602](DEBUG): Fix Requested
2019-08-06T22:28:45.822Z,1565130525.822 [CommandLine](IMPORTANT): got command get WetLabsBB2FL.loadAtStartup
2019-08-06T22:28:45.822Z,1565130525.822 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup 0 bool
2019-08-06T22:28:48.779Z,1565130528.779 [CommandLine](IMPORTANT): got command configSet list
2019-08-06T22:28:48.779Z,1565130528.779 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-08-06T22:28:48.780Z,1565130528.780 [CommandLine](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;

2019-08-06T22:28:48.780Z,1565130528.780 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-08-06T22:28:48.780Z,1565130528.780 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=0 count;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=6 hour;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): CBIT.abortDepth=296 meter;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): CBIT.gf24Offset=172 microampere;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): CBIT.stopDepth=288 meter;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): DAT.ignoreElevationAngle=1 bool;

2019-08-06T22:28:48.781Z,1565130528.781 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=0 bool;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): Express linearApproximation DAT.range 5.000000 meter;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2019-08-06T22:28:48.782Z,1565130528.782 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-08-06T22:28:48.785Z,1565130528.785 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;

2019-08-06T22:28:48.785Z,1565130528.785 [CommandLine](IMPORTANT): VerticalControl.massDefault=-4 millimeter;

2019-08-06T22:28:48.785Z,1565130528.785 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-31 millimeter;

2019-08-06T22:28:48.785Z,1565130528.785 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=30 millimeter;

2019-08-06T22:28:48.785Z,1565130528.785 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup=0 bool;

2019-08-06T22:29:01.618Z,1565130541.618 [NAL9602](INFO): SBD MO Status=2, MOMSN=15850, MT Status=2, MTMSN=0
2019-08-06T22:29:01.618Z,1565130541.618 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T22:29:09.723Z,1565130549.723 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-08-06T22:29:09.723Z,1565130549.723 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-08-06T22:29:09.723Z,1565130549.723 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-08-06T22:29:09.734Z,1565130549.734 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-08-06T22:29:10.228Z,1565130550.228 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-08-06T22:29:10.228Z,1565130550.228 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-08-06T22:29:17.377Z,1565130557.377 [NAL9602](INFO): SBD MO Status=2, MOMSN=15850, MT Status=2, MTMSN=0
2019-08-06T22:29:17.377Z,1565130557.377 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T22:29:36.389Z,1565130576.389 [NAL9602](INFO): SBD MO Status=2, MOMSN=15850, MT Status=2, MTMSN=0
2019-08-06T22:29:36.389Z,1565130576.389 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T22:30:18.013Z,1565130618.013 [NAL9602](INFO): SBD MO Status=2, MOMSN=15850, MT Status=2, MTMSN=0
2019-08-06T22:30:18.013Z,1565130618.013 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T22:30:24.129Z,1565130624.129 [CommandLine](IMPORTANT): got command show stack
2019-08-06T22:30:24.130Z,1565130624.130 [CommandLine](IMPORTANT): Behavior Stack:

2019-08-06T22:30:24.130Z,1565130624.130 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2019-08-06T22:30:24.130Z,1565130624.130 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2019-08-06T22:30:53.559Z,1565130653.559 [NAL9602](INFO): SBD MO Status=2, MOMSN=15850, MT Status=2, MTMSN=0
2019-08-06T22:30:53.559Z,1565130653.559 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-08-06T22:31:00.548Z,1565130660.548 [DataOverHttps](IMPORTANT): SBD MTMSN=20190806T222955
2019-08-06T22:31:05.350Z,1565130665.350 [DataOverHttps](INFO): Received command:restart app
2019-08-06T22:31:05.380Z,1565130665.380 [CommandLine](IMPORTANT): got command restart application
2019-08-06T22:31:06.383Z,1565130666.383 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-06T22:31:06.383Z,1565130666.383 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.535Z,1565130666.535 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-08-06T22:31:06.535Z,1565130666.535 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.536Z,1565130666.536 [CommandLine](INFO): Join timeout helper Thread ID is 1024
2019-08-06T22:31:06.536Z,1565130666.536 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-08-06T22:31:06.536Z,1565130666.536 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.537Z,1565130666.537 [NavChartDb](INFO): Join timeout helper Thread ID is 1025
2019-08-06T22:31:06.711Z,1565130666.711 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-06T22:31:06.711Z,1565130666.711 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.719Z,1565130666.719 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-08-06T22:31:06.719Z,1565130666.719 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.719Z,1565130666.719 [Radio_Surface](INFO): Join timeout helper Thread ID is 1026
2019-08-06T22:31:06.811Z,1565130666.811 [Radio_Surface](INFO): Powering down
2019-08-06T22:31:06.812Z,1565130666.812 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-06T22:31:06.812Z,1565130666.812 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.819Z,1565130666.819 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-08-06T22:31:06.819Z,1565130666.819 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.819Z,1565130666.819 [DataOverHttps](INFO): Join timeout helper Thread ID is 1027
2019-08-06T22:31:06.963Z,1565130666.963 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-06T22:31:06.963Z,1565130666.963 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.979Z,1565130666.979 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-08-06T22:31:06.979Z,1565130666.979 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.979Z,1565130666.979 [logger](INFO): Join timeout helper Thread ID is 1028
2019-08-06T22:31:06.995Z,1565130666.995 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-06T22:31:06.995Z,1565130666.995 [logger ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.000Z,1565130667.000 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-08-06T22:31:06.000Z,1565130667.000 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:06.000Z,1565130667.000 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-08-06T22:31:07.000Z,1565130667.000 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:07.000Z,1565130667.000 [controlThread](INFO): Join timeout helper Thread ID is 1029
2019-08-06T22:31:07.279Z,1565130667.279 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-08-06T22:31:07.279Z,1565130667.279 [controlThread](DEBUG): Uninitializing ControlThread
2019-08-06T22:31:07.280Z,1565130667.280 [NAL9602](INFO): Powering down
2019-08-06T22:31:07.282Z,1565130667.282 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-08-06T22:31:07.282Z,1565130667.282 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-08-06T22:31:07.283Z,1565130667.283 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-08-06T22:31:07.283Z,1565130667.283 [MissionManager](INFO): Uninitializing Mission Default
2019-08-06T22:31:07.283Z,1565130667.283 [Default] Stopped
2019-08-06T22:31:07.284Z,1565130667.284 [Default](DEBUG): Aggregate::uninitialize Default
2019-08-06T22:31:07.284Z,1565130667.284 [Default:B.GoToSurface] Stopped
2019-08-06T22:31:07.284Z,1565130667.284 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-08-06T22:31:07.284Z,1565130667.284 [Default:CheckIn] Stopped
2019-08-06T22:31:07.284Z,1565130667.284 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-08-06T22:31:07.284Z,1565130667.284 [Default:CheckIn:Read_GPS] Stopped
2019-08-06T22:31:07.286Z,1565130667.286 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-08-06T22:31:07.286Z,1565130667.286 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-08-06T22:31:07.286Z,1565130667.286 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-08-06T22:31:07.287Z,1565130667.287 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-08-06T22:31:07.287Z,1565130667.287 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-08-06T22:31:07.287Z,1565130667.287 [BuoyancyServo](INFO): Powering down
2019-08-06T22:31:07.299Z,1565130667.299 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-08-06T22:31:07.299Z,1565130667.299 [ElevatorServo](INFO): Powering down
2019-08-06T22:31:07.300Z,1565130667.300 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-08-06T22:31:07.300Z,1565130667.300 [MassServo](INFO): Powering down
2019-08-06T22:31:07.301Z,1565130667.301 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-08-06T22:31:07.301Z,1565130667.301 [RudderServo](INFO): Powering down
2019-08-06T22:31:07.302Z,1565130667.302 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-08-06T22:31:07.302Z,1565130667.302 [ThrusterServo](INFO): Powering down
2019-08-06T22:31:07.303Z,1565130667.303 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-08-06T22:31:07.303Z,1565130667.303 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-08-06T22:31:07.303Z,1565130667.303 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-08-06T22:31:07.303Z,1565130667.303 [CBIT](DEBUG): Powering off loads.
2019-08-06T22:31:07.315Z,1565130667.315 [CBIT](DEBUG): Disabling WDT.
2019-08-06T22:31:07.327Z,1565130667.327 [CBIT](DEBUG): Opening all GF detection circuits.
2019-08-06T22:31:07.327Z,1565130667.327 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:07.406Z,1565130667.406 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:07.412Z,1565130667.412 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:07.470Z,1565130667.470 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-08-06T22:31:07.537Z,1565130667.537 [logger ThreadHandler](INFO): Thread cancelled.