2017-10-26T21:48:49.043Z,1509054529.043 [DataOverHttps](INFO): Sending 344 bytes from file Logs/20171025T005524/Courier0016.lzma
2017-10-26T21:48:49.848Z,1509054529.848 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005524/Courier0016.lzma.bak
2017-10-26T21:48:49.848Z,1509054529.848 [DataOverHttps](INFO): SBD MOMSN=5165255
2017-10-26T21:48:58.586Z,1509054538.586 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171025T005524/Courier0020.lzma
2017-10-26T21:48:59.365Z,1509054539.365 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005524/Courier0020.lzma.bak
2017-10-26T21:48:59.365Z,1509054539.365 [DataOverHttps](INFO): SBD MOMSN=5165300
2017-10-26T21:49:08.893Z,1509054548.893 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171025T075431/Courier0000.lzma
2017-10-26T21:49:09.702Z,1509054549.702 [DataOverHttps](INFO): Moved sent file to Logs/20171025T075431/Courier0000.lzma.bak
2017-10-26T21:49:09.702Z,1509054549.702 [DataOverHttps](INFO): SBD MOMSN=5165302
2017-10-26T21:49:18.435Z,1509054558.435 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171025T075928/Courier0000.lzma
2017-10-26T21:49:19.218Z,1509054559.218 [DataOverHttps](INFO): Moved sent file to Logs/20171025T075928/Courier0000.lzma.bak
2017-10-26T21:49:19.218Z,1509054559.218 [DataOverHttps](INFO): SBD MOMSN=5165305
2017-10-26T21:49:24.045Z,1509054564.045 [DataOverHttps](IMPORTANT): SBD MTMSN=20171026T214923
2017-10-26T21:49:27.994Z,1509054567.994 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20171025T080149/Courier0000.lzma
2017-10-26T21:49:28.013Z,1509054568.013 [DataOverHttps](INFO): Received command:load Maintenance/sample.xml;set sample.Depth 0 meter;set sample.NumberOfSamples 10 count;set sample.WaitBeforeSample 10 second;run 
2017-10-26T21:49:28.034Z,1509054568.034 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2017-10-26T21:49:28.035Z,1509054568.035 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2017-10-26T21:49:28.098Z,1509054568.098 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2017-10-26T21:49:28.100Z,1509054568.100 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2017-10-26T21:49:28.102Z,1509054568.102 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2017-10-26T21:49:28.104Z,1509054568.104 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2017-10-26T21:49:28.105Z,1509054568.105 [sample:A.Pitch](DEBUG): Construct.
2017-10-26T21:49:28.125Z,1509054568.125 [sample:B.SetSpeed](DEBUG): Construct.
2017-10-26T21:49:28.127Z,1509054568.127 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2017-10-26T21:49:28.192Z,1509054568.192 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2017-10-26T21:49:28.194Z,1509054568.194 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 30.000000 s
2017-10-26T21:49:28.196Z,1509054568.196 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2017-10-26T21:49:28.199Z,1509054568.198 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool
2017-10-26T21:49:28.201Z,1509054568.201 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool
2017-10-26T21:49:28.203Z,1509054568.203 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2017-10-26T21:49:28.205Z,1509054568.205 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2017-10-26T21:49:28.207Z,1509054568.207 [sample:SampleAtDepth:B.Pitch](DEBUG): Construct.
2017-10-26T21:49:28.229Z,1509054568.229 [sample:SampleAtDepth:D.Wait](DEBUG): Construct Wait.
2017-10-26T21:49:28.246Z,1509054568.246 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2017-10-26T21:49:28.265Z,1509054568.265 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2017-10-26T21:49:28.289Z,1509054568.289 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns: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"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

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

    <Insert Filename="Insert/SampleAtDepth.xml"/>

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2017-10-26T21:49:28.290Z,1509054568.290 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2017-10-26T21:49:30.557Z,1509054570.557 [CommandLine](IMPORTANT): got command set sample.Depth 0.000000 meter
2017-10-26T21:49:30.557Z,1509054570.557 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 10.000000 count
2017-10-26T21:49:30.558Z,1509054570.558 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 10.000000 second
2017-10-26T21:49:30.559Z,1509054570.559 [CommandLine](IMPORTANT): got command run 
2017-10-26T21:49:30.576Z,1509054570.576 [CommandLine](IMPORTANT): Running 
2017-10-26T21:49:30.664Z,1509054570.664 [Default] Stopped
2017-10-26T21:49:30.664Z,1509054570.664 [Default](DEBUG): Aggregate::uninitialize Default
2017-10-26T21:49:30.664Z,1509054570.664 [Default:B.GoToSurface] Stopped
2017-10-26T21:49:30.664Z,1509054570.664 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-10-26T21:49:30.664Z,1509054570.664 [Default:CheckIn] Stopped
2017-10-26T21:49:30.665Z,1509054570.665 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-10-26T21:49:30.665Z,1509054570.665 [Default:CheckIn:Read_Iridium] Stopped
2017-10-26T21:49:30.665Z,1509054570.665 [MissionManager](IMPORTANT): Started mission sample
2017-10-26T21:49:30.665Z,1509054570.665 [sample] Running Loop=1
2017-10-26T21:49:30.665Z,1509054570.665 [sample](DEBUG): Aggregate::initialize sample
2017-10-26T21:49:30.665Z,1509054570.665 [sample:A.Pitch] Running Loop=1
2017-10-26T21:49:30.665Z,1509054570.665 [sample:A.Pitch](DEBUG): Initialize.
2017-10-26T21:49:30.665Z,1509054570.665 [sample:B.SetSpeed] Running Loop=1
2017-10-26T21:49:30.666Z,1509054570.666 [sample:B.SetSpeed](DEBUG): Initialize.
2017-10-26T21:49:30.666Z,1509054570.666 [sample:D] Running Loop=1
2017-10-26T21:49:30.667Z,1509054570.667 [sample:D] Stopped
2017-10-26T21:49:30.667Z,1509054570.667 [sample:E] Running Loop=1
2017-10-26T21:49:30.672Z,1509054570.672 [sample:B.SetSpeed] Running Loop=1
2017-10-26T21:49:30.672Z,1509054570.672 [sample:A.Pitch] Running Loop=1
2017-10-26T21:49:30.808Z,1509054570.808 [sample:E] Stopped
2017-10-26T21:49:30.808Z,1509054570.808 [sample:SampleRepeater] Running Loop=1
2017-10-26T21:49:30.809Z,1509054570.809 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2017-10-26T21:49:30.809Z,1509054570.809 [sample:SampleRepeater:Sample] Running Loop=1
2017-10-26T21:49:30.809Z,1509054570.809 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2017-10-26T21:49:31.109Z,1509054571.109 [DataOverHttps](INFO): Moved sent file to Logs/20171025T080149/Courier0000.lzma.bak
2017-10-26T21:49:31.109Z,1509054571.109 [DataOverHttps](INFO): SBD MOMSN=5165309
2017-10-26T21:49:31.191Z,1509054571.191 [sample:SampleAtDepth] Running Loop=1
2017-10-26T21:49:31.191Z,1509054571.191 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2017-10-26T21:49:31.191Z,1509054571.191 [sample:SampleAtDepth:B.Pitch] Running Loop=1
2017-10-26T21:49:31.191Z,1509054571.191 [sample:SampleAtDepth:B.Pitch](DEBUG): Initialize.
2017-10-26T21:49:31.192Z,1509054571.192 [sample:SampleAtDepth:A] Running Loop=1
2017-10-26T21:49:31.193Z,1509054571.193 [sample:SampleAtDepth:A](INFO): Moving to 0.000000 m 
2017-10-26T21:49:31.194Z,1509054571.194 [sample:SampleAtDepth:A] Stopped
2017-10-26T21:49:31.553Z,1509054571.553 [sample:SampleAtDepth:C] Running Loop=1
2017-10-26T21:49:31.951Z,1509054571.951 [sample:SampleAtDepth:C](INFO): At 0.000000 m , settling for 0.166667 min 
2017-10-26T21:49:31.952Z,1509054571.952 [sample:SampleAtDepth:C] Stopped
2017-10-26T21:49:31.952Z,1509054571.952 [sample:SampleAtDepth:D.Wait] Running Loop=1
2017-10-26T21:49:31.952Z,1509054571.952 [sample:SampleAtDepth:D.Wait](DEBUG): Initialize Wait Component.
2017-10-26T21:49:45.155Z,1509054585.155 [sample:SampleAtDepth:D.Wait](INFO): Done Waiting.
2017-10-26T21:49:45.155Z,1509054585.155 [sample:SampleAtDepth:D.Wait] Stopped
2017-10-26T21:49:45.155Z,1509054585.155 [sample:SampleAtDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2017-10-26T21:49:45.155Z,1509054585.155 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2017-10-26T21:49:45.155Z,1509054585.155 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2017-10-26T21:49:45.155Z,1509054585.155 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2017-10-26T21:49:45.156Z,1509054585.156 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2017-10-26T21:49:45.156Z,1509054585.156 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2017-10-26T21:49:45.156Z,1509054585.156 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2017-10-26T21:49:45.156Z,1509054585.156 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2017-10-26T21:49:45.558Z,1509054585.558 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2017-10-26T21:49:45.559Z,1509054585.559 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2017-10-26T21:49:45.559Z,1509054585.559 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2017-10-26T21:49:45.559Z,1509054585.559 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2017-10-26T21:49:45.559Z,1509054585.559 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2017-10-26T21:49:45.559Z,1509054585.559 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2017-10-26T21:49:45.559Z,1509054585.559 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2017-10-26T21:49:45.559Z,1509054585.559 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2017-10-26T21:49:45.952Z,1509054585.952 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2017-10-26T21:49:47.158Z,1509054587.158 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:47.945Z,1509054587.945 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:48.741Z,1509054588.741 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:49.542Z,1509054589.542 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:50.355Z,1509054590.355 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:51.135Z,1509054591.135 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:51.944Z,1509054591.944 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:52.752Z,1509054592.752 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:53.554Z,1509054593.554 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:54.335Z,1509054594.335 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:55.135Z,1509054595.135 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:55.558Z,1509054595.558 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:49:55.558Z,1509054595.558 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 53
2017-10-26T21:49:55.558Z,1509054595.558 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-26T21:49:55.560Z,1509054595.560 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:49:55.560Z,1509054595.560 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 53
2017-10-26T21:49:55.560Z,1509054595.560 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-26T21:49:55.629Z,1509054595.629 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-26T21:49:55.629Z,1509054595.629 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-26T21:49:55.952Z,1509054595.952 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:56.009Z,1509054596.009 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-26T21:49:56.009Z,1509054596.009 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 53
2017-10-26T21:49:56.009Z,1509054596.009 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-26T21:49:56.009Z,1509054596.009 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 53
2017-10-26T21:49:56.367Z,1509054596.367 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-26T21:49:56.368Z,1509054596.368 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:49:56.368Z,1509054596.368 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:49:56.368Z,1509054596.368 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-26T21:49:56.369Z,1509054596.369 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:49:56.369Z,1509054596.369 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:49:56.746Z,1509054596.746 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:56.771Z,1509054596.771 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-10-26T21:49:57.174Z,1509054597.174 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-10-26T21:49:57.536Z,1509054597.536 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:57.550Z,1509054597.550 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-10-26T21:49:57.950Z,1509054597.950 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-10-26T21:49:58.339Z,1509054598.339 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:58.348Z,1509054598.348 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-10-26T21:49:58.770Z,1509054598.770 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-10-26T21:49:59.150Z,1509054599.150 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:59.179Z,1509054599.179 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-10-26T21:49:59.569Z,1509054599.569 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-10-26T21:49:59.943Z,1509054599.943 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:49:59.950Z,1509054599.950 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-10-26T21:50:00.345Z,1509054600.345 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-10-26T21:50:00.738Z,1509054600.738 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:00.746Z,1509054600.746 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-10-26T21:50:01.150Z,1509054601.150 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-10-26T21:50:01.538Z,1509054601.538 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:01.546Z,1509054601.546 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-10-26T21:50:01.972Z,1509054601.972 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-10-26T21:50:02.349Z,1509054602.349 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:02.373Z,1509054602.373 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-10-26T21:50:02.772Z,1509054602.772 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-10-26T21:50:03.142Z,1509054603.142 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:03.149Z,1509054603.149 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-10-26T21:50:03.548Z,1509054603.548 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-10-26T21:50:03.938Z,1509054603.938 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:03.950Z,1509054603.950 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-10-26T21:50:04.366Z,1509054604.366 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2017-10-26T21:50:04.749Z,1509054604.749 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:04.757Z,1509054604.757 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2017-10-26T21:50:05.156Z,1509054605.156 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2017-10-26T21:50:05.553Z,1509054605.553 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:05.561Z,1509054605.561 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2017-10-26T21:50:05.955Z,1509054605.955 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2017-10-26T21:50:06.345Z,1509054606.345 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:06.352Z,1509054606.352 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s.
2017-10-26T21:50:06.748Z,1509054606.748 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s.
2017-10-26T21:50:07.144Z,1509054607.144 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:07.151Z,1509054607.151 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2017-10-26T21:50:07.548Z,1509054607.548 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s.
2017-10-26T21:50:07.954Z,1509054607.954 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:07.962Z,1509054607.962 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s.
2017-10-26T21:50:08.362Z,1509054608.362 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s.
2017-10-26T21:50:08.757Z,1509054608.757 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:08.773Z,1509054608.773 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s.
2017-10-26T21:50:09.166Z,1509054609.166 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2017-10-26T21:50:09.548Z,1509054609.548 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:09.564Z,1509054609.564 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s.
2017-10-26T21:50:09.955Z,1509054609.955 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s.
2017-10-26T21:50:10.362Z,1509054610.362 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:10.380Z,1509054610.380 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s.
2017-10-26T21:50:10.793Z,1509054610.793 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s.
2017-10-26T21:50:11.155Z,1509054611.155 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:11.183Z,1509054611.183 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2017-10-26T21:50:11.580Z,1509054611.580 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s.
2017-10-26T21:50:11.944Z,1509054611.944 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:11.951Z,1509054611.951 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s.
2017-10-26T21:50:12.354Z,1509054612.354 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s.
2017-10-26T21:50:12.773Z,1509054612.773 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:12.782Z,1509054612.782 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2017-10-26T21:50:13.171Z,1509054613.171 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s.
2017-10-26T21:50:13.550Z,1509054613.550 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:13.570Z,1509054613.570 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s.
2017-10-26T21:50:13.983Z,1509054613.983 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s.
2017-10-26T21:50:14.376Z,1509054614.376 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:14.422Z,1509054614.422 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.9 s old, using for 20.0 s.
2017-10-26T21:50:14.770Z,1509054614.770 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s.
2017-10-26T21:50:15.141Z,1509054615.141 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:15.173Z,1509054615.173 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2017-10-26T21:50:15.942Z,1509054615.942 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:16.768Z,1509054616.768 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:17.580Z,1509054617.580 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:18.341Z,1509054618.341 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:19.144Z,1509054619.144 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:19.950Z,1509054619.950 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:20.751Z,1509054620.751 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:21.544Z,1509054621.544 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:22.343Z,1509054622.343 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:23.155Z,1509054623.155 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:23.935Z,1509054623.935 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:24.735Z,1509054624.735 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:25.535Z,1509054625.535 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:26.360Z,1509054626.360 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:27.139Z,1509054627.139 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:27.936Z,1509054627.936 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:28.753Z,1509054628.753 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:29.555Z,1509054629.555 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:30.335Z,1509054630.335 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:31.136Z,1509054631.136 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:31.962Z,1509054631.962 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:35.253Z,1509054635.253 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:36.020Z,1509054636.020 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:36.821Z,1509054636.821 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:37.625Z,1509054637.625 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:38.416Z,1509054638.416 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:39.220Z,1509054639.220 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:40.026Z,1509054640.026 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:40.826Z,1509054640.826 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:41.614Z,1509054641.614 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:42.411Z,1509054642.411 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:43.225Z,1509054643.225 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:44.018Z,1509054644.018 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:44.816Z,1509054644.816 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:45.613Z,1509054645.613 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:46.434Z,1509054646.434 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:47.218Z,1509054647.218 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:48.018Z,1509054648.018 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:48.829Z,1509054648.829 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:49.625Z,1509054649.625 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:50.417Z,1509054650.417 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:51.222Z,1509054651.222 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:52.025Z,1509054652.025 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:52.827Z,1509054652.827 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:53.614Z,1509054653.614 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:53.877Z,1509054653.877 [CommandLine](IMPORTANT): got command stop
2017-10-26T21:50:53.877Z,1509054653.877 [CommandLine](IMPORTANT): Scheduling is paused
2017-10-26T21:50:53.877Z,1509054653.877 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2017-10-26T21:50:54.030Z,1509054654.030 [MissionManager](INFO): MissionManager is completed.
2017-10-26T21:50:54.030Z,1509054654.030 [MissionManager](INFO): Uninitializing Mission sample
2017-10-26T21:50:54.030Z,1509054654.030 [sample] Stopped
2017-10-26T21:50:54.030Z,1509054654.030 [sample](DEBUG): Aggregate::uninitialize sample
2017-10-26T21:50:54.030Z,1509054654.030 [sample:A.Pitch] Stopped
2017-10-26T21:50:54.030Z,1509054654.030 [sample:B.SetSpeed] Stopped
2017-10-26T21:50:54.030Z,1509054654.030 [sample:B.SetSpeed](DEBUG): Uninitialize.
2017-10-26T21:50:54.030Z,1509054654.030 [sample:SampleAtDepth] Stopped
2017-10-26T21:50:54.030Z,1509054654.030 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleAtDepth:B.Pitch] Stopped
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleAtDepth:SampleWrapper] Stopped
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleRepeater] Stopped
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleRepeater:Sample] Stopped
2017-10-26T21:50:54.031Z,1509054654.031 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2017-10-26T21:50:54.419Z,1509054654.419 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:50:54.429Z,1509054654.429 [MissionManager](IMPORTANT): Started mission Default
2017-10-26T21:50:54.429Z,1509054654.429 [Default] Running Loop=1
2017-10-26T21:50:54.429Z,1509054654.429 [Default](DEBUG): Aggregate::initialize Default
2017-10-26T21:50:54.429Z,1509054654.429 [Default:B.GoToSurface] Running Loop=1
2017-10-26T21:50:54.429Z,1509054654.429 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-10-26T21:50:54.429Z,1509054654.429 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-10-26T21:50:54.430Z,1509054654.430 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-10-26T21:50:54.430Z,1509054654.430 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-10-26T21:50:54.430Z,1509054654.430 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-10-26T21:50:54.431Z,1509054654.431 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-10-26T21:50:54.431Z,1509054654.431 [Default:A.Wait] Running Loop=1
2017-10-26T21:50:54.431Z,1509054654.431 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-10-26T21:50:55.225Z,1509054655.225 [ESPComponent](INFO): powering down ESP
2017-10-26T21:51:07.639Z,1509054667.639 [Default:A.Wait](INFO): Done Waiting.
2017-10-26T21:51:07.639Z,1509054667.639 [Default:A.Wait] Stopped
2017-10-26T21:51:07.640Z,1509054667.640 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-10-26T21:51:08.041Z,1509054668.041 [Default:CheckIn] Running Loop=1
2017-10-26T21:51:08.041Z,1509054668.041 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-10-26T21:51:08.041Z,1509054668.041 [Default:CheckIn:Read_GPS] Running Loop=1
2017-10-26T21:51:36.048Z,1509054696.048 [DataOverHttps](IMPORTANT): SBD MTMSN=20171026T215135
2017-10-26T21:51:40.065Z,1509054700.065 [DataOverHttps](INFO): Received command:load Maintenance/sample.xml;set sample.Depth 0 meter;set sample.NumberOfSamples 10 count;set sample.WaitBeforeSample 10 second;set sample:SampleAtDepth.TargetDepth 0 meter;set sample:SampleAtDepth.SettleTime 10 second;run 
2017-10-26T21:51:40.089Z,1509054700.089 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample.xml
2017-10-26T21:51:40.089Z,1509054700.089 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml
2017-10-26T21:51:40.131Z,1509054700.131 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min
2017-10-26T21:51:40.133Z,1509054700.133 [MissionManager](INFO): DefineArg sample.Depth = 7.000000 m
2017-10-26T21:51:40.135Z,1509054700.135 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 1.000000 count
2017-10-26T21:51:40.137Z,1509054700.137 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 3.000000 min
2017-10-26T21:51:40.138Z,1509054700.138 [sample:A.Pitch](DEBUG): Construct.
2017-10-26T21:51:40.174Z,1509054700.174 [sample:B.SetSpeed](DEBUG): Construct.
2017-10-26T21:51:40.176Z,1509054700.176 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml
2017-10-26T21:51:40.225Z,1509054700.225 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m
2017-10-26T21:51:40.227Z,1509054700.227 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 30.000000 s
2017-10-26T21:51:40.229Z,1509054700.229 [MissionManager](INFO): DefineArg sample:SampleAtDepth.RotateOnly = 0.000000 bool
2017-10-26T21:51:40.232Z,1509054700.232 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool
2017-10-26T21:51:40.234Z,1509054700.234 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool
2017-10-26T21:51:40.236Z,1509054700.236 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min
2017-10-26T21:51:40.238Z,1509054700.238 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 6.000000 min
2017-10-26T21:51:40.240Z,1509054700.240 [sample:SampleAtDepth:B.Pitch](DEBUG): Construct.
2017-10-26T21:51:40.274Z,1509054700.274 [sample:SampleAtDepth:D.Wait](DEBUG): Construct Wait.
2017-10-26T21:51:40.281Z,1509054700.281 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler:A_Timeout:B.Execute](DEBUG): Construct Execute.
2017-10-26T21:51:40.315Z,1509054700.315 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:E:A_Timeout:B.Execute](DEBUG): Construct Execute.
2017-10-26T21:51:40.333Z,1509054700.333 [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: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"
       Id="sample">

    <Description>
        This mission is designed to be run in the test tank only and samples
        whichever sampler is installed once the vehicle reaches the target
        depth.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="Depth"><Description>
        Depth to sample at.
    </Description><Units:meter/><Value>7</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <DefineArg Name="WaitBeforeSample"><Description>
        How long to wait between samples. This starts *before* the first sample
        to exercise the SettleTime setting in the insert aggregate.
    </Description><Units:minute/><Value>3</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Control:VerticalControl.massDefault/></Setting>
    </Guidance:Pitch>

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

    <Insert Filename="Insert/SampleAtDepth.xml"/>

    <Assign><Sequence/><Arg Name="SampleAtDepth:TargetDepth"/><Arg Name="Depth"/></Assign>

    <Assign><Sequence/><Arg Name="SampleAtDepth:SettleTime"/><Arg Name="WaitBeforeSample"/></Assign>

    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Call Id="Sample" RefId="SampleAtDepth"/>

    </Aggregate>

</Mission>


2017-10-26T21:51:40.334Z,1509054700.334 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample.xml
2017-10-26T21:51:44.787Z,1509054704.787 [CommandLine](IMPORTANT): got command set sample.Depth 0.000000 meter
2017-10-26T21:51:44.788Z,1509054704.788 [CommandLine](IMPORTANT): got command set sample.NumberOfSamples 10.000000 count
2017-10-26T21:51:44.789Z,1509054704.789 [CommandLine](IMPORTANT): got command set sample.WaitBeforeSample 10.000000 second
2017-10-26T21:51:44.789Z,1509054704.789 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.TargetDepth 0.000000 meter
2017-10-26T21:51:44.790Z,1509054704.790 [CommandLine](IMPORTANT): got command set sample:SampleAtDepth.SettleTime 10.000000 second
2017-10-26T21:51:44.791Z,1509054704.791 [CommandLine](IMPORTANT): got command run 
2017-10-26T21:51:44.815Z,1509054704.815 [CommandLine](IMPORTANT): Running 
2017-10-26T21:51:44.897Z,1509054704.897 [Default] Stopped
2017-10-26T21:51:44.897Z,1509054704.897 [Default](DEBUG): Aggregate::uninitialize Default
2017-10-26T21:51:44.897Z,1509054704.897 [Default:B.GoToSurface] Stopped
2017-10-26T21:51:44.898Z,1509054704.898 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2017-10-26T21:51:44.898Z,1509054704.898 [Default:CheckIn] Stopped
2017-10-26T21:51:44.898Z,1509054704.898 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2017-10-26T21:51:44.898Z,1509054704.898 [Default:CheckIn:Read_GPS] Stopped
2017-10-26T21:51:44.898Z,1509054704.898 [MissionManager](IMPORTANT): Started mission sample
2017-10-26T21:51:44.898Z,1509054704.898 [sample] Running Loop=1
2017-10-26T21:51:44.898Z,1509054704.898 [sample](DEBUG): Aggregate::initialize sample
2017-10-26T21:51:44.898Z,1509054704.898 [sample:A.Pitch] Running Loop=1
2017-10-26T21:51:44.898Z,1509054704.898 [sample:A.Pitch](DEBUG): Initialize.
2017-10-26T21:51:44.899Z,1509054704.899 [sample:B.SetSpeed] Running Loop=1
2017-10-26T21:51:44.899Z,1509054704.899 [sample:B.SetSpeed](DEBUG): Initialize.
2017-10-26T21:51:44.899Z,1509054704.899 [sample:D] Running Loop=1
2017-10-26T21:51:44.900Z,1509054704.900 [sample:D] Stopped
2017-10-26T21:51:44.900Z,1509054704.900 [sample:E] Running Loop=1
2017-10-26T21:51:44.900Z,1509054704.900 [sample:B.SetSpeed] Running Loop=1
2017-10-26T21:51:44.901Z,1509054704.901 [sample:A.Pitch] Running Loop=1
2017-10-26T21:51:45.069Z,1509054705.069 [sample:E] Stopped
2017-10-26T21:51:45.069Z,1509054705.069 [sample:SampleRepeater] Running Loop=1
2017-10-26T21:51:45.069Z,1509054705.069 [sample:SampleRepeater](DEBUG): Aggregate::initialize sample:SampleRepeater
2017-10-26T21:51:45.069Z,1509054705.069 [sample:SampleRepeater:Sample] Running Loop=1
2017-10-26T21:51:45.069Z,1509054705.069 [sample:SampleRepeater:Sample](DEBUG): Aggregate::initialize sample:SampleRepeater:Sample
2017-10-26T21:51:45.450Z,1509054705.450 [sample:SampleAtDepth] Running Loop=1
2017-10-26T21:51:45.451Z,1509054705.451 [sample:SampleAtDepth](DEBUG): Aggregate::initialize sample:SampleAtDepth
2017-10-26T21:51:45.451Z,1509054705.451 [sample:SampleAtDepth:B.Pitch] Running Loop=1
2017-10-26T21:51:45.451Z,1509054705.451 [sample:SampleAtDepth:B.Pitch](DEBUG): Initialize.
2017-10-26T21:51:45.451Z,1509054705.451 [sample:SampleAtDepth:A] Running Loop=1
2017-10-26T21:51:45.472Z,1509054705.472 [sample:SampleAtDepth:A](INFO): Moving to 0.000000 m 
2017-10-26T21:51:45.473Z,1509054705.473 [sample:SampleAtDepth:A] Stopped
2017-10-26T21:51:45.846Z,1509054705.846 [sample:SampleAtDepth:C] Running Loop=1
2017-10-26T21:51:46.238Z,1509054706.238 [sample:SampleAtDepth:C](INFO): At 0.000000 m , settling for 0.166667 min 
2017-10-26T21:51:46.238Z,1509054706.238 [sample:SampleAtDepth:C] Stopped
2017-10-26T21:51:46.239Z,1509054706.239 [sample:SampleAtDepth:D.Wait] Running Loop=1
2017-10-26T21:51:46.239Z,1509054706.239 [sample:SampleAtDepth:D.Wait](DEBUG): Initialize Wait Component.
2017-10-26T21:51:56.653Z,1509054716.653 [sample:SampleAtDepth:D.Wait](INFO): Done Waiting.
2017-10-26T21:51:56.653Z,1509054716.653 [sample:SampleAtDepth:D.Wait] Stopped
2017-10-26T21:51:56.653Z,1509054716.653 [sample:SampleAtDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2017-10-26T21:51:56.653Z,1509054716.653 [sample:SampleAtDepth:SampleWrapper] Running Loop=1
2017-10-26T21:51:56.653Z,1509054716.653 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper
2017-10-26T21:51:56.653Z,1509054716.653 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Running Loop=1
2017-10-26T21:51:56.653Z,1509054716.653 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2017-10-26T21:51:56.654Z,1509054716.654 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Running Loop=1
2017-10-26T21:51:56.654Z,1509054716.654 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Running Loop=1
2017-10-26T21:51:56.654Z,1509054716.654 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Running Loop=1
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler] Stopped
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleCANONSampler
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:A] Stopped
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:B] Stopped
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleCANONSampler:TriggerCANONSampler] Stopped
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleESP] Running Loop=1
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::initialize sample:SampleAtDepth:SampleWrapper:SampleESP
2017-10-26T21:51:57.043Z,1509054717.043 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Running Loop=1
2017-10-26T21:51:57.449Z,1509054717.449 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2017-10-26T21:51:58.619Z,1509054718.619 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:51:59.439Z,1509054719.439 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:00.218Z,1509054720.218 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:01.020Z,1509054721.020 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:01.838Z,1509054721.838 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:02.638Z,1509054722.638 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:03.419Z,1509054723.419 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:04.223Z,1509054724.223 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:05.037Z,1509054725.037 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:05.841Z,1509054725.841 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:06.618Z,1509054726.618 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:07.419Z,1509054727.419 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:08.243Z,1509054728.243 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:09.019Z,1509054729.019 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:09.818Z,1509054729.818 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:10.618Z,1509054730.618 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:11.439Z,1509054731.439 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:12.218Z,1509054732.218 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:13.019Z,1509054733.019 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:13.838Z,1509054733.838 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:14.638Z,1509054734.638 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:15.418Z,1509054735.418 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:16.223Z,1509054736.223 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:17.035Z,1509054737.035 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:17.839Z,1509054737.839 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:18.618Z,1509054738.618 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:19.418Z,1509054739.418 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:20.244Z,1509054740.244 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:21.019Z,1509054741.019 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:21.820Z,1509054741.820 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:22.623Z,1509054742.623 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:23.442Z,1509054743.442 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:24.219Z,1509054744.219 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:25.020Z,1509054745.020 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:25.837Z,1509054745.837 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:26.640Z,1509054746.640 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:27.418Z,1509054747.418 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:28.219Z,1509054748.219 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:29.039Z,1509054749.039 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:29.840Z,1509054749.840 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:30.618Z,1509054750.618 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:31.422Z,1509054751.422 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:32.240Z,1509054752.240 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:33.018Z,1509054753.018 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:33.822Z,1509054753.822 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:34.618Z,1509054754.618 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:35.439Z,1509054755.439 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:36.222Z,1509054756.222 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:37.024Z,1509054757.024 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:40.253Z,1509054760.253 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:41.009Z,1509054761.009 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:41.798Z,1509054761.798 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:42.598Z,1509054762.598 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:43.411Z,1509054763.411 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:44.196Z,1509054764.196 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:45.001Z,1509054765.001 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:45.807Z,1509054765.807 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:46.605Z,1509054766.605 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:47.400Z,1509054767.400 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:48.197Z,1509054768.197 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:49.006Z,1509054769.006 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:49.809Z,1509054769.809 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:50.596Z,1509054770.596 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:51.396Z,1509054771.396 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:52.208Z,1509054772.208 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:52.997Z,1509054772.997 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:53.795Z,1509054773.795 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:54.597Z,1509054774.597 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:55.419Z,1509054775.419 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:56.197Z,1509054776.197 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:56.610Z,1509054776.610 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:52:56.610Z,1509054776.610 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 54
2017-10-26T21:52:56.611Z,1509054776.611 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-26T21:52:56.612Z,1509054776.612 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:52:56.612Z,1509054776.612 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 54
2017-10-26T21:52:56.612Z,1509054776.612 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-26T21:52:56.625Z,1509054776.625 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-26T21:52:56.625Z,1509054776.625 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-26T21:52:56.999Z,1509054776.999 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:57.018Z,1509054777.018 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-26T21:52:57.018Z,1509054777.018 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 54
2017-10-26T21:52:57.019Z,1509054777.019 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-26T21:52:57.019Z,1509054777.019 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 54
2017-10-26T21:52:57.409Z,1509054777.409 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-26T21:52:57.410Z,1509054777.410 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:52:57.410Z,1509054777.410 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:52:57.410Z,1509054777.410 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-26T21:52:57.411Z,1509054777.411 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:52:57.411Z,1509054777.411 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:52:57.809Z,1509054777.809 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:57.816Z,1509054777.816 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-10-26T21:52:58.218Z,1509054778.218 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-10-26T21:52:58.614Z,1509054778.614 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:58.626Z,1509054778.626 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-10-26T21:52:59.014Z,1509054779.014 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-10-26T21:52:59.402Z,1509054779.402 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:52:59.411Z,1509054779.411 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-10-26T21:52:59.809Z,1509054779.809 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-10-26T21:53:00.203Z,1509054780.203 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:00.214Z,1509054780.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-10-26T21:53:00.609Z,1509054780.609 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-10-26T21:53:01.007Z,1509054781.007 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:01.015Z,1509054781.015 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-10-26T21:53:01.422Z,1509054781.422 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-10-26T21:53:01.810Z,1509054781.810 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:01.818Z,1509054781.818 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-10-26T21:53:02.213Z,1509054782.213 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-10-26T21:53:02.590Z,1509054782.591 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:02.614Z,1509054782.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-10-26T21:53:03.013Z,1509054783.013 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-10-26T21:53:03.390Z,1509054783.390 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:03.413Z,1509054783.413 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-10-26T21:53:03.822Z,1509054783.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-10-26T21:53:04.211Z,1509054784.211 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:04.219Z,1509054784.219 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-10-26T21:53:04.618Z,1509054784.618 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-10-26T21:53:04.990Z,1509054784.990 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:05.015Z,1509054785.015 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-10-26T21:53:05.412Z,1509054785.412 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2017-10-26T21:53:05.790Z,1509054785.790 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:05.814Z,1509054785.814 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2017-10-26T21:53:06.213Z,1509054786.213 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2017-10-26T21:53:06.590Z,1509054786.590 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:06.614Z,1509054786.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2017-10-26T21:53:07.021Z,1509054787.021 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2017-10-26T21:53:07.411Z,1509054787.411 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:07.419Z,1509054787.419 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s.
2017-10-26T21:53:07.821Z,1509054787.821 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s.
2017-10-26T21:53:08.194Z,1509054788.194 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:08.214Z,1509054788.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2017-10-26T21:53:08.614Z,1509054788.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s.
2017-10-26T21:53:08.995Z,1509054788.995 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:09.014Z,1509054789.014 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s.
2017-10-26T21:53:09.414Z,1509054789.414 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s.
2017-10-26T21:53:09.811Z,1509054789.811 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:09.819Z,1509054789.819 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s.
2017-10-26T21:53:10.222Z,1509054790.222 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2017-10-26T21:53:10.607Z,1509054790.607 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:10.622Z,1509054790.622 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s.
2017-10-26T21:53:11.023Z,1509054791.023 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s.
2017-10-26T21:53:11.391Z,1509054791.391 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:11.414Z,1509054791.414 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s.
2017-10-26T21:53:11.813Z,1509054791.813 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s.
2017-10-26T21:53:12.191Z,1509054792.191 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:12.207Z,1509054792.207 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2017-10-26T21:53:12.618Z,1509054792.618 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s.
2017-10-26T21:53:13.010Z,1509054793.010 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:13.018Z,1509054793.018 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s.
2017-10-26T21:53:13.422Z,1509054793.422 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s.
2017-10-26T21:53:13.815Z,1509054793.815 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:13.822Z,1509054793.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2017-10-26T21:53:14.218Z,1509054794.218 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s.
2017-10-26T21:53:14.590Z,1509054794.590 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:14.598Z,1509054794.598 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s.
2017-10-26T21:53:15.018Z,1509054795.018 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s.
2017-10-26T21:53:15.391Z,1509054795.391 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:15.418Z,1509054795.418 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s.
2017-10-26T21:53:15.822Z,1509054795.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s.
2017-10-26T21:53:16.214Z,1509054796.214 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:16.222Z,1509054796.222 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2017-10-26T21:53:16.991Z,1509054796.991 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:17.790Z,1509054797.790 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:18.599Z,1509054798.599 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:19.409Z,1509054799.409 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:20.198Z,1509054800.198 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:20.994Z,1509054800.994 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:21.813Z,1509054801.813 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:22.609Z,1509054802.609 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:23.396Z,1509054803.396 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:24.198Z,1509054804.198 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:25.001Z,1509054805.001 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:25.805Z,1509054805.805 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:26.596Z,1509054806.596 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:27.399Z,1509054807.399 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:28.205Z,1509054808.205 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:28.997Z,1509054808.997 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:29.249Z,1509054809.249 [CommandLine](IMPORTANT): got command show variable ESPComm
2017-10-26T21:53:29.797Z,1509054809.797 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:30.596Z,1509054810.596 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:31.405Z,1509054811.405 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:32.195Z,1509054812.195 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:32.997Z,1509054812.997 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:33.805Z,1509054813.805 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:34.602Z,1509054814.602 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:35.396Z,1509054815.396 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:36.198Z,1509054816.198 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:37.010Z,1509054817.010 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:40.545Z,1509054820.545 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:41.010Z,1509054821.010 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:41.813Z,1509054821.813 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:42.607Z,1509054822.607 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:43.416Z,1509054823.416 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:44.213Z,1509054824.213 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:45.008Z,1509054825.008 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:45.821Z,1509054825.821 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:46.622Z,1509054826.622 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:47.402Z,1509054827.402 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:48.213Z,1509054828.213 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:49.022Z,1509054829.022 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:49.819Z,1509054829.819 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:50.602Z,1509054830.602 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:51.402Z,1509054831.402 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:52.227Z,1509054832.227 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:53.002Z,1509054833.002 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:53.807Z,1509054833.807 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:54.602Z,1509054834.602 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:55.417Z,1509054835.417 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:56.210Z,1509054836.210 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:57.011Z,1509054837.011 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:57.817Z,1509054837.817 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:58.617Z,1509054838.617 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:53:59.406Z,1509054839.406 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:00.210Z,1509054840.210 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:01.017Z,1509054841.017 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:01.062Z,1509054841.062 [CBIT](DEBUG): EFC running - data check-sum false
2017-10-26T21:54:01.821Z,1509054841.821 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:02.606Z,1509054842.606 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:03.408Z,1509054843.408 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:04.217Z,1509054844.217 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:05.012Z,1509054845.012 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:05.582Z,1509054845.582 [CommandLine](IMPORTANT): got command stop
2017-10-26T21:54:05.582Z,1509054845.582 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop
2017-10-26T21:54:05.810Z,1509054845.810 [ESPComponent](DEBUG): Error in ESPComm::open: cannot open socket port
2017-10-26T21:54:05.824Z,1509054845.824 [MissionManager](INFO): MissionManager is completed.
2017-10-26T21:54:05.824Z,1509054845.824 [MissionManager](INFO): Uninitializing Mission sample
2017-10-26T21:54:05.824Z,1509054845.824 [sample] Stopped
2017-10-26T21:54:05.824Z,1509054845.824 [sample](DEBUG): Aggregate::uninitialize sample
2017-10-26T21:54:05.824Z,1509054845.824 [sample:A.Pitch] Stopped
2017-10-26T21:54:05.824Z,1509054845.824 [sample:B.SetSpeed] Stopped
2017-10-26T21:54:05.824Z,1509054845.824 [sample:B.SetSpeed](DEBUG): Uninitialize.
2017-10-26T21:54:05.824Z,1509054845.824 [sample:SampleAtDepth] Stopped
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleAtDepth](DEBUG): Aggregate::uninitialize sample:SampleAtDepth
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleAtDepth:B.Pitch] Stopped
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleAtDepth:SampleWrapper] Stopped
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleAtDepth:SampleWrapper](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleAtDepth:SampleWrapper:SampleESP] Stopped
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleAtDepth:SampleWrapper:SampleESP](DEBUG): Aggregate::uninitialize sample:SampleAtDepth:SampleWrapper:SampleESP
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleAtDepth:SampleWrapper:SampleESP:TriggerESP] Stopped
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleRepeater] Stopped
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleRepeater](DEBUG): Aggregate::uninitialize sample:SampleRepeater
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleRepeater:Sample] Stopped
2017-10-26T21:54:05.825Z,1509054845.825 [sample:SampleRepeater:Sample](DEBUG): Aggregate::uninitialize sample:SampleRepeater:Sample
2017-10-26T21:54:06.244Z,1509054846.244 [MissionManager](IMPORTANT): Started mission Default
2017-10-26T21:54:06.244Z,1509054846.244 [Default] Running Loop=1
2017-10-26T21:54:06.245Z,1509054846.245 [Default](DEBUG): Aggregate::initialize Default
2017-10-26T21:54:06.245Z,1509054846.245 [Default:B.GoToSurface] Running Loop=1
2017-10-26T21:54:06.245Z,1509054846.245 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2017-10-26T21:54:06.245Z,1509054846.245 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2017-10-26T21:54:06.245Z,1509054846.245 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2017-10-26T21:54:06.246Z,1509054846.246 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2017-10-26T21:54:06.246Z,1509054846.246 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2017-10-26T21:54:06.246Z,1509054846.246 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2017-10-26T21:54:06.247Z,1509054846.247 [Default:A.Wait] Running Loop=1
2017-10-26T21:54:06.247Z,1509054846.247 [Default:A.Wait](DEBUG): Initialize Wait Component.
2017-10-26T21:54:06.607Z,1509054846.607 [ESPComponent](INFO): powering down ESP
2017-10-26T21:54:09.777Z,1509054849.777 [NAL9602](FAULT): GPS failed to acquire within timeout.
2017-10-26T21:54:09.777Z,1509054849.777 [NAL9602] Data Fault, FailCount= 5
2017-10-26T21:54:09.777Z,1509054849.777 [NAL9602](ERROR): Data Fault
2017-10-26T21:54:09.882Z,1509054849.882 [CBIT](ERROR): Data Fault in component: NAL9602
2017-10-26T21:54:09.882Z,1509054849.882 [CBIT](CRITICAL): Data Fault in component: NAL9602
2017-10-26T21:54:10.177Z,1509054850.177 [NAL9602](INFO): Powering down
2017-10-26T21:54:10.254Z,1509054850.254 [CommandLine](FAULT): Scheduling is paused
2017-10-26T21:54:10.254Z,1509054850.254 [CBIT](INFO): Critical error at 20171026T215409
2017-10-26T21:54:19.416Z,1509054859.416 [Default:A.Wait](INFO): Done Waiting.
2017-10-26T21:54:19.416Z,1509054859.416 [Default:A.Wait] Stopped
2017-10-26T21:54:19.416Z,1509054859.416 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2017-10-26T21:54:19.821Z,1509054859.821 [Default:CheckIn] Running Loop=1
2017-10-26T21:54:19.821Z,1509054859.821 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2017-10-26T21:54:19.821Z,1509054859.821 [Default:CheckIn:Read_GPS] Running Loop=1
2017-10-26T21:55:57.747Z,1509054957.747 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:55:57.747Z,1509054957.747 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 55
2017-10-26T21:55:57.747Z,1509054957.747 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-26T21:55:57.749Z,1509054957.749 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:55:57.749Z,1509054957.749 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 55
2017-10-26T21:55:57.749Z,1509054957.749 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-26T21:55:57.761Z,1509054957.761 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-26T21:55:57.761Z,1509054957.761 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-26T21:55:58.164Z,1509054958.164 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-26T21:55:58.164Z,1509054958.164 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 55
2017-10-26T21:55:58.165Z,1509054958.165 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-26T21:55:58.165Z,1509054958.165 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 55
2017-10-26T21:55:58.557Z,1509054958.557 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-26T21:55:58.558Z,1509054958.558 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:55:58.558Z,1509054958.558 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:55:58.558Z,1509054958.558 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-26T21:55:58.559Z,1509054958.559 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:55:58.559Z,1509054958.559 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:55:58.951Z,1509054958.951 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-10-26T21:55:59.354Z,1509054959.354 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-10-26T21:55:59.750Z,1509054959.750 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-10-26T21:56:00.153Z,1509054960.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-10-26T21:56:00.554Z,1509054960.554 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-10-26T21:56:00.951Z,1509054960.951 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-10-26T21:56:01.351Z,1509054961.351 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-10-26T21:56:01.754Z,1509054961.754 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-10-26T21:56:02.154Z,1509054962.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-10-26T21:56:02.551Z,1509054962.551 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-10-26T21:56:02.954Z,1509054962.954 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-10-26T21:56:03.354Z,1509054963.354 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-10-26T21:56:03.751Z,1509054963.751 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-10-26T21:56:04.154Z,1509054964.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-10-26T21:56:04.551Z,1509054964.551 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-10-26T21:56:04.951Z,1509054964.951 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-10-26T21:56:05.354Z,1509054965.354 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-10-26T21:56:05.752Z,1509054965.752 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-10-26T21:56:06.152Z,1509054966.152 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-10-26T21:56:06.562Z,1509054966.562 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2017-10-26T21:56:06.952Z,1509054966.952 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2017-10-26T21:56:07.352Z,1509054967.352 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2017-10-26T21:56:07.762Z,1509054967.762 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2017-10-26T21:56:08.158Z,1509054968.158 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2017-10-26T21:56:08.552Z,1509054968.552 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s.
2017-10-26T21:56:08.966Z,1509054968.966 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s.
2017-10-26T21:56:09.350Z,1509054969.350 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2017-10-26T21:56:09.750Z,1509054969.750 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s.
2017-10-26T21:56:10.157Z,1509054970.157 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s.
2017-10-26T21:56:10.170Z,1509054970.170 [CBIT](INFO): Clearing failed state for component NAL9602
2017-10-26T21:56:10.170Z,1509054970.170 [NAL9602] No Fault, FailCount= 5
2017-10-26T21:56:10.513Z,1509054970.513 [NAL9602](INFO): Powering up NAL9602
2017-10-26T21:56:10.562Z,1509054970.562 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s.
2017-10-26T21:56:10.951Z,1509054970.951 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s.
2017-10-26T21:56:11.363Z,1509054971.363 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2017-10-26T21:56:11.758Z,1509054971.758 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s.
2017-10-26T21:56:12.158Z,1509054972.158 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s.
2017-10-26T21:56:12.554Z,1509054972.554 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s.
2017-10-26T21:56:12.954Z,1509054972.954 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s.
2017-10-26T21:56:13.350Z,1509054973.350 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2017-10-26T21:56:13.754Z,1509054973.754 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s.
2017-10-26T21:56:14.158Z,1509054974.158 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s.
2017-10-26T21:56:14.558Z,1509054974.558 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s.
2017-10-26T21:56:14.954Z,1509054974.954 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2017-10-26T21:56:15.354Z,1509054975.354 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s.
2017-10-26T21:56:15.751Z,1509054975.751 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s.
2017-10-26T21:56:16.154Z,1509054976.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s.
2017-10-26T21:56:16.558Z,1509054976.558 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s.
2017-10-26T21:56:16.958Z,1509054976.958 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s.
2017-10-26T21:56:17.354Z,1509054977.354 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2017-10-26T21:56:21.713Z,1509054981.713 [NAL9602](INFO): NAL9602 initialized
2017-10-26T21:57:44.456Z,1509055064.456 [PNI_TCM](ERROR): CRC does not match. Expected:0x43037 got:0x17069
2017-10-26T21:57:44.853Z,1509055064.853 [PNI_TCM](ERROR): CRC does not match. Expected:0x30196 got:0x17928
2017-10-26T21:57:52.464Z,1509055072.464 [PNI_TCM](ERROR): CRC does not match. Expected:0x23280 got:0x15133
2017-10-26T21:57:55.666Z,1509055075.666 [PNI_TCM](ERROR): CRC does not match. Expected:0x30094 got:0x16796
2017-10-26T21:57:58.862Z,1509055078.862 [PNI_TCM](ERROR): CRC does not match. Expected:0x5896 got:0x25495
2017-10-26T21:58:02.062Z,1509055082.062 [PNI_TCM](ERROR): CRC does not match. Expected:0x53647 got:0x28703
2017-10-26T21:58:05.251Z,1509055085.251 [PNI_TCM](ERROR): CRC does not match. Expected:0x5989 got:0x6210
2017-10-26T21:58:05.653Z,1509055085.653 [PNI_TCM](ERROR): CRC does not match. Expected:0x17805 got:0x54297
2017-10-26T21:58:08.455Z,1509055088.455 [PNI_TCM](ERROR): CRC does not match. Expected:0x8298 got:0x17069
2017-10-26T21:58:08.852Z,1509055088.852 [PNI_TCM](ERROR): CRC does not match. Expected:0x23396 got:0x1053
2017-10-26T21:58:16.464Z,1509055096.464 [PNI_TCM](ERROR): CRC does not match. Expected:0x32263 got:0x7617
2017-10-26T21:58:19.668Z,1509055099.668 [PNI_TCM](ERROR): CRC does not match. Expected:0x20914 got:0x63818
2017-10-26T21:58:22.862Z,1509055102.862 [PNI_TCM](ERROR): CRC does not match. Expected:0x18299 got:0x39965
2017-10-26T21:58:26.060Z,1509055106.060 [PNI_TCM](ERROR): CRC does not match. Expected:0x2391 got:0x36722
2017-10-26T21:58:29.257Z,1509055109.257 [PNI_TCM](ERROR): CRC does not match. Expected:0x48771 got:0x1287
2017-10-26T21:58:29.652Z,1509055109.652 [PNI_TCM](ERROR): CRC does not match. Expected:0x20208 got:0x77
2017-10-26T21:58:32.455Z,1509055112.455 [PNI_TCM](ERROR): CRC does not match. Expected:0x12500 got:0x15896
2017-10-26T21:58:32.859Z,1509055112.859 [PNI_TCM](ERROR): CRC does not match. Expected:0x11687 got:0x49525
2017-10-26T21:58:35.658Z,1509055115.658 [PNI_TCM](ERROR): CRC does not match. Expected:0x13764 got:0x10501
2017-10-26T21:58:58.811Z,1509055138.811 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:58:58.812Z,1509055138.812 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 56
2017-10-26T21:58:58.812Z,1509055138.812 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-26T21:58:58.813Z,1509055138.813 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T21:58:58.813Z,1509055138.813 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 56
2017-10-26T21:58:58.813Z,1509055138.813 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-26T21:58:58.826Z,1509055138.826 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-26T21:58:58.827Z,1509055138.827 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-26T21:58:59.225Z,1509055139.225 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-26T21:58:59.225Z,1509055139.225 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 56
2017-10-26T21:58:59.226Z,1509055139.226 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-26T21:58:59.226Z,1509055139.226 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 56
2017-10-26T21:58:59.614Z,1509055139.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-26T21:58:59.614Z,1509055139.614 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:58:59.615Z,1509055139.615 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:58:59.615Z,1509055139.615 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-26T21:58:59.615Z,1509055139.615 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T21:58:59.616Z,1509055139.616 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T21:59:00.016Z,1509055140.016 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s.
2017-10-26T21:59:00.426Z,1509055140.426 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s.
2017-10-26T21:59:00.826Z,1509055140.826 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s.
2017-10-26T21:59:01.207Z,1509055141.207 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s.
2017-10-26T21:59:01.610Z,1509055141.610 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s.
2017-10-26T21:59:02.008Z,1509055142.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s.
2017-10-26T21:59:02.408Z,1509055142.408 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s.
2017-10-26T21:59:02.814Z,1509055142.814 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s.
2017-10-26T21:59:03.221Z,1509055143.221 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s.
2017-10-26T21:59:03.620Z,1509055143.620 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s.
2017-10-26T21:59:04.022Z,1509055144.022 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-10-26T21:59:04.416Z,1509055144.416 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-10-26T21:59:04.807Z,1509055144.807 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-10-26T21:59:05.214Z,1509055145.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-10-26T21:59:05.614Z,1509055145.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s.
2017-10-26T21:59:06.017Z,1509055146.017 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s.
2017-10-26T21:59:06.426Z,1509055146.426 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s.
2017-10-26T21:59:06.824Z,1509055146.824 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s.
2017-10-26T21:59:07.208Z,1509055147.208 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s.
2017-10-26T21:59:07.614Z,1509055147.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s.
2017-10-26T21:59:08.017Z,1509055148.017 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s.
2017-10-26T21:59:08.409Z,1509055148.409 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s.
2017-10-26T21:59:08.814Z,1509055148.814 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s.
2017-10-26T21:59:09.223Z,1509055149.223 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s.
2017-10-26T21:59:09.622Z,1509055149.622 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s.
2017-10-26T21:59:10.022Z,1509055150.022 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s.
2017-10-26T21:59:10.420Z,1509055150.420 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s.
2017-10-26T21:59:10.809Z,1509055150.809 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s.
2017-10-26T21:59:11.215Z,1509055151.215 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s.
2017-10-26T21:59:11.617Z,1509055151.617 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s.
2017-10-26T21:59:12.021Z,1509055152.021 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s.
2017-10-26T21:59:12.421Z,1509055152.421 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2017-10-26T21:59:12.826Z,1509055152.826 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s.
2017-10-26T21:59:13.208Z,1509055153.208 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s.
2017-10-26T21:59:13.611Z,1509055153.611 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s.
2017-10-26T21:59:14.016Z,1509055154.016 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s.
2017-10-26T21:59:14.408Z,1509055154.408 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s.
2017-10-26T21:59:14.814Z,1509055154.814 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s.
2017-10-26T21:59:15.222Z,1509055155.222 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s.
2017-10-26T21:59:15.620Z,1509055155.620 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s.
2017-10-26T21:59:16.022Z,1509055156.022 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s.
2017-10-26T21:59:16.409Z,1509055156.409 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s.
2017-10-26T21:59:16.814Z,1509055156.814 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s.
2017-10-26T21:59:17.214Z,1509055157.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s.
2017-10-26T21:59:17.609Z,1509055157.609 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s.
2017-10-26T21:59:18.020Z,1509055158.020 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s.
2017-10-26T21:59:18.426Z,1509055158.426 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s.
2017-10-26T21:59:20.012Z,1509055160.012 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-10-26T21:54:19.8Z
2017-10-26T21:59:20.012Z,1509055160.012 [Default:CheckIn:Read_GPS] Stopped
2017-10-26T21:59:20.012Z,1509055160.012 [Default:CheckIn:Read_Iridium] Running Loop=1
2017-10-26T21:59:24.374Z,1509055164.374 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20171025T080149/Courier0004.lzma
2017-10-26T21:59:25.153Z,1509055165.153 [DataOverHttps](INFO): Moved sent file to Logs/20171025T080149/Courier0004.lzma.bak
2017-10-26T21:59:25.153Z,1509055165.153 [DataOverHttps](INFO): SBD MOMSN=5165317
2017-10-26T21:59:33.851Z,1509055173.851 [DataOverHttps](INFO): Sending 399 bytes from file Logs/20171025T080149/Courier0008.lzma
2017-10-26T21:59:34.656Z,1509055174.656 [DataOverHttps](INFO): Moved sent file to Logs/20171025T080149/Courier0008.lzma.bak
2017-10-26T21:59:34.656Z,1509055174.656 [DataOverHttps](INFO): SBD MOMSN=5165320
2017-10-26T21:59:43.364Z,1509055183.364 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20171025T080149/Courier0012.lzma
2017-10-26T21:59:44.176Z,1509055184.176 [DataOverHttps](INFO): Moved sent file to Logs/20171025T080149/Courier0012.lzma.bak
2017-10-26T21:59:44.176Z,1509055184.176 [DataOverHttps](INFO): SBD MOMSN=5165366
2017-10-26T21:59:52.867Z,1509055192.867 [DataOverHttps](INFO): Sending 353 bytes from file Logs/20171025T080149/Courier0016.lzma
2017-10-26T21:59:53.675Z,1509055193.675 [DataOverHttps](INFO): Moved sent file to Logs/20171025T080149/Courier0016.lzma.bak
2017-10-26T21:59:53.675Z,1509055193.675 [DataOverHttps](INFO): SBD MOMSN=5165411
2017-10-26T22:00:02.618Z,1509055202.618 [DataOverHttps](INFO): Sending 341 bytes from file Logs/20171025T080149/Courier0020.lzma
2017-10-26T22:00:03.424Z,1509055203.424 [DataOverHttps](INFO): Moved sent file to Logs/20171025T080149/Courier0020.lzma.bak
2017-10-26T22:00:03.425Z,1509055203.425 [DataOverHttps](INFO): SBD MOMSN=5165456
2017-10-26T22:00:14.106Z,1509055214.106 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171025T080149/Courier0024.lzma
2017-10-26T22:00:14.920Z,1509055214.920 [DataOverHttps](INFO): Moved sent file to Logs/20171025T080149/Courier0024.lzma.bak
2017-10-26T22:00:14.920Z,1509055214.920 [DataOverHttps](INFO): SBD MOMSN=5165501
2017-10-26T22:00:23.928Z,1509055223.928 [DataOverHttps](INFO): Sending 106 bytes from file Logs/20171025T175616/Courier0000.lzma
2017-10-26T22:00:24.733Z,1509055224.733 [DataOverHttps](INFO): Moved sent file to Logs/20171025T175616/Courier0000.lzma.bak
2017-10-26T22:00:24.733Z,1509055224.733 [DataOverHttps](INFO): SBD MOMSN=5165503
2017-10-26T22:00:33.434Z,1509055233.434 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20171025T175616/Courier0004.lzma
2017-10-26T22:00:34.243Z,1509055234.243 [DataOverHttps](INFO): Moved sent file to Logs/20171025T175616/Courier0004.lzma.bak
2017-10-26T22:00:34.243Z,1509055234.243 [DataOverHttps](INFO): SBD MOMSN=5165508
2017-10-26T22:00:42.918Z,1509055242.918 [DataOverHttps](INFO): Sending 92 bytes from file Logs/20171025T175959/Courier0000.lzma
2017-10-26T22:00:43.724Z,1509055243.724 [DataOverHttps](INFO): Moved sent file to Logs/20171025T175959/Courier0000.lzma.bak
2017-10-26T22:00:43.725Z,1509055243.725 [DataOverHttps](INFO): SBD MOMSN=5165510
2017-10-26T22:00:52.423Z,1509055252.423 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20171025T175959/Courier0004.lzma
2017-10-26T22:00:53.232Z,1509055253.232 [DataOverHttps](INFO): Moved sent file to Logs/20171025T175959/Courier0004.lzma.bak
2017-10-26T22:00:53.232Z,1509055253.232 [DataOverHttps](INFO): SBD MOMSN=5165514
2017-10-26T22:01:01.941Z,1509055261.941 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20171025T175959/Courier0008.lzma
2017-10-26T22:01:02.748Z,1509055262.748 [DataOverHttps](INFO): Moved sent file to Logs/20171025T175959/Courier0008.lzma.bak
2017-10-26T22:01:02.748Z,1509055262.748 [DataOverHttps](INFO): SBD MOMSN=5165517
2017-10-26T22:01:11.446Z,1509055271.446 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20171025T195206/Courier0000.lzma
2017-10-26T22:01:12.252Z,1509055272.252 [DataOverHttps](INFO): Moved sent file to Logs/20171025T195206/Courier0000.lzma.bak
2017-10-26T22:01:12.252Z,1509055272.252 [DataOverHttps](INFO): SBD MOMSN=5165538
2017-10-26T22:01:21.388Z,1509055281.388 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20171025T195357/Courier0004.lzma
2017-10-26T22:01:22.192Z,1509055282.192 [DataOverHttps](INFO): Moved sent file to Logs/20171025T195357/Courier0004.lzma.bak
2017-10-26T22:01:22.192Z,1509055282.192 [DataOverHttps](INFO): SBD MOMSN=5165541
2017-10-26T22:01:30.880Z,1509055290.880 [DataOverHttps](INFO): Sending 165 bytes from file Logs/20171025T195357/Courier0008.lzma
2017-10-26T22:01:31.688Z,1509055291.688 [DataOverHttps](INFO): Moved sent file to Logs/20171025T195357/Courier0008.lzma.bak
2017-10-26T22:01:31.688Z,1509055291.688 [DataOverHttps](INFO): SBD MOMSN=5165544
2017-10-26T22:01:40.391Z,1509055300.391 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20171025T195357/Courier0012.lzma
2017-10-26T22:01:41.198Z,1509055301.198 [DataOverHttps](INFO): Moved sent file to Logs/20171025T195357/Courier0012.lzma.bak
2017-10-26T22:01:41.198Z,1509055301.198 [DataOverHttps](INFO): SBD MOMSN=5165548
2017-10-26T22:01:49.904Z,1509055309.904 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20171025T195357/Courier0016.lzma
2017-10-26T22:01:50.713Z,1509055310.713 [DataOverHttps](INFO): Moved sent file to Logs/20171025T195357/Courier0016.lzma.bak
2017-10-26T22:01:50.713Z,1509055310.713 [DataOverHttps](INFO): SBD MOMSN=5165551
2017-10-26T22:01:59.417Z,1509055319.417 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20171025T220325/Courier0004.lzma
2017-10-26T22:01:59.974Z,1509055319.974 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T22:01:59.974Z,1509055319.974 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 57
2017-10-26T22:01:59.974Z,1509055319.974 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-26T22:01:59.985Z,1509055319.985 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T22:01:59.985Z,1509055319.985 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 57
2017-10-26T22:01:59.987Z,1509055319.987 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-26T22:02:00.092Z,1509055320.092 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-26T22:02:00.092Z,1509055320.092 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-26T22:02:00.247Z,1509055320.247 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0004.lzma.bak
2017-10-26T22:02:00.247Z,1509055320.247 [DataOverHttps](INFO): SBD MOMSN=5165553
2017-10-26T22:02:00.335Z,1509055320.335 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-26T22:02:00.335Z,1509055320.335 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 57
2017-10-26T22:02:00.336Z,1509055320.336 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-26T22:02:00.336Z,1509055320.336 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 57
2017-10-26T22:02:00.750Z,1509055320.750 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-26T22:02:00.750Z,1509055320.750 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T22:02:00.750Z,1509055320.750 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T22:02:00.751Z,1509055320.751 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-26T22:02:00.751Z,1509055320.751 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T22:02:00.752Z,1509055320.752 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T22:02:01.054Z,1509055321.054 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.1 s old, using for 20.0 s.
2017-10-26T22:02:04.133Z,1509055324.133 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.2 s old, using for 20.0 s.
2017-10-26T22:02:04.278Z,1509055324.278 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.3 s old, using for 20.0 s.
2017-10-26T22:02:04.606Z,1509055324.606 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.6 s old, using for 20.0 s.
2017-10-26T22:02:05.009Z,1509055325.009 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.0 s old, using for 20.0 s.
2017-10-26T22:02:05.410Z,1509055325.410 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.4 s old, using for 20.0 s.
2017-10-26T22:02:05.802Z,1509055325.802 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.8 s old, using for 20.0 s.
2017-10-26T22:02:08.869Z,1509055328.869 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.9 s old, using for 20.0 s.
2017-10-26T22:02:08.929Z,1509055328.929 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20171025T220325/Courier0008.lzma
2017-10-26T22:02:09.001Z,1509055329.001 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.0 s old, using for 20.0 s.
2017-10-26T22:02:09.351Z,1509055329.351 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.4 s old, using for 20.0 s.
2017-10-26T22:02:09.696Z,1509055329.696 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0008.lzma.bak
2017-10-26T22:02:09.696Z,1509055329.696 [DataOverHttps](INFO): SBD MOMSN=5165557
2017-10-26T22:02:09.781Z,1509055329.781 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.8 s old, using for 20.0 s.
2017-10-26T22:02:10.227Z,1509055330.227 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.3 s old, using for 20.0 s.
2017-10-26T22:02:10.531Z,1509055330.531 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.6 s old, using for 20.0 s.
2017-10-26T22:02:13.620Z,1509055333.620 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s.
2017-10-26T22:02:13.730Z,1509055333.730 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.8 s old, using for 20.0 s.
2017-10-26T22:02:14.100Z,1509055334.100 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.1 s old, using for 20.0 s.
2017-10-26T22:02:14.506Z,1509055334.506 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.5 s old, using for 20.0 s.
2017-10-26T22:02:14.906Z,1509055334.906 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.9 s old, using for 20.0 s.
2017-10-26T22:02:15.301Z,1509055335.301 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.3 s old, using for 20.0 s.
2017-10-26T22:02:18.360Z,1509055338.360 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s.
2017-10-26T22:02:18.383Z,1509055338.383 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20171025T220325/Courier0012.lzma
2017-10-26T22:02:18.473Z,1509055338.473 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.5 s old, using for 20.0 s.
2017-10-26T22:02:18.854Z,1509055338.854 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.9 s old, using for 20.0 s.
2017-10-26T22:02:19.189Z,1509055339.189 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0012.lzma.bak
2017-10-26T22:02:19.189Z,1509055339.189 [DataOverHttps](INFO): SBD MOMSN=5165563
2017-10-26T22:02:19.254Z,1509055339.254 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.3 s old, using for 20.0 s.
2017-10-26T22:02:19.722Z,1509055339.722 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.7 s old, using for 20.0 s.
2017-10-26T22:02:28.684Z,1509055348.684 [DataOverHttps](INFO): Sending 124 bytes from file Logs/20171025T220325/Courier0016.lzma
2017-10-26T22:02:29.489Z,1509055349.489 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0016.lzma.bak
2017-10-26T22:02:29.489Z,1509055349.489 [DataOverHttps](INFO): SBD MOMSN=5165568
2017-10-26T22:02:38.183Z,1509055358.183 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20171025T220325/Courier0020.lzma
2017-10-26T22:02:39.063Z,1509055359.063 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0020.lzma.bak
2017-10-26T22:02:39.063Z,1509055359.063 [DataOverHttps](INFO): SBD MOMSN=5165573
2017-10-26T22:02:47.686Z,1509055367.686 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20171025T220325/Courier0024.lzma
2017-10-26T22:02:48.464Z,1509055368.464 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0024.lzma.bak
2017-10-26T22:02:48.464Z,1509055368.464 [DataOverHttps](INFO): SBD MOMSN=5165579
2017-10-26T22:02:57.161Z,1509055377.161 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20171025T220325/Courier0028.lzma
2017-10-26T22:02:57.968Z,1509055377.968 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0028.lzma.bak
2017-10-26T22:02:57.969Z,1509055377.969 [DataOverHttps](INFO): SBD MOMSN=5165584
2017-10-26T22:03:06.651Z,1509055386.651 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20171025T220325/Courier0032.lzma
2017-10-26T22:03:07.457Z,1509055387.457 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0032.lzma.bak
2017-10-26T22:03:07.457Z,1509055387.457 [DataOverHttps](INFO): SBD MOMSN=5165590
2017-10-26T22:03:16.202Z,1509055396.202 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20171025T220325/Courier0036.lzma
2017-10-26T22:03:17.008Z,1509055397.008 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0036.lzma.bak
2017-10-26T22:03:17.008Z,1509055397.008 [DataOverHttps](INFO): SBD MOMSN=5165595
2017-10-26T22:03:25.709Z,1509055405.709 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20171025T220325/Courier0040.lzma
2017-10-26T22:03:26.516Z,1509055406.516 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0040.lzma.bak
2017-10-26T22:03:26.516Z,1509055406.516 [DataOverHttps](INFO): SBD MOMSN=5165600
2017-10-26T22:03:35.214Z,1509055415.214 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20171025T220325/Courier0044.lzma
2017-10-26T22:03:36.020Z,1509055416.020 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0044.lzma.bak
2017-10-26T22:03:36.021Z,1509055416.021 [DataOverHttps](INFO): SBD MOMSN=5165606
2017-10-26T22:03:45.258Z,1509055425.258 [DataOverHttps](INFO): Sending 69 bytes from file Logs/20171025T220325/Courier0048.lzma
2017-10-26T22:03:46.134Z,1509055426.134 [DataOverHttps](INFO): Moved sent file to Logs/20171025T220325/Courier0048.lzma.bak
2017-10-26T22:03:46.135Z,1509055426.135 [DataOverHttps](INFO): SBD MOMSN=5165611
2017-10-26T22:03:50.861Z,1509055430.861 [PNI_TCM](ERROR): CRC does not match. Expected:0x5643 got:0x36852
2017-10-26T22:03:54.761Z,1509055434.761 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20171026T214841/Courier0000.lzma
2017-10-26T22:03:55.568Z,1509055435.568 [DataOverHttps](INFO): Moved sent file to Logs/20171026T214841/Courier0000.lzma.bak
2017-10-26T22:03:55.568Z,1509055435.568 [DataOverHttps](INFO): SBD MOMSN=5165614
2017-10-26T22:04:01.174Z,1509055441.174 [CBIT](DEBUG): EFC running - data check-sum false
2017-10-26T22:04:04.274Z,1509055444.274 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20171026T214841/Courier0004.lzma
2017-10-26T22:04:05.084Z,1509055445.084 [DataOverHttps](INFO): Moved sent file to Logs/20171026T214841/Courier0004.lzma.bak
2017-10-26T22:04:05.085Z,1509055445.085 [DataOverHttps](INFO): SBD MOMSN=5165618
2017-10-26T22:04:13.770Z,1509055453.770 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20171025T005205/Express0001.lzma
2017-10-26T22:04:14.577Z,1509055454.577 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005205/Express0001.lzma.bak
2017-10-26T22:04:14.577Z,1509055454.577 [DataOverHttps](INFO): SBD MOMSN=5165620
2017-10-26T22:04:23.280Z,1509055463.280 [DataOverHttps](INFO): Sending 1144 bytes from file Logs/20171025T005524/Express0001.lzma
2017-10-26T22:04:24.084Z,1509055464.084 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005524/Express0001.lzma.bak
2017-10-26T22:04:24.085Z,1509055464.085 [DataOverHttps](INFO): SBD MOMSN=5165622
2017-10-26T22:04:32.797Z,1509055472.797 [DataOverHttps](INFO): Sending 519 bytes from file Logs/20171025T005524/Express0005.lzma
2017-10-26T22:04:33.597Z,1509055473.597 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005524/Express0005.lzma.bak
2017-10-26T22:04:33.597Z,1509055473.597 [DataOverHttps](INFO): SBD MOMSN=5165665
2017-10-26T22:04:42.305Z,1509055482.305 [DataOverHttps](INFO): Sending 3780 bytes from file Logs/20171025T005524/Express0009.lzma
2017-10-26T22:04:43.104Z,1509055483.104 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005524/Express0009.lzma.bak
2017-10-26T22:04:43.104Z,1509055483.104 [DataOverHttps](INFO): SBD MOMSN=5165692
2017-10-26T22:04:51.808Z,1509055491.808 [DataOverHttps](INFO): Sending 3692 bytes from file Logs/20171025T005524/Express0013.lzma
2017-10-26T22:04:52.582Z,1509055492.582 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005524/Express0013.lzma.bak
2017-10-26T22:04:52.582Z,1509055492.582 [DataOverHttps](INFO): SBD MOMSN=5166350
2017-10-26T22:05:01.697Z,1509055501.697 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T22:05:01.697Z,1509055501.697 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 58
2017-10-26T22:05:01.697Z,1509055501.697 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2017-10-26T22:05:01.699Z,1509055501.699 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2017-10-26T22:05:01.699Z,1509055501.699 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 58
2017-10-26T22:05:01.699Z,1509055501.699 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2017-10-26T22:05:01.711Z,1509055501.711 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2017-10-26T22:05:01.711Z,1509055501.711 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2017-10-26T22:05:01.726Z,1509055501.726 [DataOverHttps](INFO): Sending 3874 bytes from file Logs/20171025T005524/Express0017.lzma
2017-10-26T22:05:01.894Z,1509055501.894 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2017-10-26T22:05:01.894Z,1509055501.894 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 58
2017-10-26T22:05:01.894Z,1509055501.894 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2017-10-26T22:05:01.894Z,1509055501.894 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 58
2017-10-26T22:05:02.176Z,1509055502.176 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2017-10-26T22:05:02.177Z,1509055502.177 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T22:05:02.177Z,1509055502.177 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T22:05:02.177Z,1509055502.177 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2017-10-26T22:05:02.178Z,1509055502.178 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2017-10-26T22:05:02.178Z,1509055502.178 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2017-10-26T22:05:02.529Z,1509055502.529 [DataOverHttps](INFO): Moved sent file to Logs/20171025T005524/Express0017.lzma.bak
2017-10-26T22:05:02.529Z,1509055502.529 [DataOverHttps](INFO): SBD MOMSN=5166983
2017-10-26T22:05:02.609Z,1509055502.609 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.9 s old, using for 20.0 s.
2017-10-26T22:05:03.133Z,1509055503.133 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.4 s old, using for 20.0 s.
2017-10-26T22:05:03.364Z,1509055503.364 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.7 s old, using for 20.0 s.
2017-10-26T22:05:06.430Z,1509055506.430 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.7 s old, using for 20.0 s.
2017-10-26T22:05:06.557Z,1509055506.557 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s.
2017-10-26T22:05:06.932Z,1509055506.932 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s.
2017-10-26T22:05:07.342Z,1509055507.342 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s.
2017-10-26T22:05:07.740Z,1509055507.740 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s.
2017-10-26T22:05:08.127Z,1509055508.127 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s.
2017-10-26T22:05:13.401Z,1509055513.401 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.7 s old, using for 20.0 s.
2017-10-26T22:05:13.433Z,1509055513.433 [DataOverHttps](INFO): Sending 691 bytes from file Logs/20171025T005524/Express0021.lzma
2017-10-26T22:05:13.560Z,1509055513.560 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.9 s old, using for 20.0 s.
2017-10-26T22:05: