2014-04-29T23:26:19.314Z,1398813979.314 [Supervisor](DEBUG): Initializing supervisor.
2014-04-29T23:26:19.316Z,1398813979.316 [SyncHandler](DEBUG): Created PCaller Thread at 4033C4E0
2014-04-29T23:26:19.317Z,1398813979.317 [SyncHandler](INFO): Protected caller Thread ID is 782
2014-04-29T23:26:19.317Z,1398813979.317 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-04-29T23:26:19.318Z,1398813979.318 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036C4E0
2014-04-29T23:26:19.319Z,1398813979.319 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 783
2014-04-29T23:26:19.322Z,1398813979.322 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-04-29T23:26:19.333Z,1398813979.333 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-04-29T23:26:19.334Z,1398813979.334 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039C4E0
2014-04-29T23:26:19.334Z,1398813979.334 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 784
2014-04-29T23:26:19.335Z,1398813979.335 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-04-29T23:26:19.336Z,1398813979.336 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CC4E0
2014-04-29T23:26:19.337Z,1398813979.337 [logger ThreadHandler](INFO): Protected caller Thread ID is 785
2014-04-29T23:26:19.339Z,1398813979.339 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-04-29T23:26:19.339Z,1398813979.339 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-04-29T23:26:19.343Z,1398813979.343 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-04-29T23:26:19.854Z,1398813979.854 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-04-29T23:26:19.854Z,1398813979.854 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-04-29T23:26:20.155Z,1398813980.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-04-29T23:26:20.156Z,1398813980.156 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-04-29T23:26:20.244Z,1398813980.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-04-29T23:26:20.245Z,1398813980.245 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-04-29T23:26:20.460Z,1398813980.460 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-04-29T23:26:20.461Z,1398813980.461 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-04-29T23:26:20.628Z,1398813980.628 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-04-29T23:26:20.630Z,1398813980.630 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-04-29T23:26:20.948Z,1398813980.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-04-29T23:26:20.949Z,1398813980.949 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-04-29T23:26:21.139Z,1398813981.139 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-04-29T23:26:21.141Z,1398813981.141 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-04-29T23:26:21.533Z,1398813981.533 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-04-29T23:26:21.535Z,1398813981.535 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-04-29T23:26:21.648Z,1398813981.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-04-29T23:26:21.651Z,1398813981.651 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-04-29T23:26:22.206Z,1398813982.206 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-04-29T23:26:22.207Z,1398813982.207 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-04-29T23:26:22.323Z,1398813982.323 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-04-29T23:26:22.326Z,1398813982.326 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-04-29T23:26:22.415Z,1398813982.415 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-04-29T23:26:22.529Z,1398813982.529 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-04-29T23:26:22.530Z,1398813982.530 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-04-29T23:26:22.636Z,1398813982.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-04-29T23:26:22.637Z,1398813982.637 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-04-29T23:26:22.780Z,1398813982.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-04-29T23:26:22.782Z,1398813982.782 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-04-29T23:26:22.786Z,1398813982.786 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-04-29T23:26:22.898Z,1398813982.898 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-04-29T23:26:23.034Z,1398813983.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-04-29T23:26:23.134Z,1398813983.134 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-04-29T23:26:23.230Z,1398813983.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-04-29T23:26:23.392Z,1398813983.392 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-04-29T23:26:23.515Z,1398813983.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-04-29T23:26:23.603Z,1398813983.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-04-29T23:26:23.711Z,1398813983.711 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-04-29T23:26:23.816Z,1398813983.816 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-04-29T23:26:23.916Z,1398813983.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-04-29T23:26:24.008Z,1398813984.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-04-29T23:26:24.109Z,1398813984.109 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2014-04-29T23:26:24.113Z,1398813984.113 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-04-29T23:26:24.976Z,1398813984.976 [AHRS_sp3003D] Loaded
2014-04-29T23:26:24.976Z,1398813984.976 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-04-29T23:26:25.268Z,1398813985.268 [Batt_Ocean_Server] Loaded
2014-04-29T23:26:25.268Z,1398813985.268 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-04-29T23:26:25.784Z,1398813985.784 [DataOverHttps] Loaded
2014-04-29T23:26:25.784Z,1398813985.784 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-04-29T23:26:25.797Z,1398813985.797 [Depth_Keller] Loaded
2014-04-29T23:26:25.797Z,1398813985.797 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-04-29T23:26:25.802Z,1398813985.802 [DropWeight] Loaded
2014-04-29T23:26:25.802Z,1398813985.802 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-04-29T23:26:25.900Z,1398813985.900 [NAL9602] Loaded
2014-04-29T23:26:25.901Z,1398813985.901 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-04-29T23:26:25.952Z,1398813985.952 [Onboard] Loaded
2014-04-29T23:26:25.952Z,1398813985.952 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-04-29T23:26:25.960Z,1398813985.960 [Radio_Freewave] Loaded
2014-04-29T23:26:25.960Z,1398813985.960 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2014-04-29T23:26:25.961Z,1398813985.961 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-04-29T23:26:25.961Z,1398813985.961 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-04-29T23:26:26.263Z,1398813986.263 [ExternalSim] Loaded
2014-04-29T23:26:26.264Z,1398813986.264 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2014-04-29T23:26:26.317Z,1398813986.317 [InternalSim] Loaded
2014-04-29T23:26:26.317Z,1398813986.317 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-04-29T23:26:26.317Z,1398813986.317 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-04-29T23:26:26.320Z,1398813986.320 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-04-29T23:26:26.599Z,1398813986.599 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-04-29T23:26:26.601Z,1398813986.601 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-04-29T23:26:26.609Z,1398813986.609 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2014-04-29T23:26:26.614Z,1398813986.614 [AsyncPiEstimator] Loaded
2014-04-29T23:26:26.615Z,1398813986.615 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2014-04-29T23:26:26.616Z,1398813986.616 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A34E0
2014-04-29T23:26:26.616Z,1398813986.616 [AsyncPiEstimator ThreadHandler](INFO): Protected caller Thread ID is 867
2014-04-29T23:26:26.617Z,1398813986.617 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-04-29T23:26:26.617Z,1398813986.617 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-04-29T23:26:26.716Z,1398813986.716 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-04-29T23:26:26.716Z,1398813986.716 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-04-29T23:26:26.732Z,1398813986.732 [NavChart] Loaded
2014-04-29T23:26:26.733Z,1398813986.733 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-04-29T23:26:26.737Z,1398813986.737 [UniversalFixResidualReporter] Loaded
2014-04-29T23:26:26.737Z,1398813986.737 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-04-29T23:26:26.738Z,1398813986.738 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-04-29T23:26:26.738Z,1398813986.738 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-04-29T23:26:26.806Z,1398813986.806 [VerticalControl](DEBUG): Construct VerticalControl.
2014-04-29T23:26:26.912Z,1398813986.912 [VerticalControl] Loaded
2014-04-29T23:26:26.912Z,1398813986.912 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-04-29T23:26:26.913Z,1398813986.913 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-04-29T23:26:26.981Z,1398813986.981 [HorizontalControl] Loaded
2014-04-29T23:26:26.981Z,1398813986.981 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-04-29T23:26:26.981Z,1398813986.981 [SpeedControl](DEBUG): Construct SpeedControl.
2014-04-29T23:26:26.983Z,1398813986.983 [SpeedControl] Loaded
2014-04-29T23:26:26.984Z,1398813986.984 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-04-29T23:26:26.984Z,1398813986.984 [LoopControl](DEBUG): Construct LoopControl.
2014-04-29T23:26:26.985Z,1398813986.985 [LoopControl] Loaded
2014-04-29T23:26:26.985Z,1398813986.985 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-04-29T23:26:26.985Z,1398813986.986 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-04-29T23:26:26.988Z,1398813986.988 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-04-29T23:26:27.017Z,1398813987.017 [DepthRateCalculator] Loaded
2014-04-29T23:26:27.017Z,1398813987.017 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-04-29T23:26:27.022Z,1398813987.022 [PitchRateCalculator] Loaded
2014-04-29T23:26:27.023Z,1398813987.023 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-04-29T23:26:27.030Z,1398813987.030 [SpeedCalculator] Loaded
2014-04-29T23:26:27.030Z,1398813987.030 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-04-29T23:26:27.046Z,1398813987.046 [TempGradientCalculator] Loaded
2014-04-29T23:26:27.047Z,1398813987.047 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-04-29T23:26:27.052Z,1398813987.052 [YawRateCalculator] Loaded
2014-04-29T23:26:27.052Z,1398813987.052 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-04-29T23:26:27.053Z,1398813987.053 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-04-29T23:26:27.054Z,1398813987.054 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-04-29T23:26:27.181Z,1398813987.181 [CTD_NeilBrown] Loaded
2014-04-29T23:26:27.182Z,1398813987.182 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-04-29T23:26:27.183Z,1398813987.183 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407454E0
2014-04-29T23:26:27.183Z,1398813987.183 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 868
2014-04-29T23:26:27.196Z,1398813987.196 [ISUS] Loaded
2014-04-29T23:26:27.196Z,1398813987.196 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-04-29T23:26:27.211Z,1398813987.211 [PAR_Licor] Loaded
2014-04-29T23:26:27.212Z,1398813987.212 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-04-29T23:26:27.247Z,1398813987.247 [WetLabsBB2FL] Loaded
2014-04-29T23:26:27.247Z,1398813987.247 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-04-29T23:26:27.248Z,1398813987.248 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407754E0
2014-04-29T23:26:27.249Z,1398813987.249 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 869
2014-04-29T23:26:27.249Z,1398813987.249 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-04-29T23:26:27.251Z,1398813987.251 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-04-29T23:26:27.464Z,1398813987.464 [SBIT](DEBUG): Construct Startup Built In Test.
2014-04-29T23:26:27.476Z,1398813987.476 [SBIT] Loaded
2014-04-29T23:26:27.476Z,1398813987.476 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-04-29T23:26:27.477Z,1398813987.477 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-04-29T23:26:27.489Z,1398813987.489 [IBIT] Loaded
2014-04-29T23:26:27.489Z,1398813987.489 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-04-29T23:26:27.491Z,1398813987.491 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-04-29T23:26:27.560Z,1398813987.560 [CBIT] Loaded
2014-04-29T23:26:27.560Z,1398813987.560 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-04-29T23:26:27.561Z,1398813987.561 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-04-29T23:26:27.561Z,1398813987.561 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-04-29T23:26:27.818Z,1398813987.818 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-04-29T23:26:27.819Z,1398813987.819 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-04-29T23:26:27.936Z,1398813987.936 [BuoyancyServo] Loaded
2014-04-29T23:26:27.936Z,1398813987.936 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-04-29T23:26:27.944Z,1398813987.944 [ElevatorServo] Loaded
2014-04-29T23:26:27.945Z,1398813987.945 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-04-29T23:26:27.952Z,1398813987.952 [MassServo] Loaded
2014-04-29T23:26:27.953Z,1398813987.953 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-04-29T23:26:27.961Z,1398813987.961 [RudderServo] Loaded
2014-04-29T23:26:27.962Z,1398813987.962 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-04-29T23:26:27.969Z,1398813987.969 [ThrusterServo] Loaded
2014-04-29T23:26:27.970Z,1398813987.970 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-04-29T23:26:27.970Z,1398813987.970 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-04-29T23:26:27.971Z,1398813987.971 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-04-29T23:26:28.010Z,1398813988.010 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-04-29T23:26:28.012Z,1398813988.012 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-04-29T23:26:28.013Z,1398813988.013 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-04-29T23:26:28.019Z,1398813988.019 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-04-29T23:26:28.020Z,1398813988.020 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408444E0
2014-04-29T23:26:28.020Z,1398813988.020 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 870
2014-04-29T23:26:28.025Z,1398813988.025 [Supervisor](INFO): Main Thread ID is 772
2014-04-29T23:26:28.026Z,1398813988.026 [Supervisor](DEBUG): Running supervisor.
2014-04-29T23:26:28.026Z,1398813988.026 [CommandLine ThreadHandler](INFO): Handler Thread ID is 871
2014-04-29T23:26:28.029Z,1398813988.029 [controlThread ThreadHandler](INFO): Handler Thread ID is 872
2014-04-29T23:26:28.030Z,1398813988.030 [controlThread](DEBUG): Initializing ControlThread
2014-04-29T23:26:28.033Z,1398813988.033 [logger ThreadHandler](INFO): Handler Thread ID is 873
2014-04-29T23:26:28.059Z,1398813988.059 [AsyncPiEstimator ThreadHandler](INFO): Handler Thread ID is 874
2014-04-29T23:26:28.059Z,1398813988.059 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2014-04-29T23:26:28.082Z,1398813988.082 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 875
2014-04-29T23:26:28.083Z,1398813988.083 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-04-29T23:26:28.106Z,1398813988.106 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 876
2014-04-29T23:26:28.118Z,1398813988.118 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 877
2014-04-29T23:26:28.159Z,1398813988.159 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-04-29T23:26:28.162Z,1398813988.162 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-04-29T23:26:28.162Z,1398813988.162 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-04-29T23:26:28.162Z,1398813988.162 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-04-29T23:26:28.163Z,1398813988.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-04-29T23:26:28.163Z,1398813988.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-04-29T23:26:28.163Z,1398813988.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-04-29T23:26:28.163Z,1398813988.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-04-29T23:26:28.163Z,1398813988.163 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-04-29T23:26:28.491Z,1398813988.491 [CTD_NeilBrown](ERROR): Salinity reading out of range: 0.000000 psu
2014-04-29T23:26:29.930Z,1398813989.930 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-04-29T23:26:29.956Z,1398813989.956 [ExternalSim](INFO): ExternalSim initializing...
2014-04-29T23:26:30.186Z,1398813990.186 [ExternalSim](DEBUG): beaconLat = 36.81340
2014-04-29T23:26:30.186Z,1398813990.186 [ExternalSim](DEBUG): beaconLon = -121.82240
2014-04-29T23:26:30.186Z,1398813990.186 [ExternalSim](DEBUG): beaconDepth = 25.00
2014-04-29T23:26:30.225Z,1398813990.225 [ExternalSim](DEBUG): Simulator initialized
2014-04-29T23:26:30.377Z,1398813990.377 [InternalSim](DEBUG):  InternalSim initializing...
2014-04-29T23:26:30.478Z,1398813990.478 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-04-29T23:26:30.478Z,1398813990.478 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-04-29T23:26:30.478Z,1398813990.478 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-04-29T23:26:30.479Z,1398813990.479 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-04-29T23:26:30.480Z,1398813990.480 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-04-29T23:26:30.481Z,1398813990.481 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-04-29T23:26:30.489Z,1398813990.489 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-04-29T23:26:30.490Z,1398813990.490 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-04-29T23:26:30.490Z,1398813990.490 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-04-29T23:26:30.491Z,1398813990.491 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-04-29T23:26:30.491Z,1398813990.491 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-04-29T23:26:30.492Z,1398813990.492 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-04-29T23:26:30.493Z,1398813990.493 [SBIT](INFO): Initialize SBIT Component.
2014-04-29T23:26:30.493Z,1398813990.493 [SBIT](IMPORTANT): Tethys CM Info: 
$Rev:11259
2014-04-29T23:26:30.494Z,1398813990.494 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-04-29T23:26:30.494Z,1398813990.494 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-04-29T23:26:30.501Z,1398813990.501 [IBIT](INFO): Initialize IBIT Component.
2014-04-29T23:26:30.502Z,1398813990.502 [CBIT](DEBUG): Initialize CBIT Component.
2014-04-29T23:26:30.502Z,1398813990.502 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2014-04-29T23:26:30.503Z,1398813990.503 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2014-04-29T23:26:30.528Z,1398813990.528 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-04-29T23:26:30.570Z,1398813990.570 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-29T23:26:30.594Z,1398813990.594 [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-04-29T23:26:30.595Z,1398813990.595 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-04-29T23:26:30.663Z,1398813990.663 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-04-29T23:26:30.690Z,1398813990.690 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-04-29T23:26:30.693Z,1398813990.693 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-29T23:26:30.718Z,1398813990.718 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-04-29T23:26:30.721Z,1398813990.721 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-29T23:26:30.755Z,1398813990.755 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-04-29T23:26:30.781Z,1398813990.781 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-04-29T23:26:30.804Z,1398813990.804 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-04-29T23:26:30.825Z,1398813990.825 [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>
            <Sequence/>
        </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>
            <Sequence/>
        </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>

        <Guidance:GoToSurface>
            <Parallel/>
        </Guidance:GoToSurface>

    </Aggregate>

</Mission>


2014-04-29T23:26:30.846Z,1398813990.846 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-04-29T23:26:31.391Z,1398813991.391 [Radio_Freewave](INFO): Powering up
2014-04-29T23:26:31.589Z,1398813991.589 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-04-29T23:26:31.595Z,1398813991.595 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-04-29T23:26:31.617Z,1398813991.617 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-04-29T23:26:31.623Z,1398813991.623 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-04-29T23:26:31.645Z,1398813991.645 [MassServo](DEBUG): Initializing EZServoServo.
2014-04-29T23:26:31.652Z,1398813991.652 [MassServo](DEBUG): Initializing MassServo.
2014-04-29T23:26:31.658Z,1398813991.658 [RudderServo](DEBUG): Initializing EZServoServo.
2014-04-29T23:26:31.664Z,1398813991.664 [RudderServo](DEBUG): Initializing RudderServo.
2014-04-29T23:26:31.685Z,1398813991.685 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-04-29T23:26:31.720Z,1398813991.720 [CommandLine](FAULT): Scheduling is paused
2014-04-29T23:26:33.914Z,1398813993.914 [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-04-29T23:26:35.556Z,1398813995.556 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003306
2014-04-29T23:26:38.107Z,1398813998.107 [NAL9602](IMPORTANT): GPS fix at: 1398813998.10
2014-04-29T23:26:39.313Z,1398813999.313 [NAL9602](INFO): No messages in MT queue
2014-04-29T23:26:44.930Z,1398814004.930 [NAL9602](INFO): Powering down
2014-04-29T23:26:45.820Z,1398814005.820 [SBIT](IMPORTANT): Beginning Startup BIT
2014-04-29T23:26:45.823Z,1398814005.823 [CBIT](IMPORTANT): Beginning GF scan
2014-04-29T23:27:12.219Z,1398814032.219 [CBIT](IMPORTANT): No ground fault detected
2014-04-29T23:27:39.591Z,1398814059.591 [SBIT](IMPORTANT): SBIT PASSED
2014-04-29T23:27:39.943Z,1398814059.943 [MissionManager](IMPORTANT): Started mission Startup
2014-04-29T23:27:39.943Z,1398814059.943 [Startup] Running Loop=1
2014-04-29T23:27:39.943Z,1398814059.943 [Startup](INFO): Aggregate::initialize Startup
2014-04-29T23:27:39.943Z,1398814059.943 [Startup:A.GoToSurface] Running Loop=1
2014-04-29T23:27:39.943Z,1398814059.943 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:27:39.958Z,1398814059.958 [Startup:StartupSatComms] Running Loop=1
2014-04-29T23:27:39.958Z,1398814059.958 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-04-29T23:27:39.958Z,1398814059.958 [Startup:StartupSatComms:A] Running Loop=1
2014-04-29T23:27:40.326Z,1398814060.326 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-29T23:27:40.713Z,1398814060.713 [NAL9602](INFO): Powering up
2014-04-29T23:27:45.914Z,1398814065.914 [NAL9602](IMPORTANT): GPS fix at: 1398814065.91
2014-04-29T23:27:45.929Z,1398814065.929 [Startup:StartupSatComms:A] Stopped
2014-04-29T23:27:45.929Z,1398814065.929 [Startup:StartupSatComms:B] Running Loop=1
2014-04-29T23:27:46.331Z,1398814066.331 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-29T23:27:47.124Z,1398814067.124 [NAL9602](INFO): No messages in MT queue
2014-04-29T23:27:48.713Z,1398814068.713 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140429T161519/Courier0068.lzma
2014-04-29T23:27:49.469Z,1398814069.469 [DataOverHttps](INFO): Moved sent file to Logs/20140429T161519/Courier0068.lzma.bak
2014-04-29T23:27:49.470Z,1398814069.470 [DataOverHttps](INFO): SBD MOMSN=803667
2014-04-29T23:27:54.237Z,1398814074.237 [NAL9602](INFO): Powering down
2014-04-29T23:27:57.204Z,1398814077.204 [DataOverHttps](INFO): Sending 358 bytes from file Logs/20140429T232619/Courier0000.lzma
2014-04-29T23:27:57.871Z,1398814077.871 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Courier0000.lzma.bak
2014-04-29T23:27:57.871Z,1398814077.871 [DataOverHttps](INFO): SBD MOMSN=803669
2014-04-29T23:28:02.404Z,1398814082.404 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140429T161519/Express0069.lzma
2014-04-29T23:28:03.127Z,1398814083.127 [DataOverHttps](INFO): Moved sent file to Logs/20140429T161519/Express0069.lzma.bak
2014-04-29T23:28:03.128Z,1398814083.128 [DataOverHttps](INFO): SBD MOMSN=803673
2014-04-29T23:28:10.169Z,1398814090.169 [DataOverHttps](INFO): Sending 808 bytes from file Logs/20140429T232619/Express0001.lzma
2014-04-29T23:28:10.938Z,1398814090.938 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Express0001.lzma.bak
2014-04-29T23:28:10.938Z,1398814090.938 [DataOverHttps](INFO): SBD MOMSN=803675
2014-04-29T23:28:11.360Z,1398814091.360 [Startup:StartupSatComms:B] Stopped
2014-04-29T23:28:11.361Z,1398814091.361 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-04-29T23:28:11.361Z,1398814091.361 [Startup:StartupSatComms] Stopped
2014-04-29T23:28:11.361Z,1398814091.361 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-04-29T23:28:11.363Z,1398814091.363 [Startup](INFO): Completed Startup
2014-04-29T23:28:11.363Z,1398814091.363 [Startup] Stopped
2014-04-29T23:28:11.363Z,1398814091.363 [Startup](INFO): Aggregate::uninitialize Startup
2014-04-29T23:28:11.363Z,1398814091.363 [Startup:A.GoToSurface] Stopped
2014-04-29T23:28:11.363Z,1398814091.363 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:28:11.760Z,1398814091.760 [MissionManager](IMPORTANT): Started mission Default
2014-04-29T23:28:11.760Z,1398814091.760 [Default] Running Loop=1
2014-04-29T23:28:11.760Z,1398814091.760 [Default](INFO): Aggregate::initialize Default
2014-04-29T23:28:11.760Z,1398814091.760 [Default:Iridium] Running Loop=1
2014-04-29T23:28:11.760Z,1398814091.760 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-29T23:28:11.760Z,1398814091.760 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-29T23:28:11.760Z,1398814091.760 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:28:11.761Z,1398814091.761 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-29T23:28:11.761Z,1398814091.761 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:28:11.767Z,1398814091.767 [Default:Iridium:B.GoToSurface] Stopped
2014-04-29T23:28:11.767Z,1398814091.767 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:28:11.767Z,1398814091.767 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-29T23:28:11.767Z,1398814091.767 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-29T23:28:11.772Z,1398814091.772 [Default:GPS] Running Loop=1
2014-04-29T23:28:11.772Z,1398814091.772 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-29T23:28:11.772Z,1398814091.772 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-29T23:28:11.772Z,1398814091.772 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:28:11.773Z,1398814091.773 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-29T23:28:11.773Z,1398814091.773 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:28:11.778Z,1398814091.778 [Default:GPS:B.GoToSurface] Stopped
2014-04-29T23:28:11.778Z,1398814091.778 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:28:11.778Z,1398814091.778 [Default:GPS:Read_GPS] Running Loop=1
2014-04-29T23:28:11.808Z,1398814091.808 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-29T23:28:12.758Z,1398814092.758 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-04-29T23:28:12.761Z,1398814092.761 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-04-29T23:28:13.080Z,1398814093.080 [NAL9602](INFO): Powering up
2014-04-29T23:28:15.681Z,1398814095.681 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140429T232619/Courier0004.lzma
2014-04-29T23:28:16.520Z,1398814096.520 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Courier0004.lzma.bak
2014-04-29T23:28:16.520Z,1398814096.520 [DataOverHttps](INFO): SBD MOMSN=803691
2014-04-29T23:28:18.714Z,1398814098.714 [NAL9602](IMPORTANT): GPS fix at: 1398814098.71
2014-04-29T23:28:18.750Z,1398814098.750 [Default:GPS:Read_GPS] Stopped
2014-04-29T23:28:18.750Z,1398814098.750 [Default:GPS:D] Running Loop=1
2014-04-29T23:28:19.135Z,1398814099.135 [Default:GPS:D] Stopped
2014-04-29T23:28:19.135Z,1398814099.135 [Default:GPS](INFO): Completed Default:GPS
2014-04-29T23:28:19.135Z,1398814099.135 [Default:GPS] Stopped
2014-04-29T23:28:19.135Z,1398814099.135 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-29T23:28:19.135Z,1398814099.135 [Default:GPS:A.SetSpeed] Stopped
2014-04-29T23:28:19.135Z,1398814099.135 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:28:19.957Z,1398814099.957 [NAL9602](INFO): No messages in MT queue
2014-04-29T23:28:20.940Z,1398814100.940 [DataOverHttps](INFO): Sending 103 bytes from file Logs/20140429T232619/Express0005.lzma
2014-04-29T23:28:21.735Z,1398814101.735 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Express0005.lzma.bak
2014-04-29T23:28:21.735Z,1398814101.735 [DataOverHttps](INFO): SBD MOMSN=803693
2014-04-29T23:28:22.161Z,1398814102.161 [Default:Iridium:Read_Iridium] Stopped
2014-04-29T23:28:22.162Z,1398814102.162 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-29T23:28:22.162Z,1398814102.162 [Default:Iridium] Stopped
2014-04-29T23:28:22.162Z,1398814102.162 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-29T23:28:22.162Z,1398814102.162 [Default:Iridium:A.SetSpeed] Stopped
2014-04-29T23:28:22.162Z,1398814102.162 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:28:22.162Z,1398814102.162 [Default:WaitAtTheSurface] Running Loop=1
2014-04-29T23:28:22.163Z,1398814102.163 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-04-29T23:28:22.163Z,1398814102.163 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-29T23:28:22.163Z,1398814102.163 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-04-29T23:28:22.163Z,1398814102.163 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-29T23:28:22.163Z,1398814102.163 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:28:22.552Z,1398814102.552 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-04-29T23:28:22.557Z,1398814102.557 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-04-29T23:28:28.240Z,1398814108.240 [NAL9602](INFO): Powering down
2014-04-29T23:33:22.744Z,1398814402.744 [Default:CallIridium] Running Loop=1
2014-04-29T23:33:22.745Z,1398814402.745 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-29T23:33:22.745Z,1398814402.745 [Default:CallIridium:A] Running Loop=1
2014-04-29T23:33:22.747Z,1398814402.747 [Default:CallIridium:A] Stopped
2014-04-29T23:33:22.747Z,1398814402.747 [Default:CallIridium:B] Running Loop=1
2014-04-29T23:33:22.747Z,1398814402.747 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-29T23:33:27.749Z,1398814407.749 [Default:Iridium] Running Loop=1
2014-04-29T23:33:27.750Z,1398814407.750 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-29T23:33:27.750Z,1398814407.750 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-29T23:33:27.750Z,1398814407.750 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:33:27.750Z,1398814407.750 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-29T23:33:27.750Z,1398814407.750 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:33:27.751Z,1398814407.751 [Default:Iridium:B.GoToSurface] Stopped
2014-04-29T23:33:27.751Z,1398814407.751 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:33:27.751Z,1398814407.751 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-29T23:33:27.751Z,1398814407.751 [Default:GPS] Running Loop=1
2014-04-29T23:33:27.751Z,1398814407.751 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-29T23:33:27.751Z,1398814407.751 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-29T23:33:27.751Z,1398814407.751 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:33:27.752Z,1398814407.752 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-29T23:33:27.752Z,1398814407.752 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:33:27.752Z,1398814407.752 [Default:GPS:B.GoToSurface] Stopped
2014-04-29T23:33:27.753Z,1398814407.753 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:33:27.753Z,1398814407.753 [Default:GPS:Read_GPS] Running Loop=1
2014-04-29T23:33:28.326Z,1398814408.326 [NAL9602](INFO): Powering up
2014-04-29T23:33:29.739Z,1398814409.739 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20140429T232619/Courier0008.lzma
2014-04-29T23:33:30.497Z,1398814410.497 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Courier0008.lzma.bak
2014-04-29T23:33:30.498Z,1398814410.498 [DataOverHttps](INFO): SBD MOMSN=803696
2014-04-29T23:33:33.908Z,1398814413.908 [NAL9602](IMPORTANT): GPS fix at: 1398814413.90
2014-04-29T23:33:33.928Z,1398814413.928 [Default:GPS:Read_GPS] Stopped
2014-04-29T23:33:33.928Z,1398814413.928 [Default:GPS:D] Running Loop=1
2014-04-29T23:33:34.817Z,1398814414.817 [Default:GPS:D] Stopped
2014-04-29T23:33:34.817Z,1398814414.817 [Default:GPS](INFO): Completed Default:GPS
2014-04-29T23:33:34.817Z,1398814414.817 [Default:GPS] Stopped
2014-04-29T23:33:34.818Z,1398814414.818 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-29T23:33:34.818Z,1398814414.818 [Default:GPS:A.SetSpeed] Stopped
2014-04-29T23:33:34.818Z,1398814414.818 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:33:34.888Z,1398814414.888 [DataOverHttps](INFO): Sending 106 bytes from file Logs/20140429T232619/Express0009.lzma
2014-04-29T23:33:35.271Z,1398814415.271 [NAL9602](INFO): No messages in MT queue
2014-04-29T23:33:35.664Z,1398814415.664 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Express0009.lzma.bak
2014-04-29T23:33:35.665Z,1398814415.665 [DataOverHttps](INFO): SBD MOMSN=803698
2014-04-29T23:33:36.112Z,1398814416.112 [Default:Iridium:Read_Iridium] Stopped
2014-04-29T23:33:36.113Z,1398814416.113 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-29T23:33:36.113Z,1398814416.113 [Default:Iridium] Stopped
2014-04-29T23:33:36.113Z,1398814416.113 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-29T23:33:36.113Z,1398814416.113 [Default:Iridium:A.SetSpeed] Stopped
2014-04-29T23:33:36.113Z,1398814416.113 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:33:36.528Z,1398814416.528 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-29T23:33:36.528Z,1398814416.528 [Default:CallIridium:B] Stopped
2014-04-29T23:33:36.528Z,1398814416.528 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-29T23:33:36.528Z,1398814416.528 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-29T23:33:36.528Z,1398814416.528 [Default:CallIridium] Stopped
2014-04-29T23:33:36.528Z,1398814416.528 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-29T23:33:42.120Z,1398814422.120 [NAL9602](INFO): Powering down
2014-04-29T23:38:36.675Z,1398814716.675 [Default:CallIridium] Running Loop=1
2014-04-29T23:38:36.675Z,1398814716.675 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-29T23:38:36.675Z,1398814716.675 [Default:CallIridium:A] Running Loop=1
2014-04-29T23:38:36.676Z,1398814716.676 [Default:CallIridium:A] Stopped
2014-04-29T23:38:36.676Z,1398814716.676 [Default:CallIridium:B] Running Loop=1
2014-04-29T23:38:36.676Z,1398814716.676 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-29T23:38:41.669Z,1398814721.669 [Default:Iridium] Running Loop=1
2014-04-29T23:38:41.669Z,1398814721.669 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-29T23:38:41.669Z,1398814721.669 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-29T23:38:41.669Z,1398814721.669 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:38:41.669Z,1398814721.669 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-29T23:38:41.669Z,1398814721.669 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:38:41.670Z,1398814721.670 [Default:Iridium:B.GoToSurface] Stopped
2014-04-29T23:38:41.670Z,1398814721.670 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:38:41.670Z,1398814721.670 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-29T23:38:41.671Z,1398814721.671 [Default:GPS] Running Loop=1
2014-04-29T23:38:41.671Z,1398814721.671 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-29T23:38:41.672Z,1398814721.672 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-29T23:38:41.672Z,1398814721.672 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:38:41.672Z,1398814721.672 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-29T23:38:41.672Z,1398814721.672 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:38:41.673Z,1398814721.673 [Default:GPS:B.GoToSurface] Stopped
2014-04-29T23:38:41.673Z,1398814721.673 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:38:41.673Z,1398814721.673 [Default:GPS:Read_GPS] Running Loop=1
2014-04-29T23:38:42.271Z,1398814722.271 [NAL9602](INFO): Powering up
2014-04-29T23:38:43.273Z,1398814723.273 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20140429T232619/Courier0012.lzma
2014-04-29T23:38:44.017Z,1398814724.017 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Courier0012.lzma.bak
2014-04-29T23:38:44.017Z,1398814724.017 [DataOverHttps](INFO): SBD MOMSN=803701
2014-04-29T23:38:48.242Z,1398814728.242 [NAL9602](IMPORTANT): GPS fix at: 1398814728.24
2014-04-29T23:38:48.274Z,1398814728.274 [Default:GPS:Read_GPS] Stopped
2014-04-29T23:38:48.274Z,1398814728.274 [Default:GPS:D] Running Loop=1
2014-04-29T23:38:48.375Z,1398814728.375 [Default:GPS:D] Stopped
2014-04-29T23:38:48.375Z,1398814728.375 [Default:GPS](INFO): Completed Default:GPS
2014-04-29T23:38:48.375Z,1398814728.375 [Default:GPS] Stopped
2014-04-29T23:38:48.376Z,1398814728.376 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-29T23:38:48.376Z,1398814728.376 [Default:GPS:A.SetSpeed] Stopped
2014-04-29T23:38:48.376Z,1398814728.376 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:38:49.130Z,1398814729.130 [NAL9602](INFO): No messages in MT queue
2014-04-29T23:38:50.914Z,1398814730.914 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20140429T232619/Express0013.lzma
2014-04-29T23:38:51.713Z,1398814731.713 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Express0013.lzma.bak
2014-04-29T23:38:51.714Z,1398814731.714 [DataOverHttps](INFO): SBD MOMSN=803703
2014-04-29T23:38:52.141Z,1398814732.141 [Default:Iridium:Read_Iridium] Stopped
2014-04-29T23:38:52.141Z,1398814732.141 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-29T23:38:52.141Z,1398814732.141 [Default:Iridium] Stopped
2014-04-29T23:38:52.141Z,1398814732.141 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-29T23:38:52.141Z,1398814732.141 [Default:Iridium:A.SetSpeed] Stopped
2014-04-29T23:38:52.142Z,1398814732.142 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:38:52.535Z,1398814732.535 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-29T23:38:52.535Z,1398814732.535 [Default:CallIridium:B] Stopped
2014-04-29T23:38:52.535Z,1398814732.535 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-29T23:38:52.535Z,1398814732.535 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-29T23:38:52.535Z,1398814732.535 [Default:CallIridium] Stopped
2014-04-29T23:38:52.535Z,1398814732.535 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-29T23:38:58.187Z,1398814738.187 [NAL9602](INFO): Powering down
2014-04-29T23:43:52.721Z,1398815032.721 [Default:CallIridium] Running Loop=1
2014-04-29T23:43:52.721Z,1398815032.721 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-29T23:43:52.721Z,1398815032.721 [Default:CallIridium:A] Running Loop=1
2014-04-29T23:43:52.722Z,1398815032.722 [Default:CallIridium:A] Stopped
2014-04-29T23:43:52.722Z,1398815032.722 [Default:CallIridium:B] Running Loop=1
2014-04-29T23:43:52.722Z,1398815032.722 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-29T23:43:57.712Z,1398815037.712 [Default:Iridium] Running Loop=1
2014-04-29T23:43:57.713Z,1398815037.713 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-29T23:43:57.713Z,1398815037.713 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-29T23:43:57.713Z,1398815037.713 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:43:57.713Z,1398815037.713 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-29T23:43:57.713Z,1398815037.713 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:43:57.714Z,1398815037.714 [Default:Iridium:B.GoToSurface] Stopped
2014-04-29T23:43:57.714Z,1398815037.714 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:43:57.714Z,1398815037.714 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-29T23:43:57.714Z,1398815037.714 [Default:GPS] Running Loop=1
2014-04-29T23:43:57.714Z,1398815037.714 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-29T23:43:57.714Z,1398815037.714 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-29T23:43:57.715Z,1398815037.715 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:43:57.715Z,1398815037.715 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-29T23:43:57.715Z,1398815037.715 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:43:57.716Z,1398815037.716 [Default:GPS:B.GoToSurface] Stopped
2014-04-29T23:43:57.716Z,1398815037.716 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:43:57.716Z,1398815037.716 [Default:GPS:Read_GPS] Running Loop=1
2014-04-29T23:43:58.318Z,1398815038.318 [NAL9602](INFO): Powering up
2014-04-29T23:43:59.716Z,1398815039.716 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20140429T232619/Courier0016.lzma
2014-04-29T23:44:00.464Z,1398815040.464 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Courier0016.lzma.bak
2014-04-29T23:44:00.465Z,1398815040.465 [DataOverHttps](INFO): SBD MOMSN=803706
2014-04-29T23:44:03.820Z,1398815043.820 [NAL9602](IMPORTANT): GPS fix at: 1398815043.81
2014-04-29T23:44:03.838Z,1398815043.838 [Default:GPS:Read_GPS] Stopped
2014-04-29T23:44:03.838Z,1398815043.838 [Default:GPS:D] Running Loop=1
2014-04-29T23:44:04.779Z,1398815044.779 [Default:GPS:D] Stopped
2014-04-29T23:44:04.779Z,1398815044.779 [Default:GPS](INFO): Completed Default:GPS
2014-04-29T23:44:04.779Z,1398815044.779 [Default:GPS] Stopped
2014-04-29T23:44:04.779Z,1398815044.779 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-29T23:44:04.779Z,1398815044.779 [Default:GPS:A.SetSpeed] Stopped
2014-04-29T23:44:04.780Z,1398815044.780 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:44:05.252Z,1398815045.252 [NAL9602](INFO): No messages in MT queue
2014-04-29T23:44:07.467Z,1398815047.467 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20140429T232619/Express0017.lzma
2014-04-29T23:44:08.181Z,1398815048.181 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Express0017.lzma.bak
2014-04-29T23:44:08.181Z,1398815048.181 [DataOverHttps](INFO): SBD MOMSN=803708
2014-04-29T23:44:08.628Z,1398815048.628 [Default:Iridium:Read_Iridium] Stopped
2014-04-29T23:44:08.628Z,1398815048.628 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-29T23:44:08.628Z,1398815048.628 [Default:Iridium] Stopped
2014-04-29T23:44:08.629Z,1398815048.629 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-29T23:44:08.629Z,1398815048.629 [Default:Iridium:A.SetSpeed] Stopped
2014-04-29T23:44:08.629Z,1398815048.629 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:44:09.032Z,1398815049.032 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-29T23:44:09.032Z,1398815049.032 [Default:CallIridium:B] Stopped
2014-04-29T23:44:09.032Z,1398815049.032 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-29T23:44:09.032Z,1398815049.032 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-29T23:44:09.032Z,1398815049.032 [Default:CallIridium] Stopped
2014-04-29T23:44:09.032Z,1398815049.032 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-29T23:44:14.624Z,1398815054.624 [NAL9602](INFO): Powering down
2014-04-29T23:49:09.183Z,1398815349.183 [Default:CallIridium] Running Loop=1
2014-04-29T23:49:09.183Z,1398815349.183 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-29T23:49:09.183Z,1398815349.183 [Default:CallIridium:A] Running Loop=1
2014-04-29T23:49:09.184Z,1398815349.184 [Default:CallIridium:A] Stopped
2014-04-29T23:49:09.188Z,1398815349.188 [Default:CallIridium:B] Running Loop=1
2014-04-29T23:49:09.189Z,1398815349.189 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-29T23:49:14.150Z,1398815354.150 [Default:Iridium] Running Loop=1
2014-04-29T23:49:14.150Z,1398815354.150 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-04-29T23:49:14.150Z,1398815354.150 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-04-29T23:49:14.150Z,1398815354.150 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:49:14.151Z,1398815354.151 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-04-29T23:49:14.151Z,1398815354.151 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:49:14.179Z,1398815354.179 [Default:Iridium:B.GoToSurface] Stopped
2014-04-29T23:49:14.179Z,1398815354.179 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:49:14.179Z,1398815354.179 [Default:Iridium:Read_Iridium] Running Loop=1
2014-04-29T23:49:14.180Z,1398815354.180 [Default:GPS] Running Loop=1
2014-04-29T23:49:14.180Z,1398815354.180 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-04-29T23:49:14.180Z,1398815354.180 [Default:GPS:A.SetSpeed] Running Loop=1
2014-04-29T23:49:14.180Z,1398815354.180 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-04-29T23:49:14.180Z,1398815354.180 [Default:GPS:B.GoToSurface] Running Loop=1
2014-04-29T23:49:14.180Z,1398815354.180 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-04-29T23:49:14.181Z,1398815354.181 [Default:GPS:B.GoToSurface] Stopped
2014-04-29T23:49:14.181Z,1398815354.181 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:49:14.181Z,1398815354.181 [Default:GPS:Read_GPS] Running Loop=1
2014-04-29T23:49:14.787Z,1398815354.787 [NAL9602](INFO): Powering up
2014-04-29T23:49:16.191Z,1398815356.191 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20140429T232619/Courier0020.lzma
2014-04-29T23:49:16.932Z,1398815356.932 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Courier0020.lzma.bak
2014-04-29T23:49:16.932Z,1398815356.932 [DataOverHttps](INFO): SBD MOMSN=803711
2014-04-29T23:49:20.286Z,1398815360.286 [NAL9602](IMPORTANT): GPS fix at: 1398815360.28
2014-04-29T23:49:20.303Z,1398815360.303 [Default:GPS:Read_GPS] Stopped
2014-04-29T23:49:20.304Z,1398815360.304 [Default:GPS:D] Running Loop=1
2014-04-29T23:49:21.252Z,1398815361.252 [Default:GPS:D] Stopped
2014-04-29T23:49:21.252Z,1398815361.252 [Default:GPS](INFO): Completed Default:GPS
2014-04-29T23:49:21.252Z,1398815361.252 [Default:GPS] Stopped
2014-04-29T23:49:21.253Z,1398815361.253 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-04-29T23:49:21.253Z,1398815361.253 [Default:GPS:A.SetSpeed] Stopped
2014-04-29T23:49:21.253Z,1398815361.253 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:49:21.699Z,1398815361.699 [NAL9602](INFO): No messages in MT queue
2014-04-29T23:49:23.933Z,1398815363.933 [DataOverHttps](INFO): Sending 110 bytes from file Logs/20140429T232619/Express0021.lzma
2014-04-29T23:49:24.649Z,1398815364.649 [DataOverHttps](INFO): Moved sent file to Logs/20140429T232619/Express0021.lzma.bak
2014-04-29T23:49:24.650Z,1398815364.650 [DataOverHttps](INFO): SBD MOMSN=803713
2014-04-29T23:49:25.090Z,1398815365.090 [Default:Iridium:Read_Iridium] Stopped
2014-04-29T23:49:25.090Z,1398815365.090 [Default:Iridium](INFO): Completed Default:Iridium
2014-04-29T23:49:25.090Z,1398815365.090 [Default:Iridium] Stopped
2014-04-29T23:49:25.090Z,1398815365.090 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-29T23:49:25.090Z,1398815365.090 [Default:Iridium:A.SetSpeed] Stopped
2014-04-29T23:49:25.090Z,1398815365.090 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:49:25.503Z,1398815365.503 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-04-29T23:49:25.503Z,1398815365.503 [Default:CallIridium:B] Stopped
2014-04-29T23:49:25.503Z,1398815365.503 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-29T23:49:25.504Z,1398815365.504 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-04-29T23:49:25.504Z,1398815365.504 [Default:CallIridium] Stopped
2014-04-29T23:49:25.504Z,1398815365.504 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-29T23:49:31.105Z,1398815371.105 [NAL9602](INFO): Powering down
2014-04-29T23:53:45.564Z,1398815625.564 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#6 STATUS: 65535
2014-04-29T23:54:25.657Z,1398815665.657 [Default:CallIridium] Running Loop=1
2014-04-29T23:54:25.658Z,1398815665.658 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-04-29T23:54:25.658Z,1398815665.658 [Default:CallIridium:A] Running Loop=1
2014-04-29T23:54:25.658Z,1398815665.658 [Default:CallIridium:A] Stopped
2014-04-29T23:54:25.658Z,1398815665.658 [Default:CallIridium:B] Running Loop=1
2014-04-29T23:54:25.658Z,1398815665.658 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-04-29T23:54:27.364Z,1398815667.364 [CommandLine](IMPORTANT): got command quit
2014-04-29T23:54:28.370Z,1398815668.370 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-04-29T23:54:28.370Z,1398815668.370 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:28.463Z,1398815668.463 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-04-29T23:54:28.463Z,1398815668.463 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:28.464Z,1398815668.464 [CommandLine](INFO): Join timeout helper Thread ID is 1024
2014-04-29T23:54:28.464Z,1398815668.464 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-04-29T23:54:28.464Z,1398815668.464 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:28.465Z,1398815668.465 [NavChartDb](INFO): Join timeout helper Thread ID is 1025
2014-04-29T23:54:28.784Z,1398815668.784 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-04-29T23:54:28.784Z,1398815668.784 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:28.803Z,1398815668.803 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-04-29T23:54:28.804Z,1398815668.804 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:28.804Z,1398815668.804 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1026
2014-04-29T23:54:28.832Z,1398815668.832 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-04-29T23:54:28.832Z,1398815668.832 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:28.843Z,1398815668.843 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-04-29T23:54:28.844Z,1398815668.844 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:28.844Z,1398815668.844 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1027
2014-04-29T23:54:29.048Z,1398815669.048 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-04-29T23:54:29.048Z,1398815669.048 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:29.064Z,1398815669.064 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2014-04-29T23:54:29.064Z,1398815669.064 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:29.064Z,1398815669.064 [AsyncPiEstimator](INFO): Join timeout helper Thread ID is 1028
2014-04-29T23:54:29.393Z,1398815669.393 [AsyncPiEstimator ThreadHandler](INFO): Uninitializing protected caller thread.
2014-04-29T23:54:29.393Z,1398815669.393 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2014-04-29T23:54:29.393Z,1398815669.393 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:29.405Z,1398815669.405 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-04-29T23:54:29.406Z,1398815669.406 [logger ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:29.406Z,1398815669.406 [logger](INFO): Join timeout helper Thread ID is 1029
2014-04-29T23:54:29.421Z,1398815669.421 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-04-29T23:54:29.421Z,1398815669.421 [logger ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:29.425Z,1398815669.425 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-04-29T23:54:29.425Z,1398815669.425 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:29.425Z,1398815669.425 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-04-29T23:54:29.426Z,1398815669.426 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:29.426Z,1398815669.426 [controlThread](INFO): Join timeout helper Thread ID is 1030
2014-04-29T23:54:30.414Z,1398815670.414 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-04-29T23:54:30.414Z,1398815670.414 [controlThread](DEBUG): Uninitializing ControlThread
2014-04-29T23:54:30.416Z,1398815670.416 [NAL9602](INFO): Powering down
2014-04-29T23:54:30.503Z,1398815670.503 [Radio_Freewave](INFO): Powering down
2014-04-29T23:54:30.505Z,1398815670.505 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-04-29T23:54:30.507Z,1398815670.507 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-04-29T23:54:30.507Z,1398815670.507 [Default] Stopped
2014-04-29T23:54:30.507Z,1398815670.507 [Default](INFO): Aggregate::uninitialize Default
2014-04-29T23:54:30.508Z,1398815670.508 [Default:Iridium] Stopped
2014-04-29T23:54:30.508Z,1398815670.508 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-04-29T23:54:30.508Z,1398815670.508 [Default:CallIridium] Stopped
2014-04-29T23:54:30.508Z,1398815670.508 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-04-29T23:54:30.508Z,1398815670.508 [Default:CallIridium:B] Stopped
2014-04-29T23:54:30.508Z,1398815670.508 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-04-29T23:54:30.509Z,1398815670.509 [Default:WaitAtTheSurface] Stopped
2014-04-29T23:54:30.509Z,1398815670.509 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-04-29T23:54:30.509Z,1398815670.509 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-04-29T23:54:30.509Z,1398815670.509 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-04-29T23:54:30.509Z,1398815670.509 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-04-29T23:54:30.509Z,1398815670.509 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-04-29T23:54:30.516Z,1398815670.516 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-04-29T23:54:30.516Z,1398815670.516 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-04-29T23:54:30.516Z,1398815670.516 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-04-29T23:54:30.517Z,1398815670.517 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-04-29T23:54:30.517Z,1398815670.517 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-04-29T23:54:30.517Z,1398815670.517 [BuoyancyServo](INFO): Powering down
2014-04-29T23:54:30.531Z,1398815670.531 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-04-29T23:54:30.531Z,1398815670.531 [ElevatorServo](INFO): Powering down
2014-04-29T23:54:30.532Z,1398815670.532 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-04-29T23:54:30.532Z,1398815670.532 [MassServo](INFO): Powering down
2014-04-29T23:54:30.533Z,1398815670.533 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-04-29T23:54:30.533Z,1398815670.533 [RudderServo](INFO): Powering down
2014-04-29T23:54:30.534Z,1398815670.534 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-04-29T23:54:30.534Z,1398815670.534 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-04-29T23:54:30.535Z,1398815670.535 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-04-29T23:54:30.535Z,1398815670.535 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-04-29T23:54:30.580Z,1398815670.580 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:30.649Z,1398815670.649 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:30.671Z,1398815670.671 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:30.675Z,1398815670.675 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:30.703Z,1398815670.703 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-04-29T23:54:30.758Z,1398815670.758 [logger ThreadHandler](INFO): Thread cancelled.