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