2012-06-07T15:15:47.812Z,1339082147.812 [Supervisor](DEBUG): Initializing supervisor.
2012-06-07T15:15:47.814Z,1339082147.814 [SyncHandler](DEBUG): Created PCaller Thread at 1077138656
2012-06-07T15:15:47.829Z,1339082147.829 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-06-07T15:15:47.830Z,1339082147.830 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 1077335264
2012-06-07T15:15:47.831Z,1339082147.831 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-06-07T15:15:47.841Z,1339082147.841 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-06-07T15:15:47.842Z,1339082147.842 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 1077531872
2012-06-07T15:15:47.843Z,1339082147.843 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-06-07T15:15:47.844Z,1339082147.844 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-06-07T15:15:47.845Z,1339082147.845 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-06-07T15:15:48.139Z,1339082148.139 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-06-07T15:15:48.141Z,1339082148.141 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-06-07T15:15:48.324Z,1339082148.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-06-07T15:15:48.325Z,1339082148.325 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-06-07T15:15:48.411Z,1339082148.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-06-07T15:15:48.412Z,1339082148.412 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-06-07T15:15:48.600Z,1339082148.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-06-07T15:15:48.600Z,1339082148.600 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-06-07T15:15:48.726Z,1339082148.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-06-07T15:15:48.728Z,1339082148.728 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-06-07T15:15:48.944Z,1339082148.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-06-07T15:15:48.945Z,1339082148.945 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-06-07T15:15:49.094Z,1339082149.094 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-06-07T15:15:49.095Z,1339082149.095 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-06-07T15:15:49.354Z,1339082149.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-06-07T15:15:49.354Z,1339082149.354 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-06-07T15:15:49.453Z,1339082149.453 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-06-07T15:15:49.453Z,1339082149.453 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-06-07T15:15:49.835Z,1339082149.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-06-07T15:15:49.836Z,1339082149.836 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-06-07T15:15:49.947Z,1339082149.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-06-07T15:15:49.947Z,1339082149.947 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-06-07T15:15:50.034Z,1339082150.034 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-06-07T15:15:50.035Z,1339082150.035 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-06-07T15:15:50.139Z,1339082150.139 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-06-07T15:15:50.272Z,1339082150.272 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-06-07T15:15:50.374Z,1339082150.374 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-06-07T15:15:50.471Z,1339082150.471 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-06-07T15:15:50.584Z,1339082150.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-06-07T15:15:50.674Z,1339082150.674 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-06-07T15:15:50.769Z,1339082150.769 [Supervisor](IMPORTANT): Reading configuration overrides from Data/config.db
2012-06-07T15:15:50.777Z,1339082150.777 [ComponentRegistry](DEBUG): Loaded Config Component "configDb
2012-06-07T15:15:50.804Z,1339082150.804 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-06-07T15:15:50.959Z,1339082150.959 [InternalSim] Loaded
2012-06-07T15:15:50.959Z,1339082150.959 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-06-07T15:15:50.960Z,1339082150.960 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-06-07T15:15:50.960Z,1339082150.960 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-06-07T15:15:51.021Z,1339082151.021 [SBIT](DEBUG): Construct Startup Built In Test.
2012-06-07T15:15:51.032Z,1339082151.033 [SBIT] Loaded
2012-06-07T15:15:51.033Z,1339082151.033 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-06-07T15:15:51.034Z,1339082151.034 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-06-07T15:15:51.058Z,1339082151.058 [IBIT] Loaded
2012-06-07T15:15:51.058Z,1339082151.058 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-06-07T15:15:51.065Z,1339082151.065 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-06-07T15:15:51.175Z,1339082151.175 [CBIT] Loaded
2012-06-07T15:15:51.175Z,1339082151.175 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-06-07T15:15:51.176Z,1339082151.175 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-06-07T15:15:51.176Z,1339082151.176 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-06-07T15:15:51.325Z,1339082151.325 [BuoyancyServo] Loaded
2012-06-07T15:15:51.325Z,1339082151.325 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-06-07T15:15:51.332Z,1339082151.332 [ElevatorServo] Loaded
2012-06-07T15:15:51.332Z,1339082151.332 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-06-07T15:15:51.339Z,1339082151.339 [MassServo] Loaded
2012-06-07T15:15:51.339Z,1339082151.339 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2012-06-07T15:15:51.346Z,1339082151.346 [RudderServo] Loaded
2012-06-07T15:15:51.346Z,1339082151.346 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-06-07T15:15:51.353Z,1339082151.353 [ThrusterServo] Loaded
2012-06-07T15:15:51.353Z,1339082151.353 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-06-07T15:15:51.354Z,1339082151.354 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-06-07T15:15:51.354Z,1339082151.355 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-06-07T15:15:54.394Z,1339082154.394 [DepthRateCalculator] Loaded
2012-06-07T15:15:54.394Z,1339082154.394 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-06-07T15:15:54.418Z,1339082154.418 [NavChart] Loaded
2012-06-07T15:15:54.418Z,1339082154.418 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-06-07T15:15:54.431Z,1339082154.431 [PitchRateCalculator] Loaded
2012-06-07T15:15:54.431Z,1339082154.431 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-06-07T15:15:54.437Z,1339082154.437 [SpeedCalculator] Loaded
2012-06-07T15:15:54.437Z,1339082154.437 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-06-07T15:15:54.467Z,1339082154.467 [TempGradientCalculator] Loaded
2012-06-07T15:15:54.467Z,1339082154.467 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-06-07T15:15:54.473Z,1339082154.473 [YawRateCalculator] Loaded
2012-06-07T15:15:54.473Z,1339082154.473 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-06-07T15:15:54.504Z,1339082154.504 [Navigation] Loaded
2012-06-07T15:15:54.504Z,1339082154.504 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-06-07T15:15:54.504Z,1339082154.504 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-06-07T15:15:54.505Z,1339082154.505 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-06-07T15:15:54.750Z,1339082154.750 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-06-07T15:15:54.751Z,1339082154.751 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-06-07T15:15:54.785Z,1339082154.785 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-06-07T15:15:54.786Z,1339082154.786 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-06-07T15:15:54.836Z,1339082154.836 [VerticalControl](DEBUG): Construct VerticalControl.
2012-06-07T15:15:54.880Z,1339082154.880 [VerticalControl] Loaded
2012-06-07T15:15:54.880Z,1339082154.880 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-06-07T15:15:54.881Z,1339082154.881 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-06-07T15:15:54.901Z,1339082154.901 [HorizontalControl] Loaded
2012-06-07T15:15:54.901Z,1339082154.901 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-06-07T15:15:54.902Z,1339082154.902 [SpeedControl](DEBUG): Construct SpeedControl.
2012-06-07T15:15:54.904Z,1339082154.904 [SpeedControl] Loaded
2012-06-07T15:15:54.904Z,1339082154.904 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-06-07T15:15:54.905Z,1339082154.905 [LoopControl](DEBUG): Construct LoopControl.
2012-06-07T15:15:54.905Z,1339082154.905 [LoopControl] Loaded
2012-06-07T15:15:54.906Z,1339082154.906 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-06-07T15:15:54.906Z,1339082154.906 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-06-07T15:15:54.907Z,1339082154.907 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-06-07T15:15:54.919Z,1339082154.919 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-06-07T15:15:54.924Z,1339082154.924 [AsyncPiEstimator] Loaded
2012-06-07T15:15:54.925Z,1339082154.925 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-06-07T15:15:54.926Z,1339082154.926 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 1078998240
2012-06-07T15:15:54.927Z,1339082154.927 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-06-07T15:15:54.927Z,1339082154.927 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-06-07T15:15:55.055Z,1339082155.055 [AHRS_sp3003D] Loaded
2012-06-07T15:15:55.056Z,1339082155.056 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-06-07T15:15:55.310Z,1339082155.310 [Batt_Ocean_Server] Loaded
2012-06-07T15:15:55.310Z,1339082155.310 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-06-07T15:15:55.323Z,1339082155.323 [Depth_Keller] Loaded
2012-06-07T15:15:55.323Z,1339082155.323 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-06-07T15:15:55.328Z,1339082155.328 [DropWeight] Loaded
2012-06-07T15:15:55.329Z,1339082155.329 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-06-07T15:15:55.422Z,1339082155.422 [DVL_micro] Loaded
2012-06-07T15:15:55.423Z,1339082155.423 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2012-06-07T15:15:55.502Z,1339082155.502 [NAL9601] Loaded
2012-06-07T15:15:55.502Z,1339082155.502 [ComponentRegistry](DEBUG): SyncComponent "NAL9601" handled in the control thread.
2012-06-07T15:15:55.551Z,1339082155.551 [Onboard] Loaded
2012-06-07T15:15:55.551Z,1339082155.551 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-06-07T15:15:55.557Z,1339082155.557 [Radio_Freewave] Loaded
2012-06-07T15:15:55.558Z,1339082155.557 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-06-07T15:15:55.558Z,1339082155.558 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-06-07T15:15:55.559Z,1339082155.559 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-06-07T15:15:57.368Z,1339082157.368 [Aanderaa_O2] Loaded
2012-06-07T15:15:57.369Z,1339082157.369 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2012-06-07T15:15:57.400Z,1339082157.401 [CTD_NeilBrown] Loaded
2012-06-07T15:15:57.401Z,1339082157.401 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-06-07T15:15:57.402Z,1339082157.402 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 1079649504
2012-06-07T15:15:57.433Z,1339082157.432 [WetLabsBB2FL] Loaded
2012-06-07T15:15:57.433Z,1339082157.433 [ComponentRegistry](DEBUG): SyncComponent "WetLabsBB2FL" handled in the control thread.
2012-06-07T15:15:57.433Z,1339082157.433 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-06-07T15:15:57.435Z,1339082157.435 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-06-07T15:15:57.436Z,1339082157.436 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-06-07T15:15:57.442Z,1339082157.442 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-06-07T15:15:57.443Z,1339082157.443 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 1079846112
2012-06-07T15:15:57.443Z,1339082157.443 [Supervisor](DEBUG): Running supervisor.
2012-06-07T15:15:57.447Z,1339082157.447 [controlThread](DEBUG): Initializing ControlThread
2012-06-07T15:15:57.448Z,1339082157.448 [InternalSim](DEBUG):  InternalSim initializing...
2012-06-07T15:15:57.482Z,1339082157.482 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-06-07T15:15:57.483Z,1339082157.483 [SBIT](INFO): Initialize SBIT Component.
2012-06-07T15:15:57.484Z,1339082157.484 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9656 $
2012-06-07T15:15:57.484Z,1339082157.484 [IBIT](INFO): Initialize IBIT Component.
2012-06-07T15:15:57.495Z,1339082157.495 [CBIT](DEBUG): Initialize CBIT Component.
2012-06-07T15:15:57.495Z,1339082157.495 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2012-06-07T15:15:57.496Z,1339082157.496 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-06-07T15:15:57.524Z,1339082157.524 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-06-07T15:15:57.524Z,1339082157.524 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-06-07T15:15:57.525Z,1339082157.524 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-06-07T15:15:57.525Z,1339082157.525 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-06-07T15:15:57.525Z,1339082157.525 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-06-07T15:15:57.527Z,1339082157.527 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-06-07T15:15:57.527Z,1339082157.527 [Navigation](DEBUG): Initializing Navigation.
2012-06-07T15:15:57.528Z,1339082157.528 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-06-07T15:15:57.530Z,1339082157.530 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-06-07T15:15:57.530Z,1339082157.530 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-06-07T15:15:57.531Z,1339082157.531 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-06-07T15:15:57.608Z,1339082157.608 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-06-07T15:15:57.614Z,1339082157.615 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-06-07T15:15:57.618Z,1339082157.618 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-06-07T15:15:57.622Z,1339082157.622 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-06-07T15:15:57.626Z,1339082157.626 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-06-07T15:15:57.627Z,1339082157.627 [NavChartDb](INFO): Creating index for Soundings
2012-06-07T15:15:57.630Z,1339082157.630 [NavChartDb](INFO): Creating index for Contour 0p0
2012-06-07T15:15:57.632Z,1339082157.632 [NavChartDb](INFO): Creating index for Contour 1p8
2012-06-07T15:15:57.634Z,1339082157.634 [NavChartDb](INFO): Creating index for Contour 3p6
2012-06-07T15:15:57.636Z,1339082157.636 [NavChartDb](INFO): Creating index for Contour 5p4
2012-06-07T15:15:57.638Z,1339082157.638 [NavChartDb](INFO): Creating index for Contour 9p1
2012-06-07T15:15:57.640Z,1339082157.640 [NavChartDb](INFO): Creating index for Contour 10p9
2012-06-07T15:15:57.641Z,1339082157.641 [NavChartDb](INFO): Creating index for Contour 18p2
2012-06-07T15:15:57.644Z,1339082157.644 [NavChartDb](INFO): Creating index for Contour 36p5
2012-06-07T15:15:57.646Z,1339082157.645 [NavChartDb](INFO): Creating index for Contour 54p8
2012-06-07T15:15:57.648Z,1339082157.648 [NavChartDb](INFO): Creating index for Contour 73p1
2012-06-07T15:15:57.649Z,1339082157.649 [NavChartDb](INFO): Creating index for Contour 91p4
2012-06-07T15:15:57.651Z,1339082157.651 [NavChartDb](INFO): Creating index for Contour 182p8
2012-06-07T15:15:57.653Z,1339082157.653 [NavChartDb](INFO): Creating index for Contour 365p7
2012-06-07T15:15:57.655Z,1339082157.655 [NavChartDb](INFO): Creating index for Contour 548p6
2012-06-07T15:15:57.657Z,1339082157.657 [NavChartDb](INFO): Creating index for Contour 731p5
2012-06-07T15:15:57.659Z,1339082157.659 [NavChartDb](INFO): Creating index for Contour 914p4
2012-06-07T15:15:57.661Z,1339082157.661 [NavChartDb](INFO): Creating index for Contour 1097p2
2012-06-07T15:15:57.663Z,1339082157.662 [NavChartDb](INFO): Creating index for Contour 1280p1
2012-06-07T15:15:57.664Z,1339082157.664 [NavChartDb](INFO): Creating index for Contour 1463p0
2012-06-07T15:15:57.666Z,1339082157.666 [NavChartDb](INFO): Creating index for Contour 1645p9
2012-06-07T15:15:57.668Z,1339082157.668 [NavChartDb](INFO): Creating index for Contour 1828p8
2012-06-07T15:15:57.670Z,1339082157.670 [NavChartDb](INFO): Creating index for Contour 2011p6
2012-06-07T15:15:57.672Z,1339082157.672 [NavChartDb](INFO): Creating index for Contour 2194p5
2012-06-07T15:15:57.674Z,1339082157.674 [NavChartDb](INFO): Creating index for Contour 2377p4
2012-06-07T15:15:57.676Z,1339082157.676 [NavChartDb](INFO): Creating index for Contour 2560p3
2012-06-07T15:15:57.678Z,1339082157.678 [NavChartDb](INFO): Creating index for Contour 2743p2
2012-06-07T15:15:57.679Z,1339082157.680 [NavChartDb](INFO): Creating index for Contour 2926p0
2012-06-07T15:15:57.681Z,1339082157.681 [NavChartDb](INFO): Creating index for Contour 3108p9
2012-06-07T15:15:57.683Z,1339082157.683 [NavChartDb](INFO): Creating index for Contour 3291p8
2012-06-07T15:15:57.685Z,1339082157.685 [NavChartDb](INFO): Creating index for Contour 3474p7
2012-06-07T15:15:57.687Z,1339082157.687 [NavChartDb](INFO): Creating index for Contour 3657p6
2012-06-07T15:15:58.963Z,1339082158.963 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-06-07T15:15:58.968Z,1339082158.968 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-06-07T15:15:58.979Z,1339082158.979 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-06-07T15:15:58.988Z,1339082158.988 [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 RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2012-06-07T15:15:58.989Z,1339082158.989 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-06-07T15:15:59.016Z,1339082159.016 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-06-07T15:15:59.019Z,1339082159.019 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-06-07T15:15:59.022Z,1339082159.022 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-06-07T15:15:59.031Z,1339082159.031 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-06-07T15:15:59.034Z,1339082159.034 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-06-07T15:15:59.040Z,1339082159.040 [Default:Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-06-07T15:15:59.049Z,1339082159.049 [Default:D.SetSpeed](DEBUG): Construct.
2012-06-07T15:15:59.052Z,1339082159.052 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-06-07T15:15:59.056Z,1339082159.056 [Default:F.Wait](DEBUG): Construct Wait.
2012-06-07T15:15:59.060Z,1339082159.060 [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 RunIn="Parallel">
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

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

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

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute RunIn="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><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

<!-- Wait forever at the surface-->

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

    <Guidance:Wait RunIn="Sequence"></Guidance:Wait>

</Mission>


2012-06-07T15:15:59.065Z,1339082159.065 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9601,Onboard,Radio_Freewave,Aanderaa_O2,WetLabsBB2FL,Depth_Keller,DepthRateCalculator,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger,
2012-06-07T15:15:59.083Z,1339082159.083 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-06-07T15:15:59.193Z,1339082159.193 [DVL_micro](DEBUG): Initializing DVL_micro.
2012-06-07T15:15:59.213Z,1339082159.213 [Radio_Freewave](INFO): Powering up
2012-06-07T15:15:59.227Z,1339082159.227 [WetLabsBB2FL](INFO): Powering down
2012-06-07T15:15:59.294Z,1339082159.295 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-06-07T15:15:59.295Z,1339082159.295 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-06-07T15:15:59.305Z,1339082159.305 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-06-07T15:15:59.306Z,1339082159.306 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-06-07T15:15:59.314Z,1339082159.314 [MassServo](DEBUG): Initializing EZServoServo.
2012-06-07T15:15:59.315Z,1339082159.315 [MassServo](DEBUG): Initializing MassServo.
2012-06-07T15:15:59.322Z,1339082159.322 [RudderServo](DEBUG): Initializing EZServoServo.
2012-06-07T15:15:59.324Z,1339082159.324 [RudderServo](DEBUG): Initializing RudderServo.
2012-06-07T15:15:59.331Z,1339082159.332 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-06-07T15:15:59.332Z,1339082159.332 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-06-07T15:16:01.715Z,1339082161.716 [NAL9601](INFO): Powering up NAL9601
2012-06-07T15:16:03.427Z,1339082163.427 [Aanderaa_O2](INFO): Powering down
2012-06-07T15:16:12.973Z,1339082172.973 [SBIT](IMPORTANT): Beginning Startup BIT
2012-06-07T15:16:12.975Z,1339082172.975 [CBIT](IMPORTANT): Beginning GF scan
2012-06-07T15:16:39.213Z,1339082199.213 [CBIT](IMPORTANT): No ground fault detected
2012-06-07T15:16:55.122Z,1339082215.122 [SBIT](IMPORTANT): SBIT PASSED
2012-06-07T15:16:55.520Z,1339082215.520 [MissionManager](IMPORTANT): Started mission Startup
2012-06-07T15:16:55.520Z,1339082215.520 [Startup] Running Loop=1
2012-06-07T15:16:55.520Z,1339082215.520 [Startup](INFO): Aggregate::initialize Startup
2012-06-07T15:16:55.520Z,1339082215.520 [Startup:A.GoToSurface] Running Loop=1
2012-06-07T15:16:55.520Z,1339082215.520 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T15:16:55.527Z,1339082215.527 [Startup:StartupSatComms] Running Loop=1
2012-06-07T15:16:55.527Z,1339082215.527 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-06-07T15:16:55.527Z,1339082215.527 [Startup:StartupSatComms:A] Running Loop=1
2012-06-07T15:16:55.920Z,1339082215.921 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-06-07T15:17:07.439Z,1339082227.439 [NAL9601](INFO): NAL9601 initialized
2012-06-07T15:17:08.541Z,1339082228.541 [NAL9601](IMPORTANT): GPS fix at: 1339082320.00
2012-06-07T15:17:08.554Z,1339082228.554 [Startup:StartupSatComms:A] Stopped
2012-06-07T15:17:08.554Z,1339082228.554 [Startup:StartupSatComms:B] Running Loop=1
2012-06-07T15:17:08.953Z,1339082228.953 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-06-07T15:17:31.314Z,1339082251.314 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=9818, MT Status=1, MTMSN=2732
2012-06-07T15:17:31.491Z,1339082251.491 [NAL9601](INFO): Sent 177 bytes from file Logs/20120607T001433/shore0045.lzma
2012-06-07T15:17:31.491Z,1339082251.491 [NAL9601](INFO): Packets left to send: 0
2012-06-07T15:17:31.493Z,1339082251.493 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000000
2012-06-07T15:17:32.012Z,1339082252.012 [NAL9601](INFO): Received command:load Transport/transit_3km.xml;set transit_3km.Wpt1Lat 36.8156 degree;set transit_3km.Wpt1Lon -121.806 degree;set transit_3km.Speed .75 meter_per_second;set transit_3km.TimeoutDuration 70 minute;run 
2012-06-07T15:17:32.026Z,1339082252.026 [CommandLine](IMPORTANT): got command load ./Missions/Transport/transit_3km.xml
2012-06-07T15:17:32.026Z,1339082252.026 [MissionManager](INFO): Loading Mission: ./Missions/Transport/transit_3km.xml
2012-06-07T15:17:32.101Z,1339082252.101 [MissionManager](INFO): DefineArg transit_3km.ApproachDepth = 10.000000 m
2012-06-07T15:17:32.104Z,1339082252.104 [MissionManager](INFO): DefineArg transit_3km.Wpt1Lat = 36.806966 arcdeg
2012-06-07T15:17:32.115Z,1339082252.115 [MissionManager](INFO): DefineArg transit_3km.Wpt1Lon = -121.824326 arcdeg
2012-06-07T15:17:32.118Z,1339082252.118 [MissionManager](INFO): DefineArg transit_3km.Speed = 1.000000 m/s
2012-06-07T15:17:32.121Z,1339082252.121 [MissionManager](INFO): DefineArg transit_3km.MaxDepth = 20.000000 m
2012-06-07T15:17:32.132Z,1339082252.132 [MissionManager](INFO): DefineArg transit_3km.TimeoutDuration = 240.000000 min
2012-06-07T15:17:32.134Z,1339082252.134 [transit_3km:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2012-06-07T15:17:32.142Z,1339082252.142 [transit_3km:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2012-06-07T15:17:32.163Z,1339082252.163 [transit_3km:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2012-06-07T15:17:32.182Z,1339082252.182 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-06-07T15:17:32.187Z,1339082252.187 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Construct.
2012-06-07T15:17:32.211Z,1339082252.211 [transit_3km:WaypointOne:A.Pitch](DEBUG): Construct.
2012-06-07T15:17:32.216Z,1339082252.216 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Construct.
2012-06-07T15:17:32.235Z,1339082252.235 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Construct Waypoint.
2012-06-07T15:17:32.245Z,1339082252.245 [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="transit_3km">

<!-- To be used within 6km of waypoint. No science collection.  -->

    <DefineArg Name="ApproachDepth"><Units:meter /><Value>10.0</Value></DefineArg>

    <DefineArg Name="Wpt1Lat"><Units:degree /><Value>36.806966</Value></DefineArg>

    <DefineArg Name="Wpt1Lon"><Units:degree /><Value>-121.824326</Value></DefineArg>

    <DefineArg Name="Speed"><Units:meter_per_second/><Value>1</Value></DefineArg>

    <DefineArg Name="MaxDepth"><Description>
        Maximum depth for the entire mission.
    </Description><Units:meter/><Value>20</Value></DefineArg>

    <DefineArg Name="TimeoutDuration"><Description>
        Maximum length of mission
    </Description><Units:minute/><Value>240</Value></DefineArg>

    <Timeout Duration="TimeoutDuration"/>

    <Guidance:AltitudeEnvelope RunIn="Parallel">
        <Setting><Guidance:AltitudeEnvelope.minAltitude /><Units:meter /><Value>7</Value></Setting>
    </Guidance:AltitudeEnvelope>

    <Guidance:DepthEnvelope RunIn="Parallel">
        <Setting><Guidance:DepthEnvelope.maxDepth/><Arg Name="MaxDepth"/></Setting>
    </Guidance:DepthEnvelope>

    <Guidance:OffshoreEnvelope RunIn="Parallel">
        <Setting><Guidance:OffshoreEnvelope.minOffshore/><Units:kilometer/><Value>1</Value></Setting>
    </Guidance:OffshoreEnvelope>

    <Aggregate Id="SURFACECOMMS">

        <Guidance:GoToSurface RunIn="Progression" />

        <Aggregate>

            <Preemptive><True /></Preemptive>

            <Guidance:SetSpeed RunIn="Parallel">
                <Setting><Guidance:SetSpeed.speed /><Units:meter_per_second /><Value>0</Value></Setting>
            </Guidance:SetSpeed>

            <ReadDatum><Universal:latitude_fix />
            </ReadDatum>

            <ReadDatum>
                <Timeout Duration="P30M">
                    <Assign Id="TouchComms"><Universal:platform_communications/></Assign>
                </Timeout><Universal:platform_communications />
            </ReadDatum>

            <ReadDatum><Universal:latitude_fix />
            </ReadDatum>

        </Aggregate>

    </Aggregate>

<!-- GPS Update.  Don't go too long w/o a GPS fix. -->

    <Aggregate Id="NeedComms">

        <When>
            <Elapsed><Universal:time_fix /></Elapsed>
            <Gt><Units:minute/><Value>35</Value></Gt>
        </When>

        <Call Id="NEEDCOMMS" RefId="SURFACECOMMS" />

    </Aggregate>

    <Aggregate Id="WaypointOne">

<!-- Go to Wpt1 -->

        <Guidance:Pitch RunIn="Parallel">
            <Setting><Guidance:Pitch.depth /><Arg Name="ApproachDepth" /></Setting>
        </Guidance:Pitch>

        <Guidance:SetSpeed RunIn="Parallel">
            <Setting><Guidance:SetSpeed.speed/><Arg Name="Speed"/></Setting>
        </Guidance:SetSpeed>

        <Guidance:Waypoint Id="WaypointW1" RunIn="Sequence">
            <Setting><Guidance:Waypoint.latitude /><Arg Name="Wpt1Lat" /></Setting>
            <Setting><Guidance:Waypoint.longitude /><Arg Name="Wpt1Lon" /></Setting>
        </Guidance:Waypoint>

        <Call Id="PHONEHOMEWPT1" RefId="SURFACECOMMS" />

    </Aggregate>

</Mission>


2012-06-07T15:17:32.245Z,1339082252.246 [CommandLine](IMPORTANT): Loaded ./Missions/Transport/transit_3km.xml
2012-06-07T15:17:32.438Z,1339082252.438 [CommandLine](IMPORTANT): got command set transit_3km.Wpt1Lat 36.815601 degree
2012-06-07T15:17:32.629Z,1339082252.629 [CommandLine](IMPORTANT): got command set transit_3km.Wpt1Lon -121.806000 degree
2012-06-07T15:17:32.831Z,1339082252.831 [CommandLine](IMPORTANT): got command set transit_3km.Speed 0.750000 meter_per_second
2012-06-07T15:17:33.107Z,1339082253.107 [CommandLine](IMPORTANT): got command set transit_3km.TimeoutDuration 70.000000 minute
2012-06-07T15:17:33.108Z,1339082253.108 [CommandLine](IMPORTANT): got command run 
2012-06-07T15:17:33.108Z,1339082253.108 [CommandLine](IMPORTANT): Running 
2012-06-07T15:17:43.585Z,1339082263.585 [NAL9601](INFO): SBD MO Status=1, MOMSN=9819, MT Status=0, MTMSN=0
2012-06-07T15:17:43.771Z,1339082263.771 [NAL9601](INFO): Sent 332 bytes from file Logs/20120607T151546/shore0000.lzma
2012-06-07T15:17:43.771Z,1339082263.771 [NAL9601](INFO): Packets left to send: 1
2012-06-07T15:17:43.772Z,1339082263.772 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000001
2012-06-07T15:17:52.187Z,1339082272.187 [NAL9601](INFO): SBD MO Status=1, MOMSN=9820, MT Status=0, MTMSN=0
2012-06-07T15:17:52.355Z,1339082272.355 [NAL9601](INFO): Sent 280 bytes from file Logs/20120607T151546/shore0000.lzma
2012-06-07T15:17:52.355Z,1339082272.355 [NAL9601](INFO): Packets left to send: 0
2012-06-07T15:17:52.356Z,1339082272.356 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000002
2012-06-07T15:17:55.394Z,1339082275.394 [NAL9601](INFO): SBD MO Status=0, MOMSN=9821, MT Status=0, MTMSN=0
2012-06-07T15:18:07.496Z,1339082287.496 [NAL9601](INFO): SBD MO Status=1, MOMSN=9822, MT Status=0, MTMSN=0
2012-06-07T15:18:07.631Z,1339082287.631 [NAL9601](INFO): Sent 332 bytes from file Logs/20120607T151546/shore0001.lzma
2012-06-07T15:18:07.631Z,1339082287.631 [NAL9601](INFO): Packets left to send: 1
2012-06-07T15:18:07.632Z,1339082287.632 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000003
2012-06-07T15:18:10.368Z,1339082290.368 [Startup:StartupSatComms:B](INFO): Timed out from 2012-06-07T15:17:08.6Z
2012-06-07T15:18:10.369Z,1339082290.369 [Startup:StartupSatComms:A_Timeout] Running Loop=1
2012-06-07T15:18:10.369Z,1339082290.369 [Startup:StartupSatComms:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A_Timeout
2012-06-07T15:18:10.369Z,1339082290.369 [Startup:StartupSatComms:A_Timeout](INFO): Completed Startup:StartupSatComms:A_Timeout
2012-06-07T15:18:10.369Z,1339082290.369 [Startup:StartupSatComms:B] Stopped
2012-06-07T15:18:10.369Z,1339082290.369 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-06-07T15:18:10.369Z,1339082290.369 [Startup:StartupSatComms] Stopped
2012-06-07T15:18:10.370Z,1339082290.369 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-06-07T15:18:10.370Z,1339082290.370 [Startup](INFO): Completed Startup
2012-06-07T15:18:10.370Z,1339082290.371 [Startup] Stopped
2012-06-07T15:18:10.371Z,1339082290.371 [Startup](INFO): Aggregate::uninitialize Startup
2012-06-07T15:18:10.371Z,1339082290.371 [Startup:A.GoToSurface] Stopped
2012-06-07T15:18:10.371Z,1339082290.371 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T15:18:10.615Z,1339082290.615 [MissionManager](IMPORTANT): Started mission transit_3km
2012-06-07T15:18:10.615Z,1339082290.615 [transit_3km] Running Loop=1
2012-06-07T15:18:10.615Z,1339082290.615 [transit_3km](INFO): Aggregate::initialize transit_3km
2012-06-07T15:18:10.615Z,1339082290.615 [transit_3km:A.AltitudeEnvelope] Running Loop=1
2012-06-07T15:18:10.615Z,1339082290.615 [transit_3km:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2012-06-07T15:18:10.616Z,1339082290.616 [transit_3km:B.DepthEnvelope] Running Loop=1
2012-06-07T15:18:10.616Z,1339082290.616 [transit_3km:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2012-06-07T15:18:10.617Z,1339082290.617 [transit_3km:C.OffshoreEnvelope] Running Loop=1
2012-06-07T15:18:10.617Z,1339082290.617 [transit_3km:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2012-06-07T15:18:10.617Z,1339082290.617 [transit_3km:SURFACECOMMS] Running Loop=1
2012-06-07T15:18:10.617Z,1339082290.617 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS
2012-06-07T15:18:10.617Z,1339082290.617 [transit_3km:SURFACECOMMS:A.GoToSurface] Running Loop=1
2012-06-07T15:18:10.617Z,1339082290.617 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T15:18:10.627Z,1339082290.627 [transit_3km:SURFACECOMMS:B] Running Loop=1
2012-06-07T15:18:10.627Z,1339082290.627 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:B
2012-06-07T15:18:10.627Z,1339082290.627 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1
2012-06-07T15:18:10.627Z,1339082290.627 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Initialize.
2012-06-07T15:18:10.627Z,1339082290.628 [transit_3km:SURFACECOMMS:B:B] Running Loop=1
2012-06-07T15:18:10.627Z,1339082290.628 [transit_3km:C.OffshoreEnvelope] Running Loop=1
2012-06-07T15:18:10.632Z,1339082290.632 [transit_3km:B.DepthEnvelope] Running Loop=1
2012-06-07T15:18:10.638Z,1339082290.638 [transit_3km:A.AltitudeEnvelope] Running Loop=1
2012-06-07T15:18:10.939Z,1339082290.939 [transit_3km:SURFACECOMMS:B:B](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-06-07T15:18:10.940Z,1339082290.940 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1
2012-06-07T15:18:14.979Z,1339082294.979 [NAL9601](INFO): SBD MO Status=1, MOMSN=9823, MT Status=0, MTMSN=0
2012-06-07T15:18:15.119Z,1339082295.119 [NAL9601](INFO): Sent 24 bytes from file Logs/20120607T151546/shore0001.lzma
2012-06-07T15:18:15.119Z,1339082295.119 [NAL9601](INFO): Packets left to send: 0
2012-06-07T15:18:15.120Z,1339082295.120 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000004
2012-06-07T15:18:23.784Z,1339082303.784 [NAL9601](INFO): SBD MO Status=0, MOMSN=9824, MT Status=0, MTMSN=0
2012-06-07T15:18:24.951Z,1339082304.951 [NAL9601](IMPORTANT): GPS fix at: 1339082396.00
2012-06-07T15:18:24.969Z,1339082304.969 [transit_3km:SURFACECOMMS:B:B] Stopped
2012-06-07T15:18:24.969Z,1339082304.969 [transit_3km:SURFACECOMMS:B:C] Running Loop=1
2012-06-07T15:18:25.391Z,1339082305.391 [transit_3km:SURFACECOMMS:B:C](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-06-07T15:18:35.082Z,1339082315.082 [NAL9601](INFO): SBD MO Status=1, MOMSN=9825, MT Status=0, MTMSN=0
2012-06-07T15:18:35.287Z,1339082315.287 [NAL9601](INFO): Sent 152 bytes from file Logs/20120607T151546/shore0002.lzma
2012-06-07T15:18:35.287Z,1339082315.287 [NAL9601](INFO): Packets left to send: 0
2012-06-07T15:18:35.288Z,1339082315.288 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000005
2012-06-07T15:18:38.296Z,1339082318.296 [NAL9601](INFO): SBD MO Status=0, MOMSN=9826, MT Status=0, MTMSN=0
2012-06-07T15:18:38.499Z,1339082318.499 [transit_3km:SURFACECOMMS:B:C] Stopped
2012-06-07T15:18:38.499Z,1339082318.499 [transit_3km:SURFACECOMMS:B:D] Running Loop=1
2012-06-07T15:18:38.698Z,1339082318.698 [transit_3km:SURFACECOMMS:B:D](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-06-07T15:18:40.715Z,1339082320.715 [NAL9601](IMPORTANT): GPS fix at: 1339082412.00
2012-06-07T15:18:40.729Z,1339082320.729 [transit_3km:SURFACECOMMS:B:D] Stopped
2012-06-07T15:18:40.730Z,1339082320.730 [transit_3km:SURFACECOMMS:B](INFO): Completed transit_3km:SURFACECOMMS:B
2012-06-07T15:18:40.730Z,1339082320.730 [transit_3km:SURFACECOMMS:B] Stopped
2012-06-07T15:18:40.730Z,1339082320.730 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:B
2012-06-07T15:18:40.730Z,1339082320.730 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Stopped
2012-06-07T15:18:40.730Z,1339082320.730 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T15:18:40.731Z,1339082320.731 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS
2012-06-07T15:18:40.731Z,1339082320.731 [transit_3km:SURFACECOMMS] Stopped
2012-06-07T15:18:40.731Z,1339082320.731 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS
2012-06-07T15:18:40.731Z,1339082320.731 [transit_3km:SURFACECOMMS:A.GoToSurface] Stopped
2012-06-07T15:18:40.731Z,1339082320.731 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T15:18:40.732Z,1339082320.732 [transit_3km:WaypointOne] Running Loop=1
2012-06-07T15:18:40.732Z,1339082320.732 [transit_3km:WaypointOne](INFO): Aggregate::initialize transit_3km:WaypointOne
2012-06-07T15:18:40.732Z,1339082320.732 [transit_3km:WaypointOne:A.Pitch] Running Loop=1
2012-06-07T15:18:40.732Z,1339082320.732 [transit_3km:WaypointOne:A.Pitch](DEBUG): Initialize.
2012-06-07T15:18:40.732Z,1339082320.732 [transit_3km:WaypointOne:B.SetSpeed] Running Loop=1
2012-06-07T15:18:40.732Z,1339082320.732 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Initialize.
2012-06-07T15:18:40.732Z,1339082320.732 [transit_3km:WaypointOne:WaypointW1.Waypoint] Running Loop=1
2012-06-07T15:18:40.733Z,1339082320.733 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Initialize WaypointComponent.
2012-06-07T15:18:41.098Z,1339082321.098 [transit_3km:WaypointOne:B.SetSpeed] Running Loop=1
2012-06-07T15:18:41.102Z,1339082321.102 [transit_3km:WaypointOne:A.Pitch] Running Loop=1
2012-06-07T15:18:47.080Z,1339082327.080 [NAL9601](INFO): Powering down
2012-06-07T15:18:51.502Z,1339082331.502 [transit_3km:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2012-06-07T15:18:59.889Z,1339082339.889 [Radio_Freewave](INFO): Powering down
2012-06-07T15:53:40.927Z,1339084420.927 [transit_3km:NeedComms] Running Loop=1
2012-06-07T15:53:40.927Z,1339084420.927 [transit_3km:NeedComms](INFO): Aggregate::initialize transit_3km:NeedComms
2012-06-07T15:53:40.927Z,1339084420.927 [transit_3km:NeedComms:NEEDCOMMS] Running Loop=1
2012-06-07T15:53:40.927Z,1339084420.927 [transit_3km:NeedComms:NEEDCOMMS](INFO): Aggregate::initialize transit_3km:NeedComms:NEEDCOMMS
2012-06-07T15:53:41.279Z,1339084421.279 [transit_3km:SURFACECOMMS] Running Loop=1
2012-06-07T15:53:41.279Z,1339084421.279 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS
2012-06-07T15:53:41.279Z,1339084421.279 [transit_3km:SURFACECOMMS:A.GoToSurface] Running Loop=1
2012-06-07T15:53:41.279Z,1339084421.279 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T15:56:22.993Z,1339084582.993 [Radio_Freewave](INFO): Powering up
2012-06-07T15:56:23.004Z,1339084583.004 [transit_3km:SURFACECOMMS:B] Running Loop=1
2012-06-07T15:56:23.005Z,1339084583.005 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:B
2012-06-07T15:56:23.005Z,1339084583.005 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1
2012-06-07T15:56:23.005Z,1339084583.005 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Initialize.
2012-06-07T15:56:23.005Z,1339084583.005 [transit_3km:SURFACECOMMS:B:B] Running Loop=1
2012-06-07T15:56:23.783Z,1339084583.783 [NAL9601](INFO): Powering up
2012-06-07T15:57:29.407Z,1339084649.407 [NAL9601](INFO): NAL9601 initialized
2012-06-07T15:57:30.479Z,1339084650.479 [NAL9601](IMPORTANT): GPS fix at: 1339084745.00
2012-06-07T15:57:30.495Z,1339084650.496 [Navigation](IMPORTANT): Navigation Error 6.6 %DT

2012-06-07T15:57:30.496Z,1339084650.496 [transit_3km:SURFACECOMMS:B:B] Stopped
2012-06-07T15:57:30.496Z,1339084650.497 [transit_3km:SURFACECOMMS:B:C] Running Loop=1
2012-06-07T15:57:51.561Z,1339084671.561 [NAL9601](INFO): SBD MO Status=1, MOMSN=9827, MT Status=0, MTMSN=0
2012-06-07T15:57:51.763Z,1339084671.763 [NAL9601](INFO): Sent 332 bytes from file Logs/20120607T151546/shore0003.lzma
2012-06-07T15:57:51.763Z,1339084671.763 [NAL9601](INFO): Packets left to send: 1
2012-06-07T15:57:51.764Z,1339084671.764 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000006
2012-06-07T15:58:02.052Z,1339084682.053 [NAL9601](INFO): SBD MO Status=1, MOMSN=9828, MT Status=0, MTMSN=0
2012-06-07T15:58:02.243Z,1339084682.243 [NAL9601](INFO): Sent 270 bytes from file Logs/20120607T151546/shore0003.lzma
2012-06-07T15:58:02.243Z,1339084682.243 [NAL9601](INFO): Packets left to send: 0
2012-06-07T15:58:02.244Z,1339084682.244 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000007
2012-06-07T15:58:05.252Z,1339084685.252 [NAL9601](INFO): SBD MO Status=0, MOMSN=9829, MT Status=0, MTMSN=0
2012-06-07T15:58:05.457Z,1339084685.457 [transit_3km:SURFACECOMMS:B:C] Stopped
2012-06-07T15:58:05.457Z,1339084685.457 [transit_3km:SURFACECOMMS:B:D] Running Loop=1
2012-06-07T15:58:07.654Z,1339084687.654 [NAL9601](IMPORTANT): GPS fix at: 1339084783.00
2012-06-07T15:58:07.668Z,1339084687.668 [transit_3km:SURFACECOMMS:B:D] Stopped
2012-06-07T15:58:07.668Z,1339084687.668 [transit_3km:SURFACECOMMS:B](INFO): Completed transit_3km:SURFACECOMMS:B
2012-06-07T15:58:07.668Z,1339084687.668 [transit_3km:SURFACECOMMS:B] Stopped
2012-06-07T15:58:07.669Z,1339084687.668 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:B
2012-06-07T15:58:07.669Z,1339084687.668 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Stopped
2012-06-07T15:58:07.669Z,1339084687.669 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T15:58:07.669Z,1339084687.669 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS
2012-06-07T15:58:07.669Z,1339084687.670 [transit_3km:SURFACECOMMS] Stopped
2012-06-07T15:58:07.670Z,1339084687.670 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS
2012-06-07T15:58:07.670Z,1339084687.670 [transit_3km:SURFACECOMMS:A.GoToSurface] Stopped
2012-06-07T15:58:07.670Z,1339084687.670 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T15:58:08.067Z,1339084688.067 [transit_3km:NeedComms:NEEDCOMMS](INFO): Completed transit_3km:NeedComms:NEEDCOMMS
2012-06-07T15:58:08.067Z,1339084688.067 [transit_3km:NeedComms:NEEDCOMMS] Stopped
2012-06-07T15:58:08.067Z,1339084688.067 [transit_3km:NeedComms:NEEDCOMMS](INFO): Aggregate::uninitialize transit_3km:NeedComms:NEEDCOMMS
2012-06-07T15:58:08.067Z,1339084688.067 [transit_3km:NeedComms](INFO): Completed transit_3km:NeedComms
2012-06-07T15:58:08.067Z,1339084688.067 [transit_3km:NeedComms] Stopped
2012-06-07T15:58:08.067Z,1339084688.067 [transit_3km:NeedComms](INFO): Aggregate::uninitialize transit_3km:NeedComms
2012-06-07T15:58:14.051Z,1339084694.051 [NAL9601](INFO): Powering down
2012-06-07T15:58:31.260Z,1339084711.260 [Radio_Freewave](INFO): Powering down
2012-06-07T16:11:27.518Z,1339085487.519 [transit_3km:WaypointOne:WaypointW1.Waypoint](INFO): Reached Waypoint: 36.815601,-121.806001
2012-06-07T16:11:27.519Z,1339085487.519 [transit_3km:WaypointOne:WaypointW1.Waypoint] Stopped
2012-06-07T16:11:27.519Z,1339085487.519 [transit_3km:WaypointOne:WaypointW1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2012-06-07T16:11:27.519Z,1339085487.519 [transit_3km:WaypointOne:PHONEHOMEWPT1] Running Loop=1
2012-06-07T16:11:27.519Z,1339085487.519 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::initialize transit_3km:WaypointOne:PHONEHOMEWPT1
2012-06-07T16:11:27.936Z,1339085487.936 [transit_3km:SURFACECOMMS] Running Loop=1
2012-06-07T16:11:27.936Z,1339085487.936 [transit_3km:SURFACECOMMS](INFO): Aggregate::initialize transit_3km:SURFACECOMMS
2012-06-07T16:11:27.936Z,1339085487.936 [transit_3km:SURFACECOMMS:A.GoToSurface] Running Loop=1
2012-06-07T16:11:27.936Z,1339085487.936 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:14:14.672Z,1339085654.672 [Radio_Freewave](INFO): Powering up
2012-06-07T16:14:14.683Z,1339085654.683 [transit_3km:SURFACECOMMS:B] Running Loop=1
2012-06-07T16:14:14.683Z,1339085654.683 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::initialize transit_3km:SURFACECOMMS:B
2012-06-07T16:14:14.683Z,1339085654.683 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Running Loop=1
2012-06-07T16:14:14.683Z,1339085654.683 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Initialize.
2012-06-07T16:14:14.683Z,1339085654.683 [transit_3km:SURFACECOMMS:B:B] Running Loop=1
2012-06-07T16:14:15.486Z,1339085655.486 [NAL9601](INFO): Powering up
2012-06-07T16:15:21.211Z,1339085721.211 [NAL9601](INFO): NAL9601 initialized
2012-06-07T16:15:22.328Z,1339085722.328 [NAL9601](IMPORTANT): GPS fix at: 1339085819.00
2012-06-07T16:15:22.341Z,1339085722.341 [Navigation](IMPORTANT): Navigation Error 8.5 %DT

2012-06-07T16:15:22.343Z,1339085722.342 [transit_3km:SURFACECOMMS:B:B] Stopped
2012-06-07T16:15:22.343Z,1339085722.343 [transit_3km:SURFACECOMMS:B:C] Running Loop=1
2012-06-07T16:15:47.502Z,1339085747.502 [NAL9601](INFO): SBD MO Status=1, MOMSN=9830, MT Status=0, MTMSN=0
2012-06-07T16:15:47.659Z,1339085747.659 [NAL9601](INFO): Sent 332 bytes from file Logs/20120607T151546/shore0004.lzma
2012-06-07T16:15:47.659Z,1339085747.659 [NAL9601](INFO): Packets left to send: 1
2012-06-07T16:15:47.661Z,1339085747.661 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000008
2012-06-07T16:15:53.197Z,1339085753.197 [NAL9601](INFO): SBD MO Status=1, MOMSN=9831, MT Status=0, MTMSN=0
2012-06-07T16:15:53.347Z,1339085753.347 [NAL9601](INFO): Sent 17 bytes from file Logs/20120607T151546/shore0004.lzma
2012-06-07T16:15:53.347Z,1339085753.347 [NAL9601](INFO): Packets left to send: 0
2012-06-07T16:15:53.348Z,1339085753.348 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000009
2012-06-07T16:16:01.192Z,1339085761.192 [NAL9601](INFO): SBD MO Status=0, MOMSN=9832, MT Status=0, MTMSN=0
2012-06-07T16:16:01.393Z,1339085761.393 [transit_3km:SURFACECOMMS:B:C] Stopped
2012-06-07T16:16:01.394Z,1339085761.394 [transit_3km:SURFACECOMMS:B:D] Running Loop=1
2012-06-07T16:16:03.599Z,1339085763.599 [NAL9601](IMPORTANT): GPS fix at: 1339085860.00
2012-06-07T16:16:03.613Z,1339085763.614 [transit_3km:SURFACECOMMS:B:D] Stopped
2012-06-07T16:16:03.614Z,1339085763.614 [transit_3km:SURFACECOMMS:B](INFO): Completed transit_3km:SURFACECOMMS:B
2012-06-07T16:16:03.614Z,1339085763.614 [transit_3km:SURFACECOMMS:B] Stopped
2012-06-07T16:16:03.614Z,1339085763.614 [transit_3km:SURFACECOMMS:B](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS:B
2012-06-07T16:16:03.614Z,1339085763.615 [transit_3km:SURFACECOMMS:B:A.SetSpeed] Stopped
2012-06-07T16:16:03.615Z,1339085763.615 [transit_3km:SURFACECOMMS:B:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T16:16:03.615Z,1339085763.615 [transit_3km:SURFACECOMMS](INFO): Completed transit_3km:SURFACECOMMS
2012-06-07T16:16:03.615Z,1339085763.615 [transit_3km:SURFACECOMMS] Stopped
2012-06-07T16:16:03.616Z,1339085763.616 [transit_3km:SURFACECOMMS](INFO): Aggregate::uninitialize transit_3km:SURFACECOMMS
2012-06-07T16:16:03.616Z,1339085763.616 [transit_3km:SURFACECOMMS:A.GoToSurface] Stopped
2012-06-07T16:16:03.616Z,1339085763.616 [transit_3km:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T16:16:04.010Z,1339085764.010 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Completed transit_3km:WaypointOne:PHONEHOMEWPT1
2012-06-07T16:16:04.010Z,1339085764.010 [transit_3km:WaypointOne:PHONEHOMEWPT1] Stopped
2012-06-07T16:16:04.010Z,1339085764.010 [transit_3km:WaypointOne:PHONEHOMEWPT1](INFO): Aggregate::uninitialize transit_3km:WaypointOne:PHONEHOMEWPT1
2012-06-07T16:16:04.011Z,1339085764.011 [transit_3km:WaypointOne](INFO): Completed transit_3km:WaypointOne
2012-06-07T16:16:04.012Z,1339085764.011 [transit_3km:WaypointOne] Stopped
2012-06-07T16:16:04.012Z,1339085764.012 [transit_3km:WaypointOne](INFO): Aggregate::uninitialize transit_3km:WaypointOne
2012-06-07T16:16:04.012Z,1339085764.012 [transit_3km:WaypointOne:A.Pitch] Stopped
2012-06-07T16:16:04.012Z,1339085764.012 [transit_3km:WaypointOne:B.SetSpeed] Stopped
2012-06-07T16:16:04.012Z,1339085764.012 [transit_3km:WaypointOne:B.SetSpeed](DEBUG): Uninitialize.
2012-06-07T16:16:04.013Z,1339085764.013 [transit_3km](INFO): Completed transit_3km
2012-06-07T16:16:04.013Z,1339085764.013 [transit_3km] Stopped
2012-06-07T16:16:04.013Z,1339085764.013 [transit_3km](INFO): Aggregate::uninitialize transit_3km
2012-06-07T16:16:04.013Z,1339085764.013 [transit_3km:A.AltitudeEnvelope] Stopped
2012-06-07T16:16:04.014Z,1339085764.013 [transit_3km:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2012-06-07T16:16:04.014Z,1339085764.014 [transit_3km:B.DepthEnvelope] Stopped
2012-06-07T16:16:04.014Z,1339085764.014 [transit_3km:B.DepthEnvelope](DEBUG): Uninitialize.
2012-06-07T16:16:04.014Z,1339085764.014 [transit_3km:C.OffshoreEnvelope] Stopped
2012-06-07T16:16:04.014Z,1339085764.014 [transit_3km:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2012-06-07T16:16:04.417Z,1339085764.417 [MissionManager](IMPORTANT): Started mission Default
2012-06-07T16:16:04.417Z,1339085764.417 [Default] Running Loop=1
2012-06-07T16:16:04.417Z,1339085764.417 [Default](INFO): Aggregate::initialize Default
2012-06-07T16:16:04.417Z,1339085764.417 [Default:D.SetSpeed] Running Loop=1
2012-06-07T16:16:04.417Z,1339085764.417 [Default:D.SetSpeed](DEBUG): Initialize.
2012-06-07T16:16:04.417Z,1339085764.418 [Default:E.GoToSurface] Running Loop=1
2012-06-07T16:16:04.418Z,1339085764.418 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:16:04.418Z,1339085764.418 [Default:Iridium] Running Loop=1
2012-06-07T16:16:04.418Z,1339085764.418 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-06-07T16:16:04.419Z,1339085764.418 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-06-07T16:16:04.419Z,1339085764.418 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-06-07T16:16:04.419Z,1339085764.419 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-06-07T16:16:04.419Z,1339085764.419 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:16:04.419Z,1339085764.420 [Default:E.GoToSurface] Running Loop=1
2012-06-07T16:16:04.425Z,1339085764.425 [Default:D.SetSpeed] Running Loop=1
2012-06-07T16:16:04.435Z,1339085764.435 [Default:Iridium:B.GoToSurface] Stopped
2012-06-07T16:16:04.435Z,1339085764.435 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T16:16:04.435Z,1339085764.435 [Default:Iridium:Read_Iridium] Running Loop=1
2012-06-07T16:16:04.436Z,1339085764.436 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-06-07T16:16:04.440Z,1339085764.440 [Default:GPS] Running Loop=1
2012-06-07T16:16:04.441Z,1339085764.441 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-06-07T16:16:04.441Z,1339085764.441 [Default:GPS:A.SetSpeed] Running Loop=1
2012-06-07T16:16:04.441Z,1339085764.441 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-06-07T16:16:04.441Z,1339085764.441 [Default:GPS:B.GoToSurface] Running Loop=1
2012-06-07T16:16:04.441Z,1339085764.441 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:16:04.447Z,1339085764.447 [Default:GPS:B.GoToSurface] Stopped
2012-06-07T16:16:04.447Z,1339085764.447 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T16:16:04.447Z,1339085764.447 [Default:GPS:Read_GPS] Running Loop=1
2012-06-07T16:16:04.447Z,1339085764.447 [Default:GPS:A.SetSpeed] Running Loop=1
2012-06-07T16:16:04.807Z,1339085764.807 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-06-07T16:16:04.810Z,1339085764.810 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-06-07T16:16:06.799Z,1339085766.799 [NAL9601](IMPORTANT): GPS fix at: 1339085863.00
2012-06-07T16:16:06.814Z,1339085766.814 [Default:GPS:Read_GPS] Stopped
2012-06-07T16:16:06.814Z,1339085766.815 [Default:GPS:D] Running Loop=1
2012-06-07T16:16:07.253Z,1339085767.253 [Default:GPS:D] Stopped
2012-06-07T16:16:07.254Z,1339085767.254 [Default:GPS](INFO): Completed Default:GPS
2012-06-07T16:16:07.254Z,1339085767.254 [Default:GPS] Stopped
2012-06-07T16:16:07.254Z,1339085767.254 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-06-07T16:16:07.254Z,1339085767.254 [Default:GPS:A.SetSpeed] Stopped
2012-06-07T16:16:07.254Z,1339085767.254 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T16:16:29.104Z,1339085789.104 [NAL9601](INFO): SBD MO Status=1, MOMSN=9833, MT Status=0, MTMSN=0
2012-06-07T16:16:29.291Z,1339085789.291 [NAL9601](INFO): Sent 167 bytes from file Logs/20120607T151546/shore0005.lzma
2012-06-07T16:16:29.291Z,1339085789.291 [NAL9601](INFO): Packets left to send: 0
2012-06-07T16:16:29.292Z,1339085789.292 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000010
2012-06-07T16:16:37.924Z,1339085797.924 [NAL9601](INFO): SBD MO Status=0, MOMSN=9834, MT Status=0, MTMSN=0
2012-06-07T16:16:38.094Z,1339085798.094 [Default:Iridium:Read_Iridium] Stopped
2012-06-07T16:16:38.095Z,1339085798.095 [Default:Iridium](INFO): Completed Default:Iridium
2012-06-07T16:16:38.095Z,1339085798.095 [Default:Iridium] Stopped
2012-06-07T16:16:38.095Z,1339085798.095 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-06-07T16:16:38.095Z,1339085798.095 [Default:Iridium:A.SetSpeed] Stopped
2012-06-07T16:16:38.095Z,1339085798.095 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T16:16:38.095Z,1339085798.095 [Default:F.Wait] Running Loop=1
2012-06-07T16:16:38.095Z,1339085798.095 [Default:F.Wait](DEBUG): Initialize Wait Component.
2012-06-07T16:16:48.451Z,1339085808.451 [NAL9601](INFO): Powering down
2012-06-07T16:21:38.472Z,1339086098.472 [Default:CallIridium] Running Loop=1
2012-06-07T16:21:38.473Z,1339086098.473 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-06-07T16:21:38.473Z,1339086098.473 [Default:CallIridium:A] Running Loop=1
2012-06-07T16:21:38.475Z,1339086098.475 [Default:CallIridium:A] Stopped
2012-06-07T16:21:38.475Z,1339086098.475 [Default:CallIridium:B] Running Loop=1
2012-06-07T16:21:38.475Z,1339086098.475 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-06-07T16:21:43.475Z,1339086103.475 [Default:Iridium] Running Loop=1
2012-06-07T16:21:43.475Z,1339086103.475 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-06-07T16:21:43.475Z,1339086103.475 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-06-07T16:21:43.475Z,1339086103.475 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-06-07T16:21:43.475Z,1339086103.475 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-06-07T16:21:43.475Z,1339086103.475 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:21:43.476Z,1339086103.476 [Default:Iridium:B.GoToSurface] Stopped
2012-06-07T16:21:43.477Z,1339086103.477 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T16:21:43.477Z,1339086103.477 [Default:Iridium:Read_Iridium] Running Loop=1
2012-06-07T16:21:43.477Z,1339086103.477 [Default:GPS] Running Loop=1
2012-06-07T16:21:43.477Z,1339086103.477 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-06-07T16:21:43.477Z,1339086103.477 [Default:GPS:A.SetSpeed] Running Loop=1
2012-06-07T16:21:43.477Z,1339086103.477 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-06-07T16:21:43.477Z,1339086103.477 [Default:GPS:B.GoToSurface] Running Loop=1
2012-06-07T16:21:43.477Z,1339086103.477 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:21:43.478Z,1339086103.478 [Default:GPS:B.GoToSurface] Stopped
2012-06-07T16:21:43.479Z,1339086103.478 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T16:21:43.479Z,1339086103.479 [Default:GPS:Read_GPS] Running Loop=1
2012-06-07T16:21:44.108Z,1339086104.108 [NAL9601](INFO): Powering up
2012-06-07T16:22:49.831Z,1339086169.831 [NAL9601](INFO): NAL9601 initialized
2012-06-07T16:22:50.906Z,1339086170.906 [NAL9601](IMPORTANT): GPS fix at: 1339086268.00
2012-06-07T16:22:50.922Z,1339086170.922 [Default:GPS:Read_GPS] Stopped
2012-06-07T16:22:50.922Z,1339086170.922 [Default:GPS:D] Running Loop=1
2012-06-07T16:22:51.340Z,1339086171.340 [Default:GPS:D] Stopped
2012-06-07T16:22:51.340Z,1339086171.341 [Default:GPS](INFO): Completed Default:GPS
2012-06-07T16:22:51.341Z,1339086171.341 [Default:GPS] Stopped
2012-06-07T16:22:51.341Z,1339086171.341 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-06-07T16:22:51.341Z,1339086171.341 [Default:GPS:A.SetSpeed] Stopped
2012-06-07T16:22:51.341Z,1339086171.341 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T16:23:08.169Z,1339086188.170 [NAL9601](INFO): SBD MO Status=1, MOMSN=9835, MT Status=0, MTMSN=0
2012-06-07T16:23:08.295Z,1339086188.295 [NAL9601](INFO): Sent 149 bytes from file Logs/20120607T151546/shore0006.lzma
2012-06-07T16:23:08.295Z,1339086188.295 [NAL9601](INFO): Packets left to send: 0
2012-06-07T16:23:08.296Z,1339086188.296 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000011
2012-06-07T16:23:17.761Z,1339086197.760 [NAL9601](INFO): SBD MO Status=0, MOMSN=9836, MT Status=0, MTMSN=0
2012-06-07T16:23:18.006Z,1339086198.006 [Default:Iridium:Read_Iridium] Stopped
2012-06-07T16:23:18.009Z,1339086198.009 [Default:Iridium](INFO): Completed Default:Iridium
2012-06-07T16:23:18.009Z,1339086198.009 [Default:Iridium] Stopped
2012-06-07T16:23:18.009Z,1339086198.009 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-06-07T16:23:18.009Z,1339086198.009 [Default:Iridium:A.SetSpeed] Stopped
2012-06-07T16:23:18.009Z,1339086198.009 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T16:23:18.177Z,1339086198.177 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2012-06-07T16:23:18.177Z,1339086198.178 [Default:CallIridium:B] Stopped
2012-06-07T16:23:18.178Z,1339086198.178 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-06-07T16:23:18.178Z,1339086198.178 [Default:CallIridium](INFO): Completed Default:CallIridium
2012-06-07T16:23:18.178Z,1339086198.178 [Default:CallIridium] Stopped
2012-06-07T16:23:18.178Z,1339086198.178 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-06-07T16:23:28.294Z,1339086208.294 [NAL9601](INFO): Powering down
2012-06-07T16:28:18.322Z,1339086498.322 [Default:CallIridium] Running Loop=1
2012-06-07T16:28:18.322Z,1339086498.322 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-06-07T16:28:18.322Z,1339086498.322 [Default:CallIridium:A] Running Loop=1
2012-06-07T16:28:18.323Z,1339086498.323 [Default:CallIridium:A] Stopped
2012-06-07T16:28:18.323Z,1339086498.323 [Default:CallIridium:B] Running Loop=1
2012-06-07T16:28:18.323Z,1339086498.323 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-06-07T16:28:23.297Z,1339086503.297 [Default:Iridium] Running Loop=1
2012-06-07T16:28:23.298Z,1339086503.298 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-06-07T16:28:23.298Z,1339086503.298 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-06-07T16:28:23.298Z,1339086503.298 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-06-07T16:28:23.298Z,1339086503.298 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-06-07T16:28:23.298Z,1339086503.298 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:28:23.299Z,1339086503.299 [Default:Iridium:B.GoToSurface] Stopped
2012-06-07T16:28:23.299Z,1339086503.299 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T16:28:23.299Z,1339086503.299 [Default:Iridium:Read_Iridium] Running Loop=1
2012-06-07T16:28:23.300Z,1339086503.300 [Default:GPS] Running Loop=1
2012-06-07T16:28:23.300Z,1339086503.300 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-06-07T16:28:23.300Z,1339086503.300 [Default:GPS:A.SetSpeed] Running Loop=1
2012-06-07T16:28:23.300Z,1339086503.300 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-06-07T16:28:23.300Z,1339086503.300 [Default:GPS:B.GoToSurface] Running Loop=1
2012-06-07T16:28:23.300Z,1339086503.300 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-06-07T16:28:23.301Z,1339086503.301 [Default:GPS:B.GoToSurface] Stopped
2012-06-07T16:28:23.301Z,1339086503.301 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-06-07T16:28:23.301Z,1339086503.301 [Default:GPS:Read_GPS] Running Loop=1
2012-06-07T16:28:23.959Z,1339086503.959 [NAL9601](INFO): Powering up
2012-06-07T16:29:29.683Z,1339086569.683 [NAL9601](INFO): NAL9601 initialized
2012-06-07T16:29:30.762Z,1339086570.762 [NAL9601](IMPORTANT): GPS fix at: 1339086669.00
2012-06-07T16:29:30.778Z,1339086570.778 [Default:GPS:Read_GPS] Stopped
2012-06-07T16:29:30.778Z,1339086570.778 [Default:GPS:D] Running Loop=1
2012-06-07T16:29:31.184Z,1339086571.184 [Default:GPS:D] Stopped
2012-06-07T16:29:31.184Z,1339086571.184 [Default:GPS](INFO): Completed Default:GPS
2012-06-07T16:29:31.185Z,1339086571.185 [Default:GPS] Stopped
2012-06-07T16:29:31.185Z,1339086571.185 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-06-07T16:29:31.185Z,1339086571.185 [Default:GPS:A.SetSpeed] Stopped
2012-06-07T16:29:31.185Z,1339086571.185 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-06-07T16:29:44.684Z,1339086584.684 [NAL9601](IMPORTANT): SBD MO Status=1, MOMSN=9837, MT Status=1, MTMSN=2733
2012-06-07T16:29:44.847Z,1339086584.847 [NAL9601](INFO): Sent 136 bytes from file Logs/20120607T151546/shore0007.lzma
2012-06-07T16:29:44.847Z,1339086584.847 [NAL9601](INFO): Packets left to send: 0
2012-06-07T16:29:44.848Z,1339086584.848 [NAL9601](INFO): Stored copy of sent data in Logs/latest/sent0000012
2012-06-07T16:29:45.268Z,1339086585.268 [NAL9601](INFO): Received command:Restart logs
2012-06-07T16:29:45.315Z,1339086585.315 [CommandLine](IMPORTANT): got command restart logs