2014-09-19T17:24:54.692Z,1411147494.692 [Supervisor](DEBUG): Initializing supervisor.
2014-09-19T17:24:54.694Z,1411147494.694 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-09-19T17:24:54.695Z,1411147494.695 [SyncHandler](INFO): Protected caller Thread ID is 1615
2014-09-19T17:24:54.696Z,1411147494.696 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-09-19T17:24:54.697Z,1411147494.697 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-09-19T17:24:54.697Z,1411147494.697 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1616
2014-09-19T17:24:54.700Z,1411147494.700 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-09-19T17:24:54.722Z,1411147494.722 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-09-19T17:24:54.723Z,1411147494.723 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-09-19T17:24:54.723Z,1411147494.723 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1617
2014-09-19T17:24:54.724Z,1411147494.724 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-09-19T17:24:54.725Z,1411147494.725 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-09-19T17:24:54.725Z,1411147494.725 [logger ThreadHandler](INFO): Protected caller Thread ID is 1618
2014-09-19T17:24:54.728Z,1411147494.728 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-09-19T17:24:54.728Z,1411147494.728 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-09-19T17:24:54.729Z,1411147494.729 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-09-19T17:24:55.055Z,1411147495.055 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-09-19T17:24:55.055Z,1411147495.055 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-09-19T17:24:55.212Z,1411147495.212 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-09-19T17:24:55.212Z,1411147495.212 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-09-19T17:24:55.323Z,1411147495.323 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-09-19T17:24:55.324Z,1411147495.324 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-09-19T17:24:55.449Z,1411147495.449 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-09-19T17:24:55.450Z,1411147495.450 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-09-19T17:24:55.538Z,1411147495.538 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-09-19T17:24:55.683Z,1411147495.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-09-19T17:24:55.684Z,1411147495.684 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-09-19T17:24:55.772Z,1411147495.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-09-19T17:24:55.772Z,1411147495.772 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-09-19T17:24:55.972Z,1411147495.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-09-19T17:24:55.972Z,1411147495.972 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-09-19T17:24:56.282Z,1411147496.282 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-09-19T17:24:56.282Z,1411147496.282 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-09-19T17:24:56.580Z,1411147496.580 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-09-19T17:24:56.581Z,1411147496.581 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-09-19T17:24:57.071Z,1411147497.071 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-09-19T17:24:57.071Z,1411147497.071 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-09-19T17:24:57.264Z,1411147497.264 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-09-19T17:24:57.265Z,1411147497.265 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-09-19T17:24:57.372Z,1411147497.372 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-09-19T17:24:57.372Z,1411147497.372 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-09-19T17:24:57.780Z,1411147497.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-09-19T17:24:57.781Z,1411147497.781 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-09-19T17:24:57.894Z,1411147497.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-09-19T17:24:57.896Z,1411147497.896 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2014-09-19T17:24:57.896Z,1411147497.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2014-09-19T17:24:58.136Z,1411147498.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2014-09-19T17:24:58.136Z,1411147498.136 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2014-09-19T17:24:58.255Z,1411147498.255 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2014-09-19T17:24:58.354Z,1411147498.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2014-09-19T17:24:58.454Z,1411147498.454 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2014-09-19T17:24:58.553Z,1411147498.553 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2014-09-19T17:24:58.693Z,1411147498.693 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2014-09-19T17:24:58.857Z,1411147498.857 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2014-09-19T17:24:58.961Z,1411147498.961 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2014-09-19T17:24:59.049Z,1411147499.049 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2014-09-19T17:24:59.143Z,1411147499.143 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2014-09-19T17:24:59.242Z,1411147499.242 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2014-09-19T17:24:59.415Z,1411147499.415 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/LOGIN/
2014-09-19T17:24:59.416Z,1411147499.416 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-09-19T17:24:59.417Z,1411147499.417 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-09-19T17:24:59.468Z,1411147499.468 [VerticalControl](DEBUG): Construct VerticalControl.
2014-09-19T17:24:59.585Z,1411147499.585 [VerticalControl] Loaded
2014-09-19T17:24:59.585Z,1411147499.585 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-09-19T17:24:59.586Z,1411147499.586 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-09-19T17:24:59.656Z,1411147499.656 [HorizontalControl] Loaded
2014-09-19T17:24:59.657Z,1411147499.657 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-09-19T17:24:59.657Z,1411147499.657 [SpeedControl](DEBUG): Construct SpeedControl.
2014-09-19T17:24:59.663Z,1411147499.663 [SpeedControl] Loaded
2014-09-19T17:24:59.664Z,1411147499.664 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-09-19T17:24:59.664Z,1411147499.664 [LoopControl](DEBUG): Construct LoopControl.
2014-09-19T17:24:59.665Z,1411147499.665 [LoopControl] Loaded
2014-09-19T17:24:59.665Z,1411147499.665 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-09-19T17:24:59.666Z,1411147499.666 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-09-19T17:24:59.666Z,1411147499.666 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-09-19T17:24:59.760Z,1411147499.760 [SBIT](DEBUG): Construct Startup Built In Test.
2014-09-19T17:24:59.771Z,1411147499.771 [SBIT] Loaded
2014-09-19T17:24:59.771Z,1411147499.771 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-09-19T17:24:59.772Z,1411147499.772 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-09-19T17:24:59.802Z,1411147499.802 [IBIT] Loaded
2014-09-19T17:24:59.802Z,1411147499.802 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-09-19T17:24:59.804Z,1411147499.804 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-09-19T17:24:59.936Z,1411147499.936 [CBIT] Loaded
2014-09-19T17:24:59.937Z,1411147499.937 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-09-19T17:24:59.940Z,1411147499.940 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-09-19T17:24:59.940Z,1411147499.940 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-09-19T17:24:59.959Z,1411147499.959 [DepthRateCalculator] Loaded
2014-09-19T17:24:59.959Z,1411147499.959 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-09-19T17:24:59.965Z,1411147499.965 [PitchRateCalculator] Loaded
2014-09-19T17:24:59.965Z,1411147499.965 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-09-19T17:24:59.976Z,1411147499.976 [SpeedCalculator] Loaded
2014-09-19T17:24:59.977Z,1411147499.977 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-09-19T17:24:59.993Z,1411147499.993 [TempGradientCalculator] Loaded
2014-09-19T17:24:59.993Z,1411147499.993 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-09-19T17:24:59.998Z,1411147499.998 [YawRateCalculator] Loaded
2014-09-19T17:24:59.999Z,1411147499.999 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-09-19T17:24:59.999Z,1411147499.999 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-09-19T17:24:59.000Z,1411147500.000 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-09-19T17:25:12.466Z,1411147512.466 [HFRCMReconstructedInterpolator] Loaded
2014-09-19T17:25:12.466Z,1411147512.466 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2014-09-19T17:25:12.467Z,1411147512.467 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-09-19T17:25:12.467Z,1411147512.467 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-09-19T17:25:12.694Z,1411147512.694 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-09-19T17:25:12.695Z,1411147512.695 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-09-19T17:25:12.775Z,1411147512.775 [DeadReckonUsingMultipleVelocitySourcesVector] Loaded
2014-09-19T17:25:12.775Z,1411147512.775 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySourcesVector" handled in the control thread.
2014-09-19T17:25:12.829Z,1411147512.829 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-09-19T17:25:12.829Z,1411147512.829 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-09-19T17:25:12.874Z,1411147512.874 [DeadReckonWithRespectToWater] Loaded
2014-09-19T17:25:12.874Z,1411147512.874 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-09-19T17:25:12.920Z,1411147512.920 [DeadReckonWithRespectToSeafloor] Loaded
2014-09-19T17:25:12.920Z,1411147512.920 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-09-19T17:25:12.980Z,1411147512.980 [DeadReckonUsingDVLWaterTrack] Loaded
2014-09-19T17:25:12.980Z,1411147512.980 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-09-19T17:25:12.997Z,1411147512.997 [NavChart] Loaded
2014-09-19T17:25:12.997Z,1411147512.997 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-09-19T17:25:13.001Z,1411147513.001 [UniversalFixResidualReporter] Loaded
2014-09-19T17:25:13.001Z,1411147513.001 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-09-19T17:25:13.002Z,1411147513.002 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-09-19T17:25:13.002Z,1411147513.002 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-09-19T17:25:13.008Z,1411147513.008 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-09-19T17:25:13.009Z,1411147513.009 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-09-19T17:25:13.177Z,1411147513.177 [Aanderaa_O2] Loaded
2014-09-19T17:25:13.177Z,1411147513.177 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2014-09-19T17:25:13.225Z,1411147513.225 [CTD_NeilBrown] Loaded
2014-09-19T17:25:13.226Z,1411147513.226 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-09-19T17:25:13.227Z,1411147513.227 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405DB4E0
2014-09-19T17:25:13.227Z,1411147513.227 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1700
2014-09-19T17:25:13.244Z,1411147513.244 [rhodamine] Loaded
2014-09-19T17:25:13.245Z,1411147513.245 [ComponentRegistry](DEBUG): SyncComponent "rhodamine" handled in the control thread.
2014-09-19T17:25:13.280Z,1411147513.280 [WetLabsBB2FL] Loaded
2014-09-19T17:25:13.280Z,1411147513.280 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-09-19T17:25:13.282Z,1411147513.282 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4060B4E0
2014-09-19T17:25:13.282Z,1411147513.282 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1701
2014-09-19T17:25:13.282Z,1411147513.282 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-09-19T17:25:13.283Z,1411147513.283 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-09-19T17:25:13.585Z,1411147513.585 [AHRS_sp3003D] Loaded
2014-09-19T17:25:13.585Z,1411147513.585 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-09-19T17:25:13.661Z,1411147513.661 [DataOverHttps] Loaded
2014-09-19T17:25:13.662Z,1411147513.662 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-09-19T17:25:13.675Z,1411147513.675 [Depth_Keller] Loaded
2014-09-19T17:25:13.675Z,1411147513.675 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-09-19T17:25:13.680Z,1411147513.680 [DropWeight] Loaded
2014-09-19T17:25:13.680Z,1411147513.680 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-09-19T17:25:13.810Z,1411147513.810 [DVL_micro] Loaded
2014-09-19T17:25:13.810Z,1411147513.810 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-09-19T17:25:13.906Z,1411147513.906 [NAL9602] Loaded
2014-09-19T17:25:13.906Z,1411147513.906 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-09-19T17:25:13.947Z,1411147513.947 [Onboard] Loaded
2014-09-19T17:25:13.948Z,1411147513.948 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-09-19T17:25:13.955Z,1411147513.955 [Radio_Surface] Loaded
2014-09-19T17:25:13.955Z,1411147513.955 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2014-09-19T17:25:13.956Z,1411147513.956 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4084B4E0
2014-09-19T17:25:13.956Z,1411147513.956 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1702
2014-09-19T17:25:15.848Z,1411147515.848 [BPC1] Loaded
2014-09-19T17:25:15.848Z,1411147515.848 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2014-09-19T17:25:15.849Z,1411147515.849 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-09-19T17:25:15.850Z,1411147515.850 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-09-19T17:25:15.961Z,1411147515.961 [BuoyancyServo] Loaded
2014-09-19T17:25:15.962Z,1411147515.962 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-09-19T17:25:15.974Z,1411147515.974 [ElevatorServo] Loaded
2014-09-19T17:25:15.974Z,1411147515.974 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-09-19T17:25:15.986Z,1411147515.986 [MassServo] Loaded
2014-09-19T17:25:15.986Z,1411147515.986 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-09-19T17:25:15.998Z,1411147515.998 [RudderServo] Loaded
2014-09-19T17:25:15.998Z,1411147515.998 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-09-19T17:25:16.010Z,1411147516.010 [ThrusterServo] Loaded
2014-09-19T17:25:16.010Z,1411147516.010 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-09-19T17:25:16.010Z,1411147516.010 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-09-19T17:25:16.011Z,1411147516.011 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-09-19T17:25:16.164Z,1411147516.164 [InternalSim] Loaded
2014-09-19T17:25:16.164Z,1411147516.164 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-09-19T17:25:16.165Z,1411147516.165 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-09-19T17:25:16.165Z,1411147516.165 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-09-19T17:25:16.188Z,1411147516.188 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-09-19T17:25:16.191Z,1411147516.191 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-09-19T17:25:16.191Z,1411147516.191 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-09-19T17:25:16.198Z,1411147516.198 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-09-19T17:25:16.199Z,1411147516.199 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408FC4E0
2014-09-19T17:25:16.200Z,1411147516.200 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1703
2014-09-19T17:25:16.205Z,1411147516.205 [Supervisor](INFO): Main Thread ID is 1614
2014-09-19T17:25:16.205Z,1411147516.205 [Supervisor](DEBUG): Running supervisor.
2014-09-19T17:25:16.205Z,1411147516.205 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1704
2014-09-19T17:25:16.208Z,1411147516.208 [controlThread ThreadHandler](INFO): Handler Thread ID is 1705
2014-09-19T17:25:16.208Z,1411147516.208 [controlThread](DEBUG): Initializing ControlThread
2014-09-19T17:25:16.209Z,1411147516.209 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-09-19T17:25:16.211Z,1411147516.211 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-09-19T17:25:16.212Z,1411147516.212 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-09-19T17:25:16.212Z,1411147516.212 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-09-19T17:25:16.213Z,1411147516.213 [SBIT](INFO): Initialize SBIT Component.
2014-09-19T17:25:16.213Z,1411147516.213 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11651
2014-09-19T17:25:16.214Z,1411147516.214 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2014-09-19T17:25:16.214Z,1411147516.214 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-09-19T17:25:16.214Z,1411147516.214 [IBIT](INFO): Initialize IBIT Component.
2014-09-19T17:25:16.215Z,1411147516.215 [CBIT](DEBUG): Initialize CBIT Component.
2014-09-19T17:25:16.216Z,1411147516.216 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-09-19T17:25:16.217Z,1411147516.217 [logger ThreadHandler](INFO): Handler Thread ID is 1706
2014-09-19T17:25:16.242Z,1411147516.242 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-09-19T17:25:16.242Z,1411147516.242 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-09-19T17:25:16.243Z,1411147516.243 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-09-19T17:25:16.243Z,1411147516.243 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-09-19T17:25:16.244Z,1411147516.244 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-09-19T17:25:16.245Z,1411147516.245 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2014-09-19T17:25:16.247Z,1411147516.247 [DeadReckonUsingMultipleVelocitySourcesVector](DEBUG): Initializing DeadReckonUsingMultipleVelocitySourcesVector component.
2014-09-19T17:25:16.247Z,1411147516.247 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-09-19T17:25:16.248Z,1411147516.248 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-09-19T17:25:16.248Z,1411147516.248 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-09-19T17:25:16.248Z,1411147516.248 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-09-19T17:25:16.249Z,1411147516.249 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-09-19T17:25:16.249Z,1411147516.249 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-09-19T17:25:16.258Z,1411147516.258 [InternalSim](DEBUG):  InternalSim initializing...
2014-09-19T17:25:16.266Z,1411147516.266 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1707
2014-09-19T17:25:16.267Z,1411147516.267 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-09-19T17:25:16.274Z,1411147516.274 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-09-19T17:25:16.276Z,1411147516.276 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1709
2014-09-19T17:25:16.277Z,1411147516.277 [WetLabsBB2FL](INFO): Powering down
2014-09-19T17:25:16.318Z,1411147516.318 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1710
2014-09-19T17:25:16.325Z,1411147516.325 [Radio_Surface](INFO): Powering up
2014-09-19T17:25:16.342Z,1411147516.342 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1711
2014-09-19T17:25:16.345Z,1411147516.345 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-09-19T17:25:16.346Z,1411147516.346 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-09-19T17:25:16.347Z,1411147516.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-09-19T17:25:16.347Z,1411147516.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-09-19T17:25:16.347Z,1411147516.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-09-19T17:25:16.347Z,1411147516.347 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-09-19T17:25:16.348Z,1411147516.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-09-19T17:25:16.348Z,1411147516.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-09-19T17:25:16.348Z,1411147516.348 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-09-19T17:25:16.398Z,1411147516.398 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-09-19T17:25:16.432Z,1411147516.432 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-09-19T17:25:16.461Z,1411147516.461 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2014-09-19T17:25:16.470Z,1411147516.470 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-09-19T17:25:16.567Z,1411147516.567 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2014-09-19T17:25:16.578Z,1411147516.578 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2014-09-19T17:25:16.591Z,1411147516.591 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-09-19T17:25:16.600Z,1411147516.600 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2014-09-19T17:25:16.630Z,1411147516.630 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-09-19T17:25:16.662Z,1411147516.662 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-09-19T17:25:16.686Z,1411147516.686 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="TimeMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <DefineArg Name="ElapsedSinceMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <Aggregate Id="StartClock">

        <Sequence/>

        <Assign><Arg Name="TimeMissionWasStarted"/><Universal:time/></Assign>

    </Aggregate>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

<!-- TODO: Do we really want this When operating on platform_communications? or on something else like time_fix? -->

<!-- Run application at high speed -->

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
<!-- NOTE: Original Default.xml didn't have a timeout on the GPS read, so theoretically could have hung indefinitely there... -->
            <Universal:latitude_fix/>
        </ReadDatum>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped drop weight due to communications timeout</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="UpdateAndReportMinutesSinceMissionStarted">

        <When>
            <Elapsed><Arg Name="ElapsedSinceMissionWasStarted"/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
        </When>

        <Assign><Arg Name="ElapsedSinceMissionWasStarted"/><Universal:time/><Sub><Arg Name="TimeMissionWasStarted"/></Sub></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceMissionWasStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

        <Guidance:SetSpeed Id="RunApplicationAtLowSpeed">
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
        </Guidance:SetSpeed>

    </Aggregate>

</Mission>


2014-09-19T17:25:16.693Z,1411147516.693 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,Aanderaa_O2,rhodamine,AHRS_sp3003D,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRCMReconstructedInterpolator,DeadReckonUsingMultipleVelocitySourcesVector,DeadReckonUsingMultipleVelocitySources,DeadReckonWithRespectToWater,DeadReckonWithRespectToSeafloor,DeadReckonUsingDVLWaterTrack,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-09-19T17:25:16.827Z,1411147516.827 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-09-19T17:25:17.031Z,1411147517.031 [DVL_micro](INFO): Initializing
2014-09-19T17:25:17.303Z,1411147517.303 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:17.310Z,1411147517.310 [DeadReckonUsingMultipleVelocitySourcesVector](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:17.335Z,1411147517.335 [DeadReckonUsingMultipleVelocitySources](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:17.358Z,1411147517.358 [DeadReckonWithRespectToWater](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:17.384Z,1411147517.384 [DeadReckonWithRespectToSeafloor](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:17.396Z,1411147517.396 [DeadReckonUsingDVLWaterTrack](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:17.504Z,1411147517.504 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-09-19T17:25:17.512Z,1411147517.512 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-09-19T17:25:17.526Z,1411147517.526 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-09-19T17:25:17.532Z,1411147517.532 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-09-19T17:25:17.554Z,1411147517.554 [MassServo](DEBUG): Initializing EZServoServo.
2014-09-19T17:25:17.560Z,1411147517.560 [MassServo](DEBUG): Initializing MassServo.
2014-09-19T17:25:17.582Z,1411147517.582 [RudderServo](DEBUG): Initializing EZServoServo.
2014-09-19T17:25:17.588Z,1411147517.588 [RudderServo](DEBUG): Initializing RudderServo.
2014-09-19T17:25:17.594Z,1411147517.594 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-09-19T17:25:17.600Z,1411147517.600 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-09-19T17:25:18.095Z,1411147518.095 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:18.096Z,1411147518.096 [DeadReckonUsingMultipleVelocitySourcesVector](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:18.105Z,1411147518.105 [DeadReckonUsingMultipleVelocitySources](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:18.106Z,1411147518.106 [DeadReckonWithRespectToWater](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:18.107Z,1411147518.107 [DeadReckonWithRespectToSeafloor](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:18.108Z,1411147518.108 [DeadReckonUsingDVLWaterTrack](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-19T17:25:18.461Z,1411147518.461 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2014-09-19T17:25:18.461Z,1411147518.461 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2014-09-19T17:25:18.462Z,1411147518.462 [BuoyancyServo] Communications Fault, FailCount= 1
2014-09-19T17:25:18.462Z,1411147518.462 [BuoyancyServo](ERROR): Communications Fault
2014-09-19T17:25:18.671Z,1411147518.671 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2014-09-19T17:25:19.021Z,1411147519.021 [NAL9602](INFO): Powering up NAL9602
2014-09-19T17:25:19.041Z,1411147519.041 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:19.068Z,1411147519.068 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-09-19T17:25:19.068Z,1411147519.068 [BuoyancyServo](INFO): Powering down
2014-09-19T17:25:19.599Z,1411147519.599 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:20.055Z,1411147520.055 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:20.304Z,1411147520.304 [Aanderaa_O2](INFO): Powering down
2014-09-19T17:25:20.743Z,1411147520.743 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:21.185Z,1411147521.185 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:21.337Z,1411147521.337 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2014-09-19T17:25:21.337Z,1411147521.337 [BuoyancyServo] No Fault, FailCount= 1
2014-09-19T17:25:21.737Z,1411147521.737 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:21.773Z,1411147521.773 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-09-19T17:25:21.895Z,1411147521.895 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-09-19T17:25:22.475Z,1411147522.475 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:23.288Z,1411147523.288 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:23.876Z,1411147523.876 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:24.538Z,1411147524.538 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:24.987Z,1411147524.987 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:25.408Z,1411147525.408 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:26.121Z,1411147526.121 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:26.666Z,1411147526.666 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:27.305Z,1411147527.305 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:27.736Z,1411147527.736 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:28.188Z,1411147528.188 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:28.801Z,1411147528.801 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:29.230Z,1411147529.230 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:29.654Z,1411147529.654 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:30.074Z,1411147530.074 [NAL9602](INFO): NAL9602 initialized
2014-09-19T17:25:30.269Z,1411147530.269 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:30.855Z,1411147530.855 [BPC1](ERROR): B bank expecting battery number:0 and read number:1
2014-09-19T17:25:30.855Z,1411147530.855 [BPC1](FAULT): Failed to parse bank B battery data
2014-09-19T17:25:30.855Z,1411147530.855 [BPC1] Data Fault, FailCount= 1
2014-09-19T17:25:30.855Z,1411147530.855 [BPC1](ERROR): Data Fault
2014-09-19T17:25:30.881Z,1411147530.881 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:30.909Z,1411147530.909 [CBIT](ERROR): Data Fault in component: BPC1
2014-09-19T17:25:31.334Z,1411147531.334 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:31.761Z,1411147531.761 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:31.807Z,1411147531.807 [SBIT](IMPORTANT): Beginning Startup BIT
2014-09-19T17:25:31.809Z,1411147531.809 [CBIT](IMPORTANT): Beginning GF scan
2014-09-19T17:25:32.462Z,1411147532.462 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:32.568Z,1411147532.568 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-19T17:25:32.568Z,1411147532.568 [BPC1] No Fault, FailCount= 1
2014-09-19T17:25:33.044Z,1411147533.044 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:33.568Z,1411147533.568 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:34.069Z,1411147534.069 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:34.669Z,1411147534.669 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:35.167Z,1411147535.167 [CommandLine](IMPORTANT): got command failComponent
2014-09-19T17:25:35.168Z,1411147535.168 [CommandLine](IMPORTANT): Failed components:
2014-09-19T17:25:35.168Z,1411147535.168 [CommandLine](IMPORTANT): No failed Components.
2014-09-19T17:25:35.539Z,1411147535.539 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:36.091Z,1411147536.091 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:36.633Z,1411147536.633 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:37.121Z,1411147537.121 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:37.715Z,1411147537.715 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:38.235Z,1411147538.235 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:38.775Z,1411147538.775 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:39.280Z,1411147539.280 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:39.782Z,1411147539.782 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:40.290Z,1411147540.290 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:40.859Z,1411147540.859 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:41.384Z,1411147541.384 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:42.005Z,1411147542.005 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:42.484Z,1411147542.484 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:42.954Z,1411147542.954 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:43.447Z,1411147543.447 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:44.016Z,1411147544.016 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:44.513Z,1411147544.513 [BPC1](ERROR): B bank expecting battery number:0 and read number:1
2014-09-19T17:25:44.513Z,1411147544.513 [BPC1](FAULT): Failed to parse bank B battery data
2014-09-19T17:25:44.513Z,1411147544.513 [BPC1] Data Fault, FailCount= 2
2014-09-19T17:25:44.513Z,1411147544.513 [BPC1](ERROR): Data Fault
2014-09-19T17:25:44.541Z,1411147544.541 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:44.641Z,1411147544.641 [CBIT](ERROR): Data Fault in component: BPC1
2014-09-19T17:25:45.036Z,1411147545.036 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:45.506Z,1411147545.506 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:45.983Z,1411147545.983 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:46.079Z,1411147546.079 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-19T17:25:46.080Z,1411147546.080 [BPC1] No Fault, FailCount= 2
2014-09-19T17:25:46.526Z,1411147546.526 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:47.029Z,1411147547.029 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:47.898Z,1411147547.898 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:48.491Z,1411147548.491 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:48.964Z,1411147548.964 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:49.461Z,1411147549.461 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:49.969Z,1411147549.969 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:50.474Z,1411147550.474 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:51.011Z,1411147551.011 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:51.608Z,1411147551.608 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:52.157Z,1411147552.157 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:52.763Z,1411147552.763 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:53.254Z,1411147553.254 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:53.794Z,1411147553.794 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:54.300Z,1411147554.300 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:54.853Z,1411147554.853 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:55.370Z,1411147555.370 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:55.863Z,1411147555.863 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:56.363Z,1411147556.363 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:56.906Z,1411147556.906 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:57.417Z,1411147557.417 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:57.978Z,1411147557.978 [BPC1](ERROR): B bank expecting battery number:0 and read number:1
2014-09-19T17:25:57.978Z,1411147557.978 [BPC1](FAULT): Failed to parse bank B battery data
2014-09-19T17:25:57.978Z,1411147557.978 [BPC1] Data Fault, FailCount= 3
2014-09-19T17:25:57.978Z,1411147557.978 [BPC1](ERROR): Data Fault
2014-09-19T17:25:58.001Z,1411147558.001 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:58.195Z,1411147558.195 [CBIT](ERROR): Data Fault in component: BPC1
2014-09-19T17:25:58.578Z,1411147558.578 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:59.119Z,1411147559.119 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:59.148Z,1411147559.148 [CBIT](IMPORTANT): No ground fault detected
2014-09-19T17:25:59.540Z,1411147559.540 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:25:59.594Z,1411147559.594 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-19T17:25:59.594Z,1411147559.594 [BPC1] No Fault, FailCount= 3
2014-09-19T17:26:00.073Z,1411147560.073 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:00.534Z,1411147560.534 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:00.975Z,1411147560.975 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:01.435Z,1411147561.435 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:01.872Z,1411147561.872 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:02.281Z,1411147562.281 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:02.737Z,1411147562.737 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:03.031Z,1411147563.031 [CommandLine](IMPORTANT): got command quit
2014-09-19T17:26:03.158Z,1411147563.158 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:03.602Z,1411147563.602 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:04.035Z,1411147564.035 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-19T17:26:04.035Z,1411147564.035 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:04.039Z,1411147564.039 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:04.088Z,1411147564.088 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-09-19T17:26:04.088Z,1411147564.088 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:04.089Z,1411147564.089 [CommandLine](INFO): Join timeout helper Thread ID is 1725
2014-09-19T17:26:04.090Z,1411147564.090 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-09-19T17:26:04.090Z,1411147564.090 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:04.091Z,1411147564.091 [NavChartDb](INFO): Join timeout helper Thread ID is 1726
2014-09-19T17:26:04.459Z,1411147564.459 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:04.861Z,1411147564.861 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:05.318Z,1411147565.318 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:05.758Z,1411147565.758 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:05.965Z,1411147565.965 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-19T17:26:05.966Z,1411147565.966 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:05.983Z,1411147565.983 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2014-09-19T17:26:05.983Z,1411147565.983 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:05.984Z,1411147565.984 [Radio_Surface](INFO): Join timeout helper Thread ID is 1727
2014-09-19T17:26:06.108Z,1411147566.108 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-19T17:26:06.108Z,1411147566.108 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.123Z,1411147566.123 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-09-19T17:26:06.123Z,1411147566.124 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.124Z,1411147566.124 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1728
2014-09-19T17:26:06.144Z,1411147566.144 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-19T17:26:06.144Z,1411147566.144 [WetLabsBB2FL](INFO): Powering down
2014-09-19T17:26:06.145Z,1411147566.145 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.163Z,1411147566.163 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-09-19T17:26:06.163Z,1411147566.163 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.164Z,1411147566.164 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1729
2014-09-19T17:26:06.207Z,1411147566.207 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:06.432Z,1411147566.432 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-19T17:26:06.432Z,1411147566.432 [CTD_NeilBrown](INFO): Powering down
2014-09-19T17:26:06.433Z,1411147566.433 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.449Z,1411147566.449 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-09-19T17:26:06.449Z,1411147566.449 [logger ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.449Z,1411147566.449 [logger](INFO): Join timeout helper Thread ID is 1730
2014-09-19T17:26:06.472Z,1411147566.472 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-19T17:26:06.472Z,1411147566.472 [logger ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.489Z,1411147566.489 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-09-19T17:26:06.489Z,1411147566.489 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.489Z,1411147566.489 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-09-19T17:26:06.489Z,1411147566.489 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.489Z,1411147566.489 [controlThread](INFO): Join timeout helper Thread ID is 1731
2014-09-19T17:26:06.598Z,1411147566.598 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-19T17:26:06.615Z,1411147566.615 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-19T17:26:06.615Z,1411147566.615 [controlThread](DEBUG): Uninitializing ControlThread
2014-09-19T17:26:06.615Z,1411147566.615 [Aanderaa_O2](INFO): Powering down
2014-09-19T17:26:06.617Z,1411147566.617 [AHRS_sp3003D](INFO): Powering down
2014-09-19T17:26:06.777Z,1411147566.777 [DVL_micro](INFO): uninitialize:Powering down
2014-09-19T17:26:06.778Z,1411147566.778 [NAL9602](INFO): Powering down
2014-09-19T17:26:06.779Z,1411147566.779 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-09-19T17:26:06.782Z,1411147566.782 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-09-19T17:26:06.786Z,1411147566.786 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-09-19T17:26:06.786Z,1411147566.786 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-09-19T17:26:06.786Z,1411147566.786 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-09-19T17:26:06.787Z,1411147566.787 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-09-19T17:26:06.787Z,1411147566.787 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-09-19T17:26:06.787Z,1411147566.787 [BuoyancyServo](INFO): Powering down
2014-09-19T17:26:06.800Z,1411147566.800 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-09-19T17:26:06.801Z,1411147566.801 [ElevatorServo](INFO): Powering down
2014-09-19T17:26:06.801Z,1411147566.801 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-09-19T17:26:06.802Z,1411147566.802 [MassServo](INFO): Powering down
2014-09-19T17:26:06.802Z,1411147566.802 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-09-19T17:26:06.802Z,1411147566.802 [RudderServo](INFO): Powering down
2014-09-19T17:26:06.803Z,1411147566.803 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-09-19T17:26:06.803Z,1411147566.803 [ThrusterServo](INFO): Powering down
2014-09-19T17:26:06.804Z,1411147566.804 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-09-19T17:26:06.805Z,1411147566.805 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-09-19T17:26:06.805Z,1411147566.805 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-09-19T17:26:06.837Z,1411147566.837 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.894Z,1411147566.894 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.898Z,1411147566.898 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:06.957Z,1411147566.957 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:07.004Z,1411147567.004 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-09-19T17:26:07.052Z,1411147567.052 [logger ThreadHandler](INFO): Thread cancelled.