2018-11-06T20:02:17.878Z,1541534537.878 [Supervisor](DEBUG): Initializing supervisor.
2018-11-06T20:02:17.881Z,1541534537.881 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-11-06T20:02:17.881Z,1541534537.881 [SyncHandler](INFO): Protected caller Thread ID is 1589
2018-11-06T20:02:17.882Z,1541534537.882 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-11-06T20:02:17.883Z,1541534537.883 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-11-06T20:02:17.883Z,1541534537.883 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1590
2018-11-06T20:02:17.885Z,1541534537.885 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-11-06T20:02:17.897Z,1541534537.897 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-11-06T20:02:17.898Z,1541534537.898 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-11-06T20:02:17.899Z,1541534537.899 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1591
2018-11-06T20:02:17.899Z,1541534537.899 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-11-06T20:02:17.900Z,1541534537.900 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-11-06T20:02:17.901Z,1541534537.901 [logger ThreadHandler](INFO): Protected caller Thread ID is 1592
2018-11-06T20:02:17.903Z,1541534537.903 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-11-06T20:02:17.903Z,1541534537.903 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-11-06T20:02:17.908Z,1541534537.908 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-11-06T20:02:18.085Z,1541534538.085 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-11-06T20:02:18.086Z,1541534538.086 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-11-06T20:02:18.187Z,1541534538.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-11-06T20:02:18.187Z,1541534538.187 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-11-06T20:02:18.387Z,1541534538.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-11-06T20:02:18.387Z,1541534538.387 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-11-06T20:02:18.722Z,1541534538.722 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-11-06T20:02:18.723Z,1541534538.723 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-11-06T20:02:19.066Z,1541534539.066 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-11-06T20:02:19.067Z,1541534539.067 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-11-06T20:02:19.525Z,1541534539.525 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-11-06T20:02:19.526Z,1541534539.526 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-11-06T20:02:19.987Z,1541534539.987 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-11-06T20:02:19.987Z,1541534539.987 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-11-06T20:02:20.437Z,1541534540.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-11-06T20:02:20.437Z,1541534540.437 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-11-06T20:02:20.518Z,1541534540.518 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-11-06T20:02:20.832Z,1541534540.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-11-06T20:02:20.833Z,1541534540.833 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-11-06T20:02:20.982Z,1541534540.982 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-11-06T20:02:20.983Z,1541534540.983 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-11-06T20:02:21.198Z,1541534541.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-11-06T20:02:21.199Z,1541534541.199 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-11-06T20:02:21.409Z,1541534541.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-11-06T20:02:21.410Z,1541534541.410 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-11-06T20:02:21.508Z,1541534541.508 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-11-06T20:02:21.509Z,1541534541.509 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-11-06T20:02:21.655Z,1541534541.655 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-11-06T20:02:21.657Z,1541534541.657 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-11-06T20:02:21.658Z,1541534541.658 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-11-06T20:02:21.885Z,1541534541.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-11-06T20:02:21.885Z,1541534541.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-11-06T20:02:21.991Z,1541534541.991 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-11-06T20:02:22.142Z,1541534542.142 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-11-06T20:02:22.235Z,1541534542.235 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-11-06T20:02:22.321Z,1541534542.321 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-11-06T20:02:22.477Z,1541534542.477 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-11-06T20:02:22.675Z,1541534542.675 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-11-06T20:02:22.773Z,1541534542.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-11-06T20:02:22.869Z,1541534542.869 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-11-06T20:02:23.008Z,1541534543.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-11-06T20:02:23.194Z,1541534543.194 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-11-06T20:02:23.195Z,1541534543.195 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-11-06T20:02:23.198Z,1541534543.198 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-11-06T20:02:23.344Z,1541534543.344 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-11-06T20:02:23.344Z,1541534543.344 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-11-06T20:02:23.379Z,1541534543.379 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-11-06T20:02:23.380Z,1541534543.380 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-11-06T20:02:23.530Z,1541534543.530 [DepthRateCalculator] Loaded
2018-11-06T20:02:23.531Z,1541534543.531 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-11-06T20:02:23.537Z,1541534543.537 [PitchRateCalculator] Loaded
2018-11-06T20:02:23.537Z,1541534543.537 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-11-06T20:02:23.580Z,1541534543.580 [SpeedCalculator] Loaded
2018-11-06T20:02:23.580Z,1541534543.580 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-11-06T20:02:23.601Z,1541534543.601 [TempGradientCalculator] Loaded
2018-11-06T20:02:23.601Z,1541534543.601 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-11-06T20:02:23.607Z,1541534543.607 [YawRateCalculator] Loaded
2018-11-06T20:02:23.607Z,1541534543.607 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-11-06T20:02:23.699Z,1541534543.699 [ElevatorOffsetCalculator] Loaded
2018-11-06T20:02:23.699Z,1541534543.699 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-11-06T20:02:23.699Z,1541534543.699 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-11-06T20:02:23.700Z,1541534543.700 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-11-06T20:02:23.725Z,1541534543.725 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-11-06T20:02:23.725Z,1541534543.725 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-11-06T20:02:24.000Z,1541534544.000 [AcousticModem_Benthos_ATM900] Loaded
2018-11-06T20:02:24.001Z,1541534544.001 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-11-06T20:02:24.073Z,1541534544.073 [DataOverHttps] Loaded
2018-11-06T20:02:24.073Z,1541534544.073 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-11-06T20:02:24.087Z,1541534544.087 [Depth_Keller] Loaded
2018-11-06T20:02:24.087Z,1541534544.087 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-11-06T20:02:24.092Z,1541534544.092 [DropWeight] Loaded
2018-11-06T20:02:24.092Z,1541534544.092 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-11-06T20:02:24.188Z,1541534544.188 [NAL9602] Loaded
2018-11-06T20:02:24.189Z,1541534544.189 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-11-06T20:02:24.204Z,1541534544.204 [Onboard] Loaded
2018-11-06T20:02:24.205Z,1541534544.205 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-11-06T20:02:24.215Z,1541534544.215 [Radio_Surface] Loaded
2018-11-06T20:02:24.215Z,1541534544.215 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-11-06T20:02:24.216Z,1541534544.216 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407C24E0
2018-11-06T20:02:24.217Z,1541534544.217 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1671
2018-11-06T20:02:24.263Z,1541534544.263 [PNI_TCM] Loaded
2018-11-06T20:02:24.264Z,1541534544.264 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-11-06T20:02:24.324Z,1541534544.324 [Rowe_600LCM] Loaded
2018-11-06T20:02:24.324Z,1541534544.324 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-11-06T20:02:24.325Z,1541534544.325 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 407F24E0
2018-11-06T20:02:24.326Z,1541534544.326 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 1672
2018-11-06T20:02:26.070Z,1541534546.070 [BPC1] Loaded
2018-11-06T20:02:26.070Z,1541534546.070 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-11-06T20:02:26.071Z,1541534546.071 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-11-06T20:02:26.071Z,1541534546.071 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-11-06T20:02:26.201Z,1541534546.201 [SBIT](DEBUG): Construct Startup Built In Test.
2018-11-06T20:02:26.224Z,1541534546.224 [SBIT] Loaded
2018-11-06T20:02:26.225Z,1541534546.225 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-11-06T20:02:26.225Z,1541534546.225 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-11-06T20:02:26.237Z,1541534546.237 [IBIT] Loaded
2018-11-06T20:02:26.237Z,1541534546.237 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-11-06T20:02:26.240Z,1541534546.240 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-11-06T20:02:26.387Z,1541534546.387 [CBIT] Loaded
2018-11-06T20:02:26.388Z,1541534546.388 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-11-06T20:02:26.388Z,1541534546.388 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-11-06T20:02:26.389Z,1541534546.389 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-11-06T20:02:26.547Z,1541534546.547 [Aanderaa_O2] Loaded
2018-11-06T20:02:26.547Z,1541534546.547 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-11-06T20:02:26.603Z,1541534546.603 [CTD_Seabird] Loaded
2018-11-06T20:02:26.604Z,1541534546.604 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-11-06T20:02:26.605Z,1541534546.605 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408BD4E0
2018-11-06T20:02:26.605Z,1541534546.605 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1673
2018-11-06T20:02:26.622Z,1541534546.622 [ESPComponent] Loaded
2018-11-06T20:02:26.623Z,1541534546.623 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2018-11-06T20:02:26.636Z,1541534546.636 [PAR_Licor] Loaded
2018-11-06T20:02:26.637Z,1541534546.637 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-11-06T20:02:26.686Z,1541534546.686 [WetLabsBB2FL] Loaded
2018-11-06T20:02:26.686Z,1541534546.686 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-11-06T20:02:26.687Z,1541534546.687 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408ED4E0
2018-11-06T20:02:26.687Z,1541534546.687 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1674
2018-11-06T20:02:26.688Z,1541534546.688 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-11-06T20:02:26.689Z,1541534546.689 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-11-06T20:02:26.928Z,1541534546.928 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-11-06T20:02:26.928Z,1541534546.928 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-11-06T20:02:26.996Z,1541534546.996 [VerticalControl](DEBUG): Construct VerticalControl.
2018-11-06T20:02:27.092Z,1541534547.092 [VerticalControl] Loaded
2018-11-06T20:02:27.092Z,1541534547.092 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-11-06T20:02:27.093Z,1541534547.093 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-11-06T20:02:27.153Z,1541534547.153 [HorizontalControl] Loaded
2018-11-06T20:02:27.153Z,1541534547.153 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-11-06T20:02:27.154Z,1541534547.154 [SpeedControl](DEBUG): Construct SpeedControl.
2018-11-06T20:02:27.159Z,1541534547.159 [SpeedControl] Loaded
2018-11-06T20:02:27.159Z,1541534547.159 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-11-06T20:02:27.160Z,1541534547.160 [LoopControl](DEBUG): Construct LoopControl.
2018-11-06T20:02:27.161Z,1541534547.161 [LoopControl] Loaded
2018-11-06T20:02:27.161Z,1541534547.161 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-11-06T20:02:27.161Z,1541534547.161 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-11-06T20:02:27.162Z,1541534547.162 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-11-06T20:02:27.226Z,1541534547.226 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-11-06T20:02:27.226Z,1541534547.226 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-11-06T20:02:27.324Z,1541534547.324 [BuoyancyServo] Loaded
2018-11-06T20:02:27.324Z,1541534547.324 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-11-06T20:02:27.336Z,1541534547.336 [ElevatorServo] Loaded
2018-11-06T20:02:27.336Z,1541534547.336 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-11-06T20:02:27.347Z,1541534547.347 [MassServo] Loaded
2018-11-06T20:02:27.347Z,1541534547.347 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-11-06T20:02:27.359Z,1541534547.359 [RudderServo] Loaded
2018-11-06T20:02:27.359Z,1541534547.359 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-11-06T20:02:27.370Z,1541534547.370 [ThrusterServo] Loaded
2018-11-06T20:02:27.370Z,1541534547.370 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-11-06T20:02:27.371Z,1541534547.371 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-11-06T20:02:27.371Z,1541534547.371 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-11-06T20:02:27.460Z,1541534547.460 [DeadReckonUsingSpeedCalculator] Loaded
2018-11-06T20:02:27.461Z,1541534547.461 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-11-06T20:02:27.477Z,1541534547.477 [NavChart] Loaded
2018-11-06T20:02:27.477Z,1541534547.477 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-11-06T20:02:27.481Z,1541534547.481 [UniversalFixResidualReporter] Loaded
2018-11-06T20:02:27.481Z,1541534547.481 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-11-06T20:02:27.482Z,1541534547.482 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-11-06T20:02:27.485Z,1541534547.485 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-11-06T20:02:27.486Z,1541534547.486 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-11-06T20:02:27.493Z,1541534547.493 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-11-06T20:02:27.494Z,1541534547.494 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A464E0
2018-11-06T20:02:27.494Z,1541534547.494 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1675
2018-11-06T20:02:27.499Z,1541534547.499 [Supervisor](INFO): Main Thread ID is 795
2018-11-06T20:02:27.499Z,1541534547.499 [Supervisor](DEBUG): Running supervisor.
2018-11-06T20:02:27.500Z,1541534547.500 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1676
2018-11-06T20:02:27.502Z,1541534547.502 [controlThread ThreadHandler](INFO): Handler Thread ID is 1677
2018-11-06T20:02:27.503Z,1541534547.503 [controlThread](DEBUG): Initializing ControlThread
2018-11-06T20:02:27.503Z,1541534547.503 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T20:02:27.504Z,1541534547.504 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-11-06T20:02:27.504Z,1541534547.504 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-11-06T20:02:27.504Z,1541534547.504 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-11-06T20:02:27.505Z,1541534547.505 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-11-06T20:02:27.505Z,1541534547.505 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-11-06T20:02:27.512Z,1541534547.512 [SBIT](INFO): Initialize SBIT Component.
2018-11-06T20:02:27.513Z,1541534547.513 [SBIT](IMPORTANT): git: 2018-10-09-28-gfb31231
2018-11-06T20:02:27.513Z,1541534547.513 [SBIT](INFO): git hash: fb31231d9cfa0398c7caa27b55986cf0267a1f2c
2018-11-06T20:02:27.513Z,1541534547.513 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-11-06T20:02:27.514Z,1541534547.514 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-11-06T20:02:27.515Z,1541534547.515 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2018-11-06T20:02:27.515Z,1541534547.515 [IBIT](INFO): Initialize IBIT Component.
2018-11-06T20:02:27.516Z,1541534547.516 [CBIT](DEBUG): Initialize CBIT Component.
2018-11-06T20:02:27.516Z,1541534547.516 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-11-06T20:02:27.517Z,1541534547.517 [logger ThreadHandler](INFO): Handler Thread ID is 1678
2018-11-06T20:02:27.535Z,1541534547.535 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1679
2018-11-06T20:02:27.541Z,1541534547.541 [Radio_Surface](INFO): Powering up
2018-11-06T20:02:27.546Z,1541534547.546 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 1680
2018-11-06T20:02:27.547Z,1541534547.547 [Rowe_600LCM](INFO): Initializing
2018-11-06T20:02:27.548Z,1541534547.548 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T20:02:27.557Z,1541534547.557 [Rowe_600LCM](INFO): LCM OK
2018-11-06T20:02:27.557Z,1541534547.557 [Rowe_600LCM](INFO): Powering up
2018-11-06T20:02:27.563Z,1541534547.563 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1681
2018-11-06T20:02:27.563Z,1541534547.563 [CTD_Seabird](INFO): Initializing
2018-11-06T20:02:27.564Z,1541534547.564 [CTD_Seabird](INFO): Checking LCM
2018-11-06T20:02:27.564Z,1541534547.564 [CTD_Seabird](INFO): LCM OK
2018-11-06T20:02:27.564Z,1541534547.564 [CTD_Seabird](INFO): Powering up
2018-11-06T20:02:27.570Z,1541534547.570 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1682
2018-11-06T20:02:27.572Z,1541534547.572 [WetLabsBB2FL](INFO): Powering down
2018-11-06T20:02:27.594Z,1541534547.594 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1683
2018-11-06T20:02:27.597Z,1541534547.597 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-11-06T20:02:27.598Z,1541534547.598 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-11-06T20:02:27.598Z,1541534547.598 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-11-06T20:02:27.599Z,1541534547.599 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-11-06T20:02:27.599Z,1541534547.599 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-11-06T20:02:27.599Z,1541534547.599 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-11-06T20:02:27.599Z,1541534547.599 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-11-06T20:02:27.599Z,1541534547.599 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-11-06T20:02:27.599Z,1541534547.599 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-11-06T20:02:27.600Z,1541534547.600 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-11-06T20:02:27.600Z,1541534547.600 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-11-06T20:02:27.600Z,1541534547.600 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-11-06T20:02:27.600Z,1541534547.600 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-11-06T20:02:27.600Z,1541534547.600 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-11-06T20:02:27.601Z,1541534547.601 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-11-06T20:02:27.601Z,1541534547.601 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-11-06T20:02:27.626Z,1541534547.626 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-11-06T20:02:27.628Z,1541534547.628 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-11-06T20:02:27.629Z,1541534547.629 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-11-06T20:02:27.629Z,1541534547.629 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-11-06T20:02:27.631Z,1541534547.631 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T20:02:27.632Z,1541534547.632 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T20:02:27.632Z,1541534547.632 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T20:02:27.633Z,1541534547.633 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-11-06T20:02:27.633Z,1541534547.633 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-11-06T20:02:27.634Z,1541534547.634 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-11-06T20:02:27.658Z,1541534547.658 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T20:02:27.689Z,1541534547.689 [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-11-06T20:02:27.690Z,1541534547.690 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-11-06T20:02:27.760Z,1541534547.760 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-11-06T20:02:27.761Z,1541534547.761 [Default:A.Wait](DEBUG): Construct Wait.
2018-11-06T20:02:27.783Z,1541534547.783 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-11-06T20:02:27.809Z,1541534547.809 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-11-06T20:02:27.812Z,1541534547.812 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-11-06T20:02:27.830Z,1541534547.830 [Default:E.Execute](DEBUG): Construct Execute.
2018-11-06T20:02:27.833Z,1541534547.833 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2018-11-06T20:02:27.846Z,1541534547.846 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-11-06T20:02:27.870Z,1541534547.870 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-11-06T20:02:27.871Z,1541534547.871 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-11-06T20:02:27.896Z,1541534547.896 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-11-06T20:02:28.205Z,1541534548.205 [ESPComponent](INFO): powering down ESP
2018-11-06T20:02:28.730Z,1541534548.730 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-06T20:02:28.738Z,1541534548.738 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-06T20:02:28.761Z,1541534548.761 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-11-06T20:02:28.766Z,1541534548.766 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-11-06T20:02:28.773Z,1541534548.773 [MassServo](DEBUG): Initializing EZServoServo.
2018-11-06T20:02:28.779Z,1541534548.779 [MassServo](DEBUG): Initializing MassServo.
2018-11-06T20:02:28.801Z,1541534548.801 [RudderServo](DEBUG): Initializing EZServoServo.
2018-11-06T20:02:28.806Z,1541534548.806 [RudderServo](DEBUG): Initializing RudderServo.
2018-11-06T20:02:28.828Z,1541534548.828 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-11-06T20:02:28.834Z,1541534548.834 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-11-06T20:02:28.982Z,1541534548.982 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-11-06T20:02:28.982Z,1541534548.982 [DropWeight] Hardware Fault, FailCount= 1
2018-11-06T20:02:28.982Z,1541534548.982 [DropWeight](ERROR): Hardware Fault
2018-11-06T20:02:29.099Z,1541534549.099 [CommandLine](FAULT): Scheduling is paused
2018-11-06T20:02:29.099Z,1541534549.099 [CBIT](INFO): Critical error at 20181106T200228
2018-11-06T20:02:29.100Z,1541534549.100 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-11-06T20:02:29.102Z,1541534549.102 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-11-06T20:02:29.103Z,1541534549.103 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-11-06T20:02:29.714Z,1541534549.714 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-11-06T20:02:29.714Z,1541534549.714 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-11-06T20:02:29.714Z,1541534549.714 [BuoyancyServo] Communications Fault, FailCount= 1
2018-11-06T20:02:29.714Z,1541534549.714 [BuoyancyServo](ERROR): Communications Fault
2018-11-06T20:02:29.920Z,1541534549.920 [CBIT](INFO): Critical error at 20181106T200229
2018-11-06T20:02:29.922Z,1541534549.922 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-11-06T20:02:29.985Z,1541534549.985 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-06T20:02:29.986Z,1541534549.986 [BuoyancyServo](INFO): Powering down
2018-11-06T20:02:31.821Z,1541534551.821 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T20:02:31.901Z,1541534551.901 [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 9600 >& /dev/null &
2018-11-06T20:02:31.986Z,1541534551.986 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T20:02:31.987Z,1541534551.987 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T20:02:31.988Z,1541534551.988 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T20:02:32.068Z,1541534552.068 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-11-06T20:02:32.068Z,1541534552.068 [BuoyancyServo] No Fault, FailCount= 1
2018-11-06T20:02:32.384Z,1541534552.384 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-11-06T20:02:32.385Z,1541534552.385 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-11-06T20:02:33.076Z,1541534553.076 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-06T20:02:33.258Z,1541534553.258 [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-11-06T20:02:33.260Z,1541534553.260 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd
2018-11-06T20:02:33.719Z,1541534553.719 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-06T20:02:33.719Z,1541534553.719 [CTD_Seabird](INFO): Powering down
2018-11-06T20:02:35.531Z,1541534555.531 [AcousticModem_Benthos_ATM900](DEBUG): 
2018-11-06T20:02:35.552Z,1541534555.552 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:02:35.552Z,1541534555.552 [PNI_TCM] Data Fault, FailCount= 1
2018-11-06T20:02:35.552Z,1541534555.552 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:02:35.644Z,1541534555.644 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:02:35.952Z,1541534555.952 [PNI_TCM](INFO): Powering down
2018-11-06T20:02:36.732Z,1541534556.732 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-11-06T20:02:36.733Z,1541534556.733 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-11-06T20:02:36.733Z,1541534556.733 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-11-06T20:02:36.734Z,1541534556.734 [AcousticModem_Benthos_ATM900](DEBUG): Oct 25 2018 20:44:32 
2018-11-06T20:02:37.131Z,1541534557.131 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-11-06T20:02:37.213Z,1541534557.213 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:02:37.214Z,1541534557.214 [PNI_TCM] No Fault, FailCount= 1
2018-11-06T20:02:37.614Z,1541534557.614 [CBIT](CRITICAL): Environmental Failure. Press:14.747842 PSI. Humidity:35%. Temp:25 C. ABORTING MISSION
2018-11-06T20:02:37.931Z,1541534557.931 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-11-06T20:02:38.009Z,1541534558.009 [CBIT](INFO): Critical error at 20181106T200237
2018-11-06T20:02:38.330Z,1541534558.330 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-11-06T20:02:38.331Z,1541534558.331 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-11-06T20:02:38.331Z,1541534558.331 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-11-06T20:02:38.367Z,1541534558.367 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:02:38.367Z,1541534558.367 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-06T20:02:38.367Z,1541534558.367 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:02:38.414Z,1541534558.414 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:02:38.731Z,1541534558.731 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-11-06T20:02:38.763Z,1541534558.763 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:02:39.131Z,1541534559.131 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-11-06T20:02:39.132Z,1541534559.132 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-11-06T20:02:39.531Z,1541534559.531 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-11-06T20:02:39.644Z,1541534559.644 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:02:39.644Z,1541534559.644 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-06T20:02:44.751Z,1541534564.751 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:02:44.752Z,1541534564.752 [PNI_TCM] Data Fault, FailCount= 2
2018-11-06T20:02:44.752Z,1541534564.752 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:02:44.802Z,1541534564.802 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:02:45.152Z,1541534565.152 [PNI_TCM](INFO): Powering down
2018-11-06T20:02:46.417Z,1541534566.417 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:02:46.417Z,1541534566.417 [PNI_TCM] No Fault, FailCount= 2
2018-11-06T20:02:49.954Z,1541534569.954 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:02:49.954Z,1541534569.954 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-06T20:02:49.954Z,1541534569.954 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:02:50.029Z,1541534570.029 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:02:50.353Z,1541534570.353 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:02:51.208Z,1541534571.208 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:02:51.208Z,1541534571.208 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-06T20:02:52.042Z,1541534572.042 [SBIT](IMPORTANT): Beginning Startup BIT
2018-11-06T20:02:52.063Z,1541534572.063 [CBIT](IMPORTANT): Beginning ground fault scan
2018-11-06T20:02:53.961Z,1541534573.961 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:02:53.961Z,1541534573.961 [PNI_TCM] Data Fault, FailCount= 3
2018-11-06T20:02:53.962Z,1541534573.962 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:02:54.480Z,1541534574.480 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:02:54.510Z,1541534574.510 [NAL9602](INFO): Powering up NAL9602
2018-11-06T20:02:54.541Z,1541534574.541 [PNI_TCM](INFO): Powering down
2018-11-06T20:02:55.828Z,1541534575.828 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:02:55.828Z,1541534575.828 [PNI_TCM] No Fault, FailCount= 3
2018-11-06T20:03:01.724Z,1541534581.724 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:03:01.724Z,1541534581.724 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-11-06T20:03:01.724Z,1541534581.724 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:03:01.840Z,1541534581.840 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:03:01.840Z,1541534581.840 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-11-06T20:03:02.242Z,1541534582.242 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:03:03.015Z,1541534583.015 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007023
CHAN A1 (24V): -0.010188
CHAN A2 (12V): -0.005299
CHAN A3 (5V): -0.002637
CHAN B0 (3.3V): -0.000631
CHAN B1 (3.15aV): -0.001440
CHAN B2 (3.15bV): -0.001278
CHAN B3 (GND): -0.000054
OPEN: 0.004317
Full Scale Calc: 4.765 mA, -1.589 mA
2018-11-06T20:03:03.324Z,1541534583.324 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:03:03.324Z,1541534583.324 [PNI_TCM] Data Fault, FailCount= 4
2018-11-06T20:03:03.324Z,1541534583.324 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:03:03.420Z,1541534583.420 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:03:03.736Z,1541534583.736 [PNI_TCM](INFO): Powering down
2018-11-06T20:03:05.028Z,1541534585.028 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:03:05.028Z,1541534585.028 [PNI_TCM] No Fault, FailCount= 4
2018-11-06T20:03:05.309Z,1541534585.309 [NAL9602](INFO): NAL9602 initialized
2018-11-06T20:03:12.744Z,1541534592.744 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:03:12.744Z,1541534592.744 [PNI_TCM] Data Fault, FailCount= 5
2018-11-06T20:03:12.744Z,1541534592.744 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:03:13.027Z,1541534593.027 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:03:13.027Z,1541534593.027 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2018-11-06T20:03:13.144Z,1541534593.144 [PNI_TCM](INFO): Powering down
2018-11-06T20:03:13.441Z,1541534593.441 [CBIT](INFO): Critical error at 20181106T200313
2018-11-06T20:03:40.871Z,1541534620.871 [BPC1](FAULT): Failed to parse data from all battery packs.
2018-11-06T20:03:40.871Z,1541534620.871 [BPC1] Data Fault, FailCount= 1
2018-11-06T20:03:40.872Z,1541534620.872 [BPC1](ERROR): Data Fault
2018-11-06T20:03:40.891Z,1541534620.891 [CBIT](ERROR): Data Fault in component: BPC1
2018-11-06T20:03:46.085Z,1541534626.085 [SBIT](IMPORTANT): SBIT PASSED
2018-11-06T20:03:46.170Z,1541534626.170 [CommandLine](IMPORTANT): got command configSet list
2018-11-06T20:03:46.171Z,1541534626.171 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-11-06T20:03:46.171Z,1541534626.171 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2018-11-06T20:03:46.480Z,1541534626.480 [MissionManager](IMPORTANT): Started mission Startup
2018-11-06T20:03:46.480Z,1541534626.480 [Startup] Running Loop=1
2018-11-06T20:03:46.480Z,1541534626.480 [Startup](DEBUG): Aggregate::initialize Startup
2018-11-06T20:03:46.480Z,1541534626.480 [Startup:A.GoToSurface] Running Loop=1
2018-11-06T20:03:46.480Z,1541534626.480 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-11-06T20:03:46.481Z,1541534626.481 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-11-06T20:03:46.481Z,1541534626.481 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-11-06T20:03:46.482Z,1541534626.482 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-11-06T20:03:46.482Z,1541534626.482 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-11-06T20:03:46.483Z,1541534626.483 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-11-06T20:03:46.489Z,1541534626.489 [Startup:StartupSatComms] Running Loop=1
2018-11-06T20:03:46.489Z,1541534626.489 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-11-06T20:03:46.489Z,1541534626.489 [Startup:StartupSatComms:A] Running Loop=1
2018-11-06T20:03:46.861Z,1541534626.861 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-11-06T20:04:27.622Z,1541534667.622 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-06T20:04:27.622Z,1541534667.622 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-11-06T20:04:27.622Z,1541534667.622 [Rowe_600LCM](ERROR): Communications Fault
2018-11-06T20:04:27.664Z,1541534667.664 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-11-06T20:04:27.664Z,1541534667.664 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-11-06T20:04:27.664Z,1541534667.664 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-11-06T20:04:27.709Z,1541534667.709 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-06T20:04:27.709Z,1541534667.709 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-11-06T20:04:28.034Z,1541534668.034 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T20:04:28.152Z,1541534668.152 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-11-06T20:04:28.152Z,1541534668.152 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-11-06T20:04:28.213Z,1541534668.213 [Rowe_600LCM](INFO): Powering down
2018-11-06T20:04:28.477Z,1541534668.477 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T20:04:28.477Z,1541534668.477 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T20:04:28.478Z,1541534668.478 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T20:04:29.692Z,1541534669.692 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-06T20:04:29.692Z,1541534669.692 [Rowe_600LCM] No Fault, FailCount= 1
2018-11-06T20:04:29.830Z,1541534669.830 [Rowe_600LCM](INFO): Initializing
2018-11-06T20:04:29.831Z,1541534669.831 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T20:04:29.831Z,1541534669.831 [Rowe_600LCM](INFO): LCM OK
2018-11-06T20:04:29.831Z,1541534669.831 [Rowe_600LCM](INFO): Powering up
2018-11-06T20:04:33.952Z,1541534673.952 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T20:04:34.014Z,1541534674.014 [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 9600 >& /dev/null &
2018-11-06T20:04:34.024Z,1541534674.024 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T20:04:34.024Z,1541534674.024 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T20:04:34.025Z,1541534674.025 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T20:04:46.887Z,1541534686.887 [Startup:StartupSatComms:A](INFO): Timed out from 2018-11-06T20:03:46.5Z
2018-11-06T20:04:46.887Z,1541534686.887 [Startup:StartupSatComms:A] Stopped
2018-11-06T20:04:46.887Z,1541534686.887 [Startup:StartupSatComms:B] Running Loop=1
2018-11-06T20:04:47.281Z,1541534687.281 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-11-06T20:05:31.999Z,1541534731.999 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:05:31.999Z,1541534731.999 [Aanderaa_O2] No Fault, FailCount= 3
2018-11-06T20:05:32.812Z,1541534732.812 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004329
2018-11-06T20:05:37.272Z,1541534737.272 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20181106T194812/Courier0000.lzma
2018-11-06T20:05:38.072Z,1541534738.072 [DataOverHttps](INFO): Moved sent file to Logs/20181106T194812/Courier0000.lzma.bak
2018-11-06T20:05:38.073Z,1541534738.073 [DataOverHttps](INFO): SBD MOMSN=8797039
2018-11-06T20:05:42.532Z,1541534742.532 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:05:42.532Z,1541534742.532 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-06T20:05:42.533Z,1541534742.533 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:05:42.556Z,1541534742.556 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:05:42.779Z,1541534742.779 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:05:43.419Z,1541534743.419 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:05:43.419Z,1541534743.419 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-06T20:05:48.094Z,1541534748.094 [Startup:StartupSatComms:B](INFO): Timed out from 2018-11-06T20:04:46.9Z
2018-11-06T20:05:48.095Z,1541534748.095 [Startup:StartupSatComms:B] Stopped
2018-11-06T20:05:48.095Z,1541534748.095 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-11-06T20:05:48.095Z,1541534748.095 [Startup:StartupSatComms] Stopped
2018-11-06T20:05:48.095Z,1541534748.095 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-11-06T20:05:48.096Z,1541534748.096 [Startup](INFO): Completed Startup
2018-11-06T20:05:48.096Z,1541534748.096 [MissionManager](INFO): Startup is completed.
2018-11-06T20:05:48.096Z,1541534748.096 [MissionManager](INFO): Uninitializing Mission Startup
2018-11-06T20:05:48.096Z,1541534748.096 [Startup] Stopped
2018-11-06T20:05:48.096Z,1541534748.096 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-11-06T20:05:48.096Z,1541534748.096 [Startup:A.GoToSurface] Stopped
2018-11-06T20:05:48.097Z,1541534748.097 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-11-06T20:05:48.119Z,1541534748.119 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20181106T195218/Courier0000.lzma
2018-11-06T20:05:48.245Z,1541534748.245 [MissionManager](IMPORTANT): Started mission Default
2018-11-06T20:05:48.245Z,1541534748.245 [Default] Running Loop=1
2018-11-06T20:05:48.245Z,1541534748.245 [Default](DEBUG): Aggregate::initialize Default
2018-11-06T20:05:48.245Z,1541534748.245 [Default:B.GoToSurface] Running Loop=1
2018-11-06T20:05:48.245Z,1541534748.245 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-11-06T20:05:48.250Z,1541534748.250 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-11-06T20:05:48.251Z,1541534748.251 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-11-06T20:05:48.251Z,1541534748.251 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-11-06T20:05:48.251Z,1541534748.251 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-11-06T20:05:48.252Z,1541534748.252 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-11-06T20:05:48.252Z,1541534748.252 [Default:A.Wait] Running Loop=1
2018-11-06T20:05:48.252Z,1541534748.252 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-11-06T20:05:48.916Z,1541534748.916 [DataOverHttps](INFO): Moved sent file to Logs/20181106T195218/Courier0000.lzma.bak
2018-11-06T20:05:48.917Z,1541534748.917 [DataOverHttps](INFO): SBD MOMSN=8797042
2018-11-06T20:05:54.101Z,1541534754.101 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:05:54.101Z,1541534754.101 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-06T20:05:54.101Z,1541534754.101 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:05:54.159Z,1541534754.159 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:05:54.634Z,1541534754.634 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:05:55.353Z,1541534755.353 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:05:55.353Z,1541534755.353 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-06T20:06:01.325Z,1541534761.325 [Default:A.Wait](INFO): Done Waiting.
2018-11-06T20:06:01.325Z,1541534761.325 [Default:A.Wait] Stopped
2018-11-06T20:06:01.325Z,1541534761.325 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-11-06T20:06:01.717Z,1541534761.717 [Default:CheckIn] Running Loop=1
2018-11-06T20:06:01.717Z,1541534761.717 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-11-06T20:06:01.717Z,1541534761.717 [Default:CheckIn:Read_GPS] Running Loop=1
2018-11-06T20:06:02.117Z,1541534762.117 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-11-06T20:06:05.722Z,1541534765.722 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:06:05.722Z,1541534765.722 [Aanderaa_O2] Communications Fault, FailCount= 3
2018-11-06T20:06:05.723Z,1541534765.723 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:06:05.873Z,1541534765.873 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:06:05.873Z,1541534765.873 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2018-11-06T20:06:06.234Z,1541534766.234 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:06:28.516Z,1541534788.516 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-11-06T20:06:28.516Z,1541534788.516 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-11-06T20:06:28.516Z,1541534788.516 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-11-06T20:06:28.529Z,1541534788.529 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-11-06T20:06:28.933Z,1541534788.933 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-11-06T20:06:28.933Z,1541534788.933 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-11-06T20:06:29.321Z,1541534789.321 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T20:06:29.322Z,1541534789.322 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T20:06:29.322Z,1541534789.322 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T20:06:30.250Z,1541534790.250 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-06T20:06:30.250Z,1541534790.250 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-11-06T20:06:30.250Z,1541534790.250 [Rowe_600LCM](ERROR): Communications Fault
2018-11-06T20:06:30.534Z,1541534790.534 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-06T20:06:30.656Z,1541534790.656 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T20:06:30.743Z,1541534790.743 [Rowe_600LCM](INFO): Powering down
2018-11-06T20:06:32.147Z,1541534792.147 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-06T20:06:32.147Z,1541534792.147 [Rowe_600LCM] No Fault, FailCount= 2
2018-11-06T20:06:32.358Z,1541534792.358 [Rowe_600LCM](INFO): Initializing
2018-11-06T20:06:32.359Z,1541534792.359 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T20:06:32.359Z,1541534792.359 [Rowe_600LCM](INFO): LCM OK
2018-11-06T20:06:32.359Z,1541534792.359 [Rowe_600LCM](INFO): Powering up
2018-11-06T20:06:36.491Z,1541534796.491 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T20:06:36.637Z,1541534796.637 [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 9600 >& /dev/null &
2018-11-06T20:06:36.639Z,1541534796.639 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T20:06:36.640Z,1541534796.640 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T20:06:36.641Z,1541534796.641 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T20:08:08.568Z,1541534888.568 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-11-06T20:08:13.089Z,1541534893.089 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:08:13.089Z,1541534893.089 [PNI_TCM] No Fault, FailCount= 5
2018-11-06T20:08:20.584Z,1541534900.584 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:08:20.584Z,1541534900.584 [PNI_TCM] Data Fault, FailCount= 1
2018-11-06T20:08:20.584Z,1541534900.584 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:08:20.642Z,1541534900.642 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:08:20.984Z,1541534900.984 [PNI_TCM](INFO): Powering down
2018-11-06T20:08:22.229Z,1541534902.229 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:08:22.229Z,1541534902.229 [PNI_TCM] No Fault, FailCount= 1
2018-11-06T20:08:29.396Z,1541534909.396 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2018-11-06T20:08:29.396Z,1541534909.396 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-11-06T20:08:29.396Z,1541534909.396 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-11-06T20:08:29.450Z,1541534909.450 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-11-06T20:08:29.784Z,1541534909.784 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:08:29.785Z,1541534909.785 [PNI_TCM] Data Fault, FailCount= 2
2018-11-06T20:08:29.785Z,1541534909.785 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:08:29.847Z,1541534909.847 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:08:29.847Z,1541534909.847 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-11-06T20:08:29.847Z,1541534909.847 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-11-06T20:08:30.183Z,1541534910.183 [PNI_TCM](INFO): Powering down
2018-11-06T20:08:30.279Z,1541534910.279 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-11-06T20:08:30.280Z,1541534910.280 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-11-06T20:08:30.280Z,1541534910.280 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-11-06T20:08:31.432Z,1541534911.432 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:08:31.432Z,1541534911.432 [PNI_TCM] No Fault, FailCount= 2
2018-11-06T20:08:33.118Z,1541534913.118 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-11-06T20:08:33.118Z,1541534913.118 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-11-06T20:08:33.118Z,1541534913.118 [Rowe_600LCM](ERROR): Communications Fault
2018-11-06T20:08:33.428Z,1541534913.428 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-11-06T20:08:33.522Z,1541534913.522 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T20:08:33.613Z,1541534913.613 [Rowe_600LCM](INFO): Powering down
2018-11-06T20:08:35.031Z,1541534915.031 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-11-06T20:08:35.031Z,1541534915.031 [Rowe_600LCM] No Fault, FailCount= 3
2018-11-06T20:08:35.230Z,1541534915.230 [Rowe_600LCM](INFO): Initializing
2018-11-06T20:08:35.231Z,1541534915.231 [Rowe_600LCM](INFO): Checking LCM
2018-11-06T20:08:35.231Z,1541534915.231 [Rowe_600LCM](INFO): LCM OK
2018-11-06T20:08:35.231Z,1541534915.231 [Rowe_600LCM](INFO): Powering up
2018-11-06T20:08:35.859Z,1541534915.859 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:08:35.859Z,1541534915.859 [Aanderaa_O2] No Fault, FailCount= 3
2018-11-06T20:08:38.984Z,1541534918.984 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:08:38.985Z,1541534918.985 [PNI_TCM] Data Fault, FailCount= 3
2018-11-06T20:08:38.985Z,1541534918.985 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:08:39.048Z,1541534919.048 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:08:39.352Z,1541534919.352 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-11-06T20:08:39.415Z,1541534919.415 [PNI_TCM](INFO): Powering down
2018-11-06T20:08:39.514Z,1541534919.514 [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 9600 >& /dev/null &
2018-11-06T20:08:39.515Z,1541534919.515 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-11-06T20:08:39.516Z,1541534919.516 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-11-06T20:08:39.516Z,1541534919.516 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-11-06T20:08:40.627Z,1541534920.627 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:08:40.627Z,1541534920.627 [PNI_TCM] No Fault, FailCount= 3
2018-11-06T20:08:46.207Z,1541534926.207 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:08:46.207Z,1541534926.207 [Aanderaa_O2] Communications Fault, FailCount= 1
2018-11-06T20:08:46.208Z,1541534926.208 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:08:46.236Z,1541534926.236 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:08:46.597Z,1541534926.597 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:08:47.487Z,1541534927.487 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:08:47.487Z,1541534927.487 [Aanderaa_O2] No Fault, FailCount= 1
2018-11-06T20:08:48.199Z,1541534928.199 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:08:48.199Z,1541534928.199 [PNI_TCM] Data Fault, FailCount= 4
2018-11-06T20:08:48.200Z,1541534928.200 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:08:48.266Z,1541534928.266 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:08:48.590Z,1541534928.590 [PNI_TCM](INFO): Powering down
2018-11-06T20:08:49.895Z,1541534929.895 [CBIT](INFO): Clearing failed state for component PNI_TCM
2018-11-06T20:08:49.895Z,1541534929.895 [PNI_TCM] No Fault, FailCount= 4
2018-11-06T20:08:58.108Z,1541534938.108 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2018-11-06T20:08:58.108Z,1541534938.108 [Aanderaa_O2] Communications Fault, FailCount= 2
2018-11-06T20:08:58.108Z,1541534938.108 [Aanderaa_O2](ERROR): Communications Fault
2018-11-06T20:08:58.131Z,1541534938.131 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2018-11-06T20:08:58.499Z,1541534938.499 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:08:59.333Z,1541534939.333 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2018-11-06T20:08:59.334Z,1541534939.334 [Aanderaa_O2] No Fault, FailCount= 2
2018-11-06T20:09:01.872Z,1541534941.872 [CommandLine](IMPORTANT): got command restart application
2018-11-06T20:09:02.882Z,1541534942.882 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:02.883Z,1541534942.883 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:02.898Z,1541534942.898 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2018-11-06T20:09:02.898Z,1541534942.898 [PNI_TCM] Data Fault, FailCount= 5
2018-11-06T20:09:02.898Z,1541534942.898 [PNI_TCM](ERROR): Data Fault
2018-11-06T20:09:02.944Z,1541534942.944 [CBIT](ERROR): Data Fault in component: PNI_TCM
2018-11-06T20:09:02.945Z,1541534942.945 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2018-11-06T20:09:03.030Z,1541534943.030 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-11-06T20:09:03.030Z,1541534943.030 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.031Z,1541534943.031 [CommandLine](INFO): Join timeout helper Thread ID is 1742
2018-11-06T20:09:03.031Z,1541534943.031 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-11-06T20:09:03.031Z,1541534943.031 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.032Z,1541534943.032 [NavChartDb](INFO): Join timeout helper Thread ID is 1743
2018-11-06T20:09:03.251Z,1541534943.251 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:03.251Z,1541534943.251 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.270Z,1541534943.270 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-11-06T20:09:03.270Z,1541534943.270 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.271Z,1541534943.271 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1744
2018-11-06T20:09:03.292Z,1541534943.292 [PNI_TCM](INFO): Powering down
2018-11-06T20:09:03.346Z,1541534943.346 [CBIT](INFO): Critical error at 20181106T200902
2018-11-06T20:09:03.582Z,1541534943.582 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:03.582Z,1541534943.582 [WetLabsBB2FL](INFO): Powering down
2018-11-06T20:09:03.583Z,1541534943.583 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.594Z,1541534943.594 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-11-06T20:09:03.594Z,1541534943.594 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.595Z,1541534943.595 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1745
2018-11-06T20:09:03.818Z,1541534943.818 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:03.907Z,1541534943.907 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-11-06T20:09:03.907Z,1541534943.907 [CTD_Seabird](INFO): Powering down
2018-11-06T20:09:03.909Z,1541534943.909 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.922Z,1541534943.922 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-11-06T20:09:03.922Z,1541534943.922 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:03.923Z,1541534943.923 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 1747
2018-11-06T20:09:04.602Z,1541534944.602 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:04.603Z,1541534944.603 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-11-06T20:09:04.708Z,1541534944.708 [Rowe_600LCM](INFO): Powering down
2018-11-06T20:09:04.709Z,1541534944.709 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:04.723Z,1541534944.723 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-11-06T20:09:04.723Z,1541534944.723 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:04.724Z,1541534944.724 [Radio_Surface](INFO): Join timeout helper Thread ID is 1749
2018-11-06T20:09:04.898Z,1541534944.898 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:04.899Z,1541534944.899 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:04.903Z,1541534944.903 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-11-06T20:09:04.903Z,1541534944.903 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:04.904Z,1541534944.904 [logger](INFO): Join timeout helper Thread ID is 1750
2018-11-06T20:09:04.906Z,1541534944.906 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:04.906Z,1541534944.906 [logger ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:04.908Z,1541534944.908 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-11-06T20:09:04.908Z,1541534944.908 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:04.908Z,1541534944.908 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-11-06T20:09:04.908Z,1541534944.908 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:04.909Z,1541534944.909 [controlThread](INFO): Join timeout helper Thread ID is 1751
2018-11-06T20:09:04.930Z,1541534944.930 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-11-06T20:09:04.930Z,1541534944.930 [controlThread](DEBUG): Uninitializing ControlThread
2018-11-06T20:09:04.931Z,1541534944.931 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-11-06T20:09:05.051Z,1541534945.051 [NAL9602](INFO): Powering down
2018-11-06T20:09:05.052Z,1541534945.052 [PNI_TCM](INFO): Powering down
2018-11-06T20:09:05.170Z,1541534945.170 [Aanderaa_O2](INFO): Powering down
2018-11-06T20:09:05.173Z,1541534945.173 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-11-06T20:09:05.174Z,1541534945.174 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-11-06T20:09:05.174Z,1541534945.174 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-11-06T20:09:05.175Z,1541534945.175 [MissionManager](INFO): Uninitializing Mission Default
2018-11-06T20:09:05.175Z,1541534945.175 [Default] Stopped
2018-11-06T20:09:05.175Z,1541534945.175 [Default](DEBUG): Aggregate::uninitialize Default
2018-11-06T20:09:05.176Z,1541534945.176 [Default:B.GoToSurface] Stopped
2018-11-06T20:09:05.176Z,1541534945.176 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-11-06T20:09:05.176Z,1541534945.176 [Default:CheckIn] Stopped
2018-11-06T20:09:05.176Z,1541534945.176 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-11-06T20:09:05.176Z,1541534945.176 [Default:CheckIn:Read_GPS] Stopped
2018-11-06T20:09:05.180Z,1541534945.180 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-11-06T20:09:05.180Z,1541534945.180 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-11-06T20:09:05.180Z,1541534945.180 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-11-06T20:09:05.180Z,1541534945.180 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-11-06T20:09:05.181Z,1541534945.181 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-11-06T20:09:05.181Z,1541534945.181 [BuoyancyServo](INFO): Powering down
2018-11-06T20:09:05.194Z,1541534945.194 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-11-06T20:09:05.194Z,1541534945.194 [ElevatorServo](INFO): Powering down
2018-11-06T20:09:05.195Z,1541534945.195 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-11-06T20:09:05.195Z,1541534945.195 [MassServo](INFO): Powering down
2018-11-06T20:09:05.196Z,1541534945.196 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-11-06T20:09:05.196Z,1541534945.196 [RudderServo](INFO): Powering down
2018-11-06T20:09:05.197Z,1541534945.197 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-11-06T20:09:05.197Z,1541534945.197 [ThrusterServo](INFO): Powering down
2018-11-06T20:09:05.198Z,1541534945.198 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-11-06T20:09:05.199Z,1541534945.199 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-11-06T20:09:05.199Z,1541534945.199 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-11-06T20:09:05.200Z,1541534945.200 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:05.307Z,1541534945.307 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:05.313Z,1541534945.313 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:05.357Z,1541534945.357 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:05.362Z,1541534945.362 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:05.420Z,1541534945.420 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-11-06T20:09:05.479Z,1541534945.479 [logger ThreadHandler](INFO): Thread cancelled.