Experimental Physics and
Industrial Control System

Mark Rivers <[email protected]> · Mon, 22 Apr 2013 23:12:38 +0000

The problematic IOC is on a dual-boot system, Linux Fedora Core 14 and Windows 7 64-bit.

I just rebooted it with Windows.

Initially caget and caput worked without delay.  But after running the IOC for a while it is now in a state where caget and caput are again slow.  This is from a remote Linux system to the Windows IOC.  The IOC computer is more than 90% idle.

I have now modified the 3.14.12.3 version of caput to also print the time in various steps:

corvette:base/src/catools>../../bin/linux-x86_64/caput 13PS1:cam1:Acquire 0
Old : 13PS1:cam1:Acquire             Done
New : 13PS1:cam1:Acquire             Done
 Time to create context=0.000555
    Time to connect PVs=0.030361
        Time to put PVs=0.000936
    Time for ca_pend_io=0.000006
        Time to get PVs=0.000381
Time to destroy context=2.010504
             Total time=2.042742

corvette:base/src/catools>../../bin/linux-x86_64/caget 13PS1:cam1:Acquire
13PS1:cam1:Acquire             Done
 Time to create context=0.000547
    Time to connect PVs=0.030242
        Time to get PVs=0.000579
Time to destroy context=2.010867
             Total time=2.042235

This is running caget and caput from a remote Windows 7 machine:

H:\epics\base\src\catools>..\..\bin\windows-x64\caput 13PS1:cam1:Acquire 0
Old : 13PS1:cam1:Acquire             Done
New : 13PS1:cam1:Acquire             Done
 Time to create context=0.007857
    Time to connect PVs=0.040451
        Time to put PVs=0.007289
    Time for ca_pend_io=0.000005
        Time to get PVs=0.007154
Time to destroy context=8.858039
             Total time=8.920796

H:\epics\base\src\catools>..\..\bin\windows-x64\caget 13PS1:cam1:Acquire
13PS1:cam1:Acquire             Done
 Time to create context=0.011290
    Time to connect PVs=0.033812
        Time to get PVs=0.006111
Time to destroy context=4.530879
             Total time=4.582092

So destroying the context is taking 2 to 9 seconds on these systems for both caput and caget.

I also learned a little more about my problem with using IDL to start the cameras, with IDL doing a caput to the Acquire PV.  It always works fine to start the cameras the first time the script is running after starting IDL.  However, running the script again always causes the cameras to lose close to 100% of their frames.

Thanks,
Mark

-----Original Message-----
From: [email protected] [mailto:[email protected]] On Behalf Of Mark Rivers
Sent: Monday, April 22, 2013 4:43 PM
To: 'Andrew Johnson'
Cc: EPICS Tech Talk
Subject: RE: caget delays

I did another test, running the new version of caget on the problematic Linux machine itself, the one whose IOC has long times to destroy the context.

I find the if EPICS_CA_ADDR_LIST is localhost it is very fast, but if it is the broadcast address of my subnet it is slow.

Colorado:areaDetector/iocBoot/iocPS3>setenv EPICS_CA_ADDR_LIST localhost

Colorado:areaDetector/iocBoot/iocPS3>/corvette/usr/local/epics/base/bin/linux-x86-gcc43/caget 13PS1:cam1:Acquire
13PS1:cam1:Acquire Done
Time to create context=0.000799
Time to connect PVs=0.028771
Time to get PVs=0.000303
Time to destroy context=0.001288
Total time=0.031160

Colorado:areaDetector/iocBoot/iocPS3>setenv EPICS_CA_ADDR_LIST 164.54.160.255

Colorado:areaDetector/iocBoot/iocPS3>/corvette/usr/local/epics/base/bin/linux-x86-gcc43/caget 13PS1:cam1:Acquire
13PS1:cam1:Acquire Done
Time to create context=0.000783
Time to connect PVs=0.028628
Time to get PVs=0.000367
Time to destroy context=1.999753
Total time=2.029531

________________________________________
From: [email protected] [[email protected]] on behalf of Mark Rivers [[email protected]]
Sent: Monday, April 22, 2013 4:32 PM
To: 'Andrew Johnson'
Cc: EPICS Tech Talk
Subject: RE: caget delays

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