Bug #42634 % character in query can cause mysqld signal 11 segfault
Submitted: 6 Feb 2009 0:46 Modified: 18 Feb 2009 20:09
Reporter: Noah E Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:5.1.31, 5.1 bzr OS:Linux (Redhat ES 4 X86_64)
Assigned to: Davi Arnaut CPU Architecture:Any
Tags: binlog, crash, regression, statement not safe
Triage: Needs Triage: D1 (Critical)

[6 Feb 2009 0:46] Noah E
Description:
I am able to crash mysqld 100% of the time simply by running these specific and simple update queries: 

Notes: I have binlog on in statement format and I am replicating to one slave. 
Notes: ChatUsers used to be a MEMORY table but i switched it to InnoDB to see if the problem would fix, but it still caused a crash.

How to repeat:
Create Table: CREATE TABLE `ChatUsers` (
  `aid` int(11) NOT NULL DEFAULT '0',
  `room` int(11) NOT NULL DEFAULT '50000',
  `host` enum('deviator','dummie') NOT NULL DEFAULT 'deviator',
  `active` tinyint(1) NOT NULL DEFAULT '0',
  `idle` tinyint(1) NOT NULL DEFAULT '0',
  `nick` varchar(25) NOT NULL DEFAULT '''Someone''',
  `avatar` varchar(200) NOT NULL DEFAULT '',
  `color` varchar(40) NOT NULL DEFAULT '',
  `icon` varchar(30) NOT NULL DEFAULT '',
  `admin` tinyint(4) NOT NULL DEFAULT '0',
  `ip` int(10) unsigned NOT NULL,
  `port` int(11) NOT NULL,
  `nowplaying` varchar(100) NOT NULL,
  `warn` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `tstamp` int(12) unsigned NOT NULL DEFAULT '0',
  `INSERTED` timestamp NULL DEFAULT CURRENT_TIMESTAMP,
  PRIMARY KEY (`aid`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1;

INSERT INTO ChatUsers(ip) VALUES('1474024258');

UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip = '1474024258' LIMIT 1;

(mysqld crashes before query returns)

Suggested fix:
I discovered that this query however worked fine:

UPDATE ChatUsers set nowplaying = 'Animetal - Ufo' where ip = '1474024258' LIMIT 1;

Somehow the jumble of % characters caused the fault.

However, this warning occured, which I cant figure out why:
[Warning] Statement is not safe to log in statement format.
[6 Feb 2009 0:57] Noah E
Oh wow, I just noticed that if you dont include the "limit 1" in the query it doesn't crash either!

Its the combination of the % characters and the limit 1 which crashes mysqld on my system. 

I just tried it on other tables in my database, same crash. 
For example:

update users set email = '%5b%B1b%b%1b%15b!%b!bh!Bb' where id = '7' limit 1

CRASH.
[6 Feb 2009 6:56] Sveta Smirnova
Thank you for the report.

Verified as described.

Having binary log enabled is necessary to get the crash. Storage engine does not matter.

Backtrace from 5.1-bzr:

#0  0x002ce402 in __kernel_vsyscall ()
#0  0x002ce402 in __kernel_vsyscall ()
#1  0x0046264f in pthread_kill () from /lib/libpthread.so.0
#2  0x085a33b5 in my_write_core (sig=11) at stacktrace.c:310
#3  0x0824c061 in handle_segfault (sig=11) at mysqld.cc:2505
#4  <signal handler called>
#5  0x0035840a in memmove () from /lib/libc.so.6
#6  0x085cf28c in my_vsnprintf (to=0xb7459ad4 "##r\b#####E#c#Z\b\020/X\t#^F", n=1024, fmt=0xb7459ff2 "b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", 
    ap=0xb7459f48 "##g\bZJP\t##[\t\204#E#\200#E#:x=\b Oo\b##o\b\f\n") at my_vsnprintf.c:112
#7  0x0831ff8b in vprint_msg_to_log (level=WARNING_LEVEL, 
    format=0xb7459f80 "Statement is not safe to log in statement format. Statement: UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", 
    args=0xb7459f44 "") at log.cc:4780
#8  0x0831ffe3 in Log_to_file_event_handler::log_error (this=0x94f7c50, level=WARNING_LEVEL, 
    format=0xb7459f80 "Statement is not safe to log in statement format. Statement: UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", 
    args=0xb7459f44 "") at log.cc:727
#9  0x0831522b in LOGGER::error_log_print (this=0x8874400, level=WARNING_LEVEL, 
    format=0xb7459f80 "Statement is not safe to log in statement format. Statement: UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", 
    args=0xb7459f44 "") at log.cc:834
#10 0x083179bb in error_log_print (level=WARNING_LEVEL, 
    format=0xb7459f80 "Statement is not safe to log in statement format. Statement: UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", 
    args=0xb7459f44 "") at log.cc:4087
#11 0x0832004c in sql_print_warning (
    format=0xb7459f80 "Statement is not safe to log in statement format. Statement: UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1")
    at log.cc:4811
#12 0x0823b409 in THD::binlog_query (this=0x95428e8, qtype=THD::ROW_QUERY_TYPE, 
    query_arg=0x95bd1d8 "UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", query_len=109, is_trans=false, suppress_use=false, 
    killed_status_arg=THD::NOT_KILLED) at sql_class.cc:3672
#13 0x08309db7 in mysql_update (thd=0x95428e8, table_list=0x95bd338, fields=@0x9543d10, values=@0x9543f24, conds=0x95bd7e8, order_num=0, order=0x0, limit=0, handle_duplicates=DUP_ERROR, ignore=false)
    at sql_update.cc:798
#14 0x08263964 in mysql_execute_command (thd=0x95428e8) at sql_parse.cc:2981
#15 0x0826a752 in mysql_parse (thd=0x95428e8, inBuf=0x95bd1d8 "UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", length=109, 
    found_semicolon=0xb745b2fc) at sql_parse.cc:5809
#16 0x0826b38e in dispatch_command (command=COM_QUERY, thd=0x95428e8, packet=0x9587629 "UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip =\n'1474024258' LIMIT 1", 
    packet_length=109) at sql_parse.cc:1216
#17 0x0826c5ac in do_command (thd=0x95428e8) at sql_parse.cc:857
#18 0x0825922d in handle_one_connection (arg=0x95428e8) at sql_connect.cc:1115
#19 0x0045fbd4 in start_thread () from /lib/libpthread.so.0
#20 0x003b74fe in clone () from /lib/libc.so.6
[6 Feb 2009 7:02] Sveta Smirnova
Bug exists only in version 5.1 and was introduced in version 5.1.29
[6 Feb 2009 7:04] Sveta Smirnova
Reduced test case:

--source include/have_log_bin.inc

CREATE TABLE `ChatUsers` (
  `ip` int(10) unsigned NOT NULL,
  `nowplaying` varchar(100) NOT NULL
);

INSERT INTO ChatUsers(ip) VALUES('1474024258');

UPDATE ChatUsers set nowplaying = 'Animetal - Ufo%e5%b0%91%e5%b9%b4%ee%99%91' where ip = '1474024258' LIMIT 1;
[6 Feb 2009 8:40] Sveta Smirnova
See also bug #42640
[8 Feb 2009 2:16] Davi Arnaut
Bug#42674 has been marked as a duplicate of this bug.
[8 Feb 2009 8:55] Mark Plomer
At Bug#42674 I posted yesterday the simple patch for this crash:

At "mysql-5.1.31/sql/sql_class.cc" in function "THD::binlog_query": Replace "sql_print_warning(warn_buf);" with "sql_print_warning("%s", warn_buf);" or remove the my_snprintf call and use sql_print_warning directly with "%s Statement: %s" ...
[9 Feb 2009 11:59] 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/65597

2793 Davi Arnaut	2009-02-09
      Bug#42634: % character in query can cause mysqld signal 11
      segfault
      
      The problem is that a unfiltered user query was being passed as
      the format string parameter of sql_print_warning which later
      performs printf-like formatting, leading to crashes if the
      user query contains formatting instructions (ie: %s). Also, it
      was using THD::query as the source of the user query, but this
      variable is not meaningful in some situations -- in a delayed
      insert, it points to the table name.
      
      The solution is to pass the user query as a parameter for the
      format string and use the function parameter query_arg as the
      source of the user query.
[9 Feb 2009 18:18] 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/65641

2794 Davi Arnaut	2009-02-09
      Bug#42634: % character in query can cause mysqld signal 11 segfault
      
      The problem is that a unfiltered user query was being passed as
      the format string parameter of sql_print_warning which later
      performs printf-like formatting, leading to crashes if the user
      query contains formatting instructions (ie: %s). Also, it was
      using THD::query as the source of the user query, but this
      variable is not meaningful in some situations -- in a delayed
      insert, it points to the table name.
      
      The solution is to pass the user query as a parameter for the
      format string and use the function parameter query_arg as the
      source of the user query.
[9 Feb 2009 18:30] Davi Arnaut
Queued to 5.1-bugteam
[9 Feb 2009 22:34] Bugs System
Pushed into 5.1.32 (revid:davi.arnaut@sun.com-20090209214102-gj3sb3ujpnvpiy4c) (version source revid:davi.arnaut@sun.com-20090209214102-gj3sb3ujpnvpiy4c) (merge vers: 5.1.32) (pib:6)
[14 Feb 2009 13:01] Bugs System
Pushed into 6.0.10-alpha (revid:matthias.leich@sun.com-20090212211028-y72faag15q3z3szy) (version source revid:matthias.leich@sun.com-20090212211028-y72faag15q3z3szy) (merge vers: 6.0.10-alpha) (pib:6)
[17 Feb 2009 14:57] Bugs System
Pushed into 5.1.32-ndb-6.3.23 (revid:tomas.ulin@sun.com-20090217131017-6u8qz1edkjfiobef) (version source revid:tomas.ulin@sun.com-20090216083408-rmvyaxjt6mk8sg1y) (merge vers: 5.1.32-ndb-6.3.23) (pib:6)
[17 Feb 2009 16:45] Bugs System
Pushed into 5.1.32-ndb-6.4.3 (revid:tomas.ulin@sun.com-20090217134419-5ha6xg4dpedrbmau) (version source revid:tomas.ulin@sun.com-20090216083646-m8st11oj1hhfuuh5) (merge vers: 5.1.32-ndb-6.4.3) (pib:6)
[17 Feb 2009 18:21] Bugs System
Pushed into 5.1.32-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090217134216-5699eq74ws4oxa0j) (version source revid:tomas.ulin@sun.com-20090211111208-wf0acl7c1vl5653e) (merge vers: 5.1.32-ndb-6.2.17) (pib:6)
[18 Feb 2009 20:09] Paul Dubois
Noted in 5.1.32, 6.0.10 changelogs.

A '%' character in SQL statements could cause the server to crash.
[23 May 2010 14:04] Shane Bester
bug #53869 is a duplicate of this