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 <2019> 2020 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 <2019> 2020 2021 2022 2023 2024
<== Date ==>		<== Thread ==>

Subject:	RE: Uploading a file with SFTP from an EPICS driver
From:	Mark Rivers via Tech-talk <[email protected]>
To:	"'J. Lewis Muir'" <[email protected]>
Cc:	"[email protected]" <[email protected]>
Date:	Mon, 18 Nov 2019 14:03:57 +0000

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