2013-05-15T18:36:50.450Z,1368643010.450 [Supervisor](DEBUG): Initializing supervisor.
2013-05-15T18:36:50.454Z,1368643010.454 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-05-15T18:36:50.455Z,1368643010.455 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-05-15T18:36:50.458Z,1368643010.458 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-05-15T18:36:50.462Z,1368643010.462 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-05-15T18:36:50.472Z,1368643010.472 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-05-15T18:36:50.474Z,1368643010.474 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-05-15T18:36:50.475Z,1368643010.475 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-05-15T18:36:50.478Z,1368643010.478 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-05-15T18:36:50.479Z,1368643010.479 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-05-15T18:36:50.483Z,1368643010.483 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-05-15T18:36:50.821Z,1368643010.821 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-05-15T18:36:50.822Z,1368643010.822 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-05-15T18:36:51.042Z,1368643011.042 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-05-15T18:36:51.042Z,1368643011.042 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-05-15T18:36:51.138Z,1368643011.138 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-05-15T18:36:51.140Z,1368643011.140 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-05-15T18:36:51.305Z,1368643011.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-05-15T18:36:51.305Z,1368643011.305 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-05-15T18:36:51.462Z,1368643011.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-05-15T18:36:51.464Z,1368643011.464 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-05-15T18:36:51.731Z,1368643011.731 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-05-15T18:36:51.732Z,1368643011.732 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-05-15T18:36:51.926Z,1368643011.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-05-15T18:36:51.928Z,1368643011.928 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-05-15T18:36:52.220Z,1368643012.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-05-15T18:36:52.222Z,1368643012.222 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-05-15T18:36:52.336Z,1368643012.336 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-05-15T18:36:52.337Z,1368643012.337 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-05-15T18:36:52.788Z,1368643012.788 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-05-15T18:36:52.789Z,1368643012.789 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-05-15T18:36:52.922Z,1368643012.922 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-05-15T18:36:52.923Z,1368643012.923 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-05-15T18:36:54.219Z,1368643014.219 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-05-15T18:36:54.226Z,1368643014.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-05-15T18:36:55.036Z,1368643015.036 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-05-15T18:36:55.184Z,1368643015.184 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-05-15T18:36:55.282Z,1368643015.282 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-05-15T18:36:55.400Z,1368643015.400 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-05-15T18:36:55.510Z,1368643015.510 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-05-15T18:36:55.647Z,1368643015.648 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-05-15T18:36:55.752Z,1368643015.751 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-05-15T18:36:55.850Z,1368643015.850 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-05-15T18:36:55.856Z,1368643015.856 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-05-15T18:36:56.058Z,1368643016.058 [InternalSim] Loaded
2013-05-15T18:36:56.058Z,1368643016.058 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-05-15T18:36:56.059Z,1368643016.059 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-05-15T18:36:56.060Z,1368643016.060 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-05-15T18:36:56.144Z,1368643016.144 [SBIT](DEBUG): Construct Startup Built In Test.
2013-05-15T18:36:56.177Z,1368643016.177 [SBIT] Loaded
2013-05-15T18:36:56.177Z,1368643016.177 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-05-15T18:36:56.178Z,1368643016.178 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-05-15T18:36:56.210Z,1368643016.210 [IBIT] Loaded
2013-05-15T18:36:56.210Z,1368643016.210 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-05-15T18:36:56.214Z,1368643016.214 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-05-15T18:36:56.343Z,1368643016.343 [CBIT] Loaded
2013-05-15T18:36:56.343Z,1368643016.343 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-05-15T18:36:56.344Z,1368643016.344 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-05-15T18:36:56.345Z,1368643016.345 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-05-15T18:36:56.528Z,1368643016.528 [BuoyancyServo] Loaded
2013-05-15T18:36:56.528Z,1368643016.528 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-05-15T18:36:56.540Z,1368643016.540 [ElevatorServo] Loaded
2013-05-15T18:36:56.540Z,1368643016.540 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-05-15T18:36:56.556Z,1368643016.556 [MassServo] Loaded
2013-05-15T18:36:56.557Z,1368643016.557 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-05-15T18:36:56.568Z,1368643016.569 [RudderServo] Loaded
2013-05-15T18:36:56.569Z,1368643016.569 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-05-15T18:36:56.581Z,1368643016.581 [ThrusterServo] Loaded
2013-05-15T18:36:56.581Z,1368643016.581 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-05-15T18:36:56.581Z,1368643016.581 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-05-15T18:36:56.582Z,1368643016.582 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-05-15T18:36:56.618Z,1368643016.618 [DepthRateCalculator] Loaded
2013-05-15T18:36:56.619Z,1368643016.619 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-05-15T18:37:00.314Z,1368643020.314 [HFRadarModelCalc] Loaded
2013-05-15T18:37:00.314Z,1368643020.314 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-05-15T18:37:00.331Z,1368643020.330 [NavChart] Loaded
2013-05-15T18:37:00.331Z,1368643020.331 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-05-15T18:37:00.336Z,1368643020.336 [PitchRateCalculator] Loaded
2013-05-15T18:37:00.337Z,1368643020.337 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-05-15T18:37:00.347Z,1368643020.347 [SpeedCalculator] Loaded
2013-05-15T18:37:00.348Z,1368643020.348 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-05-15T18:37:00.363Z,1368643020.362 [TempGradientCalculator] Loaded
2013-05-15T18:37:00.363Z,1368643020.363 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-05-15T18:37:00.369Z,1368643020.369 [YawRateCalculator] Loaded
2013-05-15T18:37:00.369Z,1368643020.369 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-05-15T18:37:00.415Z,1368643020.415 [Navigation] Loaded
2013-05-15T18:37:00.415Z,1368643020.415 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-05-15T18:37:00.415Z,1368643020.415 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-05-15T18:37:00.416Z,1368643020.416 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-05-15T18:37:00.693Z,1368643020.693 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-05-15T18:37:00.693Z,1368643020.694 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-05-15T18:37:00.739Z,1368643020.739 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-05-15T18:37:00.740Z,1368643020.740 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-05-15T18:37:00.806Z,1368643020.806 [VerticalControl](DEBUG): Construct VerticalControl.
2013-05-15T18:37:00.907Z,1368643020.907 [VerticalControl] Loaded
2013-05-15T18:37:00.907Z,1368643020.907 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-05-15T18:37:00.908Z,1368643020.908 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-05-15T18:37:00.972Z,1368643020.972 [HorizontalControl] Loaded
2013-05-15T18:37:00.972Z,1368643020.972 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-05-15T18:37:00.973Z,1368643020.973 [SpeedControl](DEBUG): Construct SpeedControl.
2013-05-15T18:37:00.975Z,1368643020.975 [SpeedControl] Loaded
2013-05-15T18:37:00.975Z,1368643020.975 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-05-15T18:37:00.976Z,1368643020.976 [LoopControl](DEBUG): Construct LoopControl.
2013-05-15T18:37:00.976Z,1368643020.976 [LoopControl] Loaded
2013-05-15T18:37:00.977Z,1368643020.977 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-05-15T18:37:00.977Z,1368643020.977 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-05-15T18:37:00.978Z,1368643020.978 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-05-15T18:37:00.986Z,1368643020.986 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-05-15T18:37:00.991Z,1368643020.991 [AsyncPiEstimator] Loaded
2013-05-15T18:37:00.991Z,1368643020.991 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-05-15T18:37:00.994Z,1368643020.994 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-05-15T18:37:00.995Z,1368643020.995 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-05-15T18:37:00.996Z,1368643020.996 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-05-15T18:37:01.179Z,1368643021.180 [AHRS_sp3003D] Loaded
2013-05-15T18:37:01.180Z,1368643021.180 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-05-15T18:37:01.471Z,1368643021.471 [Batt_Ocean_Server] Loaded
2013-05-15T18:37:01.472Z,1368643021.472 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-05-15T18:37:01.486Z,1368643021.486 [Depth_Keller] Loaded
2013-05-15T18:37:01.486Z,1368643021.486 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-05-15T18:37:01.491Z,1368643021.491 [DropWeight] Loaded
2013-05-15T18:37:01.492Z,1368643021.492 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-05-15T18:37:01.689Z,1368643021.689 [DVL_micro] Loaded
2013-05-15T18:37:01.689Z,1368643021.689 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-05-15T18:37:01.690Z,1368643021.690 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406C04E0
2013-05-15T18:37:01.784Z,1368643021.784 [NAL9602] Loaded
2013-05-15T18:37:01.785Z,1368643021.784 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-05-15T18:37:01.840Z,1368643021.840 [Onboard] Loaded
2013-05-15T18:37:01.840Z,1368643021.840 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-05-15T18:37:01.847Z,1368643021.847 [Radio_Freewave] Loaded
2013-05-15T18:37:01.847Z,1368643021.847 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-05-15T18:37:01.848Z,1368643021.848 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-05-15T18:37:01.849Z,1368643021.849 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-05-15T18:37:01.952Z,1368643021.952 [CTD_NeilBrown] Loaded
2013-05-15T18:37:01.952Z,1368643021.952 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-05-15T18:37:01.954Z,1368643021.954 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407124E0
2013-05-15T18:37:01.990Z,1368643021.990 [WetLabsBB2FL] Loaded
2013-05-15T18:37:01.990Z,1368643021.990 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-05-15T18:37:01.994Z,1368643021.994 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407424E0
2013-05-15T18:37:01.995Z,1368643021.995 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-05-15T18:37:01.997Z,1368643021.997 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-05-15T18:37:01.998Z,1368643021.998 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-05-15T18:37:02.005Z,1368643022.005 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-05-15T18:37:02.006Z,1368643022.006 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407724E0
2013-05-15T18:37:02.011Z,1368643022.011 [Supervisor](DEBUG): Running supervisor.
2013-05-15T18:37:02.015Z,1368643022.015 [CommandLine](INFO): Thread ID is 753
2013-05-15T18:37:02.017Z,1368643022.017 [controlThread](INFO): Thread ID is 752
2013-05-15T18:37:02.017Z,1368643022.017 [controlThread](DEBUG): Initializing ControlThread
2013-05-15T18:37:02.018Z,1368643022.018 [CycleStarter](INFO): Thread ID is 751
2013-05-15T18:37:02.018Z,1368643022.018 [InternalSim](DEBUG):  InternalSim initializing...
2013-05-15T18:37:02.133Z,1368643022.133 [logger](INFO): Thread ID is 754
2013-05-15T18:37:02.243Z,1368643022.243 [AsyncPiEstimator](INFO): Thread ID is 815
2013-05-15T18:37:02.243Z,1368643022.243 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-05-15T18:37:02.259Z,1368643022.259 [DVL_micro](INFO): Thread ID is 816
2013-05-15T18:37:02.359Z,1368643022.359 [CTD_NeilBrown](INFO): Thread ID is 817
2013-05-15T18:37:02.360Z,1368643022.360 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-05-15T18:37:02.363Z,1368643022.363 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-05-15T18:37:02.415Z,1368643022.415 [DVL_micro](INFO): Initializing
2013-05-15T18:37:02.416Z,1368643022.416 [DVL_micro](INFO): start:Powering up
2013-05-15T18:37:02.417Z,1368643022.417 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-15T18:37:02.417Z,1368643022.417 [DVL_micro](INFO): Cycling power to configure device.
2013-05-15T18:37:02.427Z,1368643022.427 [WetLabsBB2FL](INFO): Thread ID is 818
2013-05-15T18:37:02.428Z,1368643022.428 [WetLabsBB2FL](INFO): Powering down
2013-05-15T18:37:02.463Z,1368643022.463 [SBIT](INFO): Initialize SBIT Component.
2013-05-15T18:37:02.463Z,1368643022.463 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10336
2013-05-15T18:37:02.464Z,1368643022.464 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-05-15T18:37:02.464Z,1368643022.464 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-05-15T18:37:02.464Z,1368643022.464 [IBIT](INFO): Initialize IBIT Component.
2013-05-15T18:37:02.465Z,1368643022.465 [CBIT](DEBUG): Initialize CBIT Component.
2013-05-15T18:37:02.465Z,1368643022.466 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-05-15T18:37:02.467Z,1368643022.467 [NavChartDb](INFO): Thread ID is 819
2013-05-15T18:37:02.480Z,1368643022.480 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-05-15T18:37:02.481Z,1368643022.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-05-15T18:37:02.481Z,1368643022.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-05-15T18:37:02.481Z,1368643022.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-05-15T18:37:02.481Z,1368643022.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-05-15T18:37:02.481Z,1368643022.481 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-05-15T18:37:02.482Z,1368643022.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-05-15T18:37:02.482Z,1368643022.482 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-05-15T18:37:02.483Z,1368643022.483 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-05-15T18:37:02.512Z,1368643022.512 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-15T18:37:02.512Z,1368643022.512 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-05-15T18:37:02.513Z,1368643022.513 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-05-15T18:37:02.513Z,1368643022.513 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-05-15T18:37:02.513Z,1368643022.513 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-05-15T18:37:02.525Z,1368643022.525 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-05-15T18:37:02.526Z,1368643022.526 [Navigation](DEBUG): Initializing Navigation.
2013-05-15T18:37:02.526Z,1368643022.526 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-05-15T18:37:02.528Z,1368643022.528 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-05-15T18:37:02.528Z,1368643022.528 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-05-15T18:37:02.529Z,1368643022.529 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-05-15T18:37:04.108Z,1368643024.108 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2013-05-15T18:37:04.108Z,1368643024.108 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2013-05-15T18:37:04.108Z,1368643024.108 [Batt_Ocean_Server] Communications Fault, FailCount= 1
2013-05-15T18:37:04.108Z,1368643024.108 [Batt_Ocean_Server](ERROR): Communications Fault
2013-05-15T18:37:04.116Z,1368643024.116 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-05-15T18:37:04.170Z,1368643024.170 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-15T18:37:04.231Z,1368643024.231 [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>


2013-05-15T18:37:04.232Z,1368643024.232 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-05-15T18:37:04.373Z,1368643024.373 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-05-15T18:37:04.375Z,1368643024.375 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-05-15T18:37:04.378Z,1368643024.378 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-15T18:37:04.468Z,1368643024.468 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-05-15T18:37:04.479Z,1368643024.479 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-15T18:37:04.486Z,1368643024.486 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-05-15T18:37:04.531Z,1368643024.531 [Default:D.SetSpeed](DEBUG): Construct.
2013-05-15T18:37:04.543Z,1368643024.543 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-15T18:37:04.543Z,1368643024.543 [DVL_micro](INFO): Querying output modes
2013-05-15T18:37:04.543Z,1368643024.543 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-15T18:37:04.554Z,1368643024.554 [DVL_micro](DEBUG): cmdResponse: 01
2013-05-15T18:37:04.555Z,1368643024.555 [DVL_micro](INFO): NQ1 output enabled
2013-05-15T18:37:04.555Z,1368643024.555 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-15T18:37:04.534Z,1368643024.534 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-15T18:37:04.563Z,1368643024.563 [Default:F.Wait](DEBUG): Construct Wait.
2013-05-15T18:37:04.567Z,1368643024.567 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-05-15T18:37:04.572Z,1368643024.572 [DVL_micro](INFO): pause:Powering down
2013-05-15T18:37:04.597Z,1368643024.597 [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>


2013-05-15T18:37:04.601Z,1368643024.601 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-05-15T18:37:04.682Z,1368643024.682 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-05-15T18:37:04.913Z,1368643024.913 [Radio_Freewave](INFO): Powering up
2013-05-15T18:37:05.187Z,1368643025.187 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-05-15T18:37:05.195Z,1368643025.195 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-05-15T18:37:05.209Z,1368643025.209 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-05-15T18:37:05.215Z,1368643025.215 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-05-15T18:37:05.257Z,1368643025.257 [MassServo](DEBUG): Initializing EZServoServo.
2013-05-15T18:37:05.267Z,1368643025.267 [MassServo](DEBUG): Initializing MassServo.
2013-05-15T18:37:05.280Z,1368643025.280 [RudderServo](DEBUG): Initializing EZServoServo.
2013-05-15T18:37:05.306Z,1368643025.306 [RudderServo](DEBUG): Initializing RudderServo.
2013-05-15T18:37:05.312Z,1368643025.312 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-05-15T18:37:05.323Z,1368643025.323 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-05-15T18:37:05.392Z,1368643025.392 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2013-05-15T18:37:05.393Z,1368643025.393 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server
2013-05-15T18:37:05.393Z,1368643025.393 [Batt_Ocean_Server] No Fault, FailCount= 1
2013-05-15T18:37:07.594Z,1368643027.594 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-05-15T18:37:07.637Z,1368643027.637 [NAL9602](INFO): Powering up NAL9602
2013-05-15T18:37:18.263Z,1368643038.263 [SBIT](IMPORTANT): Beginning Startup BIT
2013-05-15T18:37:18.266Z,1368643038.266 [CBIT](IMPORTANT): Beginning GF scan
2013-05-15T18:37:18.507Z,1368643038.507 [NAL9602](INFO): NAL9602 initialized
2013-05-15T18:37:45.099Z,1368643065.099 [CBIT](IMPORTANT): No ground fault detected
2013-05-15T18:37:58.220Z,1368643078.220 [NAL9602](IMPORTANT): GPS fix at: 1368643016.00
2013-05-15T18:38:05.596Z,1368643085.596 [NAL9602](INFO): Powering down
2013-05-15T18:38:12.014Z,1368643092.014 [SBIT](IMPORTANT): SBIT PASSED
2013-05-15T18:38:12.373Z,1368643092.373 [MissionManager](IMPORTANT): Started mission Startup
2013-05-15T18:38:12.373Z,1368643092.373 [Startup] Running Loop=1
2013-05-15T18:38:12.373Z,1368643092.373 [Startup](INFO): Aggregate::initialize Startup
2013-05-15T18:38:12.373Z,1368643092.373 [Startup:A.GoToSurface] Running Loop=1
2013-05-15T18:38:12.373Z,1368643092.373 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:38:12.380Z,1368643092.379 [Startup:StartupSatComms] Running Loop=1
2013-05-15T18:38:12.380Z,1368643092.380 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-05-15T18:38:12.380Z,1368643092.380 [Startup:StartupSatComms:A] Running Loop=1
2013-05-15T18:38:12.776Z,1368643092.776 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-15T18:38:13.160Z,1368643093.159 [NAL9602](INFO): Powering up
2013-05-15T18:38:24.163Z,1368643104.163 [NAL9602](INFO): NAL9602 initialized
2013-05-15T18:39:00.779Z,1368643140.779 [NAL9602](IMPORTANT): GPS fix at: 1368643078.00
2013-05-15T18:39:00.791Z,1368643140.792 [Startup:StartupSatComms:A] Stopped
2013-05-15T18:39:00.792Z,1368643140.792 [Startup:StartupSatComms:B] Running Loop=1
2013-05-15T18:39:01.206Z,1368643141.206 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-15T18:40:01.065Z,1368643201.065 [Startup:StartupSatComms:B](INFO): Timed out from 2013-05-15T18:39:00.8Z
2013-05-15T18:40:01.065Z,1368643201.066 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-05-15T18:40:01.066Z,1368643201.066 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-05-15T18:40:01.066Z,1368643201.066 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-05-15T18:40:01.066Z,1368643201.066 [Startup:StartupSatComms:B] Stopped
2013-05-15T18:40:01.066Z,1368643201.066 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-05-15T18:40:01.066Z,1368643201.066 [Startup:StartupSatComms] Stopped
2013-05-15T18:40:01.067Z,1368643201.066 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-05-15T18:40:01.067Z,1368643201.067 [Startup](INFO): Completed Startup
2013-05-15T18:40:01.068Z,1368643201.068 [Startup] Stopped
2013-05-15T18:40:01.068Z,1368643201.068 [Startup](INFO): Aggregate::uninitialize Startup
2013-05-15T18:40:01.068Z,1368643201.068 [Startup:A.GoToSurface] Stopped
2013-05-15T18:40:01.068Z,1368643201.068 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T18:40:02.052Z,1368643202.052 [MissionManager](IMPORTANT): Started mission Default
2013-05-15T18:40:02.052Z,1368643202.052 [Default] Running Loop=1
2013-05-15T18:40:02.052Z,1368643202.052 [Default](INFO): Aggregate::initialize Default
2013-05-15T18:40:02.052Z,1368643202.052 [Default:D.SetSpeed] Running Loop=1
2013-05-15T18:40:02.052Z,1368643202.052 [Default:D.SetSpeed](DEBUG): Initialize.
2013-05-15T18:40:02.052Z,1368643202.052 [Default:E.GoToSurface] Running Loop=1
2013-05-15T18:40:02.052Z,1368643202.052 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:40:02.052Z,1368643202.053 [Default:Iridium] Running Loop=1
2013-05-15T18:40:02.053Z,1368643202.053 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-15T18:40:02.053Z,1368643202.053 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-15T18:40:02.053Z,1368643202.053 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-15T18:40:02.053Z,1368643202.053 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-15T18:40:02.053Z,1368643202.053 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:40:02.054Z,1368643202.053 [Default:E.GoToSurface] Running Loop=1
2013-05-15T18:40:02.059Z,1368643202.059 [Default:D.SetSpeed] Running Loop=1
2013-05-15T18:40:02.064Z,1368643202.064 [Default:CallIridium] Running Loop=1
2013-05-15T18:40:02.064Z,1368643202.065 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-15T18:40:02.065Z,1368643202.065 [Default:CallIridium:A] Running Loop=1
2013-05-15T18:40:02.067Z,1368643202.067 [Default:CallIridium:A] Stopped
2013-05-15T18:40:02.067Z,1368643202.067 [Default:CallIridium:B] Running Loop=1
2013-05-15T18:40:02.067Z,1368643202.067 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-15T18:40:02.072Z,1368643202.072 [Default:Iridium:B.GoToSurface] Stopped
2013-05-15T18:40:02.073Z,1368643202.073 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T18:40:02.073Z,1368643202.073 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-15T18:40:02.073Z,1368643202.073 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-15T18:40:02.078Z,1368643202.078 [Default:GPS] Running Loop=1
2013-05-15T18:40:02.078Z,1368643202.078 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-15T18:40:02.078Z,1368643202.078 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-15T18:40:02.078Z,1368643202.078 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-15T18:40:02.079Z,1368643202.079 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-15T18:40:02.079Z,1368643202.079 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:40:02.084Z,1368643202.084 [Default:GPS:B.GoToSurface] Stopped
2013-05-15T18:40:02.084Z,1368643202.084 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T18:40:02.084Z,1368643202.084 [Default:GPS:Read_GPS] Running Loop=1
2013-05-15T18:40:02.084Z,1368643202.085 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-15T18:40:02.327Z,1368643202.327 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-15T18:40:02.329Z,1368643202.329 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-15T18:40:03.491Z,1368643203.491 [NAL9602](IMPORTANT): GPS fix at: 1368643141.00
2013-05-15T18:40:03.506Z,1368643203.506 [Default:GPS:Read_GPS] Stopped
2013-05-15T18:40:03.506Z,1368643203.506 [Default:GPS:D] Running Loop=1
2013-05-15T18:40:03.917Z,1368643203.917 [Default:GPS:D] Stopped
2013-05-15T18:40:03.917Z,1368643203.917 [Default:GPS](INFO): Completed Default:GPS
2013-05-15T18:40:03.918Z,1368643203.918 [Default:GPS] Stopped
2013-05-15T18:40:03.918Z,1368643203.918 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-15T18:40:03.918Z,1368643203.918 [Default:GPS:A.SetSpeed] Stopped
2013-05-15T18:40:03.918Z,1368643203.918 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-15T18:42:02.725Z,1368643322.725 [NAL9602](INFO): SBD MO Status=1, MOMSN=12057, MT Status=0, MTMSN=0
2013-05-15T18:42:02.783Z,1368643322.783 [NAL9602](INFO): Sent 70 bytes from file Logs/20130515T000238/Courier0052.lzma
2013-05-15T18:42:02.783Z,1368643322.783 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:42:02.786Z,1368643322.786 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T000238/Courier0052.lzma.parts/0000.sbd
2013-05-15T18:42:13.857Z,1368643333.857 [NAL9602](INFO): SBD MO Status=1, MOMSN=12058, MT Status=0, MTMSN=0
2013-05-15T18:42:13.907Z,1368643333.907 [NAL9602](INFO): Sent 258 bytes from file Logs/20130515T183650/Courier0000.lzma
2013-05-15T18:42:13.907Z,1368643333.907 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:42:13.910Z,1368643333.910 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Courier0000.lzma.parts/0000.sbd
2013-05-15T18:42:28.161Z,1368643348.161 [NAL9602](INFO): SBD MO Status=2, MOMSN=12059, MT Status=2, MTMSN=0
2013-05-15T18:42:28.161Z,1368643348.161 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T18:43:14.725Z,1368643394.725 [NAL9602](INFO): SBD MO Status=1, MOMSN=12059, MT Status=0, MTMSN=0
2013-05-15T18:43:14.787Z,1368643394.787 [NAL9602](INFO): Sent 138 bytes from file Logs/20130515T000238/Express0053.lzma
2013-05-15T18:43:14.787Z,1368643394.787 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:43:14.790Z,1368643394.790 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T000238/Express0053.lzma.parts/0000.sbd
2013-05-15T18:43:26.149Z,1368643406.149 [NAL9602](INFO): SBD MO Status=1, MOMSN=12060, MT Status=0, MTMSN=0
2013-05-15T18:43:26.199Z,1368643406.199 [NAL9602](INFO): Sent 332 bytes from file Logs/20130515T183650/Express0001.lzma
2013-05-15T18:43:26.199Z,1368643406.199 [NAL9602](INFO): Packets left to send: 1
2013-05-15T18:43:26.504Z,1368643406.504 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Express0001.lzma.parts/0001.sbd
2013-05-15T18:43:45.373Z,1368643425.373 [NAL9602](INFO): SBD MO Status=2, MOMSN=12061, MT Status=2, MTMSN=0
2013-05-15T18:43:45.374Z,1368643425.374 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T18:44:35.540Z,1368643475.540 [NAL9602](INFO): SBD MO Status=1, MOMSN=12061, MT Status=0, MTMSN=0
2013-05-15T18:44:35.591Z,1368643475.591 [NAL9602](INFO): Sent 299 bytes from file Logs/20130515T183650/Express0001.lzma
2013-05-15T18:44:35.591Z,1368643475.591 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:44:35.592Z,1368643475.592 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Express0001.lzma.parts/0000.sbd
2013-05-15T18:44:45.545Z,1368643485.545 [NAL9602](INFO): SBD MO Status=0, MOMSN=12062, MT Status=0, MTMSN=0
2013-05-15T18:44:49.289Z,1368643489.289 [Default:Iridium:Read_Iridium] Stopped
2013-05-15T18:44:49.289Z,1368643489.289 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-15T18:44:49.289Z,1368643489.289 [Default:Iridium] Stopped
2013-05-15T18:44:49.290Z,1368643489.290 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-15T18:44:49.290Z,1368643489.290 [Default:Iridium:A.SetSpeed] Stopped
2013-05-15T18:44:49.290Z,1368643489.290 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-15T18:44:49.290Z,1368643489.290 [Default:F.Wait] Running Loop=1
2013-05-15T18:44:49.290Z,1368643489.290 [Default:F.Wait](DEBUG): Initialize Wait Component.
2013-05-15T18:44:49.676Z,1368643489.676 [Depth_Keller](ERROR): Pressure reading out of range: 1830.611084 decibar
2013-05-15T18:44:49.696Z,1368643489.696 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-15T18:44:49.696Z,1368643489.696 [Default:CallIridium:B] Stopped
2013-05-15T18:44:49.696Z,1368643489.696 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-15T18:44:49.697Z,1368643489.697 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-15T18:44:49.697Z,1368643489.697 [Default:CallIridium] Stopped
2013-05-15T18:44:49.697Z,1368643489.697 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-15T18:44:59.719Z,1368643499.719 [NAL9602](INFO): Powering down
2013-05-15T18:49:49.727Z,1368643789.727 [Default:CallIridium] Running Loop=1
2013-05-15T18:49:49.727Z,1368643789.727 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-15T18:49:49.727Z,1368643789.727 [Default:CallIridium:A] Running Loop=1
2013-05-15T18:49:49.728Z,1368643789.728 [Default:CallIridium:A] Stopped
2013-05-15T18:49:49.728Z,1368643789.728 [Default:CallIridium:B] Running Loop=1
2013-05-15T18:49:49.728Z,1368643789.728 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-15T18:49:54.679Z,1368643794.680 [Default:Iridium] Running Loop=1
2013-05-15T18:49:54.680Z,1368643794.680 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-15T18:49:54.680Z,1368643794.680 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-15T18:49:54.680Z,1368643794.680 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-15T18:49:54.680Z,1368643794.680 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-15T18:49:54.680Z,1368643794.680 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:49:54.681Z,1368643794.681 [Default:Iridium:B.GoToSurface] Stopped
2013-05-15T18:49:54.681Z,1368643794.681 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T18:49:54.681Z,1368643794.681 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-15T18:49:54.682Z,1368643794.682 [Default:GPS] Running Loop=1
2013-05-15T18:49:54.682Z,1368643794.682 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-15T18:49:54.682Z,1368643794.682 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-15T18:49:54.682Z,1368643794.682 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-15T18:49:54.682Z,1368643794.682 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-15T18:49:54.682Z,1368643794.682 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:49:54.683Z,1368643794.683 [Default:GPS:B.GoToSurface] Stopped
2013-05-15T18:49:54.683Z,1368643794.683 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T18:49:54.683Z,1368643794.683 [Default:GPS:Read_GPS] Running Loop=1
2013-05-15T18:49:55.308Z,1368643795.307 [NAL9602](INFO): Powering up
2013-05-15T18:50:05.923Z,1368643805.923 [NAL9602](INFO): NAL9602 initialized
2013-05-15T18:50:32.715Z,1368643832.715 [NAL9602](IMPORTANT): GPS fix at: 1368643771.99
2013-05-15T18:50:32.730Z,1368643832.730 [Default:GPS:Read_GPS] Stopped
2013-05-15T18:50:32.730Z,1368643832.730 [Default:GPS:D] Running Loop=1
2013-05-15T18:50:33.137Z,1368643833.137 [Default:GPS:D] Stopped
2013-05-15T18:50:33.138Z,1368643833.138 [Default:GPS](INFO): Completed Default:GPS
2013-05-15T18:50:33.138Z,1368643833.138 [Default:GPS] Stopped
2013-05-15T18:50:33.138Z,1368643833.138 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-15T18:50:33.138Z,1368643833.138 [Default:GPS:A.SetSpeed] Stopped
2013-05-15T18:50:33.138Z,1368643833.138 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-15T18:51:10.789Z,1368643870.789 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=12063, MT Status=1, MTMSN=867
2013-05-15T18:51:10.843Z,1368643870.843 [NAL9602](INFO): Sent 70 bytes from file Logs/20130515T183650/Courier0004.lzma
2013-05-15T18:51:10.843Z,1368643870.843 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:51:10.851Z,1368643870.851 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Courier0004.lzma.parts/0000.sbd
2013-05-15T18:51:11.748Z,1368643871.749 [NAL9602](IMPORTANT): Initialized file: Missions/Demo/Circle.xml
2013-05-15T18:51:11.750Z,1368643871.750 [NAL9602](IMPORTANT): More data left to go, at position 83
2013-05-15T18:51:35.009Z,1368643895.009 [NAL9602](INFO): SBD MO Status=2, MOMSN=12064, MT Status=2, MTMSN=0
2013-05-15T18:51:35.009Z,1368643895.009 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T18:52:10.213Z,1368643930.213 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=12064, MT Status=1, MTMSN=868
2013-05-15T18:52:10.263Z,1368643930.263 [NAL9602](INFO): Sent 258 bytes from file Logs/20130515T183650/Express0005.lzma
2013-05-15T18:52:10.263Z,1368643930.263 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:52:10.266Z,1368643930.266 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Express0005.lzma.parts/0000.sbd
2013-05-15T18:52:10.861Z,1368643930.861 [NAL9602](IMPORTANT): Added data to file: Missions/Demo/Circle.xml
2013-05-15T18:52:10.863Z,1368643930.863 [NAL9602](IMPORTANT): Executing cat Logs/latest/5193D74B.part | gunzip -f -d | cat `cp Missions/Demo/.svn/text-base/Circle.xml.svn-base Missions/Demo/Circle.xml` | patch Missions/Demo/Circle.xml
2013-05-15T18:52:12.040Z,1368643932.040 [CommandLine](IMPORTANT): missing header for unified diff at line 3 of patch
patching file Missions/Demo/Circle.xml

2013-05-15T18:52:12.180Z,1368643932.180 [CommandLine](IMPORTANT): e138ac85094b046104bf7870694054be  Missions/Demo/Circle.xml

2013-05-15T18:52:18.728Z,1368643938.728 [NAL9602](INFO): SBD MO Status=0, MOMSN=12065, MT Status=0, MTMSN=0
2013-05-15T18:52:37.313Z,1368643957.313 [NAL9602](INFO): SBD MO Status=1, MOMSN=12066, MT Status=0, MTMSN=0
2013-05-15T18:52:37.363Z,1368643957.363 [NAL9602](INFO): Sent 70 bytes from file Logs/20130515T183650/Courier0008.lzma
2013-05-15T18:52:37.363Z,1368643957.363 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:52:37.366Z,1368643957.366 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Courier0008.lzma.parts/0000.sbd
2013-05-15T18:52:48.377Z,1368643968.377 [NAL9602](INFO): SBD MO Status=1, MOMSN=12067, MT Status=0, MTMSN=0
2013-05-15T18:52:48.431Z,1368643968.431 [NAL9602](INFO): Sent 332 bytes from file Logs/20130515T183650/Express0009.lzma
2013-05-15T18:52:48.431Z,1368643968.431 [NAL9602](INFO): Packets left to send: 1
2013-05-15T18:52:48.434Z,1368643968.434 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Express0009.lzma.parts/0001.sbd
2013-05-15T18:53:06.221Z,1368643986.221 [NAL9602](INFO): SBD MO Status=2, MOMSN=12068, MT Status=2, MTMSN=0
2013-05-15T18:53:06.221Z,1368643986.221 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T18:54:25.740Z,1368644065.740 [NAL9602](INFO): SBD MO Status=1, MOMSN=12068, MT Status=0, MTMSN=0
2013-05-15T18:54:25.791Z,1368644065.791 [NAL9602](INFO): Sent 123 bytes from file Logs/20130515T183650/Express0009.lzma
2013-05-15T18:54:25.791Z,1368644065.791 [NAL9602](INFO): Packets left to send: 0
2013-05-15T18:54:25.792Z,1368644065.792 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Express0009.lzma.parts/0000.sbd
2013-05-15T18:54:33.745Z,1368644073.745 [NAL9602](INFO): SBD MO Status=0, MOMSN=12069, MT Status=0, MTMSN=0
2013-05-15T18:54:37.634Z,1368644077.634 [Default:Iridium:Read_Iridium] Stopped
2013-05-15T18:54:37.635Z,1368644077.635 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-15T18:54:37.635Z,1368644077.635 [Default:Iridium] Stopped
2013-05-15T18:54:37.635Z,1368644077.635 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-15T18:54:37.635Z,1368644077.635 [Default:Iridium:A.SetSpeed] Stopped
2013-05-15T18:54:37.635Z,1368644077.635 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-15T18:54:38.033Z,1368644078.033 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-15T18:54:38.033Z,1368644078.033 [Default:CallIridium:B] Stopped
2013-05-15T18:54:38.034Z,1368644078.033 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-15T18:54:38.034Z,1368644078.034 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-15T18:54:38.034Z,1368644078.034 [Default:CallIridium] Stopped
2013-05-15T18:54:38.034Z,1368644078.034 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-15T18:54:48.016Z,1368644088.016 [NAL9602](INFO): Powering down
2013-05-15T18:59:38.032Z,1368644378.032 [Default:CallIridium] Running Loop=1
2013-05-15T18:59:38.032Z,1368644378.032 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-15T18:59:38.032Z,1368644378.033 [Default:CallIridium:A] Running Loop=1
2013-05-15T18:59:38.033Z,1368644378.033 [Default:CallIridium:A] Stopped
2013-05-15T18:59:38.033Z,1368644378.033 [Default:CallIridium:B] Running Loop=1
2013-05-15T18:59:38.033Z,1368644378.033 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-15T18:59:43.029Z,1368644383.029 [Default:Iridium] Running Loop=1
2013-05-15T18:59:43.029Z,1368644383.029 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-15T18:59:43.029Z,1368644383.029 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-15T18:59:43.029Z,1368644383.029 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-15T18:59:43.030Z,1368644383.030 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-15T18:59:43.030Z,1368644383.030 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:59:43.031Z,1368644383.031 [Default:Iridium:B.GoToSurface] Stopped
2013-05-15T18:59:43.031Z,1368644383.031 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T18:59:43.031Z,1368644383.031 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-15T18:59:43.031Z,1368644383.031 [Default:GPS] Running Loop=1
2013-05-15T18:59:43.031Z,1368644383.031 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-15T18:59:43.032Z,1368644383.032 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-15T18:59:43.032Z,1368644383.032 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-15T18:59:43.032Z,1368644383.032 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-15T18:59:43.032Z,1368644383.032 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T18:59:43.033Z,1368644383.033 [Default:GPS:B.GoToSurface] Stopped
2013-05-15T18:59:43.033Z,1368644383.033 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T18:59:43.033Z,1368644383.033 [Default:GPS:Read_GPS] Running Loop=1
2013-05-15T18:59:43.632Z,1368644383.632 [NAL9602](INFO): Powering up
2013-05-15T18:59:54.663Z,1368644394.663 [NAL9602](INFO): NAL9602 initialized
2013-05-15T19:00:10.834Z,1368644410.834 [NAL9602](INFO): SBD MO Status=1, MOMSN=12070, MT Status=0, MTMSN=0
2013-05-15T19:00:10.883Z,1368644410.883 [NAL9602](INFO): Sent 45 bytes from file Logs/20130515T183650/Courier0012.lzma
2013-05-15T19:00:10.883Z,1368644410.883 [NAL9602](INFO): Packets left to send: 0
2013-05-15T19:00:10.886Z,1368644410.886 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Courier0012.lzma.parts/0000.sbd
2013-05-15T19:00:19.493Z,1368644419.493 [NAL9602](INFO): SBD MO Status=1, MOMSN=12071, MT Status=0, MTMSN=0
2013-05-15T19:00:19.543Z,1368644419.543 [NAL9602](INFO): Sent 72 bytes from file Logs/20130515T183650/Express0013.lzma
2013-05-15T19:00:19.543Z,1368644419.543 [NAL9602](INFO): Packets left to send: 0
2013-05-15T19:00:19.546Z,1368644419.546 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Express0013.lzma.parts/0000.sbd
2013-05-15T19:00:31.141Z,1368644431.141 [NAL9602](INFO): SBD MO Status=0, MOMSN=12072, MT Status=0, MTMSN=0
2013-05-15T19:00:34.925Z,1368644434.925 [Default:Iridium:Read_Iridium] Stopped
2013-05-15T19:00:34.925Z,1368644434.925 [Default:Iridium](INFO): Completed Default:Iridium
2013-05-15T19:00:34.925Z,1368644434.925 [Default:Iridium] Stopped
2013-05-15T19:00:34.925Z,1368644434.925 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2013-05-15T19:00:34.925Z,1368644434.925 [Default:Iridium:A.SetSpeed] Stopped
2013-05-15T19:00:34.925Z,1368644434.925 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2013-05-15T19:00:35.236Z,1368644435.236 [Depth_Keller](ERROR): Pressure reading out of range: 1830.632935 decibar
2013-05-15T19:00:35.253Z,1368644435.253 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2013-05-15T19:00:35.254Z,1368644435.253 [Default:CallIridium:B] Stopped
2013-05-15T19:00:35.254Z,1368644435.254 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2013-05-15T19:00:35.254Z,1368644435.254 [Default:CallIridium](INFO): Completed Default:CallIridium
2013-05-15T19:00:35.254Z,1368644435.254 [Default:CallIridium] Stopped
2013-05-15T19:00:35.254Z,1368644435.254 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2013-05-15T19:00:35.931Z,1368644435.931 [NAL9602](IMPORTANT): GPS fix at: 1368644376.00
2013-05-15T19:00:35.946Z,1368644435.946 [Default:GPS:Read_GPS] Stopped
2013-05-15T19:00:35.946Z,1368644435.946 [Default:GPS:D] Running Loop=1
2013-05-15T19:00:36.445Z,1368644436.445 [Default:GPS:D] Stopped
2013-05-15T19:00:36.445Z,1368644436.445 [Default:GPS](INFO): Completed Default:GPS
2013-05-15T19:00:36.445Z,1368644436.445 [Default:GPS] Stopped
2013-05-15T19:00:36.446Z,1368644436.446 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-15T19:00:36.446Z,1368644436.446 [Default:GPS:A.SetSpeed] Stopped
2013-05-15T19:00:36.446Z,1368644436.446 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-15T19:00:56.919Z,1368644456.919 [NAL9602](INFO): Powering down
2013-05-15T19:01:10.727Z,1368644470.727 [CommandLine](IMPORTANT): got command conversation stop
2013-05-15T19:01:10.727Z,1368644470.727 [CommandLine](IMPORTANT): Conversation is stopped.
2013-05-15T19:01:21.982Z,1368644481.982 [Radio_Freewave](FAULT): LCB fault:  Invalid Command. Hardware Overcurrent Shutdown. Current Limiter Activated.
2013-05-15T19:01:21.982Z,1368644481.982 [Radio_Freewave] Hardware Fault, FailCount= 1
2013-05-15T19:01:21.982Z,1368644481.982 [Radio_Freewave](ERROR): Hardware Fault
2013-05-15T19:01:22.055Z,1368644482.055 [CBIT](ERROR): Hardware Fault in component: Radio_Freewave
2013-05-15T19:01:27.153Z,1368644487.152 [Radio_Freewave](INFO): Powering down
2013-05-15T19:01:32.019Z,1368644492.019 [Radio_Freewave](FAULT): LCB fault:  Software Overcurrent.
2013-05-15T19:01:37.117Z,1368644497.117 [Radio_Freewave](INFO): Powering up
2013-05-15T19:01:37.152Z,1368644497.152 [CBIT](INFO): Clearing failed state for component Radio_Freewave
2013-05-15T19:01:37.152Z,1368644497.152 [Radio_Freewave] No Fault, FailCount= 1
2013-05-15T20:00:31.883Z,1368648031.883 [Default:CallIridium] Running Loop=1
2013-05-15T20:00:31.883Z,1368648031.883 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-15T20:00:31.883Z,1368648031.883 [Default:CallIridium:A] Running Loop=1
2013-05-15T20:00:31.883Z,1368648031.883 [Default:CallIridium:A] Stopped
2013-05-15T20:00:31.883Z,1368648031.884 [Default:CallIridium:B] Running Loop=1
2013-05-15T20:00:31.884Z,1368648031.884 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-15T20:00:36.935Z,1368648036.935 [Default:Iridium] Running Loop=1
2013-05-15T20:00:36.935Z,1368648036.935 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-15T20:00:36.935Z,1368648036.935 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-15T20:00:36.935Z,1368648036.935 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-15T20:00:36.935Z,1368648036.935 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-15T20:00:36.935Z,1368648036.935 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T20:00:36.936Z,1368648036.936 [Default:Iridium:B.GoToSurface] Stopped
2013-05-15T20:00:36.936Z,1368648036.936 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T20:00:36.936Z,1368648036.936 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-15T20:00:36.937Z,1368648036.937 [Default:GPS] Running Loop=1
2013-05-15T20:00:36.937Z,1368648036.937 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-15T20:00:36.937Z,1368648036.937 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-15T20:00:36.937Z,1368648036.937 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-15T20:00:36.937Z,1368648036.937 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-15T20:00:36.937Z,1368648036.937 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-15T20:00:36.938Z,1368648036.938 [Default:GPS:B.GoToSurface] Stopped
2013-05-15T20:00:36.938Z,1368648036.938 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-15T20:00:36.938Z,1368648036.938 [Default:GPS:Read_GPS] Running Loop=1
2013-05-15T20:00:37.527Z,1368648037.527 [NAL9602](INFO): Powering up
2013-05-15T20:00:48.099Z,1368648048.099 [NAL9602](INFO): NAL9602 initialized
2013-05-15T20:01:26.665Z,1368648086.665 [NAL9602](IMPORTANT): GPS fix at: 1368648032.00
2013-05-15T20:01:26.680Z,1368648086.680 [Default:GPS:Read_GPS] Stopped
2013-05-15T20:01:26.680Z,1368648086.681 [Default:GPS:D] Running Loop=1
2013-05-15T20:01:27.167Z,1368648087.167 [Default:GPS:D] Stopped
2013-05-15T20:01:27.167Z,1368648087.167 [Default:GPS](INFO): Completed Default:GPS
2013-05-15T20:01:27.167Z,1368648087.167 [Default:GPS] Stopped
2013-05-15T20:01:27.168Z,1368648087.168 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2013-05-15T20:01:27.168Z,1368648087.168 [Default:GPS:A.SetSpeed] Stopped
2013-05-15T20:01:27.168Z,1368648087.168 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2013-05-15T20:03:25.954Z,1368648205.954 [NAL9602](INFO): SBD MO Status=2, MOMSN=12073, MT Status=2, MTMSN=0
2013-05-15T20:03:25.954Z,1368648205.954 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T20:06:14.472Z,1368648374.472 [NAL9602](INFO): SBD MO Status=2, MOMSN=12073, MT Status=2, MTMSN=0
2013-05-15T20:06:14.472Z,1368648374.472 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T20:06:47.573Z,1368648407.573 [NAL9602](INFO): SBD MO Status=1, MOMSN=12073, MT Status=0, MTMSN=0
2013-05-15T20:06:47.631Z,1368648407.631 [NAL9602](INFO): Sent 68 bytes from file Logs/20130515T183650/Courier0016.lzma
2013-05-15T20:06:47.631Z,1368648407.631 [NAL9602](INFO): Packets left to send: 0
2013-05-15T20:06:47.638Z,1368648407.638 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Courier0016.lzma.parts/0000.sbd
2013-05-15T20:07:08.645Z,1368648428.645 [NAL9602](INFO): SBD MO Status=2, MOMSN=12074, MT Status=2, MTMSN=0
2013-05-15T20:07:08.646Z,1368648428.645 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T20:12:42.425Z,1368648762.425 [NAL9602](INFO): SBD MO Status=2, MOMSN=12074, MT Status=2, MTMSN=0
2013-05-15T20:12:42.425Z,1368648762.425 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T20:13:07.912Z,1368648787.912 [NAL9602](INFO): SBD MO Status=2, MOMSN=12074, MT Status=2, MTMSN=0
2013-05-15T20:13:07.912Z,1368648787.912 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T20:15:06.919Z,1368648906.919 [CommandLine](IMPORTANT): got command conversation start
2013-05-15T20:15:06.919Z,1368648906.919 [CommandLine](IMPORTANT): Conversation is started.
2013-05-15T20:16:03.989Z,1368648963.989 [NAL9602](INFO): SBD MO Status=1, MOMSN=12074, MT Status=0, MTMSN=0
2013-05-15T20:16:04.043Z,1368648964.043 [NAL9602](INFO): Sent 286 bytes from file Logs/20130515T183650/Express0017.lzma
2013-05-15T20:16:04.043Z,1368648964.043 [NAL9602](INFO): Packets left to send: 0
2013-05-15T20:16:04.046Z,1368648964.046 [NAL9602](INFO): Stored copy of sent data in Logs/20130515T183650/Express0017.lzma.parts/0000.sbd
2013-05-15T20:16:20.380Z,1368648980.380 [NAL9602](INFO): SBD MO Status=2, MOMSN=12075, MT Status=2, MTMSN=0
2013-05-15T20:16:20.380Z,1368648980.380 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2013-05-15T20:16:25.651Z,1368648985.651 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:27.904Z,1368648987.904 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:32.212Z,1368648992.212 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:34.548Z,1368648994.548 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:38.925Z,1368648998.925 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:41.259Z,1368649001.259 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:45.697Z,1368649005.697 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:47.921Z,1368649007.921 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:52.277Z,1368649012.277 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:54.549Z,1368649014.549 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:16:58.919Z,1368649018.919 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:01.288Z,1368649021.288 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:05.587Z,1368649025.587 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:14.755Z,1368649034.755 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:19.029Z,1368649039.029 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:28.930Z,1368649048.930 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:39.259Z,1368649059.259 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:43.578Z,1368649063.578 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:47.905Z,1368649067.905 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:50.271Z,1368649070.270 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:54.556Z,1368649074.556 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:17:56.985Z,1368649076.986 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:01.204Z,1368649081.204 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:03.560Z,1368649083.560 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:07.922Z,1368649087.921 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:10.323Z,1368649090.323 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:14.652Z,1368649094.652 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:16.972Z,1368649096.972 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:21.285Z,1368649101.285 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:24.430Z,1368649104.430 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:33.179Z,1368649113.179 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-15T20:18:50.649Z,1368649130.649 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=12075, MT Status=1, MTMSN=869
2013-05-15T20:18:51.242Z,1368649131.241 [NAL9602](INFO): Received command:load Science/science_to.xml;set science_to.Wpt1Lat 36.8 degree;set science_to.Wpt1Lon -122 degree;run 
2013-05-15T20:18:51.260Z,1368649131.260 [CommandLine](IMPORTANT): got command load ./Missions/Science/science_to.xml
2013-05-15T20:18:51.264Z,1368649131.264 [MissionManager](INFO): Loading Mission: ./Missions/Science/science_to.xml
2013-05-15T20:18:51.375Z,1368649131.375 [MissionManager](INFO): DefineArg science_to.MinAltitude = 10.000000 m
2013-05-15T20:18:51.378Z,1368649131.378 [MissionManager](INFO): DefineArg science_to.MaxDepth = 105.000000 m
2013-05-15T20:18:51.381Z,1368649131.381 [MissionManager](INFO): DefineArg science_to.MinOffshore = 2000.000000 m
2013-05-15T20:18:51.384Z,1368649131.384 [MissionManager](INFO): DefineArg science_to.YoYoMinDepth = 3.000000 m
2013-05-15T20:18:51.388Z,1368649131.388 [MissionManager](INFO): DefineArg science_to.YoYoMaxDepth = 100.000000 m
2013-05-15T20:18:51.391Z,1368649131.391 [MissionManager](INFO): DefineArg science_to.YoYoUpPitch = 20.000000 arcdeg
2013-05-15T20:18:51.394Z,1368649131.394 [MissionManager](INFO): DefineArg science_to.YoYoDownPitch = -15.000000 arcdeg
2013-05-15T20:18:51.397Z,1368649131.397 [MissionManager](INFO): DefineArg science_to.Wpt1Lat = 0.000000 arcdeg
2013-05-15T20:18:51.436Z,1368649131.436 [MissionManager](INFO): DefineArg science_to.Wpt1Lon = 0.000000 arcdeg
2013-05-15T20:18:51.439Z,1368649131.439 [MissionManager](INFO): DefineArg science_to.Wpt2Lat = 0.000000 arcdeg
2013-05-15T20:18:51.442Z,1368649131.442 [MissionManager](INFO): DefineArg science_to.Wpt2Lon = 0.000000 arcdeg
2013-05-15T20:18:51.445Z,1368649131.445 [MissionManager](INFO): DefineArg science_to.Wpt3Lat = 0.000000 arcdeg
2013-05-15T20:18:51.453Z,1368649131.453 [MissionManager](INFO): DefineArg science_to.Wpt3Lon = 0.000000 arcdeg
2013-05-15T20:18:51.456Z,1368649131.457 [MissionManager](INFO): DefineArg science_to.Wpt4Lat = 0.000000 arcdeg
2013-05-15T20:18:51.462Z,1368649131.462 [MissionManager](INFO): DefineArg science_to.Wpt4Lon = 0.000000 arcdeg
2013-05-15T20:18:51.465Z,1368649131.465 [MissionManager](INFO): DefineArg science_to.NeedCommsTime = 120.000000 min
2013-05-15T20:18:51.468Z,1368649131.468 [MissionManager](INFO): DefineArg science_to.Speed = 1.000000 m/s
2013-05-15T20:18:51.471Z,1368649131.471 [MissionManager](INFO): DefineArg science_to.Timeout = 36.000000 h
2013-05-15T20:18:51.475Z,1368649131.475 [MissionManager](INFO): DefineArg science_to.BuoyancyNeutral = 0.000450 n/a
2013-05-15T20:18:51.479Z,1368649131.479 [MissionManager](INFO): DefineArg science_to.MassDefault = 0.000000 n/a
2013-05-15T20:18:51.482Z,1368649131.482 [MissionManager](INFO): DefineArg science_to.ZeroDeg = 0.000000 arcdeg
2013-05-15T20:18:51.486Z,1368649131.486 [science_to:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2013-05-15T20:18:51.495Z,1368649131.495 [science_to:AltEnvWrapper:B.Wait](DEBUG): Construct Wait.
2013-05-15T20:18:51.496Z,1368649131.496 [science_to:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2013-05-15T20:18:51.544Z,1368649131.544 [science_to:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2013-05-15T20:18:51.558Z,1368649131.557 [science_to:OffshoreWrapper:B.Wait](DEBUG): Construct Wait.
2013-05-15T20:18:51.559Z,1368649131.559 [science_to:D.Pitch](DEBUG): Construct.
2013-05-15T20:18:51.564Z,1368649131.565 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml
2013-05-15T20:18:51.593Z,1368649131.593 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfaceDepthRate = nan m/s
2013-05-15T20:18:51.596Z,1368649131.596 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfacePitch = nan arcdeg
2013-05-15T20:18:51.635Z,1368649131.635 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfaceSpeed = 0.500000 m/s
2013-05-15T20:18:51.638Z,1368649131.638 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.IridiumTimeout = 30.000000 min
2013-05-15T20:18:51.641Z,1368649131.641 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.UnpackSplitAtSurface = 0 bool
2013-05-15T20:18:51.642Z,1368649131.642 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-15T20:18:51.660Z,1368649131.660 [MissionManager](INFO): RedefineArg science_to:SURFACECOMMS.SurfacePitch = 20.000000 arcdeg
2013-05-15T20:18:51.665Z,1368649131.665 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml
2013-05-15T20:18:51.783Z,1368649131.783 [MissionManager](ERROR): Cannot load Xml file Missions/Insert/Science.xml due to: Error reading end tag.
2013-05-15T20:18:51.788Z,1368649131.788 [MissionManager](CRITICAL): Could not load mission Missions/Insert/Science.xml
2013-05-15T20:18:51.793Z,1368649131.793 [NAL9602](CRITICAL): SIGSEGV: address not mapped to object
2013-05-15T20:18:51.793Z,1368649131.793 [NAL9602](CRITICAL): Bad address: 0x168
2013-05-15T20:18:51.793Z,1368649131.793 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.794Z,1368649131.794 [NAL9602] Software Fault, FailCount= 1
2013-05-15T20:18:51.794Z,1368649131.794 [NAL9602](ERROR): Software Fault
2013-05-15T20:18:51.814Z,1368649131.814 [NAL9602](CRITICAL): SIGSEGV: address not mapped to object
2013-05-15T20:18:51.814Z,1368649131.814 [NAL9602](CRITICAL): Bad address: 0x0
2013-05-15T20:18:51.814Z,1368649131.815 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.821Z,1368649131.821 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.822Z,1368649131.822 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.837Z,1368649131.837 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.837Z,1368649131.838 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.842Z,1368649131.842 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.842Z,1368649131.842 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.846Z,1368649131.846 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.850Z,1368649131.850 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.854Z,1368649131.854 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.854Z,1368649131.855 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.860Z,1368649131.860 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.861Z,1368649131.861 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.864Z,1368649131.864 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.865Z,1368649131.865 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.868Z,1368649131.868 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.868Z,1368649131.868 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:51.872Z,1368649131.872 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:51.872Z,1368649131.872 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.207Z,1368649132.207 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.207Z,1368649132.207 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.219Z,1368649132.219 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.220Z,1368649132.220 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.236Z,1368649132.236 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.236Z,1368649132.236 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.243Z,1368649132.243 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.243Z,1368649132.243 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.251Z,1368649132.251 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.251Z,1368649132.251 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.261Z,1368649132.261 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.262Z,1368649132.262 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.268Z,1368649132.268 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.269Z,1368649132.269 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.272Z,1368649132.272 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.273Z,1368649132.273 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.276Z,1368649132.276 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.276Z,1368649132.276 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.280Z,1368649132.280 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.280Z,1368649132.280 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.634Z,1368649132.634 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.635Z,1368649132.635 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.639Z,1368649132.639 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.639Z,1368649132.639 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.643Z,1368649132.643 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.643Z,1368649132.643 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.650Z,1368649132.650 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.650Z,1368649132.650 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.654Z,1368649132.654 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.654Z,1368649132.654 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:52.658Z,1368649132.658 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:52.671Z,1368649132.671 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.018Z,1368649133.018 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.019Z,1368649133.019 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.023Z,1368649133.023 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.023Z,1368649133.023 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.027Z,1368649133.027 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.027Z,1368649133.027 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.043Z,1368649133.043 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.043Z,1368649133.043 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.047Z,1368649133.047 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.048Z,1368649133.048 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.051Z,1368649133.051 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.052Z,1368649133.052 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.391Z,1368649133.391 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.391Z,1368649133.391 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.395Z,1368649133.395 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.395Z,1368649133.395 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.399Z,1368649133.399 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.399Z,1368649133.399 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.419Z,1368649133.419 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.419Z,1368649133.419 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.423Z,1368649133.423 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.424Z,1368649133.424 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.427Z,1368649133.427 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.428Z,1368649133.428 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.443Z,1368649133.443 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.443Z,1368649133.443 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.777Z,1368649133.777 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.778Z,1368649133.778 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.781Z,1368649133.782 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.782Z,1368649133.782 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.785Z,1368649133.785 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.786Z,1368649133.786 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.801Z,1368649133.801 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.802Z,1368649133.802 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.806Z,1368649133.806 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.806Z,1368649133.806 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.810Z,1368649133.810 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.822Z,1368649133.822 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.826Z,1368649133.826 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.827Z,1368649133.827 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:53.830Z,1368649133.830 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:53.831Z,1368649133.831 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.174Z,1368649134.174 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.175Z,1368649134.175 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.179Z,1368649134.179 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.180Z,1368649134.180 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.187Z,1368649134.187 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.188Z,1368649134.188 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.192Z,1368649134.192 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.192Z,1368649134.192 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.204Z,1368649134.204 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.204Z,1368649134.204 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.212Z,1368649134.212 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.213Z,1368649134.213 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.221Z,1368649134.221 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.221Z,1368649134.221 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.555Z,1368649134.555 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.555Z,1368649134.555 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.559Z,1368649134.559 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.559Z,1368649134.559 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.563Z,1368649134.563 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.563Z,1368649134.563 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.587Z,1368649134.587 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.587Z,1368649134.587 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.596Z,1368649134.596 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.597Z,1368649134.597 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.606Z,1368649134.606 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.606Z,1368649134.606 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.616Z,1368649134.616 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.616Z,1368649134.616 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.949Z,1368649134.949 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.950Z,1368649134.950 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.953Z,1368649134.953 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.953Z,1368649134.954 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.957Z,1368649134.957 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.957Z,1368649134.957 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.973Z,1368649134.973 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.973Z,1368649134.973 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.978Z,1368649134.978 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.978Z,1368649134.978 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.982Z,1368649134.982 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.982Z,1368649134.982 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:54.998Z,1368649134.998 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:54.999Z,1368649134.999 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]

2013-05-15T20:18:55.331Z,1368649135.331 [NAL9602](CRITICAL): SIGABRT: execution aborted (failed assertion, corrupted heap, or other problem?)
2013-05-15T20:18:55.331Z,1368649135.332 [NAL9602](CRITICAL): Backtrace: 
bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x156738]
/lib/libc.so.6(__default_rt_sa_restorer+0) [0x40203510]