2017-06-14T17:18:53.932Z,1497460733.932 [Supervisor](DEBUG): Initializing supervisor.
2017-06-14T17:18:53.935Z,1497460733.935 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0
2017-06-14T17:18:53.936Z,1497460733.936 [SyncHandler](INFO): Protected caller Thread ID is 906
2017-06-14T17:18:53.936Z,1497460733.936 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2017-06-14T17:18:53.937Z,1497460733.937 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0
2017-06-14T17:18:53.938Z,1497460733.938 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 907
2017-06-14T17:18:53.940Z,1497460733.940 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2017-06-14T17:18:53.953Z,1497460733.953 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2017-06-14T17:18:53.954Z,1497460733.954 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0
2017-06-14T17:18:53.954Z,1497460733.954 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 908
2017-06-14T17:18:53.955Z,1497460733.955 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2017-06-14T17:18:53.956Z,1497460733.956 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0
2017-06-14T17:18:53.956Z,1497460733.956 [logger ThreadHandler](INFO): Protected caller Thread ID is 909
2017-06-14T17:18:53.959Z,1497460733.959 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2017-06-14T17:18:53.959Z,1497460733.959 [Supervisor](INFO): Looking for Config files in directory: Config/
2017-06-14T17:18:53.960Z,1497460733.960 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2017-06-14T17:18:54.148Z,1497460734.148 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2017-06-14T17:18:54.148Z,1497460734.148 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2017-06-14T17:18:54.282Z,1497460734.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2017-06-14T17:18:54.283Z,1497460734.283 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2017-06-14T17:18:54.613Z,1497460734.613 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2017-06-14T17:18:54.613Z,1497460734.613 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2017-06-14T17:18:54.753Z,1497460734.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2017-06-14T17:18:54.753Z,1497460734.753 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2017-06-14T17:18:54.838Z,1497460734.838 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2017-06-14T17:18:55.037Z,1497460735.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2017-06-14T17:18:55.037Z,1497460735.037 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2017-06-14T17:18:55.123Z,1497460735.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2017-06-14T17:18:55.124Z,1497460735.124 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2017-06-14T17:18:55.415Z,1497460735.415 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2017-06-14T17:18:55.415Z,1497460735.415 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2017-06-14T17:18:55.776Z,1497460735.776 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2017-06-14T17:18:55.776Z,1497460735.776 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2017-06-14T17:18:56.076Z,1497460736.076 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2017-06-14T17:18:56.077Z,1497460736.077 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2017-06-14T17:18:56.674Z,1497460736.674 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2017-06-14T17:18:56.675Z,1497460736.675 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2017-06-14T17:18:56.913Z,1497460736.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2017-06-14T17:18:56.914Z,1497460736.914 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2017-06-14T17:18:57.017Z,1497460737.017 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2017-06-14T17:18:57.017Z,1497460737.017 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2017-06-14T17:18:57.515Z,1497460737.515 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2017-06-14T17:18:57.516Z,1497460737.516 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2017-06-14T17:18:57.627Z,1497460737.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2017-06-14T17:18:57.630Z,1497460737.630 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2017-06-14T17:18:57.630Z,1497460737.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2017-06-14T17:18:57.951Z,1497460737.951 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2017-06-14T17:18:57.952Z,1497460737.952 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2017-06-14T17:18:58.056Z,1497460738.056 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2017-06-14T17:18:58.150Z,1497460738.150 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2017-06-14T17:18:58.256Z,1497460738.256 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2017-06-14T17:18:58.346Z,1497460738.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2017-06-14T17:18:58.475Z,1497460738.475 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2017-06-14T17:18:58.631Z,1497460738.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2017-06-14T17:18:58.730Z,1497460738.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2017-06-14T17:18:58.826Z,1497460738.826 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2017-06-14T17:18:58.914Z,1497460738.914 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2017-06-14T17:18:59.096Z,1497460739.096 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2017-06-14T17:18:59.177Z,1497460739.177 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2017-06-14T17:18:59.188Z,1497460739.188 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2017-06-14T17:18:59.322Z,1497460739.322 [SBIT](DEBUG): Construct Startup Built In Test.
2017-06-14T17:18:59.353Z,1497460739.353 [SBIT] Loaded
2017-06-14T17:18:59.353Z,1497460739.353 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2017-06-14T17:18:59.354Z,1497460739.354 [IBIT](DEBUG): Construct Initiated Built In Test.
2017-06-14T17:18:59.383Z,1497460739.383 [IBIT] Loaded
2017-06-14T17:18:59.383Z,1497460739.383 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2017-06-14T17:18:59.386Z,1497460739.386 [CBIT](DEBUG): Construct Continuous Built In Test.
2017-06-14T17:18:59.540Z,1497460739.540 [CBIT] Loaded
2017-06-14T17:18:59.540Z,1497460739.540 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2017-06-14T17:18:59.540Z,1497460739.540 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2017-06-14T17:18:59.541Z,1497460739.541 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2017-06-14T17:18:59.591Z,1497460739.591 [VerticalControl](DEBUG): Construct VerticalControl.
2017-06-14T17:18:59.693Z,1497460739.693 [VerticalControl] Loaded
2017-06-14T17:18:59.693Z,1497460739.693 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2017-06-14T17:18:59.694Z,1497460739.694 [HorizontalControl](DEBUG): Construct HorizontalControl.
2017-06-14T17:18:59.757Z,1497460739.757 [HorizontalControl] Loaded
2017-06-14T17:18:59.757Z,1497460739.757 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2017-06-14T17:18:59.758Z,1497460739.758 [SpeedControl](DEBUG): Construct SpeedControl.
2017-06-14T17:18:59.763Z,1497460739.763 [SpeedControl] Loaded
2017-06-14T17:18:59.764Z,1497460739.764 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2017-06-14T17:18:59.764Z,1497460739.764 [LoopControl](DEBUG): Construct LoopControl.
2017-06-14T17:18:59.765Z,1497460739.765 [LoopControl] Loaded
2017-06-14T17:18:59.765Z,1497460739.765 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2017-06-14T17:18:59.765Z,1497460739.765 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2017-06-14T17:18:59.766Z,1497460739.766 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2017-06-14T17:18:59.792Z,1497460739.792 [DepthRateCalculator] Loaded
2017-06-14T17:18:59.792Z,1497460739.792 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2017-06-14T17:18:59.797Z,1497460739.797 [PitchRateCalculator] Loaded
2017-06-14T17:18:59.798Z,1497460739.798 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2017-06-14T17:18:59.809Z,1497460739.809 [SpeedCalculator] Loaded
2017-06-14T17:18:59.809Z,1497460739.809 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2017-06-14T17:18:59.832Z,1497460739.832 [TempGradientCalculator] Loaded
2017-06-14T17:18:59.832Z,1497460739.832 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2017-06-14T17:18:59.848Z,1497460739.848 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2017-06-14T17:18:59.848Z,1497460739.848 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2017-06-14T17:18:59.853Z,1497460739.853 [YawRateCalculator] Loaded
2017-06-14T17:18:59.854Z,1497460739.854 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2017-06-14T17:18:59.854Z,1497460739.854 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2017-06-14T17:18:59.855Z,1497460739.855 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2017-06-14T17:18:59.936Z,1497460739.936 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2017-06-14T17:18:59.936Z,1497460739.936 [StratificationFrontDetector](DEBUG): (re)initializing
2017-06-14T17:18:59.936Z,1497460739.936 [StratificationFrontDetector] Loaded
2017-06-14T17:18:59.937Z,1497460739.937 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2017-06-14T17:18:59.961Z,1497460739.961 [DepAvgTempFrontDetector] Loaded
2017-06-14T17:18:59.961Z,1497460739.961 [ComponentRegistry](DEBUG): SyncComponent "DepAvgTempFrontDetector" handled in the control thread.
2017-06-14T17:18:59.962Z,1497460739.962 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2017-06-14T17:18:59.962Z,1497460739.962 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2017-06-14T17:19:00.207Z,1497460740.207 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2017-06-14T17:19:00.208Z,1497460740.208 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2017-06-14T17:19:00.307Z,1497460740.307 [DeadReckonUsingMultipleVelocitySources] Loaded
2017-06-14T17:19:00.307Z,1497460740.307 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2017-06-14T17:19:00.363Z,1497460740.363 [DeadReckonUsingSpeedCalculator] Loaded
2017-06-14T17:19:00.363Z,1497460740.363 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2017-06-14T17:19:00.380Z,1497460740.380 [NavChart] Loaded
2017-06-14T17:19:00.381Z,1497460740.381 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2017-06-14T17:19:00.385Z,1497460740.385 [UniversalFixResidualReporter] Loaded
2017-06-14T17:19:00.385Z,1497460740.385 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2017-06-14T17:19:00.386Z,1497460740.386 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2017-06-14T17:19:00.386Z,1497460740.386 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2017-06-14T17:19:00.393Z,1497460740.393 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2017-06-14T17:19:00.393Z,1497460740.393 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2017-06-14T17:19:00.540Z,1497460740.540 [Aanderaa_O2] Loaded
2017-06-14T17:19:00.541Z,1497460740.541 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2017-06-14T17:19:00.553Z,1497460740.553 [CANONSampler] Loaded
2017-06-14T17:19:00.553Z,1497460740.553 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2017-06-14T17:19:00.634Z,1497460740.634 [CTD_NeilBrown] Loaded
2017-06-14T17:19:00.635Z,1497460740.635 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2017-06-14T17:19:00.636Z,1497460740.636 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407734E0
2017-06-14T17:19:00.636Z,1497460740.636 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 991
2017-06-14T17:19:00.679Z,1497460740.679 [CTD_Seabird] Loaded
2017-06-14T17:19:00.679Z,1497460740.679 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2017-06-14T17:19:00.680Z,1497460740.680 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 407A34E0
2017-06-14T17:19:00.680Z,1497460740.680 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 992
2017-06-14T17:19:00.696Z,1497460740.696 [PAR_Licor] Loaded
2017-06-14T17:19:00.696Z,1497460740.696 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2017-06-14T17:19:00.746Z,1497460740.746 [WetLabsBB2FL] Loaded
2017-06-14T17:19:00.747Z,1497460740.747 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2017-06-14T17:19:00.748Z,1497460740.748 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407D34E0
2017-06-14T17:19:00.748Z,1497460740.748 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 993
2017-06-14T17:19:00.749Z,1497460740.749 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2017-06-14T17:19:00.749Z,1497460740.749 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2017-06-14T17:19:01.022Z,1497460741.022 [DataOverHttps] Loaded
2017-06-14T17:19:01.023Z,1497460741.023 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2017-06-14T17:19:01.036Z,1497460741.036 [Depth_Keller] Loaded
2017-06-14T17:19:01.037Z,1497460741.037 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2017-06-14T17:19:01.042Z,1497460741.042 [DropWeight] Loaded
2017-06-14T17:19:01.042Z,1497460741.042 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2017-06-14T17:19:01.136Z,1497460741.136 [NAL9602] Loaded
2017-06-14T17:19:01.136Z,1497460741.136 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2017-06-14T17:19:01.145Z,1497460741.145 [Onboard] Loaded
2017-06-14T17:19:01.146Z,1497460741.146 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2017-06-14T17:19:01.153Z,1497460741.153 [Radio_Surface] Loaded
2017-06-14T17:19:01.153Z,1497460741.153 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2017-06-14T17:19:01.154Z,1497460741.154 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1E4E0
2017-06-14T17:19:01.155Z,1497460741.155 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 994
2017-06-14T17:19:01.203Z,1497460741.203 [PNI_TCM] Loaded
2017-06-14T17:19:01.204Z,1497460741.204 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2017-06-14T17:19:03.068Z,1497460743.068 [BPC1] Loaded
2017-06-14T17:19:03.069Z,1497460743.069 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2017-06-14T17:19:03.069Z,1497460743.069 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2017-06-14T17:19:03.070Z,1497460743.070 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2017-06-14T17:19:03.405Z,1497460743.405 [BuoyancyServo] Loaded
2017-06-14T17:19:03.406Z,1497460743.406 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2017-06-14T17:19:03.418Z,1497460743.418 [ElevatorServo] Loaded
2017-06-14T17:19:03.418Z,1497460743.418 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2017-06-14T17:19:03.430Z,1497460743.430 [MassServo] Loaded
2017-06-14T17:19:03.430Z,1497460743.430 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2017-06-14T17:19:03.442Z,1497460743.442 [RudderServo] Loaded
2017-06-14T17:19:03.442Z,1497460743.442 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2017-06-14T17:19:03.454Z,1497460743.454 [ThrusterServo] Loaded
2017-06-14T17:19:03.454Z,1497460743.454 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2017-06-14T17:19:03.455Z,1497460743.455 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2017-06-14T17:19:03.455Z,1497460743.455 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2017-06-14T17:19:03.559Z,1497460743.559 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2017-06-14T17:19:03.560Z,1497460743.560 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2017-06-14T17:19:03.584Z,1497460743.584 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2017-06-14T17:19:03.588Z,1497460743.588 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2017-06-14T17:19:03.589Z,1497460743.589 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2017-06-14T17:19:03.596Z,1497460743.596 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2017-06-14T17:19:03.597Z,1497460743.597 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACC4E0
2017-06-14T17:19:03.598Z,1497460743.598 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 995
2017-06-14T17:19:03.603Z,1497460743.603 [Supervisor](INFO): Main Thread ID is 766
2017-06-14T17:19:03.603Z,1497460743.603 [Supervisor](DEBUG): Running supervisor.
2017-06-14T17:19:03.603Z,1497460743.603 [CommandLine ThreadHandler](INFO): Handler Thread ID is 996
2017-06-14T17:19:03.606Z,1497460743.606 [controlThread ThreadHandler](INFO): Handler Thread ID is 997
2017-06-14T17:19:03.607Z,1497460743.607 [controlThread](DEBUG): Initializing ControlThread
2017-06-14T17:19:03.608Z,1497460743.608 [SBIT](INFO): Initialize SBIT Component.
2017-06-14T17:19:03.608Z,1497460743.608 [SBIT](IMPORTANT): git: 2017-04-25-1-g5be4203
2017-06-14T17:19:03.608Z,1497460743.608 [SBIT](INFO): git hash: 5be4203e99563ce232d7cf111035ff7c729bf400
2017-06-14T17:19:03.610Z,1497460743.610 [SBIT](INFO): Kernel Reporting Different Release From Configuration.
Kernel Expected: 2.6.27.8
Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty
2017-06-14T17:19:03.610Z,1497460743.610 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016
2017-06-14T17:19:03.612Z,1497460743.612 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2017-06-14T17:19:03.612Z,1497460743.612 [IBIT](INFO): Initialize IBIT Component.
2017-06-14T17:19:03.613Z,1497460743.613 [CBIT](DEBUG): Initialize CBIT Component.
2017-06-14T17:19:03.613Z,1497460743.613 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2017-06-14T17:19:03.614Z,1497460743.614 [logger ThreadHandler](INFO): Handler Thread ID is 998
2017-06-14T17:19:03.642Z,1497460743.642 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 999
2017-06-14T17:19:03.643Z,1497460743.643 [CTD_NeilBrown](INFO): Powering down
2017-06-14T17:19:03.677Z,1497460743.677 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1000
2017-06-14T17:19:03.682Z,1497460743.682 [CTD_Seabird](INFO): Initializing
2017-06-14T17:19:03.715Z,1497460743.715 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2017-06-14T17:19:03.717Z,1497460743.717 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2017-06-14T17:19:03.718Z,1497460743.718 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2017-06-14T17:19:03.719Z,1497460743.719 [LoopControl](DEBUG): Initialize LoopControlComponent.
2017-06-14T17:19:03.719Z,1497460743.719 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-06-14T17:19:03.720Z,1497460743.720 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2017-06-14T17:19:03.720Z,1497460743.720 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2017-06-14T17:19:03.721Z,1497460743.721 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2017-06-14T17:19:03.721Z,1497460743.721 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2017-06-14T17:19:03.722Z,1497460743.722 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2017-06-14T17:19:03.723Z,1497460743.723 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-06-14T17:19:03.724Z,1497460743.724 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-06-14T17:19:03.725Z,1497460743.725 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-06-14T17:19:03.725Z,1497460743.725 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-06-14T17:19:03.726Z,1497460743.726 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-06-14T17:19:03.726Z,1497460743.726 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-06-14T17:19:03.726Z,1497460743.726 [NavChart](DEBUG): Initialize NavChart Navigation.
2017-06-14T17:19:03.727Z,1497460743.727 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2017-06-14T17:19:03.735Z,1497460743.735 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1002
2017-06-14T17:19:03.737Z,1497460743.737 [WetLabsBB2FL](INFO): Powering down
2017-06-14T17:19:03.767Z,1497460743.767 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2017-06-14T17:19:03.779Z,1497460743.779 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1003
2017-06-14T17:19:03.785Z,1497460743.785 [Radio_Surface](INFO): Powering up
2017-06-14T17:19:03.799Z,1497460743.799 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1004
2017-06-14T17:19:03.802Z,1497460743.802 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2017-06-14T17:19:03.803Z,1497460743.803 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2017-06-14T17:19:03.803Z,1497460743.803 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2017-06-14T17:19:03.803Z,1497460743.803 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2017-06-14T17:19:03.803Z,1497460743.803 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2017-06-14T17:19:03.804Z,1497460743.804 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2017-06-14T17:19:03.804Z,1497460743.804 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2017-06-14T17:19:03.804Z,1497460743.804 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2017-06-14T17:19:03.804Z,1497460743.804 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2017-06-14T17:19:03.804Z,1497460743.804 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2017-06-14T17:19:03.805Z,1497460743.805 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2017-06-14T17:19:03.805Z,1497460743.805 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2017-06-14T17:19:03.805Z,1497460743.805 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2017-06-14T17:19:03.805Z,1497460743.805 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2017-06-14T17:19:03.806Z,1497460743.806 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2017-06-14T17:19:03.806Z,1497460743.806 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2017-06-14T17:19:03.834Z,1497460743.834 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2017-06-14T17:19:03.881Z,1497460743.881 [MissionManager](DEBUG):
2017-06-14T17:19:03.882Z,1497460743.882 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2017-06-14T17:19:03.977Z,1497460743.977 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2017-06-14T17:19:03.978Z,1497460743.978 [Default:A.Wait](DEBUG): Construct Wait.
2017-06-14T17:19:03.000Z,1497460744.000 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2017-06-14T17:19:04.005Z,1497460744.005 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-06-14T17:19:04.005Z,1497460744.005 [CTD_Seabird](INFO): Powering down
2017-06-14T17:19:04.047Z,1497460744.047 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2017-06-14T17:19:04.050Z,1497460744.050 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2017-06-14T17:19:04.071Z,1497460744.071 [Default:E.Execute](DEBUG): Construct Execute.
2017-06-14T17:19:04.075Z,1497460744.075 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn 300
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2017-06-14T17:19:04.090Z,1497460744.090 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DepAvgTempFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2017-06-14T17:19:04.147Z,1497460744.147 [CANONSampler](INFO): Powering down
2017-06-14T17:19:04.259Z,1497460744.259 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2017-06-14T17:19:04.292Z,1497460744.292 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2017-06-14T17:19:04.482Z,1497460744.482 [DepthRateCalculator](ERROR): Depth measurement is not active
2017-06-14T17:19:04.612Z,1497460744.612 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:04.636Z,1497460744.636 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:04.738Z,1497460744.738 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-06-14T17:19:04.744Z,1497460744.744 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-06-14T17:19:04.766Z,1497460744.766 [ElevatorServo](DEBUG): Initializing EZServoServo.
2017-06-14T17:19:04.772Z,1497460744.772 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2017-06-14T17:19:04.793Z,1497460744.793 [MassServo](DEBUG): Initializing EZServoServo.
2017-06-14T17:19:04.800Z,1497460744.800 [MassServo](DEBUG): Initializing MassServo.
2017-06-14T17:19:04.806Z,1497460744.806 [RudderServo](DEBUG): Initializing EZServoServo.
2017-06-14T17:19:04.812Z,1497460744.812 [RudderServo](DEBUG): Initializing RudderServo.
2017-06-14T17:19:04.834Z,1497460744.834 [ThrusterServo](DEBUG): Initializing EZServoServo.
2017-06-14T17:19:04.840Z,1497460744.840 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2017-06-14T17:19:05.174Z,1497460745.174 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2017-06-14T17:19:05.174Z,1497460745.174 [DropWeight] Hardware Fault, FailCount= 1
2017-06-14T17:19:05.175Z,1497460745.175 [DropWeight](ERROR): Hardware Fault
2017-06-14T17:19:05.256Z,1497460745.256 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:05.257Z,1497460745.257 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:05.597Z,1497460745.597 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2017-06-14T17:19:05.597Z,1497460745.597 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2017-06-14T17:19:05.597Z,1497460745.597 [BuoyancyServo] Communications Fault, FailCount= 1
2017-06-14T17:19:05.597Z,1497460745.597 [BuoyancyServo](ERROR): Communications Fault
2017-06-14T17:19:05.803Z,1497460745.803 [CommandLine](FAULT): Scheduling is paused
2017-06-14T17:19:05.803Z,1497460745.803 [CBIT](INFO): Critical error at 20170614T171905
2017-06-14T17:19:05.804Z,1497460745.804 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2017-06-14T17:19:05.807Z,1497460745.807 [CBIT](ERROR): Hardware Fault in component: DropWeight
2017-06-14T17:19:05.808Z,1497460745.808 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2017-06-14T17:19:05.808Z,1497460745.808 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2017-06-14T17:19:05.894Z,1497460745.894 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:05.895Z,1497460745.895 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:05.907Z,1497460745.907 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-06-14T17:19:05.908Z,1497460745.908 [BuoyancyServo](INFO): Powering down
2017-06-14T17:19:05.985Z,1497460745.985 [CBIT](INFO): Critical error at 20170614T171905
2017-06-14T17:19:06.227Z,1497460746.227 [NAL9602](INFO): Powering up NAL9602
2017-06-14T17:19:06.267Z,1497460746.267 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:06.268Z,1497460746.268 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:06.695Z,1497460746.695 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:06.696Z,1497460746.696 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:07.083Z,1497460747.083 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:07.085Z,1497460747.085 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:07.536Z,1497460747.536 [Aanderaa_O2](INFO): Powering down
2017-06-14T17:19:07.657Z,1497460747.657 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:07.658Z,1497460747.658 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:07.864Z,1497460747.864 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:07.865Z,1497460747.865 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2017-06-14T17:19:07.982Z,1497460747.982 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2017-06-14T17:19:07.982Z,1497460747.982 [BuoyancyServo] No Fault, FailCount= 1
2017-06-14T17:19:08.336Z,1497460748.336 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2017-06-14T17:19:08.454Z,1497460748.454 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2017-06-14T17:19:17.425Z,1497460757.425 [NAL9602](INFO): NAL9602 initialized
2017-06-14T17:19:32.627Z,1497460772.627 [NAL9602](INFO): SBD MO Status=0, MOMSN=64928, MT Status=0, MTMSN=0
2017-06-14T17:19:32.627Z,1497460772.627 [NAL9602](INFO): No messages in MT queue
2017-06-14T17:19:43.031Z,1497460783.031 [NAL9602](INFO): GPS fix at 20170614T171754: (36.802877, -121.788083)
2017-06-14T17:19:50.228Z,1497460790.228 [NAL9602](INFO): Powering down
2017-06-14T17:20:03.127Z,1497460803.127 [SBIT](IMPORTANT): Beginning Startup BIT
2017-06-14T17:20:03.152Z,1497460803.152 [CBIT](IMPORTANT): Beginning ground fault scan
2017-06-14T17:20:13.740Z,1497460813.740 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): 0.027735
CHAN A2 (12V): -0.001882
CHAN A3 (5V): 4.753929
CHAN B0 (3.3V): 0.001782
CHAN B1 (3.15aV): -0.000267
CHAN B2 (3.15bV): 0.000458
CHAN B3 (GND): 0.000096
OPEN: -0.000374
Full Scale Calc: 4.765 mA, -1.589 mA
2017-06-14T17:20:57.254Z,1497460857.254 [SBIT](IMPORTANT): SBIT PASSED
2017-06-14T17:20:57.617Z,1497460857.617 [MissionManager](IMPORTANT): Started mission Startup
2017-06-14T17:20:57.618Z,1497460857.618 [Startup] Running Loop=1
2017-06-14T17:20:57.630Z,1497460857.630 [Startup](DEBUG): Aggregate::initialize Startup
2017-06-14T17:20:57.630Z,1497460857.630 [Startup:A.GoToSurface] Running Loop=1
2017-06-14T17:20:57.630Z,1497460857.630 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-06-14T17:20:57.631Z,1497460857.631 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-06-14T17:20:57.631Z,1497460857.631 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-06-14T17:20:57.632Z,1497460857.632 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-06-14T17:20:57.632Z,1497460857.632 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-06-14T17:20:57.632Z,1497460857.632 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-06-14T17:20:57.639Z,1497460857.639 [Startup:StartupSatComms] Running Loop=1
2017-06-14T17:20:57.639Z,1497460857.639 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2017-06-14T17:20:57.639Z,1497460857.639 [Startup:StartupSatComms:A] Running Loop=1
2017-06-14T17:20:58.018Z,1497460858.018 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2017-06-14T17:20:58.348Z,1497460858.348 [NAL9602](INFO): Powering up
2017-06-14T17:21:09.149Z,1497460869.149 [NAL9602](INFO): NAL9602 initialized
2017-06-14T17:21:39.181Z,1497460899.181 [BPC1](ERROR): Failed to parse bank B battery data
2017-06-14T17:21:39.182Z,1497460899.182 [BPC1] Data Fault, FailCount= 1
2017-06-14T17:21:39.182Z,1497460899.182 [BPC1](ERROR): Data Fault
2017-06-14T17:21:39.233Z,1497460899.233 [CBIT](ERROR): Data Fault in component: BPC1
2017-06-14T17:21:39.551Z,1497460899.551 [NAL9602](INFO): SBD MO Status=2, MOMSN=64929, MT Status=2, MTMSN=0
2017-06-14T17:21:39.551Z,1497460899.551 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-06-14T17:21:40.428Z,1497460900.428 [CBIT](INFO): Clearing failed state for component BPC1
2017-06-14T17:21:40.428Z,1497460900.428 [BPC1] No Fault, FailCount= 1
2017-06-14T17:21:55.556Z,1497460915.556 [NAL9602](INFO): SBD MO Status=2, MOMSN=64929, MT Status=2, MTMSN=0
2017-06-14T17:21:55.556Z,1497460915.556 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-06-14T17:21:58.013Z,1497460918.013 [Startup:StartupSatComms:A](INFO): Timed out from 2017-06-14T17:20:57.6Z
2017-06-14T17:21:58.013Z,1497460918.013 [Startup:StartupSatComms:A] Stopped
2017-06-14T17:21:58.013Z,1497460918.013 [Startup:StartupSatComms:B] Running Loop=1
2017-06-14T17:21:58.410Z,1497460918.410 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-06-14T17:22:27.949Z,1497460947.949 [NAL9602](INFO): SBD MO Status=0, MOMSN=64929, MT Status=0, MTMSN=0
2017-06-14T17:22:27.949Z,1497460947.949 [NAL9602](INFO): No messages in MT queue
2017-06-14T17:22:35.321Z,1497460955.321 [BPC1](ERROR): Failed to parse bank A battery data
2017-06-14T17:22:35.321Z,1497460955.321 [BPC1] Data Fault, FailCount= 1
2017-06-14T17:22:35.321Z,1497460955.321 [BPC1](ERROR): Data Fault
2017-06-14T17:22:35.366Z,1497460955.366 [CBIT](ERROR): Data Fault in component: BPC1
2017-06-14T17:22:36.518Z,1497460956.518 [CBIT](INFO): Clearing failed state for component BPC1
2017-06-14T17:22:36.518Z,1497460956.518 [BPC1] No Fault, FailCount= 1
2017-06-14T17:22:38.059Z,1497460958.059 [NAL9602](INFO): SBD MO Status=1, MOMSN=64930, MT Status=0, MTMSN=0
2017-06-14T17:22:38.109Z,1497460958.109 [NAL9602](INFO): Sent 25 bytes from file Logs/20170614T171242/Courier0008.lzma
2017-06-14T17:22:38.109Z,1497460958.109 [NAL9602](INFO): Packets left to send: 0
2017-06-14T17:22:38.111Z,1497460958.111 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170614T171242/Courier0008.lzma.parts/0000.sbd
2017-06-14T17:22:38.111Z,1497460958.111 [NAL9602](DEBUG): Completed sending Logs/20170614T171242/Courier0008.lzma
2017-06-14T17:22:48.175Z,1497460968.175 [NAL9602](INFO): SBD MO Status=1, MOMSN=64931, MT Status=0, MTMSN=0
2017-06-14T17:22:48.225Z,1497460968.225 [NAL9602](INFO): Sent 25 bytes from file Logs/20170614T171242/Courier0012.lzma
2017-06-14T17:22:48.225Z,1497460968.225 [NAL9602](INFO): Packets left to send: 0
2017-06-14T17:22:48.227Z,1497460968.227 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170614T171242/Courier0012.lzma.parts/0000.sbd
2017-06-14T17:22:48.227Z,1497460968.227 [NAL9602](DEBUG): Completed sending Logs/20170614T171242/Courier0012.lzma
2017-06-14T17:22:57.951Z,1497460977.951 [NAL9602](INFO): SBD MO Status=1, MOMSN=64932, MT Status=0, MTMSN=0
2017-06-14T17:22:58.001Z,1497460978.001 [NAL9602](INFO): Sent 305 bytes from file Logs/20170614T171853/Courier0000.lzma
2017-06-14T17:22:58.001Z,1497460978.001 [NAL9602](INFO): Packets left to send: 0
2017-06-14T17:22:58.002Z,1497460978.002 [NAL9602](DEBUG): Stored copy of sent data in Logs/20170614T171853/Courier0000.lzma.parts/0000.sbd
2017-06-14T17:22:58.003Z,1497460978.003 [NAL9602](DEBUG): Completed sending Logs/20170614T171853/Courier0000.lzma
2017-06-14T17:22:58.058Z,1497460978.058 [Startup:StartupSatComms:B](INFO): Timed out from 2017-06-14T17:21:58.0Z
2017-06-14T17:22:58.058Z,1497460978.058 [Startup:StartupSatComms:B] Stopped
2017-06-14T17:22:58.058Z,1497460978.058 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2017-06-14T17:22:58.058Z,1497460978.058 [Startup:StartupSatComms] Stopped
2017-06-14T17:22:58.058Z,1497460978.058 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2017-06-14T17:22:58.059Z,1497460978.059 [Startup](INFO): Completed Startup
2017-06-14T17:22:58.060Z,1497460978.060 [MissionManager](INFO): Startup is completed.
2017-06-14T17:22:58.060Z,1497460978.060 [MissionManager](INFO): Uninitializing Mission Startup
2017-06-14T17:22:58.060Z,1497460978.060 [Startup] Stopped
2017-06-14T17:22:58.060Z,1497460978.060 [Startup](DEBUG): Aggregate::uninitialize Startup
2017-06-14T17:22:58.060Z,1497460978.060 [Startup:A.GoToSurface] Stopped
2017-06-14T17:22:58.060Z,1497460978.060 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-06-14T17:22:58.596Z,1497460978.596 [MissionManager](IMPORTANT): Started mission Default
2017-06-14T17:22:58.596Z,1497460978.596 [Default] Running Loop=1
2017-06-14T17:22:58.597Z,1497460978.597 [Default](DEBUG): Aggregate::initialize Default
2017-06-14T17:22:58.597Z,1497460978.597 [Default:B.GoToSurface] Running Loop=1
2017-06-14T17:22:58.597Z,1497460978.597 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-06-14T17:22:58.597Z,1497460978.597 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-06-14T17:22:58.597Z,1497460978.597 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-06-14T17:22:58.598Z,1497460978.598 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-06-14T17:22:58.598Z,1497460978.598 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-06-14T17:22:58.598Z,1497460978.598 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-06-14T17:22:58.599Z,1497460978.599 [Default:A.Wait] Running Loop=1
2017-06-14T17:22:58.599Z,1497460978.599 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-06-14T17:23:09.857Z,1497460989.857 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003707
2017-06-14T17:23:11.912Z,1497460991.912 [Default:A.Wait](INFO): Done Waiting.
2017-06-14T17:23:11.912Z,1497460991.912 [Default:A.Wait] Stopped
2017-06-14T17:23:11.912Z,1497460991.912 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-06-14T17:23:12.323Z,1497460992.323 [Default:CheckIn] Running Loop=1
2017-06-14T17:23:12.323Z,1497460992.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-06-14T17:23:12.323Z,1497460992.323 [Default:CheckIn:Read_GPS] Running Loop=1
2017-06-14T17:23:12.716Z,1497460992.716 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2017-06-14T17:23:16.664Z,1497460996.664 [NAL9602](INFO): SBD MO Status=2, MOMSN=64933, MT Status=2, MTMSN=0
2017-06-14T17:23:16.664Z,1497460996.664 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2017-06-14T17:23:17.860Z,1497460997.860 [NAL9602](INFO): GPS fix at 20170614T172129: (36.802921, -121.788088)
2017-06-14T17:23:17.932Z,1497460997.932 [Default:CheckIn:Read_GPS] Stopped
2017-06-14T17:23:17.932Z,1497460997.932 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-06-14T17:23:18.333Z,1497460998.333 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2017-06-14T17:23:24.962Z,1497461004.962 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20170614T171853/Courier0004.lzma
2017-06-14T17:23:25.763Z,1497461005.763 [DataOverHttps](INFO): Moved sent file to Logs/20170614T171853/Courier0004.lzma.bak
2017-06-14T17:23:25.763Z,1497461005.763 [DataOverHttps](INFO): SBD MOMSN=5046402
2017-06-14T17:23:29.996Z,1497461009.996 [NAL9602](INFO): Powering down
2017-06-14T17:23:35.841Z,1497461015.841 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20170614T171242/Express0009.lzma
2017-06-14T17:23:36.576Z,1497461016.576 [DataOverHttps](INFO): Moved sent file to Logs/20170614T171242/Express0009.lzma.bak
2017-06-14T17:23:36.576Z,1497461016.576 [DataOverHttps](IMPORTANT): SBD MOMSN=5046406, MTMSN=20170614T172148
2017-06-14T17:23:41.478Z,1497461021.478 [DataOverHttps](INFO): Received command:configSet list
2017-06-14T17:23:41.558Z,1497461021.558 [CommandLine](IMPORTANT): got command configSet list
2017-06-14T17:23:41.558Z,1497461021.558 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2017-06-14T17:23:41.559Z,1497461021.559 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool;
2017-06-14T17:23:41.559Z,1497461021.559 [CommandLine](IMPORTANT): CANONSampler.simulateHardware=0 bool;
2017-06-14T17:23:41.559Z,1497461021.559 [CommandLine](IMPORTANT): CBIT.abortDepth=250 meter;
2017-06-14T17:23:41.559Z,1497461021.559 [CommandLine](IMPORTANT): CBIT.runFaultClassifier=1 bool;
2017-06-14T17:23:41.559Z,1497461021.559 [CommandLine](IMPORTANT): CBIT.stopDepth=205 meter;
2017-06-14T17:23:41.559Z,1497461021.559 [CommandLine](IMPORTANT): Normal linearApproximation Rowe_600LCM.height_above_sea_floor 5.000000 meter;
2017-06-14T17:23:41.560Z,1497461021.560 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool;
2017-06-14T17:23:41.560Z,1497461021.560 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=315 milliliter;
2017-06-14T17:23:41.560Z,1497461021.560 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 centimeter;
2017-06-14T17:23:41.560Z,1497461021.560 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-35 millimeter;
2017-06-14T17:23:41.560Z,1497461021.560 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=26 millimeter;
2017-06-14T17:23:46.558Z,1497461026.558 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20170614T171242/Express0013.lzma
2017-06-14T17:23:47.300Z,1497461027.300 [DataOverHttps](INFO): Moved sent file to Logs/20170614T171242/Express0013.lzma.bak
2017-06-14T17:23:47.301Z,1497461027.301 [DataOverHttps](INFO): SBD MOMSN=5046413
2017-06-14T17:23:56.650Z,1497461036.650 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20170614T171853/Courier0008.lzma
2017-06-14T17:23:57.397Z,1497461037.397 [DataOverHttps](INFO): Moved sent file to Logs/20170614T171853/Courier0008.lzma.bak
2017-06-14T17:23:57.397Z,1497461037.397 [DataOverHttps](INFO): SBD MOMSN=5046415
2017-06-14T17:24:06.655Z,1497461046.655 [DataOverHttps](INFO): Sending 674 bytes from file Logs/20170614T171853/Express0001.lzma
2017-06-14T17:24:07.400Z,1497461047.400 [DataOverHttps](INFO): Moved sent file to Logs/20170614T171853/Express0001.lzma.bak
2017-06-14T17:24:07.400Z,1497461047.400 [DataOverHttps](INFO): SBD MOMSN=5046417
2017-06-14T17:24:18.585Z,1497461058.585 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20170614T171853/Express0005.lzma
2017-06-14T17:24:19.359Z,1497461059.359 [DataOverHttps](INFO): Moved sent file to Logs/20170614T171853/Express0005.lzma.bak
2017-06-14T17:24:19.359Z,1497461059.359 [DataOverHttps](INFO): SBD MOMSN=5046429
2017-06-14T17:24:28.789Z,1497461068.789 [DataOverHttps](INFO): Sending 476 bytes from file Logs/20170614T171853/Express0009.lzma
2017-06-14T17:24:29.568Z,1497461069.568 [DataOverHttps](INFO): Moved sent file to Logs/20170614T171853/Express0009.lzma.bak
2017-06-14T17:24:29.569Z,1497461069.569 [DataOverHttps](INFO): SBD MOMSN=5046435
2017-06-14T17:24:30.159Z,1497461070.159 [Default:CheckIn:Read_Iridium] Stopped
2017-06-14T17:24:30.159Z,1497461070.159 [Default:CheckIn:C.Wait] Running Loop=1
2017-06-14T17:24:30.159Z,1497461070.159 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2017-06-14T17:25:34.935Z,1497461134.935 [DataOverHttps](IMPORTANT): SBD MTMSN=20170614T172347
2017-06-14T17:25:39.170Z,1497461139.170 [DataOverHttps](INFO): Received command:configSet Radio_Surface.loadAtStartup 0 bool persist; restart app
2017-06-14T17:25:39.316Z,1497461139.316 [CommandLine](IMPORTANT): got command configSet Radio_Surface.loadAtStartup 0.000000 bool persist
2017-06-14T17:25:39.317Z,1497461139.317 [CommandLine](IMPORTANT): configSet Radio_Surface.loadAtStartup requires a restart to take effect.
2017-06-14T17:25:39.323Z,1497461139.323 [CommandLine](IMPORTANT): got command restart application
2017-06-14T17:25:40.328Z,1497461140.328 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:40.329Z,1497461140.329 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:40.521Z,1497461140.521 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2017-06-14T17:25:40.521Z,1497461140.521 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:40.522Z,1497461140.522 [CommandLine](INFO): Join timeout helper Thread ID is 1026
2017-06-14T17:25:40.525Z,1497461140.525 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2017-06-14T17:25:40.526Z,1497461140.526 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:40.526Z,1497461140.526 [NavChartDb](INFO): Join timeout helper Thread ID is 1027
2017-06-14T17:25:40.766Z,1497461140.766 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:40.766Z,1497461140.766 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:40.782Z,1497461140.782 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2017-06-14T17:25:40.782Z,1497461140.782 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:40.782Z,1497461140.782 [Radio_Surface](INFO): Join timeout helper Thread ID is 1028
2017-06-14T17:25:40.990Z,1497461140.990 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:40.991Z,1497461140.991 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:41.010Z,1497461141.010 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2017-06-14T17:25:41.010Z,1497461141.010 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:41.011Z,1497461141.011 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1029
2017-06-14T17:25:41.323Z,1497461141.323 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:41.323Z,1497461141.323 [WetLabsBB2FL](INFO): Powering down
2017-06-14T17:25:41.324Z,1497461141.324 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:41.343Z,1497461141.343 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2017-06-14T17:25:41.343Z,1497461141.343 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:41.343Z,1497461141.343 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1030
2017-06-14T17:25:41.563Z,1497461141.563 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:41.756Z,1497461141.756 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2017-06-14T17:25:41.756Z,1497461141.756 [CTD_Seabird](INFO): Powering down
2017-06-14T17:25:41.757Z,1497461141.757 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:41.776Z,1497461141.776 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2017-06-14T17:25:41.777Z,1497461141.777 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:41.777Z,1497461141.777 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1032
2017-06-14T17:25:42.020Z,1497461142.020 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:42.020Z,1497461142.020 [CTD_NeilBrown](INFO): Powering down
2017-06-14T17:25:42.021Z,1497461142.021 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.041Z,1497461142.041 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2017-06-14T17:25:42.041Z,1497461142.041 [logger ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.041Z,1497461142.041 [logger](INFO): Join timeout helper Thread ID is 1033
2017-06-14T17:25:42.047Z,1497461142.047 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:42.047Z,1497461142.047 [logger ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.049Z,1497461142.049 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2017-06-14T17:25:42.049Z,1497461142.049 [CommandLine ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.049Z,1497461142.049 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2017-06-14T17:25:42.049Z,1497461142.049 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.050Z,1497461142.050 [controlThread](INFO): Join timeout helper Thread ID is 1034
2017-06-14T17:25:42.328Z,1497461142.328 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2017-06-14T17:25:42.329Z,1497461142.329 [controlThread](DEBUG): Uninitializing ControlThread
2017-06-14T17:25:42.329Z,1497461142.329 [Aanderaa_O2](INFO): Powering down
2017-06-14T17:25:42.331Z,1497461142.331 [NAL9602](INFO): Powering down
2017-06-14T17:25:42.333Z,1497461142.333 [PNI_TCM](INFO): Powering down
2017-06-14T17:25:42.422Z,1497461142.422 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2017-06-14T17:25:42.423Z,1497461142.423 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2017-06-14T17:25:42.424Z,1497461142.424 [MissionManager](INFO): Uninitializing Mission Default
2017-06-14T17:25:42.424Z,1497461142.424 [Default] Stopped
2017-06-14T17:25:42.424Z,1497461142.424 [Default](DEBUG): Aggregate::uninitialize Default
2017-06-14T17:25:42.424Z,1497461142.424 [Default:B.GoToSurface] Stopped
2017-06-14T17:25:42.424Z,1497461142.424 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-06-14T17:25:42.424Z,1497461142.424 [Default:CheckIn] Stopped
2017-06-14T17:25:42.425Z,1497461142.425 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-06-14T17:25:42.425Z,1497461142.425 [Default:CheckIn:C.Wait] Stopped
2017-06-14T17:25:42.425Z,1497461142.425 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2017-06-14T17:25:42.428Z,1497461142.428 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2017-06-14T17:25:42.428Z,1497461142.428 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2017-06-14T17:25:42.428Z,1497461142.428 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2017-06-14T17:25:42.429Z,1497461142.429 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2017-06-14T17:25:42.429Z,1497461142.429 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2017-06-14T17:25:42.429Z,1497461142.429 [BuoyancyServo](INFO): Powering down
2017-06-14T17:25:42.440Z,1497461142.440 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2017-06-14T17:25:42.441Z,1497461142.441 [ElevatorServo](INFO): Powering down
2017-06-14T17:25:42.441Z,1497461142.441 [MassServo](DEBUG): Uninitialize Mass Servo.
2017-06-14T17:25:42.441Z,1497461142.441 [MassServo](INFO): Powering down
2017-06-14T17:25:42.442Z,1497461142.442 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2017-06-14T17:25:42.443Z,1497461142.443 [RudderServo](INFO): Powering down
2017-06-14T17:25:42.443Z,1497461142.443 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2017-06-14T17:25:42.444Z,1497461142.444 [ThrusterServo](INFO): Powering down
2017-06-14T17:25:42.445Z,1497461142.445 [SBIT](DEBUG): Uninitialize SBIT Component.
2017-06-14T17:25:42.445Z,1497461142.445 [IBIT](DEBUG): Uninitialize IBIT Component.
2017-06-14T17:25:42.445Z,1497461142.445 [CBIT](DEBUG): Uninitialize CBIT Component.
2017-06-14T17:25:42.446Z,1497461142.446 [controlThread ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.500Z,1497461142.500 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.504Z,1497461142.504 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.507Z,1497461142.507 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.577Z,1497461142.577 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.620Z,1497461142.620 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2017-06-14T17:25:42.692Z,1497461142.692 [logger ThreadHandler](INFO): Thread cancelled.