2017-04-26T16:42:18.827Z,1493224938.828 [Supervisor](DEBUG): Initializing supervisor.
2017-04-26T16:42:18.831Z,1493224938.831 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0
2017-04-26T16:42:18.831Z,1493224938.831 [SyncHandler](INFO): Protected caller Thread ID is 769
2017-04-26T16:42:18.832Z,1493224938.832 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2017-04-26T16:42:18.834Z,1493224938.834 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0
2017-04-26T16:42:18.835Z,1493224938.835 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 770
2017-04-26T16:42:18.837Z,1493224938.837 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2017-04-26T16:42:18.850Z,1493224938.850 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2017-04-26T16:42:18.854Z,1493224938.854 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0
2017-04-26T16:42:18.855Z,1493224938.855 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 771
2017-04-26T16:42:18.855Z,1493224938.855 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2017-04-26T16:42:18.858Z,1493224938.858 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0
2017-04-26T16:42:18.859Z,1493224938.859 [logger ThreadHandler](INFO): Protected caller Thread ID is 772
2017-04-26T16:42:18.861Z,1493224938.861 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2017-04-26T16:42:18.861Z,1493224938.861 [Supervisor](INFO): Looking for Config files in directory: Config/
2017-04-26T16:42:18.865Z,1493224938.865 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2017-04-26T16:42:18.963Z,1493224938.963 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2017-04-26T16:42:19.327Z,1493224939.327 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2017-04-26T16:42:19.328Z,1493224939.328 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2017-04-26T16:42:19.479Z,1493224939.479 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2017-04-26T16:42:19.479Z,1493224939.480 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2017-04-26T16:42:19.703Z,1493224939.703 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2017-04-26T16:42:19.704Z,1493224939.704 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2017-04-26T16:42:19.819Z,1493224939.819 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2017-04-26T16:42:19.820Z,1493224939.820 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2017-04-26T16:42:20.039Z,1493224940.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2017-04-26T16:42:20.041Z,1493224940.041 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2017-04-26T16:42:20.563Z,1493224940.563 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2017-04-26T16:42:20.564Z,1493224940.564 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2017-04-26T16:42:20.886Z,1493224940.886 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2017-04-26T16:42:20.887Z,1493224940.887 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2017-04-26T16:42:20.998Z,1493224940.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2017-04-26T16:42:20.998Z,1493224940.998 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2017-04-26T16:42:25.575Z,1493224945.575 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2017-04-26T16:42:25.576Z,1493224945.576 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2017-04-26T16:42:25.799Z,1493224945.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2017-04-26T16:42:25.800Z,1493224945.800 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2017-04-26T16:42:26.287Z,1493224946.287 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2017-04-26T16:42:26.287Z,1493224946.287 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2017-04-26T16:42:26.715Z,1493224946.716 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2017-04-26T16:42:26.716Z,1493224946.716 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2017-04-26T16:42:27.059Z,1493224947.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2017-04-26T16:42:27.060Z,1493224947.060 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2017-04-26T16:42:27.181Z,1493224947.181 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2017-04-26T16:42:27.184Z,1493224947.184 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2017-04-26T16:42:27.188Z,1493224947.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2017-04-26T16:42:27.307Z,1493224947.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2017-04-26T16:42:27.411Z,1493224947.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2017-04-26T16:42:27.510Z,1493224947.510 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2017-04-26T16:42:27.623Z,1493224947.623 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2017-04-26T16:42:27.725Z,1493224947.724 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2017-04-26T16:42:27.870Z,1493224947.870 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2017-04-26T16:42:27.975Z,1493224947.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2017-04-26T16:42:28.171Z,1493224948.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2017-04-26T16:42:28.435Z,1493224948.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2017-04-26T16:42:28.436Z,1493224948.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2017-04-26T16:42:28.611Z,1493224948.611 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2017-04-26T16:42:28.723Z,1493224948.723 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2017-04-26T16:42:28.814Z,1493224948.814 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2017-04-26T16:42:28.817Z,1493224948.817 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2017-04-26T16:42:28.896Z,1493224948.897 [VerticalControl](DEBUG): Construct VerticalControl.
2017-04-26T16:42:29.029Z,1493224949.029 [VerticalControl] Loaded
2017-04-26T16:42:29.030Z,1493224949.030 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2017-04-26T16:42:29.030Z,1493224949.030 [HorizontalControl](DEBUG): Construct HorizontalControl.
2017-04-26T16:42:29.110Z,1493224949.110 [HorizontalControl] Loaded
2017-04-26T16:42:29.110Z,1493224949.110 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2017-04-26T16:42:29.111Z,1493224949.111 [SpeedControl](DEBUG): Construct SpeedControl.
2017-04-26T16:42:29.117Z,1493224949.117 [SpeedControl] Loaded
2017-04-26T16:42:29.117Z,1493224949.117 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2017-04-26T16:42:29.118Z,1493224949.118 [LoopControl](DEBUG): Construct LoopControl.
2017-04-26T16:42:29.122Z,1493224949.122 [LoopControl] Loaded
2017-04-26T16:42:29.123Z,1493224949.123 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2017-04-26T16:42:29.123Z,1493224949.123 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2017-04-26T16:42:29.124Z,1493224949.124 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2017-04-26T16:42:29.305Z,1493224949.305 [SBIT](DEBUG): Construct Startup Built In Test.
2017-04-26T16:42:29.321Z,1493224949.321 [SBIT] Loaded
2017-04-26T16:42:29.321Z,1493224949.321 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2017-04-26T16:42:29.322Z,1493224949.322 [IBIT](DEBUG): Construct Initiated Built In Test.
2017-04-26T16:42:29.355Z,1493224949.355 [IBIT] Loaded
2017-04-26T16:42:29.355Z,1493224949.355 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2017-04-26T16:42:29.359Z,1493224949.359 [CBIT](DEBUG): Construct Continuous Built In Test.
2017-04-26T16:42:29.523Z,1493224949.523 [CBIT] Loaded
2017-04-26T16:42:29.523Z,1493224949.523 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2017-04-26T16:42:29.524Z,1493224949.524 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2017-04-26T16:42:29.526Z,1493224949.526 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2017-04-26T16:42:29.573Z,1493224949.573 [DepthRateCalculator] Loaded
2017-04-26T16:42:29.573Z,1493224949.573 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2017-04-26T16:42:29.579Z,1493224949.579 [PitchRateCalculator] Loaded
2017-04-26T16:42:29.579Z,1493224949.579 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2017-04-26T16:42:29.595Z,1493224949.595 [SpeedCalculator] Loaded
2017-04-26T16:42:29.595Z,1493224949.595 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2017-04-26T16:42:29.618Z,1493224949.618 [TempGradientCalculator] Loaded
2017-04-26T16:42:29.618Z,1493224949.618 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2017-04-26T16:42:29.638Z,1493224949.638 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2017-04-26T16:42:29.638Z,1493224949.638 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2017-04-26T16:42:29.644Z,1493224949.644 [YawRateCalculator] Loaded
2017-04-26T16:42:29.644Z,1493224949.644 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2017-04-26T16:42:29.645Z,1493224949.645 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2017-04-26T16:42:29.645Z,1493224949.645 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2017-04-26T16:42:29.783Z,1493224949.783 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2017-04-26T16:42:29.783Z,1493224949.783 [StratificationFrontDetector](DEBUG): (re)initializing
2017-04-26T16:42:29.783Z,1493224949.783 [StratificationFrontDetector] Loaded
2017-04-26T16:42:29.783Z,1493224949.783 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2017-04-26T16:42:29.807Z,1493224949.807 [DepAvgTempFrontDetector] Loaded
2017-04-26T16:42:29.808Z,1493224949.808 [ComponentRegistry](DEBUG): SyncComponent "DepAvgTempFrontDetector" handled in the control thread.
2017-04-26T16:42:29.808Z,1493224949.808 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2017-04-26T16:42:29.809Z,1493224949.809 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2017-04-26T16:42:30.135Z,1493224950.135 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2017-04-26T16:42:30.136Z,1493224950.136 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2017-04-26T16:42:30.284Z,1493224950.284 [DeadReckonUsingMultipleVelocitySources] Loaded
2017-04-26T16:42:30.285Z,1493224950.285 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2017-04-26T16:42:30.345Z,1493224950.345 [DeadReckonUsingSpeedCalculator] Loaded
2017-04-26T16:42:30.345Z,1493224950.345 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2017-04-26T16:42:30.367Z,1493224950.367 [NavChart] Loaded
2017-04-26T16:42:30.367Z,1493224950.367 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2017-04-26T16:42:30.372Z,1493224950.372 [UniversalFixResidualReporter] Loaded
2017-04-26T16:42:30.372Z,1493224950.372 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2017-04-26T16:42:30.372Z,1493224950.372 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2017-04-26T16:42:30.373Z,1493224950.373 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2017-04-26T16:42:30.383Z,1493224950.383 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2017-04-26T16:42:30.383Z,1493224950.383 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2017-04-26T16:42:30.598Z,1493224950.598 [Aanderaa_O2] Loaded
2017-04-26T16:42:30.598Z,1493224950.598 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2017-04-26T16:42:30.689Z,1493224950.689 [CTD_NeilBrown] Loaded
2017-04-26T16:42:30.689Z,1493224950.689 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2017-04-26T16:42:30.698Z,1493224950.698 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407734E0
2017-04-26T16:42:30.699Z,1493224950.699 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 854
2017-04-26T16:42:31.082Z,1493224951.082 [CTD_Seabird] Loaded
2017-04-26T16:42:31.082Z,1493224951.082 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2017-04-26T16:42:31.086Z,1493224951.086 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 407A34E0
2017-04-26T16:42:31.087Z,1493224951.087 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 855
2017-04-26T16:42:31.102Z,1493224951.102 [PAR_Licor] Loaded
2017-04-26T16:42:31.102Z,1493224951.102 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2017-04-26T16:42:31.162Z,1493224951.162 [WetLabsBB2FL] Loaded
2017-04-26T16:42:31.162Z,1493224951.162 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2017-04-26T16:42:31.166Z,1493224951.166 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407D34E0
2017-04-26T16:42:31.167Z,1493224951.167 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 856
2017-04-26T16:42:31.167Z,1493224951.167 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2017-04-26T16:42:31.168Z,1493224951.168 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2017-04-26T16:42:31.871Z,1493224951.871 [DataOverHttps] Loaded
2017-04-26T16:42:31.871Z,1493224951.871 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2017-04-26T16:42:31.885Z,1493224951.885 [Depth_Keller] Loaded
2017-04-26T16:42:31.886Z,1493224951.886 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2017-04-26T16:42:31.895Z,1493224951.895 [DropWeight] Loaded
2017-04-26T16:42:31.895Z,1493224951.895 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2017-04-26T16:42:31.998Z,1493224951.998 [NAL9602] Loaded
2017-04-26T16:42:31.999Z,1493224951.999 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2017-04-26T16:42:32.008Z,1493224952.008 [Onboard] Loaded
2017-04-26T16:42:32.008Z,1493224952.008 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2017-04-26T16:42:32.015Z,1493224952.016 [Radio_Surface] Loaded
2017-04-26T16:42:32.016Z,1493224952.016 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2017-04-26T16:42:32.018Z,1493224952.018 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1E4E0
2017-04-26T16:42:32.019Z,1493224952.019 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 857
2017-04-26T16:42:32.239Z,1493224952.239 [PNI_TCM] Loaded
2017-04-26T16:42:32.240Z,1493224952.240 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2017-04-26T16:42:32.313Z,1493224952.313 [Rowe_600LCM] Loaded
2017-04-26T16:42:32.313Z,1493224952.313 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2017-04-26T16:42:32.314Z,1493224952.314 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A4E4E0
2017-04-26T16:42:32.315Z,1493224952.315 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 858
2017-04-26T16:42:34.473Z,1493224954.473 [BPC1] Loaded
2017-04-26T16:42:34.474Z,1493224954.474 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2017-04-26T16:42:34.474Z,1493224954.474 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2017-04-26T16:42:34.475Z,1493224954.475 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2017-04-26T16:42:37.704Z,1493224957.704 [BuoyancyServo] Loaded
2017-04-26T16:42:37.704Z,1493224957.704 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2017-04-26T16:42:37.717Z,1493224957.717 [ElevatorServo] Loaded
2017-04-26T16:42:37.717Z,1493224957.717 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2017-04-26T16:42:37.733Z,1493224957.733 [MassServo] Loaded
2017-04-26T16:42:37.733Z,1493224957.733 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2017-04-26T16:42:37.745Z,1493224957.745 [RudderServo] Loaded
2017-04-26T16:42:37.746Z,1493224957.746 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2017-04-26T16:42:37.757Z,1493224957.757 [ThrusterServo] Loaded
2017-04-26T16:42:37.757Z,1493224957.757 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2017-04-26T16:42:37.758Z,1493224957.758 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2017-04-26T16:42:37.758Z,1493224957.759 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2017-04-26T16:42:37.911Z,1493224957.911 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2017-04-26T16:42:37.912Z,1493224957.912 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2017-04-26T16:42:37.957Z,1493224957.957 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2017-04-26T16:42:37.961Z,1493224957.961 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2017-04-26T16:42:37.962Z,1493224957.962 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2017-04-26T16:42:37.969Z,1493224957.969 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2017-04-26T16:42:37.970Z,1493224957.970 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFC4E0
2017-04-26T16:42:37.971Z,1493224957.971 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 860
2017-04-26T16:42:37.975Z,1493224957.975 [Supervisor](INFO): Main Thread ID is 764
2017-04-26T16:42:37.975Z,1493224957.976 [Supervisor](DEBUG): Running supervisor.
2017-04-26T16:42:37.976Z,1493224957.976 [CommandLine ThreadHandler](INFO): Handler Thread ID is 861
2017-04-26T16:42:37.983Z,1493224957.983 [controlThread ThreadHandler](INFO): Handler Thread ID is 862
2017-04-26T16:42:37.983Z,1493224957.983 [controlThread](DEBUG): Initializing ControlThread
2017-04-26T16:42:37.984Z,1493224957.984 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2017-04-26T16:42:37.986Z,1493224957.986 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2017-04-26T16:42:37.987Z,1493224957.987 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2017-04-26T16:42:37.987Z,1493224957.987 [LoopControl](DEBUG): Initialize LoopControlComponent.
2017-04-26T16:42:37.988Z,1493224957.988 [SBIT](INFO): Initialize SBIT Component.
2017-04-26T16:42:37.988Z,1493224957.988 [SBIT](IMPORTANT): git: 2017-04-19-5-g443ab08
2017-04-26T16:42:37.988Z,1493224957.988 [SBIT](INFO): git hash: 443ab0852958b11c27b2467e632b948d2f0b0b23
2017-04-26T16:42:37.990Z,1493224957.990 [SBIT](INFO): Kernel Reporting Different Release From Configuration.
Kernel Expected: 2.6.27.8
Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty
2017-04-26T16:42:37.990Z,1493224957.990 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016
2017-04-26T16:42:37.992Z,1493224957.991 [SBIT](INFO): Beginning SBIT in 32.000000 seconds.
2017-04-26T16:42:37.992Z,1493224957.992 [IBIT](INFO): Initialize IBIT Component.
2017-04-26T16:42:37.993Z,1493224957.993 [CBIT](DEBUG): Initialize CBIT Component.
2017-04-26T16:42:37.993Z,1493224957.993 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2017-04-26T16:42:37.993Z,1493224957.993 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2017-04-26T16:42:37.995Z,1493224957.995 [logger ThreadHandler](INFO): Handler Thread ID is 863
2017-04-26T16:42:38.039Z,1493224958.039 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 864
2017-04-26T16:42:38.040Z,1493224958.040 [CTD_NeilBrown](INFO): Powering down
2017-04-26T16:42:38.075Z,1493224958.075 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-04-26T16:42:38.075Z,1493224958.075 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2017-04-26T16:42:38.075Z,1493224958.075 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2017-04-26T16:42:38.075Z,1493224958.075 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2017-04-26T16:42:38.076Z,1493224958.076 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2017-04-26T16:42:38.077Z,1493224958.077 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2017-04-26T16:42:38.077Z,1493224958.077 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-26T16:42:38.078Z,1493224958.078 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:42:38.079Z,1493224958.079 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:42:38.079Z,1493224958.079 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-04-26T16:42:38.080Z,1493224958.080 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:42:38.080Z,1493224958.080 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:42:38.081Z,1493224958.081 [NavChart](DEBUG): Initialize NavChart Navigation.
2017-04-26T16:42:38.081Z,1493224958.081 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2017-04-26T16:42:38.091Z,1493224958.091 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 865
2017-04-26T16:42:38.091Z,1493224958.091 [CTD_Seabird](INFO): Initializing
2017-04-26T16:42:38.103Z,1493224958.103 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2017-04-26T16:42:38.132Z,1493224958.132 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 867
2017-04-26T16:42:38.134Z,1493224958.134 [WetLabsBB2FL](INFO): Powering down
2017-04-26T16:42:38.167Z,1493224958.167 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 868
2017-04-26T16:42:38.174Z,1493224958.174 [Radio_Surface](INFO): Powering up
2017-04-26T16:42:38.184Z,1493224958.184 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2017-04-26T16:42:38.211Z,1493224958.211 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 869
2017-04-26T16:42:38.219Z,1493224958.219 [Rowe_600LCM](INFO): Initializing
2017-04-26T16:42:38.220Z,1493224958.220 [Rowe_600LCM](INFO): Checking LCM
2017-04-26T16:42:38.220Z,1493224958.220 [Rowe_600LCM](INFO): LCM OK
2017-04-26T16:42:38.220Z,1493224958.220 [Rowe_600LCM](INFO): Powering up
2017-04-26T16:42:38.221Z,1493224958.221 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 870
2017-04-26T16:42:38.231Z,1493224958.231 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2017-04-26T16:42:38.231Z,1493224958.231 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2017-04-26T16:42:38.231Z,1493224958.231 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2017-04-26T16:42:38.231Z,1493224958.231 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2017-04-26T16:42:38.232Z,1493224958.232 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2017-04-26T16:42:38.232Z,1493224958.232 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2017-04-26T16:42:38.232Z,1493224958.232 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2017-04-26T16:42:38.232Z,1493224958.232 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2017-04-26T16:42:38.232Z,1493224958.232 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2017-04-26T16:42:38.233Z,1493224958.233 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2017-04-26T16:42:38.233Z,1493224958.233 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2017-04-26T16:42:38.233Z,1493224958.233 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2017-04-26T16:42:38.233Z,1493224958.233 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2017-04-26T16:42:38.234Z,1493224958.234 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2017-04-26T16:42:38.234Z,1493224958.234 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2017-04-26T16:42:38.234Z,1493224958.234 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2017-04-26T16:42:38.268Z,1493224958.268 [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>


2017-04-26T16:42:38.269Z,1493224958.269 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2017-04-26T16:42:38.388Z,1493224958.388 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2017-04-26T16:42:38.389Z,1493224958.389 [Default:A.Wait](DEBUG): Construct Wait.
2017-04-26T16:42:38.391Z,1493224958.391 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2017-04-26T16:42:38.417Z,1493224958.417 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2017-04-26T16:42:38.430Z,1493224958.430 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-04-26T16:42:38.430Z,1493224958.430 [CTD_Seabird](INFO): Powering down
2017-04-26T16:42:38.470Z,1493224958.470 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2017-04-26T16:42:38.496Z,1493224958.496 [Default:E.Execute](DEBUG): Construct Execute.
2017-04-26T16:42:38.500Z,1493224958.500 [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>


2017-04-26T16:42:38.515Z,1493224958.515 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DepAvgTempFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2017-04-26T16:42:38.630Z,1493224958.630 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2017-04-26T16:42:38.807Z,1493224958.807 [NAL9602](INFO): Powering up NAL9602
2017-04-26T16:42:39.111Z,1493224959.111 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:39.481Z,1493224959.481 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:39.587Z,1493224959.587 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-04-26T16:42:39.599Z,1493224959.599 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-04-26T16:42:39.621Z,1493224959.621 [ElevatorServo](DEBUG): Initializing EZServoServo.
2017-04-26T16:42:39.627Z,1493224959.627 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2017-04-26T16:42:39.633Z,1493224959.633 [MassServo](DEBUG): Initializing EZServoServo.
2017-04-26T16:42:39.639Z,1493224959.639 [MassServo](DEBUG): Initializing MassServo.
2017-04-26T16:42:39.660Z,1493224959.660 [RudderServo](DEBUG): Initializing EZServoServo.
2017-04-26T16:42:39.667Z,1493224959.667 [RudderServo](DEBUG): Initializing RudderServo.
2017-04-26T16:42:39.688Z,1493224959.688 [ThrusterServo](DEBUG): Initializing EZServoServo.
2017-04-26T16:42:39.695Z,1493224959.695 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2017-04-26T16:42:40.079Z,1493224960.079 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:40.080Z,1493224960.080 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:40.430Z,1493224960.430 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2017-04-26T16:42:40.431Z,1493224960.431 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2017-04-26T16:42:40.431Z,1493224960.431 [BuoyancyServo] Communications Fault, FailCount= 1
2017-04-26T16:42:40.431Z,1493224960.431 [BuoyancyServo](ERROR): Communications Fault
2017-04-26T16:42:40.706Z,1493224960.706 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2017-04-26T16:42:40.788Z,1493224960.788 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:40.789Z,1493224960.789 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:40.818Z,1493224960.818 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-04-26T16:42:40.835Z,1493224960.835 [BuoyancyServo](INFO): Powering down
2017-04-26T16:42:41.163Z,1493224961.163 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:41.164Z,1493224961.164 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:41.634Z,1493224961.634 [Aanderaa_O2](INFO): Powering down
2017-04-26T16:42:41.774Z,1493224961.774 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:41.775Z,1493224961.775 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:41.966Z,1493224961.967 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:41.968Z,1493224961.968 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:42.380Z,1493224962.380 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:42.382Z,1493224962.382 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:42.566Z,1493224962.566 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-04-26T16:42:42.646Z,1493224962.646 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-04-26T16:42:42.769Z,1493224962.769 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:42.780Z,1493224962.780 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-04-26T16:42:43.051Z,1493224963.051 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2017-04-26T16:42:43.051Z,1493224963.051 [BuoyancyServo] No Fault, FailCount= 1
2017-04-26T16:42:43.290Z,1493224963.290 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-04-26T16:42:43.298Z,1493224963.298 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-04-26T16:42:44.789Z,1493224964.789 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-04-26T16:42:44.790Z,1493224964.790 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-04-26T16:42:44.791Z,1493224964.791 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-04-26T16:42:49.683Z,1493224969.683 [NAL9602](INFO): NAL9602 initialized
2017-04-26T16:43:07.237Z,1493224987.237 [NAL9602](INFO): SBD MO Status=0, MOMSN=63496, MT Status=0, MTMSN=0
2017-04-26T16:43:07.238Z,1493224987.238 [NAL9602](INFO): No messages in MT queue
2017-04-26T16:43:10.481Z,1493224990.481 [SBIT](IMPORTANT): Beginning Startup BIT
2017-04-26T16:43:10.501Z,1493224990.501 [CBIT](IMPORTANT): Beginning ground fault scan
2017-04-26T16:43:21.155Z,1493225001.155 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): 0.027343
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.012157
CHAN B0 (3.3V): 4.766929
CHAN B1 (3.15aV): 0.002235
CHAN B2 (3.15bV): -0.001170
CHAN B3 (GND): 0.000143
OPEN: -0.001092
Full Scale Calc: 4.765 mA, -1.589 mA
2017-04-26T16:43:24.301Z,1493225004.301 [BPC1](ERROR): Failed to parse bank A battery data
2017-04-26T16:43:24.301Z,1493225004.301 [BPC1] Data Fault, FailCount= 1
2017-04-26T16:43:24.301Z,1493225004.301 [BPC1](ERROR): Data Fault
2017-04-26T16:43:24.452Z,1493225004.452 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-26T16:43:26.007Z,1493225006.007 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:43:26.007Z,1493225006.007 [BPC1] No Fault, FailCount= 1
2017-04-26T16:44:03.962Z,1493225043.962 [SBIT](IMPORTANT): SBIT PASSED
2017-04-26T16:44:04.351Z,1493225044.351 [MissionManager](IMPORTANT): Started mission Startup
2017-04-26T16:44:04.351Z,1493225044.351 [Startup] Running Loop=1
2017-04-26T16:44:04.351Z,1493225044.351 [Startup](DEBUG): Aggregate::initialize Startup
2017-04-26T16:44:04.351Z,1493225044.351 [Startup:A.GoToSurface] Running Loop=1
2017-04-26T16:44:04.351Z,1493225044.351 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-04-26T16:44:04.352Z,1493225044.352 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-04-26T16:44:04.352Z,1493225044.352 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-04-26T16:44:04.353Z,1493225044.353 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-04-26T16:44:04.353Z,1493225044.353 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-04-26T16:44:04.353Z,1493225044.353 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-04-26T16:44:04.364Z,1493225044.364 [Startup:StartupSatComms] Running Loop=1
2017-04-26T16:44:04.364Z,1493225044.364 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2017-04-26T16:44:04.364Z,1493225044.364 [Startup:StartupSatComms:A] Running Loop=1
2017-04-26T16:44:04.761Z,1493225044.761 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2017-04-26T16:44:38.854Z,1493225078.854 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-04-26T16:44:38.854Z,1493225078.854 [Rowe_600LCM] Communications Fault, FailCount= 1
2017-04-26T16:44:38.854Z,1493225078.854 [Rowe_600LCM](ERROR): Communications Fault
2017-04-26T16:44:39.131Z,1493225079.131 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s.
2017-04-26T16:44:39.145Z,1493225079.145 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-04-26T16:44:39.258Z,1493225079.258 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-04-26T16:44:39.356Z,1493225079.356 [Rowe_600LCM](INFO): Powering down
2017-04-26T16:44:39.530Z,1493225079.530 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s.
2017-04-26T16:44:39.924Z,1493225079.924 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-04-26T16:44:40.335Z,1493225080.335 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-04-26T16:44:40.725Z,1493225080.725 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-04-26T16:44:40.739Z,1493225080.739 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-04-26T16:44:40.739Z,1493225080.739 [Rowe_600LCM] No Fault, FailCount= 1
2017-04-26T16:44:40.970Z,1493225080.970 [Rowe_600LCM](INFO): Initializing
2017-04-26T16:44:40.971Z,1493225080.971 [Rowe_600LCM](INFO): Checking LCM
2017-04-26T16:44:40.971Z,1493225080.971 [Rowe_600LCM](INFO): LCM OK
2017-04-26T16:44:40.971Z,1493225080.971 [Rowe_600LCM](INFO): Powering up
2017-04-26T16:44:41.131Z,1493225081.131 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-04-26T16:44:41.535Z,1493225081.535 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-04-26T16:44:41.937Z,1493225081.937 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-04-26T16:44:42.317Z,1493225082.317 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-04-26T16:44:42.729Z,1493225082.729 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-04-26T16:44:43.139Z,1493225083.139 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-04-26T16:44:43.531Z,1493225083.532 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-04-26T16:44:43.965Z,1493225083.965 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-04-26T16:44:44.328Z,1493225084.328 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-04-26T16:44:44.723Z,1493225084.723 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-04-26T16:44:45.154Z,1493225085.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-04-26T16:44:45.204Z,1493225085.204 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-04-26T16:44:45.292Z,1493225085.292 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-04-26T16:44:45.293Z,1493225085.293 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-04-26T16:44:45.294Z,1493225085.294 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-04-26T16:44:45.295Z,1493225085.295 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-04-26T16:44:45.595Z,1493225085.595 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.9 s old, using for 20.0 s.
2017-04-26T16:45:04.729Z,1493225104.729 [Startup:StartupSatComms:A](INFO): Timed out from 2017-04-26T16:44:04.4Z
2017-04-26T16:45:04.729Z,1493225104.729 [Startup:StartupSatComms:A] Stopped
2017-04-26T16:45:04.729Z,1493225104.729 [Startup:StartupSatComms:B] Running Loop=1
2017-04-26T16:45:05.131Z,1493225105.131 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-04-26T16:45:22.002Z,1493225122.001 [NAL9602](INFO): SBD MO Status=1, MOMSN=63497, MT Status=0, MTMSN=0
2017-04-26T16:45:22.055Z,1493225122.055 [NAL9602](INFO): Sent 25 bytes from file Logs/20170425T205601/Courier0408.lzma
2017-04-26T16:45:22.055Z,1493225122.055 [NAL9602](INFO): Packets left to send: 0
2017-04-26T16:45:22.057Z,1493225122.057 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170425T205601/Courier0408.lzma.parts/0000.sbd
2017-04-26T16:45:22.057Z,1493225122.057 [NAL9602](DEBUG): Completed sending Logs/20170425T205601/Courier0408.lzma
2017-04-26T16:45:27.677Z,1493225127.677 [NAL9602](INFO): SBD MO Status=1, MOMSN=63498, MT Status=0, MTMSN=0
2017-04-26T16:45:27.727Z,1493225127.727 [NAL9602](INFO): Sent 18 bytes from file Logs/20170426T163941/Courier0000.lzma
2017-04-26T16:45:27.727Z,1493225127.727 [NAL9602](INFO): Packets left to send: 0
2017-04-26T16:45:27.729Z,1493225127.730 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170426T163941/Courier0000.lzma.parts/0000.sbd
2017-04-26T16:45:27.730Z,1493225127.730 [NAL9602](DEBUG): Completed sending Logs/20170426T163941/Courier0000.lzma
2017-04-26T16:45:37.893Z,1493225137.893 [NAL9602](INFO): SBD MO Status=1, MOMSN=63499, MT Status=0, MTMSN=0
2017-04-26T16:45:37.943Z,1493225137.943 [NAL9602](INFO): Sent 145 bytes from file Logs/20170425T205601/Express0409.lzma
2017-04-26T16:45:37.943Z,1493225137.943 [NAL9602](INFO): Packets left to send: 0
2017-04-26T16:45:37.945Z,1493225137.945 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170425T205601/Express0409.lzma.parts/0000.sbd
2017-04-26T16:45:37.945Z,1493225137.945 [NAL9602](DEBUG): Completed sending Logs/20170425T205601/Express0409.lzma
2017-04-26T16:45:38.621Z,1493225138.621 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-04-26T16:45:38.621Z,1493225138.621 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2017-04-26T16:45:38.621Z,1493225138.621 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-04-26T16:45:38.623Z,1493225138.623 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-04-26T16:45:38.623Z,1493225138.623 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2017-04-26T16:45:38.623Z,1493225138.623 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-04-26T16:45:38.637Z,1493225138.637 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-04-26T16:45:38.637Z,1493225138.637 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-04-26T16:45:40.780Z,1493225140.780 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-04-26T16:45:40.780Z,1493225140.780 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2017-04-26T16:45:40.781Z,1493225140.781 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-04-26T16:45:40.781Z,1493225140.781 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2017-04-26T16:45:40.904Z,1493225140.904 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-26T16:45:40.905Z,1493225140.905 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:45:40.905Z,1493225140.905 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:45:40.905Z,1493225140.905 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-04-26T16:45:40.906Z,1493225140.906 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:45:40.906Z,1493225140.906 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:45:45.197Z,1493225145.197 [NAL9602](INFO): SBD MO Status=1, MOMSN=63500, MT Status=0, MTMSN=0
2017-04-26T16:45:45.247Z,1493225145.247 [NAL9602](INFO): Sent 18 bytes from file Logs/20170426T163941/Express0001.lzma
2017-04-26T16:45:45.247Z,1493225145.247 [NAL9602](INFO): Packets left to send: 0
2017-04-26T16:45:46.097Z,1493225146.097 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170426T163941/Express0001.lzma.parts/0000.sbd
2017-04-26T16:45:46.097Z,1493225146.097 [NAL9602](DEBUG): Completed sending Logs/20170426T163941/Express0001.lzma
2017-04-26T16:45:55.734Z,1493225155.734 [NAL9602](INFO): SBD MO Status=1, MOMSN=63501, MT Status=0, MTMSN=0
2017-04-26T16:45:55.783Z,1493225155.783 [NAL9602](INFO): Sent 332 bytes from file Logs/20170426T164218/Express0001.lzma
2017-04-26T16:45:55.783Z,1493225155.783 [NAL9602](INFO): Packets left to send: 2
2017-04-26T16:45:55.784Z,1493225155.784 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170426T164218/Express0001.lzma.parts/0002.sbd
2017-04-26T16:46:04.657Z,1493225164.657 [NAL9602](INFO): SBD MO Status=1, MOMSN=63502, MT Status=0, MTMSN=0
2017-04-26T16:46:04.706Z,1493225164.707 [NAL9602](INFO): Sent 332 bytes from file Logs/20170426T164218/Express0001.lzma
2017-04-26T16:46:04.707Z,1493225164.707 [NAL9602](INFO): Packets left to send: 1
2017-04-26T16:46:04.708Z,1493225164.708 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170426T164218/Express0001.lzma.parts/0001.sbd
2017-04-26T16:46:04.784Z,1493225164.784 [Startup:StartupSatComms:B](INFO): Timed out from 2017-04-26T16:45:04.7Z
2017-04-26T16:46:04.784Z,1493225164.784 [Startup:StartupSatComms:B] Stopped
2017-04-26T16:46:04.784Z,1493225164.784 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2017-04-26T16:46:04.785Z,1493225164.784 [Startup:StartupSatComms] Stopped
2017-04-26T16:46:04.785Z,1493225164.785 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2017-04-26T16:46:04.785Z,1493225164.785 [Startup](INFO): Completed Startup
2017-04-26T16:46:04.786Z,1493225164.786 [MissionManager](INFO): Startup is completed.
2017-04-26T16:46:04.786Z,1493225164.786 [MissionManager](INFO): Uninitializing Mission Startup
2017-04-26T16:46:04.786Z,1493225164.786 [Startup] Stopped
2017-04-26T16:46:04.786Z,1493225164.786 [Startup](DEBUG): Aggregate::uninitialize Startup
2017-04-26T16:46:04.786Z,1493225164.786 [Startup:A.GoToSurface] Stopped
2017-04-26T16:46:04.786Z,1493225164.786 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-04-26T16:46:05.340Z,1493225165.340 [MissionManager](IMPORTANT): Started mission Default
2017-04-26T16:46:05.340Z,1493225165.340 [Default] Running Loop=1
2017-04-26T16:46:05.340Z,1493225165.341 [Default](DEBUG): Aggregate::initialize Default
2017-04-26T16:46:05.341Z,1493225165.341 [Default:B.GoToSurface] Running Loop=1
2017-04-26T16:46:05.341Z,1493225165.341 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-04-26T16:46:05.341Z,1493225165.341 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-04-26T16:46:05.341Z,1493225165.341 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-04-26T16:46:05.342Z,1493225165.342 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-04-26T16:46:05.342Z,1493225165.342 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-04-26T16:46:05.343Z,1493225165.342 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-04-26T16:46:05.343Z,1493225165.343 [Default:A.Wait] Running Loop=1
2017-04-26T16:46:05.343Z,1493225165.343 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-04-26T16:46:17.969Z,1493225177.969 [NAL9602](INFO): SBD MO Status=1, MOMSN=63503, MT Status=0, MTMSN=0
2017-04-26T16:46:18.031Z,1493225178.031 [NAL9602](INFO): Sent 10 bytes from file Logs/20170426T164218/Express0001.lzma
2017-04-26T16:46:18.031Z,1493225178.031 [NAL9602](INFO): Packets left to send: 0
2017-04-26T16:46:18.032Z,1493225178.032 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170426T164218/Express0001.lzma.parts/0000.sbd
2017-04-26T16:46:18.032Z,1493225178.032 [NAL9602](DEBUG): Completed sending Logs/20170426T164218/Express0001.lzma
2017-04-26T16:46:18.472Z,1493225178.472 [Default:A.Wait](INFO): Done Waiting.
2017-04-26T16:46:18.472Z,1493225178.472 [Default:A.Wait] Stopped
2017-04-26T16:46:18.472Z,1493225178.472 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-04-26T16:46:18.840Z,1493225178.840 [Default:CheckIn] Running Loop=1
2017-04-26T16:46:18.840Z,1493225178.840 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-04-26T16:46:18.840Z,1493225178.840 [Default:CheckIn:Read_GPS] Running Loop=1
2017-04-26T16:46:19.177Z,1493225179.177 [NAL9602](INFO): GPS fix at 20170426T164613: (36.802914, -121.787955)
2017-04-26T16:46:19.275Z,1493225179.275 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2017-04-26T16:46:19.277Z,1493225179.277 [Default:CheckIn:Read_GPS] Stopped
2017-04-26T16:46:19.277Z,1493225179.277 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-04-26T16:46:19.616Z,1493225179.616 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-04-26T16:46:19.616Z,1493225179.616 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2017-04-26T16:46:19.616Z,1493225179.616 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-04-26T16:46:19.628Z,1493225179.628 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-04-26T16:46:19.657Z,1493225179.657 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-04-26T16:46:20.023Z,1493225180.023 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-04-26T16:46:20.023Z,1493225180.023 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2017-04-26T16:46:20.443Z,1493225180.443 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-26T16:46:20.444Z,1493225180.444 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:46:20.444Z,1493225180.444 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:46:29.657Z,1493225189.657 [NAL9602](INFO): SBD MO Status=1, MOMSN=63504, MT Status=0, MTMSN=0
2017-04-26T16:46:29.706Z,1493225189.707 [NAL9602](INFO): Sent 212 bytes from file Logs/20170426T164218/Courier0004.lzma
2017-04-26T16:46:29.707Z,1493225189.707 [NAL9602](INFO): Packets left to send: 0
2017-04-26T16:46:29.708Z,1493225189.708 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170426T164218/Courier0004.lzma.parts/0000.sbd
2017-04-26T16:46:29.709Z,1493225189.709 [NAL9602](DEBUG): Completed sending Logs/20170426T164218/Courier0004.lzma
2017-04-26T16:46:39.008Z,1493225199.008 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003500
2017-04-26T16:46:41.682Z,1493225201.682 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-04-26T16:46:41.682Z,1493225201.682 [Rowe_600LCM] Communications Fault, FailCount= 2
2017-04-26T16:46:41.682Z,1493225201.682 [Rowe_600LCM](ERROR): Communications Fault
2017-04-26T16:46:42.086Z,1493225202.086 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-04-26T16:46:42.239Z,1493225202.239 [Rowe_600LCM](INFO): Powering down
2017-04-26T16:46:43.368Z,1493225203.368 [NAL9602](INFO): SBD MO Status=1, MOMSN=63505, MT Status=0, MTMSN=0
2017-04-26T16:46:43.417Z,1493225203.417 [NAL9602](INFO): Sent 208 bytes from file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:46:43.417Z,1493225203.418 [NAL9602](INFO): Packets left to send: 0
2017-04-26T16:46:43.419Z,1493225203.419 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170426T164218/Express0005.lzma.parts/0000.sbd
2017-04-26T16:46:43.419Z,1493225203.419 [NAL9602](DEBUG): Completed sending Logs/20170426T164218/Express0005.lzma
2017-04-26T16:46:43.493Z,1493225203.493 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-04-26T16:46:43.499Z,1493225203.499 [Default:CheckIn:Read_Iridium] Stopped
2017-04-26T16:46:43.499Z,1493225203.499 [Default:CheckIn:C.Wait] Running Loop=1
2017-04-26T16:46:43.499Z,1493225203.499 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-04-26T16:46:43.522Z,1493225203.522 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-04-26T16:46:43.522Z,1493225203.522 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-04-26T16:46:43.522Z,1493225203.522 [Rowe_600LCM] No Fault, FailCount= 2
2017-04-26T16:46:43.557Z,1493225203.557 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:46:43.558Z,1493225203.558 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:46:43.622Z,1493225203.622 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.8 s old, using for 20.0 s.
2017-04-26T16:46:43.663Z,1493225203.663 [CommandLine](FAULT): Scheduling is paused
2017-04-26T16:46:43.663Z,1493225203.663 [CBIT](INFO): Critical error at 20170426T164643
2017-04-26T16:46:43.664Z,1493225203.664 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2017-04-26T16:46:43.854Z,1493225203.854 [Rowe_600LCM](INFO): Initializing
2017-04-26T16:46:43.855Z,1493225203.855 [Rowe_600LCM](INFO): Checking LCM
2017-04-26T16:46:43.855Z,1493225203.855 [Rowe_600LCM](INFO): LCM OK
2017-04-26T16:46:43.855Z,1493225203.855 [Rowe_600LCM](INFO): Powering up
2017-04-26T16:46:43.988Z,1493225203.989 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.1 s old, using for 20.0 s.
2017-04-26T16:46:44.391Z,1493225204.391 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.5 s old, using for 20.0 s.
2017-04-26T16:46:44.790Z,1493225204.790 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s.
2017-04-26T16:46:45.193Z,1493225205.193 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.3 s old, using for 20.0 s.
2017-04-26T16:46:45.595Z,1493225205.595 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.7 s old, using for 20.0 s.
2017-04-26T16:46:45.992Z,1493225205.992 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.1 s old, using for 20.0 s.
2017-04-26T16:46:46.399Z,1493225206.399 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.6 s old, using for 20.0 s.
2017-04-26T16:46:48.074Z,1493225208.074 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-04-26T16:46:48.181Z,1493225208.181 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-04-26T16:46:48.183Z,1493225208.183 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-04-26T16:46:48.184Z,1493225208.184 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-04-26T16:46:48.184Z,1493225208.184 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-04-26T16:46:50.255Z,1493225210.255 [NAL9602](INFO): Powering down
2017-04-26T16:46:50.398Z,1493225210.398 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:46:50.398Z,1493225210.398 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:46:50.515Z,1493225210.515 [CBIT](INFO): Critical error at 20170426T164650
2017-04-26T16:46:59.591Z,1493225219.591 [PNI_TCM](ERROR): CRC does not match. Expected:0x64398 got:0x36360
2017-04-26T16:47:02.405Z,1493225222.405 [PNI_TCM](ERROR): CRC does not match. Expected:0x13764 got:0x10501
2017-04-26T16:47:03.992Z,1493225223.992 [PNI_TCM](ERROR): CRC does not match. Expected:0x2491 got:0x33308
2017-04-26T16:47:11.984Z,1493225231.984 [PNI_TCM](ERROR): CRC does not match. Expected:0x39802 got:0x49370
2017-04-26T16:47:19.606Z,1493225239.606 [BPC1](ERROR): Failed to parse bank A battery data
2017-04-26T16:47:19.606Z,1493225239.606 [BPC1] Data Fault, FailCount= 1
2017-04-26T16:47:19.606Z,1493225239.606 [BPC1](ERROR): Data Fault
2017-04-26T16:47:19.636Z,1493225239.636 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-26T16:47:20.901Z,1493225240.901 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:47:20.901Z,1493225240.901 [BPC1] No Fault, FailCount= 1
2017-04-26T16:47:48.820Z,1493225268.820 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:47:48.820Z,1493225268.820 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:47:48.912Z,1493225268.912 [CBIT](INFO): Critical error at 20170426T164748
2017-04-26T16:48:44.230Z,1493225324.230 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-04-26T16:48:44.230Z,1493225324.230 [Rowe_600LCM] Communications Fault, FailCount= 3
2017-04-26T16:48:44.230Z,1493225324.230 [Rowe_600LCM](ERROR): Communications Fault
2017-04-26T16:48:44.477Z,1493225324.477 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s.
2017-04-26T16:48:44.504Z,1493225324.504 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-04-26T16:48:44.635Z,1493225324.635 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-04-26T16:48:44.760Z,1493225324.760 [Rowe_600LCM](INFO): Powering down
2017-04-26T16:48:44.881Z,1493225324.881 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s.
2017-04-26T16:48:45.272Z,1493225325.272 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-04-26T16:48:48.782Z,1493225328.782 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.7 s old, using for 20.0 s.
2017-04-26T16:48:48.805Z,1493225328.805 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-04-26T16:48:48.805Z,1493225328.806 [Rowe_600LCM] No Fault, FailCount= 3
2017-04-26T16:48:48.869Z,1493225328.869 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:48:48.869Z,1493225328.869 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:48:48.949Z,1493225328.949 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s.
2017-04-26T16:48:48.984Z,1493225328.984 [CBIT](INFO): Critical error at 20170426T164848
2017-04-26T16:48:49.202Z,1493225329.202 [Rowe_600LCM](INFO): Initializing
2017-04-26T16:48:49.203Z,1493225329.203 [Rowe_600LCM](INFO): Checking LCM
2017-04-26T16:48:49.203Z,1493225329.203 [Rowe_600LCM](INFO): LCM OK
2017-04-26T16:48:49.203Z,1493225329.203 [Rowe_600LCM](INFO): Powering up
2017-04-26T16:48:49.293Z,1493225329.293 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-04-26T16:48:49.713Z,1493225329.713 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-04-26T16:48:50.078Z,1493225330.078 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-04-26T16:48:50.518Z,1493225330.518 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-04-26T16:48:50.910Z,1493225330.910 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-04-26T16:48:51.297Z,1493225331.297 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-04-26T16:48:51.707Z,1493225331.707 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-04-26T16:48:52.075Z,1493225332.076 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-04-26T16:48:52.486Z,1493225332.486 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-04-26T16:48:52.890Z,1493225332.890 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2017-04-26T16:48:53.390Z,1493225333.390 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.3 s old, using for 20.0 s.
2017-04-26T16:48:53.499Z,1493225333.499 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-04-26T16:48:53.565Z,1493225333.565 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-04-26T16:48:53.568Z,1493225333.568 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-04-26T16:48:53.568Z,1493225333.569 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-04-26T16:48:53.569Z,1493225333.569 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-04-26T16:48:53.712Z,1493225333.712 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2017-04-26T16:49:16.466Z,1493225356.466 [BPC1](ERROR): Failed to parse bank A battery data
2017-04-26T16:49:16.466Z,1493225356.466 [BPC1] Data Fault, FailCount= 1
2017-04-26T16:49:16.466Z,1493225356.466 [BPC1](ERROR): Data Fault
2017-04-26T16:49:16.519Z,1493225356.519 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-26T16:49:17.716Z,1493225357.716 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:49:17.716Z,1493225357.716 [BPC1] No Fault, FailCount= 1
2017-04-26T16:49:20.481Z,1493225360.481 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-04-26T16:49:20.481Z,1493225360.481 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2017-04-26T16:49:20.481Z,1493225360.481 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-04-26T16:49:20.526Z,1493225360.526 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-04-26T16:49:20.911Z,1493225360.911 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-04-26T16:49:20.911Z,1493225360.911 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2017-04-26T16:49:21.385Z,1493225361.385 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-26T16:49:21.386Z,1493225361.385 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:49:21.386Z,1493225361.386 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:49:48.710Z,1493225388.710 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:49:48.710Z,1493225388.710 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:49:48.818Z,1493225388.818 [CBIT](INFO): Critical error at 20170426T164948
2017-04-26T16:50:49.109Z,1493225449.109 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:50:49.109Z,1493225449.109 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:50:49.195Z,1493225449.195 [CBIT](INFO): Critical error at 20170426T165049
2017-04-26T16:51:34.717Z,1493225494.717 [BPC1](ERROR): Failed to receive battery data
2017-04-26T16:51:34.717Z,1493225494.717 [BPC1] Communications Fault, FailCount= 1
2017-04-26T16:51:34.717Z,1493225494.717 [BPC1](ERROR): Communications Fault
2017-04-26T16:51:34.741Z,1493225494.741 [CBIT](ERROR): Communications Fault in component: BPC1
2017-04-26T16:51:35.978Z,1493225495.978 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:51:35.978Z,1493225495.978 [BPC1] No Fault, FailCount= 1
2017-04-26T16:51:43.935Z,1493225503.935 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2017-04-26T16:51:43.935Z,1493225503.935 [Default:CheckIn:C.Wait] Stopped
2017-04-26T16:51:43.935Z,1493225503.935 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-04-26T16:51:43.935Z,1493225503.935 [Default:CheckIn:D] Running Loop=1
2017-04-26T16:51:44.349Z,1493225504.349 [Default:CheckIn:D] Stopped
2017-04-26T16:51:44.349Z,1493225504.349 [Default:CheckIn:E] Running Loop=1
2017-04-26T16:51:44.748Z,1493225504.747 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 5.650113 min 
2017-04-26T16:51:44.749Z,1493225504.749 [Default:CheckIn:E] Stopped
2017-04-26T16:51:44.750Z,1493225504.750 [Default:CheckIn](INFO): Completed Default:CheckIn
2017-04-26T16:51:44.750Z,1493225504.750 [Default:CheckIn] Stopped
2017-04-26T16:51:44.750Z,1493225504.750 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-04-26T16:51:44.750Z,1493225504.750 [Default:CheckIn](INFO): Running loop #2
2017-04-26T16:51:44.750Z,1493225504.750 [Default:CheckIn] Running Loop=2
2017-04-26T16:51:44.750Z,1493225504.750 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-04-26T16:51:44.750Z,1493225504.750 [Default:CheckIn:Read_GPS] Running Loop=1
2017-04-26T16:51:45.492Z,1493225505.492 [NAL9602](INFO): Powering up
2017-04-26T16:51:49.357Z,1493225509.357 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:51:49.357Z,1493225509.358 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:51:49.435Z,1493225509.435 [CBIT](INFO): Critical error at 20170426T165149
2017-04-26T16:51:56.520Z,1493225516.520 [NAL9602](INFO): NAL9602 initialized
2017-04-26T16:52:05.610Z,1493225525.610 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-04-26T16:52:05.610Z,1493225525.610 [Rowe_600LCM] Communications Fault, FailCount= 4
2017-04-26T16:52:05.610Z,1493225525.610 [Rowe_600LCM](ERROR): Communications Fault
2017-04-26T16:52:05.777Z,1493225525.777 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s.
2017-04-26T16:52:05.792Z,1493225525.792 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-04-26T16:52:06.014Z,1493225526.014 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-04-26T16:52:06.184Z,1493225526.184 [Rowe_600LCM](INFO): Powering down
2017-04-26T16:52:06.185Z,1493225526.185 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s.
2017-04-26T16:52:06.581Z,1493225526.581 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-04-26T16:52:06.992Z,1493225526.992 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-04-26T16:52:07.371Z,1493225527.371 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-04-26T16:52:07.775Z,1493225527.775 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-04-26T16:52:07.791Z,1493225527.791 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2017-04-26T16:52:07.791Z,1493225527.791 [Rowe_600LCM] No Fault, FailCount= 4
2017-04-26T16:52:07.798Z,1493225527.798 [Rowe_600LCM](INFO): Initializing
2017-04-26T16:52:07.799Z,1493225527.799 [Rowe_600LCM](INFO): Checking LCM
2017-04-26T16:52:07.799Z,1493225527.799 [Rowe_600LCM](INFO): LCM OK
2017-04-26T16:52:07.799Z,1493225527.799 [Rowe_600LCM](INFO): Powering up
2017-04-26T16:52:08.187Z,1493225528.187 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-04-26T16:52:08.557Z,1493225528.557 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-04-26T16:52:08.960Z,1493225528.960 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-04-26T16:52:09.360Z,1493225529.360 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-04-26T16:52:09.761Z,1493225529.761 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-04-26T16:52:10.168Z,1493225530.168 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-04-26T16:52:10.567Z,1493225530.567 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-04-26T16:52:10.966Z,1493225530.966 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-04-26T16:52:11.369Z,1493225531.369 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-04-26T16:52:11.772Z,1493225531.772 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-04-26T16:52:11.936Z,1493225531.936 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2017-04-26T16:52:12.005Z,1493225532.005 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2017-04-26T16:52:12.006Z,1493225532.006 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2017-04-26T16:52:12.007Z,1493225532.007 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2017-04-26T16:52:12.008Z,1493225532.008 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2017-04-26T16:52:12.211Z,1493225532.211 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-04-26T16:52:13.329Z,1493225533.329 [NAL9602](INFO): SBD MO Status=0, MOMSN=63506, MT Status=0, MTMSN=0
2017-04-26T16:52:13.329Z,1493225533.329 [NAL9602](INFO): No messages in MT queue
2017-04-26T16:52:21.389Z,1493225541.389 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-04-26T16:52:21.389Z,1493225541.389 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2017-04-26T16:52:21.389Z,1493225541.389 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-04-26T16:52:21.405Z,1493225541.405 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-04-26T16:52:21.815Z,1493225541.815 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-04-26T16:52:21.815Z,1493225541.815 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2017-04-26T16:52:22.159Z,1493225542.159 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-26T16:52:22.160Z,1493225542.160 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:52:22.160Z,1493225542.160 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:52:35.380Z,1493225555.380 [BPC1](ERROR): Failed to receive battery data
2017-04-26T16:52:35.380Z,1493225555.380 [BPC1] Communications Fault, FailCount= 1
2017-04-26T16:52:35.380Z,1493225555.380 [BPC1](ERROR): Communications Fault
2017-04-26T16:52:35.412Z,1493225555.412 [CBIT](ERROR): Communications Fault in component: BPC1
2017-04-26T16:52:36.608Z,1493225556.608 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:52:36.608Z,1493225556.608 [BPC1] No Fault, FailCount= 1
2017-04-26T16:52:49.364Z,1493225569.364 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:52:49.364Z,1493225569.364 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:52:49.468Z,1493225569.468 [CBIT](INFO): Critical error at 20170426T165249
2017-04-26T16:52:52.561Z,1493225572.561 [BPC1](ERROR): Failed to receive battery data
2017-04-26T16:52:52.561Z,1493225572.561 [BPC1] Communications Fault, FailCount= 2
2017-04-26T16:52:52.561Z,1493225572.561 [BPC1](ERROR): Communications Fault
2017-04-26T16:52:52.606Z,1493225572.606 [CBIT](ERROR): Communications Fault in component: BPC1
2017-04-26T16:52:53.777Z,1493225573.777 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:52:53.777Z,1493225573.777 [BPC1] No Fault, FailCount= 2
2017-04-26T16:53:40.960Z,1493225620.960 [PNI_TCM](ERROR): CRC does not match. Expected:0x30946 got:0x16779
2017-04-26T16:53:49.367Z,1493225629.367 [DataOverHttps](IMPORTANT): Could not stat file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:53:49.368Z,1493225629.368 [DataOverHttps](CRITICAL): Could not open file Logs/20170426T164218/Express0005.lzma
2017-04-26T16:53:49.462Z,1493225629.462 [CBIT](INFO): Critical error at 20170426T165349
2017-04-26T16:53:54.523Z,1493225634.523 [NAL9602](INFO): GPS fix at 20170426T165350: (36.802998, -121.787933)
2017-04-26T16:53:54.664Z,1493225634.664 [Default:CheckIn:Read_GPS] Stopped
2017-04-26T16:53:54.664Z,1493225634.664 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-04-26T16:53:55.061Z,1493225635.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-04-26T16:53:55.061Z,1493225635.061 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2017-04-26T16:53:55.061Z,1493225635.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-04-26T16:53:55.116Z,1493225635.115 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-04-26T16:53:55.553Z,1493225635.553 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-04-26T16:53:55.553Z,1493225635.553 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2017-04-26T16:53:55.940Z,1493225635.940 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-26T16:53:55.941Z,1493225635.941 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:53:55.941Z,1493225635.941 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:53:59.648Z,1493225639.648 [DataOverHttps](INFO): Sending 357 bytes from file Logs/20170426T164218/Courier0008.lzma
2017-04-26T16:54:00.384Z,1493225640.384 [DataOverHttps](INFO): Moved sent file to Logs/20170426T164218/Courier0008.lzma.bak
2017-04-26T16:54:00.385Z,1493225640.385 [DataOverHttps](INFO): SBD MOMSN=4965599
2017-04-26T16:54:04.778Z,1493225644.778 [NAL9602](INFO): Powering down
2017-04-26T16:54:08.006Z,1493225648.006 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2017-04-26T16:54:08.006Z,1493225648.006 [Rowe_600LCM] Communications Fault, FailCount= 5
2017-04-26T16:54:08.006Z,1493225648.006 [Rowe_600LCM](ERROR): Communications Fault
2017-04-26T16:54:08.410Z,1493225648.410 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-04-26T16:54:08.624Z,1493225648.624 [Rowe_600LCM](INFO): Powering down
2017-04-26T16:54:11.069Z,1493225651.069 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.5 s old, using for 20.0 s.
2017-04-26T16:54:11.116Z,1493225651.116 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2017-04-26T16:54:11.116Z,1493225651.116 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM
2017-04-26T16:54:11.176Z,1493225651.176 [DataOverHttps](INFO): Sending 397 bytes from file Logs/20170426T164218/Express0009.lzma
2017-04-26T16:54:11.255Z,1493225651.255 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.7 s old, using for 20.0 s.
2017-04-26T16:54:11.597Z,1493225651.597 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-04-26T16:54:11.937Z,1493225651.937 [DataOverHttps](INFO): Moved sent file to Logs/20170426T164218/Express0009.lzma.bak
2017-04-26T16:54:11.937Z,1493225651.937 [DataOverHttps](INFO): SBD MOMSN=4965627
2017-04-26T16:54:12.011Z,1493225652.011 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-04-26T16:54:12.421Z,1493225652.421 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s.
2017-04-26T16:54:12.428Z,1493225652.428 [Default:CheckIn:Read_Iridium] Stopped
2017-04-26T16:54:12.428Z,1493225652.428 [Default:CheckIn:C.Wait] Running Loop=1
2017-04-26T16:54:12.428Z,1493225652.428 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-04-26T16:54:12.780Z,1493225652.780 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-04-26T16:54:16.161Z,1493225656.161 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.6 s old, using for 20.0 s.
2017-04-26T16:54:16.255Z,1493225656.255 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.7 s old, using for 20.0 s.
2017-04-26T16:54:16.648Z,1493225656.648 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.1 s old, using for 20.0 s.
2017-04-26T16:54:17.101Z,1493225657.101 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.5 s old, using for 20.0 s.
2017-04-26T16:54:17.449Z,1493225657.449 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.9 s old, using for 20.0 s.
2017-04-26T16:54:17.897Z,1493225657.897 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.3 s old, using for 20.0 s.
2017-04-26T16:54:18.249Z,1493225658.249 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.7 s old, using for 20.0 s.
2017-04-26T16:54:18.686Z,1493225658.686 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.1 s old, using for 20.0 s.
2017-04-26T16:54:19.047Z,1493225659.047 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.5 s old, using for 20.0 s.
2017-04-26T16:54:19.469Z,1493225659.469 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.9 s old, using for 20.0 s.
2017-04-26T16:54:19.853Z,1493225659.853 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.3 s old, using for 20.0 s.
2017-04-26T16:54:20.300Z,1493225660.300 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.7 s old, using for 20.0 s.
2017-04-26T16:54:20.659Z,1493225660.659 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.1 s old, using for 20.0 s.
2017-04-26T16:54:21.047Z,1493225661.047 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.5 s old, using for 20.0 s.
2017-04-26T16:54:21.459Z,1493225661.459 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.9 s old, using for 20.0 s.
2017-04-26T16:54:21.859Z,1493225661.859 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.3 s old, using for 20.0 s.
2017-04-26T16:54:22.243Z,1493225662.243 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.7 s old, using for 20.0 s.
2017-04-26T16:54:22.661Z,1493225662.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.1 s old, using for 20.0 s.
2017-04-26T16:54:23.034Z,1493225663.034 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.5 s old, using for 20.0 s.
2017-04-26T16:54:23.439Z,1493225663.439 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.9 s old, using for 20.0 s.
2017-04-26T16:54:23.849Z,1493225663.849 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.3 s old, using for 20.0 s.
2017-04-26T16:54:24.243Z,1493225664.243 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.7 s old, using for 20.0 s.
2017-04-26T16:54:24.645Z,1493225664.645 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.1 s old, using for 20.0 s.
2017-04-26T16:54:25.047Z,1493225665.046 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.5 s old, using for 20.0 s.
2017-04-26T16:54:25.444Z,1493225665.444 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.9 s old, using for 20.0 s.
2017-04-26T16:54:25.861Z,1493225665.861 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.3 s old, using for 20.0 s.
2017-04-26T16:54:26.261Z,1493225666.261 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.7 s old, using for 20.0 s.
2017-04-26T16:54:26.668Z,1493225666.668 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.1 s old, using for 20.0 s.
2017-04-26T16:54:27.057Z,1493225667.057 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.5 s old, using for 20.0 s.
2017-04-26T16:54:27.451Z,1493225667.451 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.9 s old, using for 20.0 s.
2017-04-26T16:55:04.239Z,1493225704.239 [BPC1](ERROR): Failed to receive battery data
2017-04-26T16:55:04.239Z,1493225704.239 [BPC1] Communications Fault, FailCount= 1
2017-04-26T16:55:04.239Z,1493225704.239 [BPC1](ERROR): Communications Fault
2017-04-26T16:55:04.263Z,1493225704.263 [CBIT](ERROR): Communications Fault in component: BPC1
2017-04-26T16:55:05.488Z,1493225705.488 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:55:05.488Z,1493225705.488 [BPC1] No Fault, FailCount= 1
2017-04-26T16:55:17.619Z,1493225717.619 [BPC1](ERROR): Failed to parse bank B battery data
2017-04-26T16:55:17.619Z,1493225717.619 [BPC1] Data Fault, FailCount= 2
2017-04-26T16:55:17.619Z,1493225717.619 [BPC1](ERROR): Data Fault
2017-04-26T16:55:17.676Z,1493225717.676 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-26T16:55:18.874Z,1493225718.874 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:55:18.874Z,1493225718.874 [BPC1] No Fault, FailCount= 2
2017-04-26T16:55:27.604Z,1493225727.604 [PNI_TCM](ERROR): CRC does not match. Expected:0x38008 got:0x16775
2017-04-26T16:55:45.604Z,1493225745.604 [BPC1](ERROR): Failed to parse bank B battery data
2017-04-26T16:55:45.604Z,1493225745.604 [BPC1] Data Fault, FailCount= 1
2017-04-26T16:55:45.604Z,1493225745.604 [BPC1](ERROR): Data Fault
2017-04-26T16:55:45.684Z,1493225745.684 [CBIT](ERROR): Data Fault in component: BPC1
2017-04-26T16:55:46.864Z,1493225746.864 [CBIT](INFO): Clearing failed state for component BPC1
2017-04-26T16:55:46.864Z,1493225746.864 [BPC1] No Fault, FailCount= 1
2017-04-26T16:56:56.223Z,1493225816.223 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-04-26T16:56:56.223Z,1493225816.223 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2017-04-26T16:56:56.223Z,1493225816.223 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-04-26T16:56:56.247Z,1493225816.247 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-04-26T16:56:56.649Z,1493225816.649 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-04-26T16:56:56.649Z,1493225816.649 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2017-04-26T16:56:57.028Z,1493225817.028 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-04-26T16:56:57.028Z,1493225817.028 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-04-26T16:56:57.028Z,1493225817.028 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-04-26T16:56:57.423Z,1493225817.423 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-04-26T16:56:57.835Z,1493225817.835 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-04-26T16:56:58.233Z,1493225818.233 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-04-26T16:56:58.640Z,1493225818.640 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-04-26T16:56:59.041Z,1493225819.041 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-04-26T16:56:59.411Z,1493225819.411 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-04-26T16:56:59.876Z,1493225819.876 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.7 s old, using for 20.0 s.
2017-04-26T16:57:00.232Z,1493225820.232 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-04-26T16:57:00.650Z,1493225820.650 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-04-26T16:57:01.022Z,1493225821.022 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-04-26T16:57:01.463Z,1493225821.463 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-04-26T16:57:01.842Z,1493225821.842 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-04-26T16:57:02.233Z,1493225822.233 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-04-26T16:57:02.629Z,1493225822.629 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-04-26T16:57:03.019Z,1493225823.019 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-04-26T16:57:03.432Z,1493225823.432 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-04-26T16:57:03.832Z,1493225823.832 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-04-26T16:57:04.231Z,1493225824.231 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-04-26T16:57:04.615Z,1493225824.615 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-04-26T16:57:05.037Z,1493225825.037 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2017-04-26T16:57:05.439Z,1493225825.439 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2017-04-26T16:57:05.804Z,1493225825.804 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2017-04-26T16:57:06.212Z,1493225826.212 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2017-04-26T16:57:06.647Z,1493225826.647 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2017-04-26T16:57:07.008Z,1493225827.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s.
2017-04-26T16:57:07.418Z,1493225827.418 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s.
2017-04-26T16:57:07.812Z,1493225827.812 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2017-04-26T16:57:08.219Z,1493225828.219 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s.
2017-04-26T16:57:08.623Z,1493225828.622 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s.
2017-04-26T16:57:09.021Z,1493225829.021 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s.
2017-04-26T16:57:09.435Z,1493225829.435 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s.
2017-04-26T16:57:09.822Z,1493225829.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2017-04-26T16:57:10.230Z,1493225830.230 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s.
2017-04-26T16:57:10.635Z,1493225830.635 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s.
2017-04-26T16:57:11.026Z,1493225831.026 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s.
2017-04-26T16:57:11.434Z,1493225831.434 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s.
2017-04-26T16:57:11.820Z,1493225831.820 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2017-04-26T16:57:12.228Z,1493225832.228 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s.
2017-04-26T16:57:12.607Z,1493225832.607 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s.
2017-04-26T16:57:13.045Z,1493225833.045 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s.
2017-04-26T16:57:13.444Z,1493225833.444 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2017-04-26T16:57:17.648Z,1493225837.648 [DataOverHttps](IMPORTANT): SBD MTMSN=20170426T165713
2017-04-26T16:57:21.884Z,1493225841.884 [DataOverHttps](INFO): Received command:restart app
2017-04-26T16:57:21.959Z,1493225841.959 [CommandLine](IMPORTANT): got command restart application
2017-04-26T16:57:22.966Z,1493225842.966 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:22.966Z,1493225842.966 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:23.070Z,1493225843.070 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2017-04-26T16:57:23.071Z,1493225843.070 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:23.071Z,1493225843.071 [CommandLine](INFO): Join timeout helper Thread ID is 935
2017-04-26T16:57:23.074Z,1493225843.074 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2017-04-26T16:57:23.075Z,1493225843.075 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:23.075Z,1493225843.075 [NavChartDb](INFO): Join timeout helper Thread ID is 936
2017-04-26T16:57:23.298Z,1493225843.298 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:23.299Z,1493225843.299 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:23.314Z,1493225843.314 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2017-04-26T16:57:23.314Z,1493225843.314 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:23.315Z,1493225843.315 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 937
2017-04-26T16:57:23.442Z,1493225843.442 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:23.442Z,1493225843.442 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2017-04-26T16:57:23.630Z,1493225843.630 [Rowe_600LCM](INFO): Powering down
2017-04-26T16:57:23.632Z,1493225843.632 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:23.646Z,1493225843.646 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2017-04-26T16:57:23.646Z,1493225843.646 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:23.647Z,1493225843.647 [Radio_Surface](INFO): Join timeout helper Thread ID is 939
2017-04-26T16:57:24.022Z,1493225844.022 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:24.023Z,1493225844.023 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.026Z,1493225844.026 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2017-04-26T16:57:24.026Z,1493225844.026 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.027Z,1493225844.027 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 940
2017-04-26T16:57:24.154Z,1493225844.154 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:24.155Z,1493225844.155 [WetLabsBB2FL](INFO): Powering down
2017-04-26T16:57:24.155Z,1493225844.155 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.167Z,1493225844.167 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2017-04-26T16:57:24.167Z,1493225844.167 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.168Z,1493225844.168 [CTD_Seabird](INFO): Join timeout helper Thread ID is 941
2017-04-26T16:57:24.331Z,1493225844.331 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:24.435Z,1493225844.435 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-04-26T16:57:24.435Z,1493225844.435 [CTD_Seabird](INFO): Powering down
2017-04-26T16:57:24.437Z,1493225844.437 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.447Z,1493225844.447 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2017-04-26T16:57:24.447Z,1493225844.447 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.448Z,1493225844.448 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 943
2017-04-26T16:57:24.587Z,1493225844.587 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:24.587Z,1493225844.587 [CTD_NeilBrown](INFO): Powering down
2017-04-26T16:57:24.588Z,1493225844.588 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.613Z,1493225844.613 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2017-04-26T16:57:24.613Z,1493225844.613 [logger ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.614Z,1493225844.614 [logger](INFO): Join timeout helper Thread ID is 944
2017-04-26T16:57:24.614Z,1493225844.614 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:24.614Z,1493225844.614 [logger ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.615Z,1493225844.615 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2017-04-26T16:57:24.616Z,1493225844.616 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.616Z,1493225844.616 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2017-04-26T16:57:24.616Z,1493225844.616 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.616Z,1493225844.616 [controlThread](INFO): Join timeout helper Thread ID is 945
2017-04-26T16:57:24.627Z,1493225844.626 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2017-04-26T16:57:24.627Z,1493225844.627 [controlThread](DEBUG): Uninitializing ControlThread
2017-04-26T16:57:24.627Z,1493225844.627 [Aanderaa_O2](INFO): Powering down
2017-04-26T16:57:24.629Z,1493225844.629 [NAL9602](INFO): Powering down
2017-04-26T16:57:24.631Z,1493225844.631 [PNI_TCM](INFO): Powering down
2017-04-26T16:57:24.720Z,1493225844.720 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-04-26T16:57:24.721Z,1493225844.721 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2017-04-26T16:57:24.722Z,1493225844.722 [MissionManager](INFO): Uninitializing Mission Default
2017-04-26T16:57:24.722Z,1493225844.722 [Default] Stopped
2017-04-26T16:57:24.722Z,1493225844.722 [Default](DEBUG): Aggregate::uninitialize Default
2017-04-26T16:57:24.723Z,1493225844.723 [Default:B.GoToSurface] Stopped
2017-04-26T16:57:24.723Z,1493225844.723 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-04-26T16:57:24.723Z,1493225844.723 [Default:CheckIn] Stopped
2017-04-26T16:57:24.723Z,1493225844.723 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-04-26T16:57:24.723Z,1493225844.723 [Default:CheckIn:C.Wait] Stopped
2017-04-26T16:57:24.723Z,1493225844.723 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-04-26T16:57:24.727Z,1493225844.727 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2017-04-26T16:57:24.727Z,1493225844.727 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2017-04-26T16:57:24.727Z,1493225844.727 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2017-04-26T16:57:24.727Z,1493225844.727 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2017-04-26T16:57:24.728Z,1493225844.728 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-04-26T16:57:24.728Z,1493225844.728 [BuoyancyServo](INFO): Powering down
2017-04-26T16:57:24.742Z,1493225844.742 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2017-04-26T16:57:24.743Z,1493225844.743 [ElevatorServo](INFO): Powering down
2017-04-26T16:57:24.743Z,1493225844.743 [MassServo](DEBUG): Uninitialize Mass Servo.
2017-04-26T16:57:24.743Z,1493225844.743 [MassServo](INFO): Powering down
2017-04-26T16:57:24.744Z,1493225844.744 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2017-04-26T16:57:24.745Z,1493225844.745 [RudderServo](INFO): Powering down
2017-04-26T16:57:24.746Z,1493225844.746 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2017-04-26T16:57:24.746Z,1493225844.746 [ThrusterServo](INFO): Powering down
2017-04-26T16:57:24.747Z,1493225844.747 [SBIT](DEBUG): Uninitialize SBIT Component.
2017-04-26T16:57:24.747Z,1493225844.747 [IBIT](DEBUG): Uninitialize IBIT Component.
2017-04-26T16:57:24.747Z,1493225844.747 [CBIT](DEBUG): Uninitialize CBIT Component.
2017-04-26T16:57:24.748Z,1493225844.748 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.807Z,1493225844.807 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.812Z,1493225844.812 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.815Z,1493225844.815 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.878Z,1493225844.878 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.909Z,1493225844.909 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:24.952Z,1493225844.952 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-04-26T16:57:25.014Z,1493225845.014 [logger ThreadHandler](INFO): Thread cancelled.