Gianni Angelozzi added a comment - 2018-02-07 15:57 Also, if the problem was a duplicate key, shouldn't the error message also display the problematic ID ?

Gianni Angelozzi added a comment - 2018-04-26 12:27 Updated to 10.3.6, issue still present

Marko Mäkelä added a comment - 2018-05-18 15:25 johnkiller , I wonder if the duplicate could be reported for the hidden FTS_DOC_ID column? If you rebuild the table without any FULLTEXT INDEX , will you still get the errors? There was a related bug fix in MDEV-12676 , but that fix is present in 10.3.6. Note that the hidden FTS_DOC_ID nor the hidden unique FTS_DOC_ID_INDEX(FTS_DOC_ID) will not be dropped when you drop the fulltext indexes. You must rebuild the table, for example by specifying the FORCE keyword in the ALTER TABLE statement.

Gianni Angelozzi added a comment - 2018-05-18 15:33 I'll try to disable fulltext and rebuild the tables, then report back if it happens again. As I said, this is not always reproducible, so it may take a couple of days before it happens. Also, I have set "ft_min_word_len = 3" in my.cnf, if that could help. Thanks

Gianni Angelozzi added a comment - 2018-05-23 14:58 Hi, after 4 days it seems that the error disappeared. What can I do now? Thanks

Marko Mäkelä added a comment - 2018-05-24 10:59 johnkiller , do you mean that the bug stopped repeating even before you dropped the fulltext index? I do not think that duplicate key errors should be related to any FOREIGN KEY constraints, with the exception of ON UPDATE CASCADE that causes an update of a unique index or the primary key in a child table. My best guess is that the error is somehow related to fulltext index, but because it is only a guess, I would want to verify it. InnoDB fulltext indexes are internally implemented in hidden tables. In most of these tables, the unique index (primary key) is on the FTS_DOC_ID column. The main table is indexed by (word,first_doc_id) where first_doc_id is a FTS_DOC_ID . The only exception are the CONFIG tables, where I believe the key to be one of the few hard-coded strings defined in include/fts0priv.h . So, if the problem is in the fulltext index, it should likely be either due to the FTS_DOC_ID or due to a bug in the management of the inverted index.

Gianni Angelozzi added a comment - 2018-05-24 11:25 I mean that after doing what you requested (disabling fulltext & rebuild) has stopped producing the error. I'm not 100% sure because the error is random. Thanks

Marko Mäkelä added a comment - 2018-05-25 19:45 johnkiller , thank you for clarifying. I believe that the InnoDB fulltext index code is the most likely culprit. Now the only remaining problem is that we need to reproduce the issue.

Gianni Angelozzi added a comment - 2018-05-29 08:10 Updated to 10.3.7 and the issue is still present. Issuing a SHOW WARNINGS produces this: stdClass Object ( [Level] => Error [Code] => 1022 [Message] => Can't write; duplicate key in table 'subject' ) Repeating the query then works as expected. Is there a way to enable more logging so I can help better? For example, is there a way to see the exact index that is failing, even if it's a system column? I've tried to run a loop of inserts and updates but I can't reliably reproduce this issue

Marko Mäkelä added a comment - 2018-05-29 09:33 I got this error once when running ./mtr --parallel=auto --force --big-test --max-test-fail=0 : CURRENT_TEST: innodb_fts.fulltext2 mysqltest: At line 225: query 'update t1 set a='ab c d'' failed: 1022: Can't write; duplicate key in table 't1'

Matthias Leich added a comment - 2018-06-05 18:31 I tried to reproduce the problem based on innodb_fts.fulltext2 (see Marko's comment) with some brute force test. But none of the setup combinations 10.2 or 10.3 (both compiled with debug) overloaded CPU or overloaded CPU+HDD replayed the problem.

Gianni Angelozzi added a comment - 2018-06-05 20:44 custom.cnf This is my configuration. Some settings (like ft_min_word_len) affects the fulltext search, maybe this helps.

Matthias Leich added a comment - 2018-06-06 14:06 I am now giving up with the brute force tests based on innodb_fts.fulltext2. Even using most of the settings in custom.cnf did not replay.

Gianni Angelozzi added a comment - 2018-06-06 14:23 Is there a way for me to get more debug info? I continue to get this error at least twice a day on 2 different servers, both in production.

Matthias Leich added a comment - 2018-06-06 14:37 Hi Gianni Angelozzi, I assume that there is some problem with FOREIGN KEYs. The duplicate key error message thrown because of PRIMARY KEY or UNIQUE INDEX look different. In such cases the corresponding key would be mentioned in the error message. I am just experimenting in order to see how the messages for violations of FOREIGN KEY relationship look like. Regards Matthias

Matthias Leich added a comment - 2018-06-08 14:31 - edited Some news: No replay with some RQG test working on a table with similar layout like mentioned on top, 100000 rows and 12 concurrent sessions updating rows like mentioned on top in transactions. Some statements failed because of error 1213 (deadlock) or 1205 (Lock wait timeout). All other passed. (Debug build and also ASAN build) My tests with MTR, InnoDB table, sometimes forreign keys, unique indices, PRIMARY KEYs gave all time error messages mentioning the constraint/foreign key/... violated. (10.2 used). There was never a ER_DUP_ENTRY error message. Some search over our MTR tests showed a crowd of tests where statements are expected to harvest ER_DUP_ENTRY or ER_DUP_KEY. The reason seems to be that older software versions gave often the less detailed ER_DUP_KEY message and now the better ER_DUP_ENTRY. Aside of tests using partitioned tables/engines like federated, merge, blackhole which seem to be mostly irrelevant suite/perfschema/t/dml_setup_objects.test looked quite interesting. Some table is using the ENGINE=PERFORMANCE_SCHEMA which needs to invoke whatever (I assume its some builtin storage engine extended by additional properties) storage engine. One attempt to insert some record leads to ER_DUP_KEY. Also some other statements report violations of FOREIGN KEY. Both things happen even though the table definition does not mention any unique constraints or foreign keys. So it looks as if we could have hidden structures (not presented in SHOW TABLE) acting as unique constraint. And in case that gets violated than ER_DUP_KEY and not the better ER_DUP_ENTRY gets reported. One thing which springs into the eye when looking on the table definition is CREATE TABLE `user` ( `id` int(11) unsigned NOT NULL, ... `user` varchar(250) NOT NULL, ... PRIMARY KEY (`id`), KEY `id` (`id`,`deleted`), FULLTEXT KEY `user` ... the heavy reuse of the same name for different objects like table, full text index, index etc. And I found in the Web several reports about hitting ER_DUP_KEY mostly when trying to alter the table definition. The workaround which usually finally helped was to make names unique per database. It would be interesting to know if making the name of fulltext and normal indexes unique could somehow improve the situation.

Matthias Leich added a comment - 2018-06-14 11:35 Hi Gianni Angelozzi, you mention 'The table is referenced on other tables, but the error should occur on creation of them, not by writing rows.'. You are of course right with this statement and in addition the error message should tell in which object (foreign key/unique index/primary key) the duplicate happened. Would you please upload the definition of these tables? In case there are triggers involved than some information about them would be of interest too. There are some other ways to get more debug info but they have usually very unfortunate properties (extreme slow throughput and similar) at runtime. Many thanks in advance Matthias

Gianni Angelozzi added a comment - 2018-06-14 14:23 CREATE TABLE ` user ` ( `id` int (11) UNSIGNED NOT NULL , `revision_date` int (14) NOT NULL , `revision_author` int (11) UNSIGNED NOT NULL , `creation_date` int (14) NOT NULL , `creation_author` int (11) UNSIGNED NOT NULL , `deleted` tinyint(1) NOT NULL , ` user ` varchar (250) NOT NULL , ` password ` varchar (255) NOT NULL , ` name ` varchar (250) NOT NULL , `surname` varchar (250) NOT NULL , `lastlogin` int (14) NOT NULL , `lastip` varchar (32) NOT NULL , `lastpsw` int (14) NOT NULL , `email` varchar (60) NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8;   CREATE TABLE `user_by_b2bmaster_to_b2b_master` ( `user_id` int (11) UNSIGNED NOT NULL , `b2b_master` int (11) UNSIGNED NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8;   CREATE TABLE `user_by_b2bstore_to_b2b_store` ( `user_id` int (11) UNSIGNED NOT NULL , `b2b_store` int (11) UNSIGNED NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8;   CREATE TABLE `user_by_group_to_user_group` ( `user_id` int (11) UNSIGNED NOT NULL , `user_group` int (11) UNSIGNED NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8;   CREATE TABLE `user_group` ( `id` int (11) UNSIGNED NOT NULL , `revision_date` int (14) NOT NULL , `revision_author` int (11) UNSIGNED NOT NULL , `creation_date` int (14) NOT NULL , `creation_author` int (11) UNSIGNED NOT NULL , `deleted` tinyint(1) NOT NULL , ` name ` varchar (250) NOT NULL , `b2bmaster` tinyint(1) NOT NULL , `b2bstore` tinyint(1) NOT NULL , `special` tinyint(1) NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8;   CREATE TABLE `user_group_by_permission_to_user_group_permission` ( `user_group_id` int (11) UNSIGNED NOT NULL , `user_group_permission` int (11) UNSIGNED NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8;   CREATE TABLE `user_group_permission` ( `id` int (11) UNSIGNED NOT NULL , `revision_date` int (14) NOT NULL , `revision_author` int (11) UNSIGNED NOT NULL , `creation_date` int (14) NOT NULL , `creation_author` int (11) UNSIGNED NOT NULL , ` name ` varchar (250) NOT NULL , `description` varchar (250) NOT NULL , ` group ` varchar (250) NOT NULL , `groupname` varchar (250) NOT NULL , `folder` varchar (250) NOT NULL ) ENGINE=InnoDB DEFAULT CHARSET=utf8;   ALTER TABLE ` user ` ADD PRIMARY KEY (`id`), ADD KEY `id` (`id`,`deleted`), ADD KEY `deleted` (`deleted`); ALTER TABLE ` user ` ADD FULLTEXT KEY `ft_user` (` user `,` name `,`surname`);   ALTER TABLE `user_by_b2bmaster_to_b2b_master` ADD PRIMARY KEY (`user_id`,`b2b_master`), ADD KEY `user_id` (`user_id`), ADD KEY `b2b_master` (`b2b_master`);   ALTER TABLE `user_by_b2bstore_to_b2b_store` ADD PRIMARY KEY (`user_id`,`b2b_store`), ADD KEY `user_id` (`user_id`), ADD KEY `b2b_store` (`b2b_store`);   ALTER TABLE `user_by_group_to_user_group` ADD PRIMARY KEY (`user_id`,`user_group`), ADD KEY `user_id` (`user_id`), ADD KEY `user_group` (`user_group`);   ALTER TABLE `user_group` ADD PRIMARY KEY (`id`), ADD KEY `id` (`id`,`deleted`), ADD KEY `deleted` (`deleted`); ALTER TABLE `user_group` ADD FULLTEXT KEY `ft_user_group` (` name `);   ALTER TABLE `user_group_by_permission_to_user_group_permission` ADD PRIMARY KEY (`user_group_id`,`user_group_permission`), ADD KEY `user_group_id` (`user_group_id`), ADD KEY `user_group_permission` (`user_group_permission`);   ALTER TABLE `user_group_permission` ADD PRIMARY KEY (`id`); ALTER TABLE `user_group_permission` ADD FULLTEXT KEY `ft_user_group_permission` (` name `,`description`);   ALTER TABLE `user_by_b2bmaster_to_b2b_master` ADD CONSTRAINT `f1_user_by_b2bmaster_to_b2b_master` FOREIGN KEY (`user_id`) REFERENCES ` user ` (`id`) ON DELETE CASCADE ON UPDATE CASCADE , ADD CONSTRAINT `f2_user_by_b2bmaster_to_b2b_master` FOREIGN KEY (`b2b_master`) REFERENCES `b2b_master` (`id`) ON DELETE CASCADE ON UPDATE CASCADE ;   ALTER TABLE `user_by_b2bstore_to_b2b_store` ADD CONSTRAINT `f1_user_by_b2bstore_to_b2b_store` FOREIGN KEY (`user_id`) REFERENCES ` user ` (`id`) ON DELETE CASCADE ON UPDATE CASCADE , ADD CONSTRAINT `f2_user_by_b2bstore_to_b2b_store` FOREIGN KEY (`b2b_store`) REFERENCES `b2b_store` (`id`) ON DELETE CASCADE ON UPDATE CASCADE ;   ALTER TABLE `user_by_group_to_user_group` ADD CONSTRAINT `f1_user_by_group_to_user_group` FOREIGN KEY (`user_id`) REFERENCES ` user ` (`id`) ON DELETE CASCADE ON UPDATE CASCADE , ADD CONSTRAINT `f2_user_by_group_to_user_group` FOREIGN KEY (`user_group`) REFERENCES `user_group` (`id`) ON DELETE CASCADE ON UPDATE CASCADE ;   ALTER TABLE `user_group_by_permission_to_user_group_permission` ADD CONSTRAINT `f1_user_group_by_permission_to_user_group_permission` FOREIGN KEY (`user_group_id`) REFERENCES `user_group` (`id`) ON DELETE CASCADE ON UPDATE CASCADE , ADD CONSTRAINT `f2_user_group_by_permission_to_user_group_permission` FOREIGN KEY (`user_group_permission`) REFERENCES `user_group_permission` (`id`) ON DELETE CASCADE ON UPDATE CASCADE ; I have many tables but they are very similar. There are no triggers, no views, nothing fancy. However almost all of them have a FULLTEXT index, possibily with multiple columns. About the performance issue, I have a server that I don't care if it's slow, so if you can tell me how to enable some more debugging I can try it there. Thanks

Matthias Leich added a comment - 2018-06-15 11:56 Many thanks for the table definitions sent. I am discussing with Marko if we could generate some server binary giving more debugging information on which object the duplicate was hit.

Matthias Leich added a comment - 2018-06-21 12:27 Hi Gianni Angelozzi, would you please 1. Apply the uploaded patch to some fresh cloned 10.2 source and compile a binary with debug. 2. Add --plugin-load=sql_errlog.so to the [mysqld] section in your my.cnf file or just start the server with "--plugin-load=sql_errlog.so" ( https://mariadb.com/kb/en/library/sql-error-log-plugin/ ) This will collect errors sent to clients in a log file 'sql_errors.log' located within the server data directory. The entries there in combination with the additional entries (caused by the patch) in the server error log might help to identify in which operation of the workflow of executing a INSERT or UPDATE in your tables 'users' or 'subject' .... the trouble occurs. 3. Run your application on a testing box till the problem showed a few times up. My hope is that we either get some more or less cryptic entry written by InnoDB which could be used for searching within the InnoDB internal data dictionary or [ERROR] get_dup_key: nnn which maybe than points to some temporary shortage of free resources. What the patch does: The error messages sent by the server to the client will be not changed. In case the InnoDB storage engine hits a duplicate key on whatever object than it will most probably write a message based on its internal 'knowledge'. Examples: [ERROR] err_index (0) for uidx:test/city Client gets ERROR 23000: Duplicate entry 'Castelo de Vide' for key 'uidx' ... [ERROR] err_index (0) for PRIMARY:mysqld.1/#sql2f87_15_2 Client gets ERROR 23000: Duplicate entry '20' for key 'PRIMARY' The table was defined CREATE TEMPORARY TABLE t1 (..., PRIMARY KEY ...) which explains the strange schema and table name reported by InnoDB. [ERROR] err_index (0) for PRIMARY:test/t1#P#pNeg#SP#subp1 The table test . t1 is partitioned ... into the server error log. In case the duplicate key does not happen within InnoDB than some routine in the upper layer will often but not all time write messages like [ERROR] get_dup_key: nnn. into the server error log. Example: [ERROR] get_dup_key: 135 Client gets ERROR HY000: The table '... var/tmp/mysqld.1/#sql_1568_0' is full This means some internal temporary table (usually MyISAM/Aria storage engine) with limited size (server system variables tmp_disk_table_size, tmp_memory_table_size) and used internally for complex queries was full. The server error log might grow fast. In case you let our regression tests run then MTR will report a batch of fails like Found warnings/errors in server log file! Test ended at 2018-06-21 13:48:30 line 2018-06-21 13:48:29 140547810891520 [ERROR] err_index (0) for a:test/t1 ^ Found warnings in .../var/1/log/mysqld.1.err ok but that is to be expected with the patch and harmless. Many thanks in advance.

Gianni Angelozzi added a comment - 2018-06-26 08:16 Hi, I've successfully compiled the binary with your patch and I'm now waiting for the error to appear. Let's hope it's not an Heisenbug

Gianni Angelozzi added a comment - 2018-07-10 13:57 Hi, After some time running in debug mode, the error didn't come up, so I switched to a normal build with your patch applied. This popped up in /var/log/syslog: Jul 10 15:04:46 logico_ac mysqld[28840]: 2018-07-10 15:04:46 140332408940288 [ERROR] InnoDB: Duplicate FTS_DOC_ID value on table `logico_ac`.`anl_method` Jul 10 15:04:46 logico_ac mysqld[28840]: 2018-07-10 15:04:46 140332408940288 [ERROR] Cannot find index FTS_DOC_ID_INDEX in InnoDB index translation table. Jul 10 15:04:46 logico_ac mysqld[28840]: 2018-07-10 15:04:46 140332408940288 [Warning] Found index FTS_DOC_ID_INDEX in InnoDB index list but not its MariaDB index number. It could be an InnoDB internal index. Jul 10 15:04:46 logico_ac mysqld[28840]: 2018-07-10 15:04:46 140332408940288 [ERROR] err_index (-1) for FTS_DOC_ID_INDEX:logico_ac/anl_method This was in /var/lib/mysql/sql_errors.log: 2018-07-10 15:04:46 root[root] @ localhost [] ERROR 1022: Can 't write; duplicate key in table ' anl_method' : INSERT INTO `anl_method` SET `id` = 1055, `revision_id` = 1, `revision_date` = 1531235086, `revision_author` = 7, `creation_date` = 1531235086, `creation_author` = 7, `tmp` = "" , `code` = "EXT" , ` name ` = "Metodi di Analisi per i Fertilizzanti - met. X.2" , `official` = "" , `date_start` = "1530403200" , `date_end` = "0" , `notes` = "" Do you need anything else?

Matthias Leich added a comment - 2018-07-11 10:37 Hi, many thanks for your input. Would you please keep the files with the snippets above and if possible a raw backup (the files when the server is not running) of the database at some safe place. So it seems now more clear that the sporadic trouble comes from the fulltext indexes. Now the InnoDB developers need to discuss these results and how to proceed. Based on your experiences (... a retry of the same insert or update usually passes) and my latest experiences with RQG based tests (certain bad effects do not show up except the testing box is under under excessive load) I fear we are in the region of a Heisenbug.

Gianni Angelozzi added a comment - 2018-07-26 12:40 Hi, I'm keeping an eye on syslog, and I've noticed that it's now cluttered with Jul 26 14:09:51 logico_ac mysqld[1137]: 2018-07-26 14:09:51 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:12:35 logico_ac mysqld[1137]: 2018-07-26 14:12:35 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:13:28 logico_ac mysqld[1137]: 2018-07-26 14:13:28 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:17:02 logico_ac mysqld[1137]: 2018-07-26 14:17:02 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:17:20 logico_ac mysqld[1137]: 2018-07-26 14:17:20 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:22:16 logico_ac mysqld[1137]: 2018-07-26 14:22:16 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:22:30 logico_ac mysqld[1137]: 2018-07-26 14:22:30 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:22:30 logico_ac mysqld[1137]: 2018-07-26 14:22:30 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:23:11 logico_ac mysqld[1137]: 2018-07-26 14:23:11 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:24:28 logico_ac mysqld[1137]: 2018-07-26 14:24:28 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:24:33 logico_ac mysqld[1137]: 2018-07-26 14:24:33 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:25:50 logico_ac mysqld[1137]: 2018-07-26 14:25:50 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:27:48 logico_ac mysqld[1137]: 2018-07-26 14:27:48 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:28:05 logico_ac mysqld[1137]: 2018-07-26 14:28:05 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:28:10 logico_ac mysqld[1137]: 2018-07-26 14:28:10 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:28:23 logico_ac mysqld[1137]: 2018-07-26 14:28:23 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:28:30 logico_ac mysqld[1137]: 2018-07-26 14:28:30 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:28:42 logico_ac mysqld[1137]: 2018-07-26 14:28:42 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:28:48 logico_ac mysqld[1137]: 2018-07-26 14:28:48 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:29:57 logico_ac mysqld[1137]: 2018-07-26 14:29:57 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:30:05 logico_ac mysqld[1137]: 2018-07-26 14:30:05 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:30:46 logico_ac mysqld[1137]: 2018-07-26 14:30:46 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:30:50 logico_ac mysqld[1137]: 2018-07-26 14:30:50 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:31:34 logico_ac mysqld[1137]: 2018-07-26 14:31:34 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:32:16 logico_ac mysqld[1137]: 2018-07-26 14:32:16 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:32:31 logico_ac mysqld[1137]: 2018-07-26 14:32:31 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:33:33 logico_ac mysqld[1137]: 2018-07-26 14:33:33 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:34:01 logico_ac mysqld[1137]: 2018-07-26 14:34:01 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:34:16 logico_ac mysqld[1137]: 2018-07-26 14:34:16 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Jul 26 14:34:26 logico_ac mysqld[1137]: 2018-07-26 14:34:26 139747516819200 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. If I issue ALTER TABLE ` user ` ENGINE=InnoDB; should the error go away?

Matthias Leich added a comment - 2018-07-27 09:42 Yes, because ALTER TABLE `user` ENGINE=InnoDB will rebuild all storage structures belonging to that table.

Karl Friedrich added a comment - 2018-12-04 13:13 - edited I came from ticket MDEV-12676 I have this line in /var/log/mariadb.log few hundred times. (MariaDB-server-10.1.37-1.el7.centos.x86_64) 2018 - 12 - 04 13 : 28 : 27 7f8413ffb700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. Since there is no name of the table which is responsible for this error, I'm a bit baffled. There are many databases and tables. How I can find the right one?

Gianni Angelozzi added a comment - 2018-12-04 14:15 Hi Karl, if you have a FULLTEXT search index on a INNODB table, I'm afraid that this is the same bug I've encountered here. I've since stopped using FULLTEXT search since the erros breaks Galera replication, so I don't know if in recent versions of MariaDB this error is still present or not. The table that has the error is an internal index of InnoDB, it's not your fault or something that you can fix by yourself. Thanks.

Gianni Angelozzi added a comment - 2019-12-29 12:22 Just a quick update. I've tested 10.4.11 and the bug is still present. Also since my production database has grown in size and traffic (about 20gb of data, 3 galera cluster nodes) the error appears more frequently (and breaks replication)

Wagner Bianchi (Inactive) added a comment - 2020-04-13 13:46 Folks, it's happening for Ubuntu Trusty (a little old, yeah) when running the MariaDB Server 10.2.18-MariaDB-10.2.18+maria~trusty-log. 2020 - 04 - 12 11 : 16 : 37 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 12 17 : 11 : 58 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 12 17 : 15 : 08 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 12 17 : 15 : 36 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 12 17 : 15 : 57 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 12 22 : 57 : 08 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 12 22 : 57 : 27 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 12 22 : 57 : 39 140382549571328 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. Bianchi

Wagner Bianchi (Inactive) added a comment - 2020-04-16 20:21 Folks, it's happening also on CentOS Linux release 7.7.1908 (Core) running the 10.1.42-MariaDB for Linux on x86_64. 2020 - 04 - 16 13 : 20 : 11 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 12 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 13 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 13 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 04 - 16 13 : 20 : 13 7ee682bfa700 InnoDB: Error (Duplicate key) writing word node to FTS auxiliary index table.

Karl Friedrich added a comment - 2020-11-06 16:44 CentOS Linux 8.2.2004 / Server-Version: 10.3.17-MariaDB-log Afer two years, every few minutes I have still this errors in my logfile /var/log/mariadb.log 2020 - 11 - 06 12 : 40 : 56 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 11 - 06 12 : 43 : 27 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 11 - 06 12 : 45 : 43 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table. 2020 - 11 - 06 12 : 47 : 15 0 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table.

Matthias Leich added a comment - 2020-11-06 18:46 - edited Hi, sorry for the long time without response. Would it be possible to send me a complete logical dump of your database and some sample SQL's? Please feel free to scramble sensitive data in strings as needed Without some sample data and sample SQL's the chances to replay these problems are extreme low. Many thanks in advance Regards Matthias

Jérémie Rioux added a comment - 2021-03-02 16:48 We are seeing this issue on Ubuntu 18.04.5 LTS LXC container with latest MariaDB 10.3.28 version. I'll check to see if we can share the information required for the investigation.

Daniel Black added a comment - 2021-03-11 05:52 jrioux if there data and configuration is shareable and not exceptionally large - an upload would be appreciated https://mariadb.com/kb/en/meta/mariadb-ftp-server/ Otherwise the same information mleich has requested from other users.

Marko Mäkelä added a comment - 2022-01-28 16:55 This might share a root cause with MDEV-24608 . The fts_commit() call at transaction commit time is modifying persistent data related to fulltext indexes. If XA PREPARE is being used, either explicitly by the application, or implicitly by the use of the binlog (which internally generates distributed transactions of the form MySQLXid ), problems could arise.

Marko Mäkelä added a comment - 2022-08-22 08:54 It seems that MDEV-25581 would convert the error message to a server crash, as reported in MDEV-29335 . johnkiller or jrioux or anyone who can reproduce this error, we would greatly appreciate something that would allow us to reproduce and fix this bug.

Jérémie Rioux added a comment - 2022-08-29 13:32 We unfortunately had to move to another engine because of this issue. I cannot reproduce it anymore.

Marko Mäkelä added a comment - 2022-08-29 14:41 There now is a test case in MDEV-29342 .

Marko Mäkelä added a comment - 2022-09-14 12:33 - edited It is possible that this bug was fixed in MDEV-29342 . Given that this bug has been open so long, with relatively few votes and watchers, I think that we must wait several months for any feedback. An unscheduled release of MariaDB Server 10.6.10, 10.7.6, 10.8.5, 10.9.3 is expected to be available soon. For older major versions, releases including the fix of MDEV-29342 should become available in the next scheduled quarterly release (October or November 2022).

Khai Ping added a comment - 2024-07-19 01:27 - edited i am still seeing this error in 10.6.12 in a 3 node galera cluster. When duplicate key happens, the galera cluster will slow down and eventually unable to serve. 240716 14 : 05 : 11 mysqld_safe mysqld from pid file /var/lib/mysql/mysql.pid ended 240716 14 : 05 : 37 mysqld_safe Starting mariadbd daemon with databases from /var/lib/mysql 240716 14 : 05 : 37 mysqld_safe WSREP: Running position recovery with --disable-log-error --pid-file= '/var/lib/mysql/server-h3-recover.pid' 240716 14 : 05 : 39 mysqld_safe WSREP: Recovered position 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 39 0 [Note] Starting MariaDB 10.6 . 12 -MariaDB source revision 4c79e15cc3716f69c044d4287ad2160da8101cdc as process 28412 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: Loading provider /usr/lib64/galera/libgalera_smm.so initial position: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera/libgalera_smm.so' 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: wsrep_load(): Galera 26.4 . 14 (rf27da2a) by Codership Oy <info @codership .com> loaded successfully. 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: CRC-32C: using 64 -bit x86 acceleration. 2024 - 07 - 16 14 : 05 : 39 0 [Warning] WSREP: SSL compression is not effective. The option socket.ssl_compression is deprecated and will be removed in future releases. 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: Found saved state: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 , safe_to_bootstrap: 0 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: GCache DEBUG: opened preamble: Version: 2 UUID: 67210f6b-52bc-11ed- 8997 -d697d3148f87 Seqno: 87943436 - 88711849 Offset: 1749575000 Synced: 1 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: Recovering GCache ring buffer: version: 2 , UUID: 67210f6b-52bc-11ed- 8997 -d697d3148f87, offset: 1749575000 2024 - 07 - 16 14 : 05 : 39 0 [Note] WSREP: GCache::RingBuffer initial scan... 0.0 % ( 0 / 2147483672 bytes) complete. 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: GCache::RingBuffer initial scan... 100.0 % ( 2147483672 / 2147483672 bytes) complete. 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Recovering GCache ring buffer: found gapless sequence 87943436 - 88711849 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: GCache::RingBuffer unused buffers scan... 0.0 % ( 0 / 2147055560 bytes) complete. 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Recovering GCache ring buffer: found 1 / 768415 locked buffers 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Recovering GCache ring buffer: free space: 428280 / 2147483648 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: GCache::RingBuffer unused buffers scan... 100.0 % ( 2147055560 / 2147055560 bytes) complete. 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = tdmint-h3; base_port = 4567 ; cert.log_conflicts = no; cert.optimistic_pa = yes; debug = no; evs.auto_evict = 0 ; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT10S; evs.inactive_timeout = PT60S; evs.install_timeout = PT60S; evs.join_retrans_period = PT1S; evs.keepalive_period = PT3S; evs.max_install_timeouts = 3 ; evs.send_window = 512 ; evs.stats_report_period = PT1M; evs.suspect_timeout = PT30S; evs.user_send_window = 512 ; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.keep_pages_size = 0 ; gcache.keep_plaintext_size = 1G; gcache.mem_size = 0 ; gcache.name = galera.cache; gcache.page_size = 1G; gcache.recover = yes; gcache.size = 2G; gcomm.thread_prio = ; gcs.fc_debug = 0 ; gcs.fc_factor = 1.0 ; gcs.fc_limit = 16 ; gcs.fc_master_slave = no; gcs.fc_single_primary = no; gcs.max_packet_size = 64500 ; gcs.max_throttle = 0.25 ; gcs.recv_q_hard_limit = 9223372036854775807 ; gcs.recv_q_soft_l 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: ####### Assign initial position for certification: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 , protocol version: - 1 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Start replication 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Connecting with bootstrap option: 0 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Setting GCS initial position to 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: Using CRC- 32 (backward-compatible) for message checksums. 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: backend: asio 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: gcomm thread scheduling priority set to other: 0 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: access file(/var/lib/mysql //gvwstate.dat) failed(No such file or directory) 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: restore pc from disk failed 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: GMCast version 0 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: (7d3f1c69-bd93, 'ssl://0.0.0.0:4567' ) listening at ssl:// 0.0 . 0.0 : 4567 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: (7d3f1c69-bd93, 'ssl://0.0.0.0:4567' ) multicast: , ttl: 1 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: EVS version 1 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: gcomm: connecting to group 'accdbcluster' , peer '57.3.12.100:,57.3.12.101:,57.3.12.107:' 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: (7d3f1c69-bd93, 'ssl://0.0.0.0:4567' ) Found matching local endpoint for a connection, blacklisting address ssl:// 57.3 . 12.107 : 4567 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: (7d3f1c69-bd93, 'ssl://0.0.0.0:4567' ) connection established to 29aeda1c-8bc1 ssl:// 57.3 . 12.101 : 4567 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: (7d3f1c69-bd93, 'ssl://0.0.0.0:4567' ) turning message relay requesting on, nonlive peers: 2024 - 07 - 16 14 : 05 : 42 0 [Note] WSREP: (7d3f1c69-bd93, 'ssl://0.0.0.0:4567' ) connection established to 49695eda-b162 ssl:// 57.3 . 12.100 : 4567 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: EVS version upgrade 0 -> 1 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: declaring 29aeda1c-8bc1 at ssl: //57.3.12.101:4567 stable 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: declaring 49695eda-b162 at ssl: //57.3.12.100:4567 stable 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: PC protocol upgrade 0 -> 1 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Node 29aeda1c-8bc1 state prim 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: view(view_id(PRIM,29aeda1c-8bc1, 14 ) memb { 29aeda1c-8bc1, 4 49695eda-b162, 3 7d3f1c69-bd93, 7 } joined { } left { } partitioned { }) 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: save pc into disk 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: gcomm: connected 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Changing maximum packet size to 64500 , resulting msg size: 32636 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0 ) 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Opened channel 'accdbcluster' 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 2 , memb_num = 3 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID. 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 7d8e3f95-437c-11ef-a8ec-bb1b8da382a8 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7d8e3f95-437c-11ef-a8ec-bb1b8da382a8 from 0 (tdmint-h2) 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7d8e3f95-437c-11ef-a8ec-bb1b8da382a8 from 1 (tdmint-h1) 2024 - 07 - 16 14 : 05 : 43 1 [Note] WSREP: Starting rollbacker thread 1 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: Starting applier thread 2 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7d8e3f95-437c-11ef-a8ec-bb1b8da382a8 from 2 (tdmint-h3) 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Quorum results: version = 6 , component = PRIMARY, conf_id = 11 , members = 2 / 3 (joined/total), act_id = 88711850 , last_appl. = 88711807 , protocols = 2 / 10 / 4 (gcs/repl/appl), vote policy= 0 , group UUID = 67210f6b-52bc-11ed- 8997 -d697d3148f87 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Flow-control interval: [ 28 , 28 ] 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 88711851 ) 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: ####### processing CC 88711851 , local, ordered 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: Process first view: 67210f6b-52bc-11ed- 8997 -d697d3148f87 my uuid: 7d3f1c69-437c-11ef-bd93-1be78d6491dc 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: Server tdmint-h3 connected to cluster at position 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711851 with ID 7d3f1c69-437c-11ef-bd93-1be78d6491dc 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: Server status change disconnected -> connected 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: ####### My UUID: 7d3f1c69-437c-11ef-bd93-1be78d6491dc 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: Cert index reset to 00000000 - 0000 - 0000 - 0000 - 000000000000 :- 1 (proto: 10 ), state transfer needed: yes 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: ####### Assign initial position for certification: 00000000 - 0000 - 0000 - 0000 - 000000000000 :- 1 , protocol version: - 1 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: State transfer required: Group state: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711851 Local state: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 43 2 [Note] WSREP: Server status change connected -> joiner 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Joiner monitor thread started to monitor 2024 - 07 - 16 14 : 05 : 43 0 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role ' joiner ' --address ' tdmint-h3 ' --datadir ' /var/lib/mysql/ ' --parent 28412 --progress 0 --mysqld-args --basedir=/opt --datadir=/var/lib/mysql --plugin-dir=/opt/lib64/mysql/plugin --user=mysql --wsrep_provider=/usr/lib64/galera/libgalera_smm.so --wsrep_on=ON --log-error=/var/lib/mysql/mysql.err --pid-file=/var/lib/mysql/mysql.pid --wsrep_start_position=67210f6b-52bc-11ed-8997-d697d3148f87:88711849' WSREP_SST: [INFO] mariabackup SST started on joiner ( 20240716 14 : 05 : 44.005 ) WSREP_SST: [INFO] SSL configuration: CA= '' , CAPATH= '' , CERT= '/var/lib/mysql/galera_cert.pem' , KEY= '/var/lib/mysql/galera_key.pem' , MODE= 'DISABLED' , encrypt= '3' ( 20240716 14 : 05 : 44.127 ) WSREP_SST: [INFO] Streaming with mbstream ( 20240716 14 : 05 : 44.278 ) WSREP_SST: [INFO] Using socat as streamer ( 20240716 14 : 05 : 44.280 ) WSREP_SST: [INFO] Using openssl based encryption with socat: with key and crt ( 20240716 14 : 05 : 44.294 ) WSREP_SST: [INFO] Decrypting with cert= '/var/lib/mysql/galera_cert.pem' , key= '/var/lib/mysql/galera_key.pem' , verify= 0 ( 20240716 14 : 05 : 44.324 ) WSREP_SST: [INFO] Evaluating timeout -k 310 300 socat -u openssl-listen: 4444 ,reuseaddr,cert= '/var/lib/mysql/galera_cert.pem' ,key= '/var/lib/mysql/galera_key.pem' ,verify= 0 stdio | '/opt//bin/mbstream' -x; RC=( ${PIPESTATUS[@]} ) ( 20240716 14 : 05 : 44.366 ) 2024 - 07 - 16 14 : 05 : 44 2 [Note] WSREP: ####### IST uuid:67210f6b-52bc-11ed- 8997 -d697d3148f87 f: 88711850 , l: 88711851 , STRv: 3 2024 - 07 - 16 14 : 05 : 44 2 [Note] WSREP: IST receiver addr using ssl: //h3-tdmint:4568 2024 - 07 - 16 14 : 05 : 44 2 [Note] WSREP: IST receiver using ssl 2024 - 07 - 16 14 : 05 : 44 2 [Note] WSREP: Prepared IST receiver for 88711850 - 88711851 , listening at: ssl: //57.3.12.107:4568 2024 - 07 - 16 14 : 05 : 44 0 [Note] WSREP: Member 2.7 (tdmint-h3) requested state transfer from '*any*' . Selected 1.3 (tdmint-h1)(SYNCED) as donor. 2024 - 07 - 16 14 : 05 : 44 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 88711851 ) 2024 - 07 - 16 14 : 05 : 44 2 [Note] WSREP: Requesting state transfer: success, donor: 1 WSREP_SST: [INFO] 'xtrabackup_ist' received from donor: Running IST ( 20240716 14 : 05 : 45.351 ) WSREP_SST: [INFO] Galera co-ords from recovery: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 0 ( 20240716 14 : 05 : 45.356 ) WSREP_SST: [INFO] Total time on joiner: 0 seconds ( 20240716 14 : 05 : 45.358 ) WSREP_SST: [INFO] mariabackup IST completed on joiner ( 20240716 14 : 05 : 45.361 ) WSREP_SST: [INFO] Removing the sst_in_progress file ( 20240716 14 : 05 : 45.364 ) WSREP_SST: [INFO] Cleaning up temporary directories ( 20240716 14 : 05 : 45.368 ) 2024 - 07 - 16 14 : 05 : 45 0 [Note] WSREP: 1.3 (tdmint-h1): State transfer to 2.7 (tdmint-h3) complete. 2024 - 07 - 16 14 : 05 : 45 0 [Note] WSREP: Member 1.3 (tdmint-h1) synced with group. 2024 - 07 - 16 14 : 05 : 45 3 [Note] WSREP: SST received 2024 - 07 - 16 14 : 05 : 45 3 [Note] WSREP: Server status change joiner -> initializing 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Compressed tables use zlib 1.2 . 7 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Number of pools: 1 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Using Linux native AIO 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Initializing buffer pool, total size = 3221225472 , chunk size = 134217728 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Completed initialization of buffer pool 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: 128 rollback segments are active. 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: 10.6 . 12 started; log sequence number 201028063150 ; transaction id 210746763 2024 - 07 - 16 14 : 05 : 45 0 [Note] InnoDB: Loading buffer pool(s) from /db/mysql/ib_buffer_pool 2024 - 07 - 16 14 : 05 : 45 0 [Note] Plugin 'FEEDBACK' is disabled. 2024 - 07 - 16 14 : 05 : 45 0 [Note] Server socket created on IP: '0.0.0.0' . 2024 - 07 - 16 14 : 05 : 45 0 [Note] Server socket created on IP: '::' . 2024 - 07 - 16 14 : 05 : 45 0 [Note] WSREP: wsrep_init_schema_and_SR (nil) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Server initialized 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Server status change initializing -> initialized 2024 - 07 - 16 14 : 05 : 46 3 [Note] WSREP: Recovered position from storage: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 46 3 [Note] WSREP: Recovered view from SST: id: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 status: primary protocol_version: 4 capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO final : no own_index: - 1 members( 3 ): 0 : 29aeda1c-437c-11ef-8bc1-6eceee2419ad, tdmint-h2 1 : 49695eda-437b-11ef-b162-a6a2c1a29b12, tdmint-h1 2 : 63a42fae- 8953 -11ee-adad-56d15056d25c, tdmint-h3   2024 - 07 - 16 14 : 05 : 46 0 [Note] /opt/sbin/mariadbd: ready for connections. Version: '10.6.12-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server 2024 - 07 - 16 14 : 05 : 46 7 [Note] WSREP: Recovered cluster id 67210f6b-52bc-11ed- 8997 -d697d3148f87 2024 - 07 - 16 14 : 05 : 46 3 [Note] WSREP: SST received: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 46 3 [Note] WSREP: SST succeeded for position 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Joiner monitor thread ended with total time 3 sec 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Installed new state from SST: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711849 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Receiving IST: 2 writesets, seqnos 88711850 - 88711851 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### IST applying starts with 88711850 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### IST current seqno initialized to 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Receiving IST... 0.0 % ( 0 / 44 events) complete. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: IST preload starting at 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### Assign initial position for certification: 00000000 - 0000 - 0000 - 0000 - 000000000000 : 88711807 , protocol version: 5 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: REPL Protocols: 10 ( 5 ) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### Adjusting cert position: 88711838 -> 88711839 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Min available from gcache for CC from preload: 87943436 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: REPL Protocols: 10 ( 5 ) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### Adjusting cert position: 88711839 -> 88711840 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Min available from gcache for CC from preload: 87943436 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: REPL Protocols: 10 ( 5 ) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### Adjusting cert position: 88711840 -> 88711841 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Min available from gcache for CC from preload: 87943436 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: REPL Protocols: 10 ( 5 ) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### Adjusting cert position: 88711848 -> 88711849 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Min available from gcache for CC from preload: 87943436 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: REPL Protocols: 10 ( 5 ) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### Adjusting cert position: 88711849 -> 88711850 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Lowest cert index boundary for CC from ist: 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Min available from gcache for CC from ist: 87943437 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: ================================================ View: id: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711850 status: primary protocol_version: 4 capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO final : no own_index: - 1 members( 2 ): 0 : 29aeda1c-437c-11ef-8bc1-6eceee2419ad, tdmint-h2 1 : 49695eda-437b-11ef-b162-a6a2c1a29b12, tdmint-h1 ================================================= 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: REPL Protocols: 10 ( 5 ) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: ####### Adjusting cert position: 88711850 -> 88711851 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Service thread queue flushed. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Lowest cert index boundary for CC from ist: 88711808 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Min available from gcache for CC from ist: 87943437 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: ================================================ View: id: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711851 status: primary protocol_version: 4 capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO final : no own_index: 2 members( 3 ): 0 : 29aeda1c-437c-11ef-8bc1-6eceee2419ad, tdmint-h2 1 : 49695eda-437b-11ef-b162-a6a2c1a29b12, tdmint-h1 2 : 7d3f1c69-437c-11ef-bd93-1be78d6491dc, tdmint-h3 ================================================= 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Receiving IST... 100.0 % ( 44 / 44 events) complete. 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Server status change initialized -> joined 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: (7d3f1c69-bd93, 'ssl://0.0.0.0:4567' ) turning message relay requesting off 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Draining apply monitors after IST up to 88711851 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: IST received: 67210f6b-52bc-11ed- 8997 -d697d3148f87: 88711851 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Lowest cert index boundary for CC from sst: 88711808 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Min available from gcache for CC from sst: 87943437 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: 2.7 (tdmint-h3): State transfer from 1.3 (tdmint-h1) complete. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Shifting JOINER -> JOINED (TO: 88711851 ) 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Processing event queue:... -nan% ( 0 / 0 events) complete. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Member 2.7 (tdmint-h3) synced with group. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Processing event queue:... 100.0 % ( 1 / 1 events) complete. 2024 - 07 - 16 14 : 05 : 46 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 88711851 ) 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Server tdmint-h3 synced with group 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Server status change joined -> synced 2024 - 07 - 16 14 : 05 : 46 2 [Note] WSREP: Synchronized with group, ready for connections 2024 - 07 - 16 14 : 05 : 48 0 [Note] InnoDB: Buffer pool(s) load completed at 240716 14 : 05 : 48 2024 - 07 - 16 14 : 07 : 09 105 [Warning] Access denied for user 'monitor' @ 'localhost' (using password: YES) 2024 - 07 - 16 14 : 08 : 57 143 [Warning] Aborted connection 143 to db: 'configurationDB' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 57 144 [Warning] Aborted connection 144 to db: 'database_users' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 65 [Warning] Aborted connection 65 to db: 'configurationDB' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 64 [Warning] Aborted connection 64 to db: 'configurationDB' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 63 [Warning] Aborted connection 63 to db: 'database_users' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 66 [Warning] Aborted connection 66 to db: 'database_users' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 98 [Warning] Aborted connection 98 to db: 'database_users' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 99 [Warning] Aborted connection 99 to db: 'configurationDB' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 100 [Warning] Aborted connection 100 to db: 'configurationDB' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 101 [Warning] Aborted connection 101 to db: 'database_users' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 208 [Warning] Aborted connection 208 to db: 'configurationDB' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 08 : 58 209 [Warning] Aborted connection 209 to db: 'database_users' user: 'app_user' host: 'localhost' (Got an error reading communication packets) 2024 - 07 - 16 14 : 17 : 01 400 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 04 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 04 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 08 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 08 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 08 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 09 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 09 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 09 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 09 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 09 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 10 390 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 10 392 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 10 392 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */ 2024 - 07 - 16 14 : 17 : 11 2 [ERROR] InnoDB: (Duplicate key) writing word node to FTS auxiliary index table `database_users`.`events` /* Partition `for20240716` */