2018-01-23T00:24:46.772Z,1516667086.772 [Supervisor](DEBUG): Initializing supervisor.
2018-01-23T00:24:46.775Z,1516667086.775 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-01-23T00:24:46.775Z,1516667086.775 [SyncHandler](INFO): Protected caller Thread ID is 799
2018-01-23T00:24:46.776Z,1516667086.776 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-01-23T00:24:46.777Z,1516667086.777 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-01-23T00:24:46.777Z,1516667086.777 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 800
2018-01-23T00:24:46.780Z,1516667086.780 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-01-23T00:24:46.792Z,1516667086.792 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-01-23T00:24:46.793Z,1516667086.793 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-01-23T00:24:46.793Z,1516667086.793 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 801
2018-01-23T00:24:46.794Z,1516667086.794 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-01-23T00:24:46.795Z,1516667086.795 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-01-23T00:24:46.795Z,1516667086.795 [logger ThreadHandler](INFO): Protected caller Thread ID is 802
2018-01-23T00:24:46.797Z,1516667086.797 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-01-23T00:24:46.798Z,1516667086.798 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-01-23T00:24:46.802Z,1516667086.802 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-01-23T00:24:47.100Z,1516667087.100 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-01-23T00:24:47.102Z,1516667087.102 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-01-23T00:24:47.281Z,1516667087.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-01-23T00:24:47.283Z,1516667087.283 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-01-23T00:24:47.544Z,1516667087.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-01-23T00:24:47.545Z,1516667087.545 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-01-23T00:24:47.681Z,1516667087.681 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-01-23T00:24:47.682Z,1516667087.682 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-01-23T00:24:47.777Z,1516667087.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-01-23T00:24:47.779Z,1516667087.779 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-01-23T00:24:48.205Z,1516667088.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-01-23T00:24:48.206Z,1516667088.206 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-01-23T00:24:48.526Z,1516667088.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-01-23T00:24:48.527Z,1516667088.527 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-01-23T00:24:48.942Z,1516667088.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-01-23T00:24:48.944Z,1516667088.944 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-01-23T00:24:49.046Z,1516667089.046 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-01-23T00:24:49.047Z,1516667089.047 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-01-23T00:24:49.143Z,1516667089.143 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-01-23T00:24:49.143Z,1516667089.143 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-01-23T00:24:49.333Z,1516667089.333 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-01-23T00:24:49.335Z,1516667089.335 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-01-23T00:24:49.523Z,1516667089.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-01-23T00:24:49.524Z,1516667089.524 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-01-23T00:24:49.836Z,1516667089.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-01-23T00:24:49.836Z,1516667089.836 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-01-23T00:24:49.971Z,1516667089.971 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-01-23T00:24:49.972Z,1516667089.972 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-01-23T00:24:50.055Z,1516667090.055 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-01-23T00:24:50.058Z,1516667090.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-01-23T00:24:51.118Z,1516667091.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-01-23T00:24:51.286Z,1516667091.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-01-23T00:24:51.378Z,1516667091.378 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-01-23T00:24:51.462Z,1516667091.462 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-01-23T00:24:51.604Z,1516667091.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-01-23T00:24:51.770Z,1516667091.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-01-23T00:24:51.846Z,1516667091.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-01-23T00:24:52.067Z,1516667092.067 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-01-23T00:24:52.068Z,1516667092.068 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-01-23T00:24:52.149Z,1516667092.149 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-01-23T00:24:52.238Z,1516667092.238 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-01-23T00:24:52.334Z,1516667092.334 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-01-23T00:24:52.454Z,1516667092.454 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-01-23T00:24:52.459Z,1516667092.459 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-01-23T00:24:52.735Z,1516667092.735 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-01-23T00:24:52.736Z,1516667092.736 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-01-23T00:24:52.791Z,1516667092.791 [DepthRateCalculator] Loaded
2018-01-23T00:24:52.791Z,1516667092.791 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-01-23T00:24:52.797Z,1516667092.797 [PitchRateCalculator] Loaded
2018-01-23T00:24:52.797Z,1516667092.797 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-01-23T00:24:52.813Z,1516667092.813 [SpeedCalculator] Loaded
2018-01-23T00:24:52.813Z,1516667092.813 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-01-23T00:24:52.834Z,1516667092.834 [TempGradientCalculator] Loaded
2018-01-23T00:24:52.834Z,1516667092.834 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-01-23T00:24:52.850Z,1516667092.850 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-01-23T00:24:52.850Z,1516667092.850 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-01-23T00:24:52.855Z,1516667092.855 [YawRateCalculator] Loaded
2018-01-23T00:24:52.856Z,1516667092.856 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-01-23T00:24:52.856Z,1516667092.856 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-01-23T00:24:52.857Z,1516667092.857 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-01-23T00:24:52.974Z,1516667092.974 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-01-23T00:24:52.974Z,1516667092.974 [StratificationFrontDetector](DEBUG): (re)initializing
2018-01-23T00:24:52.974Z,1516667092.974 [StratificationFrontDetector] Loaded
2018-01-23T00:24:52.975Z,1516667092.975 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-01-23T00:24:52.975Z,1516667092.975 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-01-23T00:24:52.977Z,1516667092.977 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-01-23T00:24:53.110Z,1516667093.110 [BuoyancyServo] Loaded
2018-01-23T00:24:53.110Z,1516667093.110 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-01-23T00:24:53.125Z,1516667093.125 [ElevatorServo] Loaded
2018-01-23T00:24:53.125Z,1516667093.125 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-01-23T00:24:53.139Z,1516667093.139 [MassServo] Loaded
2018-01-23T00:24:53.140Z,1516667093.140 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-01-23T00:24:53.155Z,1516667093.155 [RudderServo] Loaded
2018-01-23T00:24:53.155Z,1516667093.155 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-01-23T00:24:53.169Z,1516667093.169 [ThrusterServo] Loaded
2018-01-23T00:24:53.170Z,1516667093.170 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-01-23T00:24:53.170Z,1516667093.170 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-01-23T00:24:53.171Z,1516667093.171 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-01-23T00:24:53.195Z,1516667093.195 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-01-23T00:24:53.195Z,1516667093.195 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-01-23T00:24:53.317Z,1516667093.317 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-01-23T00:24:53.318Z,1516667093.318 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-01-23T00:24:53.852Z,1516667093.852 [DataOverHttps] Loaded
2018-01-23T00:24:53.852Z,1516667093.852 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-01-23T00:24:53.866Z,1516667093.866 [Depth_Keller] Loaded
2018-01-23T00:24:53.866Z,1516667093.866 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-01-23T00:24:53.871Z,1516667093.871 [DropWeight] Loaded
2018-01-23T00:24:53.871Z,1516667093.871 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-01-23T00:24:53.966Z,1516667093.966 [NAL9602] Loaded
2018-01-23T00:24:53.966Z,1516667093.966 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-01-23T00:24:53.982Z,1516667093.982 [Onboard] Loaded
2018-01-23T00:24:53.983Z,1516667093.983 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-01-23T00:24:53.993Z,1516667093.993 [Radio_Surface] Loaded
2018-01-23T00:24:53.993Z,1516667093.993 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-01-23T00:24:53.995Z,1516667093.995 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4086B4E0
2018-01-23T00:24:53.995Z,1516667093.995 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 884
2018-01-23T00:24:54.148Z,1516667094.148 [PNI_TCM] Loaded
2018-01-23T00:24:54.148Z,1516667094.148 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-01-23T00:24:54.207Z,1516667094.207 [Rowe_600LCM] Loaded
2018-01-23T00:24:54.207Z,1516667094.207 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-01-23T00:24:54.208Z,1516667094.208 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 4089B4E0
2018-01-23T00:24:54.209Z,1516667094.209 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 885
2018-01-23T00:24:56.275Z,1516667096.275 [BPC1] Loaded
2018-01-23T00:24:56.276Z,1516667096.276 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-01-23T00:24:56.276Z,1516667096.276 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-01-23T00:24:56.278Z,1516667096.278 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-01-23T00:24:56.429Z,1516667096.429 [SBIT](DEBUG): Construct Startup Built In Test.
2018-01-23T00:24:56.454Z,1516667096.454 [SBIT] Loaded
2018-01-23T00:24:56.454Z,1516667096.454 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-01-23T00:24:56.455Z,1516667096.455 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-01-23T00:24:56.466Z,1516667096.466 [IBIT] Loaded
2018-01-23T00:24:56.466Z,1516667096.466 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-01-23T00:24:56.470Z,1516667096.470 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-01-23T00:24:56.622Z,1516667096.622 [CBIT] Loaded
2018-01-23T00:24:56.622Z,1516667096.622 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-01-23T00:24:56.623Z,1516667096.623 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-01-23T00:24:56.623Z,1516667096.623 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-01-23T00:24:56.805Z,1516667096.805 [Aanderaa_O2] Loaded
2018-01-23T00:24:56.805Z,1516667096.805 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-01-23T00:24:56.817Z,1516667096.817 [CANONSampler] Loaded
2018-01-23T00:24:56.817Z,1516667096.817 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2018-01-23T00:24:56.894Z,1516667096.894 [CTD_NeilBrown] Loaded
2018-01-23T00:24:56.894Z,1516667096.894 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-01-23T00:24:56.895Z,1516667096.895 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2018-01-23T00:24:56.896Z,1516667096.896 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 886
2018-01-23T00:24:56.928Z,1516667096.928 [CTD_Seabird] Loaded
2018-01-23T00:24:56.929Z,1516667096.929 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-01-23T00:24:56.930Z,1516667096.930 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2018-01-23T00:24:56.930Z,1516667096.930 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 887
2018-01-23T00:24:56.944Z,1516667096.944 [PAR_Licor] Loaded
2018-01-23T00:24:56.945Z,1516667096.945 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-01-23T00:24:56.993Z,1516667096.993 [WetLabsBB2FL] Loaded
2018-01-23T00:24:56.993Z,1516667096.993 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-01-23T00:24:56.994Z,1516667096.994 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C14E0
2018-01-23T00:24:56.995Z,1516667096.995 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 888
2018-01-23T00:24:57.037Z,1516667097.037 [WetLabsSeaOWL_UV_A] Loaded
2018-01-23T00:24:57.038Z,1516667097.038 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-01-23T00:24:57.038Z,1516667097.038 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409F14E0
2018-01-23T00:24:57.039Z,1516667097.039 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 889
2018-01-23T00:24:57.039Z,1516667097.039 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-01-23T00:24:57.040Z,1516667097.040 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-01-23T00:24:57.126Z,1516667097.126 [VerticalControl](DEBUG): Construct VerticalControl.
2018-01-23T00:24:57.212Z,1516667097.212 [VerticalControl] Loaded
2018-01-23T00:24:57.213Z,1516667097.213 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-01-23T00:24:57.213Z,1516667097.213 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-01-23T00:24:57.270Z,1516667097.270 [HorizontalControl] Loaded
2018-01-23T00:24:57.271Z,1516667097.271 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-01-23T00:24:57.271Z,1516667097.271 [SpeedControl](DEBUG): Construct SpeedControl.
2018-01-23T00:24:57.273Z,1516667097.273 [SpeedControl] Loaded
2018-01-23T00:24:57.273Z,1516667097.273 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-01-23T00:24:57.274Z,1516667097.274 [LoopControl](DEBUG): Construct LoopControl.
2018-01-23T00:24:57.275Z,1516667097.275 [LoopControl] Loaded
2018-01-23T00:24:57.275Z,1516667097.275 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-01-23T00:24:57.275Z,1516667097.275 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-01-23T00:24:57.276Z,1516667097.276 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-01-23T00:24:57.313Z,1516667097.313 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-01-23T00:24:57.313Z,1516667097.313 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-01-23T00:24:57.419Z,1516667097.419 [DeadReckonUsingSpeedCalculator] Loaded
2018-01-23T00:24:57.420Z,1516667097.420 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-01-23T00:24:57.475Z,1516667097.475 [DeadReckonWithRespectToSeafloor] Loaded
2018-01-23T00:24:57.475Z,1516667097.475 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2018-01-23T00:24:57.491Z,1516667097.491 [NavChart] Loaded
2018-01-23T00:24:57.491Z,1516667097.491 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-01-23T00:24:57.495Z,1516667097.495 [UniversalFixResidualReporter] Loaded
2018-01-23T00:24:57.496Z,1516667097.496 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-01-23T00:24:57.496Z,1516667097.496 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-01-23T00:24:57.500Z,1516667097.500 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-01-23T00:24:57.501Z,1516667097.501 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-01-23T00:24:57.508Z,1516667097.508 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-01-23T00:24:57.509Z,1516667097.509 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A7C4E0
2018-01-23T00:24:57.509Z,1516667097.509 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 890
2018-01-23T00:24:57.514Z,1516667097.514 [Supervisor](INFO): Main Thread ID is 794
2018-01-23T00:24:57.514Z,1516667097.514 [Supervisor](DEBUG): Running supervisor.
2018-01-23T00:24:57.515Z,1516667097.515 [CommandLine ThreadHandler](INFO): Handler Thread ID is 891
2018-01-23T00:24:57.517Z,1516667097.517 [controlThread ThreadHandler](INFO): Handler Thread ID is 892
2018-01-23T00:24:57.518Z,1516667097.518 [controlThread](DEBUG): Initializing ControlThread
2018-01-23T00:24:57.519Z,1516667097.519 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-01-23T00:24:57.519Z,1516667097.519 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-01-23T00:24:57.519Z,1516667097.519 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-01-23T00:24:57.520Z,1516667097.520 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-01-23T00:24:57.520Z,1516667097.520 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-01-23T00:24:57.521Z,1516667097.521 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-01-23T00:24:57.527Z,1516667097.527 [SBIT](INFO): Initialize SBIT Component.
2018-01-23T00:24:57.528Z,1516667097.528 [SBIT](IMPORTANT): git: 2017-12-12
2018-01-23T00:24:57.528Z,1516667097.528 [SBIT](INFO): git hash: 18638d31f033e3fa0cb90b26256f5481d37f00cc
2018-01-23T00:24:57.528Z,1516667097.528 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-01-23T00:24:57.529Z,1516667097.529 [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-01-23T00:24:57.530Z,1516667097.530 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-01-23T00:24:57.531Z,1516667097.531 [IBIT](INFO): Initialize IBIT Component.
2018-01-23T00:24:57.532Z,1516667097.532 [CBIT](DEBUG): Initialize CBIT Component.
2018-01-23T00:24:57.532Z,1516667097.532 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-01-23T00:24:57.533Z,1516667097.533 [logger ThreadHandler](INFO): Handler Thread ID is 893
2018-01-23T00:24:57.553Z,1516667097.553 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 894
2018-01-23T00:24:57.559Z,1516667097.559 [Radio_Surface](INFO): Powering up
2018-01-23T00:24:57.565Z,1516667097.565 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 895
2018-01-23T00:24:57.566Z,1516667097.566 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:24:57.566Z,1516667097.566 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:24:57.621Z,1516667097.621 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-01-23T00:24:57.623Z,1516667097.623 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-01-23T00:24:57.623Z,1516667097.623 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-01-23T00:24:57.624Z,1516667097.624 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-01-23T00:24:57.624Z,1516667097.624 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T00:24:57.625Z,1516667097.625 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:24:57.666Z,1516667097.666 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:24:57.667Z,1516667097.667 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T00:24:57.667Z,1516667097.667 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:24:57.668Z,1516667097.668 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:24:57.668Z,1516667097.668 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-01-23T00:24:57.669Z,1516667097.669 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-01-23T00:24:57.670Z,1516667097.670 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 896
2018-01-23T00:24:57.671Z,1516667097.671 [CTD_NeilBrown](INFO): Powering down
2018-01-23T00:24:57.697Z,1516667097.697 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-01-23T00:24:57.708Z,1516667097.708 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 897
2018-01-23T00:24:57.708Z,1516667097.708 [CTD_Seabird](INFO): Initializing
2018-01-23T00:24:57.868Z,1516667097.868 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-23T00:24:57.869Z,1516667097.869 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 899
2018-01-23T00:24:57.870Z,1516667097.870 [WetLabsBB2FL](INFO): Powering down
2018-01-23T00:24:57.897Z,1516667097.897 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 900
2018-01-23T00:24:57.942Z,1516667097.942 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-01-23T00:24:57.942Z,1516667097.942 [CTD_Seabird](INFO): Powering down
2018-01-23T00:24:57.986Z,1516667097.986 [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-01-23T00:24:57.989Z,1516667097.989 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 901
2018-01-23T00:24:57.991Z,1516667097.991 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-01-23T00:24:57.998Z,1516667097.998 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-01-23T00:24:57.998Z,1516667097.998 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-01-23T00:24:57.998Z,1516667097.998 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-01-23T00:24:57.998Z,1516667097.998 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-01-23T00:24:57.998Z,1516667097.998 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-01-23T00:24:57.999Z,1516667097.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-01-23T00:24:57.999Z,1516667097.999 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-01-23T00:24:57.999Z,1516667097.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-01-23T00:24:57.999Z,1516667097.999 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-01-23T00:24:57.999Z,1516667097.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-01-23T00:24:57.000Z,1516667098.000 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-01-23T00:24:57.000Z,1516667098.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-01-23T00:24:57.000Z,1516667098.000 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-01-23T00:24:58.000Z,1516667098.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-01-23T00:24:58.000Z,1516667098.000 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-01-23T00:24:58.000Z,1516667098.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-01-23T00:24:58.107Z,1516667098.107 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:24:58.107Z,1516667098.107 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:24:58.121Z,1516667098.121 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-01-23T00:24:58.122Z,1516667098.122 [Default:A.Wait](DEBUG): Construct Wait.
2018-01-23T00:24:58.124Z,1516667098.124 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-23T00:24:58.169Z,1516667098.169 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-01-23T00:24:58.172Z,1516667098.172 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-01-23T00:24:58.194Z,1516667098.194 [Default:E.Execute](DEBUG): Construct Execute.
2018-01-23T00:24:58.197Z,1516667098.197 [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-01-23T00:24:58.209Z,1516667098.209 [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,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-01-23T00:24:58.221Z,1516667098.221 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-01-23T00:24:58.245Z,1516667098.245 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-01-23T00:24:58.479Z,1516667098.479 [CANONSampler](INFO): Powering down
2018-01-23T00:24:58.671Z,1516667098.671 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-01-23T00:24:58.757Z,1516667098.757 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:24:58.890Z,1516667098.890 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:24:58.985Z,1516667098.985 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:24:58.993Z,1516667098.993 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-01-23T00:24:59.015Z,1516667099.015 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:24:59.021Z,1516667099.021 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-01-23T00:24:59.028Z,1516667099.028 [MassServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:24:59.033Z,1516667099.033 [MassServo](DEBUG): Initializing MassServo.
2018-01-23T00:24:59.039Z,1516667099.039 [RudderServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:24:59.046Z,1516667099.046 [RudderServo](DEBUG): Initializing RudderServo.
2018-01-23T00:24:59.052Z,1516667099.052 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:24:59.069Z,1516667099.069 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-01-23T00:24:59.397Z,1516667099.397 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:24:59.398Z,1516667099.398 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:24:59.665Z,1516667099.665 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:24:59.670Z,1516667099.670 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:00.128Z,1516667100.128 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:00.128Z,1516667100.128 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:00.572Z,1516667100.572 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:00.573Z,1516667100.573 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:00.939Z,1516667100.939 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:00.940Z,1516667100.940 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:01.342Z,1516667101.342 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:01.343Z,1516667101.343 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:01.849Z,1516667101.849 [Aanderaa_O2](INFO): Powering down
2018-01-23T00:25:01.932Z,1516667101.932 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:01.938Z,1516667101.938 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:25:01.992Z,1516667101.992 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:25:02.142Z,1516667102.142 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2018-01-23T00:25:02.315Z,1516667102.315 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:25:02.315Z,1516667102.315 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:25:02.316Z,1516667102.316 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:25:18.520Z,1516667118.520 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:25:18.520Z,1516667118.520 [BPC1] Communications Fault, FailCount= 1
2018-01-23T00:25:18.520Z,1516667118.520 [BPC1](ERROR): Communications Fault
2018-01-23T00:25:18.614Z,1516667118.614 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:25:19.775Z,1516667119.775 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:25:19.775Z,1516667119.775 [BPC1] No Fault, FailCount= 1
2018-01-23T00:25:21.023Z,1516667121.023 [SBIT](IMPORTANT): Beginning Startup BIT
2018-01-23T00:25:21.035Z,1516667121.035 [CBIT](IMPORTANT): Beginning ground fault scan
2018-01-23T00:25:24.231Z,1516667124.231 [NAL9602](INFO): Powering up NAL9602
2018-01-23T00:25:31.954Z,1516667131.954 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): 0.127715
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001619
CHAN B0 (3.3V): -0.000142
CHAN B1 (3.15aV): -0.000523
CHAN B2 (3.15bV): -0.000039
CHAN B3 (GND): -0.000509
OPEN: -0.000294
Full Scale Calc: 4.765 mA, -1.589 mA
2018-01-23T00:25:35.435Z,1516667135.435 [NAL9602](INFO): NAL9602 initialized
2018-01-23T00:25:40.540Z,1516667140.540 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:25:40.540Z,1516667140.540 [BPC1] Communications Fault, FailCount= 2
2018-01-23T00:25:40.540Z,1516667140.540 [BPC1](ERROR): Communications Fault
2018-01-23T00:25:40.690Z,1516667140.690 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:25:41.951Z,1516667141.951 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:25:41.951Z,1516667141.951 [BPC1] No Fault, FailCount= 2
2018-01-23T00:26:02.530Z,1516667162.530 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:26:02.530Z,1516667162.530 [BPC1] Communications Fault, FailCount= 3
2018-01-23T00:26:02.530Z,1516667162.530 [BPC1](ERROR): Communications Fault
2018-01-23T00:26:02.572Z,1516667162.572 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:26:04.020Z,1516667164.020 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:26:04.020Z,1516667164.020 [BPC1] No Fault, FailCount= 3
2018-01-23T00:26:15.111Z,1516667175.111 [SBIT](IMPORTANT): SBIT PASSED
2018-01-23T00:26:15.526Z,1516667175.526 [MissionManager](IMPORTANT): Started mission Startup
2018-01-23T00:26:15.526Z,1516667175.526 [Startup] Running Loop=1
2018-01-23T00:26:15.527Z,1516667175.527 [Startup](DEBUG): Aggregate::initialize Startup
2018-01-23T00:26:15.527Z,1516667175.527 [Startup:A.GoToSurface] Running Loop=1
2018-01-23T00:26:15.527Z,1516667175.527 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-01-23T00:26:15.527Z,1516667175.527 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-01-23T00:26:15.528Z,1516667175.528 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-01-23T00:26:15.528Z,1516667175.528 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-01-23T00:26:15.537Z,1516667175.537 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-01-23T00:26:15.538Z,1516667175.538 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-01-23T00:26:15.550Z,1516667175.550 [Startup:StartupSatComms] Running Loop=1
2018-01-23T00:26:15.550Z,1516667175.550 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-01-23T00:26:15.550Z,1516667175.550 [Startup:StartupSatComms:A] Running Loop=1
2018-01-23T00:26:15.916Z,1516667175.916 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-01-23T00:26:24.685Z,1516667184.685 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:26:24.685Z,1516667184.685 [BPC1] Communications Fault, FailCount= 4
2018-01-23T00:26:24.685Z,1516667184.685 [BPC1](ERROR): Communications Fault
2018-01-23T00:26:24.733Z,1516667184.733 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:26:25.947Z,1516667185.947 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:26:25.947Z,1516667185.947 [BPC1] No Fault, FailCount= 4
2018-01-23T00:26:46.696Z,1516667206.696 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:26:46.696Z,1516667206.696 [BPC1] Communications Fault, FailCount= 5
2018-01-23T00:26:46.696Z,1516667206.696 [BPC1](ERROR): Communications Fault
2018-01-23T00:26:46.756Z,1516667206.756 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:26:47.930Z,1516667207.930 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:26:47.930Z,1516667207.930 [BPC1] No Fault, FailCount= 5
2018-01-23T00:27:08.697Z,1516667228.697 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:27:08.697Z,1516667228.697 [BPC1] Communications Fault, FailCount= 6
2018-01-23T00:27:08.697Z,1516667228.697 [BPC1](ERROR): Communications Fault
2018-01-23T00:27:08.759Z,1516667228.759 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:27:09.919Z,1516667229.919 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:27:09.920Z,1516667229.920 [BPC1] No Fault, FailCount= 6
2018-01-23T00:27:15.894Z,1516667235.894 [Startup:StartupSatComms:A](INFO): Timed out from 2018-01-23T00:26:15.6Z
2018-01-23T00:27:15.895Z,1516667235.895 [Startup:StartupSatComms:A] Stopped
2018-01-23T00:27:15.895Z,1516667235.895 [Startup:StartupSatComms:B] Running Loop=1
2018-01-23T00:27:16.413Z,1516667236.413 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-01-23T00:27:21.400Z,1516667241.400 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003612
2018-01-23T00:27:25.703Z,1516667245.703 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180123T001143/Courier0008.lzma
2018-01-23T00:27:26.502Z,1516667246.502 [DataOverHttps](INFO): Moved sent file to Logs/20180123T001143/Courier0008.lzma.bak
2018-01-23T00:27:26.502Z,1516667246.502 [DataOverHttps](INFO): SBD MOMSN=7753550
2018-01-23T00:27:30.762Z,1516667250.762 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:27:30.762Z,1516667250.762 [BPC1] Communications Fault, FailCount= 7
2018-01-23T00:27:30.762Z,1516667250.762 [BPC1](ERROR): Communications Fault
2018-01-23T00:27:30.815Z,1516667250.815 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:27:31.715Z,1516667251.715 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:27:31.715Z,1516667251.715 [BPC1] No Fault, FailCount= 7
2018-01-23T00:27:36.242Z,1516667256.242 [DataOverHttps](INFO): Sending 308 bytes from file Logs/20180123T001143/Express0009.lzma
2018-01-23T00:27:37.042Z,1516667257.042 [DataOverHttps](INFO): Moved sent file to Logs/20180123T001143/Express0009.lzma.bak
2018-01-23T00:27:37.042Z,1516667257.042 [DataOverHttps](INFO): SBD MOMSN=7753552
2018-01-23T00:27:42.192Z,1516667262.192 [PNI_TCM](ERROR): CRC does not match. Expected:0x46149 got:0x12357
2018-01-23T00:27:46.487Z,1516667266.487 [DataOverHttps](INFO): Sending 520 bytes from file Logs/20180123T002446/Express0001.lzma
2018-01-23T00:27:47.277Z,1516667267.277 [DataOverHttps](INFO): Moved sent file to Logs/20180123T002446/Express0001.lzma.bak
2018-01-23T00:27:47.278Z,1516667267.278 [DataOverHttps](INFO): SBD MOMSN=7753565
2018-01-23T00:27:47.731Z,1516667267.731 [Startup:StartupSatComms:B] Stopped
2018-01-23T00:27:47.731Z,1516667267.731 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-01-23T00:27:47.731Z,1516667267.731 [Startup:StartupSatComms] Stopped
2018-01-23T00:27:47.731Z,1516667267.731 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-01-23T00:27:47.732Z,1516667267.732 [Startup](INFO): Completed Startup
2018-01-23T00:27:47.732Z,1516667267.732 [MissionManager](INFO): Startup is completed.
2018-01-23T00:27:47.732Z,1516667267.732 [MissionManager](INFO): Uninitializing Mission Startup
2018-01-23T00:27:47.732Z,1516667267.732 [Startup] Stopped
2018-01-23T00:27:47.732Z,1516667267.732 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-01-23T00:27:47.733Z,1516667267.733 [Startup:A.GoToSurface] Stopped
2018-01-23T00:27:47.733Z,1516667267.733 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-01-23T00:27:48.136Z,1516667268.136 [MissionManager](IMPORTANT): Started mission Default
2018-01-23T00:27:48.137Z,1516667268.137 [Default] Running Loop=1
2018-01-23T00:27:48.137Z,1516667268.137 [Default](DEBUG): Aggregate::initialize Default
2018-01-23T00:27:48.137Z,1516667268.137 [Default:B.GoToSurface] Running Loop=1
2018-01-23T00:27:48.137Z,1516667268.137 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-01-23T00:27:48.137Z,1516667268.137 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-01-23T00:27:48.137Z,1516667268.137 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-01-23T00:27:48.138Z,1516667268.138 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-01-23T00:27:48.138Z,1516667268.138 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-01-23T00:27:48.138Z,1516667268.138 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-01-23T00:27:48.139Z,1516667268.139 [Default:A.Wait] Running Loop=1
2018-01-23T00:27:48.139Z,1516667268.139 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-01-23T00:27:52.910Z,1516667272.910 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:27:52.910Z,1516667272.910 [BPC1] Communications Fault, FailCount= 8
2018-01-23T00:27:52.911Z,1516667272.911 [BPC1](ERROR): Communications Fault
2018-01-23T00:27:52.957Z,1516667272.957 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:27:54.105Z,1516667274.105 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:27:54.105Z,1516667274.105 [BPC1] No Fault, FailCount= 8
2018-01-23T00:27:57.668Z,1516667277.668 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:27:57.669Z,1516667277.669 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-01-23T00:27:57.669Z,1516667277.669 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-01-23T00:27:57.671Z,1516667277.671 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:27:57.671Z,1516667277.671 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T00:27:57.671Z,1516667277.671 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T00:27:57.696Z,1516667277.696 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-01-23T00:27:57.696Z,1516667277.696 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T00:27:58.086Z,1516667278.086 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-01-23T00:27:58.086Z,1516667278.086 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-01-23T00:27:58.086Z,1516667278.086 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T00:27:58.086Z,1516667278.086 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T00:27:58.472Z,1516667278.472 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T00:27:58.473Z,1516667278.473 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:27:58.473Z,1516667278.473 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:27:58.474Z,1516667278.474 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T00:27:58.474Z,1516667278.474 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:27:58.475Z,1516667278.475 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:28:01.278Z,1516667281.278 [Default:A.Wait](INFO): Done Waiting.
2018-01-23T00:28:01.279Z,1516667281.279 [Default:A.Wait] Stopped
2018-01-23T00:28:01.279Z,1516667281.279 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T00:28:01.693Z,1516667281.693 [Default:CheckIn] Running Loop=1
2018-01-23T00:28:01.693Z,1516667281.693 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-01-23T00:28:01.693Z,1516667281.693 [Default:CheckIn:Read_GPS] Running Loop=1
2018-01-23T00:28:02.090Z,1516667282.090 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-01-23T00:28:08.541Z,1516667288.541 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-01-23T00:28:08.541Z,1516667288.541 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-01-23T00:28:08.541Z,1516667288.541 [Rowe_600LCM](ERROR): Communications Fault
2018-01-23T00:28:08.945Z,1516667288.945 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:28:09.022Z,1516667289.022 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-01-23T00:28:09.121Z,1516667289.121 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:28:10.512Z,1516667290.512 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-01-23T00:28:10.512Z,1516667290.512 [Rowe_600LCM] No Fault, FailCount= 1
2018-01-23T00:28:10.737Z,1516667290.737 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:28:10.737Z,1516667290.737 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:28:10.737Z,1516667290.737 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:28:10.738Z,1516667290.738 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:28:14.863Z,1516667294.863 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:28:14.863Z,1516667294.863 [BPC1] Communications Fault, FailCount= 9
2018-01-23T00:28:14.863Z,1516667294.863 [BPC1](ERROR): Communications Fault
2018-01-23T00:28:14.955Z,1516667294.955 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:28:14.996Z,1516667294.996 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:28:15.077Z,1516667295.077 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2018-01-23T00:28:15.078Z,1516667295.078 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:28:15.079Z,1516667295.079 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:28:15.080Z,1516667295.080 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:28:16.076Z,1516667296.076 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:28:16.076Z,1516667296.076 [BPC1] No Fault, FailCount= 9
2018-01-23T00:28:36.865Z,1516667316.865 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:28:36.865Z,1516667316.865 [BPC1] Communications Fault, FailCount= 10
2018-01-23T00:28:36.865Z,1516667316.865 [BPC1](ERROR): Communications Fault
2018-01-23T00:28:36.911Z,1516667316.911 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:28:36.911Z,1516667316.911 [CBIT](CRITICAL): Communications Fault in component: BPC1
2018-01-23T00:28:37.296Z,1516667317.296 [CommandLine](FAULT): Scheduling is paused
2018-01-23T00:28:37.301Z,1516667317.301 [CBIT](INFO): Critical error at 20180123T002836
2018-01-23T00:28:37.301Z,1516667317.301 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-01-23T00:30:10.931Z,1516667410.931 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-01-23T00:30:10.932Z,1516667410.932 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-01-23T00:30:10.932Z,1516667410.932 [Rowe_600LCM](ERROR): Communications Fault
2018-01-23T00:30:11.252Z,1516667411.252 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-01-23T00:30:11.333Z,1516667411.333 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:30:11.433Z,1516667411.433 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:30:12.868Z,1516667412.868 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-01-23T00:30:12.868Z,1516667412.868 [Rowe_600LCM] No Fault, FailCount= 2
2018-01-23T00:30:13.049Z,1516667413.049 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:30:13.049Z,1516667413.049 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:30:13.050Z,1516667413.050 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:30:13.050Z,1516667413.050 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:30:17.176Z,1516667417.176 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:30:17.352Z,1516667417.352 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null &
2018-01-23T00:30:17.353Z,1516667417.353 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:30:17.354Z,1516667417.354 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:30:17.354Z,1516667417.354 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:30:38.794Z,1516667438.794 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-01-23T00:30:58.676Z,1516667458.676 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:30:58.676Z,1516667458.676 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-01-23T00:30:58.676Z,1516667458.676 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-01-23T00:30:58.678Z,1516667458.678 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:30:58.678Z,1516667458.678 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2018-01-23T00:30:58.678Z,1516667458.678 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T00:30:58.707Z,1516667458.707 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-01-23T00:30:58.707Z,1516667458.707 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T00:30:59.088Z,1516667459.088 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-01-23T00:30:59.088Z,1516667459.088 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-01-23T00:30:59.089Z,1516667459.089 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T00:30:59.089Z,1516667459.089 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2018-01-23T00:30:59.474Z,1516667459.474 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T00:30:59.474Z,1516667459.474 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:30:59.475Z,1516667459.475 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:30:59.475Z,1516667459.475 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T00:30:59.475Z,1516667459.475 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:30:59.476Z,1516667459.476 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:32:58.833Z,1516667578.833 [CommandLine](IMPORTANT): got command quit
2018-01-23T00:32:59.840Z,1516667579.840 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:32:59.840Z,1516667579.840 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:32:59.977Z,1516667579.977 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-01-23T00:32:59.977Z,1516667579.977 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:32:59.978Z,1516667579.978 [CommandLine](INFO): Join timeout helper Thread ID is 936
2018-01-23T00:32:59.978Z,1516667579.978 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-01-23T00:32:59.978Z,1516667579.978 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:32:59.979Z,1516667579.979 [NavChartDb](INFO): Join timeout helper Thread ID is 937
2018-01-23T00:33:00.009Z,1516667580.009 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:00.009Z,1516667580.009 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.017Z,1516667580.017 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-01-23T00:33:00.017Z,1516667580.017 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.017Z,1516667580.017 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 938
2018-01-23T00:33:00.049Z,1516667580.049 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:00.049Z,1516667580.049 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.061Z,1516667580.061 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-01-23T00:33:00.061Z,1516667580.061 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.061Z,1516667580.061 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 939
2018-01-23T00:33:00.105Z,1516667580.105 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:00.105Z,1516667580.105 [WetLabsBB2FL](INFO): Powering down
2018-01-23T00:33:00.106Z,1516667580.106 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.121Z,1516667580.121 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-01-23T00:33:00.121Z,1516667580.121 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.121Z,1516667580.121 [CTD_Seabird](INFO): Join timeout helper Thread ID is 940
2018-01-23T00:33:00.286Z,1516667580.286 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:00.463Z,1516667580.463 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-01-23T00:33:00.463Z,1516667580.463 [CTD_Seabird](INFO): Powering down
2018-01-23T00:33:00.464Z,1516667580.464 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.482Z,1516667580.482 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-01-23T00:33:00.482Z,1516667580.482 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.482Z,1516667580.482 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 942
2018-01-23T00:33:00.773Z,1516667580.773 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:00.773Z,1516667580.773 [CTD_NeilBrown](INFO): Powering down
2018-01-23T00:33:00.774Z,1516667580.774 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.794Z,1516667580.794 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-01-23T00:33:00.794Z,1516667580.794 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:00.794Z,1516667580.794 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 943
2018-01-23T00:33:01.365Z,1516667581.365 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:01.366Z,1516667581.366 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:33:01.544Z,1516667581.544 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:33:01.545Z,1516667581.545 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:01.554Z,1516667581.554 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-01-23T00:33:01.554Z,1516667581.554 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:01.554Z,1516667581.554 [Radio_Surface](INFO): Join timeout helper Thread ID is 945
2018-01-23T00:33:01.829Z,1516667581.829 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:01.829Z,1516667581.829 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:01.850Z,1516667581.850 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-01-23T00:33:01.850Z,1516667581.850 [logger ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:01.850Z,1516667581.850 [logger](INFO): Join timeout helper Thread ID is 946
2018-01-23T00:33:01.877Z,1516667581.877 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:01.877Z,1516667581.877 [logger ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:01.891Z,1516667581.891 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-01-23T00:33:01.891Z,1516667581.891 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:01.892Z,1516667581.892 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-01-23T00:33:01.892Z,1516667581.892 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:01.892Z,1516667581.892 [controlThread](INFO): Join timeout helper Thread ID is 947
2018-01-23T00:33:01.914Z,1516667581.914 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-01-23T00:28:01.7Z
2018-01-23T00:33:01.914Z,1516667581.914 [Default:CheckIn:Read_GPS] Stopped
2018-01-23T00:33:01.914Z,1516667581.914 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-01-23T00:33:01.926Z,1516667581.926 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:33:01.926Z,1516667581.926 [controlThread](DEBUG): Uninitializing ControlThread
2018-01-23T00:33:01.927Z,1516667581.927 [NAL9602](INFO): Powering down
2018-01-23T00:33:01.928Z,1516667581.928 [PNI_TCM](INFO): Powering down
2018-01-23T00:33:02.013Z,1516667582.013 [Aanderaa_O2](INFO): Powering down
2018-01-23T00:33:02.015Z,1516667582.015 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-01-23T00:33:02.017Z,1516667582.017 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-01-23T00:33:02.018Z,1516667582.018 [MissionManager](INFO): Uninitializing Mission Default
2018-01-23T00:33:02.018Z,1516667582.018 [Default] Stopped
2018-01-23T00:33:02.018Z,1516667582.018 [Default](DEBUG): Aggregate::uninitialize Default
2018-01-23T00:33:02.018Z,1516667582.018 [Default:B.GoToSurface] Stopped
2018-01-23T00:33:02.018Z,1516667582.018 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-01-23T00:33:02.018Z,1516667582.018 [Default:CheckIn] Stopped
2018-01-23T00:33:02.018Z,1516667582.018 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-01-23T00:33:02.018Z,1516667582.018 [Default:CheckIn:Read_Iridium] Stopped
2018-01-23T00:33:02.021Z,1516667582.021 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-01-23T00:33:02.021Z,1516667582.021 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-01-23T00:33:02.021Z,1516667582.021 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-01-23T00:33:02.022Z,1516667582.022 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-01-23T00:33:02.022Z,1516667582.022 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-01-23T00:33:02.022Z,1516667582.022 [BuoyancyServo](INFO): Powering down
2018-01-23T00:33:02.037Z,1516667582.037 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-01-23T00:33:02.037Z,1516667582.037 [ElevatorServo](INFO): Powering down
2018-01-23T00:33:02.038Z,1516667582.038 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-01-23T00:33:02.038Z,1516667582.038 [MassServo](INFO): Powering down
2018-01-23T00:33:02.039Z,1516667582.039 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-01-23T00:33:02.039Z,1516667582.039 [RudderServo](INFO): Powering down
2018-01-23T00:33:02.040Z,1516667582.040 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-01-23T00:33:02.040Z,1516667582.040 [ThrusterServo](INFO): Powering down
2018-01-23T00:33:02.041Z,1516667582.041 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-01-23T00:33:02.041Z,1516667582.041 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-01-23T00:33:02.041Z,1516667582.041 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-01-23T00:33:02.042Z,1516667582.042 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.148Z,1516667582.148 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.154Z,1516667582.154 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.189Z,1516667582.189 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.191Z,1516667582.191 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.194Z,1516667582.194 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.196Z,1516667582.196 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.224Z,1516667582.224 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:33:02.277Z,1516667582.277 [logger ThreadHandler](INFO): Thread cancelled.