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

mariadb-binlog cannot process more than 1 logfiles when --stop-datetime is specified

Details

    Description

      Note

      The fix for this issue has been submitted in https://github.com/MariaDB/server/pull/3670. Please review it and provide feedback on GitHub. I am willing to iterate on as many times as you want and with a quick turnaround.

      Description

      This is related to the behavior of mariadb-binlog, and the issue was introduced from minor versions (e.g 10.5.27, 10.6.20...) released on Nov 1, 2024

      According to using-mariadb-binlog, mariadb-binlog should be able to process multiple log files when listing them all on the command line. For example:

      shell> mariadb-binlog mariadb-bin.000001 mariadb-bin.000002

      Since the affected versions, when multiple log files are specified, together with a --stop-datetime parameter value which is later than timestamp of the first log file, mariadb-binlog will exit after processing the first log file, and silently skip other log files. For example

      shell> mariadb-binlog --stop-datetime="2024-11-30 18:52:00" mariadb-bin.000001 mariadb-bin.000002 mariadb-bin.000003

      The result should include events from mariadb-bin.000001 to 000003. However, test result shows that it only returns events in mariadb-bin.000001

      Analysis

      This is related to 2 recent commits: commit1 and commit2 for MDEV-27037.

      The changes set retval to OK_STOP after processing current log file and if not reached the boundary indicated by --stop-datetime or --stop-position

      According to status definition, OK_STOP means it already reached the specified range of events to process, but in these 2 cases, it just reach the end of the log file, but not the specified --stop-datetime or --stop-position

      @retval OK_STOP No error, but the end of the specified range of
        events to process has been reached and the program should terminate.
      

      This causes a problem that in main method, after it processes first log file, it will exit from the for loop, because retval is OK_STOP now, instead of OK_CONTINUE as before, thus following log files will not be processed.

      Proposed Fix

      This problem should be fixed if we remove the code to set retval = OK_STOP in the new commits as below. While we may want to keep the code the emit warnings.

      We will work on a fix and merge the code if no objections.

            /*
              Emit a warning in the event that we finished processing input
              before reaching the boundary indicated by --stop-position.
            */
            if (((longlong)stop_position != stop_position_default) &&
                stop_position > my_b_tell(file))
            {
      --          retval = OK_STOP;
                warning("Did not reach stop position %llu before "
                        "end of input", stop_position);
            }
       
            /*
              Emit a warning in the event that we finished processing input
              before reaching the boundary indicated by --stop-datetime.
            */
            if (stop_datetime != MY_TIME_T_MAX &&
                stop_datetime > last_ev_when)
            {
      --          retval = OK_STOP;
                warning("Did not reach stop datetime '%s' "
                        "before end of input", stop_datetime_str);
            }
      

      Attachments

        Issue Links

          Activity

            xiaochuan.cui Xiaochuan Cui created issue -
            xiaochuan.cui Xiaochuan Cui made changes -
            Field Original Value New Value
            xiaochuan.cui Xiaochuan Cui made changes -
            Description h4. Description
            This is related to the behavior of mariadb-binlog, and the issue was introduced from minor versions (e.g 10.5.27, 10.6.20...) released on Nov 1, 2024

            According to [using-mariadb-binlog|https://mariadb.com/kb/en/using-mariadb-binlog/], mariadb-binlog should be able to process multiple log files when listing them all on the command line. For example:

            {code:shell}shell> mariadb-binlog mariadb-bin.000001 mariadb-bin.000002{code}

            Since the affected versions, when multiple log files are specified, together with a --stop-datetime parameter value which is later than timestamp of the first log file, mariadb-binlog will exit after processing the first log file, and silently skip other log files. For example

            {code:shell}shell> mariadb-binlog --stop-datetime="2024-11-30 18:52:00" mariadb-bin.000001 mariadb-bin.000002 mariadb-bin.000003{code}

            The result should include events from mariadb-bin.000001 to 000003. However, test result shows that it only returns events in mariadb-bin.000001

            h4. Analysis
            This is related to 2 recent commits: [commit1|https://github.com/MariaDB/server/commit/95885261f0] and [commit2|https://github.com/MariaDB/server/commit/242b67f1de] for [MDEV-27037|https://jira.mariadb.org/browse/MDEV-27037].

            The changes set retval to OK_STOP after processing current log file and if not reached the boundary indicated by --stop-datetime or --stop-position

            According to status definition, OK_STOP means it already reached the specified range of events to process, but in these 2 cases, it just reach the end of the log file, but not the specified --stop-datetime or --stop-position
            {code}
            @retval OK_STOP No error, but the end of the specified range of
              events to process has been reached and the program should terminate.
            {code}

            This causes a problem that in [main method|https://github.com/MariaDB/server/blob/mariadb-10.5.27/client/mysqlbinlog.cc#L3139-L3140], after it processes first log file, it will exit from the for loop, because retval is OK_STOP now, instead of OK_CONTINUE as before, thus following log files will not be processed.

            h4. Proposed Fix
            This problem should be fixed if we remove the code to set retval = OK_STOP in the new commits as below. While we may want to keep the code the emit warnings.

            We will work on a fix and merge the code if no objections.

            {code:c}
                  /*
                    Emit a warning in the event that we finished processing input
                    before reaching the boundary indicated by --stop-position.
                  */
                  if (((longlong)stop_position != stop_position_default) &&
                      stop_position > my_b_tell(file))
                  {
            -- retval = OK_STOP;
                      warning("Did not reach stop position %llu before "
                              "end of input", stop_position);
                  }

                  /*
                    Emit a warning in the event that we finished processing input
                    before reaching the boundary indicated by --stop-datetime.
                  */
                  if (stop_datetime != MY_TIME_T_MAX &&
                      stop_datetime > last_ev_when)
                  {
            -- retval = OK_STOP;
                      warning("Did not reach stop datetime '%s' "
                              "before end of input", stop_datetime_str);
                  }
            {code}



            h4. Note
            The fix for this issue has been submitted in https://github.com/MariaDB/server/pull/3670. Please review it and provide feedback on GitHub. I am willing to iterate on as many times as you want and with a quick turnaround.

            h4. Description
            This is related to the behavior of mariadb-binlog, and the issue was introduced from minor versions (e.g 10.5.27, 10.6.20...) released on Nov 1, 2024

            According to [using-mariadb-binlog|https://mariadb.com/kb/en/using-mariadb-binlog/], mariadb-binlog should be able to process multiple log files when listing them all on the command line. For example:

            {code:shell}shell> mariadb-binlog mariadb-bin.000001 mariadb-bin.000002{code}

            Since the affected versions, when multiple log files are specified, together with a --stop-datetime parameter value which is later than timestamp of the first log file, mariadb-binlog will exit after processing the first log file, and silently skip other log files. For example

            {code:shell}shell> mariadb-binlog --stop-datetime="2024-11-30 18:52:00" mariadb-bin.000001 mariadb-bin.000002 mariadb-bin.000003{code}

            The result should include events from mariadb-bin.000001 to 000003. However, test result shows that it only returns events in mariadb-bin.000001

            h4. Analysis
            This is related to 2 recent commits: [commit1|https://github.com/MariaDB/server/commit/95885261f0] and [commit2|https://github.com/MariaDB/server/commit/242b67f1de] for [MDEV-27037|https://jira.mariadb.org/browse/MDEV-27037].

            The changes set retval to OK_STOP after processing current log file and if not reached the boundary indicated by --stop-datetime or --stop-position

            According to status definition, OK_STOP means it already reached the specified range of events to process, but in these 2 cases, it just reach the end of the log file, but not the specified --stop-datetime or --stop-position
            {code}
            @retval OK_STOP No error, but the end of the specified range of
              events to process has been reached and the program should terminate.
            {code}

            This causes a problem that in [main method|https://github.com/MariaDB/server/blob/mariadb-10.5.27/client/mysqlbinlog.cc#L3139-L3140], after it processes first log file, it will exit from the for loop, because retval is OK_STOP now, instead of OK_CONTINUE as before, thus following log files will not be processed.

            h4. Proposed Fix
            This problem should be fixed if we remove the code to set retval = OK_STOP in the new commits as below. While we may want to keep the code the emit warnings.

            We will work on a fix and merge the code if no objections.

            {code:c}
                  /*
                    Emit a warning in the event that we finished processing input
                    before reaching the boundary indicated by --stop-position.
                  */
                  if (((longlong)stop_position != stop_position_default) &&
                      stop_position > my_b_tell(file))
                  {
            -- retval = OK_STOP;
                      warning("Did not reach stop position %llu before "
                              "end of input", stop_position);
                  }

                  /*
                    Emit a warning in the event that we finished processing input
                    before reaching the boundary indicated by --stop-datetime.
                  */
                  if (stop_datetime != MY_TIME_T_MAX &&
                      stop_datetime > last_ev_when)
                  {
            -- retval = OK_STOP;
                      warning("Did not reach stop datetime '%s' "
                              "before end of input", stop_datetime_str);
                  }
            {code}


            bnestere Brandon Nesterenko made changes -
            Assignee Brandon Nesterenko [ JIRAUSER48702 ]
            bnestere Brandon Nesterenko made changes -
            Fix Version/s 10.5 [ 23123 ]
            bnestere Brandon Nesterenko made changes -
            Priority Major [ 3 ] Blocker [ 1 ]
            bnestere Brandon Nesterenko made changes -
            Status Open [ 1 ] In Progress [ 3 ]
            bnestere Brandon Nesterenko made changes -
            Status In Progress [ 3 ] In Review [ 10002 ]

            Made this a blocker, as it is a regression. Though there is a workaround (i.e to process binary log flies one-by-one), so I'd be ok with Critical too.

            bnestere Brandon Nesterenko added a comment - Made this a blocker, as it is a regression. Though there is a workaround (i.e to process binary log flies one-by-one), so I'd be ok with Critical too.
            bnestere Brandon Nesterenko made changes -
            Status In Review [ 10002 ] Stalled [ 10000 ]
            ParadoxV5 Jimmy Hú made changes -
            xiaochuan.cui Xiaochuan Cui made changes -
            bnestere Brandon Nesterenko made changes -
            Status Stalled [ 10000 ] Needs Feedback [ 10501 ]
            ParadoxV5 Jimmy Hú made changes -
            Status Needs Feedback [ 10501 ] Open [ 1 ]
            bnestere Brandon Nesterenko made changes -
            serg Sergei Golubchik made changes -
            Labels regression
            serg Sergei Golubchik made changes -
            Priority Blocker [ 1 ] Critical [ 2 ]
            ParadoxV5 Jimmy Hú made changes -
            Fix Version/s 10.5.28 [ 29952 ]
            Fix Version/s 10.5 [ 23123 ]
            Resolution Fixed [ 1 ]
            Status Open [ 1 ] Closed [ 6 ]
            julien.fritsch Julien Fritsch made changes -
            Fix Version/s 10.6.21 [ 29953 ]
            Fix Version/s 10.11.11 [ 29954 ]
            Fix Version/s 11.4.5 [ 29956 ]
            Fix Version/s 11.7.2 [ 29914 ]

            Pushed into 10.5 as 6e86fe00639

            bnestere Brandon Nesterenko added a comment - Pushed into 10.5 as 6e86fe00639
            oli Oli Sennhauser made changes -
            bnestere Brandon Nesterenko made changes -
            bnestere Brandon Nesterenko made changes -
            ralf.gebhardt Ralf Gebhardt made changes -

            People

              bnestere Brandon Nesterenko
              xiaochuan.cui Xiaochuan Cui
              Votes:
              0 Vote for this issue
              Watchers:
              5 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.