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.