Snippets

Carlos Rueda ESPComponent testing with LRAUV and ESP simulators

You are viewing an old version of this snippet. View the current version.
Revised by Carlos Rueda 3811747
snippet.markdown
Raw

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.

On bufflehead

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

   $ cd esp2
   $ . bin/ESPenv auv honu
   $ ESPmode=simreal

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

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:

  $ ESPclient=tethyssim:9998 ESPcmdPort=7777 esp

This prepares the subsequent execution of the ESP system (see below) once the socket server 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.

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;

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:

Run the mission:

[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:

[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

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-21T18:02:14.496Z,1453399334.496 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=30.0000)
tethyssim>! 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

Launch ESP simulator as before:

carueda@bufflehead:~/esp2$ ESPclient=tethyssim:9998 ESPcmdPort=7777 esp
@10:02:19.67PST21-Jan-16 <simreal> Copyright 2015 MBARI
/home/carueda/esp2/auv/honu/configure.rb
ESP 3G "honu" 5 cartridge prototype
@10:02:19.84 ArS.stop
ArS.configure ArSconfig
Rod.stop
Rod.configure RodConfig
PV.stop
PV.configure PVconfig
SC.stop
SC.configure SCconfig
TV.stop
TV.configure TVconfig
SP.stop
SP.configure SPconfig
All dwarves are running firmware version 3.74sim
@10:02:19.85 <closeIntake> Intake.close
<closeExhaust> Exhaust.close
@10:02:21.17 <simreal> Clients may connect on TCP port 7777
Connecting to tethyssim:9998
@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-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.