[MDEV-20354] All but last insert ignored in InnoDB tables when table locked Created: 2019-08-15  Updated: 2020-12-08  Resolved: 2019-10-30

Status: Closed
Project: MariaDB Server
Component/s: Data Manipulation - Insert, Locking
Affects Version/s: 10.1, 10.4.6, 10.2, 10.3, 10.4
Fix Version/s: 10.2.28, 10.1.42, 10.3.19, 10.4.9

Type: Bug Priority: Blocker
Reporter: William Turrell Assignee: Sergei Golubchik
Resolution: Fixed Votes: 1
Labels: insert, lock
Environment:

macOS High Sierra 10.13.6, homebrew install stable 10.4.6 (bottled), mysql --version: mysql Ver 15.1 Distrib 10.4.6-MariaDB, for osx10.13 (x86_64) using readline 5.1


Attachments: File client.cnf     File mariadb-insertion-bug-demo.sql     File my.cnf     File mysql-clients.cnf     File server.cnf     Text File variables.txt    
Issue Links:
Duplicate
duplicates MDEV-20683 MariaDB Transaction insert one data 1... Closed
duplicates MDEV-20741 Inserted row missing after commit Closed

 Description   

It's common when doing bulk inserts (e.g. when importing an SQL dump) for the table to be locked first. Whenever this happens, apparently only on InnoDB tables, all but the final insert is being ignored.

$ mysqladmin create mariadb_bug
$ mysql mariadb_bug < mariadb-insertion-bug-demo.sql

Here's a demo using a standard WordPress database structure from one table, and three demo rows.

Expected: 3 rows for users foo, bar and baz

Observed - single row - the last one baz.

$ mysql mariadb_bug

MariaDB [mariadb_bug]> select * from wp_users;
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
| ID | user_login | user_pass                          | user_nicename | user_email      | user_url | user_registered     | user_activation_key | user_status | display_name |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
|  3 | baz        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | baz           | baz@example.com |          | 2017-11-14 11:19:35 |                     |           0 | baz          |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
1 row in set (0.001 sec)

I can confirm that if the inserts are batched, the last batch (of however many rows were in the insert statement) is retained.

If can also confirm the same behaviour if I run the commands manually in SQL, one at at a time, rather than piping the SQL dump in - the table has 3 rows if I omit the lock and unlock statements, but only one if I include them.

Multiple people are experiencing this with Drupal installations (either fresh installs, or when clearing the cache, which repopulates the Symfony routing table).

When testing in_ MySQL_ (installed via homebrew or other means) in the same environment, rather than mariadb, the bug doesn't appear.

It's possible this began in an earlier version than 10.4.6 (someone mentioned 10.4.4 on the above Drupal issue). I looked at the release notes for 10.4.7 (not available on Homebrew yet) and didn't spot anything related.



 Comments   
Comment by Alice Sherepa [ 2019-08-15 ]

Could you please add your .cnf file(s).
I failed to reproduce the issue on MariaDB 10.4.6, Ubuntu 16.04:

MariaDB [test]> select * from wp_users;
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
| ID | user_login | user_pass                          | user_nicename | user_email      | user_url | user_registered     | user_activation_key | user_status | display_name |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
|  1 | foo        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | foo           | foo@example.com |          | 2017-11-14 11:19:35 |                     |           0 | foo          |
|  2 | bar        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | bar           | bar@example.com |          | 2017-11-14 11:19:35 |                     |           0 | bar          |
|  3 | baz        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | baz           | baz@example.com |          | 2017-11-14 11:19:35 |                     |           0 | baz          |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
3 rows in set (0.000 sec)
 
MariaDB [test]> select version();
+----------------+
| version()      |
+----------------+
| 10.4.6-MariaDB |
+----------------+
1 row in set (0.000 sec)

Comment by William Turrell [ 2019-08-15 ]

Hi Alice, thanks for looking.

Here's the full output of 'SHOW VARIABLES': variables.txt

I don't seem to have any meaningful .cnf settings: according to this StackOverflow answer, there's no default config for Homebrew mysql (and, I assume, therefore, mariadb).

I get this if I run mariadb --help

"Default options are read from the following files in the given order:
/usr/local/etc/my.cnf ~/.my.cnf"

I all have in the former is:

# Default Homebrew MySQL server config
[mysqld]
# Only allow connections from localhost
bind-address = 127.0.0.1

and all I have in the latter (my home directory) is:

[client]
user=root
password=---redacted---
 
[mysqld]
innodb_force_recovery = 0

There's some Homebrew files here:

/usr/local/Cellar/mariadb/10.4.6/.bottle/etc/my.cnf
/usr/local/Cellar/mariadb/10.4.6/.bottle/etc/my.cnf.d
/usr/local/Cellar/mariadb/10.4.6/.bottle/etc/my.cnf.default

but there's nothing in those other than 'bind-address', and an instruction to include the other files/directory.

Comment by Alice Sherepa [ 2019-08-20 ]

I could not repeat, tried also on OS X 10.14.6, MariaDB 10.4.6, fresh installation by brew:

MariaDB [test]> LOCK TABLES `wp_users` WRITE;
Query OK, 0 rows affected (0.000 sec)
 
MariaDB [test]> /*!40000 ALTER TABLE `wp_users` DISABLE KEYS */;
Query OK, 0 rows affected, 1 warning (0.000 sec)
 
MariaDB [test]> INSERT INTO `wp_users` VALUES (1,'foo','$P$B/p0FE1jehIvSqVgw3ytaBGS1234567','foo','foo@example.com','','2017-11-14 11:19:35','',0,'foo');
Query OK, 1 row affected (0.001 sec)
 
MariaDB [test]> INSERT INTO `wp_users` VALUES (2,'bar','$P$B/p0FE1jehIvSqVgw3ytaBGS1234567','bar','bar@example.com','','2017-11-14 11:19:35','',0,'bar');
Query OK, 1 row affected (0.000 sec)
 
MariaDB [test]> INSERT INTO `wp_users` VALUES (3,'baz','$P$B/p0FE1jehIvSqVgw3ytaBGS1234567','baz','baz@example.com','','2017-11-14 11:19:35','',0,'baz');
Query OK, 1 row affected (0.000 sec)
 
MariaDB [test]> /*!40000 ALTER TABLE `wp_users` ENABLE KEYS */;
Query OK, 0 rows affected, 1 warning (0.000 sec)
 
MariaDB [test]> UNLOCK TABLES;
Query OK, 0 rows affected (0.000 sec)
 
MariaDB [test]> select * from wp_users;
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
| ID | user_login | user_pass                          | user_nicename | user_email      | user_url | user_registered     | user_activation_key | user_status | display_name |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
|  1 | foo        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | foo           | foo@example.com |          | 2017-11-14 11:19:35 |                     |           0 | foo          |
|  2 | bar        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | bar           | bar@example.com |          | 2017-11-14 11:19:35 |                     |           0 | bar          |
|  3 | baz        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | baz           | baz@example.com |          | 2017-11-14 11:19:35 |                     |           0 | baz          |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
3 rows in set (0.001 sec)
 
MariaDB [test]> select version();
+----------------+
| version()      |
+----------------+
| 10.4.6-MariaDB |
+----------------+
1 row in set (0.000 sec)
 
MariaDB [test]> \! sw_vers
ProductName:	Mac OS X
ProductVersion:	10.14.6
BuildVersion:	18G87

Comment by Elena Stepanova [ 2019-08-20 ]

wturrell,

Could you please copy-paste your script contents (followed by the final select of course) into the client and provide complete unabridged output from it, like alice did above, only starting from the very beginning, DROP TABLE IF EXISTS etc.?

Comment by William Turrell [ 2019-08-20 ]

@Elena Stepanova - done, see below.
Note this is (as per version info at end, and mentioned in original post) macOS 10.13.6 – I'll see if I can reproduce it on a system running 10.14.6 shortly.

wt@wt-macmini ~ $ mysqladmin drop mariadb_bug
Dropping the database is potentially a very bad thing to do.
Any data stored in the database will be destroyed.
 
Do you really want to drop the 'mariadb_bug' database [y/N] y
Database "mariadb_bug" dropped
wt@wt-macmini ~ $ mysqladmin create mariadb_bug
 
wt@wt-macmini ~ $ mariadb mariadb_bug
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 133
Server version: 10.4.6-MariaDB Homebrew
 
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
MariaDB [mariadb_bug]> CREATE TABLE `wp_users` (
    ->   `ID` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
    ->   `user_login` varchar(60) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
    ->   `user_pass` varchar(255) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
    ->   `user_nicename` varchar(50) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
    ->   `user_email` varchar(100) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
    ->   `user_url` varchar(100) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
    ->   `user_registered` datetime NOT NULL DEFAULT '0000-00-00 00:00:00',
    ->   `user_activation_key` varchar(255) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
    ->   `user_status` int(11) NOT NULL DEFAULT 0,
    ->   `display_name` varchar(250) COLLATE utf8_unicode_ci NOT NULL DEFAULT '',
    ->   PRIMARY KEY (`ID`),
    ->   KEY `user_login_key` (`user_login`),
    ->   KEY `user_nicename` (`user_nicename`),
    ->   KEY `user_email` (`user_email`)
    -> ) ENGINE=InnoDB AUTO_INCREMENT=12 DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
Query OK, 0 rows affected (0.072 sec)
 
MariaDB [mariadb_bug]> desc wp_users;
+---------------------+---------------------+------+-----+---------------------+----------------+
| Field               | Type                | Null | Key | Default             | Extra          |
+---------------------+---------------------+------+-----+---------------------+----------------+
| ID                  | bigint(20) unsigned | NO   | PRI | NULL                | auto_increment |
| user_login          | varchar(60)         | NO   | MUL |                     |                |
| user_pass           | varchar(255)        | NO   |     |                     |                |
| user_nicename       | varchar(50)         | NO   | MUL |                     |                |
| user_email          | varchar(100)        | NO   | MUL |                     |                |
| user_url            | varchar(100)        | NO   |     |                     |                |
| user_registered     | datetime            | NO   |     | 0000-00-00 00:00:00 |                |
| user_activation_key | varchar(255)        | NO   |     |                     |                |
| user_status         | int(11)             | NO   |     | 0                   |                |
| display_name        | varchar(250)        | NO   |     |                     |                |
+---------------------+---------------------+------+-----+---------------------+----------------+
10 rows in set (0.009 sec)
 
MariaDB [mariadb_bug]> LOCK TABLES `wp_users` WRITE;
Query OK, 0 rows affected (0.000 sec)
 
MariaDB [mariadb_bug]> /*!40000 ALTER TABLE `wp_users` DISABLE KEYS */;
Query OK, 0 rows affected, 1 warning (0.000 sec)
 
MariaDB [mariadb_bug]> INSERT INTO `wp_users` VALUES (1,'foo','$P$B/p0FE1jehIvSqVgw3ytaBGS1234567','foo','foo@example.com','','2017-11-14 11:19:35','',0,'foo');
Query OK, 1 row affected (0.003 sec)
 
MariaDB [mariadb_bug]> INSERT INTO `wp_users` VALUES (2,'bar','$P$B/p0FE1jehIvSqVgw3ytaBGS1234567','bar','bar@example.com','','2017-11-14 11:19:35','',0,'bar');
Query OK, 1 row affected (0.003 sec)
 
MariaDB [mariadb_bug]> INSERT INTO `wp_users` VALUES (3,'baz','$P$B/p0FE1jehIvSqVgw3ytaBGS1234567','baz','baz@example.com','','2017-11-14 11:19:35','',0,'baz');
Query OK, 1 row affected (0.002 sec)
 
MariaDB [mariadb_bug]> /*!40000 ALTER TABLE `wp_users` ENABLE KEYS */;
Query OK, 0 rows affected, 1 warning (0.002 sec)
 
MariaDB [mariadb_bug]> UNLOCK TABLES;
Query OK, 0 rows affected (0.000 sec)
 
MariaDB [mariadb_bug]> select * from wp_users;
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
| ID | user_login | user_pass                          | user_nicename | user_email      | user_url | user_registered     | user_activation_key | user_status | display_name |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
|  3 | baz        | $P$B/p0FE1jehIvSqVgw3ytaBGS1234567 | baz           | baz@example.com |          | 2017-11-14 11:19:35 |                     |           0 | baz          |
+----+------------+------------------------------------+---------------+-----------------+----------+---------------------+---------------------+-------------+--------------+
1 row in set (0.003 sec)
 
MariaDB [mariadb_bug]> select version();
+----------------+
| version()      |
+----------------+
| 10.4.6-MariaDB |
+----------------+
 
MariaDB [mariadb_bug]> \! sw_vers
ProductName:	Mac OS X
ProductVersion:	10.13.6
BuildVersion:	17G8030

Comment by William Turrell [ 2019-08-20 ]

So I can't reproduce it on macOS 10.14 (Mojave) either (that's the same build version as Alice).
The only caveat is I did need to wipe /usr/local/var/mysql to reinstall mariadb on my laptop.

I've diffed the SHOW VARIABLES output between the two machines - there's nothing obvious, just different character set / logfile locations, pids, random seeds etc.

Comment by Michael Sypes [ 2019-08-25 ]

I have reproduced this issue on Mojave (v10.14.6)
Starting with an empty database and running the example SQL does end up with a single row as described.

Since it was questioned earlier, I have attached my `my.conf` and `my.conf.d files`. my.cnf client.cnf mysql-clients.cnf server.cnf

Comment by John Ridgway [ 2019-09-02 ]

I have reproduced this issue on CentOS 7 with MariaDB 10.4.7. In order to get all of the INSERTs to take effect I must not lock the table, and I must use autocommit (or commit after each INSERT).

[ridgway@localhost host-migration]$ uname -a
Linux localhost.localdomain 3.10.0-957.27.2.el7.x86_64 #1 SMP Mon Jul 29 17:46:05 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
[ridgway@localhost host-migration]$ mysql --version
mysql Ver 15.1 Distrib 10.4.7-MariaDB, for Linux (x86_64) using readline 5.1
[ridgway@localhost host-migration]$ mysqld --version
mysqld Ver 10.4.7-MariaDB for Linux on x86_64 (MariaDB Server)
[ridgway@localhost host-migration]$

Comment by William Turrell [ 2019-09-02 ]

@John Ridgway thanks, someone else had problems with Drupal on CentOS 7, but when I tested it on a clean virtual server I couldn't reproduce it, either with the default mariadb version or one from http://archive.mariadb.org/ - would you be able to confirm the source of the package you're using?

Comment by John Ridgway [ 2019-09-02 ]

From the end of "yum install mariadb-server mariadb-client" (the rest had scrolled off the terminal):

Installed:
MariaDB-client.x86_64 0:10.4.7-1.el7.centos
MariaDB-compat.x86_64 0:10.4.7-1.el7.centos
MariaDB-server.x86_64 0:10.4.7-1.el7.centos

Dependency Installed:
MariaDB-common.x86_64 0:10.4.7-1.el7.centos
boost-program-options.x86_64 0:1.53.0-27.el7
galera-4.x86_64 0:26.4.2-1.rhel7.el7.centos

Replaced:
mariadb.x86_64 1:5.5.60-1.el7_5 mariadb-libs.x86_64 1:5.5.60-1.el7_5
mariadb-server.x86_64 1:5.5.60-1.el7_5

The contents of the file /etc/yum.repos.d/MariaDB.repo are:

[mariadb]
name = MariaDB
baseurl = http://yum.mariadb.org/10.4/centos7-amd64
gpgkey=https://yum.mariadb.org/RPM-GPG-KEY-MariaDB
gpgcheck=1

Comment by Elena Stepanova [ 2019-09-27 ]

jridgway@commongood.earth,

By any chance, would it be possible to give a temporary access to our developer to your CentOS where the problem is reproducible?

If not, could you please repeat the exercise from mariadb-insertion-bug-demo.sql , but run SELECT * FROM wp_users after each INSERT?

Comment by Eugene Kazakov [ 2019-10-22 ]

The problem is producible on CentOS 7 after an upgrade of the MariaDB-server package from 5.5.64 (from the base repo) to 10.4.8 (from the MariaDB repo).
Even if the database is created after the upgrade, the issue with LOCK TABLES or START TRANSACTION occurs.
I can provide access to my test server.

Comment by Elena Stepanova [ 2019-10-22 ]

ekazakov: That's great, thanks. I'll email you for the details.

Comment by Elena Stepanova [ 2019-10-22 ]

The problem occurs as described if the server is missing one (or all) of statistical tables mysql.table_stats, mysql.index_stats, mysql.column_stats.

The most likely reason for the missing tables is that the instance was upgraded from MariaDB 5.5 (as it was in Eugene's case), or crossgraded from MySQL or Percona server, and mysql_upgrade was not run or did not succeed. You might not even be aware that the instance had an old server before, especially if it's installed as a part of another product, which might be why nobody mentioned it before.

RPM-based systems don't run mysql_upgrade automatically upon installation, and probably Mac packages don't either.

If mysql_upgrade wasn't run, the server is likely to complain upon startup in the error log about a wrong structure of mysql.event table and some other missing tables (but not about the tables which actually cause the failure). However, on package installations the error log is typically written to /var/log/messages or /var/log/syslog, so errors are easy to miss.

Another symptom is the error message

2019-10-23  2:07:11 9 [ERROR] Transaction not registered for MariaDB 2PC, but transaction is active

In the scenario which reporters complained about, it is written to the error log upon UNLOCK TABLES execution.

Anyone who experiences it (wturrell, msypes, jridgway@commongood.earth, ekazakov, and those who didn't comment) – could you please check whether you are missing any of mysql.table_stats, mysql.index_stats, mysql.column_stats, and if you do, run mysql_upgrade on the instance (use --force option if it refuses to run otherwise) and then check whether the problem disappears.

Comment by Elena Stepanova [ 2019-10-23 ]

MTR test case which (artificially) represents the use case described above by removing one of stat tables:

--source include/have_innodb.inc
 
rename table mysql.table_stats to mysql.table_stats_save;
flush tables;
 
set use_stat_tables= PREFERABLY;
 
create table t1 (a int) engine=InnoDB;
lock table t1 write;
insert into t1 values (1);
select * from t1;
 
# Cleanup
drop table t1;
rename table mysql.table_stats_save to mysql.table_stats;
flush tables;

10.3 803d0521a

select * from t1;
a
drop table t1;

2019-10-23 13:59:53 9 [ERROR] Transaction not registered for MariaDB 2PC, but transaction is active

The problem is reproducible on all 10.x with engine-independent statistics enabled, but it is mainly observed on 10.4 because on 10.4 the EITS is enabled by default.

Similar with START TRANSACTION instead of LOCK TABLE (this variation was earlier reported at stackoverflow:

--source include/have_innodb.inc
 
rename table mysql.table_stats to mysql.table_stats_save;
flush tables;
 
set use_stat_tables= PREFERABLY;
 
create table t1 (a int) engine=InnoDB;
start transaction;
insert into t1 values (1);
insert into t1 values (2);
commit;
select * from t1;
 
# Cleanup
drop table t1;
rename table mysql.table_stats_save to mysql.table_stats;
flush tables;

select * from t1;
a
2

2019-10-23 14:25:04 139778672727808 [ERROR] Transaction not registered for MySQL 2PC, but transaction is active

Comment by Sergey Vojtovich [ 2019-10-23 ]

Blocker because incorrect results after upgrade to 10.4 where EITS is enabled by default.

Comment by Michael Sypes [ 2019-10-25 ]

I have none of the tables mentioned, neither mysql.table_stats, mysql.index_stats, nor mysql.column_stats. The closest I see are mysql.columns_priv and mysql.tables_priv.
I'm uncertain from the wording above whether the instruction to run mysql_upgrade is to be performed if they don't exist, or if they do exist, so I'll wait for clarification on that.

Comment by Elena Stepanova [ 2019-10-25 ]

Sorry. Yes, if the tables don't exist, please run mysql_upgrade.

Comment by Michael Sypes [ 2019-10-27 ]

Ran mysql_upgrade. Lots of information spit out and I now see the *_stats tables.

Of the three sites that displayed issues as a result, two appear to functioning normally again. The third I likely broke in other ways during my attempts to deal with the issue when it first occurred, so you can mark me down as saying that the fix works. Thanks!

Comment by Michael Sypes [ 2019-10-30 ]

I don't know if this is related, but while poking around my instance to see if it's safe to use, I noticed that Sequel Pro can't see all the users and privileges, and also tends to crap out when trying to view them.
For example, mysql.user has 36 rows representing about 30 usernames. However, Sequel Pro is only seeing two of them, and there's nothing obvious that would those two special.
In addition, if I try to look at the schema-specific privileges for them (which I did trying to find out what was special), nothing shows up as available, for any database.

Comment by William Turrell [ 2019-11-07 ]

Hello again.

  • mysql_upgrade runs successfully (albeit with errors in phase 3/7 - Fixing views from mysql).
  • subsequently, I can run my mariadb-insertion-bug-demo.sql statements and no rows are missing
  • I've also imported a large database (couple of tables with 300,000+ rows each) and that's fine too
  • not seeing the problems Michael is with Sequel Pro - the number of rows in CLI and Sequel Pro matches for me (however I have fewer records in user. table - 13 vs 36)

Thanks,
William

Comment by Michael Sypes [ 2019-11-08 ]

I've done some research on the Sequel Pro issue, and determined that it's unrelated to this this, but is a known issue, that's just new to me:
https://github.com/sequelpro/sequelpro/issues/2982, https://github.com/sequelpro/sequelpro/issues/3139, https://github.com/sequelpro/sequelpro/issues/3167

Generated at Thu Feb 08 08:58:50 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.