Opened 10 years ago

Closed 10 years ago

Last modified 7 years ago

#1889 closed enhancement (fixed)

Print stack when encountering an exception during log formatting

Reported by: sascha_silbe Owned by: sascha_silbe
Priority: High Milestone:
Component: Sugar Version: Git as of bugdate
Severity: Blocker Keywords: r+
Cc: tomeu, bernie Distribution/OS: Unspecified
Bug Status: Assigned

Description

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.

Attachments (1)

0001-Print-stack-when-encountering-an-exception-during-lo.patch (1.4 KB) - added by sascha_silbe 10 years ago.
Print stack when encountering an exception during log formatting

Download all attachments as: .zip

Change History (9)

Changed 10 years ago by sascha_silbe

Print stack when encountering an exception during log formatting

comment:1 Changed 10 years ago by tomeu

  • Keywords r! added; r? removed

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!

comment:2 Changed 10 years ago by sascha_silbe

  • Cc tomeu added
  • Keywords r? added; r! removed

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()

comment:3 Changed 10 years ago by bernie

  • Cc bernie added

comment:4 follow-up: Changed 10 years ago by tomeu

  • Keywords r+ added; r? removed

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

comment:5 in reply to: ↑ 4 Changed 10 years ago by 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
  1. 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.

comment:6 Changed 10 years ago by erikos

Ping, Sascha do you still want to push this?

comment:7 Changed 10 years ago by sascha_silbe

  • Milestone changed from 0.88.x to 0.90
  • Resolution set to fixed
  • Status changed from new to closed

Pushed as ccffdaf, thanks!

comment:8 Changed 7 years ago by dnarvaez

  • Milestone 0.90 deleted

Milestone 0.90 deleted

Note: See TracTickets for help on using tickets.