| Bug #20729 | Bad date_format() call makes mysql server crash | ||
|---|---|---|---|
| Submitted: | 27 Jun 2006 18:49 | Modified: | 20 Jul 2006 17:15 |
| Reporter: | Christian Hammers (Silver Quality Contributor) (OCA) | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server | Severity: | S2 (Serious) |
| Version: | 4.1 only | OS: | Linux (Debian GNU/Linux Sarge/FC4) |
| Assigned to: | Chad MILLER | CPU Architecture: | Any |
[27 Jun 2006 18:49]
Christian Hammers
[27 Jun 2006 19:31]
MySQL Verification Team
Thank you for the bug report. I was unable to repeat with current
source server:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 4.1.21-debug
Type 'help;' or '\h' for help. Type '\c' to clear the buffer.
mysql> select date_format('%d%s', 1);
+------------------------+
| date_format('%d%s', 1) |
+------------------------+
| NULL |
+------------------------+
1 row in set, 1 warning (0.03 sec)
mysql> show warnings;
+---------+------+---------------------------------------------------------------------------------------------+
| Level | Code | Message |
+---------+------+---------------------------------------------------------------------------------------------+
| Warning | 1292 | Truncated incorrect datetime value: '1129873952Truncated incorrect %-.32s value: '%-.128s'' |
+---------+------+---------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
mysql> select date_format('%Y-%m-%d %H:%i:%s', 1151414896);
+----------------------------------------------+
| date_format('%Y-%m-%d %H:%i:%s', 1151414896) |
+----------------------------------------------+
| NULL |
+----------------------------------------------+
1 row in set, 1 warning (0.00 sec)
mysql>
On Suse 10 and Ubuntu. I will install Debian or asking someone
for to test it.
[27 Jun 2006 19:41]
Christian Hammers
Some real output follows. As you can't reproduce it with 4.1.21, I guess it has been fixed in the meantime... so I have to find the corresponding patch to apply it to the Debian package :(
app109:/home/ch# mysql
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 5 to server version: 4.1.11-Debian_4sarge5-log
Type 'help;' or '\h' for help. Type '\c' to clear the buffer.
mysql> select date_format('%d%s', 1);
ERROR 2013 (HY000): Lost connection to MySQL server during query
Jun 27 19:37:27 app109 mysqld[27615]: /usr/sbin/mysqld: ready for connections.
Jun 27 19:37:27 app109 mysqld[27615]: Version: '4.1.11-Debian_4sarge5-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Source distribution
Jun 27 19:37:27 app109 /etc/mysql/debian-start[27649]: Checking for crashed MySQL tables.
Jun 27 19:37:28 app109 mysqld[27615]: mysqld got signal 11;
Jun 27 19:37:28 app109 mysqld[27615]: This could be because you hit a bug. It is also possible that this binary
Jun 27 19:37:28 app109 mysqld[27615]: or one of the libraries it was linked against is corrupt, improperly built,
Jun 27 19:37:28 app109 mysqld[27615]: or misconfigured. This error can also be caused by malfunctioning hardware.
Jun 27 19:37:28 app109 mysqld[27615]: We will try our best to scrape up some info that will hopefully help diagnose
Jun 27 19:37:28 app109 mysqld[27615]: the problem, but since we have already crashed, something is definitely wrong
Jun 27 19:37:28 app109 mysqld[27615]: and this may fail.
Jun 27 19:37:28 app109 mysqld[27615]:
Jun 27 19:37:28 app109 mysqld[27615]: key_buffer_size=16777216
Jun 27 19:37:28 app109 mysqld[27615]: read_buffer_size=131072
Jun 27 19:37:28 app109 mysqld[27615]: max_used_connections=1
Jun 27 19:37:28 app109 mysqld[27615]: max_connections=100
Jun 27 19:37:28 app109 mysqld[27615]: threads_connected=1
Jun 27 19:37:28 app109 mysqld[27615]: It is possible that mysqld could use up to
Jun 27 19:37:28 app109 mysqld[27615]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 233983 K
Jun 27 19:37:28 app109 mysqld[27615]: bytes of memory
Jun 27 19:37:28 app109 mysqld[27615]: Hope that's ok; if not, decrease some variables in the equation.
Jun 27 19:37:28 app109 mysqld[27615]:
Jun 27 19:37:28 app109 mysqld[27615]: thd=0x8b44a58
Jun 27 19:37:28 app109 mysqld[27615]: Attempting backtrace. You can use the following information to find out
Jun 27 19:37:28 app109 mysqld[27615]: where mysqld died. If you see no messages after this, something went
Jun 27 19:37:28 app109 mysqld[27615]: terribly wrong...
Jun 27 19:37:28 app109 mysqld[27615]: Cannot determine thread, fp=0xf3f6d2f8, backtrace may not be correct.
Jun 27 19:37:28 app109 mysqld[27615]: Stack range sanity check OK, backtrace follows:
Jun 27 19:37:28 app109 mysqld[27615]: 0x818935f
Jun 27 19:37:28 app109 mysqld[27615]: 0xffffe500
Jun 27 19:37:28 app109 mysqld[27615]: 0x383836
Jun 27 19:37:28 app109 mysqld[27615]: 0x8202035
Jun 27 19:37:28 app109 mysqld[27615]: 0x8201412
Jun 27 19:37:28 app109 mysqld[27615]: 0x8111ddd
Jun 27 19:37:28 app109 mysqld[27615]: 0x814f6ce
Jun 27 19:37:28 app109 mysqld[27615]: 0x8115a6c
Jun 27 19:37:28 app109 mysqld[27615]: 0x817b270
Jun 27 19:37:28 app109 mysqld[27615]: 0x81c5256
Jun 27 19:37:28 app109 mysqld[27615]: 0x81c68c2
Jun 27 19:37:28 app109 mysqld[27615]: 0x81c3252
Jun 27 19:37:28 app109 mysqld[27615]: 0x819d546
Jun 27 19:37:28 app109 mysqld[27615]: 0x81a2bdc
Jun 27 19:37:28 app109 mysqld[27615]: 0x819c0cf
Jun 27 19:37:28 app109 mysqld[27615]: 0x819bce6
Jun 27 19:37:28 app109 mysqld[27615]: 0x819b448
Jun 27 19:37:28 app109 mysqld[27615]: 0xf7eeeb63
Jun 27 19:37:28 app109 mysqld[27615]: 0xf7d6618a
Jun 27 19:37:28 app109 mysqld[27615]: New value of fp=(nil) failed sanity check, terminating stack trace!
Jun 27 19:37:28 app109 mysqld[27615]: Please read http://dev.mysql.com/doc/mysql/en/Using_stack_trace.html and follow instructions on how to resolve
the stack trace. Resolved
Jun 27 19:37:28 app109 mysqld[27615]: stack trace is much more helpful in diagnosing the problem, so please do
Jun 27 19:37:28 app109 mysqld[27615]: resolve it
Jun 27 19:37:28 app109 mysqld[27615]: Trying to get some variables.
Jun 27 19:37:28 app109 mysqld[27615]: Some pointers may be invalid and cause the dump to abort...
Jun 27 19:37:28 app109 mysqld[27615]: thd->query at 0x8b699d8 = select date_format('%d%s', 1)
Jun 27 19:37:28 app109 mysqld[27615]: thd->thread_id=5
Jun 27 19:37:28 app109 mysqld[27615]: The manual page at http://www.mysql.com/doc/en/Crashing.html contains
Jun 27 19:37:28 app109 mysqld[27615]: information that should help you find out what is causing the crash.
Jun 27 19:37:28 app109 mysqld_safe[27667]: Number of processes running now: 0
Jun 27 19:37:28 app109 mysqld_safe[27669]: restarted
app109:/home/ch# resolve_stack_dump /usr/share/doc/mysql-server-4.1/mysqld.sym t
0x818935f handle_segfault + 703
0xffffe500 _end + -141084944
0x383836 (?)
0x8202035 _Z28make_truncated_value_warningP3THDPKcj25enum_mysql_timestamp_type + 229
0x8201412 _Z25str_to_datetime_with_warnPKcjP13st_mysql_timej + 114
0x8111ddd _ZN4Item8get_dateEP13st_mysql_timej + 93
0x814f6ce _ZN21Item_func_date_format7val_strEP6String + 62
0x8115a6c _ZN4Item4sendEP8ProtocolP6String + 172
0x817b270 _ZN11select_send9send_dataER4ListI4ItemE + 192
0x81c5256 _ZN4JOIN4execEv + 406
0x81c68c2 _Z12mysql_selectP3THDPPP4ItemP13st_table_listjR4ListIS1_ES2_jP8st_orderSB_S2_SB_mP13select_resultP18st_select_lex_unitP13st_sel + 178
0x81c3252 _Z13handle_selectP3THDP6st_lexP13select_result + 242
0x819d546 _Z21mysql_execute_commandP3THD + 934
0x81a2bdc _Z11mysql_parseP3THDPcj + 204
0x819c0cf _Z16dispatch_command19enum_server_commandP3THDPcj + 927
0x819bce6 _Z10do_commandP3THD + 134
0x819b448 handle_one_connection + 856
0xf7eeeb63 _end + -276415149
0xf7d6618a _end + -278023302
[27 Jun 2006 19:51]
MySQL Verification Team
My source was some days older. I am compiling again and will retest again.
[27 Jun 2006 20:45]
MySQL Verification Team
I repeated using latest source, on FC4 when running :
select date_format('%d%s', 1)
0x80bd6fd handle_segfault + 461
0xc98420 data.7108 + 13206516
0x65746164 __stop___libc_freeres_ptrs + 1561674776
0x813d7ec _Z28make_truncated_value_warningP3THDPKcj25enum_mysql_timestamp_type + 228
0x813daa5 _Z25str_to_datetime_with_warnPKcjP13st_mysql_timej + 95
0x8050b11 _ZN4Item8get_dateEP13st_mysql_timej + 93
0x808b384 _ZN21Item_func_date_format7val_strEP6String + 100
0x804ee5d _ZN4Item4sendEP8ProtocolP6String + 55
0x80ae9bd _ZN11select_send9send_dataER4ListI4ItemE + 215
0x810dda2 _ZN4JOIN4execEv + 756
0x811039e _Z12mysql_selectP3THDPPP4ItemP13st_table_listjR4ListIS1_ES2_jP8st_orderSB_S2_SB_mP13select_resultP18st_select_lex_unitP13st_sel + 1506
0x81108cc _Z13handle_selectP3THDP6st_lexP13select_result + 390
0x80d19c2 _Z21mysql_execute_commandP3THD + 1512
0x80d6381 _Z11mysql_parseP3THDPcj + 289
0x80d6bd2 _Z16dispatch_command19enum_server_commandP3THDPcj + 1934
0x80d7e02 _Z10do_commandP3THD + 530
0x80d894d handle_one_connection + 2723
0x8373462 start_thread + 98
0x83a41ce __clone + 110
[29 Jun 2006 19:12]
Christian Hammers
I observed that the error leads to a segfault when I either use the Debian package or build the RPM file with the shipped spec file myself.
When using any of the distributed binaries the function correctly retuns NULL *but* the generated warning seems somehow corrupted. My guess is that this means that the bug is present in the mysql source just depending on how you compile you get only a corrupted warning message or a segfault while it tries to warn. The last function in the stack was make_truncated_value_warning().
Starting from 4.1.19 the bug seems to be fixed though as the return is:
mysql> select date_format("%d%s", 1); show warnings;
+------------------------+
| date_format("%d%s", 1) |
+------------------------+
| NULL |
+------------------------+
1 row in set, 1 warning (0.04 sec)
+---------+------+-----------------------------------------------+
| Level | Code | Message |
+---------+------+-----------------------------------------------+
| Warning | 1292 | Truncated incorrect datetime value: '0(null)' |
+---------+------+-----------------------------------------------+
1 row in set (0.00 sec)
Output with MySQL-server-4.1.11-0.i386.rpm:
mysql> select date_format("%d%s", 1); show warnings;
+------------------------+
| date_format("%d%s", 1) |
+------------------------+
| NULL |
+------------------------+
1 row in set, 1 warning (0.00 sec)
+---------+------+-------------------------------------------------------------------------------------------+
| Level | Code | Message |
+---------+------+-------------------------------------------------------------------------------------------+
| Warning | 1292 | Truncated incorrect datetime value: '-1578108Truncated incorrect %-.32s value: '%-.128s'' |
+---------+------+-------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
^^^^^^^^^^^^^^ Notice that the %-.128s in the first message is substituted by
the number and printf format string itself :)
Output with self build RPM file:
Version: '4.1.11-Max-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 MySQL Community Edition - Max (GPL)
mysqld got signal 11;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.
key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=1
max_connections=100
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 233983 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
thd=0x8b14938
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
Cannot determine thread, fp=0xf403c308, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x8185bf4
0xffffe500
0x303038
0x81fb2b3
0x81fa6b1
0x810e1ad
0x814cfae
0x8111cfc
0x81775f0
0x81c005c
0x81c1452
0x81be1a2
0x8199372
0x819e8cd
0x8197da6
0x8197a26
0x819720b
0xf7efab63
0xf7e3518a
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8b398c8 = select date_format("%d%s", 1)
thd->thread_id=1
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
[29 Jun 2006 20:50]
Christian Hammers
Ok, new findings:
a) all the 4.1 debug packages like mysql-debug-4.1.20-pc-linux-gnu-i686.tar.gz
display the warning as "0(NULL)" which would look quite ok to me.
all the 4.1 standard packages like
mysql-standard-4.1.20-pc-linux-gnu-i686.tar.gz
display the warning as "Truncated incorrect datetime value: '-1578124Truncated incorrect %-.32s value: '%-.128s''
So there is a pointer problem in the latest 4.1 version (4.1.20) but it just
manifests itself a bit differnet depending on how exactly it was build in the
sense that it is pure choice if it segfaults (Debian+FC or just prints
garbage.
b) I tracked the reason for the bug down but don't know how to fix it the
most elegant way. Start reading the backtrace from bottom to top.
(gdb) bt
#0 0x08334b5f in strlen ()
Whatever is passed to strlen() is no valid string and the segfault
occurs. In my tests it was a pointer to 0x5 which clearly is
far far away from mysql's memory block :)
#1 0x08303b8e in my_vsnprintf ()
This function works until it parses "%s", here it does not
check if there are enough arguments!
The va_arg(ap, char *s) returns a variable upon which
strlen() is called.
#2 0x0811a7c1 in push_warning_printf ()
This function works like a printf() and is called with a format
string that include "%d%s" but *no* arguments.
#3 0x08139da8 in make_truncated_value_warning ()
Here, DATETIME_NONE is not known so the case defaults
to type_str=datetime.
warn_buff is set to "Truncated incorrect datetime value: '%d%s'"
#4 0x081390b2 in str_to_datetime_with_warn ()
This function gets "%d%s" as argument str and
calculates ts_type=-2 and was_cut=1.
-2 means type "DATETIME_NONE" which looks ok.
#5 0x0804ce5d in Item::get_date ()
#6 0x0808bc5e in Item_func_date_format::val_str ()
#7 0x080509ac in Item::send ()
#8 0x080b6290 in select_send::send_data ()
#9 0x080fea3c in JOIN::exec ()
#10 0x080ffe32 in mysql_select ()
#11 0x080fcb82 in handle_select ()
#12 0x080d7d52 in mysql_execute_command ()
#13 0x080dd2ad in mysql_parse ()
#14 0x080d6786 in dispatch_command ()
#15 0x080d6406 in do_command ()
#16 0x080d5beb in handle_one_connection ()
#17 0x0830eace in pthread_start_thread (arg=0xfe7ffbe0) at manager.c:309
#18 0x0830eb41 in pthread_start_thread_event (arg=0xfe7ffbe0) at manager.c:333
#19 0x0833c37a in clone ()
The function is called as "SELECT date_format("%d%s", 1);"
Hope this helps!
bye,
-christian-
[4 Jul 2006 20:45]
Christian Hammers
Hello
I've written a patch for this. Surely isn't beautiful but seems to fix the problem - for those who can't wait for the next 4.1.x release.
bye,
-christian-
--- old/sql/time.cc.chold 2006-07-04 20:48:23.000000000 +0200
+++ new/sql/time.cc 2006-07-04 20:56:50.000000000 +0200
@@ -201,8 +201,12 @@ str_to_datetime_with_warn(const char *st
{
int was_cut;
timestamp_type ts_type= str_to_datetime(str, length, l_time, flags, &was_cut);
- if (was_cut)
- make_truncated_value_warning(current_thd, str, length, ts_type);
+ if (was_cut) {
+ if (strchr(str, '%') != NULL)
+ make_truncated_value_warning(current_thd, "INVALID TIME", strlen("INVALID TIME"), ts_type);
+ else
+ make_truncated_value_warning(current_thd, str, length, ts_type);
+ }
return ts_type;
}
[5 Jul 2006 9:40]
Sergei Golubchik
It probably doesn't close all exploitable execution paths (you put it too early).
The correct fix is:
===== time.cc 1.52 vs edited =====
--- 1.52/sql/time.cc Thu Dec 30 19:37:29 2004
+++ edited/time.cc Wed Jul 5 11:26:14 2006
@@ -797,7 +797,7 @@
}
sprintf(warn_buff, ER(ER_TRUNCATED_WRONG_VALUE),
type_str, str.ptr());
- push_warning_printf(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
+ push_warning(thd, MYSQL_ERROR::WARN_LEVEL_WARN,
ER_TRUNCATED_WRONG_VALUE, warn_buff);
}
[11 Jul 2006 17: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/9048
[11 Jul 2006 18:28]
Chad MILLER
Docs: Note: This is security bulletin CVE-2006-3469 . Applied to 4.1.21 . This was fixed in 5.0 on 1 April 2006, and would be available at the next 5.x release after that. This bug never existed in 4.0 . A user-supplied argument to date_format() could cause the server to crash.
[13 Jul 2006 3:57]
Paul DuBois
Noted in 4.1.21 changelog. Invalid arguments to DATE_FORMAT() caused a server crash. (CVE-2006-3469, Bug #20729) Thanks to Jean-David Maillefer for discovering and reporting this problem to the Debian project and to Christian Hammers from the Debian Team for notifying us of it.
[20 Jul 2006 17:15]
Paul DuBois
Noted in 5.0.21, 5.1.9 changelogs.
