[MDEV-23846] O_TMPFILE error in mysqlbinlog stream output breaks restore Created: 2020-09-29  Updated: 2021-08-25  Resolved: 2020-11-24

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Replication
Affects Version/s: 10.4.11
Fix Version/s: 10.4.18, 10.5.9

Type: Bug Priority: Major
Reporter: Kyle Joiner (Inactive) Assignee: Sujatha Sivakumar (Inactive)
Resolution: Fixed Votes: 0
Labels: None
Environment:

RHEL

Issue Links:
Relates
relates to MDEV-22202 mysqld: O_TMPFILE is not supported on... Closed

 Description   

When O_TMPFILE is not supported mysqlbinlog outputs the error to standard stream as a warning which breaks PITR:

ERROR 1064 (42000) at line 382: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)

 Comments   
Comment by Sujatha Sivakumar (Inactive) [ 2020-10-06 ]

Reproduced the issue on 10.5.

test-10.5/bld/mysql-test$ ../client/mysqlbinlog ./var/mysqld.1/data/master-bin.000001 -v -v > test.sql
../client/mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)

Will have to reproduce the same on lower version as well.

Comment by Sujatha Sivakumar (Inactive) [ 2020-10-08 ]

During the process of decoding the binary log using 'mysqlbinlog', the client
tool stores the events into an IO_CACHE and when the IO_CACHE is full its
contents are flushed into a temporary file. The temporary file creation is
attempted using 'O_TMPFILE' flag. If the underlying filesystem doesn't support
this operation, a note is printed on the standard output as shown below. It is
not an error.

MDEV-23846-10.4/bld/mysql-test$ ../client/mysqlbinlog ./var/mysqld.1/data/master-bin.000001 > out.sql
 
../client/mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)

The file creation is done without O_TMPFILE' flag, hence it doesn't alter
the binlog events. 'mysqlbinlog' tool exits gracefully. Please find the command
exit status being '0'.

MDEV-23846-10.4/bld/mysql-test$ ../client/mysqlbinlog ./var/mysqld.1/data/master-bin.000001 > out.sql
 
../client/mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)
 
 
 
MDEV-23846-10.4/bld/mysql-test$ echo $?
 
0

Restore operation also works fine. Please find the following test results

MariaDB [(none)]> use test;
 
Database changed
 
MariaDB [test]> create table t(f text) engine=innodb;
 
Query OK, 0 rows affected (0.020 sec)
 
MariaDB [test]> insert into t values (repeat('x',4096));
 
Query OK, 1 row affected (0.061 sec)
 
MariaDB [test]> insert into t select * from t;
 
Query OK, 1 row affected (0.059 sec)
 
Records: 1  Duplicates: 0  Warnings: 0
 
MariaDB [test]> insert into t select * from t;
 
Query OK, 2 rows affected (0.008 sec)
 
Records: 2  Duplicates: 0  Warnings: 0
 
MariaDB [test]> insert into t select * from t;
 
Query OK, 4 rows affected (0.009 sec)
 
Records: 4  Duplicates: 0  Warnings: 0
 
MariaDB [test]> insert into t select * from t;
 
Query OK, 8 rows affected (0.011 sec)
 
Records: 8  Duplicates: 0  Warnings: 0
 
MariaDB [test]> insert into t select * from t;
 
Query OK, 16 rows affected (0.020 sec)
 
Records: 16  Duplicates: 0  Warnings: 0
 
MariaDB [test]> insert into t select * from t;
 
Query OK, 32 rows affected (0.055 sec)
 
Records: 32  Duplicates: 0  Warnings: 0
 
MariaDB [test]> exit
 
Bye

Generate 'test.sql' file:

MDEV-23846-10.4/bld/mysql-test$ ../client/mysqlbinlog ./var/mysqld.1/data/master-bin.000001 > test.sql
 
../client/mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)

Start mysql client and drop the table 't'. Restore the test.sql file.

MariaDB [(none)]> use test;
 
Reading table information for completion of table and column names
 
You can turn off this feature to get a quicker startup with -A
 
 
 
Database changed
 
MariaDB [test]> DROP TABLE t;
 
Query OK, 0 rows affected (0.065 sec)

Source 'test.sql' to mysql client.

MDEV-23846-10.4/bld/mysql-test$ ../client/mysql -uroot -S/home/sujatha/bug_repo/MDEV-23846-10.4/bld/mysql-test/var/tmp/mysqld.1.sock < test.sql
 
 
 
MariaDB [test]> show tables;
 
+----------------+
 
| Tables_in_test |
 
+----------------+
 
| t              |
 
+----------------+
 
1 row in set (0.002 sec)
 
 
 
MariaDB [test]> select count(*) from t;
 
+----------+
 
| count(*) |
 
+----------+
 
|       64 |
 
+----------+
 
1 row in set (0.006 sec)

From support case, found the following information:

$ mysqlbinlog -u**** -p --start-position=397 --base64-output=decode-rows bin_log.000404 > /mariadb/backup/test.sql 2>&1
 
Enter password:
 
$ mysql -u**** -p < /mariadb/backup/test.sql
 
Enter password:
 
ERROR 1064 (42000) at line 382: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)

Users should not use '2>&1'. With this redirection, the information displayed on screen gets written to 'test.sql'.
Since it is not a valid 'SQL' statement the above error 'ERROR 1064' is returned by mysql client.

Incorrect usage: mysqlbinlog -u**** -p --start-position=397 --base64-output=decode-rows bin_log.000404 > /mariadb/backup/test.sql 2>&1
Correct usage : mysqlbinlog -u**** -p --start-position=397 --base64-output=decode-rows bin_log.000404 > /mariadb/backup/test.sql

Hence it is not a bug.

Comment by Sujatha Sivakumar (Inactive) [ 2020-10-30 ]

Hello ccalender

I verified once again and observed that message '../client/mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)' doesn't break point-in-time recovery. Database is restored to expected state.

 '../client/mysqlbinlog: O_TMPFILE is not supported on /tmp (disabling future attempts)'

is an informative message which gets printed on output screen, it is not an error as mentioned in https://jira.mariadb.org/browse/MDEV-22202.

Another observation from customer's data is "--base64-ouput=decode-rows" option is provided for 'mysqlbinlog' tool as shown below. This option suppresses BINLOG statements and does not print anything. Hence the resulting sql file cannot be used for point in time recovery.

mysqlbinlog -u user -p --start-position=****  --base64-output=decode-rows bin_log.*****  --vv > /mariadb/backup/first_bin_log.sql

Can you please let us know if customer observed any data loss during binlog replay?
How point in time recovery is broken?
It would be good to get a reproducible test scenario to demonstrate 'point in time recovery failure'.

Comment by Sujatha Sivakumar (Inactive) [ 2020-11-19 ]

Hello Elkin

I have implemented a patch to suppress the note, as per ccalender requirement.

Please review the changes: https://github.com/MariaDB/server/commit/99e160d3ddf077ece968932e26f741a7a43f0243
BuildBot test: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.4-sujatha

Comment by Sujatha Sivakumar (Inactive) [ 2020-11-20 ]

Hello danblack

Can you please review the following changes for MDEV-23846.

Patch: https://github.com/MariaDB/server/commit/99e160d3ddf077ece968932e26f741a7a43f0243

Thank you.

Comment by Daniel Black [ 2020-11-21 ]

Looks good to me. I accept this change.

Comment by Sujatha Sivakumar (Inactive) [ 2020-11-24 ]

Fix implemented in 10.4.18

Patch tested on higher versions.
No merge conflicts were observed.

10.5: https://github.com/MariaDB/server/commit/41970d89d88ff318673414d4ae02f1a380415250
10.6: https://github.com/MariaDB/server/commit/886284cdd8023e8c70e0f2a27025e8562e50df42

Generated at Thu Feb 08 09:25:29 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.