2014-09-24T22:38:08.292Z,1411598288.292 [Supervisor](DEBUG): Initializing supervisor.
2014-09-24T22:38:08.295Z,1411598288.295 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-09-24T22:38:08.296Z,1411598288.296 [SyncHandler](INFO): Protected caller Thread ID is 1687
2014-09-24T22:38:08.296Z,1411598288.296 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-09-24T22:38:08.297Z,1411598288.297 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-09-24T22:38:08.298Z,1411598288.298 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1688
2014-09-24T22:38:08.315Z,1411598288.315 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-09-24T22:38:08.326Z,1411598288.326 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-09-24T22:38:08.327Z,1411598288.327 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-09-24T22:38:08.327Z,1411598288.327 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1689
2014-09-24T22:38:08.328Z,1411598288.328 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-09-24T22:38:08.329Z,1411598288.329 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-09-24T22:38:08.330Z,1411598288.330 [logger ThreadHandler](INFO): Protected caller Thread ID is 1690
2014-09-24T22:38:08.332Z,1411598288.332 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-09-24T22:38:08.332Z,1411598288.332 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-09-24T22:38:08.339Z,1411598288.339 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-09-24T22:38:08.849Z,1411598288.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-09-24T22:38:08.852Z,1411598288.852 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-09-24T22:38:09.013Z,1411598289.013 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-09-24T22:38:09.014Z,1411598289.014 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-09-24T22:38:09.126Z,1411598289.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-09-24T22:38:09.127Z,1411598289.127 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-09-24T22:38:09.254Z,1411598289.254 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-09-24T22:38:09.257Z,1411598289.257 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-09-24T22:38:09.347Z,1411598289.347 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-09-24T22:38:09.495Z,1411598289.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-09-24T22:38:09.496Z,1411598289.496 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-09-24T22:38:09.585Z,1411598289.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-09-24T22:38:09.586Z,1411598289.586 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-09-24T22:38:09.790Z,1411598289.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-09-24T22:38:09.791Z,1411598289.791 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-09-24T22:38:10.133Z,1411598290.133 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-09-24T22:38:10.135Z,1411598290.135 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-09-24T22:38:10.443Z,1411598290.443 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-09-24T22:38:10.445Z,1411598290.445 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-09-24T22:38:10.952Z,1411598290.952 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-09-24T22:38:10.953Z,1411598290.953 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-09-24T22:38:11.159Z,1411598291.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-09-24T22:38:11.160Z,1411598291.160 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-09-24T22:38:11.267Z,1411598291.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-09-24T22:38:11.268Z,1411598291.268 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-09-24T22:38:11.688Z,1411598291.688 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-09-24T22:38:11.691Z,1411598291.691 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-09-24T22:38:11.807Z,1411598291.807 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-09-24T22:38:11.809Z,1411598291.809 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2014-09-24T22:38:11.814Z,1411598291.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2014-09-24T22:38:12.060Z,1411598292.060 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2014-09-24T22:38:12.061Z,1411598292.061 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2014-09-24T22:38:12.183Z,1411598292.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2014-09-24T22:38:15.498Z,1411598295.498 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2014-09-24T22:38:29.624Z,1411598309.624 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2014-09-24T22:38:29.738Z,1411598309.738 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2014-09-24T22:38:36.967Z,1411598316.967 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2014-09-24T22:38:47.704Z,1411598327.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2014-09-24T22:38:52.018Z,1411598332.018 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2014-09-24T22:38:53.787Z,1411598333.787 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2014-09-24T22:38:53.892Z,1411598333.892 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2014-09-24T22:38:53.992Z,1411598333.992 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2014-09-24T22:38:54.172Z,1411598334.172 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/LOGIN/
2014-09-24T22:38:54.172Z,1411598334.172 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-09-24T22:38:54.178Z,1411598334.178 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-09-24T22:38:54.251Z,1411598334.251 [VerticalControl](DEBUG): Construct VerticalControl.
2014-09-24T22:38:54.369Z,1411598334.369 [VerticalControl] Loaded
2014-09-24T22:38:54.370Z,1411598334.370 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-09-24T22:38:54.370Z,1411598334.370 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-09-24T22:38:54.441Z,1411598334.441 [HorizontalControl] Loaded
2014-09-24T22:38:54.441Z,1411598334.441 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-09-24T22:38:54.442Z,1411598334.442 [SpeedControl](DEBUG): Construct SpeedControl.
2014-09-24T22:38:54.448Z,1411598334.448 [SpeedControl] Loaded
2014-09-24T22:38:54.448Z,1411598334.448 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-09-24T22:38:54.449Z,1411598334.449 [LoopControl](DEBUG): Construct LoopControl.
2014-09-24T22:38:54.449Z,1411598334.449 [LoopControl] Loaded
2014-09-24T22:38:54.450Z,1411598334.450 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-09-24T22:38:54.450Z,1411598334.450 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-09-24T22:38:54.451Z,1411598334.451 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-09-24T22:38:54.572Z,1411598334.572 [SBIT](DEBUG): Construct Startup Built In Test.
2014-09-24T22:38:54.583Z,1411598334.583 [SBIT] Loaded
2014-09-24T22:38:54.584Z,1411598334.584 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-09-24T22:38:54.584Z,1411598334.584 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-09-24T22:38:54.613Z,1411598334.613 [IBIT] Loaded
2014-09-24T22:38:54.614Z,1411598334.614 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-09-24T22:38:54.616Z,1411598334.616 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-09-24T22:38:54.736Z,1411598334.736 [CBIT] Loaded
2014-09-24T22:38:54.736Z,1411598334.736 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-09-24T22:38:54.737Z,1411598334.737 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-09-24T22:38:54.737Z,1411598334.737 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-09-24T22:38:54.767Z,1411598334.767 [DepthRateCalculator] Loaded
2014-09-24T22:38:54.768Z,1411598334.768 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-09-24T22:38:54.773Z,1411598334.773 [PitchRateCalculator] Loaded
2014-09-24T22:38:54.773Z,1411598334.773 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-09-24T22:38:54.784Z,1411598334.784 [SpeedCalculator] Loaded
2014-09-24T22:38:54.785Z,1411598334.785 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-09-24T22:38:54.801Z,1411598334.801 [TempGradientCalculator] Loaded
2014-09-24T22:38:54.801Z,1411598334.801 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-09-24T22:38:54.806Z,1411598334.806 [YawRateCalculator] Loaded
2014-09-24T22:38:54.807Z,1411598334.807 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-09-24T22:38:54.807Z,1411598334.807 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-09-24T22:38:54.810Z,1411598334.810 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-09-24T22:38:56.123Z,1411598336.123 [HFRCMReconstructedInterpolator] Loaded
2014-09-24T22:38:56.124Z,1411598336.124 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2014-09-24T22:38:56.124Z,1411598336.124 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-09-24T22:38:56.125Z,1411598336.125 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-09-24T22:38:56.401Z,1411598336.401 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-09-24T22:38:56.402Z,1411598336.402 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-09-24T22:38:56.494Z,1411598336.494 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-09-24T22:38:56.494Z,1411598336.494 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-09-24T22:38:56.539Z,1411598336.539 [DeadReckonWithRespectToWater] Loaded
2014-09-24T22:38:56.539Z,1411598336.539 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-09-24T22:38:56.584Z,1411598336.584 [DeadReckonWithRespectToSeafloor] Loaded
2014-09-24T22:38:56.584Z,1411598336.584 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-09-24T22:38:56.633Z,1411598336.633 [DeadReckonUsingDVLWaterTrack] Loaded
2014-09-24T22:38:56.633Z,1411598336.633 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-09-24T22:38:56.651Z,1411598336.651 [NavChart] Loaded
2014-09-24T22:38:56.651Z,1411598336.651 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-09-24T22:38:56.655Z,1411598336.655 [UniversalFixResidualReporter] Loaded
2014-09-24T22:38:56.656Z,1411598336.656 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-09-24T22:38:56.656Z,1411598336.656 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-09-24T22:38:56.657Z,1411598336.657 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-09-24T22:38:56.666Z,1411598336.666 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-09-24T22:38:56.667Z,1411598336.667 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-09-24T22:38:56.862Z,1411598336.862 [Aanderaa_O2] Loaded
2014-09-24T22:38:56.862Z,1411598336.862 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2014-09-24T22:38:56.898Z,1411598336.898 [CTD_NeilBrown] Loaded
2014-09-24T22:38:56.899Z,1411598336.899 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-09-24T22:38:56.900Z,1411598336.900 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405D94E0
2014-09-24T22:38:56.900Z,1411598336.900 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1772
2014-09-24T22:38:56.918Z,1411598336.918 [rhodamine] Loaded
2014-09-24T22:38:56.918Z,1411598336.918 [ComponentRegistry](DEBUG): SyncComponent "rhodamine" handled in the control thread.
2014-09-24T22:38:56.953Z,1411598336.953 [WetLabsBB2FL] Loaded
2014-09-24T22:38:56.954Z,1411598336.954 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-09-24T22:38:56.955Z,1411598336.955 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406094E0
2014-09-24T22:38:56.955Z,1411598336.955 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1773
2014-09-24T22:38:56.956Z,1411598336.956 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-09-24T22:38:56.956Z,1411598336.956 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-09-24T22:38:57.686Z,1411598337.686 [AHRS_sp3003D] Loaded
2014-09-24T22:38:57.687Z,1411598337.687 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-09-24T22:38:57.731Z,1411598337.731 [AcousticModem_Benthos_ATM900] Loaded
2014-09-24T22:38:57.732Z,1411598337.732 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2014-09-24T22:38:58.099Z,1411598338.099 [DataOverHttps] Loaded
2014-09-24T22:38:58.100Z,1411598338.100 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-09-24T22:38:58.113Z,1411598338.113 [Depth_Keller] Loaded
2014-09-24T22:38:58.113Z,1411598338.113 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-09-24T22:38:58.118Z,1411598338.118 [DropWeight] Loaded
2014-09-24T22:38:58.119Z,1411598338.119 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-09-24T22:38:58.270Z,1411598338.270 [DVL_micro] Loaded
2014-09-24T22:38:58.270Z,1411598338.270 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-09-24T22:38:58.366Z,1411598338.366 [NAL9602] Loaded
2014-09-24T22:38:58.367Z,1411598338.367 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-09-24T22:38:58.408Z,1411598338.408 [Onboard] Loaded
2014-09-24T22:38:58.408Z,1411598338.408 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-09-24T22:38:58.415Z,1411598338.415 [Radio_Surface] Loaded
2014-09-24T22:38:58.416Z,1411598338.416 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2014-09-24T22:38:58.417Z,1411598338.417 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408534E0
2014-09-24T22:38:58.417Z,1411598338.417 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1774
2014-09-24T22:39:00.324Z,1411598340.324 [BPC1] Loaded
2014-09-24T22:39:00.324Z,1411598340.324 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2014-09-24T22:39:00.324Z,1411598340.324 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-09-24T22:39:00.325Z,1411598340.325 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-09-24T22:39:02.723Z,1411598342.723 [BuoyancyServo] Loaded
2014-09-24T22:39:02.724Z,1411598342.724 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-09-24T22:39:02.736Z,1411598342.736 [ElevatorServo] Loaded
2014-09-24T22:39:02.736Z,1411598342.736 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-09-24T22:39:02.748Z,1411598342.748 [MassServo] Loaded
2014-09-24T22:39:02.748Z,1411598342.748 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-09-24T22:39:02.760Z,1411598342.760 [RudderServo] Loaded
2014-09-24T22:39:02.760Z,1411598342.760 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-09-24T22:39:02.771Z,1411598342.771 [ThrusterServo] Loaded
2014-09-24T22:39:02.772Z,1411598342.772 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-09-24T22:39:02.772Z,1411598342.772 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-09-24T22:39:02.773Z,1411598342.773 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-09-24T22:39:02.963Z,1411598342.963 [InternalSim] Loaded
2014-09-24T22:39:02.963Z,1411598342.963 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-09-24T22:39:02.964Z,1411598342.964 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-09-24T22:39:02.964Z,1411598342.964 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-09-24T22:39:03.006Z,1411598343.006 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-09-24T22:39:03.008Z,1411598343.008 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-09-24T22:39:03.009Z,1411598343.009 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-09-24T22:39:03.015Z,1411598343.015 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-09-24T22:39:03.016Z,1411598343.016 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409044E0
2014-09-24T22:39:03.017Z,1411598343.017 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1775
2014-09-24T22:39:03.021Z,1411598343.021 [Supervisor](INFO): Main Thread ID is 1686
2014-09-24T22:39:03.022Z,1411598343.022 [Supervisor](DEBUG): Running supervisor.
2014-09-24T22:39:03.022Z,1411598343.022 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1776
2014-09-24T22:39:03.025Z,1411598343.025 [controlThread ThreadHandler](INFO): Handler Thread ID is 1777
2014-09-24T22:39:03.025Z,1411598343.025 [controlThread](DEBUG): Initializing ControlThread
2014-09-24T22:39:03.026Z,1411598343.026 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-09-24T22:39:03.028Z,1411598343.028 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-09-24T22:39:03.028Z,1411598343.028 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-09-24T22:39:03.029Z,1411598343.029 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-09-24T22:39:03.029Z,1411598343.029 [SBIT](INFO): Initialize SBIT Component.
2014-09-24T22:39:03.030Z,1411598343.030 [SBIT](IMPORTANT): Tethys CM Info: SVN revision: 11709
2014-09-24T22:39:03.030Z,1411598343.030 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2014-09-24T22:39:03.030Z,1411598343.030 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-09-24T22:39:03.031Z,1411598343.031 [IBIT](INFO): Initialize IBIT Component.
2014-09-24T22:39:03.032Z,1411598343.032 [CBIT](DEBUG): Initialize CBIT Component.
2014-09-24T22:39:03.032Z,1411598343.032 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-09-24T22:39:03.033Z,1411598343.033 [logger ThreadHandler](INFO): Handler Thread ID is 1778
2014-09-24T22:39:03.053Z,1411598343.053 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1779
2014-09-24T22:39:03.054Z,1411598343.054 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-09-24T22:39:03.057Z,1411598343.057 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-09-24T22:39:03.057Z,1411598343.057 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-09-24T22:39:03.057Z,1411598343.057 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-09-24T22:39:03.058Z,1411598343.058 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-09-24T22:39:03.058Z,1411598343.058 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-09-24T22:39:03.059Z,1411598343.059 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2014-09-24T22:39:03.061Z,1411598343.061 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-09-24T22:39:03.061Z,1411598343.061 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-09-24T22:39:03.062Z,1411598343.062 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-09-24T22:39:03.062Z,1411598343.062 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-09-24T22:39:03.062Z,1411598343.062 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-09-24T22:39:03.063Z,1411598343.063 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-09-24T22:39:03.068Z,1411598343.068 [InternalSim](DEBUG):  InternalSim initializing...
2014-09-24T22:39:03.077Z,1411598343.077 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-09-24T22:39:03.078Z,1411598343.078 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1781
2014-09-24T22:39:03.079Z,1411598343.079 [WetLabsBB2FL](INFO): Powering down
2014-09-24T22:39:03.117Z,1411598343.117 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1782
2014-09-24T22:39:03.123Z,1411598343.123 [Radio_Surface](INFO): Powering up
2014-09-24T22:39:03.137Z,1411598343.137 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1783
2014-09-24T22:39:03.144Z,1411598343.144 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-09-24T22:39:03.145Z,1411598343.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-09-24T22:39:03.146Z,1411598343.146 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-09-24T22:39:03.146Z,1411598343.146 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-09-24T22:39:03.146Z,1411598343.146 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-09-24T22:39:03.146Z,1411598343.146 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-09-24T22:39:03.147Z,1411598343.147 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-09-24T22:39:03.147Z,1411598343.147 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-09-24T22:39:03.147Z,1411598343.147 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-09-24T22:39:03.325Z,1411598343.325 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-09-24T22:39:03.393Z,1411598343.393 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-09-24T22:39:03.418Z,1411598343.418 [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-24T22:39:03.419Z,1411598343.419 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-09-24T22:39:03.541Z,1411598343.541 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2014-09-24T22:39:03.545Z,1411598343.545 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2014-09-24T22:39:03.549Z,1411598343.549 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-09-24T22:39:03.584Z,1411598343.584 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2014-09-24T22:39:03.615Z,1411598343.615 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-09-24T22:39:03.639Z,1411598343.639 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-09-24T22:39:03.645Z,1411598343.645 [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-24T22:39:03.667Z,1411598343.667 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,Aanderaa_O2,rhodamine,AHRS_sp3003D,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRCMReconstructedInterpolator,DeadReckonUsingMultipleVelocitySources,DeadReckonWithRespectToWater,DeadReckonWithRespectToSeafloor,DeadReckonUsingDVLWaterTrack,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-09-24T22:39:03.820Z,1411598343.820 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-09-24T22:39:03.840Z,1411598343.840 [AcousticModem_Benthos_ATM900](INFO): Powering up
2014-09-24T22:39:03.840Z,1411598343.840 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2014-09-24T22:39:04.022Z,1411598344.022 [DVL_micro](INFO): Initializing
2014-09-24T22:39:04.061Z,1411598344.061 [NAL9602](INFO): Powering up NAL9602
2014-09-24T22:39:04.278Z,1411598344.278 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:04.290Z,1411598344.290 [DeadReckonUsingMultipleVelocitySources](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:04.298Z,1411598344.298 [DeadReckonWithRespectToWater](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:04.315Z,1411598344.315 [DeadReckonWithRespectToSeafloor](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:04.323Z,1411598344.323 [DeadReckonUsingDVLWaterTrack](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:04.435Z,1411598344.435 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-09-24T22:39:04.443Z,1411598344.443 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-09-24T22:39:04.457Z,1411598344.457 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-09-24T22:39:04.463Z,1411598344.463 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-09-24T22:39:04.470Z,1411598344.470 [MassServo](DEBUG): Initializing EZServoServo.
2014-09-24T22:39:04.483Z,1411598344.483 [MassServo](DEBUG): Initializing MassServo.
2014-09-24T22:39:04.493Z,1411598344.493 [RudderServo](DEBUG): Initializing EZServoServo.
2014-09-24T22:39:04.499Z,1411598344.499 [RudderServo](DEBUG): Initializing RudderServo.
2014-09-24T22:39:04.521Z,1411598344.521 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-09-24T22:39:04.527Z,1411598344.527 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-09-24T22:39:04.788Z,1411598344.788 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:04.789Z,1411598344.789 [DeadReckonUsingMultipleVelocitySources](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:04.790Z,1411598344.790 [DeadReckonWithRespectToWater](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:04.791Z,1411598344.791 [DeadReckonWithRespectToSeafloor](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:04.800Z,1411598344.800 [DeadReckonUsingDVLWaterTrack](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:05.160Z,1411598345.160 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:05.160Z,1411598345.160 [DeadReckonUsingMultipleVelocitySources](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:05.161Z,1411598345.161 [DeadReckonWithRespectToWater](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:05.162Z,1411598345.162 [DeadReckonWithRespectToSeafloor](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:05.163Z,1411598345.163 [DeadReckonUsingDVLWaterTrack](DEBUG): Could not determine rotation from vehicle frame to navigation frame.
2014-09-24T22:39:05.856Z,1411598345.856 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:06.261Z,1411598346.261 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:06.924Z,1411598346.924 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:07.407Z,1411598347.407 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:07.692Z,1411598347.692 [Aanderaa_O2](INFO): Powering down
2014-09-24T22:39:08.128Z,1411598348.128 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:08.592Z,1411598348.592 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:09.480Z,1411598349.480 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:10.448Z,1411598350.448 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:10.976Z,1411598350.976 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:11.445Z,1411598351.445 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:11.885Z,1411598351.885 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:12.277Z,1411598352.277 [AcousticModem_Benthos_ATM900](DEBUG): 
2014-09-24T22:39:12.488Z,1411598352.488 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:12.951Z,1411598352.951 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:13.388Z,1411598353.388 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:13.816Z,1411598353.816 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series
2014-09-24T22:39:13.817Z,1411598353.817 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2014-09-24T22:39:13.818Z,1411598353.818 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.8.9
2014-09-24T22:39:14.080Z,1411598354.080 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:14.465Z,1411598354.465 [AcousticModem_Benthos_ATM900](DEBUG): Sep 24 2014 22:38:57 
2014-09-24T22:39:14.532Z,1411598354.532 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:14.999Z,1411598354.999 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:15.434Z,1411598355.434 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2014-09-24T22:39:15.443Z,1411598355.443 [NAL9602](INFO): NAL9602 initialized
2014-09-24T22:39:15.477Z,1411598355.477 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:15.875Z,1411598355.875 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2014-09-24T22:39:15.876Z,1411598355.876 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2014-09-24T22:39:15.876Z,1411598355.876 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2014-09-24T22:39:15.940Z,1411598355.940 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:16.347Z,1411598356.347 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2014-09-24T22:39:16.465Z,1411598356.465 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:16.868Z,1411598356.868 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2014-09-24T22:39:16.869Z,1411598356.869 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2014-09-24T22:39:16.939Z,1411598356.939 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:17.346Z,1411598357.346 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2014-09-24T22:39:17.557Z,1411598357.557 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:18.027Z,1411598358.027 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:18.496Z,1411598358.496 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:18.558Z,1411598358.558 [SBIT](IMPORTANT): Beginning Startup BIT
2014-09-24T22:39:18.561Z,1411598358.561 [CBIT](IMPORTANT): Beginning GF scan
2014-09-24T22:39:19.177Z,1411598359.177 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:19.714Z,1411598359.714 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:20.245Z,1411598360.245 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:20.743Z,1411598360.743 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:21.326Z,1411598361.326 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:21.813Z,1411598361.813 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:22.317Z,1411598362.317 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:22.675Z,1411598362.675 [CommandLine](IMPORTANT): got command burn 2.000000
2014-09-24T22:39:22.859Z,1411598362.859 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:23.447Z,1411598363.447 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:23.904Z,1411598363.904 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:24.488Z,1411598364.488 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:24.690Z,1411598364.690 [CommandLine](IMPORTANT): Deactivating dropweight wire
2014-09-24T22:39:24.971Z,1411598364.971 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:25.458Z,1411598365.458 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:25.987Z,1411598365.987 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:26.486Z,1411598366.486 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:26.961Z,1411598366.961 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:27.439Z,1411598367.439 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:27.959Z,1411598367.959 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:28.507Z,1411598368.507 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:29.008Z,1411598369.008 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:29.513Z,1411598369.513 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:30.045Z,1411598370.045 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:30.548Z,1411598370.548 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:31.014Z,1411598371.014 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:31.563Z,1411598371.563 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:31.692Z,1411598371.692 [SBIT](FAULT): Mass: EXPECTED:0.006000 ACTUAL:0.002473
2014-09-24T22:39:32.069Z,1411598372.069 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:32.618Z,1411598372.618 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:33.170Z,1411598373.170 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:33.638Z,1411598373.638 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:34.100Z,1411598374.100 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:34.671Z,1411598374.671 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:35.205Z,1411598375.205 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:35.702Z,1411598375.702 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:36.199Z,1411598376.199 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:36.659Z,1411598376.659 [BPC1](FAULT): Failed to receive battery data
2014-09-24T22:39:36.659Z,1411598376.659 [BPC1] Communications Fault, FailCount= 1
2014-09-24T22:39:36.660Z,1411598376.660 [BPC1](ERROR): Communications Fault
2014-09-24T22:39:36.673Z,1411598376.673 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:36.808Z,1411598376.808 [CBIT](ERROR): Communications Fault in component: BPC1
2014-09-24T22:39:37.169Z,1411598377.169 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:37.657Z,1411598377.657 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:38.275Z,1411598378.275 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:38.443Z,1411598378.443 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-24T22:39:38.443Z,1411598378.443 [BPC1] No Fault, FailCount= 1
2014-09-24T22:39:38.900Z,1411598378.900 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:39.497Z,1411598379.497 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:40.013Z,1411598380.013 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:40.518Z,1411598380.518 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:41.019Z,1411598381.019 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:41.664Z,1411598381.664 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:42.128Z,1411598382.128 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:42.609Z,1411598382.609 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:43.086Z,1411598383.086 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:43.530Z,1411598383.530 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:44.015Z,1411598384.015 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:44.504Z,1411598384.504 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:45.009Z,1411598385.009 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:45.570Z,1411598385.570 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:45.647Z,1411598385.647 [CBIT](IMPORTANT): No ground fault detected
2014-09-24T22:39:46.035Z,1411598386.035 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:46.511Z,1411598386.511 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:46.978Z,1411598386.978 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:47.457Z,1411598387.457 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:47.933Z,1411598387.933 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:48.497Z,1411598388.497 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:48.963Z,1411598388.963 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:49.416Z,1411598389.416 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:49.868Z,1411598389.868 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:50.333Z,1411598390.333 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:50.814Z,1411598390.814 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:51.304Z,1411598391.304 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:51.811Z,1411598391.811 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:52.276Z,1411598392.276 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:52.789Z,1411598392.789 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:53.266Z,1411598393.266 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:53.719Z,1411598393.719 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:54.187Z,1411598394.187 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:54.663Z,1411598394.663 [BPC1](FAULT): Failed to receive battery data
2014-09-24T22:39:54.664Z,1411598394.664 [BPC1] Communications Fault, FailCount= 2
2014-09-24T22:39:54.664Z,1411598394.664 [BPC1](ERROR): Communications Fault
2014-09-24T22:39:54.674Z,1411598394.674 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:54.761Z,1411598394.761 [CBIT](ERROR): Communications Fault in component: BPC1
2014-09-24T22:39:55.193Z,1411598395.193 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:55.697Z,1411598395.697 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:56.172Z,1411598396.172 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:56.259Z,1411598396.259 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-24T22:39:56.259Z,1411598396.259 [BPC1] No Fault, FailCount= 2
2014-09-24T22:39:56.703Z,1411598396.703 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:57.213Z,1411598397.213 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:57.677Z,1411598397.677 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:58.141Z,1411598398.141 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:58.696Z,1411598398.696 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:59.171Z,1411598399.171 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:39:59.628Z,1411598399.628 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:00.151Z,1411598400.151 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:00.629Z,1411598400.629 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:01.533Z,1411598401.533 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:02.047Z,1411598402.047 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:02.577Z,1411598402.577 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:03.145Z,1411598403.145 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:03.603Z,1411598403.603 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:04.076Z,1411598404.076 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:04.555Z,1411598404.555 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:05.147Z,1411598405.147 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:05.633Z,1411598405.633 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:06.033Z,1411598406.033 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:06.428Z,1411598406.428 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:06.847Z,1411598406.847 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:07.251Z,1411598407.251 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:07.650Z,1411598407.650 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:08.038Z,1411598408.038 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:08.452Z,1411598408.452 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:08.855Z,1411598408.855 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:09.240Z,1411598409.240 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:09.659Z,1411598409.659 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:10.074Z,1411598410.074 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:10.456Z,1411598410.456 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:10.869Z,1411598410.869 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:11.273Z,1411598411.273 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:11.686Z,1411598411.686 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:12.095Z,1411598412.095 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:12.494Z,1411598412.494 [BPC1](FAULT): Failed to receive battery data
2014-09-24T22:40:12.494Z,1411598412.494 [BPC1] Communications Fault, FailCount= 3
2014-09-24T22:40:12.494Z,1411598412.494 [BPC1](ERROR): Communications Fault
2014-09-24T22:40:12.500Z,1411598412.500 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:12.538Z,1411598412.538 [SBIT](CRITICAL): SBIT FAILED
2014-09-24T22:40:12.539Z,1411598412.539 [CommandLine](FAULT): Scheduling is paused
2014-09-24T22:40:12.540Z,1411598412.540 [CBIT](ERROR): Communications Fault in component: BPC1
2014-09-24T22:40:12.923Z,1411598412.923 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:12.928Z,1411598412.928 [MissionManager](IMPORTANT): Started mission Startup
2014-09-24T22:40:12.928Z,1411598412.928 [Startup] Running Loop=1
2014-09-24T22:40:12.928Z,1411598412.928 [Startup](INFO): Aggregate::initialize Startup
2014-09-24T22:40:12.928Z,1411598412.928 [Startup:A.GoToSurface] Running Loop=1
2014-09-24T22:40:12.928Z,1411598412.928 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-09-24T22:40:12.929Z,1411598412.929 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-09-24T22:40:12.930Z,1411598412.930 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-09-24T22:40:12.930Z,1411598412.930 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-09-24T22:40:12.936Z,1411598412.936 [Startup:StartupSatComms] Running Loop=1
2014-09-24T22:40:12.936Z,1411598412.936 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-09-24T22:40:12.937Z,1411598412.937 [Startup:StartupSatComms:A] Running Loop=1
2014-09-24T22:40:13.298Z,1411598413.298 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:13.304Z,1411598413.304 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-09-24T22:40:13.699Z,1411598413.699 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:13.743Z,1411598413.743 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-24T22:40:13.743Z,1411598413.743 [BPC1] No Fault, FailCount= 3
2014-09-24T22:40:14.171Z,1411598414.171 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:14.598Z,1411598414.598 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:15.446Z,1411598415.446 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:15.877Z,1411598415.877 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:16.296Z,1411598416.296 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:16.725Z,1411598416.725 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:17.134Z,1411598417.134 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:17.573Z,1411598417.573 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:17.995Z,1411598417.995 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:18.453Z,1411598418.453 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:18.905Z,1411598418.905 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:19.329Z,1411598419.329 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:19.736Z,1411598419.736 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:20.142Z,1411598420.142 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:20.579Z,1411598420.579 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:21.005Z,1411598421.005 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:21.503Z,1411598421.503 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:21.933Z,1411598421.933 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:22.336Z,1411598422.336 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:22.737Z,1411598422.737 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:23.143Z,1411598423.143 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:23.542Z,1411598423.542 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:23.966Z,1411598423.966 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:24.405Z,1411598424.405 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:24.855Z,1411598424.855 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:25.291Z,1411598425.291 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:25.706Z,1411598425.706 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:26.124Z,1411598426.124 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:26.544Z,1411598426.544 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:26.968Z,1411598426.968 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:27.415Z,1411598427.415 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:27.876Z,1411598427.876 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:28.301Z,1411598428.301 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:28.740Z,1411598428.740 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:29.178Z,1411598429.178 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:29.607Z,1411598429.607 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:30.047Z,1411598430.047 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:30.471Z,1411598430.471 [BPC1](FAULT): Failed to receive battery data
2014-09-24T22:40:30.471Z,1411598430.471 [BPC1] Communications Fault, FailCount= 4
2014-09-24T22:40:30.471Z,1411598430.471 [BPC1](ERROR): Communications Fault
2014-09-24T22:40:30.498Z,1411598430.498 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:30.552Z,1411598430.552 [CBIT](ERROR): Communications Fault in component: BPC1
2014-09-24T22:40:30.972Z,1411598430.972 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:31.401Z,1411598431.401 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:31.820Z,1411598431.820 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:31.894Z,1411598431.894 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-24T22:40:31.894Z,1411598431.894 [BPC1] No Fault, FailCount= 4
2014-09-24T22:40:32.307Z,1411598432.307 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:32.764Z,1411598432.764 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:33.193Z,1411598433.193 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:33.619Z,1411598433.619 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:34.065Z,1411598434.065 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:34.473Z,1411598434.473 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:34.879Z,1411598434.879 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:35.307Z,1411598435.307 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:35.712Z,1411598435.712 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:36.208Z,1411598436.208 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:36.625Z,1411598436.625 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:37.057Z,1411598437.057 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:37.434Z,1411598437.434 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:37.863Z,1411598437.863 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:38.259Z,1411598438.259 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:38.671Z,1411598438.671 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:39.085Z,1411598439.085 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:39.478Z,1411598439.478 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:39.866Z,1411598439.866 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:40.284Z,1411598440.284 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:40.680Z,1411598440.680 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:41.072Z,1411598441.072 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:41.472Z,1411598441.472 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:41.885Z,1411598441.885 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:42.286Z,1411598442.286 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:42.710Z,1411598442.710 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:43.086Z,1411598443.086 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:43.491Z,1411598443.491 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:43.899Z,1411598443.899 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:44.279Z,1411598444.279 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:44.720Z,1411598444.720 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:45.094Z,1411598445.094 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:45.503Z,1411598445.503 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:45.886Z,1411598445.886 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:46.326Z,1411598446.326 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:46.740Z,1411598446.740 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:47.135Z,1411598447.135 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:47.533Z,1411598447.533 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:47.943Z,1411598447.943 [BPC1](FAULT): Failed to receive battery data
2014-09-24T22:40:47.943Z,1411598447.943 [BPC1] Communications Fault, FailCount= 5
2014-09-24T22:40:47.943Z,1411598447.943 [BPC1](ERROR): Communications Fault
2014-09-24T22:40:47.949Z,1411598447.949 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:47.963Z,1411598447.963 [CBIT](ERROR): Communications Fault in component: BPC1
2014-09-24T22:40:48.358Z,1411598448.358 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:48.764Z,1411598448.764 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:49.150Z,1411598449.150 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:49.165Z,1411598449.165 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-24T22:40:49.165Z,1411598449.165 [BPC1] No Fault, FailCount= 5
2014-09-24T22:40:49.606Z,1411598449.606 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:50.050Z,1411598450.050 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:50.443Z,1411598450.443 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:50.854Z,1411598450.854 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:51.260Z,1411598451.260 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:51.669Z,1411598451.669 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:52.042Z,1411598452.042 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:52.447Z,1411598452.447 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:52.847Z,1411598452.847 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:53.266Z,1411598453.266 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:53.689Z,1411598453.689 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:54.108Z,1411598454.108 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:54.511Z,1411598454.511 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:54.917Z,1411598454.917 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:55.303Z,1411598455.303 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:55.696Z,1411598455.696 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:56.099Z,1411598456.099 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:56.515Z,1411598456.515 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:56.941Z,1411598456.941 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:57.341Z,1411598457.341 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:57.718Z,1411598457.718 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:58.108Z,1411598458.108 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:58.505Z,1411598458.505 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:58.905Z,1411598458.905 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:59.307Z,1411598459.307 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:40:59.720Z,1411598459.720 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:00.144Z,1411598460.144 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:00.548Z,1411598460.548 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:00.923Z,1411598460.923 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:01.307Z,1411598461.307 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:01.711Z,1411598461.711 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:02.113Z,1411598462.113 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:02.512Z,1411598462.512 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:02.979Z,1411598462.979 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:03.378Z,1411598463.378 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:03.828Z,1411598463.828 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:04.214Z,1411598464.214 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:04.610Z,1411598464.610 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:05.012Z,1411598465.012 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:05.407Z,1411598465.407 [BPC1](FAULT): Failed to receive battery data
2014-09-24T22:41:05.407Z,1411598465.407 [BPC1] Communications Fault, FailCount= 6
2014-09-24T22:41:05.407Z,1411598465.407 [BPC1](ERROR): Communications Fault
2014-09-24T22:41:05.413Z,1411598465.413 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:05.427Z,1411598465.427 [CBIT](ERROR): Communications Fault in component: BPC1
2014-09-24T22:41:05.831Z,1411598465.831 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:06.276Z,1411598466.276 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:06.679Z,1411598466.679 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:06.693Z,1411598466.693 [CBIT](INFO): Clearing failed state for component BPC1
2014-09-24T22:41:06.693Z,1411598466.693 [BPC1] No Fault, FailCount= 6
2014-09-24T22:41:07.125Z,1411598467.125 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:07.546Z,1411598467.546 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:07.933Z,1411598467.933 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:08.324Z,1411598468.324 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:08.743Z,1411598468.743 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:09.147Z,1411598469.147 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:09.596Z,1411598469.596 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:09.996Z,1411598469.996 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:10.383Z,1411598470.383 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:10.779Z,1411598470.779 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:11.182Z,1411598471.182 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:11.581Z,1411598471.581 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:12.000Z,1411598472.000 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:12.401Z,1411598472.401 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:12.849Z,1411598472.849 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:13.230Z,1411598473.230 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:13.236Z,1411598473.236 [Startup:StartupSatComms:A](INFO): Timed out from 2014-09-24T22:40:12.9Z
2014-09-24T22:41:13.236Z,1411598473.236 [Startup:StartupSatComms:A] Stopped
2014-09-24T22:41:13.236Z,1411598473.236 [Startup:StartupSatComms:B] Running Loop=1
2014-09-24T22:41:13.636Z,1411598473.636 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:13.642Z,1411598473.642 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-09-24T22:41:14.244Z,1411598474.244 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:14.660Z,1411598474.660 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:15.546Z,1411598475.546 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:15.986Z,1411598475.986 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:16.385Z,1411598476.385 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:16.787Z,1411598476.787 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:17.223Z,1411598477.223 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:17.358Z,1411598477.358 [CommandLine](IMPORTANT): got command quit
2014-09-24T22:41:17.641Z,1411598477.641 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:18.026Z,1411598478.026 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:18.362Z,1411598478.362 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-24T22:41:18.362Z,1411598478.362 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:18.431Z,1411598478.431 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:18.487Z,1411598478.487 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-09-24T22:41:18.487Z,1411598478.487 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:18.488Z,1411598478.488 [CommandLine](INFO): Join timeout helper Thread ID is 1798
2014-09-24T22:41:18.495Z,1411598478.495 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-09-24T22:41:18.495Z,1411598478.495 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:18.496Z,1411598478.496 [NavChartDb](INFO): Join timeout helper Thread ID is 1799
2014-09-24T22:41:18.672Z,1411598478.672 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-24T22:41:18.672Z,1411598478.672 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:18.684Z,1411598478.684 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2014-09-24T22:41:18.684Z,1411598478.684 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:18.684Z,1411598478.684 [Radio_Surface](INFO): Join timeout helper Thread ID is 1800
2014-09-24T22:41:18.830Z,1411598478.830 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:19.036Z,1411598479.036 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-24T22:41:19.037Z,1411598479.037 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.044Z,1411598479.044 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-09-24T22:41:19.044Z,1411598479.044 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.045Z,1411598479.045 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1801
2014-09-24T22:41:19.096Z,1411598479.096 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-24T22:41:19.096Z,1411598479.096 [WetLabsBB2FL](INFO): Powering down
2014-09-24T22:41:19.097Z,1411598479.097 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.104Z,1411598479.104 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-09-24T22:41:19.104Z,1411598479.104 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.105Z,1411598479.105 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1802
2014-09-24T22:41:19.298Z,1411598479.298 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:19.389Z,1411598479.389 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-24T22:41:19.389Z,1411598479.389 [CTD_NeilBrown](INFO): Powering down
2014-09-24T22:41:19.390Z,1411598479.390 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.406Z,1411598479.406 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-09-24T22:41:19.406Z,1411598479.406 [logger ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.406Z,1411598479.406 [logger](INFO): Join timeout helper Thread ID is 1803
2014-09-24T22:41:19.413Z,1411598479.413 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-24T22:41:19.413Z,1411598479.413 [logger ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.425Z,1411598479.425 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-09-24T22:41:19.425Z,1411598479.425 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.426Z,1411598479.426 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-09-24T22:41:19.426Z,1411598479.426 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:19.426Z,1411598479.426 [controlThread](INFO): Join timeout helper Thread ID is 1804
2014-09-24T22:41:20.201Z,1411598480.201 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2014-09-24T22:41:20.216Z,1411598480.216 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-09-24T22:41:20.216Z,1411598480.216 [controlThread](DEBUG): Uninitializing ControlThread
2014-09-24T22:41:20.217Z,1411598480.217 [Aanderaa_O2](INFO): Powering down
2014-09-24T22:41:20.218Z,1411598480.218 [AHRS_sp3003D](INFO): Powering down
2014-09-24T22:41:20.306Z,1411598480.306 [AcousticModem_Benthos_ATM900](INFO): Powering down
2014-09-24T22:41:20.522Z,1411598480.522 [DVL_micro](INFO): uninitialize:Powering down
2014-09-24T22:41:20.523Z,1411598480.523 [NAL9602](INFO): Powering down
2014-09-24T22:41:20.525Z,1411598480.525 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-09-24T22:41:20.527Z,1411598480.527 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-09-24T22:41:20.530Z,1411598480.530 [Startup] Stopped
2014-09-24T22:41:20.530Z,1411598480.530 [Startup](INFO): Aggregate::uninitialize Startup
2014-09-24T22:41:20.531Z,1411598480.531 [Startup:A.GoToSurface] Stopped
2014-09-24T22:41:20.531Z,1411598480.531 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-09-24T22:41:20.531Z,1411598480.531 [Startup:StartupSatComms] Stopped
2014-09-24T22:41:20.531Z,1411598480.531 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-09-24T22:41:20.531Z,1411598480.531 [Startup:StartupSatComms:B] Stopped
2014-09-24T22:41:20.532Z,1411598480.532 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-09-24T22:41:20.533Z,1411598480.533 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-09-24T22:41:20.533Z,1411598480.533 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-09-24T22:41:20.533Z,1411598480.533 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-09-24T22:41:20.533Z,1411598480.533 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-09-24T22:41:20.534Z,1411598480.534 [BuoyancyServo](INFO): Powering down
2014-09-24T22:41:20.547Z,1411598480.547 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-09-24T22:41:20.547Z,1411598480.547 [ElevatorServo](INFO): Powering down
2014-09-24T22:41:20.548Z,1411598480.548 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-09-24T22:41:20.548Z,1411598480.548 [MassServo](INFO): Powering down
2014-09-24T22:41:20.548Z,1411598480.548 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-09-24T22:41:20.549Z,1411598480.549 [RudderServo](INFO): Powering down
2014-09-24T22:41:20.549Z,1411598480.549 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-09-24T22:41:20.549Z,1411598480.549 [ThrusterServo](INFO): Powering down
2014-09-24T22:41:20.550Z,1411598480.550 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-09-24T22:41:20.551Z,1411598480.551 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-09-24T22:41:20.551Z,1411598480.551 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-09-24T22:41:20.583Z,1411598480.583 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:20.630Z,1411598480.630 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:20.633Z,1411598480.633 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:20.691Z,1411598480.691 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:20.739Z,1411598480.739 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-09-24T22:41:20.786Z,1411598480.786 [logger ThreadHandler](INFO): Thread cancelled.