Author arnostienen
Recipients
Date 2007-05-29.11:57:36
SpamBayes Score
Marked as misclassified
Message-id
In-reply-to
Content
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!
History
Date User Action Args
2007-08-23 14:54:18adminlinkissue1727418 messages
2007-08-23 14:54:18admincreate