Get ExpatError using FastCGI

[vyacheslav@…]

I install trac using FastCGI+Nginx and when I try run any XmlRpc method, I get this exception.

Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 444, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 205, in dispatch
    resp = chosen_handler.process_request(req)
  File "/usr/local/lib/python2.6/dist-packages/TracXMLRPC-1.0.6-py2.6.egg/tracrpc/web_ui.py", line 172, in process_request
    self.process_xml_request(req, content_type)
  File "/usr/local/lib/python2.6/dist-packages/TracXMLRPC-1.0.6-py2.6.egg/tracrpc/web_ui.py", line 176, in process_xml_request
    args, method = xmlrpclib.loads(req.read(int(req.get_header('Content-Length'))))
  File "/usr/lib/python2.6/xmlrpclib.py", line 1183, in loads
    p.close()
  File "/usr/lib/python2.6/xmlrpclib.py", line 604, in close
    self._parser.Parse("", 1) # end of data
ExpatError: no element found: line 1, column 0

Nginx configuration:

        location / {
                auth_basic "Trac";
                auth_basic_user_file /srv/trac/htpasswd;


                fastcgi_pass trac;
                fastcgi_param PATH_INFO $request_uri;
                fastcgi_param REQUEST_METHOD $request_method;
                fastcgi_param SERVER_NAME $server_name;
                fastcgi_param SERVER_PORT $server_port;
                fastcgi_param SERVER_PROTOCOL $server_protocol;
                fastcgi_param REMOTE_USER $remote_user;
                fastcgi_param QUERY_STRING $query_string;

                fastcgi_param SCRIPT_NAME "";
                fastcgi_param AUTH_USER $remote_user;

                # Test
                fastcgi_param HTTP_CONTENT_LENGTH $content_length;
        }

[vyacheslav@…]

System Information

Trac	0.11.5
Python	2.6.4 (r264:75706, Dec 7 2009, 18:43:55) [GCC 4.4.1]
setuptools	0.6c9
SQLite	3.6.16
pysqlite	2.4.1
Genshi	0.5.1
Pygments	1.0
Mercurial	1.3.1
RPC	1.0.6

[osimons]

If visiting /xmlrpc with regular browser gives you no such issues, it needs to be related to the custom _send_response() that I use to shortcut the request handling and write direct responses. Could you perhaps try to make these two changes, please:

trunk/tracrpc/web_ui.py

@@ -20 +20 @@
 from trac.perm import PermissionError
 from trac.util.datefmt import utc
 from trac.util.text import to_unicode
-from trac.web.main import IRequestHandler
+from trac.web.main import IRequestHandler, RequestDone
 from trac.web.chrome import ITemplateProvider, add_stylesheet
 from trac.wiki.formatter import wiki_to_oneliner
 
@@ -122 +122 @@
     def _send_response(self, req, response, content_type='application/xml'):
         response = to_unicode(response).encode("utf-8")
         req.send_response(200)
+        if not 'charset=' in content_type:
+            content_type = content_type + '; charset=UTF-8'
         req.send_header('Content-Type', content_type)
         req.send_header('Content-Length', len(response))
         req.end_headers()
         req.write(response)
+        raise RequestDone
 
     def process_request(self, req):
 

That should take care of any ambiguity regarding request content and finalization.

[vyacheslav@…]

After patch:

Python Traceback

Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 444, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 205, in dispatch
    resp = chosen_handler.process_request(req)
  File "/usr/local/lib/python2.6/dist-packages/TracXMLRPC-1.0.6-py2.6.egg/tracrpc/web_ui.py", line 175, in process_request
    self.process_xml_request(req, content_type)
  File "/usr/local/lib/python2.6/dist-packages/TracXMLRPC-1.0.6-py2.6.egg/tracrpc/web_ui.py", line 179, in process_xml_request
    args, method = xmlrpclib.loads(req.read(int(req.get_header('Content-Length'))))
  File "/usr/lib/python2.6/xmlrpclib.py", line 1183, in loads
    p.close()
  File "/usr/lib/python2.6/xmlrpclib.py", line 604, in close
    self._parser.Parse("", 1) # end of data
ExpatError: no element found: line 1, column 0

[osimons]

Oh, sorry - did not read your traceback properly. Presumed it was related to output, but it looks like this is an input issue where the Content-Length header is missing from client or removed by your config. It is unusual, but not impossible and the code does not deal with the possibility. Could you try making this change:

trunk/tracrpc/web_ui.py

@@ -176 +176 @@
 
     def process_xml_request(self, req, content_type):
         """ Handles XML-RPC requests """
-        args, method = xmlrpclib.loads(req.read(int(req.get_header('Content-Length'))))
+        args, method = xmlrpclib.loads(req.read())
         self.log.debug("RPC(xml) call by '%s', method '%s' with args: %s" \
                                     % (req.authname, method, repr(args)))
         args = self._normalize_xml_input(args)

[vyacheslav@…]

I'm played with nginx configuration (like fastcgi_param CONTENT_LENGTH $content_length;) and no effect. After your changes:

Python Traceback

Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 444, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.6/dist-packages/trac/web/main.py", line 205, in dispatch
    resp = chosen_handler.process_request(req)
  File "/usr/local/lib/python2.6/dist-packages/TracXMLRPC-1.0.6-py2.6.egg/tracrpc/web_ui.py", line 172, in process_request
    self.process_xml_request(req, content_type)
  File "/usr/local/lib/python2.6/dist-packages/TracXMLRPC-1.0.6-py2.6.egg/tracrpc/web_ui.py", line 177, in process_xml_request
    args, method = xmlrpclib.loads(req.read())
  File "/usr/lib/python2.6/xmlrpclib.py", line 1183, in loads
    p.close()
  File "/usr/lib/python2.6/xmlrpclib.py", line 604, in close
    self._parser.Parse("", 1) # end of data
ExpatError: no element found: line 1, column 0

[osimons]

Nope, not input or output and likely your config is fine. I've read the traceback even more closely and also poked into the xmlrpclib, and it seems to be a parsing error due to your client passing in empty information for some arguments (in xml body) and the parser raising the exception when nothing is there.

The code currently does not handle parsing errors which of course is a big omission - although it hasn't really been raised before as the XML-RPC spec is quite strict and the clients usually conform to it. What client are you using?

Could you add this to your modified file (keeping the other changes as well):

trunk/tracrpc/web_ui.py

@@ -176 +176 @@
 
     def process_xml_request(self, req, content_type):
         """ Handles XML-RPC requests """
-        args, method = xmlrpclib.loads(req.read())
+        try:
+            args, method = xmlrpclib.loads(req.read())
+        except Exception, e:
+            self.log.debug("RPC(xml) error parsing XML input: %s" % repr(e))
+            self._send_response(req, xmlrpclib.dumps(xmlrpclib.Fault(1, to_unicode(e))),
+                                    content_type)
         self.log.debug("RPC(xml) call by '%s', method '%s' with args: %s" \
                                     % (req.authname, method, repr(args)))
         args = self._normalize_xml_input(args)

[vyacheslav@…]

This works, thanks. This patch will be added into repository?

[osimons]

It will be, yes. Soon-ish.

[osimons]

From what I can see, I think this has been integrated into the major change at [7916] when we introduced pluggable protocols. It certainly was my intention, and the new code should have improved error handling in general.

Could anyone please update to latest (1.1.10+ from trunk) and confirm that this is now working? If not, please provide me with a fresh traceback and error message.

[osimons]

Closing. It should be fixed, and no recent feedback to say otherwise. Reopen if issue persists.