Bug #51160 Deadlock around SET GLOBAL EVENT_SCHEDULER = ON|OFF
Submitted: 13 Feb 2010 10:13 Modified: 28 Apr 2010 2:04
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:mysql-next-mr, 5.1 OS:Any
Assigned to: Jon Olav Hauglid CPU Architecture:Any

[13 Feb 2010 10:13] Philip Stoev
Description:
When executing SET GLOBAL EVENT_SCHEDULER = ON | OFF in two or more concurrent threads, mysqld deadlocks easily with the following backtraces:

#3  0x0000000000a136cc in safe_mutex_lock (mp=0x104f420, try_lock=0 '\0', file=0xb0e3be "sql_class.cc", line=892) at thr_mutex.c:152
#4  0x0000000000624119 in inline_mysql_mutex_lock (that=0x104f420, src_file=0xb0e3be "sql_class.cc", src_line=892) at ../include/mysql/psi/mysql_thread.h:519
#5  0x000000000062a6d4 in THD::init (this=0x2c2ab58) at sql_class.cc:892
#6  0x000000000062bb37 in THD (this=0x2c2ab58) at sql_class.cc:553
#7  0x000000000084b604 in Event_scheduler::start (this=0x2bd17e0) at event_scheduler.cc:387
#8  0x000000000085449a in Events::start () at events.cc:1027
#9  0x0000000000699eca in event_scheduler_update (self=0x1053940, thd=0x2bfafc8, type=OPT_GLOBAL) at sys_vars.cc:650
#10 0x000000000066028f in sys_var::update (this=0x1053940, thd=0x2bfafc8, var=0x2bf54e0) at set_var.cc:174
#11 0x0000000000661c4c in set_var::update (this=0x2bf54e0, thd=0x2bfafc8) at set_var.cc:641
#12 0x0000000000660b1c in sql_set_variables (thd=0x2bfafc8, var_list=0x2bfd410) at set_var.cc:545
#13 0x000000000065860f in mysql_execute_command (thd=0x2bfafc8) at sql_parse.cc:3242
#14 0x000000000065c862 in mysql_parse (thd=0x2bfafc8, inBuf=0x2bf5398 "SET GLOBAL EVENT_SCHEDULER = ON", length=31, found_semicolon=0x7f454e138ee0)
    at sql_parse.cc:5581
#15 0x000000000065d47b in dispatch_command (command=COM_QUERY, thd=0x2bfafc8, packet=0x2bdf5e9 "SET GLOBAL EVENT_SCHEDULER = ON", packet_length=31)
    at sql_parse.cc:1023
#16 0x000000000065e91b in do_command (thd=0x2bfafc8) at sql_parse.cc:709
#17 0x000000000064cafb in do_handle_one_connection (thd_arg=0x2bfafc8) at sql_connect.cc:1174
#18 0x000000000064cbca in handle_one_connection (arg=0x2bfafc8) at sql_connect.cc:1113
#19 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
#20 0x000000315a4e627d in clone () from /lib64/libc.so.6

and

#2  0x000000315b0090f0 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x0000000000a136cc in safe_mutex_lock (mp=0x10694c0, try_lock=0 '\0', file=0xb6dbfc "sys_vars.cc", line=653) at thr_mutex.c:152
#4  0x000000000068d6ac in inline_mysql_mutex_lock (that=0x10694c0, src_file=0xb6dbfc "sys_vars.cc", src_line=653) at ../include/mysql/psi/mysql_thread.h:519
#5  0x0000000000699f1a in event_scheduler_update (self=0x1053940, thd=0x2bf1348, type=OPT_GLOBAL) at sys_vars.cc:653
#6  0x000000000066028f in sys_var::update (this=0x1053940, thd=0x2bf1348, var=0x2c2ed60) at set_var.cc:174
#7  0x0000000000661c4c in set_var::update (this=0x2c2ed60, thd=0x2bf1348) at set_var.cc:641
#8  0x0000000000660b1c in sql_set_variables (thd=0x2bf1348, var_list=0x2bf3790) at set_var.cc:545
#9  0x000000000065860f in mysql_execute_command (thd=0x2bf1348) at sql_parse.cc:3242
#10 0x000000000065c862 in mysql_parse (thd=0x2bf1348, inBuf=0x2c2eba8 "SET GLOBAL EVENT_SCHEDULER = OFF", length=32, found_semicolon=0x7f454e0f7ee0)
    at sql_parse.cc:5581
#11 0x000000000065d47b in dispatch_command (command=COM_QUERY, thd=0x2bf1348, packet=0x2c26b19 "SET GLOBAL EVENT_SCHEDULER = OFF", packet_length=32)
    at sql_parse.cc:1023
#12 0x000000000065e91b in do_command (thd=0x2bf1348) at sql_parse.cc:709
#13 0x000000000064cafb in do_handle_one_connection (thd_arg=0x2bf1348) at sql_connect.cc:1174
#14 0x000000000064cbca in handle_one_connection (arg=0x2bf1348) at sql_connect.cc:1113
#15 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
#16 0x000000315a4e627d in clone () from /lib64/libc.so.6

The server has hanged solid with new connections blocking with the following backtrace:

#0  0x000000315b00db14 in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x000000315b00921c in _L_lock_1078 () from /lib64/libpthread.so.0
#2  0x000000315b0090f0 in pthread_mutex_lock () from /lib64/libpthread.so.0
#3  0x0000000000a08450 in safe_mutex_lock (mp=0x103d600, try_lock=0 '\0', file=0xb00f3e "sql_class.cc", line=891) at thr_mutex.c:152
#4  0x000000000061e04d in inline_mysql_mutex_lock (that=0x103d600, src_file=0xb00f3e "sql_class.cc", src_line=891) at ../include/mysql/psi/mysql_thread.h:519
#5  0x000000000062442a in THD::init (this=0x221c418) at sql_class.cc:891
#6  0x0000000000625858 in THD (this=0x221c418) at sql_class.cc:552
#7  0x000000000063cc5f in handle_connections_sockets () at mysqld.cc:5507
#8  0x0000000000641174 in main (argc=43, argv=0x2145540) at mysqld.cc:4854

How to repeat:
Grammar:

query:
        SET GLOBAL EVENT_SCHEDULER = ON |
        SET GLOBAL EVENT_SCHEDULER = OFF;

To reproduce with the RQG:

$ perl runall.pl \
  --basedir=/build/bzr/mysql-next-mr/ \
  --mem \
  --mysqld=--log-output=none \
  --grammar=/tmp/event.yy \
  --mysqld=--skip-innodb \
  --threads=2 \
  --reporter=
[22 Feb 2010 17:34] Philip Stoev
See also bug #40915
[25 Feb 2010 15:06] Kristofer Pettersson
I'm unable to reproduce this issue in 5.1. It locks pretty quickly as described above in the mysql-next-mr-bugfixing and mysql-pe trees though.
[3 Mar 2010 13:57] Jon Olav Hauglid
Bug#50406 marked as a duplicate of this bug.
See Bug#50406 for more info about the cause of this deadlock.
[4 Mar 2010 10:06] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/102264

3121 Jon Olav Hauglid	2010-03-04
      Bug #51160 Deadlock around SET GLOBAL EVENT_SCHEDULER = ON|OFF
      
      This deadlock could occour betweeen one connection executing
      SET GLOBAL EVENT_SCHEDULER= ON and another executing SET GLOBAL
      EVENT_SCHEDULER= OFF.
      
      The first connection would hold LOCK_event_metadata (protecting
      the global variable) while trying to lock LOCK_global_system_variables
      starting the event scheduler thread (in THD:init()).
      
      The second connection would hold LOCK_global_system_variables
      while trying to get LOCK_event_scheduler after stopping the event
      scheduler inside event_scheduler_update().
      
      This patch fixes the problem by making sure that LOCK_event_metadata
      is not held when trying to start (or stop) the event scheduler.
      The bug was introduced by WL#4738.
      
      This patch also fixes a bug where it was possible to exit create_event()
      without releasing LOCK_event_metadata if running out of memory during
      its exection.
      
      Test case added to events_sync.test.
[9 Mar 2010 10:26] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/102675

3122 Jon Olav Hauglid	2010-03-09
      Bug #51160 Deadlock around SET GLOBAL EVENT_SCHEDULER = ON|OFF
      
      This deadlock could occour betweeen one connection executing
      SET GLOBAL EVENT_SCHEDULER= ON and another executing SET GLOBAL
      EVENT_SCHEDULER= OFF. The bug was introduced by WL#4738.
      
      The first connection would hold LOCK_event_metadata (protecting
      the global variable) while trying to lock LOCK_global_system_variables
      starting the event scheduler thread (in THD:init()).
      
      The second connection would hold LOCK_global_system_variables
      while trying to get LOCK_event_scheduler after stopping the event
      scheduler inside event_scheduler_update().
      
      This patch fixes the problem by not using LOCK_event_metadata to
      protect the event_scheduler variable. It is still protected using
      LOCK_global_system_variables. This fixes the deadlock as it removes 
      one of the two mutexes used to produce it.
      
      However, this patch opens up the possibility that the event_scheduler
      variable and the real event_scheduler state can become out of sync
      (e.g. variable = OFF, but scheduler running). But this can only
      happen under very unlikely conditions - two concurrent SET GLOBAL
      statments, with one thread interrupted at the exact wrong moment.
      This is preferable to having the possibility of a deadlock.
      
      This patch also fixes a bug where it was possible to exit create_event()
      without releasing LOCK_event_metadata if running out of memory during
      its exection.
      
      No test case added since a repeatable test case would have required
      excessive use of new sync points. Instead we rely on the fact that
      this bug was easily reproduceable using RGQ tests.
[11 Mar 2010 9:01] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/102958

3124 Jon Olav Hauglid	2010-03-11
      Bug #51160 Deadlock around SET GLOBAL EVENT_SCHEDULER = ON|OFF
      
      This deadlock could occour betweeen one connection executing
      SET GLOBAL EVENT_SCHEDULER= ON and another executing SET GLOBAL
      EVENT_SCHEDULER= OFF. The bug was introduced by WL#4738.
      
      The first connection would hold LOCK_event_metadata (protecting
      the global variable) while trying to lock LOCK_global_system_variables
      starting the event scheduler thread (in THD:init()).
      
      The second connection would hold LOCK_global_system_variables
      while trying to get LOCK_event_scheduler after stopping the event
      scheduler inside event_scheduler_update().
      
      This patch fixes the problem by not using LOCK_event_metadata to
      protect the event_scheduler variable. It is still protected using
      LOCK_global_system_variables. This fixes the deadlock as it removes 
      one of the two mutexes used to produce it.
      
      However, this patch opens up the possibility that the event_scheduler
      variable and the real event_scheduler state can become out of sync
      (e.g. variable = OFF, but scheduler running). But this can only
      happen under very unlikely conditions - two concurrent SET GLOBAL
      statments, with one thread interrupted at the exact wrong moment.
      This is preferable to having the possibility of a deadlock.
      
      This patch also fixes a bug where it was possible to exit create_event()
      without releasing LOCK_event_metadata if running out of memory during
      its exection.
      
      No test case added since a repeatable test case would have required
      excessive use of new sync points. Instead we rely on the fact that
      this bug was easily reproduceable using RGQ tests.
[15 Mar 2010 13:52] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/103251

2994 Jon Olav Hauglid	2010-03-15
      Bug #51160 Deadlock around SET GLOBAL EVENT_SCHEDULER = ON|OFF
      
      This deadlock could occour betweeen one connection executing
      SET GLOBAL EVENT_SCHEDULER= ON and another executing SET GLOBAL
      EVENT_SCHEDULER= OFF. The bug was introduced by WL#4738.
      
      The first connection would hold LOCK_event_metadata (protecting
      the global variable) while trying to lock LOCK_global_system_variables
      starting the event scheduler thread (in THD:init()).
      
      The second connection would hold LOCK_global_system_variables
      while trying to get LOCK_event_scheduler after stopping the event
      scheduler inside event_scheduler_update().
      
      This patch fixes the problem by not using LOCK_event_metadata to
      protect the event_scheduler variable. It is still protected using
      LOCK_global_system_variables. This fixes the deadlock as it removes 
      one of the two mutexes used to produce it.
      
      However, this patch opens up the possibility that the event_scheduler
      variable and the real event_scheduler state can become out of sync
      (e.g. variable = OFF, but scheduler running). But this can only
      happen under very unlikely conditions - two concurrent SET GLOBAL
      statments, with one thread interrupted at the exact wrong moment.
      This is preferable to having the possibility of a deadlock.
      
      This patch also fixes a bug where it was possible to exit create_event()
      without releasing LOCK_event_metadata if running out of memory during
      its exection.
      
      No test case added since a repeatable test case would have required
      excessive use of new sync points. Instead we rely on the fact that
      this bug was easily reproduceable using RGQ tests.
[15 Mar 2010 13:53] Jon Olav Hauglid
Pushed to mysql-trunk-bugfixing (Ver 5.5.4-m3).
[24 Mar 2010 8:15] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100324081249-yfwol7qtcek6dh7w) (version source revid:alik@sun.com-20100324081113-kc7x1iytnplww91u) (merge vers: 6.0.14-alpha) (pib:16)
[24 Mar 2010 8:16] Bugs System
Pushed into 5.5.4-m3 (revid:alik@sun.com-20100324081056-6bndv6f0nrvbblhp) (version source revid:alik@sun.com-20100324081056-6bndv6f0nrvbblhp) (merge vers: 5.5.4-m3) (pib:16)
[24 Mar 2010 8:18] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100324081159-5b8juv8ldiqwce8v) (version source revid:alik@sun.com-20100324081105-y72rautcea375zxm) (pib:16)
[25 Mar 2010 1:28] Paul Dubois
Noted in 5.5.4, 6.0.14 changelogs.

Two sessions trying to set the global event_scheduler system variable
to different values could deadlock.
[25 Mar 2010 17:03] Philip Stoev
See bug #52367
[26 Mar 2010 9:42] John Embretsen
Bug#52367 looks like a duplicate of this bug. It was reported against the mysql-trunk-runtime-exp branch, in which the fix for this bug seems to be present. The issue described in both bugs can be repeated using the simplified grammar provided above.

I leave it to the assigned developers to decide whether to re-open this bug and close the other as duplicate, or treat Bug#52367 as a separate issue.
[31 Mar 2010 16:13] Paul Dubois
5.5.4 changelog entry was moved to 5.5.5.
[27 Apr 2010 9:46] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100427094135-5s49ecp3ckson6e2) (version source revid:alik@sun.com-20100427093843-uekr85qkd7orx12t) (merge vers: 6.0.14-alpha) (pib:16)
[27 Apr 2010 9:49] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100427093804-a2k3rrjpwu5jegu8) (version source revid:alik@sun.com-20100427093804-a2k3rrjpwu5jegu8) (merge vers: 5.5.5-m3) (pib:16)
[27 Apr 2010 9:51] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100427094036-38frbg3famdlvjup) (version source revid:alik@sun.com-20100427093825-92wc8b22d4yg34ju) (pib:16)