Improve debug logging for request handling

[anatoly techtonik <techtonik@…>]

The patch below improves debugging for Trac by logging names of request handler chosen to proces given request and result of its processing.

trac/web/main.py

@@ -200 +200 @@
                     # was found or not
                     chosen_handler = self._pre_process_request(req,
                                                             chosen_handler)
+                    self.log.debug('Choosing %r as request handler' % chosen_handler)
                 except TracError, e:
                     raise HTTPInternalError(e)
                 if not chosen_handler:
@@ -244 +245 @@
                         req.session.save()
                         req.display(template, content_type or 'text/html')
                     else: # Genshi
+                        self.log.debug('Rendering response from handler')
                         template, data, content_type = \
                                   self._post_process_request(req, *resp)
                         if 'hdfdump' in req.args:
@@ -260 +262 @@
                             req.session.save()
                             req.send(output, content_type or 'text/html')
                 else:
+                    self.log.debug('No response from handler, enter postprocessing')
                     self._post_process_request(req)
             except RequestDone:
+                self.log.debug('Escalating RequestDone exception')
                 raise
             except:
+                self.log.debug('Request error postprocessing')
                 # post-process the request in case of errors
                 err = sys.exc_info()
                 try:

[Christian Boos]

Why not, and maybe also some (optional) timings.

[Remy Blank]

Preparing for 1.0.

[Ryan J Ollos]

Proposed changes in log:rjollos.git:t10436. It didn't seem useful to add logging before RequestDone is raised, and in the case of Request error postprocessing the exception will be raised just after the statement is logged.

If there's justification for additional logging please let me know.

[Ryan J Ollos]

Committed to trunk in [14231].