[MDEV-11154] Write_on_release_cache(log_event.cc) function will not write "COMMIT", if use "mysqlbinlog ... | mysql ..." Created: 2016-10-27  Updated: 2023-11-28

Status: Stalled
Project: MariaDB Server
Component/s: Data Manipulation - Update, Replication
Affects Version/s: 10.1.17
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0

Type: Bug Priority: Minor
Reporter: vincen Assignee: Kristian Nielsen
Resolution: Unresolved Votes: 0
Labels: None
Environment:

suse 11


Attachments: PNG File mysqlbinlog1.PNG     PNG File mysqlbinlog2.PNG     PNG File mysqlbinlog3.PNG     PNG File mysqlbinlog4.PNG     PNG File mysqlbinlog5.PNG     PNG File mysqlbinlog6.PNG    

 Description   

Executing command, "mysqlbinlog --read-from-remote-server --host='xx.xx.xx.xx' --port=3306 --user=xxx --password=xxx --database=mysql --to-last-log mysql-bin.000001 --start-position=1098699 --stop-never |mysql -uxxx -pxxx", we found that last data read from remote couldn't commit. Write_on_release_cache(log_event.cc) function may have some problems.

In Write_on_release_cache(log_event.cc) function have following code:

public:
  enum flag
  {
    FLUSH_F
  };
...
  Write_on_release_cache(IO_CACHE *cache, FILE *file, flag_set flags = 0)
    : m_cache(cache), m_file(file), m_flags(flags)
  {
    reinit_io_cache(m_cache, WRITE_CACHE, 0L, FALSE, TRUE);
  }
 
  ~Write_on_release_cache()
  {
    copy_event_cache_to_file_and_reinit(m_cache, m_file);
    if (m_flags & FLUSH_F)
      fflush(m_file);
  }
...

The right code maybe:

public:
  enum flag
  {
    FLUSH_F = 1
  };
...



 Comments   
Comment by Elena Stepanova [ 2016-11-03 ]

Can you demonstrate the problem somehow, and/or describe the steps to reproduce?

Comment by vincen [ 2016-11-03 ]

before change:
step1:
execute command at local(10.10.10.1): "mysqlbinlog --read-from-remote-server --host='10.10.10.2' --port=3306 --user=root --password=xxx --database=mysql --to-last-log mysql-bin.000001 --start-position=4748 --stop-never |mysql -uroot -pxxx"

step2:
execute insert sql in remote server(10.10.10.2): "insert into test values(2,'aaa',2000);"

step3:
execute select sql in local server(10.10.10.1): "select * from test;"

step4:
execute insert sql in remote server(10.10.10.2): "insert into test values(3,'bbb',2000);"

step5:
execute select sql in local server(10.10.10.1): "select * from test;"

According to these steps above, we can find that last data read from remote doesn't commit. However, we solved this problem by changing the code described above.

Comment by vincen [ 2016-11-03 ]

After querying current events in local server(10.10.10.1), we can find there is an event have not been committed.

Comment by Elena Stepanova [ 2016-11-03 ]

What is the relation between "remote server" and "local server"? Is "remote" a master, and "local" is a slave?
Please also attach your cnf file(s).

Comment by vincen [ 2016-11-04 ]

No. They don't have any relations. We just want to synchronize data of remote server to the local by using this method.

Comment by Elena Stepanova [ 2016-11-04 ]

Okay, so you basically "replicate" by means of mysqlbinlog – you make it read from a "remote" server, and write into the "local" one. Thanks, I understand now.

Comment by vincen [ 2016-11-08 ]

OK. And then, in which version will this bug be fixed?

Comment by Sujatha Sivakumar (Inactive) [ 2019-07-09 ]

Hello Andrei,

Please review the fix for MDEV-11154.

Patch: https://github.com/MariaDB/server/commit/2cb0fdd7b54d46f153a66462f1e78c3cee47c9f2
BB: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha

Thank you
S.Sujatha

Comment by Andrei Elkin [ 2019-07-09 ]

Sujatha, thanks for a good piece of analysis! The patch is fine.

Comment by Andrei Elkin [ 2019-07-11 ]

The 10.2 commit looks good, Sujatha.

Comment by Sujatha Sivakumar (Inactive) [ 2019-07-15 ]

Fix has been implemented in 10.1.41.

There are some additional changes required for 10.2+ versions.

Please refer
https://github.com/MariaDB/server/commit/096722b61ebe66ffe510156d358d4ddbeb53241a

The patch has been tested on all higher versions.

Comment by Yury Chaikou [ 2023-06-14 ]

This patch should also be ported to 10.5 and all later versions, including the latest 11.1

Comment by Andrei Elkin [ 2023-06-15 ]

yury.chaikou, do you mean the bug is present in higher versions (than those in Fixed box)? Just in case the higher version are not listed 'cos they did not exist at time
of 10.2.26.

Comment by Yury Chaikou [ 2023-06-15 ]

Andrei, correct, the bug is present in any version higher than those in Fixed box.
For example, check the latest https://github.com/MariaDB/server/blob/11.1/sql/log_event.cc:

  enum flag
  {
    FLUSH_F
  };

Comment by Kristian Nielsen [ 2023-06-16 ]

As Yury Chaikou noticed, the fix for this MDEV-11154 was merged incorrectly to 10.5:

commit 624dd71b9419555eca8baadc695e3376de72286f
Merge: d4d865fcc80 e9c1701e11e
Author: Marko Mäkelä <marko.makela@mariadb.com>
Date:   Tue Aug 13 18:57:00 2019 +0300
 
    Merge 10.4 into 10.5

The fix got null-merged to 10.5, which probably is not what was intended, as now all the logic using FLUSH_F is dead code:

$ git diff 624dd71b9419555eca8baadc695e3376de72286f^1 624dd71b9419555eca8baadc695e3376de72286f -- sql/log_event.cc
# Empty output

However, the original bug, which is missing fflush() by mysqlbinlog on the output, seems nevertheless to not occur. The reason for this is another merge:

commit 69628551858825bebc3f1653882920e4f6555cbb
Merge: 26b594e4110 10ebdb7f1d7
Author: Marko Mäkelä <marko.makela@mariadb.com>
Date:   Thu Jul 18 13:10:09 2019 +0300
 
    Merge 10.1 into 10.2

$ git diff 696285518588^1 696285518588 -- client/mysqlbinlog.cc
  diff --git a/client/mysqlbinlog.cc b/client/mysqlbinlog.cc
  index 1516e08284b..acccf0a3411 100644
  --- a/client/mysqlbinlog.cc
  +++ b/client/mysqlbinlog.cc
  @@ -1534,6 +1534,7 @@ Exit_status process_event(PRINT_EVENT_INFO *print_event_info, Log_event *ev,
	 {
	   my_fwrite(result_file, (const uchar *) tmp_str.str, tmp_str.length,
		     MYF(MY_NABP));
  +        fflush(result_file);
	   my_free(tmp_str.str);
	 }
       }

I think this occured because the mysqlbinlog code is somewhat different between 10.1 and 10.2, so the MDEV-11154 flush bug is fixed differently with the new code with this fflush().
As a result, the whole FLUSH_F code in log_event_client.cc may now be mostly dead code, and should maybe be removed; or if still in use, the FLUSH_F enum should be fixed.

Interestingly, the test case for this bug (binlog_mysqlbinlog_stop_never.test) seems also to be wrong now. It is trying to do something like:

    mysqlbinlog ... | mysql ...

But the problem is that the events will be applied by the `mysql` command with binlogging enabled, which will loop around and endlessly stream events through mysqlbinlog (or rather, until a duplicate GTID or row error stops it); in any case it doesn't reliably test the missing fflush() reliably. So this should also be fixed. I think can be fixed with something like this:

    ( echo 'set @@SESSION.SQL_LOG_BIN = 0;' ; mysqlbinlog ... ) | mysql ...

Since the bug itself seems to not be present, reopening with a low priority.

Hope this helps,

- Kristian.

Generated at Thu Feb 08 07:47:43 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.