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

Invalid WSREP_SST rows appear in mysqld-bin.index file

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 10.0.16-galera
    • Fix Version/s: 10.0.20-galera
    • Component/s: Galera SST
    • Labels:
      None
    • Sprint:
      10.1.6-1

      Description

      Invalid rows appear in mysqld-bin.index file, causing server to fail starting. This occurs when WSREP galera replication was enabled. The rows do not point to a valid file but are instead output of wsrep sst.

      Example of contents of mysqld-bin.index:

      mysqld-bin.000001
      ./mysqld-bin.000002
      ./mysqld-bin.000003
      WSREP_SST: [INFO] Preparing binlog files for transfer: (20150224 21:17:07.205)
      mysqld-bin.000004
      ./mysqld-bin.000005
      ./mysqld-bin.000006
      ./mysqld-bin.000007
      WSREP_SST: [INFO] Bypassing state dump. (20150224 21:20:00.648)
      

      on #maria irc channel was mentioned that:

      "looks like when mariadb forks for a sst it should close all fds for the sst"

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

              Hide
              danblack Daniel Black added a comment -

              On a SST (rsync method) donor on a 10.0.21 instances I still see a lot of files open for tar generating binlogs.

              COMMAND  PID  USER   FD   TYPE  DEVICE    SIZE/OFF    NODE NAME
              tar     3825 mysql  cwd    DIR   253,0       40960 2997037 /var/lib/mysql
              tar     3825 mysql  rtd    DIR   253,0        4096       2 /
              tar     3825 mysql  txt    REG   253,0      390616  261280 /bin/tar
              tar     3825 mysql  mem    REG   253,0       65928  651690 /lib64/libnss_files-2.12.so
              tar     3825 mysql  mem    REG   253,0      142640  651563 /lib64/libpthread-2.12.so
              tar     3825 mysql  mem    REG   253,0       18712  651585 /lib64/libattr.so.1.1.0
              tar     3825 mysql  mem    REG   253,0       19536  651672 /lib64/libdl-2.12.so
              tar     3825 mysql  mem    REG   253,0     1921216  651539 /lib64/libc-2.12.so
              tar     3825 mysql  mem    REG   253,0       43880  651724 /lib64/librt-2.12.so
              tar     3825 mysql  mem    REG   253,0       31280  651601 /lib64/libacl.so.1.1.0
              tar     3825 mysql  mem    REG   253,0      122040  651577 /lib64/libselinux.so.1
              tar     3825 mysql  mem    REG   253,0      154664  651609 /lib64/ld-2.12.so
              tar     3825 mysql    0r   CHR     1,3         0t0    3871 /dev/null
              tar     3825 mysql    1w   REG   253,0    70925586 1045768 /var/log/mysql/error.log
              tar     3825 mysql    2w   REG   253,0    70925586 1045768 /var/log/mysql/error.log
              tar     3825 mysql    3u   CHR     5,0         0t0    5338 /dev/tty
              tar     3825 mysql    4u   REG   253,0         110 2998607 /var/lib/mysql/grastate.dat
              tar     3825 mysql    5w   REG   253,0 21542461440 2998605 /var/lib/mysql/wsrep_sst_binlog.tar
              tar     3825 mysql    6u   REG     0,9           0    3869 [eventpoll]
              tar     3825 mysql    7u   REG     0,9           0    3869 [timerfd]
              tar     3825 mysql    8u   REG     0,9           0    3869 [eventfd]
              tar     3825 mysql    9u   REG     0,9           0    3869 [eventpoll]
              tar     3825 mysql   10u   REG     0,9           0    3869 [timerfd]
              tar     3825 mysql   11u   REG     0,9           0    3869 [eventfd]
              tar     3825 mysql   12r   REG   253,0 35721262759 2998690 /var/lib/mysql/mysql-bin.000061
              tar     3825 mysql   14u   REG   253,0   297795584 2997039 /var/lib/mysql/ibdata1
              tar     3825 mysql   15u   REG   253,0        5459  651645 /tmp/iblvW3eD (deleted)
              tar     3825 mysql   16u   REG   253,0           0  651667 /tmp/ibIUPTrD (deleted)
              tar     3825 mysql   17u   REG   253,0           0  651669 /tmp/ib55RJED (deleted)
              tar     3825 mysql   18u   REG   253,0           0  651671 /tmp/ibWRMt4E (deleted)
              tar     3825 mysql   19u   REG   253,0    67108864 2998611 /var/lib/mysql/ib_logfile0
              tar     3825 mysql   20u   REG   253,0    67108864 2998612 /var/lib/mysql/ib_logfile1
              tar     3825 mysql   21u   REG   253,0    67108864 2998613 /var/lib/mysql/ib_logfile2
              tar     3825 mysql   22u   REG   253,0    67108864 2998614 /var/lib/mysql/ib_logfile3
              tar     3825 mysql   23u   REG   253,0    67108864 2998615 /var/lib/mysql/ib_logfile4
              tar     3825 mysql   24u   REG   253,0    67108864 2998616 /var/lib/mysql/ib_logfile5
              tar     3825 mysql   25u   REG   253,0    67108864 2998617 /var/lib/mysql/ib_logfile6
              tar     3825 mysql   26u   REG   253,0    67108864 2998618 /var/lib/mysql/ib_logfile7
              tar     3825 mysql   27u   REG   253,0      589824 3258475 /var/lib/mysql/drupal_radio_prod/field_data_field_date_expires.ibd
              tar     3825 mysql   28u   REG   253,0           0  651686 /tmp/ibbShLHG (deleted)
              tar     3825 mysql   29u   REG   253,0      212992 3258333 /var/lib/mysql/drupal_radio_prod/field_data_field_file_image_title_text.ibd
              
              Show
              danblack Daniel Black added a comment - On a SST (rsync method) donor on a 10.0.21 instances I still see a lot of files open for tar generating binlogs. COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME tar 3825 mysql cwd DIR 253,0 40960 2997037 /var/lib/mysql tar 3825 mysql rtd DIR 253,0 4096 2 / tar 3825 mysql txt REG 253,0 390616 261280 /bin/tar tar 3825 mysql mem REG 253,0 65928 651690 /lib64/libnss_files-2.12.so tar 3825 mysql mem REG 253,0 142640 651563 /lib64/libpthread-2.12.so tar 3825 mysql mem REG 253,0 18712 651585 /lib64/libattr.so.1.1.0 tar 3825 mysql mem REG 253,0 19536 651672 /lib64/libdl-2.12.so tar 3825 mysql mem REG 253,0 1921216 651539 /lib64/libc-2.12.so tar 3825 mysql mem REG 253,0 43880 651724 /lib64/librt-2.12.so tar 3825 mysql mem REG 253,0 31280 651601 /lib64/libacl.so.1.1.0 tar 3825 mysql mem REG 253,0 122040 651577 /lib64/libselinux.so.1 tar 3825 mysql mem REG 253,0 154664 651609 /lib64/ld-2.12.so tar 3825 mysql 0r CHR 1,3 0t0 3871 /dev/null tar 3825 mysql 1w REG 253,0 70925586 1045768 /var/log/mysql/error.log tar 3825 mysql 2w REG 253,0 70925586 1045768 /var/log/mysql/error.log tar 3825 mysql 3u CHR 5,0 0t0 5338 /dev/tty tar 3825 mysql 4u REG 253,0 110 2998607 /var/lib/mysql/grastate.dat tar 3825 mysql 5w REG 253,0 21542461440 2998605 /var/lib/mysql/wsrep_sst_binlog.tar tar 3825 mysql 6u REG 0,9 0 3869 [eventpoll] tar 3825 mysql 7u REG 0,9 0 3869 [timerfd] tar 3825 mysql 8u REG 0,9 0 3869 [eventfd] tar 3825 mysql 9u REG 0,9 0 3869 [eventpoll] tar 3825 mysql 10u REG 0,9 0 3869 [timerfd] tar 3825 mysql 11u REG 0,9 0 3869 [eventfd] tar 3825 mysql 12r REG 253,0 35721262759 2998690 /var/lib/mysql/mysql-bin.000061 tar 3825 mysql 14u REG 253,0 297795584 2997039 /var/lib/mysql/ibdata1 tar 3825 mysql 15u REG 253,0 5459 651645 /tmp/iblvW3eD (deleted) tar 3825 mysql 16u REG 253,0 0 651667 /tmp/ibIUPTrD (deleted) tar 3825 mysql 17u REG 253,0 0 651669 /tmp/ib55RJED (deleted) tar 3825 mysql 18u REG 253,0 0 651671 /tmp/ibWRMt4E (deleted) tar 3825 mysql 19u REG 253,0 67108864 2998611 /var/lib/mysql/ib_logfile0 tar 3825 mysql 20u REG 253,0 67108864 2998612 /var/lib/mysql/ib_logfile1 tar 3825 mysql 21u REG 253,0 67108864 2998613 /var/lib/mysql/ib_logfile2 tar 3825 mysql 22u REG 253,0 67108864 2998614 /var/lib/mysql/ib_logfile3 tar 3825 mysql 23u REG 253,0 67108864 2998615 /var/lib/mysql/ib_logfile4 tar 3825 mysql 24u REG 253,0 67108864 2998616 /var/lib/mysql/ib_logfile5 tar 3825 mysql 25u REG 253,0 67108864 2998617 /var/lib/mysql/ib_logfile6 tar 3825 mysql 26u REG 253,0 67108864 2998618 /var/lib/mysql/ib_logfile7 tar 3825 mysql 27u REG 253,0 589824 3258475 /var/lib/mysql/drupal_radio_prod/field_data_field_date_expires.ibd tar 3825 mysql 28u REG 253,0 0 651686 /tmp/ibbShLHG (deleted) tar 3825 mysql 29u REG 253,0 212992 3258333 /var/lib/mysql/drupal_radio_prod/field_data_field_file_image_title_text.ibd
              Hide
              rrva Ragnar Rova added a comment -

              Hmm, these files must be opened through different functions than the patched ones in mysys/

              {my_open, my_fopen}

              ?

              Show
              rrva Ragnar Rova added a comment - Hmm, these files must be opened through different functions than the patched ones in mysys/ {my_open, my_fopen} ?
              Hide
              danblack Daniel Black added a comment -

              seems so. I'll do a new bug report.

              Show
              danblack Daniel Black added a comment - seems so. I'll do a new bug report.
              Hide
              rrva Ragnar Rova added a comment -

              I did not actually test that there were no open files, just that the corruption of mysqld-bin.index did not occur, which the fix in this ticket did address. /var/lib/mysql/grastate.dat is opened by galera plugin, so they should get a report to add O_CLOEXEC as well I guess. If there are places were O_CLOEXEC cannot be added, one could consider also adding the closing of all currently open fds as well, but O_CLOEXEC was still good since it is free from race conditions. I found some methods here which are OS-specific: http://stackoverflow.com/questions/899038/getting-the-highest-allocated-file-descriptor/918469#918469

              Show
              rrva Ragnar Rova added a comment - I did not actually test that there were no open files, just that the corruption of mysqld-bin.index did not occur, which the fix in this ticket did address. /var/lib/mysql/grastate.dat is opened by galera plugin, so they should get a report to add O_CLOEXEC as well I guess. If there are places were O_CLOEXEC cannot be added, one could consider also adding the closing of all currently open fds as well, but O_CLOEXEC was still good since it is free from race conditions. I found some methods here which are OS-specific: http://stackoverflow.com/questions/899038/getting-the-highest-allocated-file-descriptor/918469#918469
              Hide
              danblack Daniel Black added a comment -

              Ragnar Rova totallly agree. MDEV-8743 is the new issue for the other files being open. As you notice above the bin.index file isn't in the list of opened ones so the essence of this bug is complete even if other fds are left open and are relying on the good behaviour of sst scripts and their spawn not to corrupt database files.

              Show
              danblack Daniel Black added a comment - Ragnar Rova totallly agree. MDEV-8743 is the new issue for the other files being open. As you notice above the bin.index file isn't in the list of opened ones so the essence of this bug is complete even if other fds are left open and are relying on the good behaviour of sst scripts and their spawn not to corrupt database files.

                People

                • Assignee:
                  nirbhay_c Nirbhay Choubey
                  Reporter:
                  rrva Ragnar Rova
                • Votes:
                  1 Vote for this issue
                  Watchers:
                  5 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved:

                    Time Tracking

                    Estimated:
                    Original Estimate - Not Specified
                    Not Specified
                    Remaining:
                    Remaining Estimate - 0 minutes
                    0m
                    Logged:
                    Time Spent - 3 hours
                    3h

                      Agile