[MDEV-19900] Failed to open the relay log after update Created: 2019-06-28  Updated: 2019-08-27  Resolved: 2019-07-17

Status: Closed
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.4.6
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: sjon Assignee: Sujatha Sivakumar (Inactive)
Resolution: Not a Bug Votes: 0
Labels: slave-configuration


 Description   

Something caused 10.4.6 to fail on startup on our upgraded (from 10.3.16) node. I can't find any documentation as to what can be done to fix this, other then a rollback

[Note] Reading Master_info: 'master-db1.info'  Relay_info:'relay-log-db1.info'
[Warning] Neither \-\-relay-log nor \-\-relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--log-basename=#' or '--relay-log=db2-relay-bin' to avoid this problem.
[ERROR] Failed to open the relay log './mysql-relay-bin-db1.000002' (relay_log_pos 134241)
[ERROR] Could not find target log during relay log initialization
[ERROR] Initialized Master_info from 'master-db1.info' failed
[Note] Added new Master_info 'db1' to hash table
[Warning] Reading of some Master_info entries failed
[ERROR] Failed to initialize multi master structures
[ERROR] Aborting

but mysqlbinlog shows the specified relay_log_pos is actually present:

mysqlbinlog /var/lib/mysql/mysql-relay-bin-db1.000002|tail
# at 134210
{{#190628 11:25:49 server id 1 end_log_pos 133942 CRC32 0x8acb5d0c Xid = 4956}}
COMMIT/!/;
# at 134241
{{#190628 11:25:59 server id 2 end_log_pos 134264 CRC32 0xe059508d Stop}}
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE/;
/!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0/;



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

Hello Sjon,

Thanks for reporting the issue.

The bug description has following details.

[Note] Reading Master_info: 'master-db1.info' Relay_info:'relay-log-db1.info'
[Warning] Neither --relay-log nor --relay-log-index were used; so
replication may break when this MySQL server acts as a slave and has his
hostname changed!! Please use '--log-basename=#' or
'--relay-log=db2-relay-bin' to avoid this problem. [ERROR] Failed to open the
relay log './mysql-relay-bin-db1.000002' (relay_log_pos 134241)

Looks like no basename was specified for the "relay-log" file. When the
basename is not set, the default basename will be hostname-relay-bin. The base
name is critical as all 'relay-log' files and their corresponding index files
will use the same base name.

For example: If basename='db1'
db1-relay-bin.index
db1-relay-bin.000001

Has the host name has been changed from 'db1' to 'db2'?
Prior to the upgrade the default basename is 'db1'. Post upgrade the default
basename is 'db2'. When the base name is changed a new index file and a new
relay log file will be created as per the new base name. The newly created
index file will not have entries of the old relay logs.

New default basename='db2'
db2-relay-bin.index
db2-relay-bin.000001

i.e prior to upgrade the slave would have been using 'db1-relay-bin.000001'.
Upon restart after upgrade it will try to look for 'db1-relay-bin.0000001' in
'db2-relay-bin.index' file. It will not be found. Hence the slave
initialization will fail.

Because of this issue even though the old relay log exists it will not be
used. To avoid such issues a valid basename should be provided by setting
'relay_log'.
https://mariadb.com/kb/en/library/replication-and-binary-log-system-variables/#relay_log

Comment by sjon [ 2019-07-10 ]

Hello Sujatha,

thanks for your extensive explanation. This error comes from a machine that is called db1 and it replicates from another machine that is called db2. While I could set relay-log as suggested, this machine will never have it's hostname changed so it doesn't seem applicable.

Fyi; this is what the binlogs are currently named:

  • mysql-bin.000004
  • mysql-bin.000005
  • mysql-bin.000006
  • mysql-bin.index
  • mysql-relay-bin-db2.000001
  • mysql-relay-bin-db2.000002
  • mysql-relay-bin-db2.index

It seems to me the default basename is not the issue? Why does mariadb-10.4 fail on Failed to open the relay log if that file is present and perfectly readable?

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

Hello Sjon,

Thanks for the updates. The reason why open relay log fails is explained
below.

The sql Thread maintains its positions in a file named "relay-log.info"
Prior to upgrade the "relay-log.info" file will look like this. Sample
relay-log.info.

File: relay-log.info
5
./mysql-relay-bin-db1.000002
134241
...

Relay log file name and index file names would be:
mysql-relay-bin-db1.000002
mysql-relay-bin-db1.000001
mysql-relay-bin-db1.index

In the latest update you mentioned that the files are currently named like
this with "-db2":

mysql-relay-bin-db2.000001
mysql-relay-bin-db2.000002
mysql-relay-bin-db2.index

The issue is caused because of this newly named index files.

When server is restarted after upgrade it tries to initialize the slave threads
by reading the 'relay-log.info' file. The 'relay-log.info' file has an entry
named "mysql-relay-bin-db1.000002". Server will open the new index file named
"mysql-relay-bin-db2.index" and look for "mysql-relay-bin-db1.000002". But
the new index file will look as shown below.

File:mysql-relay-bin-db2.index
./mysql-relay-bin-db2.000001
./mysql-relay-bin-db2.000002

It will fail to locate the file name in index file. Hence the error is
reported.

One way of fixing this issue would be to prepend the old relay log index file
to the new relay log index file, and restart the slave as mentioned in the
documentation.

https://mariadb.com/kb/en/library/relay-log/

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

Hello Sjon,

Good morning.

Were the above document references helpful to resolve the reported issue?

Please let us know.

From the MDEV description it looks like "log-basename", "relay-log" and
"relay-log-index" options were not provided and there is no change in
hostname "db1" on the slave server. Can you please let us know how
the following naming was done.

mysql-relay-bin-db2.000001
mysql-relay-bin-db2.000002
mysql-relay-bin-db2.index

Thank you.

Comment by sjon [ 2019-07-17 ]

Hello Sujatha,

it took some debugging but you were correct - we used to have relay_log=mysql-relay-bin configured, but our distribution (Archlinux) moved from /etc/mysql to /etc/my.cnf.d , effectively removing our custom configuration. After reinstating that setting I have successfully upgraded our cluster.

Thanks again!

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