From d2e6fe02d7b41b502fc40d8d40c0253ae5de6f4b Mon Sep 17 00:00:00 2001
From: Monty <monty@mariadb.org>
Date: Mon, 26 Feb 2024 12:10:08 +0200
Subject: [PATCH] Generate a warning(note) and write to error log if
 master_pos_wait() fails.

This is to make it easier to understand why master_pos_wait() fails in mtr.
---
 mysql-test/suite/multi_source/syntax.result      |  2 ++
 .../suite/rpl/r/rpl_master_pos_wait.result       |  8 ++++++++
 sql/item_func.cc                                 |  4 +++-
 sql/rpl_rli.cc                                   | 16 ++++++++++++++++
 4 files changed, 29 insertions(+), 1 deletion(-)

diff --git a/mysql-test/suite/multi_source/syntax.result b/mysql-test/suite/multi_source/syntax.result
index 6b214fe3644..ce60f48c831 100644
--- a/mysql-test/suite/multi_source/syntax.result
+++ b/mysql-test/suite/multi_source/syntax.result
@@ -69,6 +69,8 @@ set @@default_master_connection='';
 select master_pos_wait('master-bin.999999',0,2);
 master_pos_wait('master-bin.999999',0,2)
 -1
+Warnings:
+Note	1105	Timeout waiting for master-bin.999999:4. Current pos is master-bin.000001:329
 set @@default_master_connection='';
 #
 # checking variables
diff --git a/mysql-test/suite/rpl/r/rpl_master_pos_wait.result b/mysql-test/suite/rpl/r/rpl_master_pos_wait.result
index 4d19d81d407..e5943a1f5f2 100644
--- a/mysql-test/suite/rpl/r/rpl_master_pos_wait.result
+++ b/mysql-test/suite/rpl/r/rpl_master_pos_wait.result
@@ -4,6 +4,8 @@ connection slave;
 select master_pos_wait('master-bin.999999',0,2);
 master_pos_wait('master-bin.999999',0,2)
 -1
+Warnings:
+Note	1105	Timeout waiting for master-bin.999999:4. Current pos is master-bin.000001:329
 explain extended select master_pos_wait('master-bin.999999',0,2);
 id	select_type	table	type	possible_keys	key	key_len	ref	rows	filtered	Extra
 1	SIMPLE	NULL	NULL	NULL	NULL	NULL	NULL	NULL	NULL	No tables used
@@ -16,6 +18,8 @@ include/wait_for_slave_sql_to_stop.inc
 connection slave;
 master_pos_wait('master-bin.999999',0)
 NULL
+Warnings:
+Note	1105	master_pos_wait() was aborted because slave is not running
 connection master;
 "*** must be empty ***"
 show slave status;
@@ -34,6 +38,8 @@ include/start_slave.inc
 select master_pos_wait('master-bin.000001',1000000,1);
 master_pos_wait('master-bin.000001',1000000,1)
 -1
+Warnings:
+Note	1105	Timeout waiting for master-bin.000001:1000000. Current pos is master-bin.000001:329
 set default_master_connection = '';
 # Call for non-existing anonymous connection -- works (expected NULL)
 select master_pos_wait('master-bin.000001',1000000,1);
@@ -43,6 +49,8 @@ NULL
 select master_pos_wait('master-bin.000001',1000000,1,"my_slave");
 master_pos_wait('master-bin.000001',1000000,1,"my_slave")
 -1
+Warnings:
+Note	1105	Timeout waiting for master-bin.000001:1000000. Current pos is master-bin.000001:329
 STOP SLAVE 'my_slave';
 RESET SLAVE 'my_slave' ALL;
 change master to master_port=MASTER_MYPORT, master_host='127.0.0.1', master_user='root';
diff --git a/sql/item_func.cc b/sql/item_func.cc
index ec900aadaa2..92fe615a8dd 100644
--- a/sql/item_func.cc
+++ b/sql/item_func.cc
@@ -3931,8 +3931,10 @@ longlong Item_master_pos_wait::val_int()
     connection_name= thd->variables.default_master_connection;
 
   if (!(mi= get_master_info(&connection_name, Sql_condition::WARN_LEVEL_WARN)))
+  {
+    sql_print_information("Could not get master info for %s", connection_name.str);
     goto err;
-
+  }
   if ((event_count = mi->rli.wait_for_pos(thd, log_name, pos, timeout)) == -2)
   {
     null_value = 1;
diff --git a/sql/rpl_rli.cc b/sql/rpl_rli.cc
index b6655a79eb7..d5b0965f79c 100644
--- a/sql/rpl_rli.cc
+++ b/sql/rpl_rli.cc
@@ -937,6 +937,11 @@ int Relay_log_info::wait_for_pos(THD* thd, String* log_name,
     DBUG_PRINT("info",("Got signal of master update or timed out"));
     if (error == ETIMEDOUT || error == ETIME)
     {
+      my_printf_error(ER_UNKNOWN_ERROR,
+                      "Timeout waiting for %s:%llu. Current pos is %s:%llu",
+                      MYF(ME_ERROR_LOG | ME_NOTE),
+                      log_name_tmp, (ulonglong) log_pos,
+                      group_master_log_name, (ulonglong) group_master_log_pos);
       error= -1;
       break;
     }
@@ -957,6 +962,17 @@ improper_arguments: %d  timed_out: %d",
   if (thd->killed || init_abort_pos_wait != abort_pos_wait ||
       !slave_running)
   {
+    const char *cause= 0;
+    if (init_abort_pos_wait != abort_pos_wait)
+      cause= "CHANGE MASTER detected";
+    else if (!slave_running)
+      cause="slave is not running";
+    else
+      cause="connection was killed";
+    my_printf_error(ER_UNKNOWN_ERROR,
+                    "master_pos_wait() was aborted because %s",
+                    MYF(ME_ERROR_LOG | ME_NOTE),
+                    cause);
     error= -2;
   }
   DBUG_RETURN( error ? error : event_count );