#975: WSGI: simplify IOError exception logging
-------------------+----------------------
Reporter: simko | Owner: skaplun
Type: defect | Status: new
Priority: major | Component: WebStyle
Version: | Keywords:
-------------------+----------------------
WSGI handler is logging too many IOError exceptions. Logging these
exceptions may clutter log file considerably, example for one CDS worker
node:
{{{
* 2012-03-28 14:15:40 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:15:40 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:18:26 -> IOError: failed to write data
(webinterface_handler_wsgi.py:178:flush)
* 2012-03-28 14:19:23 -> IOError: failed to write data
(webinterface_handler_wsgi.py:178:flush)
* 2012-03-28 14:20:21 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:21:32 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:22:34 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:23:10 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:23:25 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:26:32 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:28:48 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:28:48 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:28:48 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:29:23 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:30:22 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:30:45 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:40:52 -> IOError: failed to write data
(webinterface_handler_wsgi.py:180:flush)
* 2012-03-28 14:51:31 -> IOError: failed to write data
(webinterface_handler_wsgi.py:178:flush)
}}}
Example for one INSPIRE worker node:
{{{
* 2012-03-28 13:08:30 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:10:50 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:18:50 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:29:48 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:40:18 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:50:03 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:51:49 -> IOError: failed to write data
(webinterface_handler_wsgi.py:179:flush)
* 2012-03-28 13:53:57 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:56:10 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:58:20 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:59:36 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 13:59:37 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:02:51 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:03:03 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:27:21 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:29:57 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:30:02 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:30:11 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:34:22 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:52:29 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
* 2012-03-28 14:54:26 -> IOError: failed to write data
(webinterface_handler_wsgi.py:181:flush)
}}}
I guess these are never looked at by the admins and so probably mostly get
ignored. This means that logging them is not very useful. Already these
exceptions were black-listed for email reporting. In case of user storms,
analysing the traceback and logging these possibly not exploitable
exceptions just unnecessarily eats from available CPU time.
We can improve the situation by simply logging the exception title without
doing traceback analysis. That is, this will keep the exception count in
the logs for stats and possible forensics and other purposes, but it will
treat the exception body as not useful to keep, and so not logged. This
will make logging faster, log files smaller, and stuff.
There may be more exceptions of this sort where analysing and logging the
exception body is not needed, so this feature may be generally useful.
New optional argument named like `perform_analysis=True` in
`register_exception()` could do the job nicely.
P.S. Even better would be to try to fix WSGI connection write failures, of
course.
--
Ticket URL: <http://invenio-software.org/ticket/975>
Invenio <http://invenio-software.org>
