Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-15010

Wrong Seconds_Behind_Master when only starting the SQL_Thread.

Details

    Description

      Hi,

      When I run replication normally, I get a value in "Seconds_Behind_Master" from "SHOW SLAVE STATUS". However, when I run only the SQL Thread (on local relay logs that have been downloaded previously), I have "NULL" in "Seconds_Behind_Master". I would expect to have a numeric value.

      Also, note that the manual ([1]) does not document a "NULL" value in "Seconds_Behind_Master", even if "NULL" is shown when the SQL Thread is not running. This might be a different bug thought and is documentation related.

      [1]: https://mariadb.com/kb/en/library/show-slave-status/

      mysql <<< "select version();"
      version()
      10.2.12-MariaDB-log
      

      mysql <<< "start slave; do sleep(1); show slave status\G stop slave" | grep Seconds_Behind_Master
              Seconds_Behind_Master: 130422
      

      mysql <<< "start slave sql_thread; do sleep(1); show slave status\G stop slave" | grep Seconds_Behind_Master
              Seconds_Behind_Master: NULL
      

      mysql <<< "stop slave; do sleep(1); show slave status\G" | grep Seconds_Behind_Master
              Seconds_Behind_Master: NULL
      

      Many thanks for looking into that,

      JFG

      Attachments

        Activity

          elenst Elena Stepanova added a comment - - edited

          It looks like a usual documentation deficiency. MySQL manual actually describes it quite explicitly:

          In MySQL 5.6.9 and later, this field is NULL (undefined or unknown) if the slave SQL thread is not running, or if the SQL thread has consumed all of the relay log and the slave I/O thread is not running. Previously, this field was NULL if the slave SQL thread or the slave I/O thread was not running or was not connected to the master.

          https://dev.mysql.com/doc/refman/5.6/en/show-slave-status.html

          So, both before and after 5.6.9, the field was/is NULL when IO thread was not running.
          I'll leave it to Elkin to decide if he wants to change it. In any case, it should be documented much better, since Seconds_Behind_Master is one of the most notoriously confusing status values in MySQL / MariaDB.

          --source include/master-slave.inc
           
          create table t1 (i int);
          drop table t1;
           
          --sync_slave_with_master
           
          --let $status_items= Seconds_Behind_Master
          --source include/show_slave_status.inc
           
          STOP SLAVE IO_THREAD;
          --source include/wait_for_slave_io_to_stop.inc
           
          --let $status_items= Seconds_Behind_Master
          --source include/show_slave_status.inc
           
          START SLAVE IO_THREAD;
          --source include/wait_for_slave_io_to_start.inc
           
          --let $status_items= Seconds_Behind_Master
          --source include/show_slave_status.inc
           
          --connection master
           
          create table t1 (i int);
          drop table t1;
           
          --sync_slave_with_master
           
          --let $status_items= Seconds_Behind_Master
          --source include/show_slave_status.inc
           
          # Cleanup
           
          --connection master
          --source include/rpl_end.inc
          

          output

          include/master-slave.inc
          [connection master]
          create table t1 (i int);
          drop table t1;
          connection slave;
          Seconds_Behind_Master = '0'
          STOP SLAVE IO_THREAD;
          include/wait_for_slave_io_to_stop.inc
          Seconds_Behind_Master = 'NULL'
          START SLAVE IO_THREAD;
          include/wait_for_slave_io_to_start.inc
          Seconds_Behind_Master = '0'
          connection master;
          create table t1 (i int);
          drop table t1;
          connection slave;
          Seconds_Behind_Master = '0'
          connection master;
          include/rpl_end.inc
          bug.mdev15010 'mix'                      [ pass ]    992
          

          elenst Elena Stepanova added a comment - - edited It looks like a usual documentation deficiency. MySQL manual actually describes it quite explicitly: In MySQL 5.6.9 and later, this field is NULL (undefined or unknown) if the slave SQL thread is not running, or if the SQL thread has consumed all of the relay log and the slave I/O thread is not running. Previously, this field was NULL if the slave SQL thread or the slave I/O thread was not running or was not connected to the master. https://dev.mysql.com/doc/refman/5.6/en/show-slave-status.html So, both before and after 5.6.9, the field was/is NULL when IO thread was not running. I'll leave it to Elkin to decide if he wants to change it. In any case, it should be documented much better, since Seconds_Behind_Master is one of the most notoriously confusing status values in MySQL / MariaDB. --source include/master-slave.inc   create table t1 (i int ); drop table t1;   --sync_slave_with_master   --let $status_items= Seconds_Behind_Master --source include/show_slave_status.inc   STOP SLAVE IO_THREAD; --source include/wait_for_slave_io_to_stop.inc   --let $status_items= Seconds_Behind_Master --source include/show_slave_status.inc   START SLAVE IO_THREAD; --source include/wait_for_slave_io_to_start.inc   --let $status_items= Seconds_Behind_Master --source include/show_slave_status.inc   --connection master   create table t1 (i int ); drop table t1;   --sync_slave_with_master   --let $status_items= Seconds_Behind_Master --source include/show_slave_status.inc   # Cleanup   --connection master --source include/rpl_end.inc output include/master-slave.inc [connection master] create table t1 (i int); drop table t1; connection slave; Seconds_Behind_Master = '0' STOP SLAVE IO_THREAD; include/wait_for_slave_io_to_stop.inc Seconds_Behind_Master = 'NULL' START SLAVE IO_THREAD; include/wait_for_slave_io_to_start.inc Seconds_Behind_Master = '0' connection master; create table t1 (i int); drop table t1; connection slave; Seconds_Behind_Master = '0' connection master; include/rpl_end.inc bug.mdev15010 'mix' [ pass ] 992
          Elkin Andrei Elkin added a comment -

          Thanks elenst for bring some background and showing it with a test!

          Indeed Mariadb behaviour in this regard is like mysql before 5.6.9: NULL is displayed
          when the IO thread is down, regardless of the SQL thread status.
          To display a numeric value when the IO thread is down is reasonable, as well to indicate
          about the reached synchronization with NULL rather than 0 of when the IO thread is up.

          Elkin Andrei Elkin added a comment - Thanks elenst for bring some background and showing it with a test! Indeed Mariadb behaviour in this regard is like mysql before 5.6.9: NULL is displayed when the IO thread is down, regardless of the SQL thread status. To display a numeric value when the IO thread is down is reasonable, as well to indicate about the reached synchronization with NULL rather than 0 of when the IO thread is up.
          sujatha.sivakumar Sujatha Sivakumar (Inactive) added a comment - Hello Andrei, Can you please review the fixes for MDEV-15010 . http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-5.5-sujatha https://github.com/MariaDB/server/commit/fb619954867232b3a733213a2703b2a425dff8e9 Thank you
          bnestere Brandon Nesterenko added a comment - - edited

          Hi jeanfrancois.gagne,

          I think MDEV-33856 (New definition for Seconds_behind_master) should solve this issue, (albeit not in the Seconds_behind_master field, which we are considering deprecating). The IO thread will update Master_last_event_time to be the event timestamp of the last received event from the master, and the value will persist when the IO thread is later stopped (though RESET MASTER will reset it). Similarly, the SQL thread will update Slave_last_event_time to be the event timestamp of the last committed transaction.

          If you agree that this solves your needs, I'd like to close this issue (as we wouldn't be able to push a fix for it in a GA release anyway, as it may break existing user's scripts). Note that MDEV-33856 debuts in 11.6, which is not quite yet released, but does have a preview release available if you'd like to test it. And also note that MDEV-33856 includes a new way to view the slave status via the INFORMATION_SCHEMA.SLAVE_STATUS table

          bnestere Brandon Nesterenko added a comment - - edited Hi jeanfrancois.gagne , I think MDEV-33856 (New definition for Seconds_behind_master) should solve this issue, (albeit not in the Seconds_behind_master field, which we are considering deprecating). The IO thread will update Master_last_event_time to be the event timestamp of the last received event from the master, and the value will persist when the IO thread is later stopped (though RESET MASTER will reset it). Similarly, the SQL thread will update Slave_last_event_time to be the event timestamp of the last committed transaction. If you agree that this solves your needs, I'd like to close this issue (as we wouldn't be able to push a fix for it in a GA release anyway, as it may break existing user's scripts). Note that MDEV-33856 debuts in 11.6, which is not quite yet released, but does have a preview release available if you'd like to test it. And also note that MDEV-33856 includes a new way to view the slave status via the INFORMATION_SCHEMA.SLAVE_STATUS table

          > The current definition of Seconds_Behind_Master is both complex and confusing

          It was explained to me that this is because InnoDB did not exist when it was 1st introduced. Without transaction, it made sense.

          > The IO thread will update Master_last_event_time to be the event timestamp of the last received event from the master

          LGTM...

          > though RESET MASTER will reset it

          RESET MASTER ? I would understand RESET SLAVE, but resetting with RESET MASTER does not make sense to me...

          > the SQL thread will update Slave_last_event_time to be the event timestamp of the last committed transaction

          LGTM...

          > I'd like to close this issue

          Ok for closing and continuing in MDEV-33856...

          > a new way to view the slave status via the INFORMATION_SCHEMA.SLAVE_STATUS

          Nice !

          Thanks for closing the look on this Brandon.

          jeanfrancois.gagne Jean-François Gagné added a comment - > The current definition of Seconds_Behind_Master is both complex and confusing It was explained to me that this is because InnoDB did not exist when it was 1st introduced. Without transaction, it made sense. > The IO thread will update Master_last_event_time to be the event timestamp of the last received event from the master LGTM... > though RESET MASTER will reset it RESET MASTER ? I would understand RESET SLAVE, but resetting with RESET MASTER does not make sense to me... > the SQL thread will update Slave_last_event_time to be the event timestamp of the last committed transaction LGTM... > I'd like to close this issue Ok for closing and continuing in MDEV-33856 ... > a new way to view the slave status via the INFORMATION_SCHEMA.SLAVE_STATUS Nice ! Thanks for closing the look on this Brandon.

          > RESET MASTER ? I would understand RESET SLAVE, but resetting with RESET MASTER does not make sense to me...

          Ah that was my blunder, I meant slave, thanks for an astute correction!

          Thanks for the quick response!

          bnestere Brandon Nesterenko added a comment - > RESET MASTER ? I would understand RESET SLAVE, but resetting with RESET MASTER does not make sense to me... Ah that was my blunder, I meant slave, thanks for an astute correction! Thanks for the quick response!

          Closing this as won't fix because MDEV-33856 (in 11.6) solves the problem better.

          bnestere Brandon Nesterenko added a comment - Closing this as won't fix because MDEV-33856 (in 11.6) solves the problem better.

          People

            Elkin Andrei Elkin
            jeanfrancois.gagne Jean-François Gagné
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.