2018-02-11T23:06:16.731Z,1518390376.731 [Supervisor](DEBUG): Initializing supervisor.
2018-02-11T23:06:16.733Z,1518390376.733 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-02-11T23:06:16.734Z,1518390376.734 [SyncHandler](INFO): Protected caller Thread ID is 1583
2018-02-11T23:06:16.734Z,1518390376.734 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-02-11T23:06:16.735Z,1518390376.735 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-02-11T23:06:16.736Z,1518390376.736 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1584
2018-02-11T23:06:16.740Z,1518390376.740 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-02-11T23:06:16.752Z,1518390376.752 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-02-11T23:06:16.753Z,1518390376.753 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-02-11T23:06:16.753Z,1518390376.753 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1585
2018-02-11T23:06:16.754Z,1518390376.754 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-02-11T23:06:16.755Z,1518390376.755 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-02-11T23:06:16.755Z,1518390376.755 [logger ThreadHandler](INFO): Protected caller Thread ID is 1586
2018-02-11T23:06:16.757Z,1518390376.757 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-02-11T23:06:16.758Z,1518390376.758 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-02-11T23:06:16.760Z,1518390376.760 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-02-11T23:06:16.918Z,1518390376.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-02-11T23:06:16.919Z,1518390376.919 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-02-11T23:06:17.015Z,1518390377.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-02-11T23:06:17.016Z,1518390377.016 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-02-11T23:06:17.199Z,1518390377.199 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-02-11T23:06:17.200Z,1518390377.200 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-02-11T23:06:17.486Z,1518390377.486 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-02-11T23:06:17.487Z,1518390377.487 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-02-11T23:06:17.802Z,1518390377.802 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-02-11T23:06:17.802Z,1518390377.802 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-02-11T23:06:18.234Z,1518390378.234 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-02-11T23:06:18.234Z,1518390378.234 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-02-11T23:06:18.552Z,1518390378.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-02-11T23:06:18.553Z,1518390378.553 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-02-11T23:06:18.958Z,1518390378.958 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-02-11T23:06:18.958Z,1518390378.958 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-02-11T23:06:19.037Z,1518390379.037 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-02-11T23:06:19.311Z,1518390379.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-02-11T23:06:19.312Z,1518390379.312 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-02-11T23:06:19.448Z,1518390379.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-02-11T23:06:19.448Z,1518390379.448 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-02-11T23:06:19.639Z,1518390379.639 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-02-11T23:06:19.640Z,1518390379.640 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-02-11T23:06:19.853Z,1518390379.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-02-11T23:06:19.854Z,1518390379.854 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-02-11T23:06:19.949Z,1518390379.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-02-11T23:06:19.949Z,1518390379.949 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-02-11T23:06:20.084Z,1518390380.084 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-02-11T23:06:20.086Z,1518390380.086 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2018-02-11T23:06:20.087Z,1518390380.087 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2018-02-11T23:06:20.309Z,1518390380.309 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-02-11T23:06:20.310Z,1518390380.310 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2018-02-11T23:06:20.385Z,1518390380.385 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2018-02-11T23:06:20.520Z,1518390380.520 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2018-02-11T23:06:20.609Z,1518390380.609 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2018-02-11T23:06:20.692Z,1518390380.692 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2018-02-11T23:06:20.821Z,1518390380.821 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2018-02-11T23:06:20.976Z,1518390380.976 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2018-02-11T23:06:21.070Z,1518390381.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2018-02-11T23:06:21.160Z,1518390381.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2018-02-11T23:06:21.253Z,1518390381.253 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2018-02-11T23:06:21.350Z,1518390381.350 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2018-02-11T23:06:21.351Z,1518390381.351 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-02-11T23:06:21.373Z,1518390381.373 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-02-11T23:06:21.656Z,1518390381.656 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-02-11T23:06:21.657Z,1518390381.657 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-02-11T23:06:21.742Z,1518390381.742 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-02-11T23:06:21.742Z,1518390381.742 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-02-11T23:06:21.784Z,1518390381.784 [DepthRateCalculator] Loaded
2018-02-11T23:06:21.784Z,1518390381.784 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-02-11T23:06:21.807Z,1518390381.807 [PitchRateCalculator] Loaded
2018-02-11T23:06:21.808Z,1518390381.808 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-02-11T23:06:21.838Z,1518390381.838 [SpeedCalculator] Loaded
2018-02-11T23:06:21.838Z,1518390381.838 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-02-11T23:06:21.859Z,1518390381.859 [TempGradientCalculator] Loaded
2018-02-11T23:06:21.859Z,1518390381.859 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-02-11T23:06:21.899Z,1518390381.899 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-02-11T23:06:21.899Z,1518390381.899 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-02-11T23:06:21.911Z,1518390381.911 [YawRateCalculator] Loaded
2018-02-11T23:06:21.911Z,1518390381.911 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-02-11T23:06:21.951Z,1518390381.951 [ElevatorOffsetCalculator] Loaded
2018-02-11T23:06:21.951Z,1518390381.951 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-02-11T23:06:21.951Z,1518390381.951 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-02-11T23:06:21.952Z,1518390381.952 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-02-11T23:06:22.027Z,1518390382.027 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-02-11T23:06:22.028Z,1518390382.028 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-02-11T23:06:22.431Z,1518390382.431 [AcousticModem_Benthos_ATM900] Loaded
2018-02-11T23:06:22.431Z,1518390382.431 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2018-02-11T23:06:22.498Z,1518390382.498 [DataOverHttps] Loaded
2018-02-11T23:06:22.499Z,1518390382.499 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-02-11T23:06:22.512Z,1518390382.512 [Depth_Keller] Loaded
2018-02-11T23:06:22.512Z,1518390382.512 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-02-11T23:06:22.518Z,1518390382.518 [DropWeight] Loaded
2018-02-11T23:06:22.518Z,1518390382.518 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-02-11T23:06:22.615Z,1518390382.615 [NAL9602] Loaded
2018-02-11T23:06:22.615Z,1518390382.615 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-02-11T23:06:22.631Z,1518390382.631 [Onboard] Loaded
2018-02-11T23:06:22.631Z,1518390382.631 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-02-11T23:06:22.641Z,1518390382.641 [Radio_Surface] Loaded
2018-02-11T23:06:22.641Z,1518390382.641 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-02-11T23:06:22.642Z,1518390382.642 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407A54E0
2018-02-11T23:06:22.643Z,1518390382.643 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1665
2018-02-11T23:06:22.689Z,1518390382.689 [PNI_TCM] Loaded
2018-02-11T23:06:22.690Z,1518390382.690 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-02-11T23:06:24.420Z,1518390384.420 [BPC1] Loaded
2018-02-11T23:06:24.420Z,1518390384.420 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-02-11T23:06:24.421Z,1518390384.421 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-02-11T23:06:24.421Z,1518390384.421 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-02-11T23:06:24.549Z,1518390384.549 [SBIT](DEBUG): Construct Startup Built In Test.
2018-02-11T23:06:24.572Z,1518390384.572 [SBIT] Loaded
2018-02-11T23:06:24.572Z,1518390384.572 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-02-11T23:06:24.573Z,1518390384.573 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-02-11T23:06:24.584Z,1518390384.584 [IBIT] Loaded
2018-02-11T23:06:24.584Z,1518390384.584 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-02-11T23:06:24.587Z,1518390384.587 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-02-11T23:06:24.734Z,1518390384.734 [CBIT] Loaded
2018-02-11T23:06:24.735Z,1518390384.735 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-02-11T23:06:24.735Z,1518390384.735 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-02-11T23:06:24.736Z,1518390384.736 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-02-11T23:06:24.878Z,1518390384.878 [Aanderaa_O2] Loaded
2018-02-11T23:06:24.879Z,1518390384.879 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-02-11T23:06:24.926Z,1518390384.926 [CTD_Seabird] Loaded
2018-02-11T23:06:24.926Z,1518390384.926 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-02-11T23:06:24.927Z,1518390384.927 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 408654E0
2018-02-11T23:06:24.927Z,1518390384.927 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1666
2018-02-11T23:06:24.941Z,1518390384.941 [PAR_Licor] Loaded
2018-02-11T23:06:24.942Z,1518390384.942 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-02-11T23:06:24.990Z,1518390384.990 [WetLabsBB2FL] Loaded
2018-02-11T23:06:24.991Z,1518390384.991 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-02-11T23:06:24.992Z,1518390384.992 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408954E0
2018-02-11T23:06:24.992Z,1518390384.992 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1667
2018-02-11T23:06:24.993Z,1518390384.993 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-02-11T23:06:24.993Z,1518390384.993 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-02-11T23:06:25.227Z,1518390385.227 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-02-11T23:06:25.228Z,1518390385.228 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-02-11T23:06:25.294Z,1518390385.294 [VerticalControl](DEBUG): Construct VerticalControl.
2018-02-11T23:06:25.389Z,1518390385.389 [VerticalControl] Loaded
2018-02-11T23:06:25.389Z,1518390385.389 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-02-11T23:06:25.389Z,1518390385.389 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-02-11T23:06:25.450Z,1518390385.450 [HorizontalControl] Loaded
2018-02-11T23:06:25.450Z,1518390385.450 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-02-11T23:06:25.451Z,1518390385.451 [SpeedControl](DEBUG): Construct SpeedControl.
2018-02-11T23:06:25.456Z,1518390385.456 [SpeedControl] Loaded
2018-02-11T23:06:25.456Z,1518390385.456 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-02-11T23:06:25.457Z,1518390385.457 [LoopControl](DEBUG): Construct LoopControl.
2018-02-11T23:06:25.458Z,1518390385.458 [LoopControl] Loaded
2018-02-11T23:06:25.458Z,1518390385.458 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-02-11T23:06:25.458Z,1518390385.458 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-02-11T23:06:25.459Z,1518390385.459 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-02-11T23:06:25.544Z,1518390385.544 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-02-11T23:06:25.544Z,1518390385.544 [StratificationFrontDetector](DEBUG): (re)initializing
2018-02-11T23:06:25.544Z,1518390385.544 [StratificationFrontDetector] Loaded
2018-02-11T23:06:25.545Z,1518390385.545 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-02-11T23:06:25.545Z,1518390385.545 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-02-11T23:06:25.546Z,1518390385.546 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-02-11T23:06:25.642Z,1518390385.642 [BuoyancyServo] Loaded
2018-02-11T23:06:25.643Z,1518390385.643 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-02-11T23:06:25.654Z,1518390385.654 [ElevatorServo] Loaded
2018-02-11T23:06:25.654Z,1518390385.654 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-02-11T23:06:25.665Z,1518390385.665 [MassServo] Loaded
2018-02-11T23:06:25.665Z,1518390385.665 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-02-11T23:06:25.676Z,1518390385.676 [RudderServo] Loaded
2018-02-11T23:06:25.677Z,1518390385.677 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-02-11T23:06:25.687Z,1518390385.687 [ThrusterServo] Loaded
2018-02-11T23:06:25.688Z,1518390385.688 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-02-11T23:06:25.688Z,1518390385.688 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-02-11T23:06:25.689Z,1518390385.689 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-02-11T23:06:25.787Z,1518390385.787 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-02-11T23:06:25.788Z,1518390385.788 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-02-11T23:06:25.842Z,1518390385.842 [DeadReckonUsingSpeedCalculator] Loaded
2018-02-11T23:06:25.843Z,1518390385.843 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-02-11T23:06:25.859Z,1518390385.859 [NavChart] Loaded
2018-02-11T23:06:25.860Z,1518390385.860 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-02-11T23:06:25.863Z,1518390385.863 [UniversalFixResidualReporter] Loaded
2018-02-11T23:06:25.864Z,1518390385.864 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-02-11T23:06:25.864Z,1518390385.864 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-02-11T23:06:25.868Z,1518390385.868 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-02-11T23:06:25.869Z,1518390385.869 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-02-11T23:06:25.875Z,1518390385.875 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-02-11T23:06:25.876Z,1518390385.876 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409EA4E0
2018-02-11T23:06:25.877Z,1518390385.877 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1668
2018-02-11T23:06:25.881Z,1518390385.881 [Supervisor](INFO): Main Thread ID is 638
2018-02-11T23:06:25.881Z,1518390385.881 [Supervisor](DEBUG): Running supervisor.
2018-02-11T23:06:25.882Z,1518390385.882 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1669
2018-02-11T23:06:25.885Z,1518390385.885 [controlThread ThreadHandler](INFO): Handler Thread ID is 1670
2018-02-11T23:06:25.885Z,1518390385.885 [controlThread](DEBUG): Initializing ControlThread
2018-02-11T23:06:25.886Z,1518390385.886 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-02-11T23:06:25.886Z,1518390385.886 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-02-11T23:06:25.887Z,1518390385.887 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-02-11T23:06:25.887Z,1518390385.887 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-02-11T23:06:25.888Z,1518390385.888 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-02-11T23:06:25.888Z,1518390385.888 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-02-11T23:06:25.889Z,1518390385.889 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-02-11T23:06:25.895Z,1518390385.895 [SBIT](INFO): Initialize SBIT Component.
2018-02-11T23:06:25.896Z,1518390385.895 [SBIT](IMPORTANT): git: 2018-02-09A-11-g1191477
2018-02-11T23:06:25.896Z,1518390385.896 [SBIT](INFO): git hash: 1191477e507aa94f59b4a9056a613189489a6cd1
2018-02-11T23:06:25.896Z,1518390385.896 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-02-11T23:06:25.897Z,1518390385.897 [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-11T23:06:25.898Z,1518390385.898 [SBIT](INFO): Beginning SBIT in 52.000000 seconds.
2018-02-11T23:06:25.899Z,1518390385.899 [IBIT](INFO): Initialize IBIT Component.
2018-02-11T23:06:25.899Z,1518390385.899 [CBIT](DEBUG): Initialize CBIT Component.
2018-02-11T23:06:25.900Z,1518390385.900 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2018-02-11T23:06:25.901Z,1518390385.901 [logger ThreadHandler](INFO): Handler Thread ID is 1671
2018-02-11T23:06:25.921Z,1518390385.921 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1672
2018-02-11T23:06:25.927Z,1518390385.927 [Radio_Surface](INFO): Powering up
2018-02-11T23:06:25.933Z,1518390385.933 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1673
2018-02-11T23:06:25.934Z,1518390385.934 [CTD_Seabird](INFO): Initializing
2018-02-11T23:06:25.934Z,1518390385.934 [CTD_Seabird](INFO): Checking LCM
2018-02-11T23:06:25.946Z,1518390385.946 [CTD_Seabird](INFO): LCM OK
2018-02-11T23:06:25.946Z,1518390385.946 [CTD_Seabird](INFO): Powering up
2018-02-11T23:06:25.953Z,1518390385.953 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1674
2018-02-11T23:06:25.955Z,1518390385.955 [WetLabsBB2FL](INFO): Powering down
2018-02-11T23:06:25.981Z,1518390385.981 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1675
2018-02-11T23:06:25.986Z,1518390385.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-02-11T23:06:25.986Z,1518390385.986 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-02-11T23:06:25.986Z,1518390385.986 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-02-11T23:06:25.987Z,1518390385.987 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-02-11T23:06:25.987Z,1518390385.987 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-02-11T23:06:25.987Z,1518390385.987 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-02-11T23:06:25.987Z,1518390385.987 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-02-11T23:06:25.987Z,1518390385.987 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-02-11T23:06:25.988Z,1518390385.988 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-02-11T23:06:25.988Z,1518390385.988 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-02-11T23:06:25.988Z,1518390385.988 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-02-11T23:06:25.988Z,1518390385.988 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-02-11T23:06:25.989Z,1518390385.989 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-02-11T23:06:25.989Z,1518390385.989 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-02-11T23:06:25.989Z,1518390385.989 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-02-11T23:06:25.989Z,1518390385.989 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-02-11T23:06:26.009Z,1518390386.009 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-02-11T23:06:26.011Z,1518390386.011 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-02-11T23:06:26.011Z,1518390386.011 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-02-11T23:06:26.012Z,1518390386.012 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-02-11T23:06:26.014Z,1518390386.014 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-02-11T23:06:26.014Z,1518390386.014 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-02-11T23:06:26.015Z,1518390386.015 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-02-11T23:06:26.015Z,1518390386.015 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-02-11T23:06:26.016Z,1518390386.016 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-02-11T23:06:26.016Z,1518390386.016 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-02-11T23:06:26.017Z,1518390386.017 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-02-11T23:06:26.017Z,1518390386.017 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-02-11T23:06:26.018Z,1518390386.018 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-02-11T23:06:26.076Z,1518390386.076 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-02-11T23:06:26.087Z,1518390386.087 [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-11T23:06:26.088Z,1518390386.088 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-02-11T23:06:26.189Z,1518390386.189 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-02-11T23:06:26.190Z,1518390386.190 [Default:A.Wait](DEBUG): Construct Wait.
2018-02-11T23:06:26.191Z,1518390386.191 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-02-11T23:06:26.213Z,1518390386.213 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-02-11T23:06:26.216Z,1518390386.216 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-02-11T23:06:26.261Z,1518390386.261 [Default:E.Execute](DEBUG): Construct Execute.
2018-02-11T23:06:26.265Z,1518390386.265 [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-11T23:06:26.283Z,1518390386.283 [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-11T23:06:26.309Z,1518390386.309 [AcousticModem_Benthos_ATM900](INFO): Powering up
2018-02-11T23:06:26.309Z,1518390386.309 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2018-02-11T23:06:26.337Z,1518390386.337 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-02-11T23:06:26.877Z,1518390386.877 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:26.909Z,1518390386.909 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:27.005Z,1518390387.005 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-02-11T23:06:27.013Z,1518390387.013 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-02-11T23:06:27.027Z,1518390387.027 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-02-11T23:06:27.034Z,1518390387.034 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-02-11T23:06:27.047Z,1518390387.047 [MassServo](DEBUG): Initializing EZServoServo.
2018-02-11T23:06:27.053Z,1518390387.053 [MassServo](DEBUG): Initializing MassServo.
2018-02-11T23:06:27.074Z,1518390387.074 [RudderServo](DEBUG): Initializing EZServoServo.
2018-02-11T23:06:27.081Z,1518390387.081 [RudderServo](DEBUG): Initializing RudderServo.
2018-02-11T23:06:27.086Z,1518390387.086 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-02-11T23:06:27.093Z,1518390387.093 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-02-11T23:06:27.126Z,1518390387.126 [CommandLine](FAULT): Scheduling is paused
2018-02-11T23:06:27.127Z,1518390387.127 [CBIT](INFO): Critical error at 20180211T230625
2018-02-11T23:06:27.127Z,1518390387.127 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-02-11T23:06:27.229Z,1518390387.229 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2018-02-11T23:06:27.229Z,1518390387.229 [DropWeight] Hardware Fault, FailCount= 1
2018-02-11T23:06:27.229Z,1518390387.229 [DropWeight](ERROR): Hardware Fault
2018-02-11T23:06:27.290Z,1518390387.290 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:27.291Z,1518390387.291 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:27.316Z,1518390387.316 [CBIT](INFO): Critical error at 20180211T230627
2018-02-11T23:06:27.319Z,1518390387.319 [CBIT](ERROR): Hardware Fault in component: DropWeight
2018-02-11T23:06:27.319Z,1518390387.319 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2018-02-11T23:06:27.612Z,1518390387.612 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:27.621Z,1518390387.621 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:27.949Z,1518390387.949 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-02-11T23:06:27.949Z,1518390387.949 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-02-11T23:06:27.949Z,1518390387.949 [BuoyancyServo] Communications Fault, FailCount= 1
2018-02-11T23:06:27.949Z,1518390387.949 [BuoyancyServo](ERROR): Communications Fault
2018-02-11T23:06:28.154Z,1518390388.154 [CBIT](INFO): Critical error at 20180211T230627
2018-02-11T23:06:28.157Z,1518390388.157 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-02-11T23:06:28.214Z,1518390388.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:28.215Z,1518390388.215 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:28.236Z,1518390388.236 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-02-11T23:06:28.253Z,1518390388.253 [BuoyancyServo](INFO): Powering down
2018-02-11T23:06:28.640Z,1518390388.640 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:28.650Z,1518390388.650 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:29.031Z,1518390389.031 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:29.032Z,1518390389.032 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:29.416Z,1518390389.416 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:29.425Z,1518390389.425 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:29.921Z,1518390389.921 [Aanderaa_O2](INFO): Powering down
2018-02-11T23:06:29.989Z,1518390389.989 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:29.990Z,1518390389.990 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-02-11T23:06:30.270Z,1518390390.270 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-02-11T23:06:30.270Z,1518390390.270 [BuoyancyServo] No Fault, FailCount= 1
2018-02-11T23:06:30.673Z,1518390390.673 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-02-11T23:06:30.794Z,1518390390.794 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-02-11T23:06:31.789Z,1518390391.789 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-02-11T23:06:31.920Z,1518390391.920 [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-11T23:06:31.966Z,1518390391.966 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-02-11T23:06:32.360Z,1518390392.360 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-02-11T23:06:32.360Z,1518390392.360 [CTD_Seabird](INFO): Powering down
2018-02-11T23:06:33.765Z,1518390393.765 [AcousticModem_Benthos_ATM900](DEBUG): 
2018-02-11T23:06:34.967Z,1518390394.967 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2018-02-11T23:06:34.968Z,1518390394.968 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2018-02-11T23:06:34.969Z,1518390394.969 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2018-02-11T23:06:34.969Z,1518390394.969 [AcousticModem_Benthos_ATM900](DEBUG): Mar  4 2000 13:31:39 
2018-02-11T23:06:35.765Z,1518390395.765 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2018-02-11T23:06:36.564Z,1518390396.564 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2018-02-11T23:06:36.964Z,1518390396.964 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2018-02-11T23:06:36.965Z,1518390396.965 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2018-02-11T23:06:36.965Z,1518390396.965 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2018-02-11T23:06:37.364Z,1518390397.364 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2018-02-11T23:06:37.764Z,1518390397.764 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2018-02-11T23:06:37.765Z,1518390397.765 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2018-02-11T23:06:38.165Z,1518390398.165 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2018-02-11T23:06:52.970Z,1518390412.970 [NAL9602](INFO): Powering up NAL9602
2018-02-11T23:07:04.170Z,1518390424.170 [NAL9602](INFO): NAL9602 initialized
2018-02-11T23:07:18.659Z,1518390438.659 [SBIT](IMPORTANT): Beginning Startup BIT
2018-02-11T23:07:18.668Z,1518390438.668 [CBIT](IMPORTANT): Beginning ground fault scan
2018-02-11T23:07:29.650Z,1518390449.650 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008462
CHAN A1 (24V): -0.012891
CHAN A2 (12V): -0.005578
CHAN A3 (5V): -0.002983
CHAN B0 (3.3V): -0.000978
CHAN B1 (3.15aV): -0.000969
CHAN B2 (3.15bV): -0.001161
CHAN B3 (GND): 0.000642
OPEN: 0.004497
Full Scale Calc: 4.765 mA, -1.589 mA
2018-02-11T23:08:12.701Z,1518390492.701 [SBIT](IMPORTANT): SBIT PASSED
2018-02-11T23:08:13.091Z,1518390493.091 [MissionManager](IMPORTANT): Started mission Startup
2018-02-11T23:08:13.092Z,1518390493.092 [Startup] Running Loop=1
2018-02-11T23:08:13.092Z,1518390493.092 [Startup](DEBUG): Aggregate::initialize Startup
2018-02-11T23:08:13.092Z,1518390493.092 [Startup:A.GoToSurface] Running Loop=1
2018-02-11T23:08:13.092Z,1518390493.092 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-02-11T23:08:13.093Z,1518390493.093 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-02-11T23:08:13.093Z,1518390493.093 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-02-11T23:08:13.094Z,1518390493.094 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-02-11T23:08:13.094Z,1518390493.094 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-02-11T23:08:13.094Z,1518390493.094 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-02-11T23:08:13.100Z,1518390493.100 [Startup:StartupSatComms] Running Loop=1
2018-02-11T23:08:13.100Z,1518390493.100 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-02-11T23:08:13.100Z,1518390493.100 [Startup:StartupSatComms:A] Running Loop=1
2018-02-11T23:08:13.492Z,1518390493.492 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-02-11T23:08:45.856Z,1518390525.856 [NAL9602](INFO): SBD MO Status=2, MOMSN=21569, MT Status=2, MTMSN=0
2018-02-11T23:08:45.856Z,1518390525.856 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2018-02-11T23:09:13.492Z,1518390553.492 [Startup:StartupSatComms:A](INFO): Timed out from 2018-02-11T23:08:13.1Z
2018-02-11T23:09:13.492Z,1518390553.492 [Startup:StartupSatComms:A] Stopped
2018-02-11T23:09:13.492Z,1518390553.492 [Startup:StartupSatComms:B] Running Loop=1
2018-02-11T23:09:13.901Z,1518390553.901 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-02-11T23:09:21.606Z,1518390561.606 [CommandLine](IMPORTANT): got command get platform_battery_voltage
2018-02-11T23:09:21.607Z,1518390561.607 [CommandLine](FAULT): Element has no value
2018-02-11T23:09:26.304Z,1518390566.304 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-02-11T23:09:26.304Z,1518390566.304 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2018-02-11T23:09:26.304Z,1518390566.304 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2018-02-11T23:09:26.306Z,1518390566.306 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-02-11T23:09:26.306Z,1518390566.306 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-02-11T23:09:26.306Z,1518390566.306 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-02-11T23:09:26.318Z,1518390566.318 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2018-02-11T23:09:26.318Z,1518390566.318 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-02-11T23:09:26.712Z,1518390566.712 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2018-02-11T23:09:26.712Z,1518390566.712 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2018-02-11T23:09:26.712Z,1518390566.712 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-02-11T23:09:26.713Z,1518390566.713 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-02-11T23:09:27.100Z,1518390567.100 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-02-11T23:09:27.101Z,1518390567.101 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-02-11T23:09:27.101Z,1518390567.101 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-02-11T23:09:27.102Z,1518390567.102 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-02-11T23:09:27.102Z,1518390567.102 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-02-11T23:09:27.102Z,1518390567.102 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-02-11T23:09:27.507Z,1518390567.507 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2018-02-11T23:09:30.620Z,1518390570.620 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.3 s old, using for 20.0 s.
2018-02-11T23:09:30.763Z,1518390570.763 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.5 s old, using for 20.0 s.
2018-02-11T23:09:31.091Z,1518390571.091 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2018-02-11T23:09:31.445Z,1518390571.445 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003699
2018-02-11T23:09:31.513Z,1518390571.513 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2018-02-11T23:09:32.616Z,1518390572.616 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.3 s old, using for 20.0 s.
2018-02-11T23:09:32.743Z,1518390572.743 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2018-02-11T23:09:35.793Z,1518390575.793 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.5 s old, using for 20.0 s.
2018-02-11T23:09:35.845Z,1518390575.845 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20180211T214251/Courier0036.lzma
2018-02-11T23:09:35.935Z,1518390575.935 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2018-02-11T23:09:36.286Z,1518390576.286 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2018-02-11T23:09:36.646Z,1518390576.646 [DataOverHttps](INFO): Moved sent file to Logs/20180211T214251/Courier0036.lzma.bak
2018-02-11T23:09:36.646Z,1518390576.646 [DataOverHttps](INFO): SBD MOMSN=7853540
2018-02-11T23:09:36.713Z,1518390576.713 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2018-02-11T23:09:37.855Z,1518390577.855 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2018-02-11T23:09:37.000Z,1518390578.000 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.7 s old, using for 20.0 s.
2018-02-11T23:09:41.540Z,1518390581.540 [NAL9602](INFO): SBD MO Status=0, MOMSN=21569, MT Status=0, MTMSN=0
2018-02-11T23:09:41.540Z,1518390581.540 [NAL9602](INFO): No messages in MT queue
2018-02-11T23:09:41.589Z,1518390581.589 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.3 s old, using for 20.0 s.
2018-02-11T23:09:41.712Z,1518390581.712 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.4 s old, using for 20.0 s.
2018-02-11T23:09:42.058Z,1518390582.058 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.8 s old, using for 20.0 s.
2018-02-11T23:09:42.419Z,1518390582.419 [NAL9602](INFO): GPS fix at 20180211T225937: (36.802783, -121.787704)
2018-02-11T23:09:42.487Z,1518390582.487 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.2 s old, using for 20.0 s.
2018-02-11T23:09:42.866Z,1518390582.866 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.6 s old, using for 20.0 s.
2018-02-11T23:09:43.261Z,1518390583.261 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.0 s old, using for 20.0 s.
2018-02-11T23:09:48.566Z,1518390588.566 [DataOverHttps](INFO): Sending 330 bytes from file Logs/20180211T230616/Courier0000.lzma
2018-02-11T23:09:49.246Z,1518390589.246 [CommandLine](IMPORTANT): got command quit
2018-02-11T23:09:49.360Z,1518390589.360 [DataOverHttps](INFO): Moved sent file to Logs/20180211T230616/Courier0000.lzma.bak
2018-02-11T23:09:49.360Z,1518390589.360 [DataOverHttps](INFO): SBD MOMSN=7853542
2018-02-11T23:09:50.256Z,1518390590.256 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-11T23:09:50.256Z,1518390590.256 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.453Z,1518390590.453 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-02-11T23:09:50.453Z,1518390590.453 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.453Z,1518390590.453 [CommandLine](INFO): Join timeout helper Thread ID is 1699
2018-02-11T23:09:50.473Z,1518390590.473 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-02-11T23:09:50.473Z,1518390590.473 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.473Z,1518390590.473 [NavChartDb](INFO): Join timeout helper Thread ID is 1700
2018-02-11T23:09:50.510Z,1518390590.510 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-11T23:09:50.510Z,1518390590.510 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.529Z,1518390590.529 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-02-11T23:09:50.529Z,1518390590.529 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.529Z,1518390590.529 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1701
2018-02-11T23:09:50.717Z,1518390590.717 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-11T23:09:50.717Z,1518390590.717 [WetLabsBB2FL](INFO): Powering down
2018-02-11T23:09:50.718Z,1518390590.718 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.729Z,1518390590.729 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-02-11T23:09:50.729Z,1518390590.729 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.729Z,1518390590.729 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1702
2018-02-11T23:09:50.809Z,1518390590.809 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-11T23:09:50.947Z,1518390590.947 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-02-11T23:09:50.947Z,1518390590.947 [CTD_Seabird](INFO): Powering down
2018-02-11T23:09:50.948Z,1518390590.948 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.957Z,1518390590.957 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-02-11T23:09:50.957Z,1518390590.957 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:50.958Z,1518390590.958 [Radio_Surface](INFO): Join timeout helper Thread ID is 1704
2018-02-11T23:09:51.350Z,1518390591.350 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-11T23:09:51.350Z,1518390591.350 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.366Z,1518390591.366 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-02-11T23:09:51.366Z,1518390591.366 [logger ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.367Z,1518390591.367 [logger](INFO): Join timeout helper Thread ID is 1705
2018-02-11T23:09:51.367Z,1518390591.367 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-11T23:09:51.367Z,1518390591.367 [logger ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.369Z,1518390591.369 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-02-11T23:09:51.369Z,1518390591.369 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.369Z,1518390591.369 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-02-11T23:09:51.369Z,1518390591.369 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.369Z,1518390591.369 [controlThread](INFO): Join timeout helper Thread ID is 1706
2018-02-11T23:09:51.480Z,1518390591.480 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-02-11T23:09:51.480Z,1518390591.480 [controlThread](DEBUG): Uninitializing ControlThread
2018-02-11T23:09:51.480Z,1518390591.480 [AcousticModem_Benthos_ATM900](INFO): Powering down
2018-02-11T23:09:51.602Z,1518390591.602 [NAL9602](INFO): Powering down
2018-02-11T23:09:51.604Z,1518390591.604 [PNI_TCM](INFO): Powering down
2018-02-11T23:09:51.689Z,1518390591.689 [Aanderaa_O2](INFO): Powering down
2018-02-11T23:09:51.691Z,1518390591.691 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-02-11T23:09:51.692Z,1518390591.692 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-02-11T23:09:51.692Z,1518390591.692 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-02-11T23:09:51.693Z,1518390591.693 [MissionManager](INFO): Uninitializing Mission Default
2018-02-11T23:09:51.696Z,1518390591.696 [MissionManager](INFO): Uninitializing Mission Startup
2018-02-11T23:09:51.696Z,1518390591.696 [Startup] Stopped
2018-02-11T23:09:51.696Z,1518390591.696 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-02-11T23:09:51.696Z,1518390591.696 [Startup:A.GoToSurface] Stopped
2018-02-11T23:09:51.696Z,1518390591.696 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-02-11T23:09:51.696Z,1518390591.696 [Startup:StartupSatComms] Stopped
2018-02-11T23:09:51.696Z,1518390591.696 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-02-11T23:09:51.696Z,1518390591.696 [Startup:StartupSatComms:B] Stopped
2018-02-11T23:09:51.698Z,1518390591.698 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-02-11T23:09:51.698Z,1518390591.698 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-02-11T23:09:51.699Z,1518390591.699 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-02-11T23:09:51.699Z,1518390591.699 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-02-11T23:09:51.699Z,1518390591.699 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-02-11T23:09:51.699Z,1518390591.699 [BuoyancyServo](INFO): Powering down
2018-02-11T23:09:51.713Z,1518390591.713 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-02-11T23:09:51.713Z,1518390591.713 [ElevatorServo](INFO): Powering down
2018-02-11T23:09:51.714Z,1518390591.714 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-02-11T23:09:51.714Z,1518390591.714 [MassServo](INFO): Powering down
2018-02-11T23:09:51.714Z,1518390591.714 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-02-11T23:09:51.715Z,1518390591.715 [RudderServo](INFO): Powering down
2018-02-11T23:09:51.715Z,1518390591.715 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-02-11T23:09:51.715Z,1518390591.715 [ThrusterServo](INFO): Powering down
2018-02-11T23:09:51.716Z,1518390591.716 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-02-11T23:09:51.717Z,1518390591.717 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-02-11T23:09:51.717Z,1518390591.717 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-02-11T23:09:51.718Z,1518390591.718 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.802Z,1518390591.802 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.839Z,1518390591.839 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.843Z,1518390591.843 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.888Z,1518390591.888 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-02-11T23:09:51.944Z,1518390591.944 [logger ThreadHandler](INFO): Thread cancelled.