UnicodeDecodeError in log file

[Ryan J Ollos]

Running the latest SpamFilter plugin [13942], I find the following errors in the log:

2015-04-01 23:15:33,851 Trac[main] ERROR: Internal Server Error:
Traceback (most recent call last):
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.5-py2.6.egg/trac/web/main.py", line 513, in _dispatch_request
    dispatcher.dispatch(req)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.5-py2.6.egg/trac/web/main.py", line 187, in dispatch
    self._pre_process_request(req, chosen_handler)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.5-py2.6.egg/trac/web/main.py", line 334, in _pre_process_request
    chosen_handler = filter_.pre_process_request(req, chosen_handler)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/TracSpamFilter-1.0.6dev_r13942-py2.6.egg/tracspamfilter/captcha/api.py", line 167, in pre_process_request
    elif req.args.get('captcha_response', "") == exp:
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.5-py2.6.egg/trac/web/api.py", line 355, in __getattr__
    value = self.callbacks[name](self)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.5-py2.6.egg/trac/web/api.py", line 338, in <lambda>
    'args': lambda req: arg_list_to_args(req.arg_list),
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.5-py2.6.egg/trac/web/api.py", line 355, in __getattr__
    value = self.callbacks[name](self)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.5-py2.6.egg/trac/web/api.py", line 704, in _parse_arg_list
    value = unicode(value.value, 'utf-8')
UnicodeDecodeError: 'utf8' codec can't decode byte 0xff in position 37: invalid start byte

SpamFilter plugin should at least trap the UnicodeDecodeErrors so that tracebacks don't result in the log.

[Jun Omae]

No. That is not a SpamFilter issue. We can raise the same error on any components, e.g. /wiki?name=%FF, /query?name=%FF.

trac/web/api.py

@@ -702 +702 @@
             self.environ['QUERY_STRING'] = qs_on_post
 
         args = []
-        for value in fs.list or ():
-            name = value.name
-            if not value.filename:
-                value = unicode(value.value, 'utf-8')
-            args.append((name, value))
+        try:
+            for value in fs.list or ():
+                name = value.name
+                if not value.filename:
+                    value = unicode(value.value, 'utf-8')
+                args.append((name, value))
+        except UnicodeDecodeError, e:
+            raise HTTPBadRequest(_("Invalid encoding in form data: %(msg)s",
+                                   msg=exception_to_unicode(e)))
         return args
 
     def _parse_cookies(self):

After the patch, the following without traceback would be logged by invalid enoding.

2015-04-13 13:35:57,989 Trac[main] WARNING: [192.168.11.24] HTTPBadRequest: 400 Bad Request (Invalid encoding in form data: UnicodeDecodeError: 'utf8' codec can't decode byte 0xff in position 0: unexpected code byte)

I noticed that /wiki?%FF=xxxx doesn't lead the same error. I think we should decode the names to unicode with utf-8 encoding.

-            name = value.name
+            name = unicode(value.name, 'utf-8')

[Ryan J Ollos]

I added unit tests in log:rjollos.git:t12017. When merging to the trunk I'll replace except UnicodeDecodeError, e: with except UnicodeDecodeError as e:. Would you mind reviewing?

[Jun Omae]

The proposed changes look good to me.

[Ryan J Ollos]

Committed to 1.0-stable in [14095], merged to trunk in [14096].