[drupal-devel] [bug] cache_set sometimes fails

Tue May 10 20:21:37 UTC 2005

Issue status update for http://drupal.org/node/19442

 Project:      Drupal
 Version:      cvs
 Component:    base system
 Category:     bug reports
 Priority:     critical
 Assigned to:  chx
 Reported by:  wiz
 Updated by:   chx
 Status:       patch
 Attachment:   http://drupal.org/files/issues/cache_set_2.patch (1.06 KB)

Drumm asked me to move doc into code. He is right.

chx

Previous comments:
------------------------------------------------------------------------

March 25, 2005 - 19:12 : wiz

When cache_set is called for a cache entry which already exists in that
very form (including the timestamp), the first UPDATE will change no
rows (db_affected_rows() == 0), and the subsequent INSERT will fail
because the row (i.e., the primary key) already exists.

This can happen only if calling cache_set with the same parameters
twice in one second -- but this can happen.  Example:
locale_refresh_cache() may be called often from locale() when no rows
exist in the translation_* tables (which is a bug by itself).  The
error message then is:

user error: Duplicate entry 'locale:de' for key 1
query: INSERT INTO cache (cid, data, created, expire, headers) VALUES
('locale:de', 'N;', 1111769323, 0, '') in
/var/www/drupal-cvs/includes/database.mysql.inc on line 66.

I can think of no obvious general fix, except to add another column to
cache that is updated with a random number, or to use a SELECT to check
for the existence of the row.  The function locale_refresh_cache in
locale.module seems to have a bug too (separate post).

------------------------------------------------------------------------

March 25, 2005 - 20:05 : Jeremy at kerneltrap.org

Why is this a problem?  If the cache entry is identical, why do you want
two copies of it?  It seems to me the error is expected and can be
ignored.

In any case, you can add microseconds to a timestamp if you really need
a finer granularity.  I used this method with locking.

------------------------------------------------------------------------

March 25, 2005 - 23:49 : wiz

Well, instead of a well-formed page the user just sees a blank page with
this error message - not an acceptable result, is it? Of course I don't
want two identical cache entries...

------------------------------------------------------------------------

March 26, 2005 - 15:54 : Jeremy at kerneltrap.org

Ah, I see.  Hmm, that shouldn't be a fatal error.  What if you try going
to "administer >> settings" and in the "Error handling" section set
"Error reporting" to "Write errors to the log"?

------------------------------------------------------------------------

March 26, 2005 - 16:59 : wiz

I have error logging and display enabled, and usually SQL query errors
are reported nicely.  I searched my log and found one such entry, but
not the one I posted - this error happened more than once for me.

The error results from trigger_error() in the function
database.mysql.inc:_db_query(), just as it should -- but obviously this
can happen /before/ set_error_handler is called in common.inc. The
default error handler just prints the message and terminates the
script. I tried to find out where this could happen but wasn't
successful.

------------------------------------------------------------------------

April 27, 2005 - 18:18 : lestat at www.winged.it

I experienced the same issue on 4.6.0, with Italian locale - some
strings were translated by me.
I solved with a small patch that adds a SELECT before the UPDATE.
Until someone tells me a better solution... :)

Check out at http://www.winged.it/node/136

Feedback is greatly appreciated!

------------------------------------------------------------------------

May 10, 2005 - 21:10 : chx

Attachment: http://drupal.org/files/issues/cache_set.patch (2.21 KB)

We can work around this mysql bug easily. Note that no surplus queries
are executed.

------------------------------------------------------------------------

May 10, 2005 - 21:20 : chx

Attachment: http://drupal.org/files/issues/cache_set_0.patch (2.16 KB)

Reworded the help, 'cos db_matched can return less rows than matched,
'cos it first tries mysql_affected_rows.

------------------------------------------------------------------------

May 10, 2005 - 22:01 : chx

Attachment: http://drupal.org/files/issues/cache_set_1.patch (769 bytes)

You can read about mysql connect flags on the mysql manual page of
mysql_real_connect() [1]:

CLIENT_FOUND_ROWS	 Return the number of found (matched) rows, not the
number of affected rows.

Ah! That's what we really need. PHP does not define this, but the value
of the above constant is 2.
[1] http://dev.mysql.com/doc/mysql/en/mysql-real-connect.html

------------------------------------------------------------------------

May 10, 2005 - 22:03 : chx

And note that client_flags is only supported since PHP 4.3.0.