MySQL Bugs: #35602: "Failed to read auto-increment value from storage engine" with Innodb

Bug #35602	"Failed to read auto-increment value from storage engine" with Innodb
Submitted:	27 Mar 2008 13:27	Modified:	25 Aug 2008 22:19
Reporter:	Philip Stoev
Status:	Closed
Category:	Server: InnoDB	Severity:	S2 (Serious)
Version:	5.1,6.0	OS:	Any
Assigned to:	Timothy Smith	Target Version:	5.1+
Triage:	D2 (Serious) / R3 (Medium) / E1 (None/Negligible)

Description:
A relatively simple and valid scenario containing insert/replace/update results in 1467:
Failed to read auto-increment value from storage engine, when using Innodb table.

How to repeat:
A test case will hopefully follow shortly.

Test case for bug #35602

Attachment: bug35602.zip (application/x-zip-compressed, text), 1.40 KiB.

To reproduce, please place the .txt files in mysql-test and the .test files in
mysql-test/t. Then run:

$ perl ./mysql-test-run.pl --stress --stress-init-file=bug35602_init.txt \
--stress-test-file=bug35602_run.txt --stress-threads=20 --skip-ndb \
--mysql=--innodb --stress-test-duration=65535 \
--mysqld=--falcon-consistent-read=off \
--mysqld=--innodb_lock_wait_timeout=1 --mysqld=--falcon_lock_wait_timeout=1

Let it run for 5 minutes, ignore the output the test sends to the console. Instead,
please go to mysql-test/var/stress, grep for "increment" in that directory and you will
see the offending error message. Any other error messages about deadlocks and timeouts
are dealt in separate bugs.

Please note that the table that reports the failure is view2/inter2, which is the Innodb
table.

Please accept my apologies for not simplifying the test further, after several hours I
was unable to progress further than that. If further simplification is required to fix
the bug, I will spend extra time on it.

Calvin is our 6.0 manager. Sunny is the auto-inc expert.

Yes this bug is present in the latest mysql-6.0 BK tree.

Assigned to our autoinc expert.

Philip,

Thanks for the test case. In your comment about the bug you say:
"
A relatively simple and valid scenario containing insert/replace/update
results in 1467:Failed to read auto-increment value from storage engine,
when using Innodb table.
"

Is this for a single thread or multiple threads ? For a single thread it would
certainly be an error. But for the case of multiple threads not so, there are
two runtime scenarios here:

 1.If multiple threads try and initialize the auto-inc counter
from the table only one should succeed and others should fail. This should
happen only once since the auto-inc counter is initialized only once.

 2. For old style autolocking there can be both deadlock and lock timeout errors
and that's OK too. Old style locking a.k.a. "traditional" autolock mode uses database
locking and that can cause these errors. The newer locking modes use mutexes and
shouldn't result in these errors.

I've been running your multiple threads test and haven't seen any errors so far though if
it's one of the above they are not really errors.

Regards,
-sunny

A few more observations:

* Multiple threads are involved.

* Initially the test does not produce any errors, however after running it for a while
(20 min), the errors accumulated start growing steadily and into the thousands. In other
words, there is more than one error per thread and it does not happen on test startup.

* The rest of the errors, e.g. deadlocks and timeouts, relate to a separate bug #35321.

* I think this error is insufficiently documented to say that it is OK to observe it
frequently. I would vote that we either document the error and say that it is OK to have
it, or protect the auto-increment counter (intialization) with a mutex in order to avoid
having it at all.

Verified as described.

Sunny, Philip, I hit this bug too, and made a simplified testcase, attached.

Attachment: bug35602.c (text/plain), 7.10 KiB.

The attached testcase from me gives the error on 5.1.24.

[sbester@box1 ~]$ ./bug35602 
running initializations..
client version=50125
server version=50124
about to spawn 5 threads
.....
completed spawning new database worker threads
testcase is now running, so watch for error output
<cut>
query failed 'delete from `qa05` where `d` in ('99','-54','105')' : 1213 (Deadlock found
when trying to get lock; try restarting transaction)
query failed 'replace into `qa05` (`d`) values ('13')' : 1213 (Deadlock found when trying
to get lock; try restarting transaction)
query failed 'insert into `qa05` (`d`) values ('-31')' : 1213 (Deadlock found when trying
to get lock; try restarting transaction)
query failed 'insert into `qa05` (`d`) values ('-49')' : 1467 (Failed to read
auto-increment value from storage engine)
queries: 000013120
query failed 'replace into `qa05` (`d`) values ('36')' : 1467 (Failed to read
auto-increment value from storage engine)
q

The problem for the autoinc read error is due to this code in
ha_innobase::innobase_autoinc_lock(void) (ha_innodb.cc):

                /* For simple (single/multi) row INSERTs, we fallback to the
                old style only if another transaction has already acquired
                the AUTOINC lock on behalf of a LOAD FILE or INSERT ... SELECT
                etc. type of statement. */
                if (thd_sql_command(user_thd) == SQLCOM_INSERT) {

We are not checking for SQLCOM_REPLACE therefore the replace statements are
falling back to the old style locking, this results in dead lock errors. The
simple fix is to add SQLCOM_REPLACE to the condition. I need to confirm whether
this is simply an oversight or not. I think it's an oversight because REPLACE
is classified as a "simple INSERT" in the documentation. However can someone
please check this fix (below) with replication because thats' the only
complication and the (only) reason for the special AUTOINC lock.

                /* For simple (single/multi) row INSERTs, we fallback to the
                old style only if another transaction has already acquired
                the AUTOINC lock on behalf of a LOAD FILE or INSERT ... SELECT
                etc. type of statement. */
                if (thd_sql_command(user_thd) == SQLCOM_INSERT
                    || thd_sql_command(user_thd) == SQLCOM_REPLACE) {
      
Regards,
-sunny

Sunny,

Your fix seems to work great. Using Shane's test case I don't get the error anymore.
I used mysql-5.1 from latest source tree. So we'll have to push this there too,
hopefully.

However you decide to handle this is ok with us.  We are doing some last-minute testing to
be sure there are no issues w.r.t. replication, but we expect none.  I repeat that (from
our viewpoint) this seems to be a low-risk fix that can be introduced in a release after
5.1.25.  We also don't think it is necessary or appropriate to hold 5.1.25 back waiting
for this fix.

I do want to clarify/correct Jeff's comment above: "the low incidence (will only affect
new customers using the feature)".  I don't claim to know anything about the incidence of
this issue, but because the "problem" exists in the old code, it does not affect only new
customers, and does not involve a new feature.  This affects users of the REPLACE command
when AUTOINC is involved, and the same behavior existed in 5.0.  Thus, this entire issue
is not a regression from 5.0.

What we have is a fix for the NEW algorithm introduced in 5.1.22.  Since 5.1.22, the NEW
algorithm (which is the default) does not handle REPLACE like it does other INSERT-like
statements.  Therefore the behavior reverts to the old behavior for REPLACE (regardless
of the setting for innodb_autoinc_lock_mode).  So, the fix at hand would be helpful for
users of the REPLACE command, but not applying the fix does not result in a regression.

Hope this helps.

Merged into 6.0.6-alpha, according to Tim. But the patch has not been pushed into 5.1
yet.

This has been queued into the mysql-5.1-bugteam tree, and will be pushed to main along
with the other SR51SP bugs.  Docs: please return to Patch Queued or NDI once documented
for 6.0.

Hmm ... the bug report doesn't seem to actually say what the problem *is*. There are vague
allusions to it, but no explicit statement. What should the changelog entry say? Thanks.

Paul,

The fix makes REPLACE work the same way as other "simple inserts" instead of
using the old locking algorithm. Before the fix REPLACE statements would fall
back to using the "traditional" style locking. With this fix REPLACE statements
are treated in the same way as as INSERT statements.

Regards,
-sunny

Noted in 6.0.6 changelog.

Setting report to Need Doc Info pending push of fix into 5.1.x.

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/52004

2714 Timothy Smith	2008-08-19
      Cherry-pick one change from innodb-5.1-ss2485 snapshot.  Fixes Bug#35602.
      
      Bug #35602 "Failed to read auto-increment value from storage engine" with
      Innodb
      
      The test for REPLACE was an error of ommission since it's classified as
      a simple INSERT. For REPLACE statements we don't acquire the special
      AUTOINC lock for AUTOINC_NEW_STYLE_LOCKING with this fix.

Pushed into 5.1.28  (revid:timothy.smith@sun.com-20080820004056-g05a56h7y8n0zczb) (version
source revid:azundris@mysql.com-20080821081500-f2d61fh4u61owz3p) (pib:3)

Noted in 5.1.28 changelog.

Pushed into 6.0.7-alpha  (revid:timothy.smith@sun.com-20080820004056-g05a56h7y8n0zczb)
(version source revid:sven@mysql.com-20080818195835-r615g9zz6xphmkzg) (pib:3)

sunny, should SQLCOM_INSERT_SELECT also have been handled ?