MySQL Bugs: #43144: Falcon Exception during pruning of table

Bug #43144	Falcon Exception during pruning of table
Submitted:	24 Feb 2009 12:56	Modified:	26 May 2010 17:52
Reporter:	Philip Stoev	Email Updates:
Status:	Unsupported	Impact on me:	None
Category:	MySQL Server: Falcon storage engine	Severity:	S1 (Critical)
Version:	6.0-falcon-team	OS:	Any
Assigned to:	Kevin Lewis	CPU Architecture:	Any
Tags:	F_RECORD TREE

Description:
When executing a RQG workload, Falcon reported the following in the error log:

Exception during pruning of table TEST.TABLE1000_FALCON_KEY_PK_PARTS_2_INT_AUTOINC#P#P0: Unknown data stream code 221
...
Exception during pruning of table TEST.TABLE1000_FALCON_KEY_PK_PARTS_2_INT_AUTOINC#P#P0: error converting to numeric from 'was90чДMW√9≤areщщщщщщщщщщщщщщщщщщщщщщщщx ⌡Ґ╙*'

The second line indicates genuine memory corruption. While the first few characters of the string are legitimate (the english word "was"), the rest is pure garbage.

How to repeat:
   perl runall.pl  --mem --rows=1000 --threads=4 --mysqld=--falcon-checkpoint-schedule='1 1 1 1 1'    --basedir=/export/home/pb2/test/sb_1-342525-1235379243.16/mysql-6.0.10-alpha-linux-x86_64-test   --mask=3334   --queries=10000000   --duration=900   --engine=Falcon   --grammar=conf/combinations.yy   --gendata=conf/combinations.zz   --reporters=Deadlock,ErrorLog,Backtrace,Recovery   --mysqld=--loose-falcon-lock-wait-timeout=1   --mysqld=--loose-innodb-lock-wait-timeout=1   --mysqld=--log-output=none   --mysqld=--skip-safemalloc

To reproduce with the RQG:

$ perl runall.pl \
  --mem \
  --rows=1000 \
  --threads=4 \
  --basedir=/build/bzr/6.0-falcon-team \
  --mask=3334 \
  --queries=10000000 \
  --duration=900 \
  --engine=Falcon \
  --grammar=conf/combinations.yy \
  --gendata=conf/combinations.zz \
  --mysqld=--loose-falcon-lock-wait-timeout=1 \
  --mysqld=--log-output=none \
  --mysqld=--skip-safemalloc

The test will not auto-detect this error. Instead, please manually monitor the error log for the problematic messages.

The workload is extremely simple INSERT/UDPATE/DELETE/SELECT scenario.

This might be the same issue as Bug#43146 where a record cannot be decoded since the data buffer has recently changed and is unuseable.

In the past, this  bug happened frequently and the attached test case reproduced the bug 100% of the time. Currently, the test case no longer triggers the bug.

However, the bug still happened twice with a binary from April 05th, on the combinations RQG runs:

./simple/vardir5/log/master.err:Exception during pruning of table TEST.TABLE10000_FALCON_KEY_PK_PARTS_2_INT_AUTOINC#P#P1: error converting to numeric from 'her95{:Є9≤how4@I@tptpasasimimqqqqakakhnhnqiqibxbxototururhmhmmdmdjkjkjujulrlrbhbh5d7≈з95K\╡6'

Again, the start of the string is a valid record value "her", followed by some garbage containing other valid values, e.g. "how".

Will convert this exception into a FATAL() in order to capture core and will upload the resulting files.

This issue has been mostly fixed and now happens very rarely. It is also not a crash. Requesting re-triage.

Unassigning myself so that this bug can be re-triaged. Let me know if you require any further information.