classification
Title: xmlrpclib waits indefinately
Type: behavior Stage: resolved
Components: Library (Lib) Versions: Python 2.6
process
Status: closed Resolution: out of date
Dependencies: Superseder:
Assigned To: Nosy List: Adam.Duston, BreamoreBoy, ajaksu2, arnostienen, ggenellina, r.david.murray
Priority: normal Keywords:

Created on 2007-05-29 11:57 by arnostienen, last changed 2013-04-28 13:17 by r.david.murray. This issue is now closed.

Messages (6)
msg32144 - (view) Author: Arno Stienen (arnostienen) Date: 2007-05-29 11:57
I'm not sure if it is a Python bug, but I'm having problems using xmlrpclib to connect to a remote server.

When using this code to connect 
to a remote XML-RPC server (C++, xmlrpc++0.7 library):

           import xmlrpclib
           server = xmlrpclib.Server("http://10.10.101.62:29500")
           print server.Connection_Request("roberto")

the Python command line 'hangs' until I kill the server. Then, the 
correct output is suddenly displayed:

           {'state': 0, 'id_session': '2Z3EUSLJFA13', 'port': 29501,
           'str': 'Connection accepted. Session attached.'}

Yet a slightly simpler call works flawlessly:

           import xmlrpclib
           server = xmlrpclib.Server("http://10.10.101.62:29500")
           print server.Info_RT('Master')

           {'state': 0, 'str': 'Info_RT'}

Looking at the TCP packages (using Wireshark), the first 
Connection_Request flow as follows (c=python client,s= xml-rpcserver):

  1	c>s	SYN
  2	s>c	SYN,ACK
  3	c>s	ACK
  4	c>s	PSH,ACK (setting content-type: text/xml)
  5	s>c	ACK
  6	c>s	PSH,ACK (xml-rpc request)
  7	s>c	ACK
  8	s>c	PSH,ACK (xml-rpc results, correct)
  9 	c>s	ACK

At this point, Python 'hangs' until I kill (-9) the server (28 seconds 
later), and then these last packages are send:

10	s>c	FIN,ACK
11	c>s	FIN,ACk
12	s>c	ACK

After which Python continues and prints the xml-rpc results on the 
screen. Strangely, before Python hangs, it has already received the 
package with the results, but doesn't do anything with it.

For comparison, this is the package flow for the Info_RT method, which 
returns within a second with the correct result on the Python command line:

  1	c>s	SYN
  2	s>c	SYN,ACK
  3	c>s	ACK
  4	c>s	PSH,ACK (setting content-type: text/xml)
  5	s>c	ACK
  6	c>s	PSH,ACK (xml-rpc request)
  7	s>c	ACK
  8	s>c	PSH,ACK (xml-rpc results, correct)
  9	s>c	FIN,ACK
10 	c>s	ACK
11	c>s	FIN,ACk
12	s>c	ACK

Notice the reverse order of packages 9 and 10. Could this be it? Is 
Python waiting until the server sends a FIN package? But if so, why?

Looking at the Python trace, this might be it. A diff between the trace 
of the killed Connection_Request and the Info_RT resulted only in 
expected differences (due to different length of parameters). But when 
diffing the traces of the killed and non-killed Connection_Request, 
something else is visible. The killed Connection_Request ends with:

[...]
string:318:     return sep.join(words)
xmlrpclib:866:         self._type = "params"
xmlrpclib:769:         try:
xmlrpclib:770:             f = self.dispatch[tag]
xmlrpclib:771:         except KeyError:
xmlrpclib:772:             pass # unknown tag ?
xmlrpclib:1273:             if sock:
xmlrpclib:1274:                 response = sock.recv(1024)
xmlrpclib:1277:             if not response:
xmlrpclib:1278:                 break
xmlrpclib:1283:         file.close()
socket:218:         try:
socket:219:             if self._sock:
socket:220:                 self.flush()
socket:232:         if self._wbuf:
socket:222:             self._sock = None
xmlrpclib:1284:         p.close()
xmlrpclib:530:             self._parser.Parse("", 1) # end of data
xmlrpclib:531:             del self._target, self._parser # get rid of 
circular references
xmlrpclib:1286:         return u.close()
xmlrpclib:741:         if self._type is None or self._marks:
xmlrpclib:743:         if self._type == "fault":
xmlrpclib:745:         return tuple(self._stack)
socket:225:         try:
socket:226:             self.close()
socket:218:         try:
socket:219:             if self._sock:
socket:222:             self._sock = None
xmlrpclib:1386:         if len(response) == 1:
xmlrpclib:1387:             response = response[0]
xmlrpclib:1389:         return response
__main__:26:     print result
{'state': 0, 'id_session': 'QDLY3GP9FBM5', 'port': 29501, 'str': 
'Connection accepted. Session attached.'}

But the non-killed Connection_Request looks like:

[...]
return sep.join(words)
xmlrpclib:866:         self._type = "params"
xmlrpclib:769:         try:
xmlrpclib:770:             f = self.dispatch[tag]
xmlrpclib:771:         except KeyError:
xmlrpclib:772:             pass # unknown tag ?
xmlrpclib:1273:             if sock:
xmlrpclib:1274:                 response = sock.recv(1024)
socket:225:         try:
socket:226:             self.close()
socket:218:         try:
socket:219:             if self._sock:
socket:220:                 self.flush()
socket:232:         if self._wbuf:
socket:222:             self._sock = None

(In the diff there is a gap between the xmlrpclib:1274 and socket:225 
lines, as compared to the killed Connection_Request; perhaps Ctrl+C 
still executes the "socket try close" lines?)

If you want to do your own 'diff' on the Python traces, or look at the 
TCP packages in more details with Wireshark, here are the files for the 
correctly working Info_RT and faulty Connection_Request methods:

http://ctw-bw008.ctw.utwente.nl/~arno/rtaixml/roberto-infort-python.ws
http://ctw-bw008.ctw.utwente.nl/~arno/rtaixml/roberto-infort-python-ws.txt
http://ctw-bw008.ctw.utwente.nl/~arno/rtaixml/roberto-infort-trace.txt

http://ctw-bw008.ctw.utwente.nl/~arno/rtaixml/roberto-conreq-python.ws
http://ctw-bw008.ctw.utwente.nl/~arno/rtaixml/roberto-conreq-python-ws.txt
http://ctw-bw008.ctw.utwente.nl/~arno/rtaixml/roberto-conreq-trace.txt
http://ctw-bw008.ctw.utwente.nl/~arno/rtaixml/roberto-conreq-trace-hardbreak.txt

(The first three ConReq files all include killing the server after ~28 
seconds, thus resulting in the correct output. In the fourth files, 
tracing is stopped before the server is killed. It is therefor the trace 
up to the 'hanging point'. Note that the first two Wireshark packages 
are not TCP, but ARP, thus the file has a total of 14 packages, not 12 
as above.)

Really, any help here is appreciated!
msg32145 - (view) Author: Gabriel Genellina (ggenellina) Date: 2007-06-02 01:19
Copying a reply from Tijs <tijs_news@artsoftonline.com> posted at c.l.p. <http://permalink.gmane.org/gmane.comp.python.general/524601>:

---
After having a quick look at your files, I conclude that the problem is in a
combination of two problems:

1. Your server is crap. It answers an HTTP/1.0 request by an HTTP/1.1
response without specifying any Connection header and without closing the
connection. Normally, a simple client that is not HTTP/1.1-aware expects
the connection to close. HTTP/1.1 leaves the connection open by default.

2. The Python implementation of xmlrpc is not very robust. It just waits for
the connection to close. A well-written client (like your Java client)
would detect the presence of a Content-Length header and use that. 

The other request is OK because the server closes the connection after
having sent the response. Why the difference? Don't know, but it is
something server-side. 

Try to force the server to send HTTP/1.0 responses, or turn off keep-alive,
or something like that. Otherwise, adapt xmlrpclib.py to robustly handle
1.1 responses.
---
msg84721 - (view) Author: Daniel Diniz (ajaksu2) (Python triager) Date: 2009-03-30 23:48
Would the patch from issue 1767370 help with the robustness part?
msg116680 - (view) Author: Mark Lawrence (BreamoreBoy) * Date: 2010-09-17 17:03
Can this be closed due to work on #6267?
msg186765 - (view) Author: Adam Duston (Adam.Duston) Date: 2013-04-13 17:12
We used the xmlrpc++0.7 library to set up a test server, consistent with what Arno reported in the original ticket. We weren’t able to reproduce the problem with 2.7.2 or 3.4. Furthermore, xmlrpclib.Server (or xmlrpc.client.Server in Python 3) connects with HTTP 1.1 as of http://bugs.python.org/issue1767370, making the original issue irrelevant. 

There is already a test for this issue: the xmlrpc server used in test_python_builders in test_xmlrpc_net.py has an HTTP 1.1 reply.
msg187980 - (view) Author: R. David Murray (r.david.murray) * (Python committer) Date: 2013-04-28 13:17
Thanks for verifying this, Adam.
History
Date User Action Args
2013-04-28 13:17:12r.david.murraysetstatus: open -> closed

nosy: + r.david.murray
messages: + msg187980

resolution: out of date
stage: test needed -> resolved
2013-04-13 17:47:16Adam.Dustonsetversions: + Python 2.6, - Python 3.4
2013-04-13 17:12:40Adam.Dustonsetnosy: + Adam.Duston

messages: + msg186765
versions: + Python 3.4, - Python 2.6
2010-09-17 17:03:40BreamoreBoysetnosy: + BreamoreBoy
messages: + msg116680
2009-03-30 23:48:55ajaksu2setversions: + Python 2.6, - Python 2.5
nosy: + ajaksu2

messages: + msg84721

type: behavior
stage: test needed
2007-05-29 11:57:36arnostienencreate