Problem

  • Logged errors are confusing for users, if the module recovered from them.
  • (Too) Many debug messages are logged and shown by dblog.module (by default in D7; not filterable in D6).
  • Primary logged message is not clear.

Goal

  • Log only one message per request (or high-level action performed).
  • Make the single log entry show the primary message first.
  • Retain additional messages within the single log message (i.e., append them).

Details

  • Mollom produces a lot of log messages. Mainly for debugging purposes in case of errors or when a post is treated inappropriately.
  • A single Drupal request may trigger multiple Mollom requests being logged, as well as "functional/primary" log messages generated by the business logic of the module (e.g., "Unsure: %teaser").
  • Users complain about the amount of log messages. The amount is not an issue for syslog, but can be an issue for dblog on large-scale sites.
  • The module recovers from certain errors, but it also logs any errors that occur, regardless of whether the final operation is successful or not.
  • Most logged messages are debug messages, primarily important for functional module tests.
  • For Mollom support requests, it is helpful to see the entire stack of operations that were attempted.
  • Most messages are logged within form processing, but some others are logged outside of the Form API scope.

    E.g., when an entity gets ultimately inserted or deleted, my.mollom.com may be informed about that, which triggers a separate log message.

  • The original cause for this issue is obsolete, since the client-side server fail-over logic has been removed.

OP by @Dries

When looking at the watchdog, it is not clear that the fail-over is working. Quite the contrary, people might believe that Mollom might be down or broken because they sometimes see error messages. I think we should make it more clear that the fail-over is working.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

Dries’s picture

FileSize
230.31 KB

error.jpg

sun’s picture

sun’s picture

Version: 7.x-1.x-dev » 6.x-1.x-dev
Status: Active » Needs review
FileSize
975 bytes

Attached patch should fix this issue by hiding non-severe log messages.

We can't really do much on 2), since dblog's theme function enables the $wordsafe parameter of truncate_utf8()... we're already doing the best we can do to improve the message summaries in the overview :(

Dries’s picture

Maybe instead of a setting called mollom_testing_mode we should have another setting like mollom_verbose_debug?

Here are two reasons why:

1) As a Mollom developer, I'd want to see the extra information on a production site.

2) As a Mollom developer or support engineer, I'd want to tell Mollom users to provide me additional debug information on a production site

sun’s picture

Title: Not clear that fail-over is working » Revamp and reduce log messages (was: Not clear that fail-over is working)
Version: 6.x-1.x-dev » 7.x-2.x-dev
Status: Needs review » Active

As mentioned in #903770-10: Integrate with Mollom moderation:

These log messages are very "debug-ish", and should ideally not exist. However, the code and requests performed might still contain edge-casey bugs, so it would be good to keep them for a bit longer.

Ideally, we'd consolidate them into other log messages, but since these are effectively logged after a form submission has been processed, and generally outside of Form API callbacks/hooks/interaction, it's going to be hard to "hide" them.

The only way I can think of would be a hook_page_footer() implementation that basically captures all logged messages that happened in the request, formats them, and puts them into a single watchdog message.

sun’s picture

Assigned: Unassigned » sun
Priority: Normal » Critical
Issue tags: +Release blocker, +D7 stable release blocker
sun’s picture

Issue summary: View changes

Updated issue summary.

sun’s picture

Issue summary: View changes

Updated issue summary.

sun’s picture

Issue summary: View changes

Updated issue summary.

sun’s picture

Status: Active » Needs review
FileSize
21.05 KB

Alright, this was a lot more work than originally estimated. After experimenting with 2-3 prototypes, I had to come back to this issue and write down the precise problems/goals/details in the issue summary in order to make sense of the task.

Not 100% complete yet, but attached patch works.

Status: Needs review » Needs work

The last submitted patch, mollom.log_.7.patch, failed testing.

sun’s picture

Status: Needs work » Needs review
FileSize
34.92 KB

Final conversion of everything, more docs, and resolved todos.

sun’s picture

FileSize
34.92 KB

Testbot seems to be stuck on that patch for some unknown reason.

@see #1460784: XMLRPC failing between testbot and qa

sun’s picture

Version: 7.x-2.x-dev » 6.x-2.x-dev
Status: Needs review » Patch (to be ported)

Ran tests manually and committed to 7.x-2.x.

sun’s picture

Status: Patch (to be ported) » Fixed

Committed to 6.x-2.x, too.

Status: Fixed » Closed (fixed)
Issue tags: -Release blocker, -D7 stable release blocker

Automatically closed -- issue fixed for 2 weeks with no activity.

Anonymous’s picture

Issue summary: View changes

Updated issue summary.

  • Commit 25933a8 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1000690 by sun: Fixed log entry without message on CAPTCHA-only...
  • Commit 4c9eb70 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1000690 by sun: Revamped log messages.
    
    
  • Commit d67dd2f on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1000690 by sun: Revamped log messages.
    
    

  • Commit 25933a8 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1000690 by sun: Fixed log entry without message on CAPTCHA-only...
  • Commit 4c9eb70 on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1000690 by sun: Revamped log messages.
    
    
  • Commit d67dd2f on 7.x-2.x, 8.x-2.x, fbajs, actions by sun:
    - #1000690 by sun: Revamped log messages.