MySQL Bugs: #97755: clone plugin doesn't work with innodb_flush_method set to O

Bug #97755	clone plugin doesn't work with innodb_flush_method set to O_DIRECT
Submitted:	22 Nov 2019 20:54	Modified:	17 Jul 2020 14:22
Reporter:	Pradeep Nayak Udupi Kadbet	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: Clone Plugin	Severity:	S3 (Non-critical)
Version:	8.0.17	OS:	CentOS
Assigned to:		CPU Architecture:	Any
Tags:	clone plugin, error, O_DIRECT

Description:
Using the clone plugin in remote mode and running the clone operation on the recipient fails during the FILE_SYNC phase of the clone operation. In the error logs we see:

2019-11-22T11:51:55.433197-08:00 22 [ERROR] [MY-012639] [InnoDB] Write to file /txlogs/3303/ib_logfile0.#clone failed at offset 81396224, 1048576 bytes should have been written, only 0 were written. Operating system error number 22. Check
 that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
2019-11-22T11:51:55.433212-08:00 22 [ERROR] [MY-012640] [InnoDB] Error number 22 means 'Invalid argument'

It seems like the offsets are not correct while writing the file. Changing the innodb_flush_method=fsync doesn't show the problem

How to repeat:
1. start the server with innodb_flush_method set to O_DIRECT
2. perform a remote clone operation and run it on the recipient instance
3. watch the clone operation fail on the recipient and see the following error:
ERROR 1026 (HY000): Error writing file '/txlogs/3303/ib_logfile0.#clone' (errno: 22 - Invalid argument)

Suggested fix:
The file_sync phase should work for all possible flush methods

Hello Pradeep,

Thank you for the report and feedback.
I tried to reproduce the reported issue on 8.0.17(release builds) with provided steps but I'm not seeing any failure at my end. May I request you to provide exact MySQL server configurations(my.cnf from both donar and recipient) details from your environment to reproduce this issue at our end? If this is a source build then exact cmake options used for the build. 

regards,
Umesh

Test results - 8.0.17

Attachment: 97755.results (application/octet-stream, text), 39.58 KiB.

I couldn't reproduce the problem on the latest 8.0 code using O_DIRECT.

mysql> drop database t;
Query OK, 1 row affected (0.11 sec)

mysql> show databases;
+--------------------+
| Database           |
+--------------------+
| information_schema |
| mysql              |
| performance_schema |
| sys                |
+--------------------+
4 rows in set (0.01 sec)

mysql> show  variables like '%flush_method%';
+---------------------+----------+
| Variable_name       | Value    |
+---------------------+----------+
| innodb_flush_method | O_DIRECT |
+---------------------+----------+
1 row in set (0.01 sec)

mysql> SET GLOBAL clone_valid_donor_list = '192.168.1.2:3306';
Query OK, 0 rows affected (0.00 sec)

mysql> CLONE INSTANCE FROM clone@192.168.1.2:3306 identified by '';
Query OK, 0 rows affected (3.26 sec)

mysql> show databases;
No connection. Trying to reconnect...
Connection id:    8
Current database: *** NONE ***

+--------------------+
| Database           |
+--------------------+
| information_schema |
| mysql              |
| performance_schema |
| sys                |
| t                  |
+--------------------+
5 rows in set (0.02 sec)

mysql> select count(*) from t.t;
+----------+
| count(*) |
+----------+
|   131072 |
+----------+
1 row in set (0.12 sec)

Sunny, Umesh - Thanks for taking a look. What filesystem you were using for the repro ? I tried using btrfs and it doesn't repro there. It consistently repros on xfs filesystem. Can you try that ?

I'm using xfs filesystem:

 df -Th /export
Filesystem     Type  Size  Used Avail Use% Mounted on
/dev/sda1      xfs    15T  9.9T  4.8T  68% /export

Are you using default server configuration? If not then please share my.cnf from your environment to try out at our end. Thank you.

regards,
Umesh

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".

I just wanted to point out that this is reproducible with the Facebook fb-mysql-8.0.17

Hi,

We do need to have it reproduced with our own MySQL 8.0.21 server.

Let us know if you are successful in that endeavour.

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".

version: 8.0.24 MySQL Community Server - GPL

```
mysql> clone local data directory='/data3/lz_clone/tmp4';
ERROR 1026 (HY000): Error writing file '/data3/lz_clone/tmp4/ib_logfile0' (errno: 22 - Invalid argument)
mysql> \s
--------------

Connection id:		8
Current database:
Current user:		root@localhost
SSL:			Not in use
Current pager:		stdout
Using outfile:		''
Using delimiter:	;
Server version:		8.0.24 MySQL Community Server - GPL
Protocol version:	10
Connection:		Localhost via UNIX socket
Server characterset:	utf8mb4
Db     characterset:	utf8mb4
Client characterset:	latin1
Conn.  characterset:	latin1
UNIX socket:		/tmp/mysql_30359.sock
Binary data as:		Hexadecimal
Uptime:			2 min 11 sec

Threads: 2  Questions: 9  Slow queries: 1  Opens: 137  Flush tables: 3  Open tables: 56  Queries per second avg: 0.068
--------------

mysql> select @@innodb_flush_method;
+-----------------------+
| @@innodb_flush_method |
+-----------------------+
| O_DIRECT              |
+-----------------------+
1 row in set (0.00 sec)
```

We fixed the bug with this patch -- https://github.com/facebook/mysql-5.6/commit/839325f61805fcb605c7af759d6ff086609a208a

We fixed the bug with this patch -- https://github.com/facebook/mysql-5.6/commit/839325f61805fcb605c7af759d6ff086609a208a

We fixed the bug with this patch -- https://github.com/facebook/mysql-5.6/commit/839325f61805fcb605c7af759d6ff086609a208a