2018-01-23T17:13:27.590Z,1516727607.590 [Supervisor](DEBUG): Initializing supervisor.
2018-01-23T17:13:27.592Z,1516727607.592 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-01-23T17:13:27.593Z,1516727607.593 [SyncHandler](INFO): Protected caller Thread ID is 991
2018-01-23T17:13:27.593Z,1516727607.593 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-01-23T17:13:27.594Z,1516727607.594 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-01-23T17:13:27.595Z,1516727607.595 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 992
2018-01-23T17:13:27.597Z,1516727607.597 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-01-23T17:13:27.608Z,1516727607.608 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-01-23T17:13:27.609Z,1516727607.609 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-01-23T17:13:27.609Z,1516727607.609 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 993
2018-01-23T17:13:27.610Z,1516727607.610 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-01-23T17:13:27.611Z,1516727607.611 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-01-23T17:13:27.611Z,1516727607.611 [logger ThreadHandler](INFO): Protected caller Thread ID is 994
2018-01-23T17:13:27.613Z,1516727607.613 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-01-23T17:13:27.614Z,1516727607.614 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-01-23T17:13:27.615Z,1516727607.615 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-01-23T17:13:27.944Z,1516727607.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-01-23T17:13:27.945Z,1516727607.945 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-01-23T17:13:28.147Z,1516727608.147 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-01-23T17:13:28.148Z,1516727608.148 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-01-23T17:13:28.432Z,1516727608.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-01-23T17:13:28.433Z,1516727608.433 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-01-23T17:13:28.584Z,1516727608.584 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-01-23T17:13:28.585Z,1516727608.585 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-01-23T17:13:28.827Z,1516727608.827 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-01-23T17:13:28.827Z,1516727608.827 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-01-23T17:13:29.298Z,1516727609.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-01-23T17:13:29.298Z,1516727609.298 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-01-23T17:13:29.643Z,1516727609.643 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-01-23T17:13:29.643Z,1516727609.643 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-01-23T17:13:30.100Z,1516727610.100 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-01-23T17:13:30.100Z,1516727610.100 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-01-23T17:13:30.206Z,1516727610.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-01-23T17:13:30.207Z,1516727610.207 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-01-23T17:13:30.305Z,1516727610.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-01-23T17:13:30.306Z,1516727610.306 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-01-23T17:13:30.507Z,1516727610.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-01-23T17:13:30.508Z,1516727610.508 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-01-23T17:13:30.709Z,1516727610.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-01-23T17:13:30.710Z,1516727610.710 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-01-23T17:13:31.045Z,1516727611.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-01-23T17:13:31.045Z,1516727611.045 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-01-23T17:13:31.186Z,1516727611.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-01-23T17:13:31.187Z,1516727611.187 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-01-23T17:13:31.270Z,1516727611.270 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-01-23T17:13:31.271Z,1516727611.271 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-01-23T17:13:31.374Z,1516727611.374 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-01-23T17:13:31.467Z,1516727611.467 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-01-23T17:13:31.562Z,1516727611.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-01-23T17:13:31.648Z,1516727611.648 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-01-23T17:13:31.801Z,1516727611.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-01-23T17:13:31.982Z,1516727611.982 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-01-23T17:13:32.058Z,1516727612.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-01-23T17:13:32.291Z,1516727612.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-01-23T17:13:32.292Z,1516727612.292 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-01-23T17:13:32.375Z,1516727612.375 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-01-23T17:13:32.466Z,1516727612.466 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-01-23T17:13:32.567Z,1516727612.567 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-01-23T17:13:32.694Z,1516727612.694 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-01-23T17:13:32.694Z,1516727612.694 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-01-23T17:13:32.699Z,1516727612.699 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-01-23T17:13:32.958Z,1516727612.958 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-01-23T17:13:32.959Z,1516727612.959 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-01-23T17:13:33.002Z,1516727613.002 [DepthRateCalculator] Loaded
2018-01-23T17:13:33.003Z,1516727613.003 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-01-23T17:13:33.009Z,1516727613.009 [PitchRateCalculator] Loaded
2018-01-23T17:13:33.009Z,1516727613.009 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-01-23T17:13:33.026Z,1516727613.026 [SpeedCalculator] Loaded
2018-01-23T17:13:33.026Z,1516727613.026 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-01-23T17:13:33.048Z,1516727613.048 [TempGradientCalculator] Loaded
2018-01-23T17:13:33.048Z,1516727613.048 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-01-23T17:13:33.064Z,1516727613.064 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-01-23T17:13:33.064Z,1516727613.064 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-01-23T17:13:33.070Z,1516727613.070 [YawRateCalculator] Loaded
2018-01-23T17:13:33.070Z,1516727613.070 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-01-23T17:13:33.071Z,1516727613.071 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-01-23T17:13:33.071Z,1516727613.071 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-01-23T17:13:33.157Z,1516727613.157 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-01-23T17:13:33.157Z,1516727613.157 [StratificationFrontDetector](DEBUG): (re)initializing
2018-01-23T17:13:33.157Z,1516727613.157 [StratificationFrontDetector] Loaded
2018-01-23T17:13:33.157Z,1516727613.157 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-01-23T17:13:33.158Z,1516727613.158 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-01-23T17:13:33.158Z,1516727613.158 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-01-23T17:13:33.278Z,1516727613.278 [BuoyancyServo] Loaded
2018-01-23T17:13:33.279Z,1516727613.279 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-01-23T17:13:33.294Z,1516727613.294 [ElevatorServo] Loaded
2018-01-23T17:13:33.294Z,1516727613.294 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-01-23T17:13:33.309Z,1516727613.309 [MassServo] Loaded
2018-01-23T17:13:33.309Z,1516727613.309 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-01-23T17:13:33.325Z,1516727613.325 [RudderServo] Loaded
2018-01-23T17:13:33.326Z,1516727613.326 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-01-23T17:13:33.340Z,1516727613.340 [ThrusterServo] Loaded
2018-01-23T17:13:33.340Z,1516727613.340 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-01-23T17:13:33.341Z,1516727613.341 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-01-23T17:13:33.341Z,1516727613.341 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-01-23T17:13:33.355Z,1516727613.355 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-01-23T17:13:33.355Z,1516727613.355 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-01-23T17:13:33.461Z,1516727613.461 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-01-23T17:13:33.462Z,1516727613.462 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-01-23T17:13:33.811Z,1516727613.811 [DataOverHttps] Loaded
2018-01-23T17:13:33.811Z,1516727613.811 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-01-23T17:13:33.852Z,1516727613.852 [Depth_Keller] Loaded
2018-01-23T17:13:33.853Z,1516727613.853 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-01-23T17:13:33.878Z,1516727613.878 [DropWeight] Loaded
2018-01-23T17:13:33.878Z,1516727613.878 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-01-23T17:13:34.229Z,1516727614.229 [NAL9602] Loaded
2018-01-23T17:13:34.229Z,1516727614.229 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-01-23T17:13:34.278Z,1516727614.278 [Onboard] Loaded
2018-01-23T17:13:34.289Z,1516727614.289 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-01-23T17:13:34.308Z,1516727614.308 [Radio_Surface] Loaded
2018-01-23T17:13:34.308Z,1516727614.308 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-01-23T17:13:34.319Z,1516727614.319 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4086B4E0
2018-01-23T17:13:34.320Z,1516727614.320 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1076
2018-01-23T17:13:34.369Z,1516727614.369 [PNI_TCM] Loaded
2018-01-23T17:13:34.370Z,1516727614.370 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-01-23T17:13:34.370Z,1516727614.370 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-01-23T17:13:34.371Z,1516727614.371 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-01-23T17:13:34.635Z,1516727614.635 [SBIT](DEBUG): Construct Startup Built In Test.
2018-01-23T17:13:34.661Z,1516727614.661 [SBIT] Loaded
2018-01-23T17:13:34.661Z,1516727614.661 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-01-23T17:13:34.662Z,1516727614.662 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-01-23T17:13:34.674Z,1516727614.674 [IBIT] Loaded
2018-01-23T17:13:34.674Z,1516727614.674 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-01-23T17:13:34.677Z,1516727614.677 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-01-23T17:13:34.837Z,1516727614.837 [CBIT] Loaded
2018-01-23T17:13:34.837Z,1516727614.837 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-01-23T17:13:34.838Z,1516727614.838 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-01-23T17:13:34.838Z,1516727614.838 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-01-23T17:13:34.989Z,1516727614.989 [Aanderaa_O2] Loaded
2018-01-23T17:13:34.989Z,1516727614.989 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-01-23T17:13:35.002Z,1516727615.002 [CANONSampler] Loaded
2018-01-23T17:13:35.002Z,1516727615.002 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2018-01-23T17:13:35.083Z,1516727615.083 [CTD_NeilBrown] Loaded
2018-01-23T17:13:35.083Z,1516727615.083 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-01-23T17:13:35.084Z,1516727615.084 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409314E0
2018-01-23T17:13:35.085Z,1516727615.085 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1077
2018-01-23T17:13:35.118Z,1516727615.118 [CTD_Seabird] Loaded
2018-01-23T17:13:35.118Z,1516727615.118 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-01-23T17:13:35.119Z,1516727615.119 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2018-01-23T17:13:35.120Z,1516727615.120 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1078
2018-01-23T17:13:35.134Z,1516727615.134 [PAR_Licor] Loaded
2018-01-23T17:13:35.135Z,1516727615.135 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-01-23T17:13:35.185Z,1516727615.185 [WetLabsBB2FL] Loaded
2018-01-23T17:13:35.186Z,1516727615.186 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-01-23T17:13:35.187Z,1516727615.187 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2018-01-23T17:13:35.187Z,1516727615.187 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1079
2018-01-23T17:13:35.233Z,1516727615.233 [WetLabsSeaOWL_UV_A] Loaded
2018-01-23T17:13:35.233Z,1516727615.233 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-01-23T17:13:35.234Z,1516727615.234 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409C14E0
2018-01-23T17:13:35.235Z,1516727615.235 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 1080
2018-01-23T17:13:35.235Z,1516727615.235 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-01-23T17:13:35.236Z,1516727615.236 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-01-23T17:13:35.308Z,1516727615.308 [VerticalControl](DEBUG): Construct VerticalControl.
2018-01-23T17:13:35.398Z,1516727615.398 [VerticalControl] Loaded
2018-01-23T17:13:35.398Z,1516727615.398 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-01-23T17:13:35.399Z,1516727615.399 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-01-23T17:13:35.458Z,1516727615.458 [HorizontalControl] Loaded
2018-01-23T17:13:35.458Z,1516727615.458 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-01-23T17:13:35.459Z,1516727615.459 [SpeedControl](DEBUG): Construct SpeedControl.
2018-01-23T17:13:35.460Z,1516727615.460 [SpeedControl] Loaded
2018-01-23T17:13:35.461Z,1516727615.461 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-01-23T17:13:35.461Z,1516727615.461 [LoopControl](DEBUG): Construct LoopControl.
2018-01-23T17:13:35.462Z,1516727615.462 [LoopControl] Loaded
2018-01-23T17:13:35.462Z,1516727615.462 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-01-23T17:13:35.463Z,1516727615.463 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-01-23T17:13:35.463Z,1516727615.463 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-01-23T17:13:35.489Z,1516727615.489 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-01-23T17:13:35.490Z,1516727615.490 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-01-23T17:13:35.585Z,1516727615.585 [DeadReckonUsingSpeedCalculator] Loaded
2018-01-23T17:13:35.585Z,1516727615.585 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-01-23T17:13:35.643Z,1516727615.643 [DeadReckonWithRespectToSeafloor] Loaded
2018-01-23T17:13:35.643Z,1516727615.643 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2018-01-23T17:13:35.660Z,1516727615.660 [NavChart] Loaded
2018-01-23T17:13:35.660Z,1516727615.660 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-01-23T17:13:35.664Z,1516727615.664 [UniversalFixResidualReporter] Loaded
2018-01-23T17:13:35.665Z,1516727615.665 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-01-23T17:13:35.665Z,1516727615.665 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-01-23T17:13:35.669Z,1516727615.669 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-01-23T17:13:35.669Z,1516727615.669 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-01-23T17:13:35.676Z,1516727615.676 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-01-23T17:13:35.677Z,1516727615.677 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A4C4E0
2018-01-23T17:13:35.677Z,1516727615.677 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1081
2018-01-23T17:13:35.682Z,1516727615.682 [Supervisor](INFO): Main Thread ID is 796
2018-01-23T17:13:35.682Z,1516727615.682 [Supervisor](DEBUG): Running supervisor.
2018-01-23T17:13:35.683Z,1516727615.683 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1082
2018-01-23T17:13:35.686Z,1516727615.686 [controlThread ThreadHandler](INFO): Handler Thread ID is 1083
2018-01-23T17:13:35.687Z,1516727615.687 [controlThread](DEBUG): Initializing ControlThread
2018-01-23T17:13:35.688Z,1516727615.688 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-01-23T17:13:35.688Z,1516727615.688 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-01-23T17:13:35.688Z,1516727615.688 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-01-23T17:13:35.689Z,1516727615.689 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-01-23T17:13:35.689Z,1516727615.689 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-01-23T17:13:35.690Z,1516727615.690 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-01-23T17:13:35.695Z,1516727615.695 [SBIT](INFO): Initialize SBIT Component.
2018-01-23T17:13:35.695Z,1516727615.695 [SBIT](IMPORTANT): git: 2017-12-12
2018-01-23T17:13:35.696Z,1516727615.696 [SBIT](INFO): git hash: 18638d31f033e3fa0cb90b26256f5481d37f00cc
2018-01-23T17:13:35.696Z,1516727615.696 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-01-23T17:13:35.697Z,1516727615.697 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-01-23T17:13:35.698Z,1516727615.698 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-01-23T17:13:35.699Z,1516727615.699 [IBIT](INFO): Initialize IBIT Component.
2018-01-23T17:13:35.699Z,1516727615.699 [CBIT](DEBUG): Initialize CBIT Component.
2018-01-23T17:13:35.700Z,1516727615.700 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-01-23T17:13:35.701Z,1516727615.701 [logger ThreadHandler](INFO): Handler Thread ID is 1084
2018-01-23T17:13:35.717Z,1516727615.717 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1085
2018-01-23T17:13:35.723Z,1516727615.723 [Radio_Surface](INFO): Powering up
2018-01-23T17:13:35.729Z,1516727615.729 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1086
2018-01-23T17:13:35.730Z,1516727615.730 [CTD_NeilBrown](INFO): Powering down
2018-01-23T17:13:35.761Z,1516727615.761 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1087
2018-01-23T17:13:35.762Z,1516727615.762 [CTD_Seabird](INFO): Initializing
2018-01-23T17:13:35.801Z,1516727615.801 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-01-23T17:13:35.803Z,1516727615.803 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-01-23T17:13:35.804Z,1516727615.804 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-01-23T17:13:35.805Z,1516727615.805 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-01-23T17:13:35.805Z,1516727615.805 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T17:13:35.806Z,1516727615.806 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:13:35.807Z,1516727615.807 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:13:35.807Z,1516727615.807 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:13:35.808Z,1516727615.808 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:13:35.808Z,1516727615.808 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:13:35.808Z,1516727615.808 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-01-23T17:13:35.808Z,1516727615.808 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-01-23T17:13:35.810Z,1516727615.810 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-01-23T17:13:35.820Z,1516727615.820 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1089
2018-01-23T17:13:35.821Z,1516727615.821 [WetLabsBB2FL](INFO): Powering down
2018-01-23T17:13:35.835Z,1516727615.835 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-23T17:13:35.858Z,1516727615.858 [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>


2018-01-23T17:13:35.859Z,1516727615.859 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-01-23T17:13:35.869Z,1516727615.869 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 1090
2018-01-23T17:13:35.877Z,1516727615.877 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1091
2018-01-23T17:13:35.881Z,1516727615.881 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-01-23T17:13:35.881Z,1516727615.881 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-01-23T17:13:35.881Z,1516727615.881 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-01-23T17:13:35.881Z,1516727615.881 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-01-23T17:13:35.881Z,1516727615.881 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-01-23T17:13:35.882Z,1516727615.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-01-23T17:13:35.882Z,1516727615.882 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-01-23T17:13:35.882Z,1516727615.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-01-23T17:13:35.882Z,1516727615.882 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-01-23T17:13:35.882Z,1516727615.882 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-01-23T17:13:35.883Z,1516727615.883 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-01-23T17:13:35.883Z,1516727615.883 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-01-23T17:13:35.883Z,1516727615.883 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-01-23T17:13:35.883Z,1516727615.883 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-01-23T17:13:35.883Z,1516727615.883 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-01-23T17:13:35.884Z,1516727615.884 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-01-23T17:13:35.991Z,1516727615.991 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-01-23T17:13:35.992Z,1516727615.992 [Default:A.Wait](DEBUG): Construct Wait.
2018-01-23T17:13:36.018Z,1516727616.018 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-23T17:13:36.052Z,1516727616.052 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-01-23T17:13:36.054Z,1516727616.054 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-01-23T17:13:36.085Z,1516727616.085 [Default:E.Execute](DEBUG): Construct Execute.
2018-01-23T17:13:36.089Z,1516727616.089 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
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/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="Default">

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

    <Guidance:Wait>
        <Sequence/>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <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">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</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>


2018-01-23T17:13:36.094Z,1516727616.094 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-01-23T17:13:36.094Z,1516727616.094 [CTD_Seabird](INFO): Powering down
2018-01-23T17:13:36.130Z,1516727616.130 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-01-23T17:13:36.138Z,1516727616.138 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-01-23T17:13:36.389Z,1516727616.389 [CANONSampler](INFO): Powering down
2018-01-23T17:13:36.674Z,1516727616.674 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:36.713Z,1516727616.713 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:36.810Z,1516727616.810 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-01-23T17:13:36.817Z,1516727616.817 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-01-23T17:13:36.824Z,1516727616.824 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-01-23T17:13:36.829Z,1516727616.829 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-01-23T17:13:36.841Z,1516727616.841 [MassServo](DEBUG): Initializing EZServoServo.
2018-01-23T17:13:36.849Z,1516727616.849 [MassServo](DEBUG): Initializing MassServo.
2018-01-23T17:13:36.863Z,1516727616.863 [RudderServo](DEBUG): Initializing EZServoServo.
2018-01-23T17:13:36.869Z,1516727616.869 [RudderServo](DEBUG): Initializing RudderServo.
2018-01-23T17:13:36.875Z,1516727616.875 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-01-23T17:13:36.881Z,1516727616.881 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-01-23T17:13:37.051Z,1516727617.051 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:37.052Z,1516727617.052 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:37.384Z,1516727617.384 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:37.389Z,1516727617.389 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:37.737Z,1516727617.737 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-01-23T17:13:37.737Z,1516727617.737 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-01-23T17:13:37.737Z,1516727617.737 [BuoyancyServo] Communications Fault, FailCount= 1
2018-01-23T17:13:37.737Z,1516727617.737 [BuoyancyServo](ERROR): Communications Fault
2018-01-23T17:13:37.944Z,1516727617.944 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-01-23T17:13:38.021Z,1516727618.021 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:38.022Z,1516727618.022 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:38.028Z,1516727618.028 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-01-23T17:13:38.029Z,1516727618.029 [BuoyancyServo](INFO): Powering down
2018-01-23T17:13:38.412Z,1516727618.412 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:38.429Z,1516727618.429 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:38.804Z,1516727618.804 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:38.813Z,1516727618.813 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:39.208Z,1516727619.208 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:39.210Z,1516727619.210 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:39.713Z,1516727619.713 [Aanderaa_O2](INFO): Powering down
2018-01-23T17:13:39.763Z,1516727619.763 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:39.764Z,1516727619.764 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T17:13:40.066Z,1516727620.066 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-01-23T17:13:40.066Z,1516727620.066 [BuoyancyServo] No Fault, FailCount= 1
2018-01-23T17:13:40.432Z,1516727620.432 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-01-23T17:13:40.550Z,1516727620.550 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-01-23T17:13:59.272Z,1516727639.272 [SBIT](IMPORTANT): Beginning Startup BIT
2018-01-23T17:13:59.284Z,1516727639.284 [CBIT](IMPORTANT): Beginning ground fault scan
2018-01-23T17:14:04.575Z,1516727644.575 [NAL9602](INFO): Powering up NAL9602
2018-01-23T17:14:10.231Z,1516727650.231 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.012926
CHAN A1 (24V): 4.657929
CHAN A2 (12V): -0.002273
CHAN A3 (5V): -0.001235
CHAN B0 (3.3V): 0.000240
CHAN B1 (3.15aV): 0.000013
CHAN B2 (3.15bV): -0.000407
CHAN B3 (GND): 0.000268
OPEN: -0.000214
Full Scale Calc: 4.765 mA, -1.589 mA
2018-01-23T17:14:15.982Z,1516727655.982 [NAL9602](INFO): NAL9602 initialized
2018-01-23T17:14:37.585Z,1516727677.585 [NAL9602](INFO): SBD MO Status=2, MOMSN=3914, MT Status=2, MTMSN=0
2018-01-23T17:14:37.585Z,1516727677.585 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-01-23T17:14:42.492Z,1516727682.492 [NAL9602](INFO): SBD MO Status=2, MOMSN=3914, MT Status=2, MTMSN=0
2018-01-23T17:14:42.492Z,1516727682.492 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-01-23T17:14:53.339Z,1516727693.339 [SBIT](IMPORTANT): SBIT PASSED
2018-01-23T17:14:53.737Z,1516727693.737 [MissionManager](IMPORTANT): Started mission Startup
2018-01-23T17:14:53.737Z,1516727693.737 [Startup] Running Loop=1
2018-01-23T17:14:53.737Z,1516727693.737 [Startup](DEBUG): Aggregate::initialize Startup
2018-01-23T17:14:53.738Z,1516727693.738 [Startup:A.GoToSurface] Running Loop=1
2018-01-23T17:14:53.738Z,1516727693.738 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-01-23T17:14:53.738Z,1516727693.738 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-01-23T17:14:53.739Z,1516727693.739 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-01-23T17:14:53.739Z,1516727693.739 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-01-23T17:14:53.739Z,1516727693.739 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-01-23T17:14:53.740Z,1516727693.740 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-01-23T17:14:53.775Z,1516727693.775 [Startup:StartupSatComms] Running Loop=1
2018-01-23T17:14:53.775Z,1516727693.775 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-01-23T17:14:53.775Z,1516727693.775 [Startup:StartupSatComms:A] Running Loop=1
2018-01-23T17:14:54.143Z,1516727694.143 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-01-23T17:15:24.892Z,1516727724.892 [NAL9602](INFO): SBD MO Status=2, MOMSN=3914, MT Status=2, MTMSN=0
2018-01-23T17:15:24.892Z,1516727724.892 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-01-23T17:15:54.146Z,1516727754.146 [Startup:StartupSatComms:A](INFO): Timed out from 2018-01-23T17:14:53.8Z
2018-01-23T17:15:54.146Z,1516727754.146 [Startup:StartupSatComms:A] Stopped
2018-01-23T17:15:54.146Z,1516727754.146 [Startup:StartupSatComms:B] Running Loop=1
2018-01-23T17:15:54.542Z,1516727754.542 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-01-23T17:15:55.292Z,1516727755.292 [NAL9602](INFO): SBD MO Status=0, MOMSN=3914, MT Status=0, MTMSN=0
2018-01-23T17:15:55.292Z,1516727755.292 [NAL9602](INFO): No messages in MT queue
2018-01-23T17:15:56.495Z,1516727756.495 [NAL9602](INFO): GPS fix at 20180123T171550: (36.802703, -121.786957)
2018-01-23T17:16:06.179Z,1516727766.179 [NAL9602](INFO): SBD MO Status=1, MOMSN=3915, MT Status=0, MTMSN=0
2018-01-23T17:16:06.230Z,1516727766.230 [NAL9602](INFO): Sent 25 bytes from file Logs/20180123T165904/Courier0012.lzma
2018-01-23T17:16:06.230Z,1516727766.230 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:16:06.232Z,1516727766.232 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T165904/Courier0012.lzma.parts/0000.sbd
2018-01-23T17:16:06.232Z,1516727766.232 [NAL9602](DEBUG): Completed sending Logs/20180123T165904/Courier0012.lzma
2018-01-23T17:16:19.535Z,1516727779.535 [NAL9602](INFO): SBD MO Status=1, MOMSN=3916, MT Status=0, MTMSN=0
2018-01-23T17:16:19.589Z,1516727779.589 [NAL9602](INFO): Sent 248 bytes from file Logs/20180123T165904/Express0013.lzma
2018-01-23T17:16:19.589Z,1516727779.589 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:16:19.594Z,1516727779.594 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T165904/Express0013.lzma.parts/0000.sbd
2018-01-23T17:16:19.595Z,1516727779.595 [NAL9602](DEBUG): Completed sending Logs/20180123T165904/Express0013.lzma
2018-01-23T17:16:25.651Z,1516727785.651 [PNI_TCM](ERROR): CRC does not match. Expected:0x11209 got:0x16922
2018-01-23T17:16:27.655Z,1516727787.655 [PNI_TCM](ERROR): CRC does not match. Expected:0x52137 got:0x18713
2018-01-23T17:16:30.461Z,1516727790.461 [PNI_TCM](ERROR): CRC does not match. Expected:0x13764 got:0x10501
2018-01-23T17:16:35.228Z,1516727795.228 [NAL9602](INFO): SBD MO Status=1, MOMSN=3917, MT Status=0, MTMSN=0
2018-01-23T17:16:35.281Z,1516727795.281 [NAL9602](INFO): Sent 332 bytes from file Logs/20180123T171327/Express0001.lzma
2018-01-23T17:16:35.281Z,1516727795.281 [NAL9602](INFO): Packets left to send: 1
2018-01-23T17:16:35.283Z,1516727795.283 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Express0001.lzma.parts/0001.sbd
2018-01-23T17:16:35.308Z,1516727795.308 [PNI_TCM](ERROR): CRC does not match. Expected:0x56095 got:0x61065
2018-01-23T17:16:38.086Z,1516727798.086 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:16:38.086Z,1516727798.086 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T17:16:38.086Z,1516727798.086 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:16:38.098Z,1516727798.098 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:16:38.261Z,1516727798.261 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:16:38.261Z,1516727798.261 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T17:16:38.564Z,1516727798.564 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:16:38.569Z,1516727798.569 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:16:38.569Z,1516727798.569 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:16:47.308Z,1516727807.308 [NAL9602](INFO): SBD MO Status=1, MOMSN=3918, MT Status=0, MTMSN=0
2018-01-23T17:16:47.357Z,1516727807.357 [NAL9602](INFO): Sent 232 bytes from file Logs/20180123T171327/Express0001.lzma
2018-01-23T17:16:47.357Z,1516727807.357 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:16:47.359Z,1516727807.359 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Express0001.lzma.parts/0000.sbd
2018-01-23T17:16:47.359Z,1516727807.359 [NAL9602](DEBUG): Completed sending Logs/20180123T171327/Express0001.lzma
2018-01-23T17:16:54.156Z,1516727814.156 [Startup:StartupSatComms:B](INFO): Timed out from 2018-01-23T17:15:54.1Z
2018-01-23T17:16:54.156Z,1516727814.156 [Startup:StartupSatComms:B] Stopped
2018-01-23T17:16:54.156Z,1516727814.156 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-01-23T17:16:54.156Z,1516727814.156 [Startup:StartupSatComms] Stopped
2018-01-23T17:16:54.157Z,1516727814.157 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-01-23T17:16:54.157Z,1516727814.157 [Startup](INFO): Completed Startup
2018-01-23T17:16:54.158Z,1516727814.158 [MissionManager](INFO): Startup is completed.
2018-01-23T17:16:54.158Z,1516727814.158 [MissionManager](INFO): Uninitializing Mission Startup
2018-01-23T17:16:54.158Z,1516727814.158 [Startup] Stopped
2018-01-23T17:16:54.158Z,1516727814.158 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-01-23T17:16:54.158Z,1516727814.158 [Startup:A.GoToSurface] Stopped
2018-01-23T17:16:54.158Z,1516727814.158 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-01-23T17:16:54.570Z,1516727814.570 [MissionManager](IMPORTANT): Started mission Default
2018-01-23T17:16:54.570Z,1516727814.570 [Default] Running Loop=1
2018-01-23T17:16:54.571Z,1516727814.571 [Default](DEBUG): Aggregate::initialize Default
2018-01-23T17:16:54.571Z,1516727814.571 [Default:B.GoToSurface] Running Loop=1
2018-01-23T17:16:54.571Z,1516727814.571 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-01-23T17:16:54.571Z,1516727814.571 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-01-23T17:16:54.571Z,1516727814.571 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-01-23T17:16:54.572Z,1516727814.572 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-01-23T17:16:54.572Z,1516727814.572 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-01-23T17:16:54.572Z,1516727814.572 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-01-23T17:16:54.572Z,1516727814.572 [Default:A.Wait] Running Loop=1
2018-01-23T17:16:54.573Z,1516727814.573 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-01-23T17:16:58.113Z,1516727818.113 [NAL9602](INFO): SBD MO Status=0, MOMSN=3919, MT Status=0, MTMSN=0
2018-01-23T17:17:07.753Z,1516727827.753 [Default:A.Wait](INFO): Done Waiting.
2018-01-23T17:17:07.753Z,1516727827.753 [Default:A.Wait] Stopped
2018-01-23T17:17:07.753Z,1516727827.753 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T17:17:08.169Z,1516727828.169 [Default:CheckIn] Running Loop=1
2018-01-23T17:17:08.169Z,1516727828.169 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-01-23T17:17:08.169Z,1516727828.169 [Default:CheckIn:Read_GPS] Running Loop=1
2018-01-23T17:17:08.556Z,1516727828.556 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-01-23T17:17:10.110Z,1516727830.110 [NAL9602](INFO): GPS fix at 20180123T171703: (36.802901, -121.786539)
2018-01-23T17:17:10.187Z,1516727830.187 [Default:CheckIn:Read_GPS] Stopped
2018-01-23T17:17:10.187Z,1516727830.187 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-01-23T17:17:10.579Z,1516727830.579 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-01-23T17:17:35.815Z,1516727855.815 [NAL9602](INFO): SBD MO Status=1, MOMSN=3920, MT Status=0, MTMSN=0
2018-01-23T17:17:35.869Z,1516727855.869 [NAL9602](INFO): Sent 216 bytes from file Logs/20180123T171327/Courier0004.lzma
2018-01-23T17:17:35.869Z,1516727855.869 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:17:35.871Z,1516727855.871 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Courier0004.lzma.parts/0000.sbd
2018-01-23T17:17:35.871Z,1516727855.871 [NAL9602](DEBUG): Completed sending Logs/20180123T171327/Courier0004.lzma
2018-01-23T17:17:43.189Z,1516727863.189 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003780
2018-01-23T17:17:47.329Z,1516727867.329 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20180123T171327/Express0005.lzma
2018-01-23T17:17:48.114Z,1516727868.114 [DataOverHttps](INFO): Moved sent file to Logs/20180123T171327/Express0005.lzma.bak
2018-01-23T17:17:48.114Z,1516727868.114 [DataOverHttps](INFO): SBD MOMSN=7756100
2018-01-23T17:17:48.587Z,1516727868.587 [Default:CheckIn:Read_Iridium] Stopped
2018-01-23T17:17:48.587Z,1516727868.587 [Default:CheckIn:C.Wait] Running Loop=1
2018-01-23T17:17:48.587Z,1516727868.587 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-01-23T17:17:52.104Z,1516727872.104 [NAL9602](INFO): SBD MO Status=1, MOMSN=3921, MT Status=0, MTMSN=0
2018-01-23T17:17:52.153Z,1516727872.153 [NAL9602](INFO): Sent 233 bytes from file Logs/20180123T171327/Express0005.lzma
2018-01-23T17:17:52.153Z,1516727872.153 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:17:52.155Z,1516727872.155 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Express0005.lzma.parts/0000.sbd
2018-01-23T17:17:52.155Z,1516727872.155 [NAL9602](DEBUG): Completed sending Logs/20180123T171327/Express0005.lzma
2018-01-23T17:18:16.259Z,1516727896.259 [CommandLine](IMPORTANT): got command show stack
2018-01-23T17:18:16.259Z,1516727896.259 [CommandLine](IMPORTANT): Behavior Stack:

2018-01-23T17:18:16.259Z,1516727896.259 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2018-01-23T17:18:16.260Z,1516727896.260 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:C.Wait
2018-01-23T17:18:22.666Z,1516727902.666 [NAL9602](INFO): Powering down
2018-01-23T17:18:26.211Z,1516727906.211 [CommandLine](IMPORTANT): got command configSet list
2018-01-23T17:18:26.211Z,1516727906.211 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-01-23T17:18:26.212Z,1516727906.212 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-01-23T17:18:26.212Z,1516727906.212 [CommandLine](IMPORTANT): CBIT.gf24Offset=107 microampere;

2018-01-23T17:18:26.213Z,1516727906.213 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-01-23T17:18:32.297Z,1516727912.297 [CommandLine](IMPORTANT): got command ibit
2018-01-23T17:18:32.358Z,1516727912.358 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-01-23T17:18:32.359Z,1516727912.359 [IBIT](IMPORTANT): Beginning control surface checks.
2018-01-23T17:18:32.362Z,1516727912.362 [CBIT](IMPORTANT): Beginning ground fault scan
2018-01-23T17:18:32.671Z,1516727912.671 [NAL9602](INFO): Powering up
2018-01-23T17:18:43.126Z,1516727923.126 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.012581
CHAN A1 (24V): -0.016310
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.000686
CHAN B0 (3.3V): 0.000534
CHAN B1 (3.15aV): -0.000363
CHAN B2 (3.15bV): -0.000502
CHAN B3 (GND): 0.000099
OPEN: -0.000392
Full Scale Calc: 4.765 mA, -1.589 mA
2018-01-23T17:18:43.870Z,1516727923.870 [NAL9602](INFO): NAL9602 initialized
2018-01-23T17:18:59.711Z,1516727939.711 [NAL9602](INFO): SBD MO Status=0, MOMSN=3922, MT Status=0, MTMSN=0
2018-01-23T17:18:59.712Z,1516727939.712 [NAL9602](INFO): No messages in MT queue
2018-01-23T17:19:06.515Z,1516727946.515 [NAL9602](INFO): GPS fix at 20180123T171900: (36.804501, -121.785501)
2018-01-23T17:19:09.314Z,1516727949.314 [NAL9602](INFO): GPS fix at 20180123T171902: (36.804538, -121.785493)
2018-01-23T17:19:12.514Z,1516727952.514 [NAL9602](INFO): GPS fix at 20180123T171906: (36.804618, -121.785473)
2018-01-23T17:19:15.314Z,1516727955.314 [NAL9602](INFO): GPS fix at 20180123T171908: (36.804656, -121.785462)
2018-01-23T17:19:18.185Z,1516727958.185 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 2
Latitude: 36.804657 Longitude: -121.785461
2018-01-23T17:19:18.517Z,1516727958.517 [NAL9602](INFO): GPS fix at 20180123T171912: (36.804732, -121.785441)
2018-01-23T17:19:18.590Z,1516727958.590 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-01-23T17:19:18.992Z,1516727958.992 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-01-23T17:19:18.992Z,1516727958.992 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-01-23T17:19:18.993Z,1516727958.993 [IBIT](IMPORTANT): Pressure:9.408313 PSI
2018-01-23T17:19:18.993Z,1516727958.993 [IBIT](IMPORTANT): Humidity:15.114149 %
2018-01-23T17:19:19.367Z,1516727959.367 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-01-23T17:19:19.367Z,1516727959.367 [IBIT](IMPORTANT): buoyancyNeutral: 315.000000 cc
2018-01-23T17:19:19.368Z,1516727959.368 [IBIT](IMPORTANT): massDefault: -0.075000 cm
2018-01-23T17:19:19.368Z,1516727959.368 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2018-01-23T17:19:19.368Z,1516727959.368 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2018-01-23T17:19:19.368Z,1516727959.368 [IBIT](IMPORTANT): IBIT PASSED
2018-01-23T17:19:29.602Z,1516727969.602 [CommandLine](INFO): End of History
2018-01-23T17:19:29.608Z,1516727969.608 [CommandLine](INFO): End of History
2018-01-23T17:19:29.613Z,1516727969.613 [CommandLine](INFO): End of History
2018-01-23T17:19:29.643Z,1516727969.643 [CommandLine](INFO): End of History
2018-01-23T17:19:29.646Z,1516727969.646 [CommandLine](INFO): End of History
2018-01-23T17:19:29.648Z,1516727969.648 [CommandLine](INFO): End of History
2018-01-23T17:19:29.664Z,1516727969.664 [CommandLine](INFO): End of History
2018-01-23T17:19:29.677Z,1516727969.677 [CommandLine](INFO): End of History
2018-01-23T17:19:29.679Z,1516727969.679 [CommandLine](INFO): End of History
2018-01-23T17:19:29.680Z,1516727969.680 [CommandLine](INFO): End of History
2018-01-23T17:19:29.690Z,1516727969.690 [CommandLine](INFO): End of History
2018-01-23T17:19:29.691Z,1516727969.691 [CommandLine](INFO): End of History
2018-01-23T17:19:29.719Z,1516727969.719 [CommandLine](INFO): End of History
2018-01-23T17:19:38.952Z,1516727978.952 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:19:38.952Z,1516727978.952 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T17:19:38.952Z,1516727978.952 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:19:38.972Z,1516727978.972 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:19:39.388Z,1516727979.388 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:19:39.389Z,1516727979.389 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T17:19:39.755Z,1516727979.755 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:19:39.756Z,1516727979.756 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:19:39.756Z,1516727979.756 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:19:52.678Z,1516727992.678 [NAL9602](INFO): Powering down
2018-01-23T17:19:55.810Z,1516727995.810 [CommandLine](INFO): End of History
2018-01-23T17:19:55.813Z,1516727995.813 [CommandLine](INFO): End of History
2018-01-23T17:19:55.818Z,1516727995.818 [CommandLine](INFO): End of History
2018-01-23T17:19:55.819Z,1516727995.819 [CommandLine](INFO): End of History
2018-01-23T17:19:55.820Z,1516727995.820 [CommandLine](INFO): End of History
2018-01-23T17:19:55.822Z,1516727995.822 [CommandLine](INFO): End of History
2018-01-23T17:19:55.823Z,1516727995.823 [CommandLine](INFO): End of History
2018-01-23T17:19:55.835Z,1516727995.835 [CommandLine](INFO): End of History
2018-01-23T17:19:55.842Z,1516727995.842 [CommandLine](INFO): End of History
2018-01-23T17:19:55.847Z,1516727995.847 [CommandLine](INFO): End of History
2018-01-23T17:19:55.877Z,1516727995.877 [CommandLine](INFO): End of History
2018-01-23T17:19:55.878Z,1516727995.878 [CommandLine](INFO): End of History
2018-01-23T17:20:25.458Z,1516728025.458 [CommandLine](IMPORTANT): got command configSet list
2018-01-23T17:20:25.458Z,1516728025.458 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-01-23T17:20:25.459Z,1516728025.459 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-01-23T17:20:25.459Z,1516728025.459 [CommandLine](IMPORTANT): CBIT.gf24Offset=107 microampere;

2018-01-23T17:20:25.459Z,1516728025.459 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-01-23T17:21:23.723Z,1516728083.723 [CommandLine](IMPORTANT): got command ibit
2018-01-23T17:21:23.760Z,1516728083.760 [IBIT](IMPORTANT): Beginning Initiated BIT
2018-01-23T17:21:23.760Z,1516728083.760 [IBIT](IMPORTANT): Beginning control surface checks.
2018-01-23T17:21:23.780Z,1516728083.780 [CBIT](IMPORTANT): Beginning ground fault scan
2018-01-23T17:21:24.040Z,1516728084.040 [NAL9602](INFO): Powering up
2018-01-23T17:21:34.539Z,1516728094.539 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.012625
CHAN A1 (24V): 4.657929
CHAN A2 (12V): -0.002238
CHAN A3 (5V): -0.001292
CHAN B0 (3.3V): -0.000086
CHAN B1 (3.15aV): -0.000037
CHAN B2 (3.15bV): -0.000643
CHAN B3 (GND): -0.000035
OPEN: -0.000506
Full Scale Calc: 4.765 mA, -1.589 mA
2018-01-23T17:21:34.866Z,1516728094.866 [NAL9602](INFO): NAL9602 initialized
2018-01-23T17:21:57.767Z,1516728117.767 [NAL9602](INFO): SBD MO Status=0, MOMSN=3923, MT Status=0, MTMSN=0
2018-01-23T17:21:57.768Z,1516728117.768 [NAL9602](INFO): No messages in MT queue
2018-01-23T17:22:25.375Z,1516728145.375 [NAL9602](INFO): GPS fix at 20180123T172219: (36.808544, -121.785697)
2018-01-23T17:22:25.451Z,1516728145.451 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.808544 Longitude: -121.785698
2018-01-23T17:22:25.863Z,1516728145.863 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active.
2018-01-23T17:22:26.225Z,1516728146.225 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2018-01-23T17:22:26.226Z,1516728146.226 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2018-01-23T17:22:26.226Z,1516728146.226 [IBIT](IMPORTANT): Pressure:9.399097 PSI
2018-01-23T17:22:26.226Z,1516728146.226 [IBIT](IMPORTANT): Humidity:15.089732 %
2018-01-23T17:22:26.752Z,1516728146.751 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2018-01-23T17:22:26.752Z,1516728146.752 [IBIT](IMPORTANT): buoyancyNeutral: 315.000000 cc
2018-01-23T17:22:26.752Z,1516728146.752 [IBIT](IMPORTANT): massDefault: -0.075000 cm
2018-01-23T17:22:26.752Z,1516728146.752 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2018-01-23T17:22:26.769Z,1516728146.769 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2018-01-23T17:22:26.769Z,1516728146.769 [IBIT](IMPORTANT): IBIT PASSED
2018-01-23T17:22:39.816Z,1516728159.816 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:22:39.816Z,1516728159.816 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T17:22:39.816Z,1516728159.816 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:22:39.832Z,1516728159.832 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:22:40.226Z,1516728160.226 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:22:40.226Z,1516728160.226 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T17:22:40.617Z,1516728160.617 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:22:40.617Z,1516728160.617 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:22:40.618Z,1516728160.618 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:22:49.006Z,1516728169.006 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-01-23T17:22:49.007Z,1516728169.007 [Default:CheckIn:C.Wait] Stopped
2018-01-23T17:22:49.007Z,1516728169.007 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T17:22:49.007Z,1516728169.007 [Default:CheckIn:D] Running Loop=1
2018-01-23T17:22:49.424Z,1516728169.424 [Default:CheckIn:D] Stopped
2018-01-23T17:22:49.424Z,1516728169.424 [Default:CheckIn:E] Running Loop=1
2018-01-23T17:22:49.816Z,1516728169.816 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.914195 min 
2018-01-23T17:22:49.818Z,1516728169.818 [Default:CheckIn:E] Stopped
2018-01-23T17:22:49.818Z,1516728169.818 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-01-23T17:22:49.818Z,1516728169.818 [Default:CheckIn] Stopped
2018-01-23T17:22:49.818Z,1516728169.818 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-01-23T17:22:49.818Z,1516728169.818 [Default:CheckIn](INFO): Running loop #2
2018-01-23T17:22:49.819Z,1516728169.819 [Default:CheckIn] Running Loop=2
2018-01-23T17:22:49.819Z,1516728169.819 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-01-23T17:22:49.819Z,1516728169.819 [Default:CheckIn:Read_GPS] Running Loop=1
2018-01-23T17:22:54.238Z,1516728174.238 [NAL9602](INFO): GPS fix at 20180123T172247: (36.808653, -121.786866)
2018-01-23T17:22:54.307Z,1516728174.307 [Default:CheckIn:Read_GPS] Stopped
2018-01-23T17:22:54.307Z,1516728174.307 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-01-23T17:22:58.749Z,1516728178.749 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20180123T171327/Courier0008.lzma
2018-01-23T17:22:59.517Z,1516728179.517 [DataOverHttps](INFO): Moved sent file to Logs/20180123T171327/Courier0008.lzma.bak
2018-01-23T17:22:59.518Z,1516728179.518 [DataOverHttps](INFO): SBD MOMSN=7756130
2018-01-23T17:23:08.516Z,1516728188.516 [DataOverHttps](INFO): Sending 1189 bytes from file Logs/20180123T171327/Express0009.lzma
2018-01-23T17:23:09.289Z,1516728189.289 [DataOverHttps](INFO): Moved sent file to Logs/20180123T171327/Express0009.lzma.bak
2018-01-23T17:23:09.290Z,1516728189.290 [DataOverHttps](INFO): SBD MOMSN=7756133
2018-01-23T17:23:09.774Z,1516728189.774 [Default:CheckIn:Read_Iridium] Stopped
2018-01-23T17:23:09.774Z,1516728189.774 [Default:CheckIn:C.Wait] Running Loop=1
2018-01-23T17:23:09.774Z,1516728189.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-01-23T17:23:28.766Z,1516728208.766 [NAL9602](INFO): Powering down
2018-01-23T17:23:36.028Z,1516728216.028 [CBIT](DEBUG): EFC running - data check-sum false
2018-01-23T17:24:14.448Z,1516728254.448 [PNI_TCM](ERROR): CRC does not match. Expected:0x13764 got:0x10501
2018-01-23T17:24:48.045Z,1516728288.045 [PNI_TCM](ERROR): CRC does not match. Expected:0x48771 got:0x1287
2018-01-23T17:25:40.901Z,1516728340.901 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:25:40.901Z,1516728340.901 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T17:25:40.901Z,1516728340.901 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:25:40.914Z,1516728340.914 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:25:41.316Z,1516728341.316 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:25:41.316Z,1516728341.316 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T17:25:41.713Z,1516728341.713 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:25:41.713Z,1516728341.713 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:25:41.713Z,1516728341.713 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:27:14.889Z,1516728434.889 [DataOverHttps](IMPORTANT): SBD MTMSN=20180123T172709
2018-01-23T17:27:19.093Z,1516728439.093 [DataOverHttps](INFO): Received command:configset list
2018-01-23T17:27:19.181Z,1516728439.181 [CommandLine](IMPORTANT): got command configSet list
2018-01-23T17:27:19.181Z,1516728439.181 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-01-23T17:27:19.182Z,1516728439.182 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-01-23T17:27:19.182Z,1516728439.182 [CommandLine](IMPORTANT): CBIT.gf24Offset=107 microampere;

2018-01-23T17:27:19.182Z,1516728439.182 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;

2018-01-23T17:28:10.329Z,1516728490.329 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-01-23T17:28:10.329Z,1516728490.329 [Default:CheckIn:C.Wait] Stopped
2018-01-23T17:28:10.329Z,1516728490.329 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T17:28:10.329Z,1516728490.329 [Default:CheckIn:D] Running Loop=1
2018-01-23T17:28:10.740Z,1516728490.740 [Default:CheckIn:D] Stopped
2018-01-23T17:28:10.740Z,1516728490.740 [Default:CheckIn:E] Running Loop=1
2018-01-23T17:28:11.143Z,1516728491.143 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.269490 min 
2018-01-23T17:28:11.143Z,1516728491.143 [Default:CheckIn:E] Stopped
2018-01-23T17:28:11.143Z,1516728491.143 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-01-23T17:28:11.143Z,1516728491.143 [Default:CheckIn] Stopped
2018-01-23T17:28:11.143Z,1516728491.143 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-01-23T17:28:11.144Z,1516728491.144 [Default:CheckIn](INFO): Running loop #3
2018-01-23T17:28:11.144Z,1516728491.144 [Default:CheckIn] Running Loop=3
2018-01-23T17:28:11.144Z,1516728491.144 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-01-23T17:28:11.144Z,1516728491.144 [Default:CheckIn:Read_GPS] Running Loop=1
2018-01-23T17:28:11.894Z,1516728491.894 [NAL9602](INFO): Powering up
2018-01-23T17:28:22.950Z,1516728502.950 [NAL9602](INFO): NAL9602 initialized
2018-01-23T17:28:40.951Z,1516728520.951 [NAL9602](INFO): SBD MO Status=0, MOMSN=3924, MT Status=0, MTMSN=0
2018-01-23T17:28:40.952Z,1516728520.952 [NAL9602](INFO): No messages in MT queue
2018-01-23T17:28:41.817Z,1516728521.817 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:28:41.817Z,1516728521.817 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2018-01-23T17:28:41.817Z,1516728521.817 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:28:41.831Z,1516728521.831 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:28:42.232Z,1516728522.232 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:28:42.232Z,1516728522.232 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2018-01-23T17:28:42.622Z,1516728522.622 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:28:42.623Z,1516728522.623 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:28:42.623Z,1516728522.623 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:30:06.626Z,1516728606.626 [NAL9602](INFO): GPS fix at 20180123T173000: (36.800611, -121.840078)
2018-01-23T17:30:06.693Z,1516728606.693 [Default:CheckIn:Read_GPS] Stopped
2018-01-23T17:30:06.693Z,1516728606.693 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-01-23T17:30:11.176Z,1516728611.176 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180123T171327/Courier0012.lzma
2018-01-23T17:30:11.977Z,1516728611.977 [DataOverHttps](INFO): Moved sent file to Logs/20180123T171327/Courier0012.lzma.bak
2018-01-23T17:30:11.978Z,1516728611.978 [DataOverHttps](INFO): SBD MOMSN=7756199
2018-01-23T17:30:21.450Z,1516728621.450 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180123T171327/Courier0016.lzma
2018-01-23T17:30:22.241Z,1516728622.241 [DataOverHttps](INFO): Moved sent file to Logs/20180123T171327/Courier0016.lzma.bak
2018-01-23T17:30:22.241Z,1516728622.241 [DataOverHttps](INFO): SBD MOMSN=7756204
2018-01-23T17:30:31.538Z,1516728631.538 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20180123T171327/Express0013.lzma
2018-01-23T17:30:32.301Z,1516728632.301 [DataOverHttps](INFO): Moved sent file to Logs/20180123T171327/Express0013.lzma.bak
2018-01-23T17:30:32.302Z,1516728632.302 [DataOverHttps](INFO): SBD MOMSN=7756206
2018-01-23T17:30:41.241Z,1516728641.241 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180123T171327/Express0017.lzma
2018-01-23T17:30:41.262Z,1516728641.262 [NAL9602](INFO): Powering down
2018-01-23T17:30:42.031Z,1516728642.031 [DataOverHttps](INFO): Moved sent file to Logs/20180123T171327/Express0017.lzma.bak
2018-01-23T17:30:42.031Z,1516728642.031 [DataOverHttps](INFO): SBD MOMSN=7756215
2018-01-23T17:30:42.523Z,1516728642.523 [Default:CheckIn:Read_Iridium] Stopped
2018-01-23T17:30:42.523Z,1516728642.523 [Default:CheckIn:C.Wait] Running Loop=1
2018-01-23T17:30:42.523Z,1516728642.523 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-01-23T17:31:42.998Z,1516728702.998 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:31:42.998Z,1516728702.998 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T17:31:42.998Z,1516728702.998 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:31:43.053Z,1516728703.053 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:31:46.201Z,1516728706.201 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:31:46.201Z,1516728706.201 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T17:31:46.288Z,1516728706.288 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:31:46.290Z,1516728706.290 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:31:46.290Z,1516728706.290 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:32:47.073Z,1516728767.073 [DataOverHttps](IMPORTANT): SBD MTMSN=20180123T173241
2018-01-23T17:32:51.146Z,1516728771.146 [DataOverHttps](INFO): Received command:! echo i > /dev/loadB3
2018-01-23T17:32:51.201Z,1516728771.201 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB3
2018-01-23T17:33:36.390Z,1516728816.390 [CBIT](DEBUG): EFC running - data check-sum false
2018-01-23T17:34:46.454Z,1516728886.454 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:34:46.454Z,1516728886.454 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2018-01-23T17:34:46.454Z,1516728886.454 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:34:46.475Z,1516728886.475 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:34:46.857Z,1516728886.857 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:34:46.857Z,1516728886.857 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2018-01-23T17:34:47.247Z,1516728887.247 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:34:47.247Z,1516728887.247 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:34:47.247Z,1516728887.247 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:35:13.682Z,1516728913.682 [Radio_Surface](INFO): Powering down
2018-01-23T17:35:19.742Z,1516728919.742 [Radio_Surface](INFO): Powering up
2018-01-23T17:35:43.122Z,1516728943.122 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-01-23T17:35:43.122Z,1516728943.122 [Default:CheckIn:C.Wait] Stopped
2018-01-23T17:35:43.122Z,1516728943.122 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T17:35:43.122Z,1516728943.122 [Default:CheckIn:D] Running Loop=1
2018-01-23T17:35:43.531Z,1516728943.531 [Default:CheckIn:D] Stopped
2018-01-23T17:35:43.531Z,1516728943.531 [Default:CheckIn:E] Running Loop=1
2018-01-23T17:35:43.929Z,1516728943.929 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.816005 min 
2018-01-23T17:35:43.929Z,1516728943.929 [Default:CheckIn:E] Stopped
2018-01-23T17:35:43.930Z,1516728943.930 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-01-23T17:35:43.930Z,1516728943.930 [Default:CheckIn] Stopped
2018-01-23T17:35:43.930Z,1516728943.930 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-01-23T17:35:43.930Z,1516728943.930 [Default:CheckIn](INFO): Running loop #4
2018-01-23T17:35:43.930Z,1516728943.930 [Default:CheckIn] Running Loop=4
2018-01-23T17:35:43.930Z,1516728943.930 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-01-23T17:35:43.930Z,1516728943.930 [Default:CheckIn:Read_GPS] Running Loop=1
2018-01-23T17:35:44.678Z,1516728944.678 [NAL9602](INFO): Powering up
2018-01-23T17:35:55.478Z,1516728955.478 [NAL9602](INFO): NAL9602 initialized
2018-01-23T17:36:10.275Z,1516728970.275 [NAL9602](INFO): SBD MO Status=0, MOMSN=3925, MT Status=0, MTMSN=0
2018-01-23T17:36:10.275Z,1516728970.275 [NAL9602](INFO): No messages in MT queue
2018-01-23T17:36:18.272Z,1516728978.272 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:36:56.278Z,1516729016.278 [NAL9602](INFO): GPS fix at 20180123T173649: (36.800135, -121.860285)
2018-01-23T17:36:56.344Z,1516729016.344 [Default:CheckIn:Read_GPS] Stopped
2018-01-23T17:36:56.344Z,1516729016.344 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-01-23T17:37:18.272Z,1516729038.272 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:37:29.078Z,1516729049.078 [NAL9602](INFO): Powering down
2018-01-23T17:37:47.541Z,1516729067.541 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:37:47.541Z,1516729067.541 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T17:37:47.541Z,1516729067.541 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:37:47.559Z,1516729067.559 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:37:47.977Z,1516729067.977 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:37:47.977Z,1516729067.977 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T17:37:48.319Z,1516729068.319 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:37:48.320Z,1516729068.320 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:37:48.320Z,1516729068.320 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:37:48.672Z,1516729068.672 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:37:52.273Z,1516729072.273 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.107849
2018-01-23T17:37:52.282Z,1516729072.282 [NAL9602](INFO): Powering up
2018-01-23T17:38:03.474Z,1516729083.474 [NAL9602](INFO): NAL9602 initialized
2018-01-23T17:38:22.748Z,1516729102.748 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:38:30.351Z,1516729110.351 [NAL9602](INFO): SBD MO Status=1, MOMSN=3926, MT Status=0, MTMSN=0
2018-01-23T17:38:30.401Z,1516729110.401 [NAL9602](INFO): Sent 65 bytes from file Logs/20180123T171327/Courier0020.lzma
2018-01-23T17:38:30.401Z,1516729110.401 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:38:30.403Z,1516729110.403 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Courier0020.lzma.parts/0000.sbd
2018-01-23T17:38:30.403Z,1516729110.403 [NAL9602](DEBUG): Completed sending Logs/20180123T171327/Courier0020.lzma
2018-01-23T17:38:43.643Z,1516729123.643 [NAL9602](INFO): SBD MO Status=1, MOMSN=3927, MT Status=0, MTMSN=0
2018-01-23T17:38:43.693Z,1516729123.693 [NAL9602](INFO): Sent 25 bytes from file Logs/20180123T171327/Courier0024.lzma
2018-01-23T17:38:43.693Z,1516729123.693 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:38:43.695Z,1516729123.695 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Courier0024.lzma.parts/0000.sbd
2018-01-23T17:38:43.695Z,1516729123.695 [NAL9602](DEBUG): Completed sending Logs/20180123T171327/Courier0024.lzma
2018-01-23T17:38:57.368Z,1516729137.368 [NAL9602](INFO): SBD MO Status=1, MOMSN=3928, MT Status=0, MTMSN=0
2018-01-23T17:38:57.417Z,1516729137.417 [NAL9602](INFO): Sent 217 bytes from file Logs/20180123T171327/Express0021.lzma
2018-01-23T17:38:57.417Z,1516729137.417 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:38:57.418Z,1516729137.418 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Express0021.lzma.parts/0000.sbd
2018-01-23T17:38:57.419Z,1516729137.419 [NAL9602](DEBUG): Completed sending Logs/20180123T171327/Express0021.lzma
2018-01-23T17:39:13.859Z,1516729153.859 [NAL9602](INFO): SBD MO Status=2, MOMSN=3929, MT Status=2, MTMSN=0
2018-01-23T17:39:13.860Z,1516729153.860 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-01-23T17:39:23.136Z,1516729163.136 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:39:30.351Z,1516729170.351 [NAL9602](INFO): SBD MO Status=1, MOMSN=3929, MT Status=0, MTMSN=0
2018-01-23T17:39:30.413Z,1516729170.413 [NAL9602](INFO): Sent 25 bytes from file Logs/20180123T171327/Express0025.lzma
2018-01-23T17:39:30.413Z,1516729170.413 [NAL9602](INFO): Packets left to send: 0
2018-01-23T17:39:30.415Z,1516729170.415 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180123T171327/Express0025.lzma.parts/0000.sbd
2018-01-23T17:39:30.416Z,1516729170.416 [NAL9602](DEBUG): Completed sending Logs/20180123T171327/Express0025.lzma
2018-01-23T17:39:54.339Z,1516729194.339 [NAL9602](INFO): SBD MO Status=0, MOMSN=3930, MT Status=0, MTMSN=0
2018-01-23T17:39:54.440Z,1516729194.440 [Default:CheckIn:Read_Iridium] Stopped
2018-01-23T17:39:54.440Z,1516729194.440 [Default:CheckIn:C.Wait] Running Loop=1
2018-01-23T17:39:54.440Z,1516729194.440 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-01-23T17:40:23.136Z,1516729223.136 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:40:25.142Z,1516729225.142 [NAL9602](INFO): Powering down
2018-01-23T17:40:48.378Z,1516729248.378 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:40:48.378Z,1516729248.378 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2018-01-23T17:40:48.379Z,1516729248.379 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:40:48.392Z,1516729248.392 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:40:48.809Z,1516729248.809 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:40:48.810Z,1516729248.810 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2018-01-23T17:40:49.185Z,1516729249.185 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:40:49.185Z,1516729249.185 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:40:49.185Z,1516729249.185 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:41:23.539Z,1516729283.539 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:42:00.799Z,1516729320.799 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002380
2018-01-23T17:42:04.022Z,1516729324.022 [PNI_TCM](ERROR): CRC does not match. Expected:0x16853 got:0x41088
2018-01-23T17:43:36.679Z,1516729416.679 [CBIT](DEBUG): EFC running - data check-sum false
2018-01-23T17:43:49.480Z,1516729429.480 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T17:43:49.480Z,1516729429.480 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 3
2018-01-23T17:43:49.480Z,1516729429.480 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T17:43:49.493Z,1516729429.493 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T17:43:49.868Z,1516729429.868 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T17:43:49.868Z,1516729429.868 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 3
2018-01-23T17:43:50.265Z,1516729430.265 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T17:43:50.266Z,1516729430.266 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T17:43:50.266Z,1516729430.266 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T17:44:24.212Z,1516729464.212 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2018-01-23T17:44:55.079Z,1516729495.079 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-01-23T17:44:55.079Z,1516729495.079 [Default:CheckIn:C.Wait] Stopped
2018-01-23T17:44:55.079Z,1516729495.079 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T17:44:55.079Z,1516729495.079 [Default:CheckIn:D] Running Loop=1
2018-01-23T17:44:55.482Z,1516729495.482 [Default:CheckIn:D] Stopped
2018-01-23T17:44:55.482Z,1516729495.482 [Default:CheckIn:E] Running Loop=1
2018-01-23T17:44:55.886Z,1516729495.886 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.015194 min 
2018-01-23T17:44:55.886Z,1516729495.886 [Default:CheckIn:E] Stopped
2018-01-23T17:44:55.886Z,1516729495.886 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-01-23T17:44:55.886Z,1516729495.886 [Default:CheckIn] Stopped
2018-01-23T17:44:55.887Z,1516729495.887 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-01-23T17:44:55.887Z,1516729495.887 [Default:CheckIn](INFO): Running loop #5
2018-01-23T17:44:55.887Z,1516729495.887 [Default:CheckIn] Running Loop=5
2018-01-23T17:44:55.887Z,1516729495.887 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-01-23T17:44:55.887Z,1516729495.887 [Default:CheckIn:Read_GPS] Running Loop=1
2018-01-23T17:44:56.614Z,1516729496.614 [NAL9602](INFO): Powering up
2018-01-23T17:45:07.490Z,1516729507.490 [NAL9602](INFO): NAL9602 initialized
2018-01-23T17:45:22.688Z,1516729522.688 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=3931, MT Status=1, MTMSN=1256
2018-01-23T17:45:22.688Z,1516729522.688 [NAL9602](INFO): Data available in MT queue
2018-01-23T17:45:23.169Z,1516729523.169 [NAL9602](INFO): Received command:restart app
2018-01-23T17:45:23.202Z,1516729523.202 [CommandLine](IMPORTANT): got command restart application
2018-01-23T17:45:24.205Z,1516729524.205 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-01-23T17:45:24.205Z,1516729524.205 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:24.206Z,1516729524.206 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.253Z,1516729524.253 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-01-23T17:45:24.253Z,1516729524.253 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.254Z,1516729524.254 [CommandLine](INFO): Join timeout helper Thread ID is 1174
2018-01-23T17:45:24.254Z,1516729524.254 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-01-23T17:45:24.254Z,1516729524.254 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.254Z,1516729524.254 [NavChartDb](INFO): Join timeout helper Thread ID is 1175
2018-01-23T17:45:24.629Z,1516729524.629 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:24.629Z,1516729524.629 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.633Z,1516729524.633 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-01-23T17:45:24.633Z,1516729524.633 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.633Z,1516729524.633 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 1176
2018-01-23T17:45:24.637Z,1516729524.637 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:24.637Z,1516729524.637 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.653Z,1516729524.653 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-01-23T17:45:24.653Z,1516729524.653 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.653Z,1516729524.653 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1177
2018-01-23T17:45:24.889Z,1516729524.889 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:24.889Z,1516729524.889 [WetLabsBB2FL](INFO): Powering down
2018-01-23T17:45:24.890Z,1516729524.890 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.897Z,1516729524.897 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-01-23T17:45:24.897Z,1516729524.897 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:24.897Z,1516729524.897 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1178
2018-01-23T17:45:24.933Z,1516729524.933 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:25.015Z,1516729525.015 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-01-23T17:45:25.015Z,1516729525.015 [CTD_Seabird](INFO): Powering down
2018-01-23T17:45:25.016Z,1516729525.016 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.026Z,1516729525.026 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-01-23T17:45:25.026Z,1516729525.026 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.027Z,1516729525.027 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1180
2018-01-23T17:45:25.329Z,1516729525.329 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:25.329Z,1516729525.329 [CTD_NeilBrown](INFO): Powering down
2018-01-23T17:45:25.330Z,1516729525.330 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.350Z,1516729525.350 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-01-23T17:45:25.350Z,1516729525.350 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.350Z,1516729525.350 [Radio_Surface](INFO): Join timeout helper Thread ID is 1181
2018-01-23T17:45:25.705Z,1516729525.705 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:25.705Z,1516729525.705 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.718Z,1516729525.718 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-01-23T17:45:25.718Z,1516729525.718 [logger ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.719Z,1516729525.719 [logger](INFO): Join timeout helper Thread ID is 1182
2018-01-23T17:45:25.719Z,1516729525.719 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:25.719Z,1516729525.719 [logger ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.720Z,1516729525.720 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-01-23T17:45:25.720Z,1516729525.720 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.721Z,1516729525.721 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-01-23T17:45:25.721Z,1516729525.721 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:25.721Z,1516729525.721 [controlThread](INFO): Join timeout helper Thread ID is 1183
2018-01-23T17:45:25.881Z,1516729525.881 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T17:45:25.881Z,1516729525.881 [controlThread](DEBUG): Uninitializing ControlThread
2018-01-23T17:45:25.882Z,1516729525.882 [NAL9602](INFO): Powering down
2018-01-23T17:45:25.883Z,1516729525.883 [PNI_TCM](INFO): Powering down
2018-01-23T17:45:25.969Z,1516729525.969 [Aanderaa_O2](INFO): Powering down
2018-01-23T17:45:25.971Z,1516729525.971 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-01-23T17:45:25.973Z,1516729525.973 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-01-23T17:45:25.974Z,1516729525.974 [MissionManager](INFO): Uninitializing Mission Default
2018-01-23T17:45:25.974Z,1516729525.974 [Default] Stopped
2018-01-23T17:45:25.974Z,1516729525.974 [Default](DEBUG): Aggregate::uninitialize Default
2018-01-23T17:45:25.974Z,1516729525.974 [Default:B.GoToSurface] Stopped
2018-01-23T17:45:25.974Z,1516729525.974 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-01-23T17:45:25.974Z,1516729525.974 [Default:CheckIn] Stopped
2018-01-23T17:45:25.974Z,1516729525.974 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-01-23T17:45:25.974Z,1516729525.974 [Default:CheckIn:Read_GPS] Stopped
2018-01-23T17:45:25.977Z,1516729525.977 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-01-23T17:45:25.978Z,1516729525.978 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-01-23T17:45:25.978Z,1516729525.978 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-01-23T17:45:25.978Z,1516729525.978 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-01-23T17:45:25.978Z,1516729525.978 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-01-23T17:45:25.979Z,1516729525.979 [BuoyancyServo](INFO): Powering down
2018-01-23T17:45:25.993Z,1516729525.993 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-01-23T17:45:25.993Z,1516729525.993 [ElevatorServo](INFO): Powering down
2018-01-23T17:45:25.994Z,1516729525.994 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-01-23T17:45:25.994Z,1516729525.994 [MassServo](INFO): Powering down
2018-01-23T17:45:25.995Z,1516729525.995 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-01-23T17:45:25.995Z,1516729525.995 [RudderServo](INFO): Powering down
2018-01-23T17:45:25.995Z,1516729525.995 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-01-23T17:45:25.996Z,1516729525.996 [ThrusterServo](INFO): Powering down
2018-01-23T17:45:25.996Z,1516729525.996 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-01-23T17:45:25.997Z,1516729525.997 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-01-23T17:45:25.997Z,1516729525.997 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-01-23T17:45:25.998Z,1516729525.998 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:26.039Z,1516729526.039 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:26.075Z,1516729526.075 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:26.077Z,1516729526.077 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:26.080Z,1516729526.080 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:26.082Z,1516729526.082 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:26.109Z,1516729526.109 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T17:45:26.175Z,1516729526.175 [logger ThreadHandler](INFO): Thread cancelled.