EPICS Controls Argonne National Laboratory

Experimental Physics and
Industrial Control System

1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020  2021  2022  2023  2024  Index 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020  2021  2022  2023  2024 
<== Date ==> <== Thread ==>

Subject: Re: Uploading a file with SFTP from an EPICS driver
From: Torsten Bögershausen via Tech-talk <[email protected]>
To: Mark Rivers <[email protected]>, "'J. Lewis Muir'" <[email protected]>
Cc: "[email protected]" <[email protected]>
Date: Mon, 18 Nov 2019 16:00:15 +0100
May be out of the blue:

Does it make sense to make a trace with Wireshark/Ethereal/tcpdump
to find out if we loose time doing ssl negotioans,
key exchange, reverse lookups and other network related
stuff ?


On 18/11/19 15:03, Mark Rivers via Tech-talk wrote:
Hi Lewis,



Ø  Strange.  Other things you could try:



     1. Run curl and curl_gen under strace (e.g., "strace -CftT -s 256

        <command>") and see if you can tell where curl_gen is taking longer

        than curl.



This is the final output of strace when running curl_gen:



07:55:27 +++ exited with 0 +++

% time     seconds  usecs/call     calls    errors syscall

------ ----------- ----------- --------- --------- ----------------

34.38    0.000722           3       224       186 open

17.76    0.000373           4       102           mmap

13.00    0.000273           4        70           mprotect

   7.05    0.000148           3        57        23 recvfrom

   5.76    0.000121           3        39           fstat

   4.95    0.000104           3        40           read

   4.90    0.000103           5        22           poll

   3.57    0.000075           2        39           close

   2.38    0.000050           3        16           sendto

   2.10    0.000044           2        24           write

   0.90    0.000019          19         1           getsockopt

   0.67    0.000014           2         7           brk

   0.52    0.000011           4         3           munmap

   0.48    0.000010           0        23        18 stat

   0.29    0.000006           3         2         2 statfs

   0.24    0.000005           1         4         2 access

   0.19    0.000004           1         3           fcntl

   0.14    0.000003           1         3           rt_sigaction

   0.14    0.000003           3         1           getsockname

   0.14    0.000003           3         1           getpeername

   0.10    0.000002           2         1           rt_sigprocmask

   0.10    0.000002           2         1           getrlimit

   0.05    0.000001           1         1           lseek

   0.05    0.000001           1         1           getuid

   0.05    0.000001           1         1           arch_prctl

   0.05    0.000001           1         1           set_tid_address

   0.05    0.000001           1         1           set_robust_list

   0.00    0.000000           0         1           socket

   0.00    0.000000           0         1         1 connect

   0.00    0.000000           0         3           setsockopt

   0.00    0.000000           0         1           execve

   0.00    0.000000           0         1           gettid

   0.00    0.000000           0         1           futex

------ ----------- ----------- --------- --------- ----------------

100.00    0.002100                   696       232 total





This is the output of strace when running the curl command:



07:55:53 +++ exited with 0 +++

% time     seconds  usecs/call     calls    errors syscall

------ ----------- ----------- --------- --------- ----------------

57.74    0.001797           4       453           write

   8.16    0.000254           5        55        21 recvfrom

   7.33    0.000228           4        54           rt_sigaction

   5.82    0.000181          10        18           poll

   3.47    0.000108           7        16           sendto

   2.96    0.000092           3        28           mprotect

   2.12    0.000066           1        72        51 open

   1.90    0.000059           3        22           read

   1.83    0.000057           1        67           mmap

   1.74    0.000054           4        15           futex

   1.35    0.000042           2        25           close

   1.06    0.000033           4         8           brk

   0.64    0.000020           7         3           munmap

   0.61    0.000019           1        30        25 stat

   0.55    0.000017           1        21           fstat

   0.32    0.000010           3         3           fcntl

   0.26    0.000008           4         2           socket

   0.26    0.000008           8         1         1 connect

   0.22    0.000007           2         4           setsockopt

   0.19    0.000006           3         2         1 access

   0.16    0.000005           5         1           pipe

   0.13    0.000004           4         1           select

   0.13    0.000004           4         1           getsockopt

   0.10    0.000003           3         1           lseek

   0.10    0.000003           3         1           rt_sigprocmask

   0.10    0.000003           3         1           getsockname

   0.10    0.000003           3         1           getpeername

   0.10    0.000003           3         1           arch_prctl

   0.10    0.000003           3         1           set_tid_address

   0.10    0.000003           3         1           set_robust_list

   0.06    0.000002           2         1           ioctl

   0.06    0.000002           2         1           getrlimit

   0.06    0.000002           2         1           getuid

   0.06    0.000002           2         1           getgid

   0.06    0.000002           2         1           geteuid

   0.06    0.000002           2         1           getegid

   0.00    0.000000           0         1           execve

   0.00    0.000000           0         1           readlink

------ ----------- ----------- --------- --------- ----------------

100.00    0.003112                   917        99 total



I don't know how to interpret these because the total elapsed time for curl_gen was 0.33 seconds while for the curl command it was 0.12 seconds.  The tables above seem to show only 2-3 ms?



      2. Check the compiler optimization level curl_gen is compiled at just

        in case it's weak compared to what I presume the curl executable was

       compiled at.  (I doubt this is the cause.)



That cannot be the problem.  All of the elapsed time in curl_gen is spent in the single call to curl_perform, which is not in curl_gen, but rather in the libcurl package.



     3. Check the ldd output for curl, libcurl.so, and curl_gen for anything

         that looks suspicious.  Make sure curl_gen is not linked against

         libgnutls.



corvette:motorNewport/newportApp/src>ldd ../../../../bin/linux-x86_64/curl_gen

         linux-vdso.so.1 =>  (0x00007ffe0e3dc000)

         libcurl.so.4 => /lib64/libcurl.so.4 (0x00007f0faff52000)

         libstdc++.so.6 => /lib64/libstdc++.so.6 (0x00007f0fafc4b000)

         libm.so.6 => /lib64/libm.so.6 (0x00007f0faf949000)

         libgcc_s.so.1 => /lib64/libgcc_s.so.1 (0x00007f0faf733000)

         libc.so.6 => /lib64/libc.so.6 (0x00007f0faf366000)

         libidn.so.11 => /lib64/libidn.so.11 (0x00007f0faf133000)

         libssh2.so.1 => /lib64/libssh2.so.1 (0x00007f0faef06000)

         libssl3.so => /lib64/libssl3.so (0x00007f0faecb4000)

         libsmime3.so => /lib64/libsmime3.so (0x00007f0faea8d000)

         libnss3.so => /lib64/libnss3.so (0x00007f0fae760000)

         libnssutil3.so => /lib64/libnssutil3.so (0x00007f0fae531000)

         libplds4.so => /lib64/libplds4.so (0x00007f0fae32d000)

         libplc4.so => /lib64/libplc4.so (0x00007f0fae128000)

         libnspr4.so => /lib64/libnspr4.so (0x00007f0fadeea000)

         libpthread.so.0 => /lib64/libpthread.so.0 (0x00007f0fadcce000)

         libdl.so.2 => /lib64/libdl.so.2 (0x00007f0fadaca000)

         libgssapi_krb5.so.2 => /lib64/libgssapi_krb5.so.2 (0x00007f0fad87d000)

         libkrb5.so.3 => /lib64/libkrb5.so.3 (0x00007f0fad594000)

         libk5crypto.so.3 => /lib64/libk5crypto.so.3 (0x00007f0fad361000)

         libcom_err.so.2 => /lib64/libcom_err.so.2 (0x00007f0fad15d000)

         liblber-2.4.so.2 => /lib64/liblber-2.4.so.2 (0x00007f0facf4e000)

         libldap-2.4.so.2 => /lib64/libldap-2.4.so.2 (0x00007f0faccf9000)

         libz.so.1 => /lib64/libz.so.1 (0x00007f0facae3000)

         /lib64/ld-linux-x86-64.so.2 (0x00007f0fb01bc000)

         libssl.so.10 => /lib64/libssl.so.10 (0x00007f0fac871000)

         libcrypto.so.10 => /lib64/libcrypto.so.10 (0x00007f0fac40e000)

         librt.so.1 => /lib64/librt.so.1 (0x00007f0fac206000)

         libkrb5support.so.0 => /lib64/libkrb5support.so.0 (0x00007f0fabff6000)

         libkeyutils.so.1 => /lib64/libkeyutils.so.1 (0x00007f0fabdf2000)

         libresolv.so.2 => /lib64/libresolv.so.2 (0x00007f0fabbd9000)

         libsasl2.so.3 => /lib64/libsasl2.so.3 (0x00007f0fab9bc000)

         libselinux.so.1 => /lib64/libselinux.so.1 (0x00007f0fab795000)

         libcrypt.so.1 => /lib64/libcrypt.so.1 (0x00007f0fab55e000)

         libpcre.so.1 => /lib64/libpcre.so.1 (0x00007f0fab2fc000)

         libfreebl3.so => /lib64/libfreebl3.so (0x00007f0fab0f9000)



     4. You usually build EPICS and modules from an NFS file system,

        right?  Is that the case here?  If so, try copying curl_gen (and any

       dependencies) to a non-network file system and running it there.



This test was run on corvette, which is our Linux file server.  So the programs are on the local file system, not NFS.



Thanks,

Mark



-----Original Message-----
From: J. Lewis Muir <[email protected]>
Sent: Friday, November 15, 2019 1:05 PM
To: Mark Rivers <[email protected]>
Cc: [email protected]
Subject: Re: Uploading a file with SFTP from an EPICS driver



On 11/15, Mark Rivers wrote:

Thanks for the suggestion.  Now things get REALLY weird.



Indeed. :-)



I did what you said, and ran curl with --libcurl.  I timed the command:



[snip]



The performance was the same, 0.33 seconds, much slower than running the curl command itself!



Strange.  Other things you could try:



1. Run curl and curl_gen under strace (e.g., "strace -CftT -s 256

    <command>") and see if you can tell where curl_gen is taking longer

    than curl.



2. Check the compiler optimization level curl_gen is compiled at just

    in case it's weak compared to what I presume the curl executable was

    compiled at.  (I doubt this is the cause.)



3. Check the ldd output for curl, libcurl.so, and curl_gen for anything

    that looks suspicious.  Make sure curl_gen is not linked against

    libgnutls.



4. You usually build EPICS and modules from an NFS file system,

    right?  Is that the case here?  If so, try copying curl_gen (and any

    dependencies) to a non-network file system and running it there.

Lewis


References:
Uploading a file with SFTP from an EPICS driver Mark Rivers via Tech-talk
Re: Uploading a file with SFTP from an EPICS driver J. Lewis Muir via Tech-talk
RE: Uploading a file with SFTP from an EPICS driver Mark Rivers via Tech-talk
Re: Uploading a file with SFTP from an EPICS driver J. Lewis Muir via Tech-talk
RE: Uploading a file with SFTP from an EPICS driver Mark Rivers via Tech-talk

Navigate by Date:
Prev: Re: [EXTERNAL] ai records with data covering many decades Kasemir, Kay via Tech-talk
Next: Re: ../../bin/linux-x86_64/testIOC: bad interpreter: No such file or directory Johnson, Andrew N. via Tech-talk
Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020  2021  2022  2023  2024 
Navigate by Thread:
Prev: RE: Uploading a file with SFTP from an EPICS driver Mark Rivers via Tech-talk
Next: Re: Uploading a file with SFTP from an EPICS driver J. Lewis Muir via Tech-talk
Index: 1994  1995  1996  1997  1998  1999  2000  2001  2002  2003  2004  2005  2006  2007  2008  2009  2010  2011  2012  2013  2014  2015  2016  2017  2018  <20192020  2021  2022  2023  2024 
ANJ, 18 Nov 2019 Valid HTML 4.01! · Home · News · About · Base · Modules · Extensions · Distributions · Download ·
· Search · EPICS V4 · IRMIS · Talk · Bugs · Documents · Links · Licensing ·