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

A failed unlink of the #sql-backup tablespace at the end of a copying ALTER TABLE leaves an orphan file; every later copying ALTER from a connection with the same thread id fails with "Tablespace already exists"

    XMLWordPrintable

Details

    Description

      Description:

      A copying ALTER TABLE renames the old table to #sql-backup-<pid>-<thread_id>,
      renames the new table into place, and then drops the backup. If unlink() of
      the backup .ibd fails (one EIO), the ALTER still succeeds (correct: it cannot
      be rolled back any more), InnoDB logs the error, and the file
      #sql-backup-<pid>-<thread_id>.ibd stays in the database directory. Nothing
      removes it later, not even a restart.

      The backup name depends only on the server pid and the connection's thread
      id, not on the table. So every later copying ALTER, on any table of that
      database, from the same connection fails when it tries to rename the table
      to the backup name. After a restart the pid is the same in a container (pid
      1), so the connection that gets the same thread id fails again.

      How to repeat:

      docker run -d --name mdb009 -e MARIADB_ALLOW_EMPTY_ROOT_PASSWORD=1 -e MARIADB_DATABASE=test \
      quay.io/mariadb-foundation/mariadb-devel:verylatest

      1. (wait until the server is ready)
        docker exec mdb009 mariadb -uroot test -e "
        CREATE TABLE t1 (a INT PRIMARY KEY, b INT) ENGINE=InnoDB; INSERT INTO t1 VALUES (1,1),(2,2);
        CREATE TABLE t2 (a INT PRIMARY KEY) ENGINE=InnoDB;"
      2. one session: ALTER t1 (copying), wait, then ALTER t2 (copying)
        docker exec mdb009 mariadb -uroot test -e "
        SELECT SLEEP(3); ALTER TABLE t1 MODIFY b BIGINT; SHOW WARNINGS; SELECT * FROM t1;
        SELECT SLEEP(5); ALTER TABLE t2 ADD COLUMN c INT, ALGORITHM=COPY;" &
        sleep 1
      3. during the first ALTER, fail the first unlink() of the server with EIO
        sudo timeout 5 strace -f -qq -p $(docker inspect -f '.State.Pid' mdb009) \
        -e trace=unlink,rename -e inject=unlink:error=EIO:when=1 -o trace.txt
        wait
        docker exec mdb009 ls /var/lib/mysql/test

      Result (identical on 13.2 main and 13.0.2; 9 is the thread id of the first
      session and depends on how many connections the server had before it, e.g.
      #sql-backup-1-5 in another run):

      trace.txt:
      rename("./test/t1.ibd", "./test/#sql-backup-1-9.ibd") = 0
      rename("./test/t1.frm", "./test/#sql-backup-1-9.frm") = 0
      rename("./test/#sql-alter-1-9-4.ibd", "./test/t1.ibd") = 0
      rename("./test/#sql-alter-1-9-4.frm", "./test/t1.frm") = 0
      unlink("./test/#sql-backup-1-9.ibd") = -1 EIO (Input/output error) (INJECTED)
      unlink("./test/#sql-backup-1-9.cfg") = -1 ENOENT (No such file or directory)
      unlink("./test/#sql-backup-1-9.frm") = 0

      ALTER TABLE t1 MODIFY b BIGINT -> OK, SHOW WARNINGS is empty, data correct
      ALTER TABLE t2 ADD COLUMN c INT, ALGORITHM=COPY
      -> ERROR 1025 (HY000): Error on rename of './test/t2' to './test/#sql-backup-1-9'
      (errno: 184 "Tablespace already exists")
      error log:
      [ERROR] InnoDB: File ./test/#sql-backup-1-9.ibd: 'delete' returned OS error 205.
      [ERROR] InnoDB: Cannot rename './test/t2.ibd' to './test/#sql-backup-1-9.ibd' because the target file exists.
      ls: #sql-backup-1-9.ibd t1.frm t1.ibd t2.frm t2.ibd db.opt

      The same ALTER from another connection succeeds. After a restart the file is
      still there, and the connection that gets thread id 9 fails the same way:

      docker restart mdb009
      for i in $(seq 1 8); do docker exec mdb009 mariadb -uroot test -e \
      "SELECT CONNECTION_ID(); ALTER TABLE t2 FORCE, ALGORITHM=COPY"; done
      -> CONNECTION_ID() 3..8 succeed; with CONNECTION_ID() 9 (the id of the first session):
      ERROR 1025 (HY000): Error on rename of './test/t2' to './test/#sql-backup-1-9' (errno: 184 "Tablespace already exists")

      On a partitioned table the same happens with #sql-backup-<pid>-<id>#P#p0.ibd
      (error 1025 errno 184), or with the backup .par file (error 1050 "Table
      './ddh/#sql-backup-1-5#P#p0' already exists"), depending on which unlink
      fails.

      Expected: an ALTER that succeeded should not make later, unrelated ALTERs
      fail. The leftover should be removed later (retry, or recorded in the DDL
      log and removed at the next start), or the next ALTER should choose a backup
      name that is not in use. At least the error should name the orphan file as
      the cause.

      Cause, as far as I can tell:

      The backup name is "#sql-backup-%lx-%llx" with current_pid and
      thd->thread_id:
      https://github.com/MariaDB/server/blob/327437ade1d6dc6e4e57a6f1723b4abe4ac6c4b4/sql/sql_table.cc#L11275-L11278
      After the swap, the backup is dropped with errors turned into warnings ("a
      failure to delete isn't an error, as we cannot rollback ALTER anymore"), and
      the DDL log entry of the ALTER is then closed, so nothing remembers the
      leftover:
      https://github.com/MariaDB/server/blob/327437ade1d6dc6e4e57a6f1723b4abe4ac6c4b4/sql/sql_table.cc#L12684-L12698
      InnoDB has already removed the table from its dictionary when the file
      deletion fails, so the file is an orphan, and a later rename to the same name
      is refused because the target file exists.

      Related: MDEV-25852 (orphan #sql*.ibd after a killed ALTER, fixed); this case
      is an I/O error on the final cleanup of a successful ALTER, without a crash.

      Attachments

        1. mdev41707_repro.sh
          7 kB
          Shipra Jain
        2. mdev41707_strace.test
          4 kB
          Shipra Jain
        3. strace_inject.sh
          2 kB
          Shipra Jain

        Activity

          People

            sanja Oleksandr Byelkin
            kehan5800 Ke Han
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:

              Git Integration

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