watchdog() passes the global $user object in the log record. dblog.module assumes $user is defined when watchdog is called:

function dblog_watchdog(array $log_entry) {
  Database::getConnection('default', 'default')->insert('watchdog')
    ->fields(array(
      'uid' => $log_entry['user']->uid,

The problem is that watchdog() can be called after global objects like $user is destructed, for example when a global output buffer handler is invoked (boost.module does this). The result is a PHP Warning because $user->uid is undefined.

If watchdog() may not be called under these conditions, it should be documented as such. Otherwise, it should have a fallback for when $user is not defined.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

deekayen’s picture

Status: Active » Needs review
FileSize
900 bytes

This adds an isset check to the uid. If not set, it assigns uid 0.

grendzy’s picture

Status: Needs review » Needs work

The code makes sense to me. It would probably benefit from a comment explaining that $user might not be there. Also it could be condensed as a ternary conditional.

grendzy’s picture

Status: Needs work » Needs review
FileSize
823 bytes
Morbus Iff’s picture

Status: Needs review » Needs work

+ // The user object may exist in all conditions, so 0 is substituted if needed.

You're missing "NOT".

grendzy’s picture

Status: Needs work » Needs review
FileSize
827 bytes

good catch! thanks.

Morbus Iff’s picture

Hrm. Will this cause a NOTICE when we check for isset() on a non-existent object? If $user is being destroyed before watchdog gets to it, then $log_entry['user'] won't exist at all (right?). In which case, we might get a NOTICE for checking on ->uid when $log_entry['user'] isn't there either? (I don't have a reliable way to test/create the fail case this is fixing…)

grendzy’s picture

isset seems to tolerate a non-existant $log_entry['user']. I also have no idea how to reproduce the actual issue though.

deekayen’s picture

@morbus since isset is a language construct, not a function and is designed to check for the the possible destruction caused by unset(), it and empty() I think are the only ways to safely check a non-existent variable without a notice.

In other words, it shouldn't cause a NOTICE if the variable isn't there.

Morbus Iff’s picture

Status: Needs review » Reviewed & tested by the community
dawehner’s picture

Version: 7.x-dev » 8.x-dev
Issue tags: +Needs backport to D7
Dries’s picture

Status: Reviewed & tested by the community » Fixed

Committed to 8.x and 7.x. Thanks.

bfroehle’s picture

Issue tags: -Needs backport to D7

Untagging since it's been committed to 7.x

gpk’s picture

Status: Fixed » Needs work

This fixes the problem for dblog_watchdog(), but not syslog_watchdog(). In any case, is fixing the problem this way in hook_watchdog() the best fix for this? There seems not much point in including $user in $log_entry if $user might sometimes be empty, requiring workarounds. Also there is a difference between user anonymous and $user undefined, but maybe that's a nicety that's not worth capturing.

matglas86’s picture

Version: 8.x-dev » 7.x-dev
Status: Needs work » Needs review
FileSize
2.44 KB
1.21 KB

I fixed it the same way as the previous patch does but now for syslog_watchdog.

I looked at hook_watchdog. The only way I can think of doing this is adding a extra element uid to the array and use that in other methods and have user as a seperate object there.

There is a example of that in the second patch.

Status: Needs review » Needs work

The last submitted patch, 598586-watchdog-13-2.patch, failed testing.

dawehner’s picture

Version: 7.x-dev » 8.x-dev
Status: Needs work » Needs review
FileSize
4.09 KB

Things should first be fixed in drupal8 and then be backported to 7.x

Here is a patch which fixes the tests in the second patch, as i think fixing this in watchdog() is the right place to do it.

Though there were some problems with the test, as they uses raw db_watchdog which changes.
In general i think db_watchdog doesn't have to check that, because people should just use watchdog() though i'm not sure about that.

Status: Needs review » Needs work

The last submitted patch, 598586-watchdog-16.patch, failed testing.

dawehner’s picture

Status: Needs work » Needs review

#16: 598586-watchdog-16.patch queued for re-testing.

matglas86’s picture

Status: Needs review » Reviewed & tested by the community

The last patch is for 8.x. I looked at it and to me it looks ready for commit.

catch’s picture

Version: 8.x-dev » 7.x-dev
Status: Reviewed & tested by the community » Patch (to be ported)
Issue tags: +Needs backport to D7

Looks good. Committed/pushed to 8.x, moving to 7.x for backport.

Zgear’s picture

FileSize
3.99 KB

I applied the patch in 7.x then did a git diff, it worked without a hitch so here is your backport ^^

Zgear’s picture

Status: Patch (to be ported) » Needs review
xjm’s picture

Status: Needs review » Reviewed & tested by the community

It has the correct number of fingers and toes, and no D8-specific anythings => RTBC. Thanks @Zgear!

webchick’s picture

Status: Reviewed & tested by the community » Fixed

Committed and pushed to 7.x. Thanks!

gpk’s picture

Version: 7.x-dev » 8.x-dev
Status: Fixed » Needs work
Issue tags: +Needs documentation

I'm a bit out of the loop these days but would I be right in thinking that the new key 'uid' in $log_entry needs some documentation? No mention of it in http://api.drupal.org/api/drupal/core!modules!system!system.api.php/function/hook_watchdog/8

Zgear’s picture

Shouldn't we just create a follow up issue for that?

xjm’s picture

Regarding #26, @gpk is correct. Proper documentation is one of the core gates:
http://drupal.org/core-gates

tim.plunkett’s picture

Status: Needs work » Needs review
FileSize
1.1 KB

Here's a first attempt.

xjm’s picture

Status: Needs review » Reviewed & tested by the community
Issue tags: -Needs documentation

This looks correct to me.

Dries’s picture

Version: 8.x-dev » 7.x-dev

Committed to 8.x. Thanks. Moving to 7.x.

tim.plunkett’s picture

FileSize
1.08 KB

Rerolled to fix offset just in case.

David_Rothstein’s picture

Status: Reviewed & tested by the community » Fixed

Status: Fixed » Closed (fixed)
Issue tags: -Needs backport to D7

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