2018-02-07T01:19:05.752Z,1517966345.752 [Supervisor](DEBUG): Initializing supervisor.
2018-02-07T01:19:05.755Z,1517966345.755 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-02-07T01:19:05.756Z,1517966345.756 [SyncHandler](INFO): Protected caller Thread ID is 4122
2018-02-07T01:19:05.756Z,1517966345.756 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-02-07T01:19:05.757Z,1517966345.757 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-02-07T01:19:05.758Z,1517966345.758 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4123
2018-02-07T01:19:05.760Z,1517966345.760 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-02-07T01:19:05.772Z,1517966345.772 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-02-07T01:19:05.773Z,1517966345.773 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-02-07T01:19:05.773Z,1517966345.773 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4124
2018-02-07T01:19:05.774Z,1517966345.774 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-02-07T01:19:05.775Z,1517966345.775 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-02-07T01:19:05.775Z,1517966345.775 [logger ThreadHandler](INFO): Protected caller Thread ID is 4125
2018-02-07T01:19:05.777Z,1517966345.777 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-02-07T01:19:05.778Z,1517966345.778 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-02-07T01:19:05.779Z,1517966345.779 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-02-07T01:19:05.876Z,1517966345.876 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-02-07T01:19:05.877Z,1517966345.877 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-02-07T01:19:05.975Z,1517966345.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-02-07T01:19:05.975Z,1517966345.975 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-02-07T01:19:06.159Z,1517966346.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-02-07T01:19:06.160Z,1517966346.160 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-02-07T01:19:06.445Z,1517966346.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-02-07T01:19:06.446Z,1517966346.446 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-02-07T01:19:06.745Z,1517966346.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-02-07T01:19:06.746Z,1517966346.746 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-02-07T01:19:07.176Z,1517966347.176 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-02-07T01:19:07.177Z,1517966347.177 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-02-07T01:19:07.496Z,1517966347.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-02-07T01:19:07.497Z,1517966347.497 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-02-07T01:19:07.903Z,1517966347.903 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-02-07T01:19:07.904Z,1517966347.904 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-02-07T01:19:07.984Z,1517966347.984 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-02-07T01:19:08.260Z,1517966348.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-02-07T01:19:08.260Z,1517966348.260 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-02-07T01:19:08.397Z,1517966348.397 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-02-07T01:19:08.398Z,1517966348.398 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-02-07T01:19:08.591Z,1517966348.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-02-07T01:19:08.592Z,1517966348.592 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-02-07T01:19:08.787Z,1517966348.787 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-02-07T01:19:08.788Z,1517966348.788 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-02-07T01:19:08.884Z,1517966348.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-02-07T01:19:08.885Z,1517966348.885 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-02-07T01:19:09.019Z,1517966349.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-02-07T01:19:09.021Z,1517966349.021 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-02-07T01:19:09.022Z,1517966349.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-02-07T01:19:09.244Z,1517966349.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-02-07T01:19:09.244Z,1517966349.244 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-02-07T01:19:09.322Z,1517966349.322 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-02-07T01:19:09.457Z,1517966349.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-02-07T01:19:09.548Z,1517966349.548 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-02-07T01:19:09.632Z,1517966349.632 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-02-07T01:19:09.801Z,1517966349.801 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-02-07T01:19:10.280Z,1517966350.280 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-02-07T01:19:10.377Z,1517966350.377 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-02-07T01:19:10.544Z,1517966350.544 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-02-07T01:19:10.720Z,1517966350.720 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-02-07T01:19:10.850Z,1517966350.850 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-02-07T01:19:10.850Z,1517966350.850 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-02-07T01:19:10.864Z,1517966350.864 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-02-07T01:19:10.957Z,1517966350.957 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-02-07T01:19:10.958Z,1517966350.958 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-02-07T01:19:10.971Z,1517966350.971 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-02-07T01:19:10.972Z,1517966350.972 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-02-07T01:19:11.011Z,1517966351.011 [DepthRateCalculator] Loaded
2018-02-07T01:19:11.011Z,1517966351.011 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-02-07T01:19:11.016Z,1517966351.016 [PitchRateCalculator] Loaded
2018-02-07T01:19:11.017Z,1517966351.017 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-02-07T01:19:11.032Z,1517966351.032 [SpeedCalculator] Loaded
2018-02-07T01:19:11.032Z,1517966351.032 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-02-07T01:19:11.052Z,1517966351.052 [TempGradientCalculator] Loaded
2018-02-07T01:19:11.053Z,1517966351.053 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-02-07T01:19:11.067Z,1517966351.067 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-02-07T01:19:11.068Z,1517966351.068 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-02-07T01:19:11.073Z,1517966351.073 [YawRateCalculator] Loaded
2018-02-07T01:19:11.073Z,1517966351.073 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-02-07T01:19:11.111Z,1517966351.111 [ElevatorOffsetCalculator] Loaded
2018-02-07T01:19:11.112Z,1517966351.112 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-02-07T01:19:11.112Z,1517966351.112 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-02-07T01:19:11.112Z,1517966351.112 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-02-07T01:19:11.136Z,1517966351.136 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-02-07T01:19:11.136Z,1517966351.136 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-02-07T01:19:11.382Z,1517966351.382 [AcousticModem_Benthos_ATM900] Loaded
2018-02-07T01:19:11.382Z,1517966351.382 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-02-07T01:19:11.449Z,1517966351.449 [DataOverHttps] Loaded
2018-02-07T01:19:11.449Z,1517966351.449 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-02-07T01:19:11.462Z,1517966351.462 [Depth_Keller] Loaded
2018-02-07T01:19:11.463Z,1517966351.463 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-02-07T01:19:11.467Z,1517966351.467 [DropWeight] Loaded
2018-02-07T01:19:11.467Z,1517966351.467 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-02-07T01:19:11.560Z,1517966351.560 [NAL9602] Loaded
2018-02-07T01:19:11.560Z,1517966351.560 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-02-07T01:19:11.575Z,1517966351.575 [Onboard] Loaded
2018-02-07T01:19:11.576Z,1517966351.576 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-02-07T01:19:11.585Z,1517966351.585 [Radio_Surface] Loaded
2018-02-07T01:19:11.586Z,1517966351.586 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-02-07T01:19:11.587Z,1517966351.587 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407A54E0
2018-02-07T01:19:11.587Z,1517966351.587 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4204
2018-02-07T01:19:11.632Z,1517966351.632 [PNI_TCM] Loaded
2018-02-07T01:19:11.632Z,1517966351.632 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-02-07T01:19:13.301Z,1517966353.301 [BPC1] Loaded
2018-02-07T01:19:13.301Z,1517966353.301 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-02-07T01:19:13.302Z,1517966353.302 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-02-07T01:19:13.302Z,1517966353.302 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-02-07T01:19:13.423Z,1517966353.423 [SBIT](DEBUG): Construct Startup Built In Test.
2018-02-07T01:19:13.446Z,1517966353.446 [SBIT] Loaded
2018-02-07T01:19:13.446Z,1517966353.446 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-02-07T01:19:13.447Z,1517966353.447 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-02-07T01:19:13.458Z,1517966353.458 [IBIT] Loaded
2018-02-07T01:19:13.458Z,1517966353.458 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-02-07T01:19:13.461Z,1517966353.461 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-02-07T01:19:13.604Z,1517966353.604 [CBIT] Loaded
2018-02-07T01:19:13.604Z,1517966353.604 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-02-07T01:19:13.604Z,1517966353.604 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-02-07T01:19:13.605Z,1517966353.605 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-02-07T01:19:13.744Z,1517966353.744 [Aanderaa_O2] Loaded
2018-02-07T01:19:13.744Z,1517966353.744 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-02-07T01:19:13.790Z,1517966353.790 [CTD_Seabird] Loaded
2018-02-07T01:19:13.790Z,1517966353.790 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-02-07T01:19:13.791Z,1517966353.791 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408654E0
2018-02-07T01:19:13.791Z,1517966353.791 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4205
2018-02-07T01:19:13.805Z,1517966353.805 [PAR_Licor] Loaded
2018-02-07T01:19:13.805Z,1517966353.805 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-02-07T01:19:13.852Z,1517966353.852 [WetLabsBB2FL] Loaded
2018-02-07T01:19:13.852Z,1517966353.852 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-02-07T01:19:13.853Z,1517966353.853 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408954E0
2018-02-07T01:19:13.853Z,1517966353.853 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4206
2018-02-07T01:19:13.854Z,1517966353.854 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-02-07T01:19:13.854Z,1517966353.854 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-02-07T01:19:14.077Z,1517966354.077 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-02-07T01:19:14.078Z,1517966354.078 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-02-07T01:19:14.142Z,1517966354.142 [VerticalControl](DEBUG): Construct VerticalControl.
2018-02-07T01:19:14.233Z,1517966354.233 [VerticalControl] Loaded
2018-02-07T01:19:14.233Z,1517966354.233 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-02-07T01:19:14.234Z,1517966354.234 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-02-07T01:19:14.292Z,1517966354.292 [HorizontalControl] Loaded
2018-02-07T01:19:14.292Z,1517966354.292 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-02-07T01:19:14.292Z,1517966354.292 [SpeedControl](DEBUG): Construct SpeedControl.
2018-02-07T01:19:14.298Z,1517966354.298 [SpeedControl] Loaded
2018-02-07T01:19:14.298Z,1517966354.298 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-02-07T01:19:14.298Z,1517966354.298 [LoopControl](DEBUG): Construct LoopControl.
2018-02-07T01:19:14.299Z,1517966354.299 [LoopControl] Loaded
2018-02-07T01:19:14.299Z,1517966354.299 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-02-07T01:19:14.300Z,1517966354.300 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-02-07T01:19:14.300Z,1517966354.300 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-02-07T01:19:14.378Z,1517966354.378 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-02-07T01:19:14.378Z,1517966354.378 [StratificationFrontDetector](DEBUG): (re)initializing
2018-02-07T01:19:14.378Z,1517966354.378 [StratificationFrontDetector] Loaded
2018-02-07T01:19:14.379Z,1517966354.379 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-02-07T01:19:14.379Z,1517966354.379 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-02-07T01:19:14.380Z,1517966354.380 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-02-07T01:19:14.472Z,1517966354.472 [BuoyancyServo] Loaded
2018-02-07T01:19:14.472Z,1517966354.472 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-02-07T01:19:14.483Z,1517966354.483 [ElevatorServo] Loaded
2018-02-07T01:19:14.483Z,1517966354.483 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-02-07T01:19:14.494Z,1517966354.494 [MassServo] Loaded
2018-02-07T01:19:14.494Z,1517966354.494 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-02-07T01:19:14.505Z,1517966354.505 [RudderServo] Loaded
2018-02-07T01:19:14.505Z,1517966354.505 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-02-07T01:19:14.516Z,1517966354.516 [ThrusterServo] Loaded
2018-02-07T01:19:14.516Z,1517966354.516 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-02-07T01:19:14.516Z,1517966354.516 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-02-07T01:19:14.517Z,1517966354.517 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-02-07T01:19:14.610Z,1517966354.610 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-02-07T01:19:14.610Z,1517966354.610 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-02-07T01:19:14.662Z,1517966354.662 [DeadReckonUsingSpeedCalculator] Loaded
2018-02-07T01:19:14.663Z,1517966354.663 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-02-07T01:19:14.679Z,1517966354.679 [NavChart] Loaded
2018-02-07T01:19:14.679Z,1517966354.679 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-02-07T01:19:14.683Z,1517966354.683 [UniversalFixResidualReporter] Loaded
2018-02-07T01:19:14.683Z,1517966354.683 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-02-07T01:19:14.683Z,1517966354.683 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-02-07T01:19:14.687Z,1517966354.687 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-02-07T01:19:14.688Z,1517966354.688 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-02-07T01:19:14.694Z,1517966354.694 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-02-07T01:19:14.695Z,1517966354.695 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409EA4E0
2018-02-07T01:19:14.696Z,1517966354.696 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4207
2018-02-07T01:19:14.700Z,1517966354.700 [Supervisor](INFO): Main Thread ID is 795
2018-02-07T01:19:14.700Z,1517966354.700 [Supervisor](DEBUG): Running supervisor.
2018-02-07T01:19:14.701Z,1517966354.701 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4208
2018-02-07T01:19:14.704Z,1517966354.704 [controlThread ThreadHandler](INFO): Handler Thread ID is 4209
2018-02-07T01:19:14.704Z,1517966354.704 [controlThread](DEBUG): Initializing ControlThread
2018-02-07T01:19:14.705Z,1517966354.705 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-02-07T01:19:14.706Z,1517966354.706 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-02-07T01:19:14.706Z,1517966354.706 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-02-07T01:19:14.706Z,1517966354.706 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-02-07T01:19:14.707Z,1517966354.707 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-02-07T01:19:14.707Z,1517966354.707 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-02-07T01:19:14.708Z,1517966354.708 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-02-07T01:19:14.715Z,1517966354.715 [SBIT](INFO): Initialize SBIT Component.
2018-02-07T01:19:14.716Z,1517966354.716 [SBIT](IMPORTANT): git: 2018-01-24-20-g7b7df60
2018-02-07T01:19:14.716Z,1517966354.716 [SBIT](INFO): git hash: 7b7df607dd4c62d1014105a1bb40f7706504dcf4
2018-02-07T01:19:14.716Z,1517966354.716 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-02-07T01:19:14.717Z,1517966354.717 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #1 PREEMPT Wed Nov 29 17:23:09 PST 2017
2018-02-07T01:19:14.718Z,1517966354.718 [SBIT](INFO): Beginning SBIT in 52.000000 seconds.
2018-02-07T01:19:14.719Z,1517966354.719 [IBIT](INFO): Initialize IBIT Component.
2018-02-07T01:19:14.720Z,1517966354.720 [CBIT](DEBUG): Initialize CBIT Component.
2018-02-07T01:19:14.720Z,1517966354.720 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-02-07T01:19:14.721Z,1517966354.721 [logger ThreadHandler](INFO): Handler Thread ID is 4210
2018-02-07T01:19:14.741Z,1517966354.741 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4211
2018-02-07T01:19:14.747Z,1517966354.747 [Radio_Surface](INFO): Powering up
2018-02-07T01:19:14.753Z,1517966354.753 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4212
2018-02-07T01:19:14.754Z,1517966354.754 [CTD_Seabird](INFO): Initializing
2018-02-07T01:19:14.754Z,1517966354.754 [CTD_Seabird](INFO): Checking LCM
2018-02-07T01:19:14.763Z,1517966354.763 [CTD_Seabird](INFO): LCM OK
2018-02-07T01:19:14.763Z,1517966354.763 [CTD_Seabird](INFO): Powering up
2018-02-07T01:19:14.769Z,1517966354.769 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4213
2018-02-07T01:19:14.771Z,1517966354.771 [WetLabsBB2FL](INFO): Powering down
2018-02-07T01:19:14.793Z,1517966354.793 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4214
2018-02-07T01:19:14.797Z,1517966354.797 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-02-07T01:19:14.797Z,1517966354.797 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-02-07T01:19:14.797Z,1517966354.797 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-02-07T01:19:14.797Z,1517966354.797 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-02-07T01:19:14.798Z,1517966354.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-02-07T01:19:14.798Z,1517966354.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-02-07T01:19:14.798Z,1517966354.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-02-07T01:19:14.798Z,1517966354.798 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-02-07T01:19:14.798Z,1517966354.798 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-02-07T01:19:14.799Z,1517966354.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-02-07T01:19:14.799Z,1517966354.799 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-02-07T01:19:14.799Z,1517966354.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-02-07T01:19:14.799Z,1517966354.799 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-02-07T01:19:14.799Z,1517966354.799 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-02-07T01:19:14.800Z,1517966354.800 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-02-07T01:19:14.800Z,1517966354.800 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-02-07T01:19:14.835Z,1517966354.835 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-02-07T01:19:14.844Z,1517966354.844 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-02-07T01:19:14.853Z,1517966354.853 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-02-07T01:19:14.854Z,1517966354.854 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-02-07T01:19:14.855Z,1517966354.855 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-02-07T01:19:14.856Z,1517966354.856 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-02-07T01:19:14.856Z,1517966354.856 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-02-07T01:19:14.857Z,1517966354.857 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-02-07T01:19:14.857Z,1517966354.857 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-02-07T01:19:14.858Z,1517966354.858 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-02-07T01:19:14.858Z,1517966354.858 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-02-07T01:19:14.858Z,1517966354.858 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-02-07T01:19:14.859Z,1517966354.859 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-02-07T01:19:14.891Z,1517966354.891 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-02-07T01:19:14.908Z,1517966354.908 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2018-02-07T01:19:14.933Z,1517966354.933 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-02-07T01:19:15.002Z,1517966355.002 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-02-07T01:19:15.003Z,1517966355.003 [Default:A.Wait](DEBUG): Construct Wait.
2018-02-07T01:19:15.004Z,1517966355.004 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-02-07T01:19:15.022Z,1517966355.022 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-02-07T01:19:15.049Z,1517966355.049 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-02-07T01:19:15.054Z,1517966355.054 [Default:E.Execute](DEBUG): Construct Execute.
2018-02-07T01:19:15.067Z,1517966355.067 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Guidance="Tethys/Guidance"
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

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

    <Guidance:Wait>
        <Sequence/>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Sequence/>
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Sequence/>
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

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

    </Aggregate>

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

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

</Mission>


2018-02-07T01:19:15.077Z,1517966355.077 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-02-07T01:19:15.105Z,1517966355.105 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-02-07T01:19:15.106Z,1517966355.106 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-02-07T01:19:15.131Z,1517966355.131 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-02-07T01:19:15.315Z,1517966355.315 [PNI_TCM](INFO): Start
2018-02-07T01:19:15.665Z,1517966355.665 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:15.689Z,1517966355.689 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:15.786Z,1517966355.786 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-02-07T01:19:15.793Z,1517966355.793 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-02-07T01:19:15.811Z,1517966355.811 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-02-07T01:19:15.817Z,1517966355.817 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-02-07T01:19:15.823Z,1517966355.823 [MassServo](DEBUG): Initializing EZServoServo.
2018-02-07T01:19:15.829Z,1517966355.829 [MassServo](DEBUG): Initializing MassServo.
2018-02-07T01:19:15.835Z,1517966355.835 [RudderServo](DEBUG): Initializing EZServoServo.
2018-02-07T01:19:15.841Z,1517966355.841 [RudderServo](DEBUG): Initializing RudderServo.
2018-02-07T01:19:15.846Z,1517966355.846 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-02-07T01:19:15.853Z,1517966355.853 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-02-07T01:19:15.878Z,1517966355.878 [CommandLine](FAULT): Scheduling is paused
2018-02-07T01:19:15.878Z,1517966355.878 [CBIT](INFO): Critical error at 20180207T011914
2018-02-07T01:19:15.878Z,1517966355.878 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-02-07T01:19:15.994Z,1517966355.994 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-02-07T01:19:15.994Z,1517966355.994 [DropWeight] Hardware Fault, FailCount= 1
2018-02-07T01:19:15.994Z,1517966355.994 [DropWeight](ERROR): Hardware Fault
2018-02-07T01:19:16.022Z,1517966356.022 [PNI_TCM](INFO): Starting
2018-02-07T01:19:16.055Z,1517966356.055 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:16.056Z,1517966356.056 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:16.081Z,1517966356.081 [CBIT](INFO): Critical error at 20180207T011915
2018-02-07T01:19:16.083Z,1517966356.083 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-02-07T01:19:16.084Z,1517966356.084 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-02-07T01:19:16.338Z,1517966356.338 [PNI_TCM](INFO): Starting
2018-02-07T01:19:16.363Z,1517966356.363 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:16.364Z,1517966356.364 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:16.701Z,1517966356.701 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-02-07T01:19:16.701Z,1517966356.701 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-02-07T01:19:16.701Z,1517966356.701 [BuoyancyServo] Communications Fault, FailCount= 1
2018-02-07T01:19:16.701Z,1517966356.701 [BuoyancyServo](ERROR): Communications Fault
2018-02-07T01:19:16.911Z,1517966356.911 [CBIT](INFO): Critical error at 20180207T011916
2018-02-07T01:19:16.913Z,1517966356.913 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-02-07T01:19:16.943Z,1517966356.943 [PNI_TCM](INFO): Starting
2018-02-07T01:19:16.970Z,1517966356.970 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:16.971Z,1517966356.971 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:16.984Z,1517966356.984 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-02-07T01:19:16.993Z,1517966356.993 [BuoyancyServo](INFO): Powering down
2018-02-07T01:19:17.342Z,1517966357.342 [PNI_TCM](INFO): Starting
2018-02-07T01:19:17.394Z,1517966357.394 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:17.395Z,1517966357.395 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:17.742Z,1517966357.742 [PNI_TCM](INFO): Starting
2018-02-07T01:19:17.773Z,1517966357.773 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:17.781Z,1517966357.781 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:18.143Z,1517966358.143 [PNI_TCM](INFO): Starting
2018-02-07T01:19:18.173Z,1517966358.173 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:18.174Z,1517966358.174 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:18.541Z,1517966358.541 [PNI_TCM](INFO): Starting
2018-02-07T01:19:18.673Z,1517966358.673 [Aanderaa_O2](INFO): Powering down
2018-02-07T01:19:18.752Z,1517966358.752 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:18.761Z,1517966358.761 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-07T01:19:19.054Z,1517966359.054 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-02-07T01:19:19.054Z,1517966359.054 [BuoyancyServo] No Fault, FailCount= 1
2018-02-07T01:19:19.382Z,1517966359.382 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-02-07T01:19:19.502Z,1517966359.502 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-02-07T01:19:20.437Z,1517966360.437 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-02-07T01:19:20.612Z,1517966360.612 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null &
2018-02-07T01:19:20.662Z,1517966360.662 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-02-07T01:19:21.131Z,1517966361.131 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-02-07T01:19:21.131Z,1517966361.131 [CTD_Seabird](INFO): Powering down
2018-02-07T01:19:22.552Z,1517966362.552 [AcousticModem_Benthos_ATM900](DEBUG): 
2018-02-07T01:19:23.755Z,1517966363.755 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-02-07T01:19:23.755Z,1517966363.755 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-02-07T01:19:23.756Z,1517966363.756 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-02-07T01:19:23.757Z,1517966363.757 [AcousticModem_Benthos_ATM900](DEBUG): Feb 28 2000 15:47:01 
2018-02-07T01:19:24.553Z,1517966364.553 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-02-07T01:19:25.352Z,1517966365.352 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-02-07T01:19:25.752Z,1517966365.752 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-02-07T01:19:25.753Z,1517966365.753 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-02-07T01:19:25.753Z,1517966365.753 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-02-07T01:19:26.152Z,1517966366.152 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-02-07T01:19:26.552Z,1517966366.552 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-02-07T01:19:26.553Z,1517966366.553 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-02-07T01:19:26.953Z,1517966366.953 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-02-07T01:19:41.758Z,1517966381.758 [NAL9602](INFO): Powering up NAL9602
2018-02-07T01:19:50.989Z,1517966390.989 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:19:50.989Z,1517966390.989 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:19:50.989Z,1517966390.989 [BPC1](ERROR): Communications Fault
2018-02-07T01:19:51.093Z,1517966391.093 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:19:52.234Z,1517966392.234 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:19:52.234Z,1517966392.234 [BPC1] No Fault, FailCount= 1
2018-02-07T01:19:52.958Z,1517966392.958 [NAL9602](INFO): NAL9602 initialized
2018-02-07T01:20:07.432Z,1517966407.432 [SBIT](IMPORTANT): Beginning Startup BIT
2018-02-07T01:20:07.440Z,1517966407.440 [CBIT](IMPORTANT): Beginning ground fault scan
2018-02-07T01:20:18.402Z,1517966418.402 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007461
CHAN A1 (24V): -0.012446
CHAN A2 (12V): -0.005543
CHAN A3 (5V): -0.002667
CHAN B0 (3.3V): -0.001404
CHAN B1 (3.15aV): -0.001358
CHAN B2 (3.15bV): -0.001547
CHAN B3 (GND): -0.000154
OPEN: 0.004703
Full Scale Calc: 4.765 mA, -1.589 mA
2018-02-07T01:21:01.458Z,1517966461.458 [SBIT](IMPORTANT): SBIT PASSED
2018-02-07T01:21:01.855Z,1517966461.855 [MissionManager](IMPORTANT): Started mission Startup
2018-02-07T01:21:01.856Z,1517966461.856 [Startup] Running Loop=1
2018-02-07T01:21:01.856Z,1517966461.856 [Startup](DEBUG): Aggregate::initialize Startup
2018-02-07T01:21:01.856Z,1517966461.856 [Startup:A.GoToSurface] Running Loop=1
2018-02-07T01:21:01.856Z,1517966461.856 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-02-07T01:21:01.857Z,1517966461.857 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-02-07T01:21:01.857Z,1517966461.857 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-02-07T01:21:01.858Z,1517966461.858 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-02-07T01:21:01.858Z,1517966461.858 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-02-07T01:21:01.858Z,1517966461.858 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-02-07T01:21:01.864Z,1517966461.864 [Startup:StartupSatComms] Running Loop=1
2018-02-07T01:21:01.864Z,1517966461.864 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-02-07T01:21:01.864Z,1517966461.864 [Startup:StartupSatComms:A] Running Loop=1
2018-02-07T01:21:02.256Z,1517966462.256 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-02-07T01:21:32.631Z,1517966492.631 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:21:32.631Z,1517966492.631 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:21:32.631Z,1517966492.631 [BPC1](ERROR): Communications Fault
2018-02-07T01:21:32.652Z,1517966492.652 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:21:33.863Z,1517966493.863 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:21:33.863Z,1517966493.863 [BPC1] No Fault, FailCount= 1
2018-02-07T01:22:02.246Z,1517966522.246 [Startup:StartupSatComms:A](INFO): Timed out from 2018-02-07T01:21:01.9Z
2018-02-07T01:22:02.246Z,1517966522.246 [Startup:StartupSatComms:A] Stopped
2018-02-07T01:22:02.246Z,1517966522.246 [Startup:StartupSatComms:B] Running Loop=1
2018-02-07T01:22:02.630Z,1517966522.630 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-02-07T01:22:15.061Z,1517966535.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-02-07T01:22:15.061Z,1517966535.061 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-02-07T01:22:15.061Z,1517966535.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-02-07T01:22:15.063Z,1517966535.063 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-02-07T01:22:15.063Z,1517966535.063 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-02-07T01:22:15.063Z,1517966535.063 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-02-07T01:22:15.083Z,1517966535.083 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-02-07T01:22:15.083Z,1517966535.083 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-02-07T01:22:15.453Z,1517966535.453 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-02-07T01:22:15.454Z,1517966535.454 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-02-07T01:22:15.454Z,1517966535.454 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-02-07T01:22:15.454Z,1517966535.454 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-02-07T01:22:15.844Z,1517966535.844 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-02-07T01:22:15.849Z,1517966535.849 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-02-07T01:22:15.853Z,1517966535.853 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-02-07T01:22:15.853Z,1517966535.853 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-02-07T01:22:15.854Z,1517966535.854 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-02-07T01:22:15.854Z,1517966535.854 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-02-07T01:22:16.243Z,1517966536.243 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2018-02-07T01:22:16.657Z,1517966536.657 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2018-02-07T01:22:19.774Z,1517966539.774 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.7 s old, using for 20.0 s.
2018-02-07T01:22:19.912Z,1517966539.912 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s.
2018-02-07T01:22:20.284Z,1517966540.284 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2018-02-07T01:22:20.625Z,1517966540.625 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003328
2018-02-07T01:22:20.702Z,1517966540.702 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2018-02-07T01:22:21.659Z,1517966541.659 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.6 s old, using for 20.0 s.
2018-02-07T01:22:21.766Z,1517966541.766 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.7 s old, using for 20.0 s.
2018-02-07T01:22:24.848Z,1517966544.848 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.8 s old, using for 20.0 s.
2018-02-07T01:22:24.891Z,1517966544.891 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180207T011228/Courier0004.lzma
2018-02-07T01:22:24.984Z,1517966544.984 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.9 s old, using for 20.0 s.
2018-02-07T01:22:25.322Z,1517966545.322 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.3 s old, using for 20.0 s.
2018-02-07T01:22:25.670Z,1517966545.670 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011228/Courier0004.lzma.bak
2018-02-07T01:22:25.670Z,1517966545.670 [DataOverHttps](INFO): SBD MOMSN=7830421
2018-02-07T01:22:25.740Z,1517966545.740 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.7 s old, using for 20.0 s.
2018-02-07T01:22:26.721Z,1517966546.721 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2018-02-07T01:22:26.844Z,1517966546.844 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.8 s old, using for 20.0 s.
2018-02-07T01:22:29.927Z,1517966549.927 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.9 s old, using for 20.0 s.
2018-02-07T01:22:30.067Z,1517966550.067 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.0 s old, using for 20.0 s.
2018-02-07T01:22:30.395Z,1517966550.395 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.3 s old, using for 20.0 s.
2018-02-07T01:22:30.791Z,1517966550.791 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.7 s old, using for 20.0 s.
2018-02-07T01:22:31.214Z,1517966551.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.2 s old, using for 20.0 s.
2018-02-07T01:22:31.599Z,1517966551.599 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.5 s old, using for 20.0 s.
2018-02-07T01:22:34.706Z,1517966554.706 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2018-02-07T01:22:34.754Z,1517966554.754 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20180207T011611/Courier0000.lzma
2018-02-07T01:22:34.851Z,1517966554.851 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.8 s old, using for 20.0 s.
2018-02-07T01:22:35.554Z,1517966555.554 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011611/Courier0000.lzma.bak
2018-02-07T01:22:35.554Z,1517966555.554 [DataOverHttps](INFO): SBD MOMSN=7830423
2018-02-07T01:22:35.604Z,1517966555.604 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:22:35.604Z,1517966555.604 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:22:35.605Z,1517966555.605 [BPC1](ERROR): Communications Fault
2018-02-07T01:22:35.654Z,1517966555.654 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:22:39.778Z,1517966559.778 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:22:39.778Z,1517966559.778 [BPC1] No Fault, FailCount= 1
2018-02-07T01:22:48.202Z,1517966568.202 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20180207T011905/Courier0000.lzma
2018-02-07T01:22:48.990Z,1517966568.990 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011905/Courier0000.lzma.bak
2018-02-07T01:22:48.990Z,1517966568.990 [DataOverHttps](INFO): SBD MOMSN=7830429
2018-02-07T01:23:05.523Z,1517966585.523 [Startup:StartupSatComms:B](INFO): Timed out from 2018-02-07T01:22:02.2Z
2018-02-07T01:23:05.523Z,1517966585.523 [Startup:StartupSatComms:B] Stopped
2018-02-07T01:23:05.523Z,1517966585.523 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-02-07T01:23:05.523Z,1517966585.523 [Startup:StartupSatComms] Stopped
2018-02-07T01:23:05.523Z,1517966585.523 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-02-07T01:23:05.524Z,1517966585.524 [Startup](INFO): Completed Startup
2018-02-07T01:23:05.524Z,1517966585.524 [MissionManager](INFO): Startup is completed.
2018-02-07T01:23:05.524Z,1517966585.524 [MissionManager](INFO): Uninitializing Mission Startup
2018-02-07T01:23:05.524Z,1517966585.524 [Startup] Stopped
2018-02-07T01:23:05.524Z,1517966585.524 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-02-07T01:23:05.524Z,1517966585.524 [Startup:A.GoToSurface] Stopped
2018-02-07T01:23:05.525Z,1517966585.525 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-02-07T01:23:05.544Z,1517966585.544 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20180207T010314/Express0009.lzma
2018-02-07T01:23:05.676Z,1517966585.676 [MissionManager](IMPORTANT): Started mission Default
2018-02-07T01:23:05.681Z,1517966585.681 [Default] Running Loop=1
2018-02-07T01:23:05.681Z,1517966585.681 [Default](DEBUG): Aggregate::initialize Default
2018-02-07T01:23:05.681Z,1517966585.681 [Default:B.GoToSurface] Running Loop=1
2018-02-07T01:23:05.681Z,1517966585.681 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-02-07T01:23:05.681Z,1517966585.681 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-02-07T01:23:05.682Z,1517966585.682 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-02-07T01:23:05.682Z,1517966585.682 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-02-07T01:23:05.682Z,1517966585.682 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-02-07T01:23:05.683Z,1517966585.683 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-02-07T01:23:05.683Z,1517966585.683 [Default:A.Wait] Running Loop=1
2018-02-07T01:23:05.683Z,1517966585.683 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-02-07T01:23:06.346Z,1517966586.346 [DataOverHttps](INFO): Moved sent file to Logs/20180207T010314/Express0009.lzma.bak
2018-02-07T01:23:06.346Z,1517966586.346 [DataOverHttps](INFO): SBD MOMSN=7830435
2018-02-07T01:23:18.399Z,1517966598.399 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:23:18.399Z,1517966598.399 [BPC1] Communications Fault, FailCount= 2
2018-02-07T01:23:18.399Z,1517966598.399 [BPC1](ERROR): Communications Fault
2018-02-07T01:23:18.420Z,1517966598.420 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:23:18.811Z,1517966598.811 [Default:A.Wait](INFO): Done Waiting.
2018-02-07T01:23:18.811Z,1517966598.811 [Default:A.Wait] Stopped
2018-02-07T01:23:18.811Z,1517966598.811 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-02-07T01:23:19.213Z,1517966599.213 [Default:CheckIn] Running Loop=1
2018-02-07T01:23:19.213Z,1517966599.213 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-02-07T01:23:19.213Z,1517966599.213 [Default:CheckIn:Read_GPS] Running Loop=1
2018-02-07T01:23:19.615Z,1517966599.615 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-02-07T01:23:19.627Z,1517966599.627 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:23:19.627Z,1517966599.627 [BPC1] No Fault, FailCount= 2
2018-02-07T01:23:59.212Z,1517966639.212 [NAL9602](INFO): SBD MO Status=2, MOMSN=21449, MT Status=2, MTMSN=0
2018-02-07T01:23:59.212Z,1517966639.212 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-02-07T01:24:30.420Z,1517966670.420 [NAL9602](INFO): SBD MO Status=2, MOMSN=21449, MT Status=2, MTMSN=0
2018-02-07T01:24:30.420Z,1517966670.420 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-02-07T01:24:44.050Z,1517966684.050 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:24:44.051Z,1517966684.051 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:24:44.051Z,1517966684.051 [BPC1](ERROR): Communications Fault
2018-02-07T01:24:44.076Z,1517966684.076 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:24:45.272Z,1517966685.272 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:24:45.272Z,1517966685.272 [BPC1] No Fault, FailCount= 1
2018-02-07T01:24:56.019Z,1517966696.019 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-02-07T01:25:07.223Z,1517966707.223 [NAL9602](INFO): GPS fix at 20180207T011736: (36.802642, -121.788233)
2018-02-07T01:25:07.294Z,1517966707.294 [Default:CheckIn:Read_GPS] Stopped
2018-02-07T01:25:07.294Z,1517966707.294 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-02-07T01:25:11.484Z,1517966711.484 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-02-07T01:25:13.159Z,1517966713.159 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20180207T011905/Courier0004.lzma
2018-02-07T01:25:13.706Z,1517966713.706 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011905/Courier0004.lzma.bak
2018-02-07T01:25:13.706Z,1517966713.706 [DataOverHttps](INFO): SBD MOMSN=7830438
2018-02-07T01:25:26.402Z,1517966726.402 [DataOverHttps](INFO): Sending 613 bytes from file Logs/20180207T011228/Express0001.lzma
2018-02-07T01:25:27.171Z,1517966727.171 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011228/Express0001.lzma.bak
2018-02-07T01:25:27.172Z,1517966727.172 [DataOverHttps](INFO): SBD MOMSN=7830441
2018-02-07T01:25:28.844Z,1517966728.844 [BPC1](ERROR): Failed to parse Bank A battery data
2018-02-07T01:25:28.844Z,1517966728.844 [BPC1] Data Fault, FailCount= 1
2018-02-07T01:25:28.844Z,1517966728.844 [BPC1](ERROR): Data Fault
2018-02-07T01:25:28.921Z,1517966728.921 [CBIT](ERROR): Data Fault in component: BPC1
2018-02-07T01:25:32.317Z,1517966732.317 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:25:32.317Z,1517966732.317 [BPC1] No Fault, FailCount= 1
2018-02-07T01:25:37.034Z,1517966737.034 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20180207T011228/Express0005.lzma
2018-02-07T01:25:37.834Z,1517966737.834 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011228/Express0005.lzma.bak
2018-02-07T01:25:37.834Z,1517966737.834 [DataOverHttps](INFO): SBD MOMSN=7830453
2018-02-07T01:25:43.425Z,1517966743.425 [NAL9602](INFO): Powering down
2018-02-07T01:25:47.855Z,1517966747.855 [DataOverHttps](INFO): Sending 598 bytes from file Logs/20180207T011611/Express0001.lzma
2018-02-07T01:25:48.642Z,1517966748.642 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011611/Express0001.lzma.bak
2018-02-07T01:25:48.642Z,1517966748.642 [DataOverHttps](INFO): SBD MOMSN=7830456
2018-02-07T01:26:00.208Z,1517966760.208 [DataOverHttps](INFO): Sending 609 bytes from file Logs/20180207T011905/Express0001.lzma
2018-02-07T01:26:00.966Z,1517966760.966 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011905/Express0001.lzma.bak
2018-02-07T01:26:00.966Z,1517966760.966 [DataOverHttps](INFO): SBD MOMSN=7830468
2018-02-07T01:26:10.682Z,1517966770.682 [DataOverHttps](INFO): Sending 301 bytes from file Logs/20180207T011905/Express0005.lzma
2018-02-07T01:26:11.482Z,1517966771.482 [DataOverHttps](INFO): Moved sent file to Logs/20180207T011905/Express0005.lzma.bak
2018-02-07T01:26:11.482Z,1517966771.482 [DataOverHttps](INFO): SBD MOMSN=7830480
2018-02-07T01:26:13.118Z,1517966773.118 [Default:CheckIn:Read_Iridium] Stopped
2018-02-07T01:26:13.118Z,1517966773.118 [Default:CheckIn:C.Wait] Running Loop=1
2018-02-07T01:26:13.118Z,1517966773.118 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-02-07T01:26:17.241Z,1517966777.241 [PNI_TCM](ERROR): CRC does not match. Expected:0x25900 got:0x1347
2018-02-07T01:26:36.433Z,1517966796.433 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:26:36.433Z,1517966796.433 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:26:36.433Z,1517966796.433 [BPC1](ERROR): Communications Fault
2018-02-07T01:26:36.515Z,1517966796.515 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:26:37.696Z,1517966797.696 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:26:37.696Z,1517966797.696 [BPC1] No Fault, FailCount= 1
2018-02-07T01:28:05.243Z,1517966885.243 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:28:05.243Z,1517966885.243 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:28:05.243Z,1517966885.243 [BPC1](ERROR): Communications Fault
2018-02-07T01:28:05.274Z,1517966885.274 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:28:06.474Z,1517966886.474 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:28:06.474Z,1517966886.474 [BPC1] No Fault, FailCount= 1
2018-02-07T01:28:42.429Z,1517966922.429 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:28:42.429Z,1517966922.429 [BPC1] Communications Fault, FailCount= 2
2018-02-07T01:28:42.429Z,1517966922.429 [BPC1](ERROR): Communications Fault
2018-02-07T01:28:42.523Z,1517966922.523 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:28:43.667Z,1517966923.667 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:28:43.667Z,1517966923.667 [BPC1] No Fault, FailCount= 2
2018-02-07T01:29:17.314Z,1517966957.314 [CBIT](DEBUG): EFC running - data check-sum false
2018-02-07T01:29:32.157Z,1517966972.157 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:29:32.157Z,1517966972.157 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:29:32.157Z,1517966972.157 [BPC1](ERROR): Communications Fault
2018-02-07T01:29:32.216Z,1517966972.216 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:29:33.397Z,1517966973.397 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:29:33.397Z,1517966973.397 [BPC1] No Fault, FailCount= 1
2018-02-07T01:30:09.356Z,1517967009.356 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:30:09.356Z,1517967009.356 [BPC1] Communications Fault, FailCount= 2
2018-02-07T01:30:09.356Z,1517967009.356 [BPC1](ERROR): Communications Fault
2018-02-07T01:30:09.380Z,1517967009.380 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:30:10.601Z,1517967010.601 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:30:10.601Z,1517967010.601 [BPC1] No Fault, FailCount= 2
2018-02-07T01:30:42.726Z,1517967042.726 [BPC1](ERROR): Failed to parse Bank A battery data
2018-02-07T01:30:42.726Z,1517967042.726 [BPC1] Data Fault, FailCount= 1
2018-02-07T01:30:42.726Z,1517967042.726 [BPC1](ERROR): Data Fault
2018-02-07T01:30:42.750Z,1517967042.750 [CBIT](ERROR): Data Fault in component: BPC1
2018-02-07T01:30:43.974Z,1517967043.974 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:30:43.974Z,1517967043.974 [BPC1] No Fault, FailCount= 1
2018-02-07T01:31:13.541Z,1517967073.541 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-02-07T01:31:13.541Z,1517967073.541 [Default:CheckIn:C.Wait] Stopped
2018-02-07T01:31:13.541Z,1517967073.541 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-02-07T01:31:13.541Z,1517967073.541 [Default:CheckIn:D] Running Loop=1
2018-02-07T01:31:13.950Z,1517967073.950 [Default:CheckIn:D] Stopped
2018-02-07T01:31:13.950Z,1517967073.950 [Default:CheckIn:E] Running Loop=1
2018-02-07T01:31:14.341Z,1517967074.341 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.137781 min 
2018-02-07T01:31:14.343Z,1517967074.343 [Default:CheckIn:E] Stopped
2018-02-07T01:31:14.343Z,1517967074.343 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-02-07T01:31:14.343Z,1517967074.343 [Default:CheckIn] Stopped
2018-02-07T01:31:14.343Z,1517967074.343 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-02-07T01:31:14.343Z,1517967074.343 [Default:CheckIn](INFO): Running loop #2
2018-02-07T01:31:14.344Z,1517967074.344 [Default:CheckIn] Running Loop=2
2018-02-07T01:31:14.344Z,1517967074.344 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-02-07T01:31:14.344Z,1517967074.344 [Default:CheckIn:Read_GPS] Running Loop=1
2018-02-07T01:31:17.552Z,1517967077.552 [NAL9602](INFO): Powering up
2018-02-07T01:31:28.734Z,1517967088.734 [NAL9602](INFO): NAL9602 initialized
2018-02-07T01:31:32.362Z,1517967092.362 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:31:32.362Z,1517967092.362 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:31:32.362Z,1517967092.362 [BPC1](ERROR): Communications Fault
2018-02-07T01:31:32.439Z,1517967092.439 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:31:33.619Z,1517967093.619 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:31:33.619Z,1517967093.619 [BPC1] No Fault, FailCount= 1
2018-02-07T01:32:00.734Z,1517967120.734 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2018-02-07T01:32:00.809Z,1517967120.809 [NAL9602](FAULT): received: 
+CSQ:0

OK449, 2, 0, 0, 0

OK
2018-02-07T01:32:00.809Z,1517967120.809 [NAL9602] Data Fault, FailCount= 1
2018-02-07T01:32:00.809Z,1517967120.809 [NAL9602](ERROR): Data Fault
2018-02-07T01:32:00.930Z,1517967120.930 [CBIT](ERROR): Data Fault in component: NAL9602
2018-02-07T01:32:01.134Z,1517967121.134 [NAL9602](INFO): Powering down
2018-02-07T01:32:02.011Z,1517967122.011 [CBIT](INFO): Clearing failed state for component NAL9602
2018-02-07T01:32:02.011Z,1517967122.011 [NAL9602] No Fault, FailCount= 1
2018-02-07T01:32:31.194Z,1517967151.194 [NAL9602](INFO): Powering up NAL9602
2018-02-07T01:32:38.017Z,1517967158.017 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:32:38.017Z,1517967158.017 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:32:38.017Z,1517967158.017 [BPC1](ERROR): Communications Fault
2018-02-07T01:32:38.087Z,1517967158.087 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:32:39.297Z,1517967159.297 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:32:39.297Z,1517967159.297 [BPC1] No Fault, FailCount= 1
2018-02-07T01:32:42.386Z,1517967162.386 [NAL9602](INFO): NAL9602 initialized
2018-02-07T01:33:26.659Z,1517967206.659 [BPC1](ERROR): Failed to receive battery data
2018-02-07T01:33:26.659Z,1517967206.659 [BPC1] Communications Fault, FailCount= 1
2018-02-07T01:33:26.659Z,1517967206.659 [BPC1](ERROR): Communications Fault
2018-02-07T01:33:26.716Z,1517967206.716 [CBIT](ERROR): Communications Fault in component: BPC1
2018-02-07T01:33:27.952Z,1517967207.952 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:33:27.952Z,1517967207.952 [BPC1] No Fault, FailCount= 1
2018-02-07T01:34:17.883Z,1517967257.883 [CBIT](INFO): Clearing failed state for component DropWeight
2018-02-07T01:34:17.883Z,1517967257.883 [DropWeight] No Fault, FailCount= 1
2018-02-07T01:34:19.131Z,1517967259.131 [BPC1](ERROR): Failed to parse message.
2018-02-07T01:34:19.131Z,1517967259.131 [BPC1](ERROR): Failed to parse Bank A battery data
2018-02-07T01:34:19.131Z,1517967259.131 [BPC1] Data Fault, FailCount= 1
2018-02-07T01:34:19.132Z,1517967259.132 [BPC1](ERROR): Data Fault
2018-02-07T01:34:19.197Z,1517967259.197 [CBIT](ERROR): Data Fault in component: BPC1
2018-02-07T01:34:20.384Z,1517967260.384 [CBIT](INFO): Clearing failed state for component BPC1
2018-02-07T01:34:20.384Z,1517967260.384 [BPC1] No Fault, FailCount= 1
2018-02-07T01:34:26.703Z,1517967266.703 [NAL9602](INFO): SBD MO Status=2, MOMSN=21449, MT Status=2, MTMSN=0
2018-02-07T01:34:26.704Z,1517967266.704 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-02-07T01:34:45.100Z,1517967285.100 [NAL9602](INFO): SBD MO Status=2, MOMSN=21449, MT Status=2, MTMSN=0
2018-02-07T01:34:45.100Z,1517967285.100 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-02-07T01:35:14.135Z,1517967314.135 [CommandLine](IMPORTANT): got command restart application
2018-02-07T01:35:15.148Z,1517967315.148 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-07T01:35:15.148Z,1517967315.148 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:15.229Z,1517967315.229 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-02-07T01:35:15.229Z,1517967315.229 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:15.230Z,1517967315.230 [CommandLine](INFO): Join timeout helper Thread ID is 4261
2018-02-07T01:35:15.237Z,1517967315.237 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-02-07T01:35:15.237Z,1517967315.237 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:15.237Z,1517967315.237 [NavChartDb](INFO): Join timeout helper Thread ID is 4262
2018-02-07T01:35:15.565Z,1517967315.565 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-07T01:35:15.565Z,1517967315.565 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:15.573Z,1517967315.573 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-02-07T01:35:15.573Z,1517967315.573 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:15.573Z,1517967315.573 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4263
2018-02-07T01:35:15.673Z,1517967315.673 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-07T01:35:15.673Z,1517967315.673 [WetLabsBB2FL](INFO): Powering down
2018-02-07T01:35:15.674Z,1517967315.674 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:15.693Z,1517967315.693 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-02-07T01:35:15.693Z,1517967315.693 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:15.693Z,1517967315.693 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4264
2018-02-07T01:35:15.977Z,1517967315.977 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-07T01:35:16.134Z,1517967316.134 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-02-07T01:35:16.134Z,1517967316.134 [CTD_Seabird](INFO): Powering down
2018-02-07T01:35:16.135Z,1517967316.135 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:16.145Z,1517967316.145 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-02-07T01:35:16.145Z,1517967316.145 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:16.146Z,1517967316.146 [Radio_Surface](INFO): Join timeout helper Thread ID is 4266
2018-02-07T01:35:16.217Z,1517967316.217 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-07T01:35:16.217Z,1517967316.217 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:16.238Z,1517967316.238 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-02-07T01:35:16.238Z,1517967316.238 [logger ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:16.238Z,1517967316.238 [logger](INFO): Join timeout helper Thread ID is 4267
2018-02-07T01:35:16.245Z,1517967316.245 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-07T01:35:16.245Z,1517967316.245 [logger ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:16.250Z,1517967316.250 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-02-07T01:35:16.250Z,1517967316.250 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:16.250Z,1517967316.250 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-02-07T01:35:16.250Z,1517967316.250 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:16.251Z,1517967316.251 [controlThread](INFO): Join timeout helper Thread ID is 4268
2018-02-07T01:35:17.971Z,1517967317.971 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-07T01:35:17.971Z,1517967317.971 [controlThread](DEBUG): Uninitializing ControlThread
2018-02-07T01:35:17.972Z,1517967317.972 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-02-07T01:35:18.096Z,1517967318.096 [NAL9602](INFO): Powering down
2018-02-07T01:35:18.098Z,1517967318.098 [PNI_TCM](INFO): uninitialize
2018-02-07T01:35:18.098Z,1517967318.098 [PNI_TCM](INFO): Powering down
2018-02-07T01:35:18.186Z,1517967318.186 [Aanderaa_O2](INFO): Powering down
2018-02-07T01:35:18.187Z,1517967318.187 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-02-07T01:35:18.188Z,1517967318.188 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-02-07T01:35:18.189Z,1517967318.189 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-02-07T01:35:18.189Z,1517967318.189 [MissionManager](INFO): Uninitializing Mission Default
2018-02-07T01:35:18.190Z,1517967318.190 [Default] Stopped
2018-02-07T01:35:18.190Z,1517967318.190 [Default](DEBUG): Aggregate::uninitialize Default
2018-02-07T01:35:18.190Z,1517967318.190 [Default:B.GoToSurface] Stopped
2018-02-07T01:35:18.190Z,1517967318.190 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-02-07T01:35:18.190Z,1517967318.190 [Default:CheckIn] Stopped
2018-02-07T01:35:18.190Z,1517967318.190 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-02-07T01:35:18.190Z,1517967318.190 [Default:CheckIn:Read_GPS] Stopped
2018-02-07T01:35:18.193Z,1517967318.193 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-02-07T01:35:18.194Z,1517967318.194 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-02-07T01:35:18.194Z,1517967318.194 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-02-07T01:35:18.194Z,1517967318.194 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-02-07T01:35:18.195Z,1517967318.195 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-02-07T01:35:18.195Z,1517967318.195 [BuoyancyServo](INFO): Powering down
2018-02-07T01:35:18.209Z,1517967318.209 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-02-07T01:35:18.209Z,1517967318.209 [ElevatorServo](INFO): Powering down
2018-02-07T01:35:18.210Z,1517967318.210 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-02-07T01:35:18.210Z,1517967318.210 [MassServo](INFO): Powering down
2018-02-07T01:35:18.211Z,1517967318.211 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-02-07T01:35:18.211Z,1517967318.211 [RudderServo](INFO): Powering down
2018-02-07T01:35:18.211Z,1517967318.211 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-02-07T01:35:18.211Z,1517967318.211 [ThrusterServo](INFO): Powering down
2018-02-07T01:35:18.212Z,1517967318.212 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-02-07T01:35:18.213Z,1517967318.213 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-02-07T01:35:18.213Z,1517967318.213 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-02-07T01:35:18.214Z,1517967318.214 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:18.298Z,1517967318.298 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:18.338Z,1517967318.338 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:18.341Z,1517967318.341 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:18.387Z,1517967318.387 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-02-07T01:35:18.455Z,1517967318.455 [logger ThreadHandler](INFO): Thread cancelled.