2018-10-16T05:41:55.718Z,1539668515.718 [Supervisor](DEBUG): Initializing supervisor.
2018-10-16T05:41:55.722Z,1539668515.722 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-10-16T05:41:55.722Z,1539668515.722 [SyncHandler](INFO): Protected caller Thread ID is 6556
2018-10-16T05:41:55.723Z,1539668515.723 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-10-16T05:41:55.724Z,1539668515.724 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-10-16T05:41:55.724Z,1539668515.724 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6557
2018-10-16T05:41:55.728Z,1539668515.728 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-10-16T05:41:55.740Z,1539668515.740 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-10-16T05:41:55.741Z,1539668515.741 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-10-16T05:41:55.741Z,1539668515.741 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6558
2018-10-16T05:41:55.742Z,1539668515.742 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-10-16T05:41:55.743Z,1539668515.743 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-10-16T05:41:55.743Z,1539668515.743 [logger ThreadHandler](INFO): Protected caller Thread ID is 6559
2018-10-16T05:41:55.745Z,1539668515.745 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-10-16T05:41:55.746Z,1539668515.746 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-10-16T05:41:55.747Z,1539668515.747 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-10-16T05:41:56.072Z,1539668516.072 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-10-16T05:41:56.073Z,1539668516.073 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-10-16T05:41:56.269Z,1539668516.269 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-10-16T05:41:56.270Z,1539668516.270 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-10-16T05:41:56.585Z,1539668516.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-10-16T05:41:56.586Z,1539668516.586 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-10-16T05:41:56.744Z,1539668516.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-10-16T05:41:56.745Z,1539668516.745 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-10-16T05:41:56.842Z,1539668516.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-10-16T05:41:56.843Z,1539668516.843 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-10-16T05:41:57.302Z,1539668517.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-10-16T05:41:57.303Z,1539668517.303 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-10-16T05:41:57.759Z,1539668517.759 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-10-16T05:41:57.759Z,1539668517.759 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-10-16T05:41:58.223Z,1539668518.223 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-10-16T05:41:58.223Z,1539668518.223 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-10-16T05:41:58.327Z,1539668518.327 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-10-16T05:41:58.327Z,1539668518.327 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-10-16T05:41:58.423Z,1539668518.423 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-10-16T05:41:58.423Z,1539668518.423 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-10-16T05:41:58.640Z,1539668518.640 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-10-16T05:41:58.641Z,1539668518.641 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-10-16T05:41:58.843Z,1539668518.843 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-10-16T05:41:58.844Z,1539668518.844 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-10-16T05:41:59.194Z,1539668519.194 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-10-16T05:41:59.195Z,1539668519.195 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-10-16T05:41:59.339Z,1539668519.339 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-10-16T05:41:59.340Z,1539668519.340 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-10-16T05:41:59.421Z,1539668519.421 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-10-16T05:41:59.422Z,1539668519.422 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-10-16T05:41:59.524Z,1539668519.524 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-10-16T05:41:59.641Z,1539668519.641 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-10-16T05:41:59.735Z,1539668519.735 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-10-16T05:41:59.819Z,1539668519.819 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-10-16T05:41:59.982Z,1539668519.982 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-10-16T05:42:00.160Z,1539668520.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-10-16T05:42:00.236Z,1539668520.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-10-16T05:42:00.469Z,1539668520.469 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-10-16T05:42:00.469Z,1539668520.469 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-10-16T05:42:00.552Z,1539668520.552 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-10-16T05:42:00.642Z,1539668520.642 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-10-16T05:42:00.743Z,1539668520.743 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-10-16T05:42:00.869Z,1539668520.869 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2018-10-16T05:42:00.869Z,1539668520.869 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-10-16T05:42:00.881Z,1539668520.881 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-10-16T05:42:01.131Z,1539668521.131 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-10-16T05:42:01.132Z,1539668521.132 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-10-16T05:42:01.175Z,1539668521.175 [DepthRateCalculator] Loaded
2018-10-16T05:42:01.175Z,1539668521.175 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-10-16T05:42:01.182Z,1539668521.182 [PitchRateCalculator] Loaded
2018-10-16T05:42:01.182Z,1539668521.182 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-10-16T05:42:01.198Z,1539668521.198 [SpeedCalculator] Loaded
2018-10-16T05:42:01.199Z,1539668521.199 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-10-16T05:42:01.220Z,1539668521.220 [TempGradientCalculator] Loaded
2018-10-16T05:42:01.220Z,1539668521.220 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-10-16T05:42:01.226Z,1539668521.226 [YawRateCalculator] Loaded
2018-10-16T05:42:01.226Z,1539668521.226 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-10-16T05:42:01.267Z,1539668521.267 [ElevatorOffsetCalculator] Loaded
2018-10-16T05:42:01.267Z,1539668521.267 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-10-16T05:42:01.268Z,1539668521.268 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-10-16T05:42:01.268Z,1539668521.268 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-10-16T05:42:01.337Z,1539668521.337 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-10-16T05:42:01.337Z,1539668521.337 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-10-16T05:42:01.452Z,1539668521.452 [BuoyancyServo] Loaded
2018-10-16T05:42:01.452Z,1539668521.452 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-10-16T05:42:01.467Z,1539668521.467 [ElevatorServo] Loaded
2018-10-16T05:42:01.467Z,1539668521.467 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-10-16T05:42:01.482Z,1539668521.482 [MassServo] Loaded
2018-10-16T05:42:01.482Z,1539668521.482 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-10-16T05:42:01.497Z,1539668521.497 [RudderServo] Loaded
2018-10-16T05:42:01.498Z,1539668521.497 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-10-16T05:42:01.512Z,1539668521.512 [ThrusterServo] Loaded
2018-10-16T05:42:01.512Z,1539668521.512 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-10-16T05:42:01.512Z,1539668521.512 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-10-16T05:42:01.513Z,1539668521.513 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-10-16T05:42:01.527Z,1539668521.527 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-10-16T05:42:01.528Z,1539668521.528 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-10-16T05:42:01.633Z,1539668521.633 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-10-16T05:42:01.634Z,1539668521.634 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-10-16T05:42:02.383Z,1539668522.383 [DataOverHttps] Loaded
2018-10-16T05:42:02.383Z,1539668522.383 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-10-16T05:42:02.397Z,1539668522.397 [Depth_Keller] Loaded
2018-10-16T05:42:02.397Z,1539668522.397 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-10-16T05:42:02.402Z,1539668522.402 [DropWeight] Loaded
2018-10-16T05:42:02.402Z,1539668522.402 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-10-16T05:42:02.502Z,1539668522.502 [NAL9602] Loaded
2018-10-16T05:42:02.503Z,1539668522.503 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-10-16T05:42:02.519Z,1539668522.519 [Onboard] Loaded
2018-10-16T05:42:02.519Z,1539668522.519 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-10-16T05:42:02.530Z,1539668522.530 [Radio_Surface] Loaded
2018-10-16T05:42:02.530Z,1539668522.530 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-10-16T05:42:02.531Z,1539668522.531 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0
2018-10-16T05:42:02.532Z,1539668522.532 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6641
2018-10-16T05:42:02.579Z,1539668522.579 [PNI_TCM] Loaded
2018-10-16T05:42:02.579Z,1539668522.579 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-10-16T05:42:02.641Z,1539668522.641 [Rowe_600LCM] Loaded
2018-10-16T05:42:02.641Z,1539668522.641 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-10-16T05:42:02.642Z,1539668522.642 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0
2018-10-16T05:42:02.642Z,1539668522.642 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 6642
2018-10-16T05:42:02.643Z,1539668522.643 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-10-16T05:42:02.643Z,1539668522.643 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-10-16T05:42:02.779Z,1539668522.779 [SBIT](DEBUG): Construct Startup Built In Test.
2018-10-16T05:42:02.801Z,1539668522.801 [SBIT] Loaded
2018-10-16T05:42:02.801Z,1539668522.801 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-10-16T05:42:02.802Z,1539668522.802 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-10-16T05:42:02.814Z,1539668522.814 [IBIT] Loaded
2018-10-16T05:42:02.814Z,1539668522.814 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-10-16T05:42:02.817Z,1539668522.817 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-10-16T05:42:02.968Z,1539668522.968 [CBIT] Loaded
2018-10-16T05:42:02.968Z,1539668522.968 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-10-16T05:42:02.968Z,1539668522.968 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-10-16T05:42:02.969Z,1539668522.969 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-10-16T05:42:03.136Z,1539668523.136 [Aanderaa_O2] Loaded
2018-10-16T05:42:03.136Z,1539668523.136 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-10-16T05:42:03.151Z,1539668523.151 [PAR_Licor] Loaded
2018-10-16T05:42:03.151Z,1539668523.151 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-10-16T05:42:03.201Z,1539668523.201 [WetLabsBB2FL] Loaded
2018-10-16T05:42:03.202Z,1539668523.202 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-10-16T05:42:03.203Z,1539668523.203 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4098A4E0
2018-10-16T05:42:03.203Z,1539668523.203 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6643
2018-10-16T05:42:03.204Z,1539668523.204 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-10-16T05:42:03.204Z,1539668523.204 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-10-16T05:42:03.277Z,1539668523.277 [VerticalControl](DEBUG): Construct VerticalControl.
2018-10-16T05:42:03.361Z,1539668523.361 [VerticalControl] Loaded
2018-10-16T05:42:03.361Z,1539668523.361 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-10-16T05:42:03.362Z,1539668523.362 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-10-16T05:42:03.420Z,1539668523.420 [HorizontalControl] Loaded
2018-10-16T05:42:03.420Z,1539668523.420 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-10-16T05:42:03.421Z,1539668523.421 [SpeedControl](DEBUG): Construct SpeedControl.
2018-10-16T05:42:03.423Z,1539668523.423 [SpeedControl] Loaded
2018-10-16T05:42:03.423Z,1539668523.423 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-10-16T05:42:03.423Z,1539668523.423 [LoopControl](DEBUG): Construct LoopControl.
2018-10-16T05:42:03.424Z,1539668523.424 [LoopControl] Loaded
2018-10-16T05:42:03.424Z,1539668523.424 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-10-16T05:42:03.425Z,1539668523.425 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-10-16T05:42:03.425Z,1539668523.425 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-10-16T05:42:03.450Z,1539668523.450 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-10-16T05:42:03.451Z,1539668523.451 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-10-16T05:42:03.542Z,1539668523.542 [DeadReckonUsingSpeedCalculator] Loaded
2018-10-16T05:42:03.542Z,1539668523.542 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-10-16T05:42:03.559Z,1539668523.559 [NavChart] Loaded
2018-10-16T05:42:03.559Z,1539668523.559 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-10-16T05:42:03.563Z,1539668523.563 [UniversalFixResidualReporter] Loaded
2018-10-16T05:42:03.563Z,1539668523.563 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-10-16T05:42:03.563Z,1539668523.563 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-10-16T05:42:03.567Z,1539668523.567 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-10-16T05:42:03.568Z,1539668523.568 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-10-16T05:42:03.575Z,1539668523.575 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-10-16T05:42:03.576Z,1539668523.576 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0
2018-10-16T05:42:03.576Z,1539668523.576 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6644
2018-10-16T05:42:03.581Z,1539668523.581 [Supervisor](INFO): Main Thread ID is 5405
2018-10-16T05:42:03.582Z,1539668523.582 [Supervisor](DEBUG): Running supervisor.
2018-10-16T05:42:03.582Z,1539668523.582 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6645
2018-10-16T05:42:03.585Z,1539668523.585 [controlThread ThreadHandler](INFO): Handler Thread ID is 6646
2018-10-16T05:42:03.585Z,1539668523.585 [controlThread](DEBUG): Initializing ControlThread
2018-10-16T05:42:03.586Z,1539668523.586 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-16T05:42:03.586Z,1539668523.586 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-10-16T05:42:03.587Z,1539668523.587 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-10-16T05:42:03.587Z,1539668523.587 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-10-16T05:42:03.588Z,1539668523.588 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-10-16T05:42:03.588Z,1539668523.588 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-10-16T05:42:03.592Z,1539668523.592 [SBIT](INFO): Initialize SBIT Component.
2018-10-16T05:42:03.593Z,1539668523.593 [SBIT](IMPORTANT): git: 2018-10-09-22-g812aa5f
2018-10-16T05:42:03.593Z,1539668523.593 [SBIT](INFO): git hash: 812aa5f738ae24d7d3f6c5c137b2640d1960a87f
2018-10-16T05:42:03.593Z,1539668523.593 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-10-16T05:42:03.594Z,1539668523.594 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2018-10-16T05:42:03.595Z,1539668523.595 [SBIT](INFO): Beginning SBIT in 36.000000 seconds.
2018-10-16T05:42:03.595Z,1539668523.595 [IBIT](INFO): Initialize IBIT Component.
2018-10-16T05:42:03.596Z,1539668523.596 [CBIT](DEBUG): Initialize CBIT Component.
2018-10-16T05:42:03.596Z,1539668523.596 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-10-16T05:42:03.597Z,1539668523.597 [logger ThreadHandler](INFO): Handler Thread ID is 6647
2018-10-16T05:42:03.615Z,1539668523.615 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6648
2018-10-16T05:42:03.620Z,1539668523.620 [Radio_Surface](INFO): Powering up
2018-10-16T05:42:03.627Z,1539668523.627 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 6649
2018-10-16T05:42:03.627Z,1539668523.627 [Rowe_600LCM](INFO): Initializing
2018-10-16T05:42:03.628Z,1539668523.628 [Rowe_600LCM](INFO): Checking LCM
2018-10-16T05:42:03.637Z,1539668523.637 [Rowe_600LCM](INFO): LCM OK
2018-10-16T05:42:03.637Z,1539668523.637 [Rowe_600LCM](INFO): Powering up
2018-10-16T05:42:03.643Z,1539668523.643 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6650
2018-10-16T05:42:03.644Z,1539668523.644 [WetLabsBB2FL](INFO): Powering down
2018-10-16T05:42:03.671Z,1539668523.671 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6651
2018-10-16T05:42:03.674Z,1539668523.674 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-10-16T05:42:03.675Z,1539668523.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-10-16T05:42:03.675Z,1539668523.675 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-10-16T05:42:03.675Z,1539668523.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-10-16T05:42:03.675Z,1539668523.675 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-10-16T05:42:03.675Z,1539668523.675 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-10-16T05:42:03.676Z,1539668523.676 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-10-16T05:42:03.676Z,1539668523.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-10-16T05:42:03.676Z,1539668523.676 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-10-16T05:42:03.676Z,1539668523.676 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-10-16T05:42:03.676Z,1539668523.676 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-10-16T05:42:03.677Z,1539668523.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-10-16T05:42:03.677Z,1539668523.677 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-10-16T05:42:03.677Z,1539668523.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-10-16T05:42:03.677Z,1539668523.677 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-10-16T05:42:03.677Z,1539668523.677 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-10-16T05:42:03.707Z,1539668523.707 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-10-16T05:42:03.709Z,1539668523.709 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-10-16T05:42:03.709Z,1539668523.709 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-10-16T05:42:03.710Z,1539668523.710 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-10-16T05:42:03.710Z,1539668523.710 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:42:03.711Z,1539668523.711 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:42:03.711Z,1539668523.711 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T05:42:03.712Z,1539668523.712 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-10-16T05:42:03.712Z,1539668523.712 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-10-16T05:42:03.713Z,1539668523.713 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-10-16T05:42:03.737Z,1539668523.737 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-16T05:42:03.773Z,1539668523.773 [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://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.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>


2018-10-16T05:42:03.773Z,1539668523.773 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-10-16T05:42:03.861Z,1539668523.861 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-10-16T05:42:03.862Z,1539668523.862 [Default:A.Wait](DEBUG): Construct Wait.
2018-10-16T05:42:03.864Z,1539668523.864 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-10-16T05:42:03.915Z,1539668523.915 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-10-16T05:42:03.917Z,1539668523.917 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-10-16T05:42:03.939Z,1539668523.939 [Default:E.Execute](DEBUG): Construct Execute.
2018-10-16T05:42:03.943Z,1539668523.943 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

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

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2018-10-16T05:42:03.954Z,1539668523.954 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-10-16T05:42:03.971Z,1539668523.971 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-10-16T05:42:03.984Z,1539668523.984 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2018-10-16T05:42:04.220Z,1539668524.220 [DepthRateCalculator](ERROR): Depth measurement is not active
2018-10-16T05:42:04.295Z,1539668524.295 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:04.407Z,1539668524.407 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:42:04.415Z,1539668524.415 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-10-16T05:42:04.421Z,1539668524.421 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:42:04.427Z,1539668524.427 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-10-16T05:42:04.433Z,1539668524.433 [MassServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:42:04.439Z,1539668524.439 [MassServo](DEBUG): Initializing MassServo.
2018-10-16T05:42:04.445Z,1539668524.445 [RudderServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:42:04.451Z,1539668524.451 [RudderServo](DEBUG): Initializing RudderServo.
2018-10-16T05:42:04.472Z,1539668524.472 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-10-16T05:42:04.479Z,1539668524.479 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-10-16T05:42:04.765Z,1539668524.765 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:05.018Z,1539668525.018 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:05.489Z,1539668525.489 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:05.892Z,1539668525.892 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:06.282Z,1539668526.282 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:06.686Z,1539668526.686 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:07.102Z,1539668527.102 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-10-16T05:42:07.603Z,1539668527.603 [Aanderaa_O2](INFO): Powering down
2018-10-16T05:42:08.187Z,1539668528.187 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-10-16T05:42:08.300Z,1539668528.300 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2018-10-16T05:42:08.359Z,1539668528.359 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-10-16T05:42:08.360Z,1539668528.360 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-10-16T05:42:08.360Z,1539668528.360 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-10-16T05:42:32.656Z,1539668552.656 [NAL9602](INFO): Powering up NAL9602
2018-10-16T05:42:39.966Z,1539668559.966 [SBIT](IMPORTANT): Beginning Startup BIT
2018-10-16T05:42:39.975Z,1539668559.975 [CBIT](IMPORTANT): Beginning ground fault scan
2018-10-16T05:42:43.592Z,1539668563.592 [NAL9602](INFO): NAL9602 initialized
2018-10-16T05:42:51.385Z,1539668571.385 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.657929
CHAN A1 (24V): -0.008028
CHAN A2 (12V): -0.002392
CHAN A3 (5V): -0.001463
CHAN B0 (3.3V): 0.000184
CHAN B1 (3.15aV): 0.000348
CHAN B2 (3.15bV): 0.000090
CHAN B3 (GND): -0.000095
OPEN: -0.000468
Full Scale Calc: 4.765 mA, -1.589 mA
2018-10-16T05:43:33.629Z,1539668613.629 [SBIT](IMPORTANT): SBIT PASSED
2018-10-16T05:43:33.649Z,1539668613.649 [CommandLine](IMPORTANT): got command configSet list
2018-10-16T05:43:33.650Z,1539668613.650 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=25 count;

2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): BPC1.batteryMuxCycleTime=10 minute;

2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute;

2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool;

2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): Express none VerticalTemperatureHomogeneityIndexCalculator.vertical_temperature_homogeneity_index;

2018-10-16T05:43:33.659Z,1539668613.659 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2018-10-16T05:43:33.660Z,1539668613.660 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool;

2018-10-16T05:43:33.660Z,1539668613.660 [CommandLine](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool;

2018-10-16T05:43:33.660Z,1539668613.660 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=213 cubic_centimeter;

2018-10-16T05:43:33.660Z,1539668613.660 [CommandLine](IMPORTANT): VerticalControl.massDefault=4 millimeter;

2018-10-16T05:43:34.046Z,1539668614.046 [MissionManager](IMPORTANT): Started mission Startup
2018-10-16T05:43:34.047Z,1539668614.047 [Startup] Running Loop=1
2018-10-16T05:43:34.047Z,1539668614.047 [Startup](DEBUG): Aggregate::initialize Startup
2018-10-16T05:43:34.047Z,1539668614.047 [Startup:A.GoToSurface] Running Loop=1
2018-10-16T05:43:34.047Z,1539668614.047 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-10-16T05:43:34.048Z,1539668614.048 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-10-16T05:43:34.048Z,1539668614.048 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-10-16T05:43:34.049Z,1539668614.049 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-10-16T05:43:34.049Z,1539668614.049 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-10-16T05:43:34.049Z,1539668614.049 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-10-16T05:43:34.072Z,1539668614.072 [Startup:StartupSatComms] Running Loop=1
2018-10-16T05:43:34.072Z,1539668614.072 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-10-16T05:43:34.072Z,1539668614.072 [Startup:StartupSatComms:A] Running Loop=1
2018-10-16T05:43:34.425Z,1539668614.425 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-10-16T05:44:34.421Z,1539668674.421 [Startup:StartupSatComms:A](INFO): Timed out from 2018-10-16T05:43:34.1Z
2018-10-16T05:44:34.422Z,1539668674.422 [Startup:StartupSatComms:A] Stopped
2018-10-16T05:44:34.422Z,1539668674.422 [Startup:StartupSatComms:B] Running Loop=1
2018-10-16T05:44:34.811Z,1539668674.811 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-10-16T05:45:04.028Z,1539668704.028 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T05:45:04.028Z,1539668704.028 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-10-16T05:45:04.028Z,1539668704.028 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T05:45:04.077Z,1539668704.077 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T05:45:04.504Z,1539668704.504 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T05:45:04.504Z,1539668704.504 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-10-16T05:45:04.902Z,1539668704.902 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:45:04.911Z,1539668704.911 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:45:04.912Z,1539668704.912 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T05:45:12.763Z,1539668712.763 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006965
2018-10-16T05:45:17.112Z,1539668717.112 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T053408/Courier0004.lzma
2018-10-16T05:45:17.912Z,1539668717.912 [DataOverHttps](INFO): Moved sent file to Logs/20181016T053408/Courier0004.lzma.bak
2018-10-16T05:45:17.912Z,1539668717.912 [DataOverHttps](INFO): SBD MOMSN=8715874
2018-10-16T05:45:27.739Z,1539668727.739 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T053853/Courier0004.lzma
2018-10-16T05:45:28.540Z,1539668728.540 [DataOverHttps](INFO): Moved sent file to Logs/20181016T053853/Courier0004.lzma.bak
2018-10-16T05:45:28.540Z,1539668728.540 [DataOverHttps](INFO): SBD MOMSN=8715876
2018-10-16T05:45:37.882Z,1539668737.882 [Startup:StartupSatComms:B](INFO): Timed out from 2018-10-16T05:44:34.4Z
2018-10-16T05:45:37.882Z,1539668737.882 [Startup:StartupSatComms:B] Stopped
2018-10-16T05:45:37.883Z,1539668737.883 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-10-16T05:45:37.883Z,1539668737.883 [Startup:StartupSatComms] Stopped
2018-10-16T05:45:37.883Z,1539668737.883 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-10-16T05:45:37.884Z,1539668737.884 [Startup](INFO): Completed Startup
2018-10-16T05:45:37.884Z,1539668737.884 [MissionManager](INFO): Startup is completed.
2018-10-16T05:45:37.884Z,1539668737.884 [MissionManager](INFO): Uninitializing Mission Startup
2018-10-16T05:45:37.884Z,1539668737.884 [Startup] Stopped
2018-10-16T05:45:37.884Z,1539668737.884 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-10-16T05:45:37.884Z,1539668737.884 [Startup:A.GoToSurface] Stopped
2018-10-16T05:45:37.885Z,1539668737.885 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-10-16T05:45:37.933Z,1539668737.933 [DataOverHttps](INFO): Sending 106 bytes from file Logs/20181016T053408/Express0005.lzma
2018-10-16T05:45:38.026Z,1539668738.026 [MissionManager](IMPORTANT): Started mission Default
2018-10-16T05:45:38.030Z,1539668738.030 [Default] Running Loop=1
2018-10-16T05:45:38.031Z,1539668738.031 [Default](DEBUG): Aggregate::initialize Default
2018-10-16T05:45:38.031Z,1539668738.031 [Default:B.GoToSurface] Running Loop=1
2018-10-16T05:45:38.031Z,1539668738.031 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-10-16T05:45:38.031Z,1539668738.031 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-10-16T05:45:38.031Z,1539668738.031 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-10-16T05:45:38.032Z,1539668738.032 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-10-16T05:45:38.032Z,1539668738.032 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-10-16T05:45:38.032Z,1539668738.032 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2018-10-16T05:45:38.033Z,1539668738.033 [Default:A.Wait] Running Loop=1
2018-10-16T05:45:38.033Z,1539668738.033 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-10-16T05:45:38.704Z,1539668738.704 [DataOverHttps](INFO): Moved sent file to Logs/20181016T053408/Express0005.lzma.bak
2018-10-16T05:45:38.704Z,1539668738.704 [DataOverHttps](INFO): SBD MOMSN=8715879
2018-10-16T05:45:51.356Z,1539668751.356 [Default:A.Wait](INFO): Done Waiting.
2018-10-16T05:45:51.356Z,1539668751.356 [Default:A.Wait] Stopped
2018-10-16T05:45:51.356Z,1539668751.356 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-10-16T05:45:51.757Z,1539668751.757 [Default:CheckIn] Running Loop=1
2018-10-16T05:45:51.758Z,1539668751.758 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-10-16T05:45:51.758Z,1539668751.758 [Default:CheckIn:Read_GPS] Running Loop=1
2018-10-16T05:45:52.170Z,1539668752.170 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-10-16T05:47:46.852Z,1539668866.852 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-10-16T05:48:04.938Z,1539668884.938 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T05:48:04.963Z,1539668884.963 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-10-16T05:48:04.963Z,1539668884.963 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T05:48:05.029Z,1539668885.029 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T05:48:05.329Z,1539668885.329 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T05:48:05.329Z,1539668885.329 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-10-16T05:48:05.698Z,1539668885.698 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:48:05.714Z,1539668885.714 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:48:05.715Z,1539668885.715 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T05:50:51.803Z,1539669051.803 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-10-16T05:45:51.8Z
2018-10-16T05:50:51.803Z,1539669051.803 [Default:CheckIn:Read_GPS] Stopped
2018-10-16T05:50:51.803Z,1539669051.803 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-10-16T05:50:52.192Z,1539669052.192 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-10-16T05:50:56.621Z,1539669056.621 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T054155/Courier0004.lzma
2018-10-16T05:50:57.420Z,1539669057.420 [DataOverHttps](INFO): Moved sent file to Logs/20181016T054155/Courier0004.lzma.bak
2018-10-16T05:50:57.420Z,1539669057.420 [DataOverHttps](INFO): SBD MOMSN=8715883
2018-10-16T05:51:06.766Z,1539669066.766 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T05:51:06.766Z,1539669066.766 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-10-16T05:51:06.766Z,1539669066.766 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T05:51:06.812Z,1539669066.812 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T05:51:06.877Z,1539669066.877 [DataOverHttps](INFO): Sending 928 bytes from file Logs/20181016T053853/Express0001.lzma
2018-10-16T05:51:07.081Z,1539669067.081 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T05:51:07.081Z,1539669067.081 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-10-16T05:51:07.293Z,1539669067.293 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:51:07.293Z,1539669067.293 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:51:07.294Z,1539669067.294 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T05:51:07.624Z,1539669067.624 [DataOverHttps](INFO): Moved sent file to Logs/20181016T053853/Express0001.lzma.bak
2018-10-16T05:51:07.624Z,1539669067.624 [DataOverHttps](INFO): SBD MOMSN=8715886
2018-10-16T05:51:17.007Z,1539669077.007 [DataOverHttps](INFO): Sending 78 bytes from file Logs/20181016T053853/Express0005.lzma
2018-10-16T05:51:17.797Z,1539669077.797 [DataOverHttps](INFO): Moved sent file to Logs/20181016T053853/Express0005.lzma.bak
2018-10-16T05:51:17.797Z,1539669077.797 [DataOverHttps](INFO): SBD MOMSN=8715911
2018-10-16T05:51:27.461Z,1539669087.461 [DataOverHttps](INFO): Sending 921 bytes from file Logs/20181016T054155/Express0001.lzma
2018-10-16T05:51:28.227Z,1539669088.227 [DataOverHttps](INFO): Moved sent file to Logs/20181016T054155/Express0001.lzma.bak
2018-10-16T05:51:28.227Z,1539669088.227 [DataOverHttps](INFO): SBD MOMSN=8715914
2018-10-16T05:51:37.628Z,1539669097.628 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20181016T054155/Express0005.lzma
2018-10-16T05:51:38.400Z,1539669098.400 [DataOverHttps](INFO): Moved sent file to Logs/20181016T054155/Express0005.lzma.bak
2018-10-16T05:51:38.400Z,1539669098.400 [DataOverHttps](INFO): SBD MOMSN=8715939
2018-10-16T05:51:39.146Z,1539669099.146 [Default:CheckIn:Read_Iridium] Stopped
2018-10-16T05:51:39.146Z,1539669099.146 [Default:CheckIn:C.Wait] Running Loop=1
2018-10-16T05:51:39.146Z,1539669099.146 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-10-16T05:52:45.600Z,1539669165.600 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-10-16T05:52:45.600Z,1539669165.600 [NAL9602] Data Fault, FailCount= 1
2018-10-16T05:52:45.600Z,1539669165.600 [NAL9602](ERROR): Data Fault
2018-10-16T05:52:45.672Z,1539669165.672 [CBIT](ERROR): Data Fault in component: NAL9602
2018-10-16T05:52:46.004Z,1539669166.004 [NAL9602](INFO): Powering down
2018-10-16T05:52:46.963Z,1539669166.963 [CBIT](INFO): Clearing failed state for component NAL9602
2018-10-16T05:52:46.964Z,1539669166.964 [NAL9602] No Fault, FailCount= 1
2018-10-16T05:53:16.400Z,1539669196.400 [NAL9602](INFO): Powering up NAL9602
2018-10-16T05:53:27.600Z,1539669207.600 [NAL9602](INFO): NAL9602 initialized
2018-10-16T05:54:07.635Z,1539669247.635 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T05:54:07.635Z,1539669247.635 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2018-10-16T05:54:07.635Z,1539669247.635 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T05:54:07.672Z,1539669247.672 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T05:54:08.044Z,1539669248.044 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T05:54:08.045Z,1539669248.045 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2018-10-16T05:54:08.428Z,1539669248.428 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:54:08.429Z,1539669248.429 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:54:08.429Z,1539669248.429 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T05:56:39.508Z,1539669399.508 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-10-16T05:56:39.508Z,1539669399.508 [Default:CheckIn:C.Wait] Stopped
2018-10-16T05:56:39.509Z,1539669399.509 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-10-16T05:56:39.509Z,1539669399.509 [Default:CheckIn:D] Running Loop=1
2018-10-16T05:56:39.881Z,1539669399.881 [Default:CheckIn:D] Stopped
2018-10-16T05:56:39.881Z,1539669399.881 [Default:CheckIn:E] Running Loop=1
2018-10-16T05:56:40.287Z,1539669400.287 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.030811 min 
2018-10-16T05:56:40.289Z,1539669400.289 [Default:CheckIn:E] Stopped
2018-10-16T05:56:40.289Z,1539669400.289 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-10-16T05:56:40.289Z,1539669400.289 [Default:CheckIn] Stopped
2018-10-16T05:56:40.289Z,1539669400.289 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-10-16T05:56:40.289Z,1539669400.289 [Default:CheckIn](INFO): Running loop #2
2018-10-16T05:56:40.289Z,1539669400.289 [Default:CheckIn] Running Loop=2
2018-10-16T05:56:40.289Z,1539669400.289 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-10-16T05:56:40.290Z,1539669400.290 [Default:CheckIn:Read_GPS] Running Loop=1
2018-10-16T05:57:08.628Z,1539669428.628 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T05:57:08.628Z,1539669428.628 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2018-10-16T05:57:08.628Z,1539669428.628 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T05:57:08.654Z,1539669428.654 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T05:57:09.006Z,1539669429.006 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T05:57:09.006Z,1539669429.006 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2018-10-16T05:57:09.459Z,1539669429.459 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T05:57:09.460Z,1539669429.460 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T05:57:09.461Z,1539669429.461 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T06:00:09.461Z,1539669609.461 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T06:00:09.461Z,1539669609.461 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6
2018-10-16T06:00:09.461Z,1539669609.461 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T06:00:09.528Z,1539669609.528 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T06:00:09.862Z,1539669609.862 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T06:00:09.862Z,1539669609.862 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6
2018-10-16T06:00:10.224Z,1539669610.224 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T06:00:10.224Z,1539669610.224 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T06:00:10.225Z,1539669610.225 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T06:01:40.594Z,1539669700.594 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-10-16T05:56:40.3Z
2018-10-16T06:01:40.594Z,1539669700.594 [Default:CheckIn:Read_GPS] Stopped
2018-10-16T06:01:40.594Z,1539669700.594 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-10-16T06:01:45.288Z,1539669705.288 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T054155/Courier0007.lzma
2018-10-16T06:01:46.080Z,1539669706.080 [DataOverHttps](INFO): Moved sent file to Logs/20181016T054155/Courier0007.lzma.bak
2018-10-16T06:01:46.080Z,1539669706.080 [DataOverHttps](INFO): SBD MOMSN=8715943
2018-10-16T06:01:55.660Z,1539669715.660 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20181016T054155/Express0008.lzma
2018-10-16T06:01:56.440Z,1539669716.440 [DataOverHttps](INFO): Moved sent file to Logs/20181016T054155/Express0008.lzma.bak
2018-10-16T06:01:56.440Z,1539669716.440 [DataOverHttps](INFO): SBD MOMSN=8715945
2018-10-16T06:01:57.214Z,1539669717.214 [Default:CheckIn:Read_Iridium] Stopped
2018-10-16T06:01:57.214Z,1539669717.214 [Default:CheckIn:C.Wait] Running Loop=1
2018-10-16T06:01:57.215Z,1539669717.215 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-10-16T06:03:10.253Z,1539669790.253 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T06:03:10.253Z,1539669790.253 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7
2018-10-16T06:03:10.253Z,1539669790.253 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T06:03:10.297Z,1539669790.297 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T06:03:10.687Z,1539669790.687 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T06:03:10.687Z,1539669790.687 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7
2018-10-16T06:03:11.062Z,1539669791.062 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T06:03:11.062Z,1539669791.062 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T06:03:11.063Z,1539669791.063 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T06:03:29.021Z,1539669809.021 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-10-16T06:03:29.021Z,1539669809.021 [NAL9602] Data Fault, FailCount= 2
2018-10-16T06:03:29.021Z,1539669809.021 [NAL9602](ERROR): Data Fault
2018-10-16T06:03:29.104Z,1539669809.104 [CBIT](ERROR): Data Fault in component: NAL9602
2018-10-16T06:03:29.424Z,1539669809.424 [NAL9602](INFO): Powering down
2018-10-16T06:03:30.290Z,1539669810.290 [CBIT](INFO): Clearing failed state for component NAL9602
2018-10-16T06:03:30.290Z,1539669810.290 [NAL9602] No Fault, FailCount= 2
2018-10-16T06:04:01.705Z,1539669841.705 [NAL9602](INFO): Powering up NAL9602
2018-10-16T06:04:12.592Z,1539669852.592 [NAL9602](INFO): NAL9602 initialized
2018-10-16T06:06:11.329Z,1539669971.329 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T06:06:11.329Z,1539669971.329 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 8
2018-10-16T06:06:11.329Z,1539669971.329 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T06:06:11.343Z,1539669971.343 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T06:06:11.739Z,1539669971.739 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T06:06:11.740Z,1539669971.740 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 8
2018-10-16T06:06:12.090Z,1539669972.090 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T06:06:12.094Z,1539669972.094 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T06:06:12.095Z,1539669972.095 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T06:06:57.682Z,1539670017.682 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2018-10-16T06:06:57.682Z,1539670017.682 [Default:CheckIn:C.Wait] Stopped
2018-10-16T06:06:57.682Z,1539670017.682 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-10-16T06:06:57.682Z,1539670017.682 [Default:CheckIn:D] Running Loop=1
2018-10-16T06:06:58.085Z,1539670018.085 [Default:CheckIn:D] Stopped
2018-10-16T06:06:58.085Z,1539670018.085 [Default:CheckIn:E] Running Loop=1
2018-10-16T06:06:58.488Z,1539670018.488 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.334245 min 
2018-10-16T06:06:58.488Z,1539670018.488 [Default:CheckIn:E] Stopped
2018-10-16T06:06:58.488Z,1539670018.488 [Default:CheckIn](INFO): Completed Default:CheckIn
2018-10-16T06:06:58.488Z,1539670018.488 [Default:CheckIn] Stopped
2018-10-16T06:06:58.488Z,1539670018.488 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-10-16T06:06:58.489Z,1539670018.489 [Default:CheckIn](INFO): Running loop #3
2018-10-16T06:06:58.489Z,1539670018.489 [Default:CheckIn] Running Loop=3
2018-10-16T06:06:58.489Z,1539670018.489 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-10-16T06:06:58.489Z,1539670018.489 [Default:CheckIn:Read_GPS] Running Loop=1
2018-10-16T06:09:12.299Z,1539670152.299 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T06:09:12.299Z,1539670152.299 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 9
2018-10-16T06:09:12.299Z,1539670152.299 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T06:09:12.311Z,1539670152.311 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T06:09:12.699Z,1539670152.699 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T06:09:12.699Z,1539670152.699 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 9
2018-10-16T06:09:13.153Z,1539670153.153 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T06:09:13.155Z,1539670153.155 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T06:09:13.156Z,1539670153.156 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T06:11:58.673Z,1539670318.673 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-10-16T06:06:58.5Z
2018-10-16T06:11:58.674Z,1539670318.674 [Default:CheckIn:Read_GPS] Stopped
2018-10-16T06:11:58.674Z,1539670318.674 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-10-16T06:12:04.179Z,1539670324.179 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T054155/Courier0010.lzma
2018-10-16T06:12:04.960Z,1539670324.960 [DataOverHttps](INFO): Moved sent file to Logs/20181016T054155/Courier0010.lzma.bak
2018-10-16T06:12:04.961Z,1539670324.961 [DataOverHttps](INFO): SBD MOMSN=8715949
2018-10-16T06:12:14.275Z,1539670334.275 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-10-16T06:12:14.275Z,1539670334.275 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 10
2018-10-16T06:12:14.275Z,1539670334.275 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-10-16T06:12:14.287Z,1539670334.287 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-10-16T06:12:14.326Z,1539670334.326 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20181016T054155/Express0011.lzma
2018-10-16T06:12:14.437Z,1539670334.437 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-10-16T06:12:14.437Z,1539670334.437 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 10
2018-10-16T06:12:14.752Z,1539670334.752 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-10-16T06:12:14.753Z,1539670334.753 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-10-16T06:12:14.753Z,1539670334.753 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-10-16T06:12:15.101Z,1539670335.101 [DataOverHttps](INFO): Moved sent file to Logs/20181016T054155/Express0011.lzma.bak
2018-10-16T06:12:15.102Z,1539670335.102 [DataOverHttps](INFO): SBD MOMSN=8715951
2018-10-16T06:12:15.690Z,1539670335.690 [Default:CheckIn:Read_Iridium] Stopped
2018-10-16T06:12:15.690Z,1539670335.690 [Default:CheckIn:C.Wait] Running Loop=1
2018-10-16T06:12:15.690Z,1539670335.690 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-10-16T06:14:13.704Z,1539670453.704 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-10-16T06:14:13.704Z,1539670453.704 [NAL9602] Data Fault, FailCount= 3
2018-10-16T06:14:13.704Z,1539670453.704 [NAL9602](ERROR): Data Fault
2018-10-16T06:14:13.770Z,1539670453.770 [CBIT](ERROR): Data Fault in component: NAL9602
2018-10-16T06:14:14.104Z,1539670454.104 [NAL9602](INFO): Powering down
2018-10-16T06:14:15.057Z,1539670455.057 [CBIT](INFO): Clearing failed state for component NAL9602
2018-10-16T06:14:15.057Z,1539670455.057 [NAL9602] No Fault, FailCount= 3
2018-10-16T06:14:44.376Z,1539670484.376 [NAL9602](INFO): Powering up NAL9602
2018-10-16T06:14:55.576Z,1539670495.576 [NAL9602](INFO): NAL9602 initialized
2018-10-16T06:14:58.103Z,1539670498.103 [CommandLine](IMPORTANT): got command restart application
2018-10-16T06:14:59.106Z,1539670499.106 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-10-16T06:14:59.109Z,1539670499.109 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T06:14:59.110Z,1539670499.110 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:14:59.294Z,1539670499.294 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-10-16T06:14:59.295Z,1539670499.295 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:14:59.295Z,1539670499.295 [CommandLine](INFO): Join timeout helper Thread ID is 6722
2018-10-16T06:14:59.310Z,1539670499.310 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-10-16T06:14:59.311Z,1539670499.311 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:14:59.311Z,1539670499.311 [NavChartDb](INFO): Join timeout helper Thread ID is 6723
2018-10-16T06:14:59.358Z,1539670499.358 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T06:14:59.359Z,1539670499.359 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:14:59.362Z,1539670499.362 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-10-16T06:14:59.362Z,1539670499.362 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:14:59.363Z,1539670499.363 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6724
2018-10-16T06:14:59.483Z,1539670499.483 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T06:14:59.483Z,1539670499.483 [WetLabsBB2FL](INFO): Powering down
2018-10-16T06:14:59.483Z,1539670499.483 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:14:59.486Z,1539670499.486 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-10-16T06:14:59.487Z,1539670499.487 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:14:59.487Z,1539670499.487 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 6725
2018-10-16T06:15:00.103Z,1539670500.103 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T06:15:00.103Z,1539670500.103 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-10-16T06:15:00.568Z,1539670500.568 [Rowe_600LCM](INFO): Powering down
2018-10-16T06:15:00.569Z,1539670500.569 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.575Z,1539670500.575 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-10-16T06:15:00.575Z,1539670500.575 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.575Z,1539670500.575 [Radio_Surface](INFO): Join timeout helper Thread ID is 6727
2018-10-16T06:15:00.691Z,1539670500.691 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T06:15:00.691Z,1539670500.691 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.712Z,1539670500.712 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-10-16T06:15:00.713Z,1539670500.713 [logger ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.713Z,1539670500.713 [logger](INFO): Join timeout helper Thread ID is 6728
2018-10-16T06:15:00.713Z,1539670500.713 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T06:15:00.713Z,1539670500.713 [logger ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.715Z,1539670500.715 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-10-16T06:15:00.715Z,1539670500.715 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.715Z,1539670500.715 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-10-16T06:15:00.715Z,1539670500.715 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.716Z,1539670500.716 [controlThread](INFO): Join timeout helper Thread ID is 6729
2018-10-16T06:15:00.767Z,1539670500.767 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-10-16T06:15:00.767Z,1539670500.767 [controlThread](DEBUG): Uninitializing ControlThread
2018-10-16T06:15:00.768Z,1539670500.768 [NAL9602](INFO): Powering down
2018-10-16T06:15:00.769Z,1539670500.769 [PNI_TCM](INFO): Powering down
2018-10-16T06:15:00.855Z,1539670500.855 [Aanderaa_O2](INFO): Powering down
2018-10-16T06:15:00.856Z,1539670500.856 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-10-16T06:15:00.857Z,1539670500.857 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-10-16T06:15:00.858Z,1539670500.858 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-10-16T06:15:00.859Z,1539670500.859 [MissionManager](INFO): Uninitializing Mission Default
2018-10-16T06:15:00.859Z,1539670500.859 [Default] Stopped
2018-10-16T06:15:00.859Z,1539670500.859 [Default](DEBUG): Aggregate::uninitialize Default
2018-10-16T06:15:00.859Z,1539670500.859 [Default:B.GoToSurface] Stopped
2018-10-16T06:15:00.859Z,1539670500.859 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-10-16T06:15:00.859Z,1539670500.859 [Default:CheckIn] Stopped
2018-10-16T06:15:00.859Z,1539670500.859 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-10-16T06:15:00.859Z,1539670500.859 [Default:CheckIn:C.Wait] Stopped
2018-10-16T06:15:00.859Z,1539670500.859 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-10-16T06:15:00.863Z,1539670500.863 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-10-16T06:15:00.863Z,1539670500.863 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-10-16T06:15:00.864Z,1539670500.864 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-10-16T06:15:00.864Z,1539670500.864 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-10-16T06:15:00.864Z,1539670500.864 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-10-16T06:15:00.865Z,1539670500.865 [BuoyancyServo](INFO): Powering down
2018-10-16T06:15:00.879Z,1539670500.879 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-10-16T06:15:00.879Z,1539670500.879 [ElevatorServo](INFO): Powering down
2018-10-16T06:15:00.880Z,1539670500.880 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-10-16T06:15:00.880Z,1539670500.880 [MassServo](INFO): Powering down
2018-10-16T06:15:00.881Z,1539670500.881 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-10-16T06:15:00.881Z,1539670500.881 [RudderServo](INFO): Powering down
2018-10-16T06:15:00.882Z,1539670500.882 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-10-16T06:15:00.882Z,1539670500.882 [ThrusterServo](INFO): Powering down
2018-10-16T06:15:00.883Z,1539670500.883 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-10-16T06:15:00.883Z,1539670500.883 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-10-16T06:15:00.884Z,1539670500.884 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-10-16T06:15:00.885Z,1539670500.885 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.969Z,1539670500.969 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:00.984Z,1539670500.984 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:01.062Z,1539670501.062 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:01.128Z,1539670501.128 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-10-16T06:15:01.249Z,1539670501.249 [logger ThreadHandler](INFO): Thread cancelled.