2018-06-03T19:16:29.971Z,1528053389.971 [Supervisor](DEBUG): Initializing supervisor.
2018-06-03T19:16:29.973Z,1528053389.973 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-06-03T19:16:29.974Z,1528053389.974 [SyncHandler](INFO): Protected caller Thread ID is 798
2018-06-03T19:16:29.974Z,1528053389.974 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-06-03T19:16:29.975Z,1528053389.975 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-06-03T19:16:29.976Z,1528053389.976 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 799
2018-06-03T19:16:29.978Z,1528053389.978 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-06-03T19:16:29.990Z,1528053389.990 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-06-03T19:16:29.991Z,1528053389.991 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-06-03T19:16:29.991Z,1528053389.991 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 800
2018-06-03T19:16:29.992Z,1528053389.992 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-06-03T19:16:29.993Z,1528053389.993 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-06-03T19:16:29.994Z,1528053389.994 [logger ThreadHandler](INFO): Protected caller Thread ID is 801
2018-06-03T19:16:29.995Z,1528053389.995 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-06-03T19:16:29.996Z,1528053389.996 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-06-03T19:16:29.000Z,1528053390.000 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-06-03T19:16:30.355Z,1528053390.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-06-03T19:16:30.357Z,1528053390.357 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-06-03T19:16:30.569Z,1528053390.569 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-06-03T19:16:30.570Z,1528053390.570 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-06-03T19:16:30.877Z,1528053390.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-06-03T19:16:30.879Z,1528053390.879 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-06-03T19:16:31.023Z,1528053391.023 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-06-03T19:16:31.024Z,1528053391.024 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-06-03T19:16:31.124Z,1528053391.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-06-03T19:16:31.125Z,1528053391.125 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-06-03T19:16:31.620Z,1528053391.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-06-03T19:16:31.622Z,1528053391.622 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-06-03T19:16:32.031Z,1528053392.031 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-06-03T19:16:32.033Z,1528053392.033 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-06-03T19:16:32.504Z,1528053392.504 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-06-03T19:16:32.506Z,1528053392.506 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-06-03T19:16:32.614Z,1528053392.614 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-06-03T19:16:32.615Z,1528053392.615 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-06-03T19:16:32.715Z,1528053392.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-06-03T19:16:32.715Z,1528053392.715 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-06-03T19:16:32.931Z,1528053392.931 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-06-03T19:16:32.931Z,1528053392.931 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-06-03T19:16:33.150Z,1528053393.150 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-06-03T19:16:33.151Z,1528053393.151 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-06-03T19:16:33.519Z,1528053393.519 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-06-03T19:16:33.519Z,1528053393.519 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-06-03T19:16:33.671Z,1528053393.671 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-06-03T19:16:33.672Z,1528053393.672 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-06-03T19:16:34.578Z,1528053394.578 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-06-03T19:16:34.581Z,1528053394.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-06-03T19:16:34.689Z,1528053394.689 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-06-03T19:16:34.813Z,1528053394.813 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-06-03T19:16:34.912Z,1528053394.912 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-06-03T19:16:34.999Z,1528053394.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-06-03T19:16:35.158Z,1528053395.158 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-06-03T19:16:35.345Z,1528053395.345 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-06-03T19:16:35.422Z,1528053395.422 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-06-03T19:16:35.658Z,1528053395.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-06-03T19:16:35.659Z,1528053395.659 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-06-03T19:16:35.744Z,1528053395.744 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-06-03T19:16:35.835Z,1528053395.835 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-06-03T19:16:35.938Z,1528053395.938 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-06-03T19:16:36.069Z,1528053396.069 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-06-03T19:16:36.073Z,1528053396.073 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-06-03T19:16:36.356Z,1528053396.356 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-06-03T19:16:36.358Z,1528053396.358 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-06-03T19:16:36.414Z,1528053396.414 [DepthRateCalculator] Loaded
2018-06-03T19:16:36.414Z,1528053396.414 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-06-03T19:16:36.420Z,1528053396.420 [PitchRateCalculator] Loaded
2018-06-03T19:16:36.420Z,1528053396.420 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-06-03T19:16:36.437Z,1528053396.437 [SpeedCalculator] Loaded
2018-06-03T19:16:36.437Z,1528053396.437 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-06-03T19:16:36.458Z,1528053396.458 [TempGradientCalculator] Loaded
2018-06-03T19:16:36.458Z,1528053396.458 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-06-03T19:16:36.474Z,1528053396.474 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-06-03T19:16:36.474Z,1528053396.474 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-06-03T19:16:36.480Z,1528053396.480 [YawRateCalculator] Loaded
2018-06-03T19:16:36.481Z,1528053396.481 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-06-03T19:16:36.521Z,1528053396.521 [ElevatorOffsetCalculator] Loaded
2018-06-03T19:16:36.521Z,1528053396.521 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-06-03T19:16:36.521Z,1528053396.521 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-06-03T19:16:36.522Z,1528053396.522 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-06-03T19:16:36.643Z,1528053396.643 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-06-03T19:16:36.644Z,1528053396.644 [StratificationFrontDetector](DEBUG): (re)initializing
2018-06-03T19:16:36.644Z,1528053396.644 [StratificationFrontDetector] Loaded
2018-06-03T19:16:36.644Z,1528053396.644 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-06-03T19:16:36.645Z,1528053396.645 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-06-03T19:16:36.645Z,1528053396.645 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-06-03T19:16:36.778Z,1528053396.778 [BuoyancyServo] Loaded
2018-06-03T19:16:36.779Z,1528053396.779 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-06-03T19:16:36.794Z,1528053396.794 [ElevatorServo] Loaded
2018-06-03T19:16:36.794Z,1528053396.794 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-06-03T19:16:36.809Z,1528053396.809 [MassServo] Loaded
2018-06-03T19:16:36.809Z,1528053396.809 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-06-03T19:16:36.824Z,1528053396.824 [RudderServo] Loaded
2018-06-03T19:16:36.825Z,1528053396.825 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-06-03T19:16:36.839Z,1528053396.839 [ThrusterServo] Loaded
2018-06-03T19:16:36.839Z,1528053396.839 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-06-03T19:16:36.840Z,1528053396.840 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-06-03T19:16:36.841Z,1528053396.841 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-06-03T19:16:36.865Z,1528053396.865 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-06-03T19:16:36.865Z,1528053396.865 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-06-03T19:16:36.992Z,1528053396.992 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-06-03T19:16:36.993Z,1528053396.993 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-06-03T19:16:37.553Z,1528053397.553 [DataOverHttps] Loaded
2018-06-03T19:16:37.554Z,1528053397.554 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-06-03T19:16:37.568Z,1528053397.568 [Depth_Keller] Loaded
2018-06-03T19:16:37.568Z,1528053397.568 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-06-03T19:16:37.573Z,1528053397.573 [DropWeight] Loaded
2018-06-03T19:16:37.573Z,1528053397.573 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-06-03T19:16:37.673Z,1528053397.673 [NAL9602] Loaded
2018-06-03T19:16:37.673Z,1528053397.673 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-06-03T19:16:37.689Z,1528053397.689 [Onboard] Loaded
2018-06-03T19:16:37.689Z,1528053397.689 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-06-03T19:16:37.699Z,1528053397.699 [Radio_Surface] Loaded
2018-06-03T19:16:37.700Z,1528053397.700 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-06-03T19:16:37.701Z,1528053397.701 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0
2018-06-03T19:16:37.701Z,1528053397.701 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 883
2018-06-03T19:16:37.856Z,1528053397.856 [PNI_TCM] Loaded
2018-06-03T19:16:37.856Z,1528053397.856 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-06-03T19:16:37.917Z,1528053397.917 [Rowe_600LCM] Loaded
2018-06-03T19:16:37.918Z,1528053397.918 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-06-03T19:16:37.919Z,1528053397.919 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408B44E0
2018-06-03T19:16:37.919Z,1528053397.919 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 884
2018-06-03T19:16:40.100Z,1528053400.100 [BPC1] Loaded
2018-06-03T19:16:40.100Z,1528053400.100 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-06-03T19:16:40.100Z,1528053400.100 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-06-03T19:16:40.101Z,1528053400.101 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-06-03T19:16:40.257Z,1528053400.257 [SBIT](DEBUG): Construct Startup Built In Test.
2018-06-03T19:16:40.279Z,1528053400.279 [SBIT] Loaded
2018-06-03T19:16:40.280Z,1528053400.280 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-06-03T19:16:40.280Z,1528053400.280 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-06-03T19:16:40.292Z,1528053400.292 [IBIT] Loaded
2018-06-03T19:16:40.292Z,1528053400.292 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-06-03T19:16:40.295Z,1528053400.295 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-06-03T19:16:40.448Z,1528053400.448 [CBIT] Loaded
2018-06-03T19:16:40.448Z,1528053400.448 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-06-03T19:16:40.448Z,1528053400.448 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-06-03T19:16:40.449Z,1528053400.449 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-06-03T19:16:40.638Z,1528053400.638 [Aanderaa_O2] Loaded
2018-06-03T19:16:40.639Z,1528053400.639 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-06-03T19:16:40.651Z,1528053400.651 [CANONSampler] Loaded
2018-06-03T19:16:40.651Z,1528053400.651 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2018-06-03T19:16:40.730Z,1528053400.730 [CTD_NeilBrown] Loaded
2018-06-03T19:16:40.730Z,1528053400.730 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-06-03T19:16:40.731Z,1528053400.731 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409754E0
2018-06-03T19:16:40.732Z,1528053400.732 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 886
2018-06-03T19:16:40.778Z,1528053400.778 [CTD_Seabird] Loaded
2018-06-03T19:16:40.779Z,1528053400.779 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-06-03T19:16:40.780Z,1528053400.780 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0
2018-06-03T19:16:40.780Z,1528053400.780 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 887
2018-06-03T19:16:40.795Z,1528053400.795 [PAR_Licor] Loaded
2018-06-03T19:16:40.795Z,1528053400.795 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-06-03T19:16:40.845Z,1528053400.845 [WetLabsBB2FL] Loaded
2018-06-03T19:16:40.846Z,1528053400.846 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-06-03T19:16:40.847Z,1528053400.847 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409D54E0
2018-06-03T19:16:40.847Z,1528053400.847 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 888
2018-06-03T19:16:40.848Z,1528053400.848 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-06-03T19:16:40.848Z,1528053400.848 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-06-03T19:16:40.937Z,1528053400.937 [VerticalControl](DEBUG): Construct VerticalControl.
2018-06-03T19:16:41.022Z,1528053401.022 [VerticalControl] Loaded
2018-06-03T19:16:41.022Z,1528053401.022 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-06-03T19:16:41.023Z,1528053401.023 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-06-03T19:16:41.081Z,1528053401.081 [HorizontalControl] Loaded
2018-06-03T19:16:41.081Z,1528053401.081 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-06-03T19:16:41.082Z,1528053401.082 [SpeedControl](DEBUG): Construct SpeedControl.
2018-06-03T19:16:41.083Z,1528053401.083 [SpeedControl] Loaded
2018-06-03T19:16:41.084Z,1528053401.084 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-06-03T19:16:41.084Z,1528053401.084 [LoopControl](DEBUG): Construct LoopControl.
2018-06-03T19:16:41.085Z,1528053401.085 [LoopControl] Loaded
2018-06-03T19:16:41.085Z,1528053401.085 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-06-03T19:16:41.086Z,1528053401.086 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-06-03T19:16:41.086Z,1528053401.086 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-06-03T19:16:41.124Z,1528053401.124 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-06-03T19:16:41.125Z,1528053401.125 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-06-03T19:16:41.233Z,1528053401.233 [DeadReckonUsingSpeedCalculator] Loaded
2018-06-03T19:16:41.233Z,1528053401.233 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-06-03T19:16:41.249Z,1528053401.249 [NavChart] Loaded
2018-06-03T19:16:41.250Z,1528053401.250 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-06-03T19:16:41.254Z,1528053401.254 [UniversalFixResidualReporter] Loaded
2018-06-03T19:16:41.254Z,1528053401.254 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-06-03T19:16:41.254Z,1528053401.254 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-06-03T19:16:41.258Z,1528053401.258 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-06-03T19:16:41.259Z,1528053401.259 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-06-03T19:16:41.266Z,1528053401.266 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-06-03T19:16:41.267Z,1528053401.267 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A614E0
2018-06-03T19:16:41.267Z,1528053401.267 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 889
2018-06-03T19:16:41.272Z,1528053401.272 [Supervisor](INFO): Main Thread ID is 797
2018-06-03T19:16:41.272Z,1528053401.272 [Supervisor](DEBUG): Running supervisor.
2018-06-03T19:16:41.273Z,1528053401.273 [CommandLine ThreadHandler](INFO): Handler Thread ID is 890
2018-06-03T19:16:41.275Z,1528053401.275 [controlThread ThreadHandler](INFO): Handler Thread ID is 891
2018-06-03T19:16:41.276Z,1528053401.276 [controlThread](DEBUG): Initializing ControlThread
2018-06-03T19:16:41.276Z,1528053401.276 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-06-03T19:16:41.277Z,1528053401.277 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-06-03T19:16:41.277Z,1528053401.277 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-06-03T19:16:41.278Z,1528053401.278 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-06-03T19:16:41.278Z,1528053401.278 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-06-03T19:16:41.279Z,1528053401.279 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-06-03T19:16:41.279Z,1528053401.279 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-06-03T19:16:41.287Z,1528053401.287 [SBIT](INFO): Initialize SBIT Component.
2018-06-03T19:16:41.288Z,1528053401.288 [SBIT](IMPORTANT): git: 2018-06-03
2018-06-03T19:16:41.288Z,1528053401.288 [SBIT](INFO): git hash: e89e4219fcae2edd415aee450018ea5d8b44159b
2018-06-03T19:16:41.288Z,1528053401.288 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-06-03T19:16:41.290Z,1528053401.290 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-06-03T19:16:41.291Z,1528053401.291 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-06-03T19:16:41.291Z,1528053401.291 [IBIT](INFO): Initialize IBIT Component.
2018-06-03T19:16:41.292Z,1528053401.292 [CBIT](DEBUG): Initialize CBIT Component.
2018-06-03T19:16:41.292Z,1528053401.292 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-06-03T19:16:41.293Z,1528053401.293 [logger ThreadHandler](INFO): Handler Thread ID is 892
2018-06-03T19:16:41.313Z,1528053401.313 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 893
2018-06-03T19:16:41.319Z,1528053401.319 [Radio_Surface](INFO): Powering up
2018-06-03T19:16:41.325Z,1528053401.325 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 894
2018-06-03T19:16:41.326Z,1528053401.326 [Rowe_600LCM](INFO): Initializing
2018-06-03T19:16:41.326Z,1528053401.326 [Rowe_600LCM](INFO): Checking LCM
2018-06-03T19:16:41.405Z,1528053401.405 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-06-03T19:16:41.407Z,1528053401.407 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-06-03T19:16:41.408Z,1528053401.408 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-06-03T19:16:41.408Z,1528053401.408 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-06-03T19:16:41.409Z,1528053401.409 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-06-03T19:16:41.410Z,1528053401.410 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-06-03T19:16:41.442Z,1528053401.442 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-06-03T19:16:41.442Z,1528053401.442 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-06-03T19:16:41.443Z,1528053401.443 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-06-03T19:16:41.444Z,1528053401.444 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-06-03T19:16:41.454Z,1528053401.454 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 895
2018-06-03T19:16:41.455Z,1528053401.455 [CTD_NeilBrown](INFO): Powering down
2018-06-03T19:16:41.565Z,1528053401.565 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 896
2018-06-03T19:16:41.569Z,1528053401.569 [CTD_Seabird](INFO): Initializing
2018-06-03T19:16:41.570Z,1528053401.570 [CTD_Seabird](INFO): Checking LCM
2018-06-03T19:16:41.585Z,1528053401.585 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-06-03T19:16:41.589Z,1528053401.589 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 897
2018-06-03T19:16:41.590Z,1528053401.590 [WetLabsBB2FL](INFO): Powering down
2018-06-03T19:16:41.693Z,1528053401.693 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 898
2018-06-03T19:16:41.695Z,1528053401.695 [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-06-03T19:16:41.696Z,1528053401.696 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-06-03T19:16:41.740Z,1528053401.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-06-03T19:16:41.740Z,1528053401.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-06-03T19:16:41.740Z,1528053401.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-06-03T19:16:41.740Z,1528053401.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-06-03T19:16:41.741Z,1528053401.741 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-06-03T19:16:41.741Z,1528053401.741 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-06-03T19:16:41.741Z,1528053401.741 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-06-03T19:16:41.741Z,1528053401.741 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-06-03T19:16:41.741Z,1528053401.741 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-06-03T19:16:41.742Z,1528053401.742 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-06-03T19:16:41.742Z,1528053401.742 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-06-03T19:16:41.742Z,1528053401.742 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-06-03T19:16:41.742Z,1528053401.742 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-06-03T19:16:41.742Z,1528053401.742 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-06-03T19:16:41.743Z,1528053401.743 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-06-03T19:16:41.743Z,1528053401.743 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-06-03T19:16:41.786Z,1528053401.786 [CTD_Seabird](INFO): LCM OK
2018-06-03T19:16:41.786Z,1528053401.786 [CTD_Seabird](INFO): Powering up
2018-06-03T19:16:41.787Z,1528053401.787 [Rowe_600LCM](INFO): LCM OK
2018-06-03T19:16:41.787Z,1528053401.787 [Rowe_600LCM](INFO): Powering up
2018-06-03T19:16:41.840Z,1528053401.840 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-06-03T19:16:41.854Z,1528053401.854 [Default:A.Wait](DEBUG): Construct Wait.
2018-06-03T19:16:41.855Z,1528053401.855 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-06-03T19:16:41.898Z,1528053401.898 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-06-03T19:16:41.900Z,1528053401.900 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-06-03T19:16:41.916Z,1528053401.916 [Default:E.Execute](DEBUG): Construct Execute.
2018-06-03T19:16:41.935Z,1528053401.935 [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 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-06-03T19:16:41.941Z,1528053401.941 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-06-03T19:16:41.995Z,1528053401.995 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-06-03T19:16:42.018Z,1528053402.018 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-06-03T19:16:42.261Z,1528053402.261 [CANONSampler](INFO): Powering down
2018-06-03T19:16:42.367Z,1528053402.367 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-06-03T19:16:42.473Z,1528053402.473 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:42.705Z,1528053402.705 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-06-03T19:16:42.713Z,1528053402.713 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-06-03T19:16:42.728Z,1528053402.728 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-06-03T19:16:42.733Z,1528053402.733 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-06-03T19:16:42.766Z,1528053402.766 [MassServo](DEBUG): Initializing EZServoServo.
2018-06-03T19:16:42.773Z,1528053402.773 [MassServo](DEBUG): Initializing MassServo.
2018-06-03T19:16:42.779Z,1528053402.779 [RudderServo](DEBUG): Initializing EZServoServo.
2018-06-03T19:16:42.785Z,1528053402.785 [RudderServo](DEBUG): Initializing RudderServo.
2018-06-03T19:16:42.799Z,1528053402.799 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-06-03T19:16:42.805Z,1528053402.805 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-06-03T19:16:43.138Z,1528053403.138 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:43.357Z,1528053403.357 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:43.701Z,1528053403.701 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-06-03T19:16:43.701Z,1528053403.701 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-06-03T19:16:43.701Z,1528053403.701 [BuoyancyServo] Communications Fault, FailCount= 1
2018-06-03T19:16:43.701Z,1528053403.701 [BuoyancyServo](ERROR): Communications Fault
2018-06-03T19:16:43.913Z,1528053403.913 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-06-03T19:16:43.955Z,1528053403.955 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:43.973Z,1528053403.973 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-06-03T19:16:43.974Z,1528053403.974 [BuoyancyServo](INFO): Powering down
2018-06-03T19:16:44.417Z,1528053404.417 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:44.793Z,1528053404.793 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:45.162Z,1528053405.162 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:45.583Z,1528053405.583 [Aanderaa_O2](INFO): Powering down
2018-06-03T19:16:45.688Z,1528053405.688 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-06-03T19:16:45.905Z,1528053405.905 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-06-03T19:16:46.060Z,1528053406.060 [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-06-03T19:16:46.178Z,1528053406.178 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-06-03T19:16:46.178Z,1528053406.178 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-06-03T19:16:46.179Z,1528053406.179 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-06-03T19:16:46.214Z,1528053406.214 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-06-03T19:16:46.214Z,1528053406.214 [BuoyancyServo] No Fault, FailCount= 1
2018-06-03T19:16:46.418Z,1528053406.418 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-06-03T19:16:46.418Z,1528053406.418 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-06-03T19:16:47.326Z,1528053407.326 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-06-03T19:16:47.349Z,1528053407.349 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2018-06-03T19:16:47.349Z,1528053407.349 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2018-06-03T19:16:47.350Z,1528053407.350 [BuoyancyServo] Communications Fault, FailCount= 2
2018-06-03T19:16:47.350Z,1528053407.350 [BuoyancyServo](ERROR): Communications Fault
2018-06-03T19:16:47.473Z,1528053407.473 [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-06-03T19:16:47.475Z,1528053407.475 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd
2018-06-03T19:16:47.811Z,1528053407.811 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2018-06-03T19:16:48.310Z,1528053408.310 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-06-03T19:16:48.316Z,1528053408.316 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-06-03T19:16:48.316Z,1528053408.316 [CTD_Seabird](INFO): Powering down
2018-06-03T19:16:48.346Z,1528053408.346 [BuoyancyServo](INFO): Powering down
2018-06-03T19:16:50.546Z,1528053410.546 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2018-06-03T19:16:50.546Z,1528053410.546 [BuoyancyServo] No Fault, FailCount= 2
2018-06-03T19:16:50.899Z,1528053410.899 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-06-03T19:16:50.899Z,1528053410.899 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-06-03T19:17:04.970Z,1528053424.970 [SBIT](IMPORTANT): Beginning Startup BIT
2018-06-03T19:17:04.984Z,1528053424.984 [CBIT](IMPORTANT): Beginning ground fault scan
2018-06-03T19:17:07.776Z,1528053427.776 [NAL9602](INFO): Powering up NAL9602
2018-06-03T19:17:16.334Z,1528053436.334 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): -0.007231
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001251
CHAN B0 (3.3V): -0.000128
CHAN B1 (3.15aV): -0.000082
CHAN B2 (3.15bV): -0.000225
CHAN B3 (GND): 0.000126
OPEN: -0.000112
Full Scale Calc: 4.765 mA, -1.589 mA
2018-06-03T19:17:18.976Z,1528053438.976 [NAL9602](INFO): NAL9602 initialized
2018-06-03T19:17:53.711Z,1528053473.711 [CommandLine](IMPORTANT): got command configSet list
2018-06-03T19:17:53.712Z,1528053473.712 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-06-03T19:17:53.712Z,1528053473.712 [CommandLine](IMPORTANT): No configSet variables persisted
2018-06-03T19:17:59.146Z,1528053479.146 [SBIT](IMPORTANT): SBIT PASSED
2018-06-03T19:17:59.217Z,1528053479.217 [CommandLine](IMPORTANT): got command configSet list
2018-06-03T19:17:59.218Z,1528053479.218 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-06-03T19:17:59.218Z,1528053479.218 [CommandLine](IMPORTANT): No configSet variables persisted
2018-06-03T19:17:59.534Z,1528053479.534 [MissionManager](IMPORTANT): Started mission Startup
2018-06-03T19:17:59.534Z,1528053479.534 [Startup] Running Loop=1
2018-06-03T19:17:59.535Z,1528053479.535 [Startup](DEBUG): Aggregate::initialize Startup
2018-06-03T19:17:59.535Z,1528053479.535 [Startup:A.GoToSurface] Running Loop=1
2018-06-03T19:17:59.535Z,1528053479.535 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-06-03T19:17:59.536Z,1528053479.536 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-06-03T19:17:59.537Z,1528053479.537 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-06-03T19:17:59.537Z,1528053479.537 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-06-03T19:17:59.538Z,1528053479.538 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-06-03T19:17:59.538Z,1528053479.538 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-06-03T19:17:59.589Z,1528053479.589 [Startup:StartupSatComms] Running Loop=1
2018-06-03T19:17:59.590Z,1528053479.590 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-06-03T19:17:59.590Z,1528053479.590 [Startup:StartupSatComms:A] Running Loop=1
2018-06-03T19:17:59.903Z,1528053479.903 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-06-03T19:18:42.597Z,1528053522.597 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-06-03T19:18:42.597Z,1528053522.597 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-06-03T19:18:42.597Z,1528053522.597 [Rowe_600LCM](ERROR): Communications Fault
2018-06-03T19:18:42.702Z,1528053522.702 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-06-03T19:18:43.002Z,1528053523.002 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-06-03T19:18:43.301Z,1528053523.301 [Rowe_600LCM](INFO): Powering down
2018-06-03T19:18:44.682Z,1528053524.682 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-06-03T19:18:44.682Z,1528053524.682 [Rowe_600LCM] No Fault, FailCount= 1
2018-06-03T19:18:44.917Z,1528053524.917 [Rowe_600LCM](INFO): Initializing
2018-06-03T19:18:44.917Z,1528053524.917 [Rowe_600LCM](INFO): Checking LCM
2018-06-03T19:18:44.917Z,1528053524.917 [Rowe_600LCM](INFO): LCM OK
2018-06-03T19:18:44.917Z,1528053524.917 [Rowe_600LCM](INFO): Powering up
2018-06-03T19:18:49.162Z,1528053529.162 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-06-03T19:18:49.227Z,1528053529.227 [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-06-03T19:18:49.230Z,1528053529.230 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-06-03T19:18:49.231Z,1528053529.231 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-06-03T19:18:49.231Z,1528053529.231 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-06-03T19:18:59.864Z,1528053539.864 [Startup:StartupSatComms:A](INFO): Timed out from 2018-06-03T19:17:59.6Z
2018-06-03T19:18:59.864Z,1528053539.864 [Startup:StartupSatComms:A] Stopped
2018-06-03T19:18:59.864Z,1528053539.864 [Startup:StartupSatComms:B] Running Loop=1
2018-06-03T19:19:00.263Z,1528053540.263 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-06-03T19:19:10.996Z,1528053550.996 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004761
2018-06-03T19:19:15.758Z,1528053555.758 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180603T190447/Courier0007.lzma
2018-06-03T19:19:16.557Z,1528053556.557 [DataOverHttps](INFO): Moved sent file to Logs/20180603T190447/Courier0007.lzma.bak
2018-06-03T19:19:16.557Z,1528053556.557 [DataOverHttps](INFO): SBD MOMSN=8309864
2018-06-03T19:19:21.058Z,1528053561.058 [CommandLine](IMPORTANT): got command restart application
2018-06-03T19:19:22.061Z,1528053562.061 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-06-03T19:19:22.065Z,1528053562.065 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:22.066Z,1528053562.066 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:22.229Z,1528053562.229 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-06-03T19:19:22.229Z,1528053562.229 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:22.230Z,1528053562.230 [CommandLine](INFO): Join timeout helper Thread ID is 936
2018-06-03T19:19:22.230Z,1528053562.230 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-06-03T19:19:22.230Z,1528053562.230 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:22.231Z,1528053562.231 [NavChartDb](INFO): Join timeout helper Thread ID is 937
2018-06-03T19:19:22.577Z,1528053562.577 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:22.577Z,1528053562.577 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:22.597Z,1528053562.597 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-06-03T19:19:22.597Z,1528053562.597 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:22.597Z,1528053562.597 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 938
2018-06-03T19:19:22.761Z,1528053562.761 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:22.761Z,1528053562.761 [WetLabsBB2FL](INFO): Powering down
2018-06-03T19:19:22.762Z,1528053562.762 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:22.765Z,1528053562.765 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-06-03T19:19:22.765Z,1528053562.765 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:22.765Z,1528053562.765 [CTD_Seabird](INFO): Join timeout helper Thread ID is 939
2018-06-03T19:19:22.833Z,1528053562.833 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:23.091Z,1528053563.091 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-06-03T19:19:23.091Z,1528053563.091 [CTD_Seabird](INFO): Powering down
2018-06-03T19:19:23.093Z,1528053563.093 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:23.097Z,1528053563.097 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-06-03T19:19:23.097Z,1528053563.097 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:23.098Z,1528053563.098 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 941
2018-06-03T19:19:23.246Z,1528053563.246 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:23.246Z,1528053563.246 [CTD_NeilBrown](INFO): Powering down
2018-06-03T19:19:23.247Z,1528053563.247 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:23.259Z,1528053563.259 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-06-03T19:19:23.259Z,1528053563.259 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:23.260Z,1528053563.260 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 942
2018-06-03T19:19:23.861Z,1528053563.861 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:23.861Z,1528053563.861 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-06-03T19:19:24.048Z,1528053564.048 [Rowe_600LCM](INFO): Powering down
2018-06-03T19:19:24.050Z,1528053564.050 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:24.062Z,1528053564.062 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-06-03T19:19:24.062Z,1528053564.062 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:24.062Z,1528053564.062 [Radio_Surface](INFO): Join timeout helper Thread ID is 944
2018-06-03T19:19:24.277Z,1528053564.277 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:24.277Z,1528053564.277 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:24.294Z,1528053564.294 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-06-03T19:19:24.294Z,1528053564.294 [logger ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:24.294Z,1528053564.294 [logger](INFO): Join timeout helper Thread ID is 945
2018-06-03T19:19:24.333Z,1528053564.333 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:24.333Z,1528053564.333 [logger ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:24.346Z,1528053564.346 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-06-03T19:19:24.346Z,1528053564.346 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:24.346Z,1528053564.346 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-06-03T19:19:24.346Z,1528053564.346 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:24.347Z,1528053564.347 [controlThread](INFO): Join timeout helper Thread ID is 946
2018-06-03T19:19:26.611Z,1528053566.611 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-06-03T19:19:26.611Z,1528053566.611 [controlThread](DEBUG): Uninitializing ControlThread
2018-06-03T19:19:26.615Z,1528053566.615 [NAL9602](INFO): Powering down
2018-06-03T19:19:26.624Z,1528053566.624 [PNI_TCM](INFO): Powering down
2018-06-03T19:19:26.714Z,1528053566.714 [Aanderaa_O2](INFO): Powering down
2018-06-03T19:19:26.717Z,1528053566.717 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-06-03T19:19:26.719Z,1528053566.719 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-06-03T19:19:26.719Z,1528053566.719 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-06-03T19:19:26.720Z,1528053566.720 [MissionManager](INFO): Uninitializing Mission Default
2018-06-03T19:19:26.723Z,1528053566.723 [MissionManager](INFO): Uninitializing Mission Startup
2018-06-03T19:19:26.723Z,1528053566.723 [Startup] Stopped
2018-06-03T19:19:26.723Z,1528053566.723 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-06-03T19:19:26.723Z,1528053566.723 [Startup:A.GoToSurface] Stopped
2018-06-03T19:19:26.723Z,1528053566.723 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-06-03T19:19:26.723Z,1528053566.723 [Startup:StartupSatComms] Stopped
2018-06-03T19:19:26.723Z,1528053566.723 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-06-03T19:19:26.724Z,1528053566.724 [Startup:StartupSatComms:B] Stopped
2018-06-03T19:19:26.742Z,1528053566.742 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-06-03T19:19:26.742Z,1528053566.742 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-06-03T19:19:26.743Z,1528053566.743 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-06-03T19:19:26.743Z,1528053566.743 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-06-03T19:19:26.744Z,1528053566.744 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-06-03T19:19:26.744Z,1528053566.744 [BuoyancyServo](INFO): Powering down
2018-06-03T19:19:26.757Z,1528053566.757 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-06-03T19:19:26.757Z,1528053566.757 [ElevatorServo](INFO): Powering down
2018-06-03T19:19:26.758Z,1528053566.758 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-06-03T19:19:26.758Z,1528053566.758 [MassServo](INFO): Powering down
2018-06-03T19:19:26.759Z,1528053566.759 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-06-03T19:19:26.759Z,1528053566.759 [RudderServo](INFO): Powering down
2018-06-03T19:19:26.760Z,1528053566.760 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-06-03T19:19:26.760Z,1528053566.760 [ThrusterServo](INFO): Powering down
2018-06-03T19:19:26.761Z,1528053566.761 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-06-03T19:19:26.762Z,1528053566.762 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-06-03T19:19:26.762Z,1528053566.762 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-06-03T19:19:26.763Z,1528053566.763 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:27.087Z,1528053567.087 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:27.094Z,1528053567.094 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:27.131Z,1528053567.131 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:27.134Z,1528053567.134 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:27.137Z,1528053567.137 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:27.226Z,1528053567.226 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-06-03T19:19:27.286Z,1528053567.286 [logger ThreadHandler](INFO): Thread cancelled.