Bug #30124 Falcon: UPDATE has unacceptable performance
Submitted: 30 Jul 2007 11:15 Modified: 31 Aug 2007 12:30
Reporter: Hakan Küçükyılmaz Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S2 (Serious)
Version: OS:Any
Assigned to: Kevin Lewis CPU Architecture:Any
Tags: F_PERFORMANCE, UPDATE

[30 Jul 2007 11:15] Hakan Küçükyılmaz
Description:
An UPDATE on a 10 million rows table takes too much time with Falcon.

How to repeat:
SET @@autocommit = 1;
DROP TABLE IF EXISTS t1;
CREATE TABLE t1 (a int auto_increment PRIMARY KEY, b int) Engine Falcon;
INSERT INTO t1 (b) VALUES (1), (2), (3), (4), (5), (6), (7), (8), (9), (0);
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;
INSERT INTO t1 (b) SELECT b from t1;

SELECT COUNT(*) FROM t1;

UPDATE t1 SET b = 5 WHERE b = 3;

I gave up after 10 hours runtime on dual-core Intel 2.3GHz. 1GB machine.

OS X profiler Shark shows 99% CPU time spent in
  Transaction::removeRecord()
[30 Jul 2007 21:53] Hakan Küçükyılmaz
Extended test with 10k - 1mio rows. Please note that 1/10 of total rows get updated.

This time I used a stored procedure to load the initial data. Loop counter was changed each round accordingly.

SET @@autocommit=0;

DROP TABLE IF EXISTS t1;
DROP PROCEDURE IF EXISTS p1;
DEALLOCATE PREPARE stmt1;

CREATE TABLE t1 (
  a int auto_increment PRIMARY KEY,
  b int
) Engine Falcon;

PREPARE stmt1 FROM
  'INSERT INTO t1 (b) VALUES (?)';

DELIMITER //

CREATE PROCEDURE p1()
BEGIN
  SET @i = 0;
  SET @v = 0;

  WHILE @i < 1000 * 1000 DO
    IF mod(@i, 10000) = 0 THEN
      SELECT @i;
    END IF;

    SET @a = @v;

    EXECUTE stmt1 USING @a;

    SET @v = @v + 1;
    IF @v = 10 THEN
      SET @v = 0;
    END IF;

    SET @i = @i + 1;
  END WHILE;
END;
//

DELIMITER ;
CALL p1;
COMMIT;

SET @@autocommit = 1;
SELECT count(*) from t1;
UPDATE t1 SET b = 5 WHERE b = 3;

10k:
[19:05] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 1000 rows affected (0.19 sec)
Rows matched: 1000  Changed: 1000  Warnings: 0

100k:
[19:12] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 10000 rows affected (4.84 sec)
Rows matched: 10000  Changed: 10000  Warnings: 0

200k:
[19:14] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 20000 rows affected (15.43 sec)
Rows matched: 20000  Changed: 20000  Warnings: 0

300k:
[19:16] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 30000 rows affected (37.97 sec)
Rows matched: 30000  Changed: 30000  Warnings: 0

400k:
[19:21] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 40000 rows affected (1 min 49.40 sec)
Rows matched: 40000  Changed: 40000  Warnings: 0

500k:
[19:27] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 50000 rows affected (4 min 5.02 sec)
Rows matched: 50000  Changed: 50000  Warnings: 0

600k:
[19:38] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 60000 rows affected (7 min 59.28 sec)
Rows matched: 60000  Changed: 60000  Warnings: 0

700k:
[19:55] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 70000 rows affected (14 min 42.74 sec)
Rows matched: 70000  Changed: 70000  Warnings: 0

800k:
[20:33] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 80000 rows affected (19 min 32.43 sec)
Rows matched: 80000  Changed: 80000  Warnings: 0

900k:
[21:21] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 90000 rows affected (28 min 55.31 sec)
Rows matched: 90000  Changed: 90000  Warnings: 0

1000k:
[22:11] root@test>UPDATE t1 SET b = 5 WHERE b = 3;
Query OK, 100000 rows affected (35 min 28.50 sec)
Rows matched: 100000  Changed: 100000  Warnings: 0
[30 Jul 2007 21:59] Hakan Küçükyılmaz
Falcon log during 10k, 100k, 200k, ..., 1000k runs

Attachment: lu0011.err.gz (application/x-gzip, text), 3.66 KiB.

[31 Jul 2007 11:57] MySQL Verification Team
Thank you for the bug report.
[2 Aug 2007 21:32] Kevin Lewis
In a phone conversation with Hakan, he pointed out that when this test is run with more and more records, it spends more and more time in Transaction::removeRecord.

I did not understand why Transaction::removeRecord() would be called at all on an autocommit  UPDATE t1 SET b = 5 WHERE b = 3;  So I tried it myself.  Field b has 10 possible values, 0 - 9.  So the update is changing 10% of the file.  It turns out that the other 90% of the file has been locked for Update.  So the transaction has 100% of the file with lock records on the transaction, 10% are changed, and then the server unlocks the rest of the records one at a time.  Transaction::removeRecord() traverses the list of records on the transaction via a singly-linked list until it finds the record to unlock.

This test updates a field that is not indexed, to the filter is not pushed down to Falcon.  This is why all records are locked for the update.

So unlocking records at the end of a transaction is very inefficient in Falcon as the transaction gets larger.  I suggest that we use a doubly-linked list of RecordVersions on a Transaction so that they can be taken out quickly.  Then the performance will be linear to the size of the transaction.

The other solutions would be;
1) Have the server issue some kind of 'unlockAll'.
2) Have the server not unlock anything, and let Falcon unlock records automatically at the Transaction commit.
[3 Aug 2007 8:44] Calvin Sun
Another option: lock escalation - escalate from record locks to table lock at certain threshold.
[22 Aug 2007 19:20] Kevin Lewis
Pushed a fix that makes RecordVersions doubly linked on the Transaction
so it can be unlinked quickly.  The testcase for this bug improved on
my system from 57 minutes to 7 seconds.
[24 Aug 2007 16:43] Kevin Lewis
A test case was generated and pushed by the developer.
mysqltest/t/falcon_bug_30124.test and
mysqltest/r/falcon_bug_30124.result

This test has a problem in that pushbuild fails with this test since it takes too long to create the file needed to test the bad performing update statement.  The developer does not know what QA should do about this naturally long running task in the test.
[29 Aug 2007 19:08] Hakan Küçükyılmaz
The performance issue is fixed and verified by test case falcon_bug_30124.test.
[31 Aug 2007 12:30] MC Brown
A note has been added to the 6.0.2 changelog: 

Updating a large table without an index would lock all the records during a transaction and unlock the records individually.