Updated by Carlos Rueda 2017-04-19

File snippet.markdown Modified

 [carueda@tethyssim lrauv-application]$ bin/LRAUV -r -x "run Maintenance/sample.xml"

```

+> Or:

+> ```

+> [carueda@tethyssim lrauv-application]$ bin/LRAUV -r -x "load Maintenance/sample.xml;set sample.Depth 1 centimeter;set sample.WaitBeforeSample 3 second;set > sample:SampleAtDepth.TargetDepth 1 centimeter;set sample:SampleAtDepth.SettleTime 3 second;run"

+> ```

 Wait until `[ESPComponent](IMPORTANT): Waiting for ESP to connect` shows up:

```

Updated by Carlos Rueda 2016-01-21

View revision

File snippet.markdown Modified

    ESPComponent.socketServerPort       = 9998 count;

    ESPComponent.debug                  = 1 bool;

    ESPComponent.poTimeout              = 30 second;

-   ESPComponent.connectTimeout         = 10 second;

```

 *Note*: port 9998 on tethyssim is where ESPComponent will listen and wait for the ESP to connect. (This port has been open so it is accessible from bufflehead.)

Updated by Carlos Rueda 2016-01-21

View revision

File snippet.markdown Modified

 Using `Missions/Maintenance/sample.xml` for this testing.

 Parameters that can be adjusted for testing convenience, for example `Depth = 1`, `NumberOfSamples = 2`.

+Here's my local relevant configuration, in `Config/sim/carueda/Science.cfg`:

+```

+   ESPComponent.loadAtStartup          = 1 bool;

+   ESPComponent.simulateHardware       = 0 bool;

+   ESPComponent.socketServerPort       = 9998 count;

+   ESPComponent.debug                  = 1 bool;

+   ESPComponent.poTimeout              = 30 second;

+   ESPComponent.connectTimeout         = 10 second;

+```

+*Note*: port 9998 on tethyssim is where ESPComponent will listen and wait for the ESP to connect. (This port has been open so it is accessible from bufflehead.)

 Here's an actual session:

Updated by Carlos Rueda 2016-01-21

View revision

File snippet.markdown Modified

 ### ESPComponent/ESP testing with simulators on bufflehead and tethyssim:

 **Note**: the config parameter `ESPComponent.simulateHardware` is false for these tests: the ESP simulator

-is still an external process and the ESPComponent interacts with it as if it were a real ESP.)

+is still an external process and the ESPComponent interacts with it as if it were a real ESP.

 ### On bufflehead

 Make sure the ESP simulator has enough "dry" cartridges. For this you can simply run `Cmd.slot All=>:dry`:

```

-  $ esp

-  -> Cmd.slot All=>:dry

-  {All => :dry}

-  -> Cmd.map

-  {1 => :dry,

-   2 => :dry,

-   3 => :dry,

-   4 => :dry,

-   5 => :dry}

-  -> exit       # Note: exit the ESP simulator for what follows.

+carueda@bufflehead:~/esp2$ esp

+@10:16:00.80PST21-Jan-16 <simreal> Copyright 2015 MBARI

+...

+@10:16:36.71 <simreal> -> Cmd.slot All=>:dry

+{All => :dry}

+@10:16:39.27 -> Cmd.map

+{1 => :dry,

+ 2 => :dry,

+ 3 => :dry,

+ 4 => :dry,

+ 5 => :dry}

+@10:16:41.42 -> exit            # Note: exit the ESP simulator for what follows.

+carueda@bufflehead:~/esp2$

```

 Then, in this bufflehead session, prepare the following command but do not launch it yet:

Updated by Carlos Rueda 2016-01-21

View revision

File snippet.markdown Modified

-### Testing with simulators on bufflehead and tethyssim:

+### ESPComponent/ESP testing with simulators on bufflehead and tethyssim:

-**Note**: the config parameter ESPComponent.simulateHardware is false for these tests: the ESP simulator

+**Note**: the config parameter `ESPComponent.simulateHardware` is false for these tests: the ESP simulator

 is still an external process and the ESPComponent interacts with it as if it were a real ESP.)

 ### On bufflehead

-Image of the ESP software ready to be exercised  (under carueda's home):

+Image of the ESP software ([esp3gcart branch](https://github.com/MBARI-ESP/ESP2Gscript/tree/esp3gcart)) ready to be exercised  (under carueda's home):

```

    $ cd esp2

    3 => :dry,

    4 => :dry,

    5 => :dry}

-  -> exit       # note, exit the ESP simulator herre for what follows.

+  -> exit       # Note: exit the ESP simulator for what follows.

```

 Then, in this bufflehead session, prepare the following command but do not launch it yet:

```

 This prepares the subsequent execution of the ESP system (see below) once the socket server

-is running on the (simulated) vehicle.

+is running on the simulated vehicle.

 ### On tethyssim:

 Using `Missions/Maintenance/sample.xml` for this testing.

-Parameters that can be adjusted for testing convenience, for example:

-- Depth = 1

-- NumberOfSamples = 2

+Parameters that can be adjusted for testing convenience, for example `Depth = 1`, `NumberOfSamples = 2`.

 Here's an actual session:

+### Run the mission:

+```

+[carueda@tethyssim lrauv-application]$ bin/LRAUV -r -x "run Maintenance/sample.xml"

+```

+Wait until `[ESPComponent](IMPORTANT): Waiting for ESP to connect` shows up:

```

 [carueda@tethyssim lrauv-application]$ bin/LRAUV -r -x "run Maintenance/sample.xml"

+Writer for level Courier will be LZMA encoded.

+Writer for level Express will be LZMA encoded.

+Writer for level Priority will not be LZMA encoded.

+Writer for level Normal will not be LZMA encoded.

+2016-01-21T17:53:09.283Z,1453398789.283 [SyncHandler](INFO): Protected caller Thread ID is 2640

+2016-01-21T17:53:09.284Z,1453398789.284 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2641

+2016-01-21T17:53:09.284Z,1453398789.284 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2642

+2016-01-21T17:53:09.284Z,1453398789.284 [logger ThreadHandler](INFO): Protected caller Thread ID is 2643

+2016-01-21T17:53:09.285Z,1453398789.285 [Supervisor](INFO): Looking for Config files in directory: Config/

+2016-01-21T17:53:09.285Z,1453398789.285 [Supervisor](INFO): Opening Config file at: Config/secure.cfg

+2016-01-21T17:53:09.292Z,1453398789.292 [Supervisor](INFO): Opening Config file at: Config/Science.cfg

+2016-01-21T17:53:09.303Z,1453398789.303 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg

+2016-01-21T17:53:09.317Z,1453398789.317 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg

+2016-01-21T17:53:09.330Z,1453398789.330 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg

+2016-01-21T17:53:09.339Z,1453398789.339 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg

+2016-01-21T17:53:09.346Z,1453398789.346 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg

+2016-01-21T17:53:09.358Z,1453398789.358 [Supervisor](INFO): Opening Config file at: Config/Control.cfg

+tethyssim>pppd: no process killed

+2016-01-21T17:53:09.369Z,1453398789.369 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg

+2016-01-21T17:53:09.376Z,1453398789.376 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg

+2016-01-21T17:53:09.384Z,1453398789.384 [Supervisor](INFO): Opening Config file at: Config/logger.cfg

+2016-01-21T17:53:09.392Z,1453398789.392 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg

+2016-01-21T17:53:09.401Z,1453398789.401 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg

+2016-01-21T17:53:09.407Z,1453398789.407 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg

+2016-01-21T17:53:09.420Z,1453398789.420 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg

+2016-01-21T17:53:09.428Z,1453398789.428 [Supervisor](INFO): Looking for Config files in directory: Config/tethyssim/

+2016-01-21T17:53:09.428Z,1453398789.428 [Supervisor](INFO): Opening Config file at: Config/tethyssim/Science.cfg

+t2016-01-21T17:53:09.435Z,1453398789.435 [Supervisor](INFO): Opening Config file at: Config/tethyssim/vehicle.cfg

+2016-01-21T17:53:09.442Z,1453398789.442 [Supervisor](INFO): Opening Config file at: Config/tethyssim/Navigation.cfg

+2016-01-21T17:53:09.449Z,1453398789.449 [Supervisor](INFO): Opening Config file at: Config/tethyssim/workSite.cfg

+2016-01-21T17:53:09.456Z,1453398789.456 [Supervisor](INFO): Opening Config file at: Config/tethyssim/Estimation.cfg

+2016-01-21T17:53:09.463Z,1453398789.463 [Supervisor](INFO): Opening Config file at: Config/tethyssim/BIT.cfg

+2016-01-21T17:53:09.470Z,1453398789.470 [Supervisor](INFO): Opening Config file at: Config/tethyssim/Sensor.cfg

+2016-01-21T17:53:09.479Z,1453398789.479 [Supervisor](INFO): Opening Config file at: Config/tethyssim/Derivation.cfg

+2016-01-21T17:53:09.486Z,1453398789.486 [Supervisor](INFO): Looking for Config files in directory: Config/tethyssim/carueda/

+2016-01-21T17:53:09.486Z,1453398789.486 [Supervisor](INFO): Looking for Config files in directory: Config/sim/

+2016-01-21T17:53:09.486Z,1453398789.486 [Supervisor](INFO): Opening Config file at: Config/sim/secure.cfg

+2016-01-21T17:53:09.493Z,1453398789.493 [Supervisor](INFO): Opening Config file at: Config/sim/Science.cfg

+2016-01-21T17:53:09.500Z,1453398789.500 [Supervisor](INFO): Opening Config file at: Config/sim/Simulator.cfg

+2016-01-21T17:53:09.506Z,1453398789.506 [Supervisor](INFO): Opening Config file at: Config/sim/vehicle.cfg

+2016-01-21T17:53:09.513Z,1453398789.513 [Supervisor](INFO): Opening Config file at: Config/sim/Servo.cfg

+2016-01-21T17:53:09.519Z,1453398789.519 [Supervisor](INFO): Opening Config file at: Config/sim/Sensor.cfg

+2016-01-21T17:53:09.526Z,1453398789.526 [Supervisor](INFO): Opening Config file at: Config/sim/Derivation.cfg

+2016-01-21T17:53:09.533Z,1453398789.533 [Supervisor](INFO): Looking for Config files in directory: Config/sim/carueda/

+2016-01-21T17:53:09.533Z,1453398789.533 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/secure.cfg

+2016-01-21T17:53:09.540Z,1453398789.540 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/Science.cfg

+2016-01-21T17:53:09.547Z,1453398789.547 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/vehicle.cfg

+2016-01-21T17:53:09.554Z,1453398789.554 [Supervisor](INFO): Opening Config file at: Config/sim/carueda/Sensor.cfg

+2016-01-21T17:53:09.561Z,1453398789.561 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg

+2016-01-21T17:53:09.627Z,1453398789.627 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2746

+2016-01-21T17:53:09.628Z,1453398789.628 [ESPComponent](ERROR): Could not open device '/dev/loadB7' at ESPComponent.loadControl

+2016-01-21T17:53:09.630Z,1453398789.630 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2747

+2016-01-21T17:53:09.656Z,1453398789.656 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2748

+2016-01-21T17:53:09.672Z,1453398789.672 [StratificationFrontDetector](IMPORTANT): threshold set to: 0.999994 degC

+2016-01-21T17:53:09.672Z,1453398789.672 [StratificationFrontDetector](INFO): (re)initializing

+2016-01-21T17:53:09.676Z,1453398789.676 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2749

+2016-01-21T17:53:09.676Z,1453398789.676 [Supervisor](INFO): Main Thread ID is 2639

+2016-01-21T17:53:09.677Z,1453398789.677 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2750

+2016-01-21T17:53:09.677Z,1453398789.677 [logger ThreadHandler](INFO): Handler Thread ID is 2753

+2016-01-21T17:53:09.677Z,1453398789.677 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2752

+2016-01-21T17:53:09.677Z,1453398789.677 [controlThread ThreadHandler](INFO): Handler Thread ID is 2751

+2016-01-21T17:53:09.677Z,1453398789.677 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2754

+2016-01-21T17:53:09.678Z,1453398789.678 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2755

+2016-01-21T17:53:09.679Z,1453398789.679 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.

+2016-01-21T17:53:09.679Z,1453398789.679 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.

+2016-01-21T17:53:09.679Z,1453398789.679 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.

+2016-01-21T17:53:09.679Z,1453398789.679 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.

+2016-01-21T17:53:09.679Z,1453398789.679 [ExternalSim](INFO): ExternalSim initializing...

+2016-01-21T17:53:09.680Z,1453398789.680 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2756

+2016-01-21T17:53:09.680Z,1453398789.680 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2757

+2016-01-21T17:53:09.680Z,1453398789.680 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory

+2016-01-21T17:53:09.681Z,1453398789.681 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts

+2016-01-21T17:53:09.681Z,1453398789.681 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000

+2016-01-21T17:53:09.681Z,1453398789.681 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA61M.000

+2016-01-21T17:53:09.682Z,1453398789.682 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000

+2016-01-21T17:53:09.683Z,1453398789.683 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4CA60M.000

+2016-01-21T17:53:09.684Z,1453398789.684 [SBIT](INFO): Initialize SBIT Component.

+2016-01-21T17:53:09.684Z,1453398789.684 [SBIT](IMPORTANT): git: 2015-11-13-1-gd1d8b46

+2016-01-21T17:53:09.684Z,1453398789.684 [SBIT](INFO): git hash: d1d8b4686f3fcabed06ed710d9fb79cd14367320

+2016-01-21T17:53:09.684Z,1453398789.684 [SBIT](INFO): Kernel Reporting Different Release From Configuration.

+Kernel Expected: 2.6.32-504.3.3.el6.x86_64

+Kernel Reported: 2.6.32-573.7.1.el6.x86_64

+2016-01-21T17:53:09.684Z,1453398789.684 [SBIT](INFO): Kernel Reporting Different Version From Configuration.

+Kernel Expected: #1 SMP Wed Dec 17 01:55:02 UTC 2014

+Kernel Reported: #1 SMP Tue Sep 22 22:00:00 UTC 2015

+2016-01-21T17:53:09.684Z,1453398789.684 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.

+2016-01-21T17:53:09.684Z,1453398789.684 [IBIT](INFO): Initialize IBIT Component.

+2016-01-21T17:53:09.684Z,1453398789.684 [CBIT](INFO): Last reboot was NOT due to watchdog timer.

+2016-01-21T17:53:09.684Z,1453398789.684 [MissionManager](INFO): Loading Mission: Missions/Startup.xml

+2016-01-21T17:53:09.685Z,1453398789.685 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000

+2016-01-21T17:53:09.686Z,1453398789.686 [MissionManager](INFO): Loading Mission: Missions/Default.xml

+2016-01-21T17:53:09.686Z,1453398789.686 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000

+2016-01-21T17:53:09.687Z,1453398789.687 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min

+2016-01-21T17:53:09.687Z,1453398789.687 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA83M.000

+2016-01-21T17:53:09.688Z,1453398789.688 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000

+2016-01-21T17:53:09.692Z,1453398789.692 [ESPComponent](INFO): powering down ESP

+2016-01-21T17:53:09.713Z,1453398789.713 [DVL_micro](INFO): Initializing

+tethyssim>run Maintenance/sample.xml

+2016-01-21T17:53:09.778Z,1453398789.778 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/sample.xml

+2016-01-21T17:53:09.778Z,1453398789.778 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample.xml

+2016-01-21T17:53:09.779Z,1453398789.779 [MissionManager](INFO): DefineArg sample.MissionTimeout = 90.000000 min

+2016-01-21T17:53:09.779Z,1453398789.779 [MissionManager](INFO): DefineArg sample.Depth = 1.000000 m

+2016-01-21T17:53:09.779Z,1453398789.779 [MissionManager](INFO): DefineArg sample.NumberOfSamples = 2.000000 count

+2016-01-21T17:53:09.779Z,1453398789.779 [MissionManager](INFO): DefineArg sample.WaitBeforeSample = 1.000000 min

+2016-01-21T17:53:09.779Z,1453398789.779 [MissionManager](INFO): Inserting Stack: Missions/Insert/SampleAtDepth.xml

+2016-01-21T17:53:09.780Z,1453398789.780 [MissionManager](INFO): DefineArg sample:SampleAtDepth.TargetDepth = 5.000000 m

+2016-01-21T17:53:09.780Z,1453398789.780 [MissionManager](INFO): DefineArg sample:SampleAtDepth.SettleTime = 30.000000 s

+2016-01-21T17:53:09.781Z,1453398789.781 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseCANONSampler = 0.000000 bool

+2016-01-21T17:53:09.781Z,1453398789.781 [MissionManager](INFO): DefineArg sample:SampleAtDepth.UseESP = 1.000000 bool

+2016-01-21T17:53:09.781Z,1453398789.781 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTriggerTimeout = 1.000000 min

+2016-01-21T17:53:09.781Z,1453398789.781 [MissionManager](INFO): DefineArg sample:SampleAtDepth.ESPComponentTriggerTimeout = 3.000000 min

+2016-01-21T17:53:09.781Z,1453398789.781 [MissionManager](INFO): DefineArg sample:SampleAtDepth.CANONSamplerTimeout = 4.750000 min

+2016-01-21T17:53:09.781Z,1453398789.781 [MissionManager](INFO): DefineArg sample:SampleAtDepth.ESPComponentTimeout = 7.000000 min

+2016-01-21T17:53:09.783Z,1453398789.783 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/sample.xml

+2016-01-21T17:53:09.881Z,1453398789.881 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA83M.000

+2016-01-21T17:53:10.489Z,1453398790.489 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.000121

+2016-01-21T17:53:19.288Z,1453398799.288 [NAL9602](INFO): GPS fix at 20160121T175319: (36.806001, -121.823002)

+2016-01-21T17:53:20.488Z,1453398800.488 [NAL9602](INFO): No messages in MT queue

+2016-01-21T17:53:26.089Z,1453398806.089 [NAL9602](INFO): Powering down

+2016-01-21T17:53:30.089Z,1453398810.089 [SBIT](IMPORTANT): Beginning Startup BIT

+2016-01-21T17:54:24.089Z,1453398864.089 [SBIT](IMPORTANT): SBIT PASSED

+2016-01-21T17:54:24.489Z,1453398864.489 [MissionManager](IMPORTANT): Started mission Startup

+2016-01-21T17:54:25.289Z,1453398865.289 [NAL9602](INFO): Powering up

+2016-01-21T17:54:30.489Z,1453398870.489 [NAL9602](INFO): GPS fix at 20160121T175430: (36.806009, -121.823017)

+2016-01-21T17:54:31.689Z,1453398871.689 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20160121T174518/Courier0004.lzma

+2016-01-21T17:54:31.693Z,1453398871.693 [NAL9602](INFO): No messages in MT queue

+2016-01-21T17:54:32.088Z,1453398872.088 [DataOverHttps](INFO): Moved sent file to Logs/20160121T174518/Courier0004.lzma.bak

+2016-01-21T17:54:32.088Z,1453398872.088 [DataOverHttps](INFO): SBD MOMSN=3824975

+2016-01-21T17:54:34.088Z,1453398874.088 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20160121T175309/Courier0000.lzma

+2016-01-21T17:54:34.489Z,1453398874.489 [DataOverHttps](INFO): Moved sent file to Logs/20160121T175309/Courier0000.lzma.bak

+2016-01-21T17:54:34.489Z,1453398874.489 [DataOverHttps](INFO): SBD MOMSN=3824977

+2016-01-21T17:54:36.488Z,1453398876.488 [DataOverHttps](INFO): Sending 803 bytes from file Logs/20160121T174518/Express0005.lzma

+2016-01-21T17:54:36.888Z,1453398876.888 [DataOverHttps](INFO): Moved sent file to Logs/20160121T174518/Express0005.lzma.bak

+2016-01-21T17:54:36.888Z,1453398876.888 [DataOverHttps](INFO): SBD MOMSN=3824981

+2016-01-21T17:54:37.292Z,1453398877.292 [NAL9602](INFO): Powering down

+2016-01-21T17:54:38.888Z,1453398878.888 [DataOverHttps](INFO): Sending 689 bytes from file Logs/20160121T175309/Express0001.lzma

+2016-01-21T17:54:39.288Z,1453398879.288 [DataOverHttps](INFO): Moved sent file to Logs/20160121T175309/Express0001.lzma.bak

+2016-01-21T17:54:39.288Z,1453398879.288 [DataOverHttps](INFO): SBD MOMSN=3824998

+2016-01-21T17:54:39.693Z,1453398879.693 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms

+2016-01-21T17:54:39.693Z,1453398879.693 [Startup](INFO): Completed Startup

+2016-01-21T17:54:40.089Z,1453398880.089 [MissionManager](IMPORTANT): Started mission sample

+2016-01-21T17:54:40.890Z,1453398880.890 [sample:SampleAtDepth:A](INFO): Moving to 1.000000 m

+2016-01-21T17:58:58.490Z,1453399138.490 [sample:SampleAtDepth:C.Wait](INFO): Done Waiting.

+2016-01-21T17:59:00.488Z,1453399140.488 [ESPComponent](INFO): powering up ESP

+2016-01-21T17:59:00.488Z,1453399140.488 [ESPComponent](INFO): manually powering up ESP

+2016-01-21T17:59:00.488Z,1453399140.488 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyS1 linkname esp noauth local lock 115200 134.89.10.51:134.89.10.60 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 134.89.10.32 ms-dns 134.89.10.10

+tethyssim>! echo 1 > /dev/loadB7sh: /sbin/pppd: No such file or directory

+2016-01-21T17:59:00.492Z,1453399140.492 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)     <<<<-----

+tethyssim>! echo 1 > /dev/loadB7

+2016-01-21T17:59:00.506Z,1453399140.506 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB7

+tethyssim>sh: /dev/loadB7: Permission denied

+```

+Launch the ESP simulator on the bufflehead session:

+```

+carueda@bufflehead:~/esp2$ ESPclient=tethyssim:9998 ESPcmdPort=7777 esp

+@09:59:03.66PST21-Jan-16 <simreal> Copyright 2015 MBARI

+/home/carueda/esp2/auv/honu/configure.rb

+ESP 3G "honu" 5 cartridge prototype

+@09:59:03.82 ArS.stop

+ArS.configure ArSconfig

+Rod.stop

+Rod.configure RodConfig

+PV.stop

+PV.configure PVconfig

+SC.stop

+SC.configure SCconfig

+TV.stop

+@09:59:03.83 TV.configure TVconfig

+SP.stop

+SP.configure SPconfig

+All dwarves are running firmware version 3.74sim

+<closeIntake> Intake.close

+<closeExhaust> Exhaust.close

+@09:59:05.14 <simreal> Clients may connect on TCP port 7777

+Connecting to tethyssim:9998

+@09:59:05.28 <LRAUV> Session Begun

+```

+On tethyssim:

+```

+2016-01-21T17:59:05.688Z,1453399145.688 [ESPComponent](IMPORTANT): ESP has connected as client

+2016-01-21T17:59:06.489Z,1453399146.489 [ESPComponent](IMPORTANT): ESP sampling sequence starting (sample #1)  sampling state: S_WAITING_INITIAL_PROMPT

+2016-01-21T17:59:06.890Z,1453399146.890 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 1.633221 m in nan degC water with nan ug/l chlorophyll fluorescence.

+2016-01-21T17:59:07.688Z,1453399147.688 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_LOG

+2016-01-21T17:59:08.088Z,1453399148.088 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_STATUS

+2016-01-21T17:59:09.689Z,1453399149.689 [ESPComponent](IMPORTANT): ESP sampling state: S_LOADING_CARTRIDGE

+2016-01-21T17:59:29.288Z,1453399169.288 [ESPComponent](IMPORTANT): ESP sampling state: S_FILTERING

+2016-01-21T17:59:31.688Z,1453399171.688 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PAUSED

+2016-01-21T17:59:52.888Z,1453399192.888 [ESPComponent](IMPORTANT): ESP sampling state: S_PROCESSING

+2016-01-21T17:59:55.288Z,1453399195.288 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PROCESSED

+2016-01-21T18:00:48.888Z,1453399248.888 [ESPComponent](IMPORTANT): ESP sampling state: S_STOPPING

+2016-01-21T18:00:53.289Z,1453399253.289 [ESPComponent](IMPORTANT): ESP sampling sequence completed normally (sample #1)

+2016-01-21T18:00:53.290Z,1453399253.290 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP

+2016-01-21T18:00:53.291Z,1453399253.291 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper

+2016-01-21T18:00:53.291Z,1453399253.291 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth

+2016-01-21T18:00:53.689Z,1453399253.689 [ESPComponent](INFO): powering down ESP

+tethyssim>pppd: no process killed

+2016-01-21T18:00:53.717Z,1453399253.717 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample

+2016-01-21T18:00:53.717Z,1453399253.717 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater

+2016-01-21T18:00:53.717Z,1453399253.717 [sample:SampleRepeater](INFO): Running loop #2

+2016-01-21T18:00:54.091Z,1453399254.091 [sample:SampleAtDepth:A](INFO): Moving to 1.000000 m

+```

-2016-01-21T17:03:15.182Z,1453395795.182 [Supervisor](INFO): Main Thread ID is 1692

-2016-01-21T17:03:15.183Z,1453395795.183 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1814

-2016-01-21T17:03:15.183Z,1453395795.183 [logger ThreadHandler](INFO): Handler Thread ID is 1815

-2016-01-21T17:03:15.183Z,1453395795.183 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1812

-2016-01-21T17:03:15.183Z,1453395795.183 [controlThread ThreadHandler](INFO): Handler Thread ID is 1813

-2016-01-21T17:03:15.183Z,1453395795.183 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1817

-2016-01-21T17:03:15.183Z,1453395795.183 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1818

-2016-01-21T17:03:15.183Z,1453395795.183 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.

-2016-01-21T17:03:15.183Z,1453395795.183 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.

-2016-01-21T17:03:15.183Z,1453395795.183 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.

-2016-01-21T17:03:15.183Z,1453395795.183 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.

-2016-01-21T17:03:15.183Z,1453395795.183 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1820

-2016-01-21T17:03:15.183Z,1453395795.183 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory

-2016-01-21T17:03:15.184Z,1453395795.184 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources/ElectronicNavigationCharts

-2016-01-21T17:03:15.184Z,1453395795.184 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA62M.000

-2016-01-21T17:03:15.184Z,1453395795.184 [ExternalSim](INFO): ExternalSim initializing...

-2016-01-21T17:03:15.285Z,1453395795.285 [MissionManager](INFO): DefineArg sample:SampleAtDepth.ESPComponentTimeout = 7.000000 min

-2016-01-21T17:03:15.286Z,1453395795.286 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/sample.xml

-2016-01-21T17:04:44.797Z,1453395884.797 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms

-2016-01-21T17:04:44.797Z,1453395884.797 [Startup](INFO): Completed Startup

-2016-01-21T17:04:45.196Z,1453395885.196 [MissionManager](IMPORTANT): Started mission sample

-2016-01-21T17:12:26.794Z,1453396346.794 [ESPComponent](INFO): manually powering up ESP

-2016-01-21T17:12:26.794Z,1453396346.794 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyS1 linkname esp noauth local lock 115200 134.89.10.51:134.89.10.60 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 134.89.10.32 ms-dns 134.89.10.10

+First sample is complete.

+Exit the ESP simulator, to then wait again for `[ESPComponent](IMPORTANT): Waiting for ESP to connect`:

+```

+2016-01-21T18:02:12.489Z,1453399332.489 [sample:SampleAtDepth:C.Wait](INFO): Done Waiting.

+2016-01-21T18:02:14.489Z,1453399334.489 [ESPComponent](INFO): powering up ESP

+2016-01-21T18:02:14.489Z,1453399334.489 [ESPComponent](INFO): manually powering up ESP

+2016-01-21T18:02:14.489Z,1453399334.489 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyS1 linkname esp noauth local lock 115200 134.89.10.51:134.89.10.60 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 134.89.10.32 ms-dns 134.89.10.10

 tethyssim>! echo 1 > /dev/loadB7sh: /sbin/pppd: No such file or directory

-2016-01-21T17:12:26.798Z,1453396346.798 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)

+2016-01-21T18:02:14.496Z,1453399334.496 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)

 tethyssim>! echo 1 > /dev/loadB7

-2016-01-21T17:12:26.808Z,1453396346.808 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB7

+2016-01-21T18:02:14.529Z,1453399334.529 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB7

 tethyssim>sh: /dev/loadB7: Permission denied

```

-Upon the `[ESPComponent](IMPORTANT): Waiting for ESP to connect` above,

-launch the ESP simulator on the bufflehead session:

+Launch ESP simulator as before:

```

 carueda@bufflehead:~/esp2$ ESPclient=tethyssim:9998 ESPcmdPort=7777 esp

-@09:09:18.51PST21-Jan-16 <simreal> Copyright 2015 MBARI

+@10:02:19.67PST21-Jan-16 <simreal> Copyright 2015 MBARI

 /home/carueda/esp2/auv/honu/configure.rb

 ESP 3G "honu" 5 cartridge prototype

-@09:09:18.68 ArS.stop

+@10:02:19.84 ArS.stop

 ArS.configure ArSconfig

 Rod.stop

 Rod.configure RodConfig

 SP.stop

 SP.configure SPconfig

 All dwarves are running firmware version 3.74sim

-@09:09:18.69 <closeIntake> Intake.close

+@10:02:19.85 <closeIntake> Intake.close

 <closeExhaust> Exhaust.close

-@09:09:20.00 <simreal> Clients may connect on TCP port 7777

+@10:02:21.17 <simreal> Clients may connect on TCP port 7777

 Connecting to tethyssim:9998

-@09:09:20.39 <LRAUV> Session Begun

-```

-then, on tethyssim:

-```

-2016-01-21T17:12:31.995Z,1453396351.995 [ESPComponent](IMPORTANT): ESP has connected as client

-2016-01-21T17:12:32.795Z,1453396352.795 [ESPComponent](IMPORTANT): ESP sampling sequence starting (sample #2)  sampling state: S_WAITING_INITIAL_PROMPT

-2016-01-21T17:12:33.196Z,1453396353.196 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 1.101370 m in nan degC water with nan ug/l chlorophyll fluorescence.

-2016-01-21T17:12:33.594Z,1453396353.594 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_LOG

-2016-01-21T17:12:33.994Z,1453396353.994 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_STATUS

-2016-01-21T17:12:35.995Z,1453396355.995 [ESPComponent](IMPORTANT): ESP sampling state: S_LOADING_CARTRIDGE

-2016-01-21T17:12:55.595Z,1453396375.595 [ESPComponent](IMPORTANT): ESP sampling state: S_FILTERING

-2016-01-21T17:12:57.995Z,1453396377.995 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PAUSED

-2016-01-21T17:13:19.195Z,1453396399.195 [ESPComponent](IMPORTANT): ESP sampling state: S_PROCESSING

-2016-01-21T17:13:21.594Z,1453396401.594 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PROCESSED

-2016-01-21T17:14:15.195Z,1453396455.195 [ESPComponent](IMPORTANT): ESP sampling state: S_STOPPING

-2016-01-21T17:14:19.595Z,1453396459.595 [ESPComponent](IMPORTANT): ESP sampling sequence completed normally (sample #2)

-2016-01-21T17:14:19.597Z,1453396459.597 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP

-2016-01-21T17:14:19.597Z,1453396459.597 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper

-2016-01-21T17:14:19.597Z,1453396459.597 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth

-2016-01-21T17:14:19.994Z,1453396459.994 [ESPComponent](INFO): powering down ESP

+@10:02:21.28 <LRAUV> Session Begun

+```

+And finally on tethyssim:

+```

+2016-01-21T18:02:21.688Z,1453399341.688 [ESPComponent](IMPORTANT): ESP has connected as client

+2016-01-21T18:02:22.489Z,1453399342.489 [ESPComponent](IMPORTANT): ESP sampling sequence starting (sample #2)  sampling state: S_WAITING_INITIAL_PROMPT

+2016-01-21T18:02:22.889Z,1453399342.889 [sample:SampleAtDepth:SampleWrapper:SampleESP:C](IMPORTANT): ESP sampling at 1.129265 m in nan degC water with nan ug/l chlorophyll fluorescence.

+2016-01-21T18:02:23.288Z,1453399343.288 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_LOG

+2016-01-21T18:02:23.689Z,1453399343.689 [ESPComponent](IMPORTANT): ESP sampling state: S_PREPARING_SHOW_STATUS

+2016-01-21T18:02:25.689Z,1453399345.689 [ESPComponent](IMPORTANT): ESP sampling state: S_LOADING_CARTRIDGE

+2016-01-21T18:02:45.289Z,1453399365.289 [ESPComponent](IMPORTANT): ESP sampling state: S_FILTERING

+2016-01-21T18:02:47.688Z,1453399367.688 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PAUSED

+2016-01-21T18:03:08.888Z,1453399388.888 [ESPComponent](IMPORTANT): ESP sampling state: S_PROCESSING

+2016-01-21T18:03:11.288Z,1453399391.288 [ESPComponent](IMPORTANT): ESP sampling state: S_WAITING_FOR_PROCESSED

+2016-01-21T18:04:04.888Z,1453399444.888 [ESPComponent](IMPORTANT): ESP sampling state: S_STOPPING

+2016-01-21T18:04:09.289Z,1453399449.289 [ESPComponent](IMPORTANT): ESP sampling sequence completed normally (sample #2)

+2016-01-21T18:04:09.290Z,1453399449.290 [sample:SampleAtDepth:SampleWrapper:SampleESP](INFO): Completed sample:SampleAtDepth:SampleWrapper:SampleESP

+2016-01-21T18:04:09.290Z,1453399449.290 [sample:SampleAtDepth:SampleWrapper](INFO): Completed sample:SampleAtDepth:SampleWrapper

+2016-01-21T18:04:09.290Z,1453399449.290 [sample:SampleAtDepth](INFO): Completed sample:SampleAtDepth

+2016-01-21T18:04:09.689Z,1453399449.689 [ESPComponent](INFO): powering down ESP

 tethyssim>pppd: no process killed

-2016-01-21T17:14:20.003Z,1453396460.003 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample

-2016-01-21T17:14:20.003Z,1453396460.003 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater

-2016-01-21T17:14:20.003Z,1453396460.003 [sample](INFO): Completed sample

-2016-01-21T17:14:20.396Z,1453396460.396 [MissionManager](IMPORTANT): Started mission Default

-```

+2016-01-21T18:04:09.719Z,1453399449.719 [sample:SampleRepeater:Sample](INFO): Completed sample:SampleRepeater:Sample

+2016-01-21T18:04:09.719Z,1453399449.719 [sample:SampleRepeater](INFO): Completed sample:SampleRepeater

+2016-01-21T18:04:09.719Z,1453399449.719 [sample](INFO): Completed sample

+2016-01-21T18:04:10.089Z,1453399450.089 [MissionManager](IMPORTANT): Started mission Default

+```

+showing completion of the 2nd ESP sample, and the mission.

HTTPS

SSH

You can clone a snippet to your computer for local editing. Learn more.

Snippets

Carlos Rueda ESPComponent testing with LRAUV and ESP simulators

File snippet.markdown Modified

File snippet.markdown Modified

File snippet.markdown Modified

File snippet.markdown Modified

File snippet.markdown Modified