2014-07-29T00:24:57.454Z,1406593497.454 [Supervisor](DEBUG): Initializing supervisor.
2014-07-29T00:24:57.457Z,1406593497.457 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-07-29T00:24:57.457Z,1406593497.457 [SyncHandler](INFO): Protected caller Thread ID is 1058
2014-07-29T00:24:57.458Z,1406593497.458 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-07-29T00:24:57.459Z,1406593497.459 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-07-29T00:24:57.459Z,1406593497.459 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1059
2014-07-29T00:24:57.462Z,1406593497.462 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-07-29T00:24:57.475Z,1406593497.475 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-07-29T00:24:57.476Z,1406593497.476 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-07-29T00:24:57.476Z,1406593497.476 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1060
2014-07-29T00:24:57.477Z,1406593497.477 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-07-29T00:24:57.478Z,1406593497.478 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-07-29T00:24:57.479Z,1406593497.479 [logger ThreadHandler](INFO): Protected caller Thread ID is 1061
2014-07-29T00:24:57.481Z,1406593497.481 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-07-29T00:24:57.481Z,1406593497.481 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-07-29T00:24:57.483Z,1406593497.483 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-07-29T00:24:57.848Z,1406593497.848 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-07-29T00:24:57.849Z,1406593497.849 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-07-29T00:24:58.014Z,1406593498.014 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-07-29T00:24:58.015Z,1406593498.015 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-07-29T00:24:58.127Z,1406593498.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-07-29T00:24:58.128Z,1406593498.128 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-07-29T00:24:58.258Z,1406593498.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-07-29T00:24:58.258Z,1406593498.258 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-07-29T00:24:58.347Z,1406593498.347 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-07-29T00:24:58.488Z,1406593498.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-07-29T00:24:58.489Z,1406593498.489 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-07-29T00:24:58.578Z,1406593498.578 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-07-29T00:24:58.579Z,1406593498.579 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-07-29T00:24:58.768Z,1406593498.768 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-07-29T00:24:58.768Z,1406593498.768 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-07-29T00:24:59.075Z,1406593499.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-07-29T00:24:59.076Z,1406593499.076 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-07-29T00:24:59.409Z,1406593499.409 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-07-29T00:24:59.410Z,1406593499.410 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-07-29T00:24:59.947Z,1406593499.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-07-29T00:24:59.947Z,1406593499.947 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-07-29T00:25:00.165Z,1406593500.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-07-29T00:25:00.165Z,1406593500.165 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-07-29T00:25:00.273Z,1406593500.273 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-07-29T00:25:00.273Z,1406593500.273 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-07-29T00:25:00.695Z,1406593500.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-07-29T00:25:00.696Z,1406593500.696 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-07-29T00:25:00.814Z,1406593500.814 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-07-29T00:25:00.815Z,1406593500.815 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-07-29T00:25:00.816Z,1406593500.816 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-07-29T00:25:00.926Z,1406593500.926 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-07-29T00:25:01.050Z,1406593501.050 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-07-29T00:25:01.199Z,1406593501.199 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-07-29T00:25:01.309Z,1406593501.309 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-07-29T00:25:01.444Z,1406593501.444 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-07-29T00:25:01.598Z,1406593501.598 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-07-29T00:25:01.704Z,1406593501.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-07-29T00:25:01.793Z,1406593501.793 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-07-29T00:25:01.890Z,1406593501.890 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-07-29T00:25:01.991Z,1406593501.991 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-07-29T00:25:02.109Z,1406593502.109 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-07-29T00:25:02.201Z,1406593502.201 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2014-07-29T00:25:02.201Z,1406593502.201 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-07-29T00:25:02.203Z,1406593502.203 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-07-29T00:25:02.258Z,1406593502.258 [VerticalControl](DEBUG): Construct VerticalControl.
2014-07-29T00:25:02.384Z,1406593502.384 [VerticalControl] Loaded
2014-07-29T00:25:02.384Z,1406593502.384 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-07-29T00:25:02.385Z,1406593502.385 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-07-29T00:25:02.460Z,1406593502.460 [HorizontalControl] Loaded
2014-07-29T00:25:02.461Z,1406593502.461 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-07-29T00:25:02.461Z,1406593502.461 [SpeedControl](DEBUG): Construct SpeedControl.
2014-07-29T00:25:02.467Z,1406593502.467 [SpeedControl] Loaded
2014-07-29T00:25:02.468Z,1406593502.468 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-07-29T00:25:02.468Z,1406593502.468 [LoopControl](DEBUG): Construct LoopControl.
2014-07-29T00:25:02.469Z,1406593502.469 [LoopControl] Loaded
2014-07-29T00:25:02.469Z,1406593502.469 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-07-29T00:25:02.470Z,1406593502.470 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-07-29T00:25:02.470Z,1406593502.470 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-07-29T00:25:02.578Z,1406593502.578 [SBIT](DEBUG): Construct Startup Built In Test.
2014-07-29T00:25:02.590Z,1406593502.590 [SBIT] Loaded
2014-07-29T00:25:02.590Z,1406593502.590 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-07-29T00:25:02.591Z,1406593502.591 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-07-29T00:25:02.622Z,1406593502.622 [IBIT] Loaded
2014-07-29T00:25:02.622Z,1406593502.622 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-07-29T00:25:02.624Z,1406593502.624 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-07-29T00:25:02.751Z,1406593502.751 [CBIT] Loaded
2014-07-29T00:25:02.751Z,1406593502.751 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-07-29T00:25:02.752Z,1406593502.752 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-07-29T00:25:02.752Z,1406593502.752 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-07-29T00:25:02.772Z,1406593502.772 [DepthRateCalculator] Loaded
2014-07-29T00:25:02.773Z,1406593502.773 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-07-29T00:25:02.778Z,1406593502.778 [PitchRateCalculator] Loaded
2014-07-29T00:25:02.779Z,1406593502.779 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-07-29T00:25:02.791Z,1406593502.791 [SpeedCalculator] Loaded
2014-07-29T00:25:02.791Z,1406593502.791 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-07-29T00:25:02.808Z,1406593502.808 [TempGradientCalculator] Loaded
2014-07-29T00:25:02.808Z,1406593502.808 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-07-29T00:25:02.814Z,1406593502.814 [YawRateCalculator] Loaded
2014-07-29T00:25:02.814Z,1406593502.814 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-07-29T00:25:02.815Z,1406593502.815 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-07-29T00:25:02.815Z,1406593502.815 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-07-29T00:25:08.716Z,1406593508.716 [HFRadarModelCalc] Loaded
2014-07-29T00:25:08.717Z,1406593508.717 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-07-29T00:25:14.387Z,1406593514.387 [HFRadarCompactModelForecaster] Loaded
2014-07-29T00:25:14.387Z,1406593514.387 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-07-29T00:25:15.672Z,1406593515.672 [HFRCMSpaceInterpolator] Loaded
2014-07-29T00:25:15.673Z,1406593515.673 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-07-29T00:25:15.675Z,1406593515.675 [HFRCMTimeInterpolator] Loaded
2014-07-29T00:25:15.675Z,1406593515.675 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-07-29T00:25:16.912Z,1406593516.912 [HFRCMReconstructedInterpolator] Loaded
2014-07-29T00:25:16.913Z,1406593516.913 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2014-07-29T00:25:16.925Z,1406593516.925 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-07-29T00:25:16.926Z,1406593516.926 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-07-29T00:25:16.954Z,1406593516.954 [HFRCMVirtualSurfaceDrifter] Loaded
2014-07-29T00:25:16.955Z,1406593516.955 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-07-29T00:25:16.955Z,1406593516.955 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-07-29T00:25:16.956Z,1406593516.956 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-07-29T00:25:17.216Z,1406593517.216 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-07-29T00:25:17.217Z,1406593517.217 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-07-29T00:25:17.302Z,1406593517.302 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-07-29T00:25:17.303Z,1406593517.303 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-07-29T00:25:17.351Z,1406593517.351 [DeadReckonWithRespectToWater] Loaded
2014-07-29T00:25:17.351Z,1406593517.351 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-07-29T00:25:17.401Z,1406593517.401 [DeadReckonWithRespectToSeafloor] Loaded
2014-07-29T00:25:17.401Z,1406593517.401 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-07-29T00:25:17.465Z,1406593517.465 [DeadReckonUsingDVLWaterTrack] Loaded
2014-07-29T00:25:17.465Z,1406593517.465 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-07-29T00:25:17.515Z,1406593517.515 [DeadReckonUsingCompactModelForecast] Loaded
2014-07-29T00:25:17.516Z,1406593517.516 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-07-29T00:25:17.534Z,1406593517.534 [NavChart] Loaded
2014-07-29T00:25:17.534Z,1406593517.534 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-07-29T00:25:17.539Z,1406593517.539 [UniversalFixResidualReporter] Loaded
2014-07-29T00:25:17.539Z,1406593517.539 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-07-29T00:25:17.539Z,1406593517.539 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-07-29T00:25:17.540Z,1406593517.540 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-07-29T00:25:17.546Z,1406593517.546 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-07-29T00:25:17.547Z,1406593517.547 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-07-29T00:25:17.730Z,1406593517.730 [CTD_NeilBrown] Loaded
2014-07-29T00:25:17.730Z,1406593517.730 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-07-29T00:25:17.731Z,1406593517.731 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407B94E0
2014-07-29T00:25:17.732Z,1406593517.732 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1148
2014-07-29T00:25:17.747Z,1406593517.747 [PAR_Licor] Loaded
2014-07-29T00:25:17.748Z,1406593517.748 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-07-29T00:25:17.786Z,1406593517.786 [WetLabsBB2FL] Loaded
2014-07-29T00:25:17.786Z,1406593517.786 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-07-29T00:25:17.787Z,1406593517.787 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407E94E0
2014-07-29T00:25:17.788Z,1406593517.787 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1149
2014-07-29T00:25:17.788Z,1406593517.788 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-07-29T00:25:17.789Z,1406593517.789 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-07-29T00:25:18.091Z,1406593518.091 [AHRS_sp3003D] Loaded
2014-07-29T00:25:18.092Z,1406593518.092 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-07-29T00:25:18.368Z,1406593518.368 [Batt_Ocean_Server] Loaded
2014-07-29T00:25:18.368Z,1406593518.368 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-07-29T00:25:18.386Z,1406593518.386 [Depth_Keller] Loaded
2014-07-29T00:25:18.386Z,1406593518.386 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-07-29T00:25:18.392Z,1406593518.392 [DropWeight] Loaded
2014-07-29T00:25:18.392Z,1406593518.392 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-07-29T00:25:18.533Z,1406593518.533 [DVL_micro] Loaded
2014-07-29T00:25:18.533Z,1406593518.533 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-07-29T00:25:18.633Z,1406593518.633 [NAL9602] Loaded
2014-07-29T00:25:18.633Z,1406593518.633 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-07-29T00:25:18.678Z,1406593518.678 [Onboard] Loaded
2014-07-29T00:25:18.678Z,1406593518.678 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-07-29T00:25:18.685Z,1406593518.685 [Radio_Freewave] Loaded
2014-07-29T00:25:18.686Z,1406593518.686 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-07-29T00:25:18.687Z,1406593518.687 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 40A1B4E0
2014-07-29T00:25:18.687Z,1406593518.687 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 1150
2014-07-29T00:25:18.849Z,1406593518.849 [DAT] Loaded
2014-07-29T00:25:18.850Z,1406593518.850 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2014-07-29T00:25:18.857Z,1406593518.857 [SCPI] Loaded
2014-07-29T00:25:18.857Z,1406593518.857 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-07-29T00:25:18.858Z,1406593518.858 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-07-29T00:25:18.858Z,1406593518.858 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-07-29T00:25:18.966Z,1406593518.966 [BuoyancyServo] Loaded
2014-07-29T00:25:18.966Z,1406593518.966 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-07-29T00:25:18.979Z,1406593518.979 [ElevatorServo] Loaded
2014-07-29T00:25:18.979Z,1406593518.979 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-07-29T00:25:18.991Z,1406593518.991 [MassServo] Loaded
2014-07-29T00:25:18.992Z,1406593518.992 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-07-29T00:25:19.004Z,1406593519.004 [RudderServo] Loaded
2014-07-29T00:25:19.005Z,1406593519.005 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-07-29T00:25:19.016Z,1406593519.016 [ThrusterServo] Loaded
2014-07-29T00:25:19.017Z,1406593519.017 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-07-29T00:25:19.017Z,1406593519.017 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-07-29T00:25:19.018Z,1406593519.018 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-07-29T00:25:19.191Z,1406593519.191 [InternalSim] Loaded
2014-07-29T00:25:19.191Z,1406593519.191 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-07-29T00:25:19.192Z,1406593519.192 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-07-29T00:25:19.192Z,1406593519.192 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-07-29T00:25:19.218Z,1406593519.218 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-07-29T00:25:19.220Z,1406593519.220 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-07-29T00:25:19.221Z,1406593519.221 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-07-29T00:25:19.227Z,1406593519.227 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-07-29T00:25:19.229Z,1406593519.229 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACC4E0
2014-07-29T00:25:19.229Z,1406593519.229 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1151
2014-07-29T00:25:19.234Z,1406593519.234 [Supervisor](INFO): Main Thread ID is 773
2014-07-29T00:25:19.234Z,1406593519.234 [Supervisor](DEBUG): Running supervisor.
2014-07-29T00:25:19.235Z,1406593519.235 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1152
2014-07-29T00:25:19.239Z,1406593519.239 [controlThread ThreadHandler](INFO): Handler Thread ID is 1153
2014-07-29T00:25:19.240Z,1406593519.240 [controlThread](DEBUG): Initializing ControlThread
2014-07-29T00:25:19.241Z,1406593519.241 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-07-29T00:25:19.242Z,1406593519.242 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-07-29T00:25:19.243Z,1406593519.243 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-07-29T00:25:19.243Z,1406593519.243 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-07-29T00:25:19.244Z,1406593519.244 [SBIT](INFO): Initialize SBIT Component.
2014-07-29T00:25:19.244Z,1406593519.244 [SBIT](IMPORTANT): Tethys CM Info: SVN revision: 11424
2014-07-29T00:25:19.245Z,1406593519.245 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2014-07-29T00:25:19.245Z,1406593519.245 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-07-29T00:25:19.245Z,1406593519.245 [IBIT](INFO): Initialize IBIT Component.
2014-07-29T00:25:19.246Z,1406593519.246 [CBIT](DEBUG): Initialize CBIT Component.
2014-07-29T00:25:19.247Z,1406593519.247 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-07-29T00:25:19.248Z,1406593519.248 [logger ThreadHandler](INFO): Handler Thread ID is 1154
2014-07-29T00:25:19.272Z,1406593519.272 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-07-29T00:25:19.273Z,1406593519.273 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-07-29T00:25:19.273Z,1406593519.273 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-07-29T00:25:19.273Z,1406593519.273 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-07-29T00:25:19.274Z,1406593519.274 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-07-29T00:25:19.281Z,1406593519.281 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-07-29T00:25:19.297Z,1406593519.297 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1155
2014-07-29T00:25:19.297Z,1406593519.297 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-07-29T00:25:19.305Z,1406593519.305 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-07-29T00:25:19.310Z,1406593519.310 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1157
2014-07-29T00:25:19.312Z,1406593519.312 [WetLabsBB2FL](INFO): Powering down
2014-07-29T00:25:19.349Z,1406593519.349 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 1158
2014-07-29T00:25:19.365Z,1406593519.365 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1159
2014-07-29T00:25:19.368Z,1406593519.368 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-07-29T00:25:19.369Z,1406593519.369 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-07-29T00:25:19.369Z,1406593519.369 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-07-29T00:25:19.369Z,1406593519.369 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-07-29T00:25:19.369Z,1406593519.369 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-07-29T00:25:19.370Z,1406593519.370 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-07-29T00:25:19.370Z,1406593519.370 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-07-29T00:25:19.370Z,1406593519.370 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-07-29T00:25:19.370Z,1406593519.370 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-07-29T00:25:28.415Z,1406593528.415 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201407282100: published 50 modes in rows, 61 hours in columns
2014-07-29T00:25:28.427Z,1406593528.427 [HFRadarCompactModelForecaster](IMPORTANT): expansionCoefficients_[0][48] = 9.046450 for 2014-07-28T21:00:00.000Z
2014-07-29T00:25:28.428Z,1406593528.428 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2014-07-29T00:25:28.429Z,1406593528.429 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-07-29T00:25:28.430Z,1406593528.430 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2014-07-29T00:25:28.431Z,1406593528.431 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-07-29T00:25:28.432Z,1406593528.432 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-07-29T00:25:28.432Z,1406593528.432 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-07-29T00:25:28.432Z,1406593528.432 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-07-29T00:25:28.433Z,1406593528.433 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-07-29T00:25:28.433Z,1406593528.433 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-07-29T00:25:28.434Z,1406593528.434 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-07-29T00:25:28.434Z,1406593528.434 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-07-29T00:25:28.443Z,1406593528.443 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-07-29T00:25:30.036Z,1406593530.036 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-07-29T00:25:30.070Z,1406593530.070 [InternalSim](DEBUG):  InternalSim initializing...
2014-07-29T00:25:30.215Z,1406593530.215 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-07-29T00:25:30.267Z,1406593530.267 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-07-29T00:25:30.289Z,1406593530.289 [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-07-29T00:25:30.318Z,1406593530.318 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-07-29T00:25:30.447Z,1406593530.447 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-07-29T00:25:30.449Z,1406593530.449 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-07-29T00:25:30.461Z,1406593530.461 [Radio_Freewave](INFO): Powering up
2014-07-29T00:25:30.473Z,1406593530.473 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-07-29T00:25:30.501Z,1406593530.501 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-07-29T00:25:30.505Z,1406593530.505 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-07-29T00:25:30.520Z,1406593530.520 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-07-29T00:25:30.546Z,1406593530.546 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-07-29T00:25:30.574Z,1406593530.574 [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="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS">

        <When>
            <Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

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

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS">
            <Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Sequence/><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium">

        <Sequence/>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

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

<!-- 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="CallIridium">

        <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>

        <Assign><Sequence/><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

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

    </Aggregate>

</Mission>


2014-07-29T00:25:30.592Z,1406593530.592 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,PAR_Licor,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,SCPI,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarModelCalc,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonWithRespectToWater,DeadReckonWithRespectToSeafloor,DeadReckonUsingDVLWaterTrack,DeadReckonUsingCompactModelForecast,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-07-29T00:25:30.770Z,1406593530.770 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-07-29T00:25:30.955Z,1406593530.955 [DVL_micro](INFO): Initializing
2014-07-29T00:25:30.977Z,1406593530.977 [NAL9602](INFO): Powering up NAL9602
2014-07-29T00:25:31.071Z,1406593531.071 [DAT](INFO): Powering up
2014-07-29T00:25:31.071Z,1406593531.071 [DAT](DEBUG): Initializing DAT.
2014-07-29T00:25:31.272Z,1406593531.272 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0
2014-07-29T00:25:38.548Z,1406593538.548 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:25:38.554Z,1406593538.554 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-07-29T00:25:38.573Z,1406593538.573 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:25:38.579Z,1406593538.579 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-07-29T00:25:38.600Z,1406593538.600 [MassServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:25:38.609Z,1406593538.609 [MassServo](DEBUG): Initializing MassServo.
2014-07-29T00:25:38.615Z,1406593538.615 [RudderServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:25:38.623Z,1406593538.623 [RudderServo](DEBUG): Initializing RudderServo.
2014-07-29T00:25:38.628Z,1406593538.628 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:25:38.635Z,1406593538.635 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-07-29T00:25:39.589Z,1406593539.589 [SBIT](IMPORTANT): Beginning Startup BIT
2014-07-29T00:25:39.592Z,1406593539.592 [CBIT](IMPORTANT): Beginning GF scan
2014-07-29T00:25:41.763Z,1406593541.763 [NAL9602](INFO): NAL9602 initialized
2014-07-29T00:25:51.513Z,1406593551.513 [DAT](INFO): Powering down
2014-07-29T00:25:59.992Z,1406593559.992 [CommandLine](IMPORTANT): got command show variable DAT
2014-07-29T00:25:59.998Z,1406593559.998 [CommandLine](IMPORTANT): HorizontalControl.loadAtStartup (bool)
2014-07-29T00:25:59.999Z,1406593559.999 [CommandLine](IMPORTANT): LoopControl.loadAtStartup (bool)
2014-07-29T00:25:59.999Z,1406593559.999 [CommandLine](IMPORTANT): SpeedControl.loadAtStartup (bool)
2014-07-29T00:25:59.000Z,1406593560.000 [CommandLine](IMPORTANT): VerticalControl.loadAtStartup (bool)
2014-07-29T00:26:00.002Z,1406593560.002 [CommandLine](IMPORTANT): CBIT.loadAtStartup (bool)
2014-07-29T00:26:00.004Z,1406593560.004 [CommandLine](IMPORTANT): SBIT.loadAtStartup (bool)
2014-07-29T00:26:00.005Z,1406593560.005 [CommandLine](IMPORTANT): IBIT.loadAtStartup (bool)
2014-07-29T00:26:00.005Z,1406593560.005 [CommandLine](IMPORTANT): DepthRateCalculator.loadAtStartup (bool)
2014-07-29T00:26:00.006Z,1406593560.006 [CommandLine](IMPORTANT): TempGradientCalculator.loadAtStartup (bool)
2014-07-29T00:26:00.006Z,1406593560.006 [CommandLine](IMPORTANT): PitchRateCalculator.loadAtStartup (bool)
2014-07-29T00:26:00.007Z,1406593560.007 [CommandLine](IMPORTANT): SpeedCalculator.loadAtStartup (bool)
2014-07-29T00:26:00.009Z,1406593560.009 [CommandLine](IMPORTANT): YawRateCalculator.loadAtStartup (bool)
2014-07-29T00:26:00.009Z,1406593560.009 [CommandLine](IMPORTANT): HFRadarModelCalc.loadAtStartup (bool)
2014-07-29T00:26:00.010Z,1406593560.010 [CommandLine](IMPORTANT): HFRadarCompactModelForecaster.loadAtStartup (bool)
2014-07-29T00:26:00.010Z,1406593560.010 [CommandLine](IMPORTANT): HFRCMSpaceInterpolator.loadAtStartup (bool)
2014-07-29T00:26:00.011Z,1406593560.011 [CommandLine](IMPORTANT): HFRCMTimeInterpolator.loadAtStartup (bool)
2014-07-29T00:26:00.011Z,1406593560.011 [CommandLine](IMPORTANT): HFRCMReconstructedInterpolator.loadAtStartup (bool)
2014-07-29T00:26:00.012Z,1406593560.012 [CommandLine](IMPORTANT): HFRCMSurfaceCurrentAtVehicleLocation.loadAtStartup (bool)
2014-07-29T00:26:00.012Z,1406593560.012 [CommandLine](IMPORTANT): HFRCMVirtualSurfaceDrifter.loadAtStartup (bool)
2014-07-29T00:26:00.013Z,1406593560.013 [CommandLine](IMPORTANT): DeadReckonUsingMultipleVelocitySources.loadAtStartup (bool)
2014-07-29T00:26:00.013Z,1406593560.013 [CommandLine](IMPORTANT): DeadReckonWithRespectToWater.loadAtStartup (bool)
2014-07-29T00:26:00.014Z,1406593560.014 [CommandLine](IMPORTANT): DeadReckonWithRespectToSeafloor.loadAtStartup (bool)
2014-07-29T00:26:00.014Z,1406593560.014 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.loadAtStartup (bool)
2014-07-29T00:26:00.015Z,1406593560.015 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.loadAtStartup (bool)
2014-07-29T00:26:00.050Z,1406593560.050 [CommandLine](IMPORTANT): NavChart.loadAtStartup (bool)
2014-07-29T00:26:00.051Z,1406593560.051 [CommandLine](IMPORTANT): UniversalFixResidualReporter.loadAtStartup (bool)
2014-07-29T00:26:00.055Z,1406593560.055 [CommandLine](IMPORTANT): AsyncPiEstimator.loadAtStartup (bool)
2014-07-29T00:26:00.056Z,1406593560.056 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup (bool)
2014-07-29T00:26:00.056Z,1406593560.056 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup (bool)
2014-07-29T00:26:00.057Z,1406593560.057 [CommandLine](IMPORTANT): ISUS.loadAtStartup (bool)
2014-07-29T00:26:00.058Z,1406593560.058 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup (bool)
2014-07-29T00:26:00.058Z,1406593560.058 [CommandLine](IMPORTANT): Turbulence_NPS.loadAtStartup (bool)
2014-07-29T00:26:00.059Z,1406593560.059 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup (bool)
2014-07-29T00:26:00.092Z,1406593560.092 [CommandLine](IMPORTANT): AHRS_3DMGX3.loadAtStartup (bool)
2014-07-29T00:26:00.093Z,1406593560.093 [CommandLine](IMPORTANT): AHRS_sp3003D.loadAtStartup (bool)
2014-07-29T00:26:00.094Z,1406593560.094 [CommandLine](IMPORTANT): Batt_Ocean_Server.loadAtStartup (bool)
2014-07-29T00:26:00.094Z,1406593560.094 [CommandLine](IMPORTANT): DataOverHttps.loadAtStartup (bool)
2014-07-29T00:26:00.095Z,1406593560.095 [CommandLine](IMPORTANT): DataOverHttps.power (watt)
2014-07-29T00:26:00.095Z,1406593560.095 [CommandLine](IMPORTANT): DataOverHttps.connectionTimeout (second)
2014-07-29T00:26:00.112Z,1406593560.112 [CommandLine](IMPORTANT): DataOverHttps.period (second)
2014-07-29T00:26:00.112Z,1406593560.112 [CommandLine](IMPORTANT): DataOverHttps.timeout (minute)
2014-07-29T00:26:00.113Z,1406593560.113 [CommandLine](IMPORTANT): DataOverHttps.verbosity (count)
2014-07-29T00:26:00.113Z,1406593560.113 [CommandLine](IMPORTANT): DAT.loadAtStartup (bool)
2014-07-29T00:26:00.114Z,1406593560.114 [CommandLine](IMPORTANT): DAT.simulateHardware (bool)
2014-07-29T00:26:00.114Z,1406593560.114 [CommandLine](IMPORTANT): Depth_Keller.loadAtStartup (bool)
2014-07-29T00:26:00.115Z,1406593560.115 [CommandLine](IMPORTANT): DropWeight.loadAtStartup (bool)
2014-07-29T00:26:00.115Z,1406593560.115 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup (bool)
2014-07-29T00:26:00.133Z,1406593560.133 [CommandLine](IMPORTANT): NAL9602.loadAtStartup (bool)
2014-07-29T00:26:00.134Z,1406593560.134 [CommandLine](IMPORTANT): Onboard.loadAtStartup (bool)
2014-07-29T00:26:00.134Z,1406593560.134 [CommandLine](IMPORTANT): PNI_TCM.loadAtStartup (bool)
2014-07-29T00:26:00.135Z,1406593560.135 [CommandLine](IMPORTANT): Radio_CDMA.loadAtStartup (bool)
2014-07-29T00:26:00.144Z,1406593560.144 [CommandLine](IMPORTANT): Radio_Freewave.loadAtStartup (bool)
2014-07-29T00:26:00.145Z,1406593560.145 [CommandLine](IMPORTANT): Rowe_600.loadAtStartup (bool)
2014-07-29T00:26:00.145Z,1406593560.145 [CommandLine](IMPORTANT): SCPI.loadAtStartup (bool)
2014-07-29T00:26:00.146Z,1406593560.146 [CommandLine](IMPORTANT): BuoyancyServo.loadAtStartup (bool)
2014-07-29T00:26:00.146Z,1406593560.146 [CommandLine](IMPORTANT): ElevatorServo.loadAtStartup (bool)
2014-07-29T00:26:00.147Z,1406593560.147 [CommandLine](IMPORTANT): MassServo.loadAtStartup (bool)
2014-07-29T00:26:00.163Z,1406593560.163 [CommandLine](IMPORTANT): RudderServo.loadAtStartup (bool)
2014-07-29T00:26:00.180Z,1406593560.180 [CommandLine](IMPORTANT): ThrusterServo.loadAtStartup (bool)
2014-07-29T00:26:00.181Z,1406593560.181 [CommandLine](IMPORTANT): ExternalSim.loadAtStartup (bool)
2014-07-29T00:26:00.182Z,1406593560.182 [CommandLine](IMPORTANT): InternalSim.loadAtStartup (bool)
2014-07-29T00:26:00.182Z,1406593560.182 [CommandLine](IMPORTANT): NavigationSim.loadAtStartup (bool)
2014-07-29T00:26:00.215Z,1406593560.215 [CommandLine](IMPORTANT): Config/Simulator.oceanModelData (none)
2014-07-29T00:26:00.233Z,1406593560.233 [CommandLine](IMPORTANT): Vehicle.sendDataToShore (bool)
2014-07-29T00:26:00.234Z,1406593560.234 [CommandLine](IMPORTANT): DAT.loadControl (none)
2014-07-29T00:26:00.235Z,1406593560.235 [CommandLine](IMPORTANT): DAT.uart (none)
2014-07-29T00:26:00.235Z,1406593560.235 [CommandLine](IMPORTANT): DAT.baud (bit_per_second)
2014-07-29T00:26:00.347Z,1406593560.347 [CommandLine](IMPORTANT): DAT.LVL1 (count)
2014-07-29T00:26:00.347Z,1406593560.347 [CommandLine](IMPORTANT): DAT.LVL2 (count)
2014-07-29T00:26:00.364Z,1406593560.364 [CommandLine](IMPORTANT): DAT.LVL3 (count)
2014-07-29T00:26:00.365Z,1406593560.365 [CommandLine](IMPORTANT): DAT.LVL4 (count)
2014-07-29T00:26:00.365Z,1406593560.365 [CommandLine](IMPORTANT): DAT.AGC (count)
2014-07-29T00:26:00.365Z,1406593560.365 [CommandLine](IMPORTANT): DAT.IDXPeak (count)
2014-07-29T00:26:00.366Z,1406593560.366 [CommandLine](IMPORTANT): DAT.IDXFit (count)
2014-07-29T00:26:00.366Z,1406593560.366 [CommandLine](IMPORTANT): DAT.IDXPhase (radian)
2014-07-29T00:26:00.366Z,1406593560.366 [CommandLine](IMPORTANT): DAT.phaseA (radian)
2014-07-29T00:26:00.367Z,1406593560.367 [CommandLine](IMPORTANT): DAT.phaseB (radian)
2014-07-29T00:26:00.367Z,1406593560.367 [CommandLine](IMPORTANT): DAT.phaseC (radian)
2014-07-29T00:26:00.367Z,1406593560.367 [CommandLine](IMPORTANT): DAT.vectorMagnitude (none)
2014-07-29T00:26:00.384Z,1406593560.384 [CommandLine](IMPORTANT): DAT.rawAzimuth (degree)
2014-07-29T00:26:00.385Z,1406593560.385 [CommandLine](IMPORTANT): DAT.rawElevation (degree)
2014-07-29T00:26:00.385Z,1406593560.385 [CommandLine](IMPORTANT): DAT.calibratedAzimuth (degree)
2014-07-29T00:26:00.385Z,1406593560.385 [CommandLine](IMPORTANT): DAT.calibratedElevation (degree)
2014-07-29T00:26:00.386Z,1406593560.386 [CommandLine](IMPORTANT): DAT.rotatedAzimuth (degree)
2014-07-29T00:26:00.386Z,1406593560.386 [CommandLine](IMPORTANT): DAT.rotatedElevation (degree)
2014-07-29T00:26:00.387Z,1406593560.387 [CommandLine](IMPORTANT): DAT.remoteAddress (enum)
2014-07-29T00:26:00.387Z,1406593560.387 [CommandLine](IMPORTANT): DAT.localAddress (enum)
2014-07-29T00:26:00.387Z,1406593560.387 [CommandLine](IMPORTANT): DAT.range (meter)
2014-07-29T00:26:00.388Z,1406593560.388 [CommandLine](IMPORTANT): DAT.onewayRequestedCmd (bool)
2014-07-29T00:26:00.401Z,1406593560.401 [CommandLine](IMPORTANT): DAT.azimuth_instrumentFrame (radian)
2014-07-29T00:26:00.401Z,1406593560.401 [CommandLine](IMPORTANT): DAT.elevation_instrumentFrame (radian)
2014-07-29T00:26:00.402Z,1406593560.402 [CommandLine](IMPORTANT): DAT.azimuth_vehicleFrame (radian)
2014-07-29T00:26:00.402Z,1406593560.402 [CommandLine](IMPORTANT): DAT.elevation_vehicleFrame (radian)
2014-07-29T00:26:00.403Z,1406593560.403 [CommandLine](IMPORTANT): DAT.direction_instrumentFrame (none)
2014-07-29T00:26:00.403Z,1406593560.403 [CommandLine](IMPORTANT): DAT.direction_vehicleFrame (none)
2014-07-29T00:26:00.403Z,1406593560.403 [CommandLine](IMPORTANT): DAT.xDirection_vehicleFrame (none)
2014-07-29T00:26:00.404Z,1406593560.404 [CommandLine](IMPORTANT): DAT.yDirection_vehicleFrame (none)
2014-07-29T00:26:00.413Z,1406593560.413 [CommandLine](IMPORTANT): DAT.zDirection_vehicleFrame (none)
2014-07-29T00:26:00.415Z,1406593560.415 [CommandLine](IMPORTANT): DAT.durationOfLastRun (second)
2014-07-29T00:26:00.450Z,1406593560.450 [CommandLine](IMPORTANT): DAT.component_voltage (volt)
2014-07-29T00:26:00.450Z,1406593560.450 [CommandLine](IMPORTANT): DAT.component_avgVoltage (volt)
2014-07-29T00:26:00.450Z,1406593560.450 [CommandLine](IMPORTANT): DAT.component_current (milliampere)
2014-07-29T00:26:00.451Z,1406593560.451 [CommandLine](IMPORTANT): DAT.component_avgCurrent (milliampere)
2014-07-29T00:26:06.414Z,1406593566.414 [CBIT](IMPORTANT): No ground fault detected
2014-07-29T00:26:14.377Z,1406593574.377 [CommandLine](INFO): End of History
2014-07-29T00:26:14.937Z,1406593574.937 [CommandLine](INFO): End of History
2014-07-29T00:26:15.169Z,1406593575.169 [CommandLine](INFO): End of History
2014-07-29T00:26:15.353Z,1406593575.353 [CommandLine](INFO): End of History
2014-07-29T00:26:19.924Z,1406593579.924 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/dat_on.xml
2014-07-29T00:26:19.925Z,1406593579.925 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/dat_on.xml
2014-07-29T00:26:19.949Z,1406593579.949 [MissionManager](INFO): DefineArg dat_on.MassDefault = 0.000000 n/a
2014-07-29T00:26:19.951Z,1406593579.951 [dat_on:A.Pitch](DEBUG): Construct.
2014-07-29T00:26:19.996Z,1406593579.996 [dat_on:TestDrive:C.Wait](DEBUG): Construct Wait.
2014-07-29T00:26:19.999Z,1406593579.999 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance"
       xmlns:Sensor="Tethys/Sensor" 
       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/Sensor http://aosn.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="dat_on">

    <DefineArg Name="MassDefault"><Control:VerticalControl.massDefault/></DefineArg>

    <Timeout Duration="P15M"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Aggregate Id="TestDrive">

        <Sequence/>

        <ReadData>
            <Sensor:DAT.range/>
        </ReadData>

        <Aggregate Id="Data">

            <When>
                <True/>
            </When>

            <SendData Service="Express">
                <Control:HorizontalControl.latitudeCmd/><Units:degree/>
                <Control:HorizontalControl.longitudeCmd/><Units:degree/>
            </SendData>

            <Syslog Severity="None">Pause a cycle</Syslog>

        </Aggregate>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>2</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2014-07-29T00:26:20.001Z,1406593580.001 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/dat_on.xml
2014-07-29T00:26:33.977Z,1406593593.977 [SBIT](IMPORTANT): SBIT PASSED
2014-07-29T00:26:34.417Z,1406593594.417 [MissionManager](IMPORTANT): Started mission Startup
2014-07-29T00:26:34.418Z,1406593594.418 [Startup] Running Loop=1
2014-07-29T00:26:34.418Z,1406593594.418 [Startup](INFO): Aggregate::initialize Startup
2014-07-29T00:26:34.418Z,1406593594.418 [Startup:A.GoToSurface] Running Loop=1
2014-07-29T00:26:34.418Z,1406593594.418 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:26:34.418Z,1406593594.418 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-07-29T00:26:34.419Z,1406593594.419 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-07-29T00:26:34.419Z,1406593594.419 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-07-29T00:26:34.425Z,1406593594.425 [Startup:StartupSatComms] Running Loop=1
2014-07-29T00:26:34.426Z,1406593594.426 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-07-29T00:26:34.426Z,1406593594.426 [Startup:StartupSatComms:A] Running Loop=1
2014-07-29T00:26:34.876Z,1406593594.876 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-07-29T00:27:34.665Z,1406593654.665 [Startup:StartupSatComms:A](INFO): Timed out from 2014-07-29T00:26:34.4Z
2014-07-29T00:27:34.665Z,1406593654.665 [Startup:StartupSatComms:A] Stopped
2014-07-29T00:27:34.665Z,1406593654.665 [Startup:StartupSatComms:B] Running Loop=1
2014-07-29T00:27:35.091Z,1406593655.091 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-07-29T00:28:35.535Z,1406593715.535 [Startup:StartupSatComms:B](INFO): Timed out from 2014-07-29T00:27:34.7Z
2014-07-29T00:28:35.535Z,1406593715.535 [Startup:StartupSatComms:B] Stopped
2014-07-29T00:28:35.535Z,1406593715.535 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-07-29T00:28:35.536Z,1406593715.536 [Startup:StartupSatComms] Stopped
2014-07-29T00:28:35.536Z,1406593715.536 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-07-29T00:28:35.583Z,1406593715.583 [Startup](INFO): Completed Startup
2014-07-29T00:28:35.584Z,1406593715.584 [Startup] Stopped
2014-07-29T00:28:35.584Z,1406593715.584 [Startup](INFO): Aggregate::uninitialize Startup
2014-07-29T00:28:35.584Z,1406593715.584 [Startup:A.GoToSurface] Stopped
2014-07-29T00:28:35.584Z,1406593715.584 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-07-29T00:28:36.037Z,1406593716.037 [MissionManager](IMPORTANT): Started mission dat_on
2014-07-29T00:28:36.037Z,1406593716.037 [dat_on] Running Loop=1
2014-07-29T00:28:36.037Z,1406593716.037 [dat_on](INFO): Aggregate::initialize dat_on
2014-07-29T00:28:36.037Z,1406593716.037 [dat_on:A.Pitch] Running Loop=1
2014-07-29T00:28:36.038Z,1406593716.038 [dat_on:A.Pitch](DEBUG): Initialize.
2014-07-29T00:28:36.038Z,1406593716.038 [dat_on:TestDrive] Running Loop=1
2014-07-29T00:28:36.038Z,1406593716.038 [dat_on:TestDrive](INFO): Aggregate::initialize dat_on:TestDrive
2014-07-29T00:28:36.038Z,1406593716.038 [dat_on:TestDrive:A] Running Loop=1
2014-07-29T00:28:36.038Z,1406593716.038 [dat_on:TestDrive:C.Wait] Running Loop=1
2014-07-29T00:28:36.038Z,1406593716.038 [dat_on:TestDrive:C.Wait](DEBUG): Initialize Wait Component.
2014-07-29T00:28:36.043Z,1406593716.043 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:36.043Z,1406593716.043 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:36.044Z,1406593716.044 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:36.103Z,1406593716.103 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:36.103Z,1406593716.103 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:36.103Z,1406593716.103 [dat_on:TestDrive:A] Running Loop=1
2014-07-29T00:28:36.104Z,1406593716.104 [dat_on:TestDrive:A](DEBUG): Initialize ReadDataComponent to sense DAT.range
2014-07-29T00:28:36.105Z,1406593716.105 [dat_on:A.Pitch] Running Loop=1
2014-07-29T00:28:36.529Z,1406593716.529 [DAT](INFO): Powering up
2014-07-29T00:28:36.547Z,1406593716.547 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:36.547Z,1406593716.547 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:36.547Z,1406593716.547 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:36.548Z,1406593716.548 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:36.994Z,1406593716.994 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:36.994Z,1406593716.994 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:36.994Z,1406593716.994 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:36.995Z,1406593716.995 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:36.995Z,1406593716.995 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:37.491Z,1406593717.491 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:37.491Z,1406593717.491 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:37.491Z,1406593717.491 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:37.500Z,1406593717.500 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:37.906Z,1406593717.906 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:37.906Z,1406593717.906 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:37.906Z,1406593717.906 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:37.907Z,1406593717.907 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:37.907Z,1406593717.907 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:38.417Z,1406593718.417 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:38.417Z,1406593718.417 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:38.417Z,1406593718.417 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:38.417Z,1406593718.417 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:38.873Z,1406593718.873 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:38.873Z,1406593718.873 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:38.873Z,1406593718.873 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:38.874Z,1406593718.874 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:38.874Z,1406593718.874 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:39.283Z,1406593719.283 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:39.283Z,1406593719.283 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:39.283Z,1406593719.283 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:39.283Z,1406593719.283 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:39.735Z,1406593719.735 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:39.735Z,1406593719.735 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:39.735Z,1406593719.735 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:39.736Z,1406593719.736 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:39.736Z,1406593719.736 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:40.139Z,1406593720.139 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:40.139Z,1406593720.139 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:40.139Z,1406593720.139 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:40.139Z,1406593720.139 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:40.624Z,1406593720.624 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:40.624Z,1406593720.624 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:40.624Z,1406593720.624 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:40.629Z,1406593720.629 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:40.629Z,1406593720.629 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:41.043Z,1406593721.043 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:41.043Z,1406593721.043 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:41.043Z,1406593721.043 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:41.043Z,1406593721.043 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:41.456Z,1406593721.456 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:41.456Z,1406593721.456 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:41.456Z,1406593721.456 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:41.457Z,1406593721.457 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:41.457Z,1406593721.457 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:41.872Z,1406593721.872 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:41.872Z,1406593721.872 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:41.872Z,1406593721.872 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:41.872Z,1406593721.872 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:42.328Z,1406593722.328 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:42.328Z,1406593722.328 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:42.328Z,1406593722.328 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:42.329Z,1406593722.329 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:42.329Z,1406593722.329 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:42.771Z,1406593722.771 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:42.771Z,1406593722.771 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:42.771Z,1406593722.771 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:42.772Z,1406593722.772 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:43.279Z,1406593723.279 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:43.279Z,1406593723.279 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:43.279Z,1406593723.279 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:43.280Z,1406593723.280 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:43.280Z,1406593723.280 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:43.732Z,1406593723.732 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:43.732Z,1406593723.732 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:43.732Z,1406593723.732 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:43.732Z,1406593723.732 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:44.131Z,1406593724.131 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:44.131Z,1406593724.131 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:44.131Z,1406593724.131 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:44.132Z,1406593724.132 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:44.132Z,1406593724.132 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:44.528Z,1406593724.528 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-07-29T00:28:44.529Z,1406593724.529 [DVL_micro] Data Fault, FailCount= 1
2014-07-29T00:28:44.529Z,1406593724.529 [DVL_micro](ERROR): Data Fault
2014-07-29T00:28:44.593Z,1406593724.593 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:44.593Z,1406593724.593 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:44.593Z,1406593724.593 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:44.593Z,1406593724.593 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:44.611Z,1406593724.611 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-07-29T00:28:44.986Z,1406593724.986 [DVL_micro](INFO): uninitialize:Powering down
2014-07-29T00:28:45.016Z,1406593725.016 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:45.016Z,1406593725.016 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:45.016Z,1406593725.016 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:45.017Z,1406593725.017 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:45.017Z,1406593725.017 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:45.430Z,1406593725.430 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-07-29T00:28:45.430Z,1406593725.430 [DVL_micro] Hardware Fault, FailCount= 1
2014-07-29T00:28:45.430Z,1406593725.430 [DVL_micro](ERROR): Hardware Fault
2014-07-29T00:28:45.515Z,1406593725.515 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:45.515Z,1406593725.515 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:45.515Z,1406593725.515 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:45.515Z,1406593725.515 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:45.895Z,1406593725.895 [DVL_micro](INFO): Initializing
2014-07-29T00:28:45.939Z,1406593725.939 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:45.939Z,1406593725.939 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:45.939Z,1406593725.939 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:45.940Z,1406593725.940 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:45.940Z,1406593725.940 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:45.948Z,1406593725.948 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-07-29T00:28:45.949Z,1406593725.949 [DVL_micro] No Fault, FailCount= 1
2014-07-29T00:28:46.397Z,1406593726.397 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:46.397Z,1406593726.397 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:46.397Z,1406593726.397 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:46.397Z,1406593726.397 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:46.843Z,1406593726.843 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:46.843Z,1406593726.843 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:46.843Z,1406593726.843 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:46.844Z,1406593726.844 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:46.844Z,1406593726.844 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:47.249Z,1406593727.249 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:47.249Z,1406593727.249 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:47.249Z,1406593727.249 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:47.250Z,1406593727.250 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:47.701Z,1406593727.701 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:47.701Z,1406593727.701 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:47.701Z,1406593727.701 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:47.702Z,1406593727.702 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:47.702Z,1406593727.702 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:48.105Z,1406593728.105 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:48.105Z,1406593728.105 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:48.105Z,1406593728.105 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:48.105Z,1406593728.105 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:48.616Z,1406593728.616 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:48.616Z,1406593728.616 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:48.616Z,1406593728.616 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:48.617Z,1406593728.617 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:48.617Z,1406593728.617 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:49.085Z,1406593729.085 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:49.085Z,1406593729.085 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:49.085Z,1406593729.085 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:49.085Z,1406593729.085 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:49.528Z,1406593729.528 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:49.528Z,1406593729.528 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:49.528Z,1406593729.528 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:49.529Z,1406593729.529 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:49.529Z,1406593729.529 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:49.935Z,1406593729.935 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:49.935Z,1406593729.935 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:49.935Z,1406593729.935 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:49.935Z,1406593729.935 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:50.350Z,1406593730.350 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:50.351Z,1406593730.351 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:50.351Z,1406593730.351 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:50.352Z,1406593730.352 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:50.352Z,1406593730.352 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:50.781Z,1406593730.781 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:50.781Z,1406593730.781 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:50.781Z,1406593730.781 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:50.781Z,1406593730.781 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:51.228Z,1406593731.228 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:51.228Z,1406593731.228 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:51.228Z,1406593731.228 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:51.229Z,1406593731.229 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:51.229Z,1406593731.229 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:51.657Z,1406593731.657 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:51.657Z,1406593731.657 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:51.657Z,1406593731.657 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:51.657Z,1406593731.657 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:52.165Z,1406593732.165 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:52.166Z,1406593732.166 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:52.166Z,1406593732.166 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:52.171Z,1406593732.171 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:52.171Z,1406593732.171 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:52.605Z,1406593732.605 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:52.606Z,1406593732.606 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:52.606Z,1406593732.606 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:52.606Z,1406593732.606 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:53.030Z,1406593733.030 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:53.030Z,1406593733.030 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:53.030Z,1406593733.030 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:53.031Z,1406593733.031 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:53.031Z,1406593733.031 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:53.462Z,1406593733.462 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:53.462Z,1406593733.462 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:53.462Z,1406593733.462 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:53.462Z,1406593733.462 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:53.941Z,1406593733.941 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:53.941Z,1406593733.941 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:53.942Z,1406593733.942 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:53.942Z,1406593733.942 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:53.942Z,1406593733.942 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:54.390Z,1406593734.390 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:54.390Z,1406593734.390 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:54.390Z,1406593734.390 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:54.390Z,1406593734.390 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:54.841Z,1406593734.841 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:54.841Z,1406593734.841 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:54.841Z,1406593734.841 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:54.842Z,1406593734.842 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:54.842Z,1406593734.842 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:55.350Z,1406593735.350 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:55.350Z,1406593735.350 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:55.350Z,1406593735.350 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:55.350Z,1406593735.350 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:55.789Z,1406593735.789 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:55.789Z,1406593735.789 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:55.789Z,1406593735.789 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:55.790Z,1406593735.790 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:55.790Z,1406593735.790 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:56.272Z,1406593736.272 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:56.272Z,1406593736.272 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:56.272Z,1406593736.272 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:56.273Z,1406593736.273 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:56.714Z,1406593736.714 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:56.714Z,1406593736.714 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:56.714Z,1406593736.714 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:56.715Z,1406593736.715 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:56.715Z,1406593736.715 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:57.159Z,1406593737.159 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:57.160Z,1406593737.160 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:57.160Z,1406593737.160 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:57.160Z,1406593737.160 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:57.626Z,1406593737.626 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:57.626Z,1406593737.626 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:57.626Z,1406593737.626 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:57.627Z,1406593737.627 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:57.627Z,1406593737.627 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:58.066Z,1406593738.066 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:58.066Z,1406593738.066 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:58.066Z,1406593738.066 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:58.066Z,1406593738.066 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:58.555Z,1406593738.555 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:58.556Z,1406593738.556 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:58.556Z,1406593738.556 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:58.561Z,1406593738.561 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:58.561Z,1406593738.561 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:59.020Z,1406593739.020 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:59.021Z,1406593739.021 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:59.021Z,1406593739.021 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:59.021Z,1406593739.021 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:28:59.548Z,1406593739.548 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:28:59.548Z,1406593739.548 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:28:59.548Z,1406593739.548 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:28:59.549Z,1406593739.549 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:28:59.549Z,1406593739.549 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:28:59.974Z,1406593739.974 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:28:59.974Z,1406593739.974 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:28:59.974Z,1406593739.974 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:28:59.978Z,1406593739.978 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:00.403Z,1406593740.403 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:00.403Z,1406593740.403 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:00.403Z,1406593740.403 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:00.404Z,1406593740.404 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:00.404Z,1406593740.404 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:00.857Z,1406593740.857 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:00.857Z,1406593740.857 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:00.857Z,1406593740.857 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:00.857Z,1406593740.857 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:01.307Z,1406593741.307 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:01.308Z,1406593741.308 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:01.308Z,1406593741.308 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:01.309Z,1406593741.309 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:01.309Z,1406593741.309 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:01.795Z,1406593741.795 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:01.795Z,1406593741.795 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:01.795Z,1406593741.795 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:01.795Z,1406593741.795 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:02.268Z,1406593742.268 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:02.268Z,1406593742.268 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:02.268Z,1406593742.268 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:02.269Z,1406593742.269 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:02.269Z,1406593742.269 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:02.707Z,1406593742.707 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:02.708Z,1406593742.708 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:02.708Z,1406593742.708 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:02.708Z,1406593742.708 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:03.156Z,1406593743.156 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:03.156Z,1406593743.156 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:03.156Z,1406593743.156 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:03.157Z,1406593743.157 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:03.157Z,1406593743.157 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:03.571Z,1406593743.571 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:03.571Z,1406593743.571 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:03.571Z,1406593743.571 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:03.571Z,1406593743.571 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:04.011Z,1406593744.011 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:04.011Z,1406593744.011 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:04.011Z,1406593744.011 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:04.012Z,1406593744.012 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:04.012Z,1406593744.012 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:04.465Z,1406593744.465 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:04.465Z,1406593744.465 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:04.465Z,1406593744.465 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:04.465Z,1406593744.465 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:05.016Z,1406593745.016 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:05.016Z,1406593745.016 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:05.016Z,1406593745.016 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:05.017Z,1406593745.017 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:05.017Z,1406593745.017 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:05.477Z,1406593745.477 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:05.477Z,1406593745.477 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:05.477Z,1406593745.477 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:05.477Z,1406593745.477 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:05.923Z,1406593745.923 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:05.923Z,1406593745.923 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:05.928Z,1406593745.928 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:05.928Z,1406593745.928 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:05.929Z,1406593745.929 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:06.355Z,1406593746.355 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:06.355Z,1406593746.355 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:06.355Z,1406593746.355 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:06.355Z,1406593746.355 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:06.831Z,1406593746.831 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:06.832Z,1406593746.832 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:06.832Z,1406593746.832 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:06.832Z,1406593746.832 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:06.832Z,1406593746.832 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:07.289Z,1406593747.289 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:07.289Z,1406593747.289 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:07.290Z,1406593747.290 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:07.290Z,1406593747.290 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:07.707Z,1406593747.707 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:07.707Z,1406593747.707 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:07.707Z,1406593747.707 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:07.708Z,1406593747.708 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:07.708Z,1406593747.708 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:08.171Z,1406593748.171 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:08.171Z,1406593748.171 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:08.171Z,1406593748.171 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:08.175Z,1406593748.175 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:08.663Z,1406593748.663 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:08.663Z,1406593748.663 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:08.663Z,1406593748.663 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:08.664Z,1406593748.664 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:08.664Z,1406593748.664 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:09.098Z,1406593749.098 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:09.098Z,1406593749.098 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:09.099Z,1406593749.099 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:09.099Z,1406593749.099 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:09.563Z,1406593749.563 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:09.563Z,1406593749.563 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:09.563Z,1406593749.563 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:09.564Z,1406593749.564 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:09.564Z,1406593749.564 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:10.065Z,1406593750.065 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:10.065Z,1406593750.065 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:10.065Z,1406593750.065 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:10.065Z,1406593750.065 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:10.522Z,1406593750.522 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:10.522Z,1406593750.522 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:10.522Z,1406593750.522 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:10.523Z,1406593750.523 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:10.523Z,1406593750.523 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:10.939Z,1406593750.939 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:10.939Z,1406593750.939 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:10.939Z,1406593750.939 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:10.939Z,1406593750.939 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:11.423Z,1406593751.423 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:11.423Z,1406593751.423 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:11.423Z,1406593751.423 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:11.428Z,1406593751.428 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:11.428Z,1406593751.428 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:11.888Z,1406593751.888 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:11.888Z,1406593751.888 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:11.888Z,1406593751.888 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:11.888Z,1406593751.888 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:12.321Z,1406593752.321 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:12.321Z,1406593752.321 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:12.321Z,1406593752.321 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:12.322Z,1406593752.322 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:12.322Z,1406593752.322 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:12.774Z,1406593752.774 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:12.774Z,1406593752.774 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:12.774Z,1406593752.774 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:12.774Z,1406593752.774 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:13.226Z,1406593753.226 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:13.226Z,1406593753.226 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:13.227Z,1406593753.227 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:13.228Z,1406593753.228 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:13.228Z,1406593753.228 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:13.637Z,1406593753.637 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:13.637Z,1406593753.637 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:13.637Z,1406593753.637 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:13.637Z,1406593753.637 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:14.084Z,1406593754.084 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:14.084Z,1406593754.084 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:14.084Z,1406593754.084 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:14.085Z,1406593754.085 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:14.085Z,1406593754.085 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:14.553Z,1406593754.553 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:14.554Z,1406593754.554 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:14.554Z,1406593754.554 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:14.554Z,1406593754.554 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:15.043Z,1406593755.043 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:15.043Z,1406593755.043 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:15.043Z,1406593755.043 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:15.044Z,1406593755.044 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:15.044Z,1406593755.044 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:15.540Z,1406593755.540 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:15.541Z,1406593755.541 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:15.541Z,1406593755.541 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:15.541Z,1406593755.541 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:15.999Z,1406593755.999 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:15.000Z,1406593756.000 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:15.000Z,1406593756.000 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:16.000Z,1406593756.000 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:16.001Z,1406593756.001 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:16.448Z,1406593756.448 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:16.449Z,1406593756.449 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:16.449Z,1406593756.449 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:16.449Z,1406593756.449 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:16.872Z,1406593756.872 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:16.872Z,1406593756.872 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:16.872Z,1406593756.872 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:16.901Z,1406593756.901 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:16.901Z,1406593756.901 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:17.304Z,1406593757.304 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:17.304Z,1406593757.304 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:17.304Z,1406593757.304 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:17.304Z,1406593757.304 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:17.778Z,1406593757.778 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:17.778Z,1406593757.778 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:17.778Z,1406593757.778 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:17.779Z,1406593757.779 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:17.779Z,1406593757.779 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:18.212Z,1406593758.212 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:18.212Z,1406593758.212 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:18.212Z,1406593758.212 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:18.213Z,1406593758.213 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:18.681Z,1406593758.681 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:18.681Z,1406593758.681 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:18.681Z,1406593758.681 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:18.682Z,1406593758.682 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:18.682Z,1406593758.682 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:19.119Z,1406593759.119 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:19.119Z,1406593759.119 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:19.119Z,1406593759.119 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:19.119Z,1406593759.119 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:19.610Z,1406593759.610 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:19.610Z,1406593759.610 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:19.610Z,1406593759.610 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:19.611Z,1406593759.611 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:19.611Z,1406593759.611 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:20.037Z,1406593760.037 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:20.037Z,1406593760.037 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:20.037Z,1406593760.037 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:20.037Z,1406593760.037 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:20.530Z,1406593760.530 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:20.530Z,1406593760.530 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:20.530Z,1406593760.530 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:20.531Z,1406593760.531 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:20.531Z,1406593760.531 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:21.010Z,1406593761.010 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:21.011Z,1406593761.011 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:21.011Z,1406593761.011 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:21.015Z,1406593761.015 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:21.459Z,1406593761.459 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:21.459Z,1406593761.459 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:21.459Z,1406593761.459 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:21.460Z,1406593761.460 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:21.460Z,1406593761.460 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:21.943Z,1406593761.943 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:21.943Z,1406593761.943 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:21.943Z,1406593761.943 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:21.943Z,1406593761.943 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:22.400Z,1406593762.400 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:22.400Z,1406593762.400 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:22.400Z,1406593762.400 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:22.401Z,1406593762.401 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:22.401Z,1406593762.401 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:22.852Z,1406593762.852 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:22.852Z,1406593762.852 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:22.852Z,1406593762.852 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:22.852Z,1406593762.852 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:23.268Z,1406593763.268 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:23.268Z,1406593763.268 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:23.268Z,1406593763.268 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:23.269Z,1406593763.269 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:23.269Z,1406593763.269 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:23.709Z,1406593763.709 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:23.710Z,1406593763.710 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:23.710Z,1406593763.710 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:23.710Z,1406593763.710 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:24.163Z,1406593764.163 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:24.168Z,1406593764.168 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:24.168Z,1406593764.168 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:24.169Z,1406593764.169 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:24.169Z,1406593764.169 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:24.613Z,1406593764.613 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:24.613Z,1406593764.613 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:24.613Z,1406593764.613 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:24.613Z,1406593764.613 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:25.089Z,1406593765.089 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:25.089Z,1406593765.089 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:25.117Z,1406593765.117 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:25.118Z,1406593765.118 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:25.118Z,1406593765.118 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:25.627Z,1406593765.627 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:25.627Z,1406593765.627 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:25.627Z,1406593765.627 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:25.627Z,1406593765.627 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:26.068Z,1406593766.068 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:26.068Z,1406593766.068 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:26.068Z,1406593766.068 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:26.069Z,1406593766.069 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:26.069Z,1406593766.069 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:26.506Z,1406593766.506 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:26.506Z,1406593766.506 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:26.506Z,1406593766.506 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:26.506Z,1406593766.506 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:26.938Z,1406593766.938 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:26.938Z,1406593766.938 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:26.938Z,1406593766.938 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:26.939Z,1406593766.939 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:26.939Z,1406593766.939 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:27.416Z,1406593767.416 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:27.416Z,1406593767.416 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:27.416Z,1406593767.416 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:27.416Z,1406593767.416 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:27.887Z,1406593767.887 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:27.887Z,1406593767.887 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:27.887Z,1406593767.887 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:27.888Z,1406593767.888 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:27.888Z,1406593767.888 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:28.332Z,1406593768.332 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:28.332Z,1406593768.332 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:28.333Z,1406593768.333 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:28.333Z,1406593768.333 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:28.827Z,1406593768.827 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:28.827Z,1406593768.827 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:28.828Z,1406593768.828 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:28.828Z,1406593768.828 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:28.828Z,1406593768.828 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:29.279Z,1406593769.279 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:29.279Z,1406593769.279 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:29.279Z,1406593769.279 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:29.279Z,1406593769.279 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:29.695Z,1406593769.695 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:29.695Z,1406593769.695 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:29.696Z,1406593769.696 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:29.696Z,1406593769.696 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:29.696Z,1406593769.696 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:30.128Z,1406593770.128 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:30.128Z,1406593770.128 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:30.128Z,1406593770.128 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:30.128Z,1406593770.128 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:30.605Z,1406593770.605 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:30.606Z,1406593770.606 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:30.606Z,1406593770.606 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:30.607Z,1406593770.607 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:30.607Z,1406593770.607 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:31.119Z,1406593771.119 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:31.119Z,1406593771.119 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:31.119Z,1406593771.119 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:31.119Z,1406593771.119 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:31.567Z,1406593771.567 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:31.567Z,1406593771.567 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:31.567Z,1406593771.567 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:31.568Z,1406593771.568 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:31.568Z,1406593771.568 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:32.056Z,1406593772.056 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:32.056Z,1406593772.056 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:32.056Z,1406593772.056 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:32.056Z,1406593772.056 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:32.485Z,1406593772.485 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:32.485Z,1406593772.485 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:32.486Z,1406593772.486 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:32.486Z,1406593772.486 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:32.486Z,1406593772.486 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:32.925Z,1406593772.925 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:32.925Z,1406593772.925 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:32.925Z,1406593772.925 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:32.926Z,1406593772.926 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:33.380Z,1406593773.380 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:33.380Z,1406593773.380 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:33.380Z,1406593773.380 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:33.381Z,1406593773.381 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:33.381Z,1406593773.381 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:33.873Z,1406593773.873 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:33.873Z,1406593773.873 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:33.873Z,1406593773.873 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:33.873Z,1406593773.873 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:34.267Z,1406593774.267 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:34.267Z,1406593774.267 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:34.267Z,1406593774.267 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:34.284Z,1406593774.284 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:34.284Z,1406593774.284 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:34.737Z,1406593774.737 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:34.737Z,1406593774.737 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:34.737Z,1406593774.737 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:34.737Z,1406593774.737 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:35.210Z,1406593775.210 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:35.210Z,1406593775.210 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:35.210Z,1406593775.210 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:35.211Z,1406593775.211 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:35.211Z,1406593775.211 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:35.624Z,1406593775.624 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:35.624Z,1406593775.624 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:35.624Z,1406593775.624 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:35.625Z,1406593775.625 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:36.154Z,1406593776.154 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:36.154Z,1406593776.154 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:36.154Z,1406593776.154 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:36.155Z,1406593776.155 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:36.155Z,1406593776.155 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:36.610Z,1406593776.610 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:36.610Z,1406593776.610 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:36.610Z,1406593776.610 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:36.610Z,1406593776.610 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:37.091Z,1406593777.091 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:37.091Z,1406593777.091 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:37.091Z,1406593777.091 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:37.092Z,1406593777.092 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:37.092Z,1406593777.092 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:37.540Z,1406593777.540 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:37.540Z,1406593777.540 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:37.540Z,1406593777.540 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:37.565Z,1406593777.565 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:37.987Z,1406593777.987 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:37.987Z,1406593777.987 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:37.987Z,1406593777.987 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:37.988Z,1406593777.988 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:37.988Z,1406593777.988 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:38.400Z,1406593778.400 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:38.400Z,1406593778.400 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:38.400Z,1406593778.400 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:38.400Z,1406593778.400 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:38.901Z,1406593778.901 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:38.902Z,1406593778.902 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:38.902Z,1406593778.902 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:38.902Z,1406593778.902 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:38.902Z,1406593778.902 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:39.316Z,1406593779.316 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:39.317Z,1406593779.317 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:39.317Z,1406593779.317 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:39.317Z,1406593779.317 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:39.772Z,1406593779.772 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:39.772Z,1406593779.772 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:39.772Z,1406593779.772 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:39.773Z,1406593779.773 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:39.773Z,1406593779.773 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:40.260Z,1406593780.260 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:40.260Z,1406593780.260 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:40.260Z,1406593780.260 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:40.260Z,1406593780.260 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:40.719Z,1406593780.719 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:40.719Z,1406593780.719 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:40.719Z,1406593780.719 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:40.719Z,1406593780.719 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:40.720Z,1406593780.720 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:41.127Z,1406593781.127 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:41.128Z,1406593781.128 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:41.128Z,1406593781.128 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:41.128Z,1406593781.128 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:41.646Z,1406593781.646 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:41.646Z,1406593781.646 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:41.646Z,1406593781.646 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:41.647Z,1406593781.647 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:41.647Z,1406593781.647 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:42.123Z,1406593782.123 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:42.123Z,1406593782.123 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:42.123Z,1406593782.123 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:42.123Z,1406593782.123 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:42.544Z,1406593782.544 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:42.544Z,1406593782.544 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:42.545Z,1406593782.545 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:42.545Z,1406593782.545 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:42.545Z,1406593782.545 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:42.988Z,1406593782.988 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:42.988Z,1406593782.988 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:42.988Z,1406593782.988 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:42.988Z,1406593782.988 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:43.488Z,1406593783.488 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:43.488Z,1406593783.488 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:43.488Z,1406593783.488 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:43.489Z,1406593783.489 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:43.489Z,1406593783.489 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:43.901Z,1406593783.901 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:43.901Z,1406593783.901 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:43.901Z,1406593783.901 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:43.901Z,1406593783.901 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:44.330Z,1406593784.330 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:44.330Z,1406593784.330 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:44.331Z,1406593784.331 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:44.356Z,1406593784.356 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:44.356Z,1406593784.356 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:44.771Z,1406593784.771 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:44.771Z,1406593784.771 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:44.771Z,1406593784.771 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:44.771Z,1406593784.771 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:45.232Z,1406593785.232 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:45.232Z,1406593785.232 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:45.232Z,1406593785.232 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:45.233Z,1406593785.233 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:45.233Z,1406593785.233 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:45.697Z,1406593785.697 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:45.697Z,1406593785.697 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:45.697Z,1406593785.697 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:45.697Z,1406593785.697 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:46.139Z,1406593786.139 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:46.139Z,1406593786.139 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:46.139Z,1406593786.139 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:46.140Z,1406593786.140 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:46.140Z,1406593786.140 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:46.684Z,1406593786.684 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:46.684Z,1406593786.684 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:46.684Z,1406593786.684 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:46.684Z,1406593786.684 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:47.108Z,1406593787.108 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:47.108Z,1406593787.108 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:47.108Z,1406593787.108 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:47.109Z,1406593787.109 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:47.109Z,1406593787.109 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:47.552Z,1406593787.552 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:47.553Z,1406593787.553 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:47.553Z,1406593787.553 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:47.553Z,1406593787.553 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:47.966Z,1406593787.966 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:47.966Z,1406593787.966 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:47.966Z,1406593787.966 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:47.967Z,1406593787.967 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:47.967Z,1406593787.967 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:48.450Z,1406593788.450 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:48.450Z,1406593788.450 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:48.450Z,1406593788.450 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:48.450Z,1406593788.450 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:48.911Z,1406593788.911 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:48.912Z,1406593788.912 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:48.912Z,1406593788.912 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:48.913Z,1406593788.913 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:48.913Z,1406593788.913 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:49.364Z,1406593789.364 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:49.364Z,1406593789.364 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:49.364Z,1406593789.364 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:49.364Z,1406593789.364 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:49.856Z,1406593789.856 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:49.856Z,1406593789.856 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:49.856Z,1406593789.856 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:49.857Z,1406593789.857 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:49.857Z,1406593789.857 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:50.282Z,1406593790.282 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:50.282Z,1406593790.282 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:50.282Z,1406593790.282 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:50.282Z,1406593790.282 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:50.734Z,1406593790.734 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:50.734Z,1406593790.734 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:50.735Z,1406593790.735 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:50.735Z,1406593790.735 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:50.735Z,1406593790.735 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:51.157Z,1406593791.157 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:51.174Z,1406593791.174 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:51.174Z,1406593791.174 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:51.174Z,1406593791.174 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:51.618Z,1406593791.618 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:51.619Z,1406593791.619 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:51.619Z,1406593791.619 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:51.619Z,1406593791.619 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:51.619Z,1406593791.619 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:52.160Z,1406593792.160 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:52.161Z,1406593792.161 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:52.161Z,1406593792.161 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:52.161Z,1406593792.161 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:52.619Z,1406593792.619 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:52.619Z,1406593792.619 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:52.620Z,1406593792.620 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:52.620Z,1406593792.620 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:52.620Z,1406593792.620 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:53.072Z,1406593793.072 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:53.072Z,1406593793.072 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:53.072Z,1406593793.072 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:53.072Z,1406593793.072 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:53.495Z,1406593793.495 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:53.496Z,1406593793.496 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:53.496Z,1406593793.496 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:53.496Z,1406593793.496 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:53.496Z,1406593793.496 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:53.941Z,1406593793.941 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:53.941Z,1406593793.941 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:53.941Z,1406593793.941 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:53.941Z,1406593793.941 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:54.400Z,1406593794.400 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:54.400Z,1406593794.400 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:54.400Z,1406593794.400 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:54.401Z,1406593794.401 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:54.401Z,1406593794.401 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:54.847Z,1406593794.847 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:54.847Z,1406593794.847 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:54.848Z,1406593794.848 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:54.848Z,1406593794.848 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:55.347Z,1406593795.347 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:55.348Z,1406593795.348 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:55.348Z,1406593795.348 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:55.349Z,1406593795.349 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:55.349Z,1406593795.349 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:55.770Z,1406593795.770 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:55.770Z,1406593795.770 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:55.771Z,1406593795.771 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:55.771Z,1406593795.771 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:56.263Z,1406593796.263 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:56.263Z,1406593796.263 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:56.264Z,1406593796.264 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:56.264Z,1406593796.264 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:56.264Z,1406593796.264 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:56.690Z,1406593796.690 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:56.690Z,1406593796.690 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:56.690Z,1406593796.690 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:56.691Z,1406593796.691 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:57.191Z,1406593797.191 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:57.191Z,1406593797.191 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:57.192Z,1406593797.192 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:57.192Z,1406593797.192 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:57.192Z,1406593797.192 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:57.639Z,1406593797.639 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:57.639Z,1406593797.639 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:57.639Z,1406593797.639 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:57.639Z,1406593797.639 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:58.096Z,1406593798.096 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:58.096Z,1406593798.096 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:58.096Z,1406593798.096 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:58.097Z,1406593798.097 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:58.097Z,1406593798.097 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:58.587Z,1406593798.587 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:58.588Z,1406593798.588 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:58.588Z,1406593798.588 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:58.588Z,1406593798.588 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:59.000Z,1406593799.000 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:59.000Z,1406593799.000 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:59.001Z,1406593799.001 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:59.001Z,1406593799.001 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:59.001Z,1406593799.001 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:29:59.470Z,1406593799.470 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:29:59.470Z,1406593799.470 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:29:59.470Z,1406593799.470 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:29:59.470Z,1406593799.470 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:29:59.901Z,1406593799.901 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:29:59.901Z,1406593799.901 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:29:59.901Z,1406593799.901 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:29:59.902Z,1406593799.902 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:29:59.902Z,1406593799.902 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:00.328Z,1406593800.328 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:00.328Z,1406593800.328 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:00.328Z,1406593800.328 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:00.328Z,1406593800.328 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:00.805Z,1406593800.805 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:00.805Z,1406593800.805 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:00.806Z,1406593800.806 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:00.806Z,1406593800.806 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:00.806Z,1406593800.806 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:01.262Z,1406593801.262 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:01.262Z,1406593801.262 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:01.262Z,1406593801.262 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:01.262Z,1406593801.262 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:01.774Z,1406593801.774 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:01.774Z,1406593801.774 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:01.783Z,1406593801.783 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:01.784Z,1406593801.784 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:01.784Z,1406593801.784 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:02.408Z,1406593802.408 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:02.408Z,1406593802.408 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:02.408Z,1406593802.408 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:02.408Z,1406593802.408 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:02.955Z,1406593802.955 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:02.955Z,1406593802.955 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:02.955Z,1406593802.955 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:02.956Z,1406593802.956 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:02.964Z,1406593802.964 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:03.417Z,1406593803.417 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:03.418Z,1406593803.418 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:03.418Z,1406593803.418 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:03.418Z,1406593803.418 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:03.980Z,1406593803.980 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:03.981Z,1406593803.981 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:03.981Z,1406593803.981 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:03.981Z,1406593803.981 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:03.986Z,1406593803.986 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:04.515Z,1406593804.515 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:04.515Z,1406593804.515 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:04.516Z,1406593804.516 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:04.516Z,1406593804.516 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:05.059Z,1406593805.059 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:05.059Z,1406593805.059 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:05.063Z,1406593805.063 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:05.064Z,1406593805.064 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:05.064Z,1406593805.064 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:05.603Z,1406593805.603 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:05.603Z,1406593805.603 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:05.604Z,1406593805.604 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:05.604Z,1406593805.604 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:06.285Z,1406593806.285 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:06.285Z,1406593806.285 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:06.292Z,1406593806.292 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:06.314Z,1406593806.314 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:06.314Z,1406593806.314 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:06.881Z,1406593806.881 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:06.882Z,1406593806.882 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:06.882Z,1406593806.882 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:06.918Z,1406593806.918 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:07.570Z,1406593807.570 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:07.571Z,1406593807.571 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:07.571Z,1406593807.571 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:07.572Z,1406593807.572 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:07.572Z,1406593807.572 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:08.167Z,1406593808.167 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:08.167Z,1406593808.167 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:08.168Z,1406593808.168 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:08.168Z,1406593808.168 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:08.815Z,1406593808.815 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:08.815Z,1406593808.815 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:08.815Z,1406593808.815 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:08.815Z,1406593808.815 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:08.816Z,1406593808.816 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:09.340Z,1406593809.340 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:09.341Z,1406593809.341 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:09.341Z,1406593809.341 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:09.341Z,1406593809.341 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:09.921Z,1406593809.921 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:09.921Z,1406593809.921 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:09.921Z,1406593809.921 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:09.921Z,1406593809.921 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:09.922Z,1406593809.922 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:10.426Z,1406593810.426 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:10.426Z,1406593810.426 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:10.426Z,1406593810.426 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:10.426Z,1406593810.426 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:11.011Z,1406593811.011 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:11.011Z,1406593811.011 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:11.011Z,1406593811.011 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:11.012Z,1406593811.012 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:11.012Z,1406593811.012 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:11.540Z,1406593811.540 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:11.540Z,1406593811.540 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:11.540Z,1406593811.540 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:11.540Z,1406593811.540 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:12.171Z,1406593812.171 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:12.171Z,1406593812.171 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:12.171Z,1406593812.171 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:12.172Z,1406593812.172 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:12.172Z,1406593812.172 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:12.687Z,1406593812.687 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:12.687Z,1406593812.687 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:12.688Z,1406593812.688 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:12.688Z,1406593812.688 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:13.413Z,1406593813.413 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:13.414Z,1406593813.414 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:13.414Z,1406593813.414 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:13.415Z,1406593813.415 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:13.415Z,1406593813.415 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:13.907Z,1406593813.907 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:13.907Z,1406593813.907 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:13.907Z,1406593813.907 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:13.907Z,1406593813.907 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:14.433Z,1406593814.433 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:14.433Z,1406593814.433 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:14.433Z,1406593814.433 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:14.437Z,1406593814.437 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:14.437Z,1406593814.437 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:15.099Z,1406593815.099 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:15.099Z,1406593815.099 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:15.099Z,1406593815.099 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:15.100Z,1406593815.100 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:15.637Z,1406593815.637 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:15.637Z,1406593815.637 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:15.637Z,1406593815.637 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:15.638Z,1406593815.638 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:15.638Z,1406593815.638 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:16.138Z,1406593816.138 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:16.138Z,1406593816.138 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:16.138Z,1406593816.138 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:16.138Z,1406593816.138 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:16.788Z,1406593816.788 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:16.789Z,1406593816.789 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:16.789Z,1406593816.789 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:16.789Z,1406593816.789 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:16.790Z,1406593816.790 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:17.274Z,1406593817.274 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:17.274Z,1406593817.274 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:17.274Z,1406593817.274 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:17.274Z,1406593817.274 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:17.809Z,1406593817.809 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:17.809Z,1406593817.809 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:17.809Z,1406593817.809 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:17.810Z,1406593817.810 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:17.810Z,1406593817.810 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:18.474Z,1406593818.474 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:18.474Z,1406593818.474 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:18.474Z,1406593818.474 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:18.474Z,1406593818.474 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:18.979Z,1406593818.979 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:18.979Z,1406593818.979 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:18.979Z,1406593818.979 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:18.980Z,1406593818.980 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:18.980Z,1406593818.980 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:19.532Z,1406593819.532 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:19.532Z,1406593819.532 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:19.532Z,1406593819.532 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:19.532Z,1406593819.532 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:20.136Z,1406593820.136 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:20.137Z,1406593820.137 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:20.137Z,1406593820.137 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:20.137Z,1406593820.137 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:20.138Z,1406593820.138 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:20.630Z,1406593820.630 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:20.631Z,1406593820.631 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:20.631Z,1406593820.631 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:20.631Z,1406593820.631 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:21.150Z,1406593821.150 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:21.150Z,1406593821.150 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:21.150Z,1406593821.150 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:21.150Z,1406593821.150 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:21.151Z,1406593821.151 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:21.751Z,1406593821.751 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:21.751Z,1406593821.751 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:21.751Z,1406593821.751 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:21.752Z,1406593821.752 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:22.261Z,1406593822.261 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:22.261Z,1406593822.261 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:22.261Z,1406593822.261 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:22.270Z,1406593822.270 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:22.270Z,1406593822.270 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:22.804Z,1406593822.804 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:22.804Z,1406593822.804 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:22.804Z,1406593822.804 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:22.804Z,1406593822.804 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:23.524Z,1406593823.524 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:23.533Z,1406593823.533 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:23.533Z,1406593823.533 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:23.534Z,1406593823.534 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:23.534Z,1406593823.534 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:24.061Z,1406593824.061 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:24.061Z,1406593824.061 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:24.061Z,1406593824.061 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:24.062Z,1406593824.062 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:24.573Z,1406593824.573 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:24.573Z,1406593824.573 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:24.573Z,1406593824.573 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:24.578Z,1406593824.578 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:24.578Z,1406593824.578 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:25.157Z,1406593825.157 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:25.157Z,1406593825.157 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:25.158Z,1406593825.158 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:25.158Z,1406593825.158 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:25.686Z,1406593825.686 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:25.686Z,1406593825.686 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:25.686Z,1406593825.686 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:25.687Z,1406593825.687 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:25.721Z,1406593825.721 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:26.271Z,1406593826.271 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:26.272Z,1406593826.272 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:26.274Z,1406593826.274 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:26.274Z,1406593826.274 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:26.952Z,1406593826.952 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:26.952Z,1406593826.952 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:26.952Z,1406593826.952 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:26.953Z,1406593826.953 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:26.958Z,1406593826.958 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:27.468Z,1406593827.468 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:27.470Z,1406593827.470 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:27.470Z,1406593827.470 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:27.472Z,1406593827.472 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:28.094Z,1406593828.094 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:28.094Z,1406593828.094 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:28.094Z,1406593828.094 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:28.120Z,1406593828.120 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:28.120Z,1406593828.120 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:28.935Z,1406593828.935 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:28.935Z,1406593828.935 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:28.935Z,1406593828.935 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:28.935Z,1406593828.935 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:29.519Z,1406593829.519 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:29.521Z,1406593829.521 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:29.521Z,1406593829.521 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:29.527Z,1406593829.527 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:29.527Z,1406593829.527 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:30.210Z,1406593830.210 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:30.210Z,1406593830.210 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:30.216Z,1406593830.216 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:30.216Z,1406593830.216 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:30.789Z,1406593830.789 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:30.790Z,1406593830.790 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:30.790Z,1406593830.790 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:30.791Z,1406593830.791 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:30.791Z,1406593830.791 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:31.395Z,1406593831.395 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:31.395Z,1406593831.395 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:31.395Z,1406593831.395 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:31.397Z,1406593831.397 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:31.959Z,1406593831.959 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:31.959Z,1406593831.959 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:31.959Z,1406593831.959 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:31.960Z,1406593831.960 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:31.960Z,1406593831.960 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:32.594Z,1406593832.594 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:32.594Z,1406593832.594 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:32.594Z,1406593832.594 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:32.595Z,1406593832.595 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:33.148Z,1406593833.148 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:33.148Z,1406593833.148 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:33.148Z,1406593833.148 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:33.151Z,1406593833.151 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:33.151Z,1406593833.151 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:33.828Z,1406593833.828 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:33.828Z,1406593833.828 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:33.828Z,1406593833.828 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:33.828Z,1406593833.828 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:34.407Z,1406593834.407 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:34.407Z,1406593834.407 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:34.408Z,1406593834.408 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:34.430Z,1406593834.430 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:34.430Z,1406593834.430 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:35.093Z,1406593835.093 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:35.094Z,1406593835.094 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:35.094Z,1406593835.094 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:35.096Z,1406593835.096 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:35.728Z,1406593835.728 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:30:35.728Z,1406593835.728 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:30:35.730Z,1406593835.730 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:30:35.733Z,1406593835.733 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:30:35.733Z,1406593835.733 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:30:36.330Z,1406593836.330 [dat_on:TestDrive:C.Wait](INFO): Done Waiting.
2014-07-29T00:30:36.330Z,1406593836.330 [dat_on:TestDrive:C.Wait] Stopped
2014-07-29T00:30:36.330Z,1406593836.330 [dat_on:TestDrive:C.Wait](DEBUG): Uninitialize Wait Component.
2014-07-29T00:30:36.331Z,1406593836.331 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:30:36.331Z,1406593836.331 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:30:36.331Z,1406593836.331 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:30:36.331Z,1406593836.331 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:30:36.331Z,1406593836.331 [dat_on:TestDrive](INFO): Completed dat_on:TestDrive
2014-07-29T00:30:36.331Z,1406593836.331 [dat_on:TestDrive] Stopped
2014-07-29T00:30:36.333Z,1406593836.333 [dat_on:TestDrive](INFO): Aggregate::uninitialize dat_on:TestDrive
2014-07-29T00:30:36.333Z,1406593836.333 [dat_on:TestDrive:A] Stopped
2014-07-29T00:30:36.335Z,1406593836.335 [dat_on](INFO): Completed dat_on
2014-07-29T00:30:36.335Z,1406593836.335 [dat_on] Stopped
2014-07-29T00:30:36.337Z,1406593836.337 [dat_on](INFO): Aggregate::uninitialize dat_on
2014-07-29T00:30:36.337Z,1406593836.337 [dat_on:A.Pitch] Stopped
2014-07-29T00:30:36.902Z,1406593836.902 [MissionManager](IMPORTANT): Started mission Default
2014-07-29T00:30:36.903Z,1406593836.903 [Default] Running Loop=1
2014-07-29T00:30:36.903Z,1406593836.903 [Default](INFO): Aggregate::initialize Default
2014-07-29T00:30:36.909Z,1406593836.909 [Default:Iridium] Running Loop=1
2014-07-29T00:30:36.911Z,1406593836.911 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-07-29T00:30:36.911Z,1406593836.911 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-07-29T00:30:36.911Z,1406593836.911 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-07-29T00:30:36.911Z,1406593836.911 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-07-29T00:30:36.911Z,1406593836.911 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:30:36.913Z,1406593836.913 [Default:Iridium:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-07-29T00:30:36.915Z,1406593836.915 [Default:Iridium:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-07-29T00:30:36.915Z,1406593836.915 [Default:Iridium:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-07-29T00:30:36.917Z,1406593836.917 [Default:CallIridium] Running Loop=1
2014-07-29T00:30:36.918Z,1406593836.918 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-07-29T00:30:36.918Z,1406593836.918 [Default:CallIridium:A] Running Loop=1
2014-07-29T00:30:36.920Z,1406593836.920 [Default:CallIridium:A] Stopped
2014-07-29T00:30:36.920Z,1406593836.920 [Default:CallIridium:B] Running Loop=1
2014-07-29T00:30:36.920Z,1406593836.920 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-07-29T00:30:36.946Z,1406593836.946 [Default:Iridium:Read_Iridium] Running Loop=1
2014-07-29T00:30:36.946Z,1406593836.946 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-07-29T00:30:36.986Z,1406593836.986 [Default:GPS] Running Loop=1
2014-07-29T00:30:36.986Z,1406593836.986 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-07-29T00:30:36.987Z,1406593836.987 [Default:GPS:A.SetSpeed] Running Loop=1
2014-07-29T00:30:36.987Z,1406593836.987 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-07-29T00:30:36.987Z,1406593836.987 [Default:GPS:B.GoToSurface] Running Loop=1
2014-07-29T00:30:36.987Z,1406593836.987 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:30:36.987Z,1406593836.987 [Default:GPS:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-07-29T00:30:36.988Z,1406593836.988 [Default:GPS:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-07-29T00:30:36.988Z,1406593836.988 [Default:GPS:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-07-29T00:30:37.045Z,1406593837.045 [Default:GPS:Read_GPS] Running Loop=1
2014-07-29T00:30:37.045Z,1406593837.045 [Default:GPS:A.SetSpeed] Running Loop=1
2014-07-29T00:30:37.621Z,1406593837.621 [DAT](INFO): Powering down
2014-07-29T00:30:37.717Z,1406593837.717 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-07-29T00:30:37.724Z,1406593837.724 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-07-29T00:30:56.618Z,1406593856.618 [DVL_micro](ERROR): No DVL communication! Re-initializing
2014-07-29T00:30:56.618Z,1406593856.618 [DVL_micro] Communications Fault, FailCount= 1
2014-07-29T00:30:56.618Z,1406593856.618 [DVL_micro](ERROR): Communications Fault
2014-07-29T00:30:56.708Z,1406593856.708 [CBIT](ERROR): Communications Fault in component: DVL_micro
2014-07-29T00:30:57.066Z,1406593857.066 [DVL_micro](INFO): uninitialize:Powering down
2014-07-29T00:30:57.515Z,1406593857.515 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-07-29T00:30:57.515Z,1406593857.515 [DVL_micro] Hardware Fault, FailCount= 1
2014-07-29T00:30:57.515Z,1406593857.515 [DVL_micro](ERROR): Hardware Fault
2014-07-29T00:30:58.014Z,1406593858.014 [DVL_micro](INFO): Initializing
2014-07-29T00:30:58.098Z,1406593858.098 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-07-29T00:30:58.098Z,1406593858.098 [DVL_micro] No Fault, FailCount= 1
2014-07-29T00:31:50.765Z,1406593910.765 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-07-29T00:31:50.765Z,1406593910.765 [DVL_micro] Data Fault, FailCount= 1
2014-07-29T00:31:50.765Z,1406593910.765 [DVL_micro](ERROR): Data Fault
2014-07-29T00:31:50.867Z,1406593910.867 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-07-29T00:31:51.262Z,1406593911.262 [DVL_micro](INFO): uninitialize:Powering down
2014-07-29T00:31:51.691Z,1406593911.691 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-07-29T00:31:51.691Z,1406593911.691 [DVL_micro] Hardware Fault, FailCount= 1
2014-07-29T00:31:51.691Z,1406593911.691 [DVL_micro](ERROR): Hardware Fault
2014-07-29T00:31:52.126Z,1406593912.126 [DVL_micro](INFO): Initializing
2014-07-29T00:31:52.205Z,1406593912.205 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-07-29T00:31:52.205Z,1406593912.205 [DVL_micro] No Fault, FailCount= 1
2014-07-29T00:34:56.834Z,1406594096.834 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-07-29T00:34:56.834Z,1406594096.834 [DVL_micro] Data Fault, FailCount= 1
2014-07-29T00:34:56.834Z,1406594096.834 [DVL_micro](ERROR): Data Fault
2014-07-29T00:34:56.913Z,1406594096.913 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-07-29T00:34:57.275Z,1406594097.275 [DVL_micro](INFO): uninitialize:Powering down
2014-07-29T00:34:57.731Z,1406594097.731 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-07-29T00:34:57.731Z,1406594097.731 [DVL_micro] Hardware Fault, FailCount= 1
2014-07-29T00:34:57.731Z,1406594097.731 [DVL_micro](ERROR): Hardware Fault
2014-07-29T00:34:58.664Z,1406594098.664 [DVL_micro](INFO): Initializing
2014-07-29T00:34:59.731Z,1406594099.731 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-07-29T00:34:59.731Z,1406594099.731 [DVL_micro] No Fault, FailCount= 1
2014-07-29T00:35:48.440Z,1406594148.440 [NAL9602](FAULT): GPS failed to acquire within timeout.
2014-07-29T00:35:48.440Z,1406594148.440 [NAL9602] Data Fault, FailCount= 1
2014-07-29T00:35:48.440Z,1406594148.440 [NAL9602](ERROR): Data Fault
2014-07-29T00:35:48.563Z,1406594148.563 [CBIT](ERROR): Data Fault in component: NAL9602
2014-07-29T00:35:48.979Z,1406594148.979 [NAL9602](INFO): Powering down
2014-07-29T00:35:50.039Z,1406594150.039 [CBIT](INFO): Clearing failed state for component NAL9602
2014-07-29T00:35:50.039Z,1406594150.039 [NAL9602] No Fault, FailCount= 1
2014-07-29T00:35:54.292Z,1406594154.292 [NAL9602](INFO): Powering up NAL9602
2014-07-29T00:36:05.266Z,1406594165.266 [NAL9602](INFO): NAL9602 initialized
2014-07-29T00:38:04.721Z,1406594284.721 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-07-29T00:38:04.721Z,1406594284.721 [DVL_micro] Data Fault, FailCount= 1
2014-07-29T00:38:04.721Z,1406594284.721 [DVL_micro](ERROR): Data Fault
2014-07-29T00:38:04.854Z,1406594284.854 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-07-29T00:38:05.258Z,1406594285.258 [DVL_micro](INFO): uninitialize:Powering down
2014-07-29T00:38:05.791Z,1406594285.791 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-07-29T00:38:05.791Z,1406594285.791 [DVL_micro] Hardware Fault, FailCount= 1
2014-07-29T00:38:05.791Z,1406594285.791 [DVL_micro](ERROR): Hardware Fault
2014-07-29T00:38:06.291Z,1406594286.291 [DVL_micro](INFO): Initializing
2014-07-29T00:38:06.396Z,1406594286.396 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-07-29T00:38:06.396Z,1406594286.396 [DVL_micro] No Fault, FailCount= 1
2014-07-29T00:38:26.573Z,1406594306.573 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:89 Calculated:49
2014-07-29T00:38:26.574Z,1406594306.574 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 00 0 0 0 0 0 0 0 0 0 0 -118 -127 -180 -45 3 3 4 3 82.7 -109.4 -126.8 2 -133.1 33.2 -126.8 2 82 -109 -126 2 -133 33 -126 2 4.94 -0.36 218.9 -3.0 23.7 0.005 35.0 1489 89
2014-07-29T00:41:12.624Z,1406594472.624 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2014-07-29T00:41:12.625Z,1406594472.625 [DVL_micro] Data Fault, FailCount= 1
2014-07-29T00:41:12.625Z,1406594472.625 [DVL_micro](ERROR): Data Fault
2014-07-29T00:41:12.759Z,1406594472.759 [CBIT](ERROR): Data Fault in component: DVL_micro
2014-07-29T00:41:13.229Z,1406594473.229 [DVL_micro](INFO): uninitialize:Powering down
2014-07-29T00:41:13.722Z,1406594473.722 [DVL_micro](FAULT): LCB fault:  Software Overcurrent.
2014-07-29T00:41:13.722Z,1406594473.722 [DVL_micro] Hardware Fault, FailCount= 1
2014-07-29T00:41:13.722Z,1406594473.722 [DVL_micro](ERROR): Hardware Fault
2014-07-29T00:41:14.883Z,1406594474.883 [DVL_micro](INFO): Initializing
2014-07-29T00:41:17.229Z,1406594477.229 [CBIT](INFO): Clearing failed state for component DVL_micro
2014-07-29T00:41:17.229Z,1406594477.229 [DVL_micro] No Fault, FailCount= 1
2014-07-29T00:42:00.540Z,1406594520.540 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46
2014-07-29T00:42:00.541Z,1406594520.541 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -96 -150 -121 -134 3 3 4 3 33.4 -21.4 -135.1 2 -39.3 -5.4 -135.1 2 33 -21 -135 2 -39 2 4.92 -0.33 220.5 -3.0 23.7 0.005 35.0 1489 81
2014-07-29T00:42:56.689Z,1406594576.689 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/dat_on.xml
2014-07-29T00:42:56.690Z,1406594576.690 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/dat_on.xml
2014-07-29T00:42:56.725Z,1406594576.725 [MissionManager](INFO): DefineArg dat_on.MassDefault = 0.000000 n/a
2014-07-29T00:42:56.726Z,1406594576.726 [dat_on:A.Pitch](DEBUG): Construct.
2014-07-29T00:42:56.766Z,1406594576.766 [dat_on:TestDrive:C.Wait](DEBUG): Construct Wait.
2014-07-29T00:42:56.769Z,1406594576.769 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance"
       xmlns:Sensor="Tethys/Sensor" 
       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/Sensor http://aosn.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="dat_on">

    <DefineArg Name="MassDefault"><Control:VerticalControl.massDefault/></DefineArg>

    <Timeout Duration="P15M"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Aggregate Id="TestDrive">

        <Sequence/>

        <ReadData>
            <Sensor:DAT.range/>
        </ReadData>

        <Aggregate Id="Data">

            <When>
                <True/>
            </When>

            <SendData Service="Express">
                <Control:HorizontalControl.latitudeCmd/><Units:degree/>
                <Control:HorizontalControl.longitudeCmd/><Units:degree/>
            </SendData>

            <Syslog Severity="None">Pause a cycle</Syslog>

        </Aggregate>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>2</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2014-07-29T00:42:56.773Z,1406594576.773 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/dat_on.xml
2014-07-29T00:42:57.709Z,1406594577.709 [Default] Stopped
2014-07-29T00:42:57.710Z,1406594577.710 [Default](INFO): Aggregate::uninitialize Default
2014-07-29T00:42:57.710Z,1406594577.710 [Default:GPS] Stopped
2014-07-29T00:42:57.710Z,1406594577.710 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-07-29T00:42:57.710Z,1406594577.710 [Default:GPS:A.SetSpeed] Stopped
2014-07-29T00:42:57.710Z,1406594577.710 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-07-29T00:42:57.710Z,1406594577.710 [Default:GPS:B.GoToSurface] Stopped
2014-07-29T00:42:57.710Z,1406594577.710 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-07-29T00:42:57.710Z,1406594577.710 [Default:GPS:Read_GPS] Stopped
2014-07-29T00:42:57.710Z,1406594577.710 [Default:Iridium] Stopped
2014-07-29T00:42:57.710Z,1406594577.710 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-07-29T00:42:57.711Z,1406594577.711 [Default:Iridium:A.SetSpeed] Stopped
2014-07-29T00:42:57.711Z,1406594577.711 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-07-29T00:42:57.711Z,1406594577.711 [Default:Iridium:B.GoToSurface] Stopped
2014-07-29T00:42:57.711Z,1406594577.711 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-07-29T00:42:57.711Z,1406594577.711 [Default:Iridium:Read_Iridium] Stopped
2014-07-29T00:42:57.711Z,1406594577.711 [Default:CallIridium] Stopped
2014-07-29T00:42:57.711Z,1406594577.711 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-07-29T00:42:57.711Z,1406594577.711 [Default:CallIridium:B] Stopped
2014-07-29T00:42:57.711Z,1406594577.711 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-07-29T00:42:57.711Z,1406594577.711 [MissionManager](IMPORTANT): Started mission dat_on
2014-07-29T00:42:57.712Z,1406594577.712 [dat_on] Running Loop=1
2014-07-29T00:42:57.712Z,1406594577.712 [dat_on](INFO): Aggregate::initialize dat_on
2014-07-29T00:42:57.712Z,1406594577.712 [dat_on:A.Pitch] Running Loop=1
2014-07-29T00:42:57.712Z,1406594577.712 [dat_on:A.Pitch](DEBUG): Initialize.
2014-07-29T00:42:57.712Z,1406594577.712 [dat_on:TestDrive] Running Loop=1
2014-07-29T00:42:57.712Z,1406594577.712 [dat_on:TestDrive](INFO): Aggregate::initialize dat_on:TestDrive
2014-07-29T00:42:57.713Z,1406594577.713 [dat_on:TestDrive:A] Running Loop=1
2014-07-29T00:42:57.713Z,1406594577.713 [dat_on:TestDrive:C.Wait] Running Loop=1
2014-07-29T00:42:57.713Z,1406594577.713 [dat_on:TestDrive:C.Wait](DEBUG): Initialize Wait Component.
2014-07-29T00:42:57.714Z,1406594577.714 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:42:57.714Z,1406594577.714 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:42:57.714Z,1406594577.714 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:42:57.716Z,1406594577.716 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:42:57.716Z,1406594577.716 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:42:57.716Z,1406594577.716 [dat_on:TestDrive:A] Running Loop=1
2014-07-29T00:42:57.716Z,1406594577.716 [dat_on:TestDrive:A](DEBUG): Initialize ReadDataComponent to sense DAT.range
2014-07-29T00:42:57.717Z,1406594577.717 [dat_on:A.Pitch] Running Loop=1
2014-07-29T00:42:58.659Z,1406594578.659 [DAT](INFO): Powering up
2014-07-29T00:42:58.730Z,1406594578.730 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:42:58.731Z,1406594578.731 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:42:58.731Z,1406594578.731 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:42:58.731Z,1406594578.731 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:42:59.218Z,1406594579.218 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:42:59.218Z,1406594579.218 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:42:59.218Z,1406594579.218 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:42:59.219Z,1406594579.219 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:42:59.219Z,1406594579.219 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:42:59.681Z,1406594579.681 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:42:59.681Z,1406594579.681 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:42:59.681Z,1406594579.681 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:42:59.681Z,1406594579.681 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:00.232Z,1406594580.232 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:00.233Z,1406594580.233 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:00.233Z,1406594580.233 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:00.233Z,1406594580.233 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:00.234Z,1406594580.234 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:00.697Z,1406594580.697 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:00.698Z,1406594580.698 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:00.702Z,1406594580.702 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:00.702Z,1406594580.702 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:01.164Z,1406594581.164 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:01.164Z,1406594581.164 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:01.164Z,1406594581.164 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:01.165Z,1406594581.165 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:01.165Z,1406594581.165 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:01.704Z,1406594581.704 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:01.704Z,1406594581.704 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:01.704Z,1406594581.704 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:01.705Z,1406594581.705 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:02.223Z,1406594582.223 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:02.224Z,1406594582.224 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:02.224Z,1406594582.224 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:02.233Z,1406594582.233 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:02.233Z,1406594582.233 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:02.728Z,1406594582.728 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:02.728Z,1406594582.728 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:02.728Z,1406594582.728 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:02.728Z,1406594582.728 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:03.463Z,1406594583.463 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:03.463Z,1406594583.463 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:03.463Z,1406594583.463 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:03.464Z,1406594583.464 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:03.464Z,1406594583.464 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:03.769Z,1406594583.769 [CommandLine](IMPORTANT): got command report mod DAT.range
2014-07-29T00:43:04.049Z,1406594584.049 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:04.049Z,1406594584.049 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:04.049Z,1406594584.049 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:04.049Z,1406594584.049 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:04.076Z,1406594584.076 [Reporter](INFO): DAT.range no_value
2014-07-29T00:43:04.537Z,1406594584.537 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:04.537Z,1406594584.537 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:04.537Z,1406594584.537 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:04.538Z,1406594584.538 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:04.538Z,1406594584.538 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:05.029Z,1406594585.029 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:05.029Z,1406594585.029 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:05.029Z,1406594585.029 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:05.030Z,1406594585.030 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:05.548Z,1406594585.548 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:05.548Z,1406594585.548 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:05.548Z,1406594585.548 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:05.549Z,1406594585.549 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:05.549Z,1406594585.549 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:06.063Z,1406594586.063 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:06.063Z,1406594586.063 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:06.063Z,1406594586.063 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:06.063Z,1406594586.063 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:06.616Z,1406594586.616 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:06.616Z,1406594586.616 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:06.616Z,1406594586.616 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:06.617Z,1406594586.617 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:06.617Z,1406594586.617 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:07.095Z,1406594587.095 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:07.095Z,1406594587.095 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:07.095Z,1406594587.095 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:07.095Z,1406594587.095 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:07.639Z,1406594587.639 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:07.639Z,1406594587.639 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:07.639Z,1406594587.639 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:07.640Z,1406594587.640 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:07.640Z,1406594587.640 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:08.128Z,1406594588.128 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:08.128Z,1406594588.128 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:08.128Z,1406594588.128 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:08.128Z,1406594588.128 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:08.774Z,1406594588.774 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:08.774Z,1406594588.774 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:08.774Z,1406594588.774 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:08.775Z,1406594588.775 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:08.775Z,1406594588.775 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:09.218Z,1406594589.218 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:09.219Z,1406594589.219 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:09.219Z,1406594589.219 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:09.219Z,1406594589.219 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:09.687Z,1406594589.687 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:09.687Z,1406594589.687 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:09.687Z,1406594589.687 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:09.688Z,1406594589.688 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:09.688Z,1406594589.688 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:10.151Z,1406594590.151 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:10.151Z,1406594590.151 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:10.151Z,1406594590.151 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:10.151Z,1406594590.151 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:10.591Z,1406594590.591 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:10.591Z,1406594590.591 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:10.591Z,1406594590.591 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:10.592Z,1406594590.592 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:10.592Z,1406594590.592 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:11.000Z,1406594591.000 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:11.001Z,1406594591.001 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:11.001Z,1406594591.001 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:11.001Z,1406594591.001 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:11.469Z,1406594591.469 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:11.469Z,1406594591.469 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:11.469Z,1406594591.469 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:11.470Z,1406594591.470 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:11.470Z,1406594591.470 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:12.019Z,1406594592.019 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:12.027Z,1406594592.027 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:12.028Z,1406594592.028 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:12.028Z,1406594592.028 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:12.490Z,1406594592.490 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:12.490Z,1406594592.490 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:12.490Z,1406594592.490 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:12.491Z,1406594592.491 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:12.491Z,1406594592.491 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:12.959Z,1406594592.959 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:12.959Z,1406594592.959 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:12.960Z,1406594592.960 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:12.960Z,1406594592.960 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:13.626Z,1406594593.626 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:13.626Z,1406594593.626 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:13.626Z,1406594593.626 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:13.627Z,1406594593.627 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:13.627Z,1406594593.627 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:14.087Z,1406594594.087 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:14.088Z,1406594594.088 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:14.088Z,1406594594.088 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:14.088Z,1406594594.088 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:14.546Z,1406594594.546 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:14.547Z,1406594594.547 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:14.547Z,1406594594.547 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:14.547Z,1406594594.547 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:14.548Z,1406594594.548 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:15.121Z,1406594595.121 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:15.121Z,1406594595.121 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:15.121Z,1406594595.121 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:15.121Z,1406594595.121 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:15.595Z,1406594595.595 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:15.595Z,1406594595.595 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:15.595Z,1406594595.595 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:15.596Z,1406594595.596 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:15.596Z,1406594595.596 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:16.059Z,1406594596.059 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:16.059Z,1406594596.059 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:16.059Z,1406594596.059 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:16.059Z,1406594596.059 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:16.597Z,1406594596.597 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:16.597Z,1406594596.597 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:16.597Z,1406594596.597 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:16.598Z,1406594596.598 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:16.598Z,1406594596.598 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:17.065Z,1406594597.065 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:17.065Z,1406594597.065 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:17.065Z,1406594597.065 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:17.065Z,1406594597.065 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:17.528Z,1406594597.528 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:17.529Z,1406594597.529 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:17.529Z,1406594597.529 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:17.529Z,1406594597.529 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:17.530Z,1406594597.530 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:17.995Z,1406594597.995 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:17.995Z,1406594597.995 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:17.995Z,1406594597.995 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:17.996Z,1406594597.996 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:18.633Z,1406594598.633 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:18.633Z,1406594598.633 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:18.633Z,1406594598.633 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:18.634Z,1406594598.634 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:18.634Z,1406594598.634 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:19.277Z,1406594599.277 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:19.277Z,1406594599.277 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:19.277Z,1406594599.277 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:19.277Z,1406594599.277 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:19.781Z,1406594599.781 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:19.781Z,1406594599.781 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:19.781Z,1406594599.781 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:19.782Z,1406594599.782 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:19.782Z,1406594599.782 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:20.289Z,1406594600.289 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:20.289Z,1406594600.289 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:20.289Z,1406594600.289 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:20.289Z,1406594600.289 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:20.806Z,1406594600.806 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:20.806Z,1406594600.806 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:20.806Z,1406594600.806 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:20.807Z,1406594600.807 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:20.807Z,1406594600.807 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:21.264Z,1406594601.264 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:21.264Z,1406594601.264 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:21.264Z,1406594601.264 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:21.264Z,1406594601.264 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:21.851Z,1406594601.851 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:21.851Z,1406594601.851 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:21.851Z,1406594601.851 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:21.852Z,1406594601.852 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:21.852Z,1406594601.852 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:22.389Z,1406594602.389 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:22.389Z,1406594602.389 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:22.389Z,1406594602.389 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:22.390Z,1406594602.390 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:22.883Z,1406594602.883 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:22.884Z,1406594602.884 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:22.884Z,1406594602.884 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:22.889Z,1406594602.889 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:22.889Z,1406594602.889 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:23.442Z,1406594603.442 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:23.443Z,1406594603.443 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:23.443Z,1406594603.443 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:23.443Z,1406594603.443 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:24.037Z,1406594604.037 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:24.037Z,1406594604.037 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:24.037Z,1406594604.037 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:24.043Z,1406594604.043 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:24.043Z,1406594604.043 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:24.540Z,1406594604.540 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:24.541Z,1406594604.541 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:24.541Z,1406594604.541 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:24.541Z,1406594604.541 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:25.106Z,1406594605.106 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:25.106Z,1406594605.106 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:25.106Z,1406594605.106 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:25.107Z,1406594605.107 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:25.107Z,1406594605.107 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:25.615Z,1406594605.615 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:25.615Z,1406594605.615 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:25.615Z,1406594605.615 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:25.615Z,1406594605.615 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:26.086Z,1406594606.086 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:26.087Z,1406594606.087 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:26.087Z,1406594606.087 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:26.087Z,1406594606.087 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:26.087Z,1406594606.087 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:26.609Z,1406594606.609 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:26.609Z,1406594606.609 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:26.609Z,1406594606.609 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:26.609Z,1406594606.609 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:27.129Z,1406594607.129 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:27.129Z,1406594607.129 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:27.129Z,1406594607.129 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:27.130Z,1406594607.130 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:27.130Z,1406594607.130 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:27.636Z,1406594607.636 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:27.637Z,1406594607.637 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:27.637Z,1406594607.637 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:27.637Z,1406594607.637 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:28.189Z,1406594608.189 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:28.189Z,1406594608.189 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:28.189Z,1406594608.189 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:28.190Z,1406594608.190 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:28.190Z,1406594608.190 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:28.699Z,1406594608.699 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:28.700Z,1406594608.700 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:28.700Z,1406594608.700 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:28.700Z,1406594608.700 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:29.185Z,1406594609.185 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:29.185Z,1406594609.185 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:29.185Z,1406594609.185 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:29.186Z,1406594609.186 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:29.186Z,1406594609.186 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:29.852Z,1406594609.852 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:29.852Z,1406594609.852 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:29.852Z,1406594609.852 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:29.852Z,1406594609.852 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:30.366Z,1406594610.366 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:30.367Z,1406594610.367 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:30.367Z,1406594610.367 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:30.393Z,1406594610.393 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:30.393Z,1406594610.393 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:30.878Z,1406594610.878 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:30.878Z,1406594610.878 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:30.878Z,1406594610.878 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:30.878Z,1406594610.878 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:31.442Z,1406594611.442 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:31.442Z,1406594611.442 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:31.442Z,1406594611.442 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:31.443Z,1406594611.443 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:31.443Z,1406594611.443 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:31.941Z,1406594611.941 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:31.942Z,1406594611.942 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:31.942Z,1406594611.942 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:31.942Z,1406594611.942 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:32.410Z,1406594612.410 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:32.410Z,1406594612.410 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:32.411Z,1406594612.411 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:32.416Z,1406594612.416 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:32.416Z,1406594612.416 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:32.931Z,1406594612.931 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:32.931Z,1406594612.931 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:32.931Z,1406594612.931 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:32.931Z,1406594612.931 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:33.498Z,1406594613.498 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:33.498Z,1406594613.498 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:33.498Z,1406594613.498 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:33.499Z,1406594613.499 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:33.499Z,1406594613.499 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:33.971Z,1406594613.971 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:33.971Z,1406594613.971 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:33.971Z,1406594613.971 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:33.971Z,1406594613.971 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:34.619Z,1406594614.619 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:34.619Z,1406594614.619 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:34.620Z,1406594614.620 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:34.620Z,1406594614.620 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:34.620Z,1406594614.620 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:35.144Z,1406594615.144 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:35.144Z,1406594615.144 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:35.144Z,1406594615.144 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:35.144Z,1406594615.144 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:35.633Z,1406594615.633 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:35.634Z,1406594615.634 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:35.634Z,1406594615.634 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:35.634Z,1406594615.634 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:35.635Z,1406594615.635 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:36.134Z,1406594616.134 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:36.134Z,1406594616.134 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:36.134Z,1406594616.134 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:36.134Z,1406594616.134 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:36.744Z,1406594616.744 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:36.744Z,1406594616.744 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:36.745Z,1406594616.745 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:36.745Z,1406594616.745 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:36.745Z,1406594616.745 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:37.242Z,1406594617.242 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:37.242Z,1406594617.242 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:37.247Z,1406594617.247 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:37.247Z,1406594617.247 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:37.815Z,1406594617.815 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:37.816Z,1406594617.816 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:37.816Z,1406594617.816 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:37.816Z,1406594617.816 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:37.817Z,1406594617.817 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:38.283Z,1406594618.283 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:38.283Z,1406594618.283 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:38.283Z,1406594618.283 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:38.283Z,1406594618.283 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:38.799Z,1406594618.799 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:38.799Z,1406594618.799 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:38.799Z,1406594618.799 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:38.800Z,1406594618.800 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:38.800Z,1406594618.800 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:39.295Z,1406594619.295 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:39.295Z,1406594619.295 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:39.295Z,1406594619.295 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:39.296Z,1406594619.296 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:39.943Z,1406594619.943 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:39.943Z,1406594619.943 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:39.944Z,1406594619.944 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:39.944Z,1406594619.944 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:39.945Z,1406594619.945 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:40.450Z,1406594620.450 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:40.450Z,1406594620.450 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:40.450Z,1406594620.450 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:40.450Z,1406594620.450 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:41.038Z,1406594621.038 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:41.038Z,1406594621.038 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:41.038Z,1406594621.038 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:41.039Z,1406594621.039 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:41.039Z,1406594621.039 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:41.495Z,1406594621.495 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:41.495Z,1406594621.495 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:41.495Z,1406594621.495 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:41.495Z,1406594621.495 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:42.017Z,1406594622.017 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:42.017Z,1406594622.017 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:42.018Z,1406594622.018 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:42.047Z,1406594622.047 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:42.047Z,1406594622.047 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:42.540Z,1406594622.540 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:42.540Z,1406594622.540 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:42.540Z,1406594622.540 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:42.540Z,1406594622.540 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:43.018Z,1406594623.018 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:43:43.019Z,1406594623.019 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:43:43.019Z,1406594623.019 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:43:43.056Z,1406594623.056 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:43:43.056Z,1406594623.056 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:43:43.212Z,1406594623.212 [CommandLine](IMPORTANT): got command stop
2014-07-29T00:43:43.611Z,1406594623.611 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:43:43.611Z,1406594623.611 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:43:43.611Z,1406594623.611 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:43:43.611Z,1406594623.611 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:43:43.612Z,1406594623.612 [dat_on] Stopped
2014-07-29T00:43:43.660Z,1406594623.660 [dat_on](INFO): Aggregate::uninitialize dat_on
2014-07-29T00:43:43.661Z,1406594623.661 [dat_on:A.Pitch] Stopped
2014-07-29T00:43:43.661Z,1406594623.661 [dat_on:TestDrive] Stopped
2014-07-29T00:43:43.661Z,1406594623.661 [dat_on:TestDrive](INFO): Aggregate::uninitialize dat_on:TestDrive
2014-07-29T00:43:43.661Z,1406594623.661 [dat_on:TestDrive:A] Stopped
2014-07-29T00:43:43.661Z,1406594623.661 [dat_on:TestDrive:C.Wait] Stopped
2014-07-29T00:43:43.661Z,1406594623.661 [dat_on:TestDrive:C.Wait](DEBUG): Uninitialize Wait Component.
2014-07-29T00:43:44.211Z,1406594624.211 [MissionManager](IMPORTANT): Started mission Default
2014-07-29T00:43:44.211Z,1406594624.211 [Default] Running Loop=1
2014-07-29T00:43:44.212Z,1406594624.212 [Default](INFO): Aggregate::initialize Default
2014-07-29T00:43:44.212Z,1406594624.212 [Default:Iridium] Running Loop=1
2014-07-29T00:43:44.212Z,1406594624.212 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-07-29T00:43:44.212Z,1406594624.212 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-07-29T00:43:44.212Z,1406594624.212 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-07-29T00:43:44.212Z,1406594624.212 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-07-29T00:43:44.212Z,1406594624.212 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:43:44.213Z,1406594624.213 [Default:Iridium:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-07-29T00:43:44.213Z,1406594624.213 [Default:Iridium:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-07-29T00:43:44.222Z,1406594624.222 [Default:Iridium:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-07-29T00:43:44.222Z,1406594624.222 [Default:CallIridium] Running Loop=1
2014-07-29T00:43:44.222Z,1406594624.222 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-07-29T00:43:44.223Z,1406594624.223 [Default:CallIridium:A] Running Loop=1
2014-07-29T00:43:44.223Z,1406594624.223 [Default:CallIridium:A] Stopped
2014-07-29T00:43:44.223Z,1406594624.223 [Default:CallIridium:B] Running Loop=1
2014-07-29T00:43:44.223Z,1406594624.223 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-07-29T00:43:44.224Z,1406594624.224 [Default:Iridium:Read_Iridium] Running Loop=1
2014-07-29T00:43:44.224Z,1406594624.224 [Default:GPS] Running Loop=1
2014-07-29T00:43:44.225Z,1406594624.225 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-07-29T00:43:44.225Z,1406594624.225 [Default:GPS:A.SetSpeed] Running Loop=1
2014-07-29T00:43:44.225Z,1406594624.225 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-07-29T00:43:44.225Z,1406594624.225 [Default:GPS:B.GoToSurface] Running Loop=1
2014-07-29T00:43:44.225Z,1406594624.225 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:43:44.234Z,1406594624.234 [Default:GPS:B.G