It is possible for two people to hit cache_set() at the same time, both executing the INSERT db_query with the same cache key, one of which will generate an error. Depending on how cache_set was called, this can result in an error being written to the generated output which will be seen by anyone accessing the Drupal-powered site. The busier a site gets, the more frequent such collisions become.

To see if you are experiencing these collisions on your own Drupal site, filter on only the 'error' watchdog logs.

Drupal's custom error_handler currently logs all errors to the database, regardless of the current error level. There is no way for a developer to tell Drupal "it is okay to ignore this error, we know it will happen but it doesn't hurt anything".

The attached patch makes the error logging a configurable option. Five options are provided: Disabled, Log important errors to database, Log all errors to database, Log all errors to database and important errors to screen, and Log all errors to database and to screen.

With this patch in place, any function that may return an error but for which the error absolutely can not hurt anything should be preceeded by an '@'. Any function that is not preceeded by an '@' is considered important when it generates an error. The vast majority of functions in Drupal will not be preceeded by an '@'.

On a stable production machine not experiencing any problems, the log level should be set to 'Log important errors to database'. When troubleshooting on a production machine, the log level should be set to 'Log all errors to database'. When troubleshooting on a test machine, you could use either of the other error levels so the errors show up on the generated page.

Prior to this patch, Drupal defaults to 'Log all errors to database and important errors to screen'. In my opinion, this is too verbose for a production server. My preference would be for Drupal to default to 'Log important errors to database'. With this patch I compromise and default to 'Log all errors to database'.

Changes:
common.inc:
- make error_handler functionality configurable
bootstrap.inc:
- preceed the INSERT db_query with an @
system.module:
- provide configurable error logging setting

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

killes@www.drop.org’s picture

That's a patch isn't it ;-?

Jeremy’s picture

Any thoughts on this?

The basic premise: currently Drupal writes debug information to the screen, which is inappropriate in a production environment.

The attached patch solution: make the debug level/destination configurable.

njivy’s picture

I recently received the following error. Just to clarify, does this patch address this problem?

user error: Duplicate entry '1-1' for key 1 query: INSERT INTO history (uid, nid, timestamp) VALUES (1, 1, 1093296571) in /usr/local/www/data-dev/includes/database.mysql.inc on line 125.

I will try the patch.

njivy’s picture

The first hunk in the patch does not apply nicely. Otherwise it looks good so far!

Jeremy’s picture

FileSize
3.79 KB

Attached is an updated version of the patch that will apply cleanly against the current CVS code. (Remove the older version first) All functionality is the same, though this also updates node.module to prevent the error you report (dependent upon how you configure your site to log errors)

Jeremy’s picture

FileSize
3.81 KB

Oops, the version I just uploaded would have reverted 'strict warning' from common.inc. Fixed in this patch.

Dries’s picture

Shouldn't the new setting be part of the watchdog settings?

Jeremy’s picture

FileSize
5.21 KB

That makes sense, thus the attached patch.

I also reworded the settings to fit with the watchdog module, and added additional help text to better explain the configuration option.

Jeremy’s picture

FileSize
5.4 KB

Resync so patch applies.

Dries’s picture

I reworked the patch and committed it to HEAD.

Jeremy’s picture

Thanks, looks good. I'm glad you removed the extra complexity involved in logging non-errors.

Anonymous’s picture

bslade’s picture

Version: » 4.6.0

Also see the related issue "improved cache api - race conditions"? ( http://drupal.org/node/1811 )

Ben in DC
PublicMailbox dot benslade dot com