2015-07-10T04:12:58.461Z,1436501578.461 [Supervisor](DEBUG): Initializing supervisor. 2015-07-10T04:12:58.466Z,1436501578.466 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-07-10T04:12:58.466Z,1436501578.466 [SyncHandler](INFO): Protected caller Thread ID is 765 2015-07-10T04:12:58.467Z,1436501578.467 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-07-10T04:12:58.470Z,1436501578.470 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-07-10T04:12:58.470Z,1436501578.470 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 766 2015-07-10T04:12:58.473Z,1436501578.473 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-07-10T04:12:58.486Z,1436501578.486 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-07-10T04:12:58.490Z,1436501578.490 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-07-10T04:12:58.490Z,1436501578.490 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 767 2015-07-10T04:12:58.491Z,1436501578.491 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-07-10T04:12:58.494Z,1436501578.494 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-07-10T04:12:58.494Z,1436501578.494 [logger ThreadHandler](INFO): Protected caller Thread ID is 768 2015-07-10T04:12:58.497Z,1436501578.497 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-07-10T04:12:58.497Z,1436501578.497 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-07-10T04:12:58.500Z,1436501578.500 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-07-10T04:12:58.924Z,1436501578.924 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-07-10T04:12:58.926Z,1436501578.926 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-07-10T04:12:59.132Z,1436501579.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-07-10T04:12:59.132Z,1436501579.132 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-07-10T04:12:59.257Z,1436501579.257 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-07-10T04:12:59.258Z,1436501579.258 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-07-10T04:12:59.400Z,1436501579.400 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-07-10T04:12:59.401Z,1436501579.401 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-07-10T04:12:59.501Z,1436501579.501 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-07-10T04:12:59.729Z,1436501579.729 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-07-10T04:12:59.729Z,1436501579.729 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-07-10T04:12:59.829Z,1436501579.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-07-10T04:12:59.829Z,1436501579.829 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-07-10T04:13:00.105Z,1436501580.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-07-10T04:13:00.106Z,1436501580.106 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-07-10T04:13:00.544Z,1436501580.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-07-10T04:13:00.545Z,1436501580.545 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-07-10T04:13:00.927Z,1436501580.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-07-10T04:13:00.928Z,1436501580.928 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-07-10T04:13:01.548Z,1436501581.548 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-07-10T04:13:01.549Z,1436501581.549 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-07-10T04:13:01.808Z,1436501581.808 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-07-10T04:13:01.809Z,1436501581.809 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-07-10T04:13:01.934Z,1436501581.934 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-07-10T04:13:01.935Z,1436501581.935 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-07-10T04:13:02.494Z,1436501582.494 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-07-10T04:13:02.494Z,1436501582.494 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-07-10T04:13:02.624Z,1436501582.624 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-07-10T04:13:02.626Z,1436501582.626 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2015-07-10T04:13:02.628Z,1436501582.628 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2015-07-10T04:13:02.906Z,1436501582.906 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-07-10T04:13:02.907Z,1436501582.907 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2015-07-10T04:13:03.046Z,1436501583.046 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg 2015-07-10T04:13:03.159Z,1436501583.159 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2015-07-10T04:13:03.271Z,1436501583.271 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2015-07-10T04:13:03.383Z,1436501583.383 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2015-07-10T04:13:03.563Z,1436501583.563 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2015-07-10T04:13:03.732Z,1436501583.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2015-07-10T04:13:03.856Z,1436501583.856 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2015-07-10T04:13:03.960Z,1436501583.960 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2015-07-10T04:13:04.070Z,1436501584.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2015-07-10T04:13:04.197Z,1436501584.197 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2015-07-10T04:13:04.421Z,1436501584.421 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2015-07-10T04:13:04.429Z,1436501584.429 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-07-10T04:13:04.503Z,1436501584.503 [VerticalControl](DEBUG): Construct VerticalControl. 2015-07-10T04:13:04.639Z,1436501584.639 [VerticalControl] Loaded 2015-07-10T04:13:04.639Z,1436501584.639 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-07-10T04:13:04.644Z,1436501584.644 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-07-10T04:13:04.725Z,1436501584.725 [HorizontalControl] Loaded 2015-07-10T04:13:04.725Z,1436501584.725 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-07-10T04:13:04.726Z,1436501584.726 [SpeedControl](DEBUG): Construct SpeedControl. 2015-07-10T04:13:04.732Z,1436501584.732 [SpeedControl] Loaded 2015-07-10T04:13:04.733Z,1436501584.733 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-07-10T04:13:04.733Z,1436501584.733 [LoopControl](DEBUG): Construct LoopControl. 2015-07-10T04:13:04.734Z,1436501584.734 [LoopControl] Loaded 2015-07-10T04:13:04.734Z,1436501584.734 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-07-10T04:13:04.735Z,1436501584.735 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-07-10T04:13:04.736Z,1436501584.736 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-07-10T04:13:04.901Z,1436501584.901 [SBIT](DEBUG): Construct Startup Built In Test. 2015-07-10T04:13:04.913Z,1436501584.913 [SBIT] Loaded 2015-07-10T04:13:04.913Z,1436501584.913 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-07-10T04:13:04.914Z,1436501584.914 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-07-10T04:13:04.949Z,1436501584.949 [IBIT] Loaded 2015-07-10T04:13:04.949Z,1436501584.949 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-07-10T04:13:04.951Z,1436501584.951 [CBIT](DEBUG): Construct Continuous Built In Test. 2015-07-10T04:13:05.109Z,1436501585.109 [CBIT] Loaded 2015-07-10T04:13:05.109Z,1436501585.109 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-07-10T04:13:05.109Z,1436501585.109 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-07-10T04:13:05.110Z,1436501585.110 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-07-10T04:13:05.142Z,1436501585.142 [DepthRateCalculator] Loaded 2015-07-10T04:13:05.142Z,1436501585.142 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-07-10T04:13:05.148Z,1436501585.148 [PitchRateCalculator] Loaded 2015-07-10T04:13:05.148Z,1436501585.148 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-07-10T04:13:05.161Z,1436501585.161 [SpeedCalculator] Loaded 2015-07-10T04:13:05.161Z,1436501585.161 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-07-10T04:13:05.178Z,1436501585.178 [TempGradientCalculator] Loaded 2015-07-10T04:13:05.178Z,1436501585.178 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-07-10T04:13:05.183Z,1436501585.183 [YawRateCalculator] Loaded 2015-07-10T04:13:05.184Z,1436501585.184 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-07-10T04:13:05.184Z,1436501585.184 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-07-10T04:13:05.185Z,1436501585.185 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-07-10T04:13:10.317Z,1436501590.317 [HFRadarCompactModelForecaster] Loaded 2015-07-10T04:13:10.317Z,1436501590.317 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread. 2015-07-10T04:13:11.624Z,1436501591.624 [HFRCMSpaceInterpolator] Loaded 2015-07-10T04:13:11.624Z,1436501591.624 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread. 2015-07-10T04:13:11.626Z,1436501591.626 [HFRCMTimeInterpolator] Loaded 2015-07-10T04:13:11.627Z,1436501591.627 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread. 2015-07-10T04:13:12.953Z,1436501592.953 [HFRCMReconstructedInterpolator] Loaded 2015-07-10T04:13:12.953Z,1436501592.953 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread. 2015-07-10T04:13:12.966Z,1436501592.966 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded 2015-07-10T04:13:12.966Z,1436501592.966 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread. 2015-07-10T04:13:13.040Z,1436501593.040 [HFRCMVirtualSurfaceDrifter] Loaded 2015-07-10T04:13:13.041Z,1436501593.041 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread. 2015-07-10T04:13:13.041Z,1436501593.041 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-07-10T04:13:13.042Z,1436501593.042 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-07-10T04:13:13.344Z,1436501593.344 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-07-10T04:13:13.345Z,1436501593.345 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-07-10T04:13:13.476Z,1436501593.476 [DeadReckonUsingMultipleVelocitySources] Loaded 2015-07-10T04:13:13.476Z,1436501593.476 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2015-07-10T04:13:13.542Z,1436501593.542 [DeadReckonUsingSpeedCalculator] Loaded 2015-07-10T04:13:13.543Z,1436501593.543 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2015-07-10T04:13:13.560Z,1436501593.560 [NavChart] Loaded 2015-07-10T04:13:13.560Z,1436501593.560 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-07-10T04:13:13.565Z,1436501593.565 [UniversalFixResidualReporter] Loaded 2015-07-10T04:13:13.565Z,1436501593.565 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-07-10T04:13:13.566Z,1436501593.566 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-07-10T04:13:13.566Z,1436501593.566 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-07-10T04:13:13.575Z,1436501593.575 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-07-10T04:13:13.576Z,1436501593.576 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-07-10T04:13:13.830Z,1436501593.830 [Aanderaa_O2] Loaded 2015-07-10T04:13:13.830Z,1436501593.830 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2015-07-10T04:13:13.841Z,1436501593.841 [CANONSampler] Loaded 2015-07-10T04:13:13.842Z,1436501593.842 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2015-07-10T04:13:13.932Z,1436501593.932 [CTD_NeilBrown] Loaded 2015-07-10T04:13:13.932Z,1436501593.932 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2015-07-10T04:13:13.934Z,1436501593.934 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406F24E0 2015-07-10T04:13:13.934Z,1436501593.934 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 853 2015-07-10T04:13:13.950Z,1436501593.950 [PAR_Licor] Loaded 2015-07-10T04:13:13.951Z,1436501593.951 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2015-07-10T04:13:14.007Z,1436501594.007 [WetLabsBB2FL] Loaded 2015-07-10T04:13:14.007Z,1436501594.007 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2015-07-10T04:13:14.010Z,1436501594.010 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407224E0 2015-07-10T04:13:14.010Z,1436501594.010 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 854 2015-07-10T04:13:14.011Z,1436501594.011 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-07-10T04:13:14.012Z,1436501594.012 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-07-10T04:13:14.552Z,1436501594.552 [AcousticModem_Benthos_ATM900] Loaded 2015-07-10T04:13:14.552Z,1436501594.552 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2015-07-10T04:13:14.743Z,1436501594.743 [DataOverHttps] Loaded 2015-07-10T04:13:14.743Z,1436501594.743 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-07-10T04:13:14.757Z,1436501594.757 [Depth_Keller] Loaded 2015-07-10T04:13:14.757Z,1436501594.757 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-07-10T04:13:14.762Z,1436501594.762 [DropWeight] Loaded 2015-07-10T04:13:14.763Z,1436501594.763 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2015-07-10T04:13:14.870Z,1436501594.870 [NAL9602] Loaded 2015-07-10T04:13:14.870Z,1436501594.870 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-07-10T04:13:14.919Z,1436501594.919 [Onboard] Loaded 2015-07-10T04:13:14.919Z,1436501594.919 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-07-10T04:13:14.926Z,1436501594.926 [Radio_Surface] Loaded 2015-07-10T04:13:14.927Z,1436501594.927 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-07-10T04:13:14.932Z,1436501594.932 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409664E0 2015-07-10T04:13:14.932Z,1436501594.932 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 855 2015-07-10T04:13:15.151Z,1436501595.151 [PNI_TCM] Loaded 2015-07-10T04:13:15.152Z,1436501595.152 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2015-07-10T04:13:17.260Z,1436501597.260 [BPC1] Loaded 2015-07-10T04:13:17.260Z,1436501597.260 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-07-10T04:13:17.261Z,1436501597.261 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-07-10T04:13:17.261Z,1436501597.261 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-07-10T04:13:17.399Z,1436501597.399 [BuoyancyServo] Loaded 2015-07-10T04:13:17.400Z,1436501597.400 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-07-10T04:13:17.413Z,1436501597.413 [ElevatorServo] Loaded 2015-07-10T04:13:17.413Z,1436501597.413 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-07-10T04:13:17.426Z,1436501597.426 [MassServo] Loaded 2015-07-10T04:13:17.426Z,1436501597.426 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2015-07-10T04:13:17.443Z,1436501597.443 [RudderServo] Loaded 2015-07-10T04:13:17.444Z,1436501597.444 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-07-10T04:13:17.456Z,1436501597.456 [ThrusterServo] Loaded 2015-07-10T04:13:17.456Z,1436501597.456 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-07-10T04:13:17.457Z,1436501597.457 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-07-10T04:13:17.458Z,1436501597.458 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-07-10T04:13:17.601Z,1436501597.601 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-07-10T04:13:17.602Z,1436501597.602 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-07-10T04:13:17.645Z,1436501597.645 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-07-10T04:13:17.649Z,1436501597.649 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-07-10T04:13:17.650Z,1436501597.650 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-07-10T04:13:17.661Z,1436501597.661 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-07-10T04:13:17.664Z,1436501597.664 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A144E0 2015-07-10T04:13:17.664Z,1436501597.664 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 857 2015-07-10T04:13:17.669Z,1436501597.669 [Supervisor](INFO): Main Thread ID is 764 2015-07-10T04:13:17.669Z,1436501597.669 [Supervisor](DEBUG): Running supervisor. 2015-07-10T04:13:17.670Z,1436501597.670 [CommandLine ThreadHandler](INFO): Handler Thread ID is 858 2015-07-10T04:13:17.676Z,1436501597.676 [controlThread ThreadHandler](INFO): Handler Thread ID is 859 2015-07-10T04:13:17.677Z,1436501597.677 [controlThread](DEBUG): Initializing ControlThread 2015-07-10T04:13:17.678Z,1436501597.678 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-07-10T04:13:17.679Z,1436501597.679 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-07-10T04:13:17.680Z,1436501597.680 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-07-10T04:13:17.681Z,1436501597.681 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-07-10T04:13:17.681Z,1436501597.681 [SBIT](INFO): Initialize SBIT Component. 2015-07-10T04:13:17.682Z,1436501597.682 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12326 2015-07-10T04:13:17.682Z,1436501597.682 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-07-10T04:13:17.682Z,1436501597.682 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-07-10T04:13:17.683Z,1436501597.683 [SBIT](INFO): Beginning SBIT in 63.000000 seconds. 2015-07-10T04:13:17.684Z,1436501597.684 [IBIT](INFO): Initialize IBIT Component. 2015-07-10T04:13:17.685Z,1436501597.685 [CBIT](DEBUG): Initialize CBIT Component. 2015-07-10T04:13:17.685Z,1436501597.685 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2015-07-10T04:13:17.688Z,1436501597.688 [logger ThreadHandler](INFO): Handler Thread ID is 860 2015-07-10T04:13:17.708Z,1436501597.708 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-07-10T04:13:17.708Z,1436501597.708 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-07-10T04:13:17.709Z,1436501597.709 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-07-10T04:13:17.709Z,1436501597.709 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-07-10T04:13:17.710Z,1436501597.710 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-07-10T04:13:17.745Z,1436501597.745 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 861 2015-07-10T04:13:17.745Z,1436501597.745 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2015-07-10T04:13:17.751Z,1436501597.751 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 863 2015-07-10T04:13:17.753Z,1436501597.753 [WetLabsBB2FL](INFO): Powering down 2015-07-10T04:13:17.777Z,1436501597.777 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2015-07-10T04:13:17.788Z,1436501597.788 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 864 2015-07-10T04:13:17.795Z,1436501597.795 [Radio_Surface](INFO): Powering up 2015-07-10T04:13:17.803Z,1436501597.803 [HFRadarCompactModelForecaster](DEBUG): Found new ECs! 2015-07-10T04:13:17.803Z,1436501597.803 [HFRadarCompactModelForecaster](ERROR): Most recent ECs are more than six hours old. 2015-07-10T04:13:17.805Z,1436501597.805 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 865 2015-07-10T04:13:17.810Z,1436501597.810 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-07-10T04:13:17.811Z,1436501597.811 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-07-10T04:13:17.811Z,1436501597.811 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-07-10T04:13:17.811Z,1436501597.811 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-07-10T04:13:17.812Z,1436501597.812 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-07-10T04:13:17.812Z,1436501597.812 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-07-10T04:13:17.812Z,1436501597.812 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-07-10T04:13:17.813Z,1436501597.813 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-07-10T04:13:17.813Z,1436501597.813 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-07-10T04:13:18.197Z,1436501598.197 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout 2015-07-10T04:13:18.198Z,1436501598.198 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.419755 2015-07-10T04:13:26.924Z,1436501606.924 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201505192300 published 2015-07-10T04:13:26.931Z,1436501606.931 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0. 2015-07-10T04:13:26.933Z,1436501606.933 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component. 2015-07-10T04:13:26.934Z,1436501606.934 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s. 2015-07-10T04:13:26.950Z,1436501606.950 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component. 2015-07-10T04:13:26.951Z,1436501606.951 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component. 2015-07-10T04:13:26.951Z,1436501606.951 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-07-10T04:13:26.952Z,1436501606.952 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-10T04:13:26.952Z,1436501606.952 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-10T04:13:26.952Z,1436501606.952 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-07-10T04:13:26.953Z,1436501606.953 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-10T04:13:26.953Z,1436501606.953 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-10T04:13:26.954Z,1436501606.954 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-07-10T04:13:26.954Z,1436501606.954 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-07-10T04:13:26.970Z,1436501606.970 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-07-10T04:13:27.023Z,1436501607.023 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-07-10T04:13:27.053Z,1436501607.053 [MissionManager](DEBUG): 2015-07-10T04:13:27.054Z,1436501607.054 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-07-10T04:13:27.133Z,1436501607.133 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2015-07-10T04:13:27.134Z,1436501607.134 [Default:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-07-10T04:13:27.175Z,1436501607.175 [Default:CheckIn:A.SetSpeed](DEBUG): Construct. 2015-07-10T04:13:27.208Z,1436501607.208 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-07-10T04:13:27.228Z,1436501607.228 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct. 2015-07-10T04:13:27.242Z,1436501607.242 [MissionManager](DEBUG): 0 5.0 1.0 400 10 500 Default mission has been running for Burn 300 Dropped weight due to communications timeout. 5 2015-07-10T04:13:27.248Z,1436501607.248 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2015-07-10T04:13:27.285Z,1436501607.285 [CANONSampler](INFO): Powering down 2015-07-10T04:13:27.331Z,1436501607.331 [AcousticModem_Benthos_ATM900](INFO): Powering up 2015-07-10T04:13:27.331Z,1436501607.331 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2015-07-10T04:13:27.561Z,1436501607.561 [NAL9602](INFO): Powering up NAL9602 2015-07-10T04:13:37.351Z,1436501617.351 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:37.531Z,1436501617.531 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:37.677Z,1436501617.677 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-07-10T04:13:37.683Z,1436501617.683 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-07-10T04:13:37.697Z,1436501617.697 [ElevatorServo](DEBUG): Initializing EZServoServo. 2015-07-10T04:13:37.703Z,1436501617.703 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2015-07-10T04:13:37.719Z,1436501617.719 [MassServo](DEBUG): Initializing EZServoServo. 2015-07-10T04:13:37.731Z,1436501617.731 [MassServo](DEBUG): Initializing MassServo. 2015-07-10T04:13:37.745Z,1436501617.745 [RudderServo](DEBUG): Initializing EZServoServo. 2015-07-10T04:13:37.751Z,1436501617.751 [RudderServo](DEBUG): Initializing RudderServo. 2015-07-10T04:13:37.771Z,1436501617.771 [ThrusterServo](DEBUG): Initializing EZServoServo. 2015-07-10T04:13:37.779Z,1436501617.779 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2015-07-10T04:13:37.927Z,1436501617.927 [AcousticModem_Benthos_ATM900](DEBUG): 2015-07-10T04:13:37.929Z,1436501617.929 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2015-07-10T04:13:37.929Z,1436501617.929 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2015-07-10T04:13:37.930Z,1436501617.930 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2015-07-10T04:13:37.931Z,1436501617.931 [AcousticModem_Benthos_ATM900](DEBUG): Jul 10 2015 04:15:24 2015-07-10T04:13:38.147Z,1436501618.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:38.156Z,1436501618.156 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:38.365Z,1436501618.365 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:38.366Z,1436501618.366 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:38.709Z,1436501618.709 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2015-07-10T04:13:38.709Z,1436501618.709 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2015-07-10T04:13:38.709Z,1436501618.709 [BuoyancyServo] Communications Fault, FailCount= 1 2015-07-10T04:13:38.709Z,1436501618.709 [BuoyancyServo](ERROR): Communications Fault 2015-07-10T04:13:38.915Z,1436501618.915 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2015-07-10T04:13:39.041Z,1436501619.041 [Aanderaa_O2](INFO): Powering down 2015-07-10T04:13:39.087Z,1436501619.087 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2015-07-10T04:13:39.122Z,1436501619.122 [NAL9602](INFO): NAL9602 initialized 2015-07-10T04:13:39.271Z,1436501619.271 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:39.272Z,1436501619.272 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:39.295Z,1436501619.295 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2015-07-10T04:13:39.296Z,1436501619.296 [BuoyancyServo](INFO): Powering down 2015-07-10T04:13:39.400Z,1436501619.400 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2015-07-10T04:13:39.401Z,1436501619.401 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2015-07-10T04:13:39.401Z,1436501619.401 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2015-07-10T04:13:39.497Z,1436501619.497 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:39.510Z,1436501619.510 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:39.807Z,1436501619.807 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2015-07-10T04:13:39.880Z,1436501619.880 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:39.882Z,1436501619.882 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:40.208Z,1436501620.208 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2015-07-10T04:13:40.209Z,1436501620.209 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2015-07-10T04:13:40.301Z,1436501620.301 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:40.302Z,1436501620.302 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-10T04:13:40.605Z,1436