Experimental Physics and
Industrial Control System

Mark Rivers <[email protected]> · Mon, 22 Apr 2013 21:32:44 +0000

Hi Andrew,

The problem is not that the IOC is busy running the cameras.  The same long delay when running caget/caput/cainfo occurs even if the cameras are not acquiring.  This is a quad-core Linux machine, and when the cameras are not acquireing all CPUs are less than 3% busy.  The network is essentially idle with less than 15 KB/sec traffic.

I modified the caget program from base-3.14.12.3 to print the time required for each operation.

Here are the results when running caget to a similar Prosilica IOC on a busier but "non-problematic" Linux server:

corvette:base/src/catools>../../bin/linux-x86_64/caget 13IDAPS1:cam1:Acquire
13IDAPS1:cam1:Acquire          Done
 Time to create context=0.000516
    Time to connect PVs=0.028928
        Time to get PVs=0.000327
Time to destroy context=0.000643
             Total time=0.030414

So the total time is 30 ms, and the time to destroy the context is 643 microseconds.

This is the result to that same Linux IOC from a Windows 7 64-bit machine:
H:\epics\base\src\catools>..\..\bin\windows-x64\caget 13IDAPS1:cam1:Acquire
13IDAPS1:cam1:Acquire          Done
 Time to create context=0.008363
    Time to connect PVs=0.035649
        Time to get PVs=0.006076
Time to destroy context=0.002816
             Total time=0.052904

So the total time is 53 ms, and the time to destroy the context is 2.8 ms.

Now here are the results from the Linux and Windows machines to the "problematic" IOC, which is completely idle because the cameras are not acquiring:

corvette:base/src/catools>../../bin/linux-x86_64/caget 13PS1:cam1:Acquire
13PS1:cam1:Acquire             Done
 Time to create context=0.000591
    Time to connect PVs=0.029165
        Time to get PVs=0.000520
Time to destroy context=3.602033
             Total time=3.632309

H:\epics\base\src\catools>..\..\bin\windows-x64\caget 13PS1:cam1:Acquire
13PS1:cam1:Acquire             Done
 Time to create context=0.020868
    Time to connect PVs=0.043227
        Time to get PVs=0.005942
Time to destroy context=8.930734
             Total time=9.000772

So from both Linux and Windows the time to create the context, connect to the PVs and get the PV values are essentially the same as on the non-problematic IOC.  

However, the time to destroy the context is 3.6 seconds on Linux and 8.93 seconds on Windows!!!

What could possibly be causing this?  How do I debug it?

Thanks,
Mark

-----Original Message-----
From: Andrew Johnson [mailto:[email protected]] 
Sent: Monday, April 22, 2013 10:11 AM
To: Mark Rivers
Subject: Re: caget delays

Hi Mark,

On 2013-04-22 you wrote:
> However, when I run the caget program from EPICS base this is what I get:
> 
> corvette:prosilicaSupport/GigE_SDK_Linux_v1.26/documents>date ;
>  /corvette/usr/local/epics/base/bin/linux-x86-gcc43/caget
>  13PS1:cam1:Acquire ; date Mon Apr 22 09:43:51 CDT 2013
> 13PS1:cam1:Acquire             Done
> Mon Apr 22 09:43:53 CDT 2013
> 
> So it takes 2 seconds.  This only seems to happen to this particular IOC,
> not to all IOCs.  The IOC is running areaDetector for Prosilica cameras,
> but the cameras are not running.  It does not matter how many IOCs are
> running on that Linux (Fedora core 14) host.

As I said in my reply a few minutes ago, I think this is because caget/caput 
program is waiting for the CA connection to close down, and it's taking that 
IOC some time to respond to the "close" request from the client because it's 
busy running the cameras.  Does it still take the 2 seconds if you stop the 
camera acquisition so the IOC is not busy?  IDL is not closing down CA, so 
it's not waiting for the shutdown to finish.

Running the IOC as a SCHED_FIFO process could also fix this, see the wiki page 
I pointed you to.

- Andrew
-- 
It is difficult to get a man to understand something, when his salary
depends upon his not understanding it. -- Upton Sinclair

Experimental Physics and Industrial Control System

Experimental Physics and
Industrial Control System