Created a small program using xmlrpclib. When connecting to one url
where my list is < 300 items and the program finishes no problem.
Connect to another url where my list is over 500 items and the program
times out after 40+ minutes with no results printed. On my RHEL system
I used oprofile and determined that time spent was in ceval.c, symbol
PyEval_EvalFrame. This issue seems to be new to Python 2.4 as shipped
with RHEL. I am currently in the process of building non-RHEL python to
verify issue does or does not exist there as well.

<code>
#!/usr/bin/env python

import xmlrpclib

u = 'someuser'
p = 'password'

server_url = 'http://rhn.redhat.com/rpc/api'

server = xmlrpclib.Server(server_url)

session = server.auth.login(u,p)

l = server.channel.listSoftwareChannels(session)
for a in l:
    print a['channel_label']
</code>

I have tested 2.4.4 and 2.5.1 from python.org and both suffer from the
exact same issue. I have also compared ceval.c from 2.3, the last known
working copy and ceval.c from 2.4+ and found that ceval.c has undergone
some pretty significant changes.

That changes to ceval should have introduced some kind of XML-RPC
package limit seems a bit unlikely. If you can still reproduce this,
can you try instrumenting the xmlrpclib.py library to see where it gets
stuck?

(passing in verbose=True to the Server[Proxy] constructor might be good
enough)

Please find the attached ceval.c. This file was generated from oprofile
and gives clear indicators where the simple program below gets hung up.

You will find in the oprofile output, from ceval.c, that PyEval_Frame
has a total of 1649 26.2789. This indicates with a high degree of
probabilty that the changes made in this portion of the code are
promblamatic.

Now I will be the first to admit that I am by no means a C programmer;
however, I can tell you that the code has changed a great deal with
regards to xmlrpc and it has impacted performance to the point where it
seems to be unusable with current releases of Python where expected
output is > 300 records.

Please check it out for yourself, using a different xmlrpc server - I
currently have access to one only where the number of records is greater
than 300.

I don't think ceval is the issue here.

the code has changed a great deal with regards to xmlrpc
I am not sure to understand what you mean: xmlrpc is mostly written in
python code.

ceval.c is the place where the interpreter executes python code.
PyEval_EvalFrame is the loop that reads and dispatches each python
instruction.
Of course this function is time-critical, but the problem probably is
that too many python code is executed.

I suggest you to use the python-level profiler:
http://docs.python.org/lib/profile-instant.html
This may reveal some interesting things in the xmlrpclib module.

Do you have an example which doesn't require a login? Failing that,
can you tell us how to get the requisite login?

Skip

Can you switch on verbose mode in xmlrpclib, so you can see *where* the
transfer hangs?

Arguing that a hanging Python program must be caused by a bug in the
code that *executes* the Python program isn't that meaningful, really.
After all, that code is used to run *all* Python programs, so I think
we'd noticed if it had a tendency to hang unexpectedly...

Has anybody else tested this against an RPC server that has more than
300 items to be returned. I find it interesting that before all the
xmlrpc code changed everything works fine, but after the code change
(re-write) things don't seem to work.

As for the bug, I do not claim there is a bug, I am simply pointing
out that when using oprofile to profile the test application, most of
the time is spent in a specific routine. Now it could be a side
affect of xmlrpc, I don't know - I do not claim to be a "programmer".

I am looking to turn on verbose mode in xmlrpc. As soon as I do that
I will test again and send the results.

On Jan 15, 2008 7:05 PM, Fredrik Lundh <report@bugs.python.org> wrote:

Fredrik Lundh added the comment:

Can you switch on verbose mode in xmlrpclib, so you can see *where* the
transfer hangs?

Arguing that a hanging Python program must be caused by a bug in the
code that *executes* the Python program isn't that meaningful, really.
After all, that code is used to run *all* Python programs, so I think
we'd noticed if it had a tendency to hang unexpectedly...

---

Tracker <report@bugs.python.org>
<http://bugs.python.org/issue1327\>

---

I have added the verbose=1 option, the processing hangs in the body: where :
<code>
for a in l:
print a['channel_label']
</code>

Is returning the data. Initially it returns data quickly and then slows
until it eventually stops.

Here is the sample of the body data... data removed...

<body>
body: '<?xml version="1.0"
encoding="ISO-8859-1"?><methodResponse><params><param><value><array><data><value><struct><member><name></name><value><string></string></value></member><member><name></name><value><string></string></value></member><member><name></name><value><string></string></value></member><member><name></name><value><string></string></value></member><member><name></name><value><string></string></value></member></struct></value><value><struct><member><name></name><value><string></string></value></member><member><name></name><value><string></string></value></member><member><name></name><value><string>
</string></value></member><member><name></name><value><string></string></value></member><m'
</body>

This information is repeats ~500 times in the server where the program
eventually times out.

If you require anything further from the verbose output please let me know.

What is the length of the response?
in verbose mode, you must read a line like:
header: Content-length: 623329

Note that I managed to produce the same kind of output as the one you
showed, with a size of ~600Kb. And the whole request takes less that 1
second.

Here is the header information that I get:
<snip>
reply: 'HTTP/1.1 200 OK\r\n'
header: Date: Tue, 22 Jan 2008 14:42:54 GMT
header: Server: Apache
header: Content-Length: 183
header: Content-Type: text/xml;charset=UTF-8
</snip>

Then I get addition send followed by more header info:

<snip>
reply: 'HTTP/1.1 200 OK\r\n'
header: Date: Tue, 22 Jan 2008 14:42:54 GMT
header: Server: Apache
header: Content-Length: 399191
header: Content-Type: text/xml;charset=UTF-8
header: X-Pad: avoid browser bug
</snip>

I am looking for additional Content-Length data. Also, the above was
done using Python 2.5.1 (r251:54863, Oct 30 2007, 13:54:11).

Thank you!

Some strace data:

WORKS:
<Python 2.3.4 (#1, Jan 9 2007, 16:40:09)>
strace -cf ./test.py >/tmp/out
Process 9439 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
33.10 0.009125 8 1086 956 open
23.47 0.006469 7 930 recvfrom
9.67 0.002667 9 311 278 stat
8.10 0.002234 14 165 read
3.40 0.000936 7 133 mmap
3.25 0.000896 6 144 close
3.24 0.000892 45 20 poll
2.97 0.000818 5 173 fstat
2.83 0.000780 15 53 munmap
2.13 0.000588 118 5 3 execve
1.34 0.000369 9 39 mprotect
1.13 0.000312 4 72 rt_sigaction
0.66 0.000183 5 35 futex
0.64 0.000176 10 17 brk
0.61 0.000169 12 14 sendto
0.57 0.000158 26 6 write
0.50 0.000139 4 34 fcntl
0.49 0.000134 10 14 socket
0.40 0.000111 4 25 lseek
0.36 0.000100 7 14 2 connect
0.34 0.000093 23 4 getdents64
0.27 0.000074 5 14 2 ioctl
0.17 0.000048 4 11 gettimeofday
0.06 0.000016 8 2 2 access
0.05 0.000014 7 2 2 readlink
0.04 0.000010 5 2 arch_prctl
0.04 0.000010 5 2 time
0.03 0.000009 9 1 _sysctl
0.03 0.000008 8 1 lstat
0.03 0.000008 4 2 uname
0.02 0.000006 6 1 rt_sigprocmask
0.02 0.000006 6 1 getcwd
0.01 0.000004 4 1 getrlimit
0.01 0.000004 4 1 set_tid_address
------ ----------- ----------- --------- --------- ----------------
100.00 0.027566 3335 1245 total
<Python 2.3.4 (#1, Jan 9 2007, 16:40:09)>

I am still compiling the same data for Python 2.4.3 (#1, Dec 11 2006,
11:39:03). However, this could take hours... as 2.4+ seem to be
problematic.

Please, could you use the python profiler instead? Since most of the
time is spent in the bytecode interpreter, the results are much more
meaningful.
Something like:

#!/usr/bin/env python
import xmlrpclib
import profile

u = 'someuser'
p = 'password'
server_url = 'http://rhn.redhat.com/rpc/api'

def f():
    server = xmlrpclib.Server(server_url)
    session = server.auth.login(u,p)
    l = server.channel.listSoftwareChannels(session)
    for a in l:
        print a['channel_label']

def g():
    try:
        f()
    except:
        pass

profile.run("g()")

Can this ticket be closed? I've still yet to see anything here that
anyone could actually do anything with.

"Requested info not available", closing this ticket.