Bug #27350 test-insert, Unexpected error; "Record has changed since last read in table"
Submitted: 21 Mar 2007 17:57 Modified: 14 May 2007 18:25
Reporter: Matthias Leich Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version:5.2 OS:Any
Assigned to: CPU Architecture:Any

[21 Mar 2007 17:57] Matthias Leich
Description:
Runs of sql-bench/test-insert abort in more than 50 % of all attempts
with "Record has changed since last read in table 'bench1'" when the
masses of
   update bench1 set id3=-<number> where id3=<number;
are executed.
- The record where this error comes up varies from run to run.
- Using a VARDIR pointing into a RAM based filesystem increases
  the probability of the error.
- There is only one connection (no concurrency) and this runs with
  autocommit = 1
  (autocommit = 0 or 1 should have no influence on the outcome
   of the update).

My environment:
- MySQL-5.1-falcon last ChangeSet@1.2498.1.1, 2007-03-19
  (compile-pentium-max)
- Linux openSUSE 10.2 (X86-64), Core2Duo (x86 64 Bit)

Bug#25557 Falcon: Unexpected error; "Record has changed since last
          read in table"
might have the same reason like the current bug.
I opened this bug because Bug#25557 occurs around concurrent connections
and the testcases are more difficult to handle than my testscript.

How to repeat:
Please use my attached testscript ml003.test which is a
heavily shrinked down and modified version of test-insert.
Copy it to mysql-test/t
echo "Dummy" > r/ml003.result   # Produce a dummy file with 
                                # expected results
./mysql-test-run --mem ml003
Please look at the end of r/ml003.reject.
If you see there
  ERROR HY000: Record has changed since last read in table 'bench1'
  Got an unexpected error after 100000 + 1 - 76714 UPDATEs
  abort
than the error occured.

Alternative method (probably not running on Windows) and much
more complicated to analyze (too many different SQL statements, rows):
cd mysql-test
./mysql-test-run.pl --mem --skip-ndb \
--mysqld="--max_allowed_packet=32M --query_cache_type=1 --query_cache_size=10M \
--innodb_buffer_pool_size=512M --innodb_log_file_size=64M \
--innodb_log_buffer_size=8M --innodb_flush_log_at_trx_commit=1 \
--falcon_max_record_memory=512M --falcon_page_cache_size=16M \
--table_cache=512 --thread_cache=16 --thread_concurrency=2" \
--skip-rpl --start-and-exit
cd ../sql-bench
perl ./test-insert --log --create-options=engine="Falcon" --user=root \
     --connect-options=mysql_socket=/dev/shm/var/tmp/master.sock > prt
Inspect prt.
[21 Mar 2007 17:58] Matthias Leich
testscript

Attachment: ml003.test (application/octet-stream, text), 1.27 KiB.

[21 Mar 2007 18:22] Hakan Küçükyılmaz
I could verify the error with the testcases:
  - index_merge_falcon
  - ps_8falcon

both fail with
"Record has changed since last read in table"

Regards, Hakan
[23 Mar 2007 17:02] Hakan Küçükyılmaz
Added test case falcon_bug_27350.test which passes now. I tested the test with loop count of 1 mio but lowered it to 100k to get better run time on Pushbuild.

Best regards, Hakan
[23 Mar 2007 19:37] Matthias Leich
Sorry I cannot confirm this. You accidently lowered the number of loops
to 10k and not to 100k!
When I run falcon_bug_27350.test with 100k loops I get the unexpected
error after about 20k loops.
A run of the original test-insert benchmark reveals also the bug.

My environment:
- MySQL-5.1-falcon last ChangeSet@1.2507, 2007-03-23
  (compile-pentium-max)
- Linux openSUSE 10.2 (X86-64), Core2Duo (x86 64 Bit)
[23 Mar 2007 22:11] Hakan Küçükyılmaz
Verified by setting the loop count to 1 million.

Sorry for confusion,

Hakan
[14 Apr 2007 18:25] Hakan Küçükyılmaz
Can't verify anymore with loop count of 1 mio.

Matthias, please recheck.

Best regards,

Hakan
[14 May 2007 23:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".