Bug #75742 meb will hangs up using --read-threads greater than 1 without RELOAD privilege
Submitted: 3 Feb 2015 7:52 Modified: 4 Feb 2015 6:18
Reporter: Zhenye Xie (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Enterprise Backup Severity:S3 (Non-critical)
Version:3.11.1, 3.11.2 OS:Linux
Assigned to: CPU Architecture:Any

[3 Feb 2015 7:52] Zhenye Xie
Description:
when using a user without RELOAD privilege, meb will hangs up while oing FLUSH TABLES WITH READ LOCK.

stderr output:
.....
150203 15:26:14 mysqlbackup: INFO: Starting log scan from lsn 1608704.
150203 15:26:14 mysqlbackup: INFO: Copying log...
150203 15:26:14 mysqlbackup: INFO: Log copied, lsn 1609205.
150203 15:26:14 mysqlbackup: INFO: Completing the copy of innodb files.
150203 15:26:15 mysqlbackup: INFO: Preparing to lock tables: Connected to mysqld server.
150203 15:26:15 mysqlbackup: INFO: Starting to lock all the tables...
 mysqlbackup: ERROR: mysql query: 'FLUSH TABLES WITH READ LOCK': Access denied; you need (at least one of) the RELOAD privilege(s) for this operation
// hangs up here

How to repeat:
backup a database using a user without RELOAD privilege
[3 Feb 2015 8:25] MySQL Verification Team
Hello Zhenye Xie,

Thank you for the report.
I cannot repeat the issue(hang) at my end with MySQL Enterprise Backup version 3.11.1 Linux-3.8.13-35.2.1.el7uek.x86_64-x86_64.
Without 'RELOAD" privileges backup process ends with below error:

 mysqlbackup: ERROR: mysql query: 'FLUSH TABLES WITH READ LOCK': Access denied; you need (at least one of) the RELOAD privilege(s) for this operation

mysqlbackup failed with errors!

Could you please confirm with MEB 3.11.1 and inform us if the issue persist at your end?

Alternatively, you may GRANT privileges mentioned here for the backup user http://dev.mysql.com/doc/mysql-enterprise-backup/3.10/en/mysqlbackup.privileges.html

Thanks,
Umesh
[4 Feb 2015 1:35] Zhenye Xie
I've tried meb 3.11.1, it still hangs up at the same condition.
[4 Feb 2015 1:59] Zhenye Xie
It seams tablespace dump threads are waiting for a lock, and the thread trys to lock tables exits and does not release the lock when failed to lock tables.
[4 Feb 2015 1:59] Zhenye Xie
It seams tablespace dump threads are waiting for a lock, and the thread trys to lock tables exits and does not release the lock when failed to lock tables.
[4 Feb 2015 2:10] Zhenye Xie
backtraces:

(gdb) info threads
  Id   Target Id         Frame 
  3    Thread 0x7f35e94ef700 (LWP 21090) "mysqlbackup" 0x00007f35fcd22294 in __lll_lock_wait () from /lib64/libpthread.so.0
  2    Thread 0x7f35e8cee700 (LWP 21091) "mysqlbackup" 0x00007f35fcd22294 in __lll_lock_wait () from /lib64/libpthread.so.0
* 1    Thread 0x7f35fd32e720 (LWP 21076) "mysqlbackup" 0x00007f35fcd1bf95 in pthread_join () from /lib64/libpthread.so.0
(gdb) bt
#0  0x00007f35fcd1bf95 in pthread_join () from /lib64/libpthread.so.0
#1  0x000000000057d2ef in meb::Thread::join() ()
#2  0x00000000004968ef in meb::Manager::join_threads() ()
#3  0x0000000000497620 in meb::Meb_session::start() ()
#4  0x0000000000499f00 in meb::Meb_session::perform() ()
#5  0x000000000055f086 in meb::mysqlbackup_parallel(int, char**) ()
#6  0x000000000055f266 in main ()
(gdb) thread 2
[Switching to thread 2 (Thread 0x7f35e8cee700 (LWP 21091))]
#0  0x00007f35fcd22294 in __lll_lock_wait () from /lib64/libpthread.so.0
(gdb) bt
#0  0x00007f35fcd22294 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f35fcd1d619 in _L_lock_1008 () from /lib64/libpthread.so.0
#2  0x00007f35fcd1d42e in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000004a6fc3 in meb::Mutex::lock() ()
#4  0x000000000056f838 in meb::Read_data_mgr::get_buffer(char) ()
#5  0x00000000005708e9 in meb::Reader::run() ()
#6  0x000000000057d353 in meb::Thread::startThread(void*) ()
#7  0x00007f35fcd1b7b6 in start_thread () from /lib64/libpthread.so.0
#8  0x00007f35fbed4d6d in clone () from /lib64/libc.so.6
#9  0x0000000000000000 in ?? ()
(gdb) thread 3
[Switching to thread 3 (Thread 0x7f35e94ef700 (LWP 21090))]
#0  0x00007f35fcd22294 in __lll_lock_wait () from /lib64/libpthread.so.0
(gdb) bt
#0  0x00007f35fcd22294 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f35fcd1d619 in _L_lock_1008 () from /lib64/libpthread.so.0
#2  0x00007f35fcd1d42e in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x00000000004a6fc3 in meb::Mutex::lock() ()
#4  0x000000000056f838 in meb::Read_data_mgr::get_buffer(char) ()
#5  0x00000000005708e9 in meb::Reader::run() ()
#6  0x000000000057d353 in meb::Thread::startThread(void*) ()
#7  0x00007f35fcd1b7b6 in start_thread () from /lib64/libpthread.so.0
#8  0x00007f35fbed4d6d in clone () from /lib64/libc.so.6
#9  0x0000000000000000 in ?? ()

I've found that this problem only occurs when --read-threads is greater than 1.
[4 Feb 2015 4:58] Zhenye Xie
this problem only occurs when using --read-threads greater than 1
[4 Feb 2015 6:18] MySQL Verification Team
Thank you for the feedback.
Observed the issue with --read-threads=3

Thanks,
Umesh
[4 Feb 2015 6:19] MySQL Verification Team
// How to repeat
// Create backup user without RELOAD privileges

mysql> show grants for mysqlbackup@localhost;
+---------------------------------------------------------------------------------------------------------+
| Grants for mysqlbackup@localhost                                                                        |
+---------------------------------------------------------------------------------------------------------+
| GRANT SELECT, CREATE, ALTER, SUPER, LOCK TABLES, REPLICATION CLIENT ON *.* TO 'mysqlbackup'@'localhost' |
| GRANT INSERT, UPDATE, CREATE, DROP ON `mysql`.`backup_progress` TO 'mysqlbackup'@'localhost'            |
| GRANT SELECT, INSERT, UPDATE, CREATE, DROP ON `mysql`.`backup_history` TO 'mysqlbackup'@'localhost'     |
+---------------------------------------------------------------------------------------------------------+
3 rows in set (0.00 sec)

// Initiate backup

[ushastry@ushastry]~/bugs/setups/meb-3-11-2-el7-x86-64bit: bin/mysqlbackup --port=15000 --protocol=tcp --user=mysqlbackup   --backup-dir=/export/umesh/mysql-5.6.24/backup  --read-threads=3 --with-timestamp backup-and-apply-log
MySQL Enterprise Backup version 3.11.2 Linux-3.8.13-35.3.1.el7uek.x86_64-x86_64 [2014/12/04]
Copyright (c) 2003, 2014, Oracle and/or its affiliates. All Rights Reserved.

 mysqlbackup: INFO: Starting with following command line ...
 bin/mysqlbackup --port=15000 --protocol=tcp --user=mysqlbackup
        --backup-dir=/export/umesh/mysql-5.6.24/backup --read-threads=3
        --with-timestamp backup-and-apply-log

 mysqlbackup: INFO:
 mysqlbackup: INFO: MySQL server version is '5.6.24-enterprise-commercial-advanced'.
 mysqlbackup: INFO: Got some server configuration information from running server.

IMPORTANT: Please check that mysqlbackup run completes successfully.
           At the end of a successful 'backup-and-apply-log' run mysqlbackup
           prints "mysqlbackup completed OK!".

150204 06:59:01 mysqlbackup: INFO: MEB logfile created at /export/umesh/mysql-5.6.24/backup/2015-02-04_06-59-01/meta/MEB_2015-02-04.06-59-01_backup_apply_log.log

..
..
.
150204 06:59:04 mysqlbackup: INFO: Preparing to lock tables: Connected to mysqld server.
150204 06:59:04 mysqlbackup: INFO: Starting to lock all the tables...
 mysqlbackup: ERROR: mysql query: 'FLUSH TABLES WITH READ LOCK': Access denied; you need (at least one of) the RELOAD privilege(s) for this operation
^C mysqlbackup: ERROR: Signal 2 received.

mysqlbackup terminated by signal 2.

^^ Hangs( waited for >5min before terminating with Ctr+C)

// traces

  [ushastry@ushastry]~/bugs: ./pmp.sh
        2 __lll_lock_wait,_L_lock_790,pthread_mutex_lock,meb::Mutex::lock(),meb::Read_data_mgr::get_buffer(char),meb::Reader::run(),meb::Thread::startThread(void*),start_thread,clone
        1 pthread_join,meb::Thread::join(),meb::Manager::join_threads(),meb::Meb_session::perform(),meb::mysqlbackup_parallel(int,,main
        1