Print stack when encountering an exception during log formatting

[sascha_silbe]

Another ticket I thought I'd already submitted - but apparently not.

When encountering an exception during log formatting, the default log handler only shows a backtrace up to the logging function, hiding the actual place of the error. By printing the stack in addition to the exception, we can pinpoint the faulty log statement.

[sascha_silbe]

Print stack when encountering an exception during log formatting

[tomeu]

Hi, have tried reproducing what I understand this patch addresses but without much luck. Can you attach the output before and after or a small script that shows its effects? Thanks!

[sascha_silbe]

Without patch:

Traceback (most recent call last):
  File "/usr/lib/python2.5/logging/__init__.py", line 744, in emit
    msg = self.format(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 630, in format
    return fmt.format(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 418, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.5/logging/__init__.py", line 288, in getMessage
    msg = msg % self.args
TypeError: int argument required

With patch:

Traceback (most recent call last):
  File "/usr/lib/python2.5/logging/__init__.py", line 744, in emit
    msg = self.format(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 630, in format
    return fmt.format(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 418, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.5/logging/__init__.py", line 288, in getMessage
    msg = msg % self.args
TypeError: int argument required
  File "/home/sascha.silbe/sugar-jhbuild/install/bin/sugar-session", line 270, in <module>
    main()
  File "/home/sascha.silbe/sugar-jhbuild/install/bin/sugar-session", line 260, in main
    gtk.main()
  File "/home/sascha.silbe/sugar-jhbuild/install/lib/python2.5/site-packages/jarabe/controlpanel/gui.py", line 321, in __select_option_cb
    self.show_section_view(option)
  File "/home/sascha.silbe/sugar-jhbuild/install/lib/python2.5/site-packages/jarabe/controlpanel/gui.py", line 218, in show_section_view
    self._options[option]['alerts'])
  File "/home/sascha.silbe/sugar-jhbuild/install/share/sugar/extensions/cpsection/aboutcomputer/view.py", line 55, in __init__
    logging.debug('foo %d', 'bar')
  File "/usr/lib/python2.5/logging/__init__.py", line 1327, in debug
    apply(root.debug, (msg,)+args, kwargs)
  File "/usr/lib/python2.5/logging/__init__.py", line 971, in debug
    apply(self._log, (DEBUG, msg, args), kwargs)
  File "/usr/lib/python2.5/logging/__init__.py", line 1101, in _log
    self.handle(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 1111, in handle
    self.callHandlers(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 1148, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 655, in handle
    self.emit(record)
  File "/usr/lib/python2.5/logging/__init__.py", line 757, in emit
    self.handleError(record)
  File "/home/sascha.silbe/sugar-jhbuild/install/lib/python2.5/site-packages/sugar/logger.py", line 113, in handleError
    traceback.print_stack()

[tomeu]

Thanks, though would be great if we could remove the logging-specific lines from the traceback.

[sascha_silbe]

Replying to tomeu:

Thanks, though would be great if we could remove the logging-specific lines from the traceback.

I just looked into that, but don't consider it useful because:

1. print_exception(): We could print the exception as a simple string instead of as a traceback, but I think that would make it harder to understand what's going on. Compare

      Traceback (most recent call last):
        File "/usr/lib/python2.5/logging/__init__.py", line 744, in emit
          msg = self.format(record)
        File "/usr/lib/python2.5/logging/__init__.py", line 630, in format
          return fmt.format(record)
        File "/usr/lib/python2.5/logging/__init__.py", line 418, in format
          record.message = record.getMessage()
        File "/usr/lib/python2.5/logging/__init__.py", line 288, in getMessage
          msg = msg % self.args
      TypeError: int argument required
   

with

Exception in log handler: int argument required

2. print_stack(): We could apply some magic to remove the last 8 entries from the traceback, but it would be somewhat complex and potentially fragile. Given that exceptions in log handlers are rare, I'd rather apply KISS than trim a few unnecessary lines.

[erikos]

Ping, Sascha do you still want to push this?

[sascha_silbe]

Pushed as ​ccffdaf, thanks!

[dnarvaez]

Milestone 0.90 deleted