We have been having problems using watchdog to debug calls made to and results returned from integrating with a 3rd party app.

Some of the watchdog entries that are being recorded faithfully in the database just didn't show up under admin/reports/dblog

After some hunting, it seems the problem is coming from code/html in the sent and returned values being changed into a link without some filtering/escaping. Adding check_plain() to the text that will form the link sorts out the problem.

Another small issues is that with data coming through and truncate_utf8 breaking on word boundaries, it becomes hard to distinguish between the messages. There are already ... being appended, so maybe not breaking only on word boundaries is better for watchdog reporting.

The patch that fixes this is:

--- dblog.admin.inc.orig        2009-06-28 10:49:25.000000000 +0200
+++ dblog.admin.inc     2009-06-28 11:12:06.000000000 +0200
@@ -78,7 +78,7 @@
         $icons[$dblog->severity],
         t($dblog->type),
         format_date($dblog->timestamp, 'small'),
-        l(truncate_utf8(_dblog_format_message($dblog), 56, TRUE, TRUE), 'admin/reports/event/'. $dblog->wid, array('html' => TRUE)),
+        l(check_plain(truncate_utf8(_dblog_format_message($dblog), 56, FALSE, TRUE)), 'admin/reports/event/'. $dblog->wid, array('html' => TRUE)),
         theme('username', $dblog),
         $dblog->link,
       ),

(Attached as well)

CommentFileSizeAuthor
#3 d7-dblog_html_flag.patch889 bytesTresler
dblog-checkplain.patch597 bytesasciikewl

Comments

Tresler’s picture

Tresler commented

Something is redundant here. the l() function specifically sets array('html' => TRUE). all that does is bypass the check plain in the l() function here:

return ''. ($options['html'] ? $text : check_plain($text)) .''

You could acheive the same affect by removing that parameter, but why is it there in the first place is my question?

damien tournoud’s picture

damien tournoud commented
Version: 6.12 » 7.x-dev

The first part of the problem is by design. The $message passed to watchdog() *is* HTML and you are supposed to pass it to check_plain() if needed. But, the following code breaks horribly:

l(truncate_utf8(_dblog_format_message($dblog), 56, TRUE, TRUE), 'admin/reports/event/'. $dblog->wid, array('html' => TRUE))

... especially if you have a lot of markup in the first 56 characters of the message.

Let's try to be a bit smarter about this.

Bumping to D7, as bugs need to be fixed there before being backported.

Tresler’s picture

Tresler commented
Status: Active » Needs review
StatusFileSize
new d7-dblog_html_flag.patch889 bytes

Feel free to correct me, but I don't see why the message and variables in the database log will ever need to contain html. I suppose you may want to return something bold or italic, but I think that is what the severity icon is for. similarly we can control the table rows with CSS classes. What in the actual message would require html?

Patch attached to remove the HTML flag from the l(). Leave open for backporting if accepted.

damien tournoud’s picture

damien tournoud commented
Status: Needs review » Needs work

watchdog messages *are* HTML, because they are the result of a call to t(), which returns HTML. See http://api.drupal.org/api/function/_dblog_format_message/7

Tresler’s picture

Tresler commented

Sorry Damien, submitted before seeing your comment. We /do/ want html there? Ok.

jhodgdon’s picture

jhodgdon
she/her
Primary language English
commented

Just as a note, truncate_utf8( $, $, TRUE, whatever) will NOT work for CJK languages, because they don't have spaces as word boundaries. And truncate_utf8 is a byte-truncation, not character-truncation function. Should probably be using drupal_substr().

For more, see
http://drupal.org/node/269911#comment-2795478
#200185: truncate_utf8() is used as a substring function

jhodgdon’s picture

jhodgdon
she/her
Primary language English
commented

See
#768040: truncate_utf8() only works for latin languages (and drupal_substr has a bug)
for discussions on truncate_utf8()

jhodgdon’s picture

jhodgdon
she/her
Primary language English
commented
Status: Needs work » Closed (duplicate)

So I think that the root causes of this issue were fixed in #718662: DBLog listings truncate messages in the middle of HTML tags.

The patch there (committed a while back) did this to format the watchdog page:

+      // Truncate message to 56 chars.
+      $output = truncate_utf8(filter_xss($output, array()), 56, TRUE, TRUE);
+      $output = l($output, 'admin/reports/event/' . $event->wid, array('html' => TRUE));
+    }

So it is filtering out all HTML tags before making the link message, and should fix the reported problem here.

And I am tentatively going to mark this issue as a duplicate... Feel free to reopen if there is still a problem.