Uploaded image for project: 'Percona XtraBackup'
  1. Percona XtraBackup
  2. PXB-621

LP #1155221: Spurious error when innobackupex fails due to a failed system call

Details

    • Bug
    • Status: Done
    • High
    • Resolution: Invalid
    • None
    • None
    • None

    Description

      **Reported in Launchpad by Ovais Tariq last update 20-11-2014 08:41:07

      I am reporting it as a separate bug as its a more general bug.

      So coming from this bug https://bugs.launchpad.net/percona-xtrabackup/+bug/1155189 which causes xbstream to fail when extracting the archive. When I pipe the output from innobackupex directly to xbstream and xbstream fails while the backup is still in progress then the following error is reported:
      Failed to stream xtrabackup_binary: Inappropriate ioctl for device at /usr/bin/innobackupex line 311.

      This is spurious due to the fact that it does not report the correct error message, the error is actually due to a broken pipe which is found when I strace the call to xbstream inside innobackupex.

      Following is the entire output of the innobackupex run:

      [[email protected]_01 backup_test]# innobackupex --stream=xbstream ./ --include=test.* | xbstream -x -C uncompress/

      InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
      and Percona Ireland Ltd 2009-2012. All Rights Reserved.

      This software is published under
      the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.

      130314 11:35:33 innobackupex: Starting mysql with options: --unbuffered –
      130314 11:35:33 innobackupex: Connected to database with mysql child process (pid=6349)
      130314 11:35:39 innobackupex: Connection to database server closed
      IMPORTANT: Please check that the backup run completes successfully.
      At the end of a successful backup run innobackupex
      prints "completed OK!".

      innobackupex: Using mysql Ver 14.14 Distrib 5.5.29, for Linux (x86_64) using readline 5.1
      innobackupex: Using mysql server version Copyright (c) 2000, 2012, Oracle and/or its affiliates. All rights reserved.

      innobackupex: Created backup directory /root/backup_test
      130314 11:35:40 innobackupex: Starting mysql with options: --unbuffered –
      130314 11:35:40 innobackupex: Connected to database with mysql child process (pid=6379)
      130314 11:35:42 innobackupex: Connection to database server closed

      130314 11:35:42 innobackupex: Starting ibbackup with command: xtrabackup_55 --defaults-group="mysqld" --backup --suspend-at-end --target-dir=/tmp --tables='test.*' --stream=xbstream
      innobackupex: Waiting for ibbackup (pid=6387) to suspend
      innobackupex: Suspend file '/tmp/xtrabackup_suspended'

      xtrabackup_55 version 2.0.5 for Percona Server 5.5.16 Linux (x86_64) (revision id: 499)
      xtrabackup: uses posix_fadvise().
      xtrabackup: cd to /var/lib/mysql
      xtrabackup: Target instance is assumed as followings.
      xtrabackup: innodb_data_home_dir = ./
      xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
      xtrabackup: innodb_log_group_home_dir = ./
      xtrabackup: innodb_log_files_in_group = 2
      xtrabackup: innodb_log_file_size = 5242880
      xtrabackup: using O_DIRECT
      xtrabackup: tables regcomp(test.*): Success
      130314 11:35:42 InnoDB: Warning: allocated tablespace 15, old maximum was 9
      >> log scanned up to (23311379)
      [01] Streaming ./ibdata1
      >> log scanned up to (23311379)
      [01] ...done
      [01] Streaming ./test/t2.ibd
      [01] ...done
      [01] Streaming ./test/t3.ibd
      [01] ...done
      [01] Streaming ./test/test_export.ibd
      [01] ...done

      130314 11:35:50 innobackupex: Continuing after ibbackup has suspended
      130314 11:35:50 innobackupex: Starting mysql with options: --unbuffered –
      130314 11:35:50 innobackupex: Connected to database with mysql child process (pid=6401)
      >> log scanned up to (23311379)
      130314 11:35:52 innobackupex: Starting to lock all tables...
      >> log scanned up to (23311379)
      >> log scanned up to (23311379)
      130314 11:36:02 innobackupex: All tables locked and flushed to disk

      130314 11:36:02 innobackupex: Starting to backup non-InnoDB tables and files
      innobackupex: in subdirectories of '/var/lib/mysql'
      percona.deadlocks.frm is skipped because it does not match test.*.
      percona.db.opt is skipped because it does not match test.*.
      innobackupex: Backing up files '/var/lib/mysql/performance_schema/*.

      {frm,MYD,MYI,MAD,MAI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}' (18 files)
      performance_schema.threads.frm is skipped because it does not match test.*.
      performance_schema.mutex_instances.frm is skipped because it does not match test.*.
      performance_schema.events_waits_summary_by_thread_by_event_name.frm is skipped because it does not match test.*.
      performance_schema.file_summary_by_instance.frm is skipped because it does not match test.*.
      performance_schema.events_waits_summary_by_instance.frm is skipped because it does not match test.*.
      performance_schema.file_instances.frm is skipped because it does not match test.*.
      performance_schema.setup_instruments.frm is skipped because it does not match test.*.
      performance_schema.rwlock_instances.frm is skipped because it does not match test.*.
      performance_schema.events_waits_history.frm is skipped because it does not match test.*.
      performance_schema.performance_timers.frm is skipped because it does not match test.*.
      performance_schema.events_waits_summary_global_by_event_name.frm is skipped because it does not match test.*.
      performance_schema.cond_instances.frm is skipped because it does not match test.*.
      performance_schema.setup_timers.frm is skipped because it does not match test.*.
      performance_schema.file_summary_by_event_name.frm is skipped because it does not match test.*.
      performance_schema.events_waits_history_long.frm is skipped because it does not match test.*.
      performance_schema.db.opt is skipped because it does not match test.*.
      performance_schema.setup_consumers.frm is skipped because it does not match test.*.
      performance_schema.events_waits_current.frm is skipped because it does not match test.*.
      innobackupex: Backing up file '/var/lib/mysql/test/t2.frm'
      innobackupex: Backing up file '/var/lib/mysql/test/test_export.frm'
      innobackupex: Backing up file '/var/lib/mysql/test/t1.frm'
      innobackupex: Backing up file '/var/lib/mysql/test/t3.frm'
      innobackupex: Backing up files '/var/lib/mysql/mysql/*.{frm,MYD,MYI,MAD,MAI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}

      ' (72 files)
      mysql.db.MYI is skipped because it does not match test.*.
      mysql.func.MYD is skipped because it does not match test.*.
      mysql.user.MYD is skipped because it does not match test.*.
      mysql.proc.MYI is skipped because it does not match test.*.
      mysql.time_zone_name.MYI is skipped because it does not match test.*.
      mysql.time_zone_transition_type.frm is skipped because it does not match test.*.
      mysql.help_relation.MYI is skipped because it does not match test.*.
      mysql.help_relation.MYD is skipped because it does not match test.*.
      mysql.general_log.CSM is skipped because it does not match test.*.
      mysql.time_zone_transition.MYD is skipped because it does not match test.*.
      mysql.event.frm is skipped because it does not match test.*.
      mysql.func.frm is skipped because it does not match test.*.
      mysql.db.MYD is skipped because it does not match test.*.
      mysql.servers.MYD is skipped because it does not match test.*.
      mysql.help_keyword.frm is skipped because it does not match test.*.
      mysql.time_zone_name.MYD is skipped because it does not match test.*.
      mysql.user.MYI is skipped because it does not match test.*.
      mysql.help_topic.MYD is skipped because it does not match test.*.
      mysql.time_zone_transition.MYI is skipped because it does not match test.*.
      mysql.help_topic.MYI is skipped because it does not match test.*.
      mysql.servers.MYI is skipped because it does not match test.*.
      mysql.slow_log.CSV is skipped because it does not match test.*.
      mysql.proc.frm is skipped because it does not match test.*.
      mysql.time_zone_transition_type.MYI is skipped because it does not match test.*.
      mysql.help_keyword.MYI is skipped because it does not match test.*.
      mysql.procs_priv.MYD is skipped because it does not match test.*.
      mysql.slow_log.frm is skipped because it does not match test.*.
      mysql.user.frm is skipped because it does not match test.*.
      mysql.ndb_binlog_index.frm is skipped because it does not match test.*.
      mysql.slow_log.CSM is skipped because it does not match test.*.
      mysql.plugin.frm is skipped because it does not match test.*.
      mysql.help_category.MYI is skipped because it does not match test.*.
      mysql.plugin.MYI is skipped because it does not match test.*.
      mysql.procs_priv.frm is skipped because it does not match test.*.
      mysql.columns_priv.MYD is skipped because it does not match test.*.
      mysql.columns_priv.frm is skipped because it does not match test.*.
      mysql.func.MYI is skipped because it does not match test.*.
      mysql.event.MYD is skipped because it does not match test.*.
      mysql.time_zone.MYI is skipped because it does not match test.*.
      mysql.time_zone_name.frm is skipped because it does not match test.*.
      mysql.host.MYD is skipped because it does not match test.*.
      mysql.time_zone_leap_second.frm is skipped because it does not match test.*.
      mysql.help_category.frm is skipped because it does not match test.*.
      mysql.general_log.CSV is skipped because it does not match test.*.
      mysql.help_topic.frm is skipped because it does not match test.*.
      mysql.proxies_priv.MYI is skipped because it does not match test.*.
      mysql.proxies_priv.frm is skipped because it does not match test.*.
      mysql.plugin.MYD is skipped because it does not match test.*.
      mysql.time_zone_transition_type.MYD is skipped because it does not match test.*.
      mysql.servers.frm is skipped because it does not match test.*.
      mysql.proxies_priv.MYD is skipped because it does not match test.*.
      mysql.ndb_binlog_index.MYD is skipped because it does not match test.*.
      mysql.time_zone.MYD is skipped because it does not match test.*.
      mysql.time_zone_leap_second.MYD is skipped because it does not match test.*.
      mysql.columns_priv.MYI is skipped because it does not match test.*.
      mysql.time_zone_transition.frm is skipped because it does not match test.*.
      mysql.time_zone.frm is skipped because it does not match test.*.
      mysql.tables_priv.frm is skipped because it does not match test.*.
      mysql.help_keyword.MYD is skipped because it does not match test.*.
      mysql.help_relation.frm is skipped because it does not match test.*.
      mysql.tables_priv.MYI is skipped because it does not match test.*.
      mysql.tables_priv.MYD is skipped because it does not match test.*.
      mysql.procs_priv.MYI is skipped because it does not match test.*.
      mysql.event.MYI is skipped because it does not match test.*.
      mysql.host.MYI is skipped because it does not match test.*.
      mysql.time_zone_leap_second.MYI is skipped because it does not match test.*.
      mysql.general_log.frm is skipped because it does not match test.*.
      mysql.ndb_binlog_index.MYI is skipped because it does not match test.*.
      mysql.db.frm is skipped because it does not match test.*.
      mysql.host.frm is skipped because it does not match test.*.
      mysql.help_category.MYD is skipped because it does not match test.*.
      mysql.proc.MYD is skipped because it does not match test.*.
      130314 11:36:02 innobackupex: Finished backing up non-InnoDB tables and files

      130314 11:36:02 innobackupex: Waiting for log copying to finish

      xtrabackup: The latest check point (for incremental): '23311379'
      xtrabackup: Stopping log copying thread.
      .>> log scanned up to (23311379)

      xtrabackup: Streaming transaction log from a temporary file...
      xtrabackup: Done.
      xtrabackup: Transaction log of lsn (23311379) to (23311379) was copied.
      xb_stream_read_chunk(): wrong chunk magic at offset 0x1b3990e.
      130314 11:36:05 innobackupex: All tables unlocked
      130314 11:36:05 innobackupex: Connection to database server closed

      innobackupex: Backup created in directory '/root/backup_test'
      innobackupex: MySQL binlog position: filename '', position
      Failed to stream xtrabackup_binary: Inappropriate ioctl for device at /usr/bin/innobackupex line 311.

      The strace log shows the following:
      write(1, "XBSTCK01\0P\21\0\0\0xtrabackup_binary\r"..., 51) = -1 EPIPE (Broken pipe)
      — SIGPIPE (Broken pipe) @ 0 (0) —
      +++ killed by SIGPIPE +++

      It would be good to have the exact error code reported.

      Attachments

        Activity

          People

            Unassigned Unassigned
            lpjirasync lpjirasync (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Smart Checklist