classification
Title: Performance issue (+fix) AIX ctypes.util with no /sbin/ldconfig present
Type: Stage: resolved
Components: ctypes Versions: Python 2.7
process
Status: closed Resolution: wont fix
Dependencies: Superseder:
Assigned To: Nosy List: Michael.Felt, martin.panter, r.david.murray, tw.bert
Priority: normal Keywords: patch

Created on 2014-06-22 16:01 by tw.bert, last changed 2018-07-23 06:55 by berker.peksag. This issue is now closed.

Files
File name Uploaded Description Edit
patch_ctypes_util_py.diff tw.bert, 2014-06-22 16:01
Messages (8)
msg221266 - (view) Author: tw.bert (tw.bert) Date: 2014-06-22 16:01
Preample: This is my first post to the python issue tracker, I included a fix.

This issue is probably related to http://bugs.python.org/issue11063 .

The problem:

After upgrading a package on AIX 7.1 x64 that started using the uuid module, we experienced serious performance issues.

The culprit (found after a day of debugging) is here:

File: ctypes/util.py
Note: The file /sbin/ldconfig does *not* exist, so no useful information is collected here.
The statement: 

`f = os.popen('/sbin/ldconfig -p 2>/dev/null')`

To be more specific about the performace at popen(), the performance degradation happens in it's close() method. It takes 300 ms, which is unacceptable. In a larger scope, statements that took 200ms now take 1400ms (because the above is called several times.

If I simply check for os.path.exists before the popen, the performance is fine again. See the included simple patch. It's a simple unix diff, we don't have git on that machine. Git can handle those diffs easily to my knowledge.

More information:

Small scope, culprit identified:

import os, time, traceback
print os.__file__
print time.clock(),'pre'
f = None
try:
  #if os.path.exists('/sbin/ldconfig'):
  f = os.popen('/sbin/ldconfig -p 2>/dev/null')
except:
  print traceback.format_exc()
finally:
  print time.clock(),'post close'
  if f: f.close()
  print time.clock(),'post finally'

This takes 300ms (post finally) without the check for exists.

Large scope, before patch:
time python -c "import hiredis;import redis;print 'redis-py version: %s , hiredis-py version: %s' %(redis.VERSION,hiredis.__ver
sion__,)"
redis-py version: (2, 10, 1) , hiredis-py version: 0.1.3

real    0m1.409s
user    0m0.416s
sys     0m0.129s

Large scope, after patch:
time python -c "import hiredis;import redis;print 'redis-py version: %s , hiredis-py version: %s' %(redis.VERSION,hiredis.__ver
sion__,)"
redis-py version: (2, 10, 1) , hiredis-py version: 0.1.3

real    0m0.192s
user    0m0.056s
sys     0m0.050s
msg221278 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2014-06-22 16:47
How does this interact with issue 11063?
msg221284 - (view) Author: tw.bert (tw.bert) Date: 2014-06-22 17:31
Hi David, thank you for looking into this.
Issue 11063 starts with "When the uuid.py module is simply imported it has the side effect of forking a subprocess (/sbin/ldconfig) and doing a lot of stuff find a uuid implementation by ctypes.".

My fix is specific about solving the AIX performance problem I encounter in the exact same condition as above. My guess is, that if 11063 is picked up (not using external tools), the AIX performance problem will be addressed automatically, rendering the new issue 21826 obsolete.
msg264149 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2016-04-25 03:26
See also Issue 26439 about find_library() AIX support
msg273324 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2016-08-22 01:31
It looks like Bert’s patch adjusted two ldconfig calls; the first one was in a BSD-specific branch. Was this intended? Only the second call (default “else:” branch) seems applicable to AIX.

Perhaps the performance is improved now that the popen() shell calls have been replaced with more direct subprocess.Popen() calls; see revision a09ae70f3489 and Issue 22636. If the 300 ms slowdown was due to the shell, that should no longer be a problem.

But if the slowdown is say inherent in fork(), I am not sure it is worth adding the proposed os.path.exists() check. Either try a way of spawning a child process without fork(), like Issue 20104. Or avoid calling find_library() in the first place, like I suggested at <https://bugs.python.org/issue11063#msg264151>.
msg273539 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2016-08-24 08:37
For the record, if you wanted to actually load the library function on AIX, I understand the code might look a bit like:

if sys.platform.startswith("aix"):
    if sys.maxsize > 2**32:
        lib = "libc.a(shr_64.o)"
    else:
        lib = "libc.a(shr.o)"
    RTLD_MEMBER = 0x00040000
    lib = ctypes.CDLL(lib, ctypes.DEFAULT_MODE | RTLD_MEMBER)
    _uuid_generate_time = lib.uuid_generate_time
else:
    # The uuid_generate_* routines are provided by libuuid on at least
    # Linux and FreeBSD, and provided by libc on Mac OS X.
    ...
msg274901 - (view) Author: Michael Felt (Michael.Felt) * Date: 2016-09-07 21:51
re: issue 26439 and issue 27435 would like to show:

without patch, find_library() is consistently slow, and in default situations, returns nothing.

root@x064:[/data/prj/aixtools/python/python-2.7.10]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("crypt")'
100 loops, best of 3: 29.6 msec per loop
root@x064:[/data/prj/aixtools/python/python-2.7.10]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("crypt")'
100 loops, best of 3: 28.8 msec per loop
root@x064:[/data/prj/aixtools/python/python-2.7.10]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("c")'
100 loops, best of 3: 29.4 msec per loop
root@x064:[/data/prj/aixtools/python/python-2.7.10]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("m")'
100 loops, best of 3: 29.8 msec per loop
root@x064:[/data/prj/aixtools/python/python-2.7.10]cd -
/data/prj/aixtools/python/python-2.7.12.1
root@x064:[/data/prj/aixtools/python/python-2.7.12.1]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("crypt")'
100 loops, best of 3: 13.5 msec per loop
root@x064:[/data/prj/aixtools/python/python-2.7.12.1]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("c")'
100 loops, best of 3: 21.4 msec per loop
root@x064:[/data/prj/aixtools/python/python-2.7.12.1]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("m")'
100 loops, best of 3: 26.1 msec per loop

The results can be explained as follows:
no patch - all fail, nothing is ever found in a default environment.

with patch: crypt - the answer includes the archive member libcrypt.so, so it is found "earlier" than for "c" which must look for legacy names, which is faster than "m" which does not exist.

What I consider "frightening" - and a good reason to stay with Python2 as long as possible is the follow difference
Python3.6a2 - unpatched, versus Python3.6a4 - ctypes.util patched for AIX:

root@x064:[/data/prj/aixtools/python/python-3.6.0.162]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("crypt")'
100 loops, best of 3: 84.1 msec per loop
root@x064:[/data/prj/aixtools/python/python-3.6.0.162]cd ../*164
root@x064:[/data/prj/aixtools/python/python-3.6.0.164]./python -m timeit -n 100 'import ctypes.util; ctypes.util.find_library("crypt")'
100 loops, best of 3: 66.6 msec per loop

FYI: this is on a POWER6 (so h/w is 'quite old', msec should be seen as relative, not as accurate for newer hardware)
msg322181 - (view) Author: Michael Felt (Michael.Felt) * Date: 2018-07-23 06:45
as this is fixed is Python3.7 (see issue26439) and has been stated several times that it will not be fixed in Python2.7 I suspect this issue may also be closed.
History
Date User Action Args
2018-07-23 06:55:39berker.peksagsetstatus: open -> closed
resolution: wont fix
stage: test needed -> resolved
2018-07-23 06:45:37Michael.Feltsetmessages: + msg322181
2016-09-07 21:51:53Michael.Feltsetnosy: + Michael.Felt
messages: + msg274901
2016-08-24 08:37:46martin.pantersetmessages: + msg273539
2016-08-22 01:31:20martin.pantersetmessages: + msg273324
stage: test needed
2016-04-25 03:26:52martin.pantersetnosy: + martin.panter
messages: + msg264149
2014-06-22 17:31:23tw.bertsetmessages: + msg221284
2014-06-22 16:47:59r.david.murraysetnosy: + r.david.murray
messages: + msg221278
2014-06-22 16:01:11tw.bertcreate