Bug #8499 'tee' in command line client causes seg fault
Submitted: 14 Feb 2005 15:08 Modified: 31 Mar 2005 4:17
Reporter: d di (Basic Quality Contributor) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Command-line Clients Severity:S3 (Non-critical)
Version:MySQL-client-4.1.9-0.glibc23.x86_64 OS:Linux (SuSE SLES 9 (2.6.5-7.145-smp))
Assigned to: Jim Winstead CPU Architecture:Any

[14 Feb 2005 15:08] d di
Description:
Using the 'tee' command from the mysql command line client causes a segmentation fault and a output file that takes up all available space on the filesystem.

Endless loop somewhere perhaps?

I used tee in combination with the 'SHOW DATABASES' command, but it seems to fail with other commands also.

Transcript:
=======
# mysql -u root -p
Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 7 to server version: 4.1.9-standard-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> tee wank.txt
Logging to file 'wank.txt'
mysql> show databases;
+-------------+
| Database    |
+-------------+
| 0000_cms    |
Segmentation fault

How to repeat:
1. Download SUSE LINUX Enterprise Server 9 (x86_64) from the Novell web site.
2. Install MySQL-server-4.1.9-0.glibc23.x86_64.rpm and MySQL-client-4.1.9-0.glibc23.x86_64.rpm.
3. Connect to the server using the 'mysql' command.
4. Enter the following commands:
  tee wank.txt
  show databases;

I don't know whether the hardware configuration has any significance.
[15 Feb 2005 13:38] Hartmut Holzgraefe
Couldn't verify this with SuSE 9.0 (kernel 2.4.21) and 4.1.9 built from source
[17 Feb 2005 7:27] d di
Status "Can't repeat" after doing a test on a completely different OS?

Now that's just either plain dumb or pretty damn lazy.

Try your test again.
This time, for added fun, use the same configuration that I stated cause the problem.

That means (at the very least):
 - Same MySQL client version (MySQL-client-4.1.9-0.glibc23.x86_64)
 - Linux Kernel _2.6_
 - Use a SMP box

The easiest way to reproduce is probably to download the OS we're using (which, might I remind you, MySQL recommends in your manual as _the best_ for running MySQL), install it on a SMP box, add the MySQL server + client versions stated in the original report, and perform the test.
[20 Feb 2005 17:10] Aleksey Kishkin
David, "can't repeat" doesn't mean "closed"
[21 Feb 2005 6:42] d di
Okay.  I just assumed it meant that you declined the existence of the bug.
I'm sorry!

It may be a bit misleading that the bug doesn't show up in the "view your bugs" page anymore, that could sort of suggest that the bug is considered closed..
[21 Feb 2005 15:05] Sergei Golubchik
Hartmut, could you try to repeat this on melody ?

(it's x86_64, two CPU, 2.6.5-7.97-smp, SLES 9)
[10 Mar 2005 12:48] Sergey Kostyliov
I've just reproduced this problem on Gentoo Linux 2004.3 (amd64). MySQL is 4.1.10 builded from source.
rathamahata@lights rathamahata $ uname -a
Linux lights.vh.com.ru 2.6.11 #1 SMP Thu Mar 3 10:56:12 MSK 2005 x86_64 AMD Opteron(tm) Processor 246 AuthenticAMD GNU/Linux
rathamahata@lights rathamahata $ mysql
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2256542 to server version: 4.1.10-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> tee logfile;
Logging to file 'logfile'
mysql> show status;
+--------------------------------+--------------+
Segmentation fault
rathamahata@lights rathamahata $
[10 Mar 2005 13:08] Sergey Kostyliov
Program received signal SIGSEGV, Segmentation fault.
0x00002aaaab6de110 in strlen () from /lib/libc.so.6
(gdb) bt
#0  0x00002aaaab6de110 in strlen () from /lib/libc.so.6
#1  0x00002aaaab6b3238 in vfprintf () from /lib/libc.so.6
#2  0x000000000040ea56 in tee_fprintf(_IO_FILE*, char const*, ...) (
    file=0x2d2d2b2d2d2d2d2d, fmt=0x4236ad " %-*s|") at mysql.cc:3076
#3  0x000000000040c806 in print_table_data (result=0x54adf0) at mysql.cc:2026
#4  0x000000000040c253 in com_go (buffer=0x5339e0,
    line=0x5476a000 <Address 0x5476a000 out of bounds>) at mysql.cc:1869
#5  0x000000000040acfa in add_line (buffer=@0x5339e0, line=0x5483f0 "show status;",
    in_string=0x7ffffffff47e "", ml_comment=0x7ffffffff47f) at mysql.cc:1153
#6  0x000000000040a757 in read_lines (execute_commands=true) at mysql.cc:1003
#7  0x0000000000409bd0 in main (argc=2, argv=0x539100) at mysql.cc:455
(gdb)
[10 Mar 2005 13:35] d di
Ooh!
A backtrace.
Good idea.

Here's a system call trace also, hope it's helpful.

==  Execute command:  TEE wak.txt  ==

open("wak.txt", O_RDWR|O_APPEND|O_CREAT, 0666) = 4
write(1, "Logging to file \'wak.txt\'\n", 26) = 26
fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2a955a6000
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
ioctl(0, TIOCGWINSZ, {ws_row=67, ws_col=132, ws_xpixel=0, ws_ypixel=0}) = 0
ioctl(0, TIOCSWINSZ, {ws_row=67, ws_col=132, ws_xpixel=0, ws_ypixel=0}) = 0
ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig -icanon -echo ...}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGINT, {0x425ac0, [], 0x4000000}, {0x4128e0, [INT], SA_RESTART|0x4000000}, 8) = 0
rt_sigaction(SIGTERM, {0x425ac0, [], 0x4000000}, {SIG_DFL}, 8) = 0
rt_sigaction(SIGQUIT, {0x425ac0, [], 0x4000000}, {0x4128e0, [QUIT], SA_RESTART|0x4000000}, 8) = 0
rt_sigaction(SIGALRM, {0x425ac0, [], 0x4000000}, {SIG_DFL}, 8) = 0
rt_sigaction(SIGTSTP, {0x425ac0, [], 0x4000000}, {SIG_DFL}, 8) = 0
rt_sigaction(SIGTTOU, {0x425ac0, [], 0x4000000}, {SIG_DFL}, 8) = 0
rt_sigaction(SIGTTIN, {0x425ac0, [], 0x4000000}, {SIG_DFL}, 8) = 0
rt_sigaction(SIGWINCH, {0x425b70, [], 0x4000000}, {SIG_DFL}, 8) = 0
write(1, "mysql> ", 7)                  = 7
# read/write("select * from mysql.test;\r\n") snipped!
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig icanon echo ...}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGINT, {0x4128e0, [INT], SA_RESTART|0x4000000}, {0x425ac0, [], 0x4000000}, 8) = 0
rt_sigaction(SIGTERM, {SIG_DFL}, {0x425ac0, [], 0x4000000}, 8) = 0
rt_sigaction(SIGQUIT, {0x4128e0, [QUIT], SA_RESTART|0x4000000}, {0x425ac0, [], 0x4000000}, 8) = 0
rt_sigaction(SIGALRM, {SIG_DFL}, {0x425ac0, [], 0x4000000}, 8) = 0
rt_sigaction(SIGTSTP, {SIG_DFL}, {0x425ac0, [], 0x4000000}, 8) = 0
rt_sigaction(SIGTTOU, {SIG_DFL}, {0x425ac0, [], 0x4000000}, 8) = 0
rt_sigaction(SIGTTIN, {SIG_DFL}, {0x425ac0, [], 0x4000000}, 8) = 0
rt_sigaction(SIGWINCH, {SIG_DFL}, {0x425b70, [], 0x4000000}, 8) = 0

==  Execute command:  SELECT * FROM mysql.test;  ==

times({tms_utime=0, tms_stime=1, tms_cutime=0, tms_cstime=0}) = 250172062
fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
read(3, 0x638b20, 16384)                = -1 EAGAIN (Resource temporarily unavailable)
fcntl(3, F_SETFL, O_RDWR)               = 0
write(3, "\31\0\0\0\3select * from mysql.test", 29) = 29
read(3, "\1\0\0\1", 4)                  = 4
read(3, "\1", 1)                        = 1
read(3, "\'\0\0\2", 4)                  = 4
read(3, "\3def\5mysql\4test\4test\2Id\2Id\f?\0\4\0\0"..., 39) = 39
read(3, "\1\0\0\3", 4)                  = 4
read(3, "\376", 1)                      = 1
read(3, "\4\0\0\4", 4)                  = 4
read(3, "\003123", 4)                   = 4
brk(0)                                  = 0x679000
brk(0x69b000)                           = 0x69b000
read(3, "\5\0\0\5", 4)                  = 4
read(3, "\376\0\0\2\0", 5)              = 5
times({tms_utime=0, tms_stime=1, tms_cutime=0, tms_cstime=0}) = 250172062
write(1, "+------+\n", 9)               = 9
mmap(NULL, 1779785728, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2a95fb5000
write(4, "mysql> select * from mysql.test;"..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096
write(4, "                                "..., 4096) = 4096

==  Yes, well, the above line repeats forever :-)  ==
[10 Mar 2005 14:12] Hartmut Holzgraefe
Verified with 4.1.10 client on SLES 9 (x86_64), client only shows the first ascii table header 
row for a SHOW STATUS, hangs for a while and crashes. The TEE file created is about
1.7GB in size although only the first two lines are valid, followed by some magled characters
and billion of spaces ...
[11 Mar 2005 18:37] Sergey Kostyliov
I believe this is due to collision between va_* internals and second vfprintf() &#1089;all in tee_fprintf()

void tee_fprintf(FILE *file, const char *fmt, ...)
{
  va_list args;

  NETWARE_YIELD;
  va_start(args, fmt);
  (void) vfprintf(file, fmt, args);
#ifdef OS2
  fflush( file);
#endif
  if (opt_outfile)
    (void) vfprintf(OUTFILE, fmt, args);
^^^^^^^^^^^^^^^^^^^^^^^^^
  va_end(args);
}

According to: http://www.opengroup.org/onlinepubs/009695399/basedefs/stdarg.h.html
<cite>
The object ap may be passed as an argument to another function; if that function invokes the va_arg() macro with parameter ap, the value of ap in the calling function is unspecified and shall be passed to the va_end() macro prior to any further reference to ap.
<cite>
[11 Mar 2005 18:41] Sergey Kostyliov
So the following patch is needed (it has fixed segfault for me). Patch is against current bk.

===== client/mysql.cc 1.199 vs edited =====
--- 1.199/client/mysql.cc       2005-03-07 11:47:18 +03:00
+++ edited/client/mysql.cc      2005-03-11 20:37:07 +03:00
@@ -3074,6 +3074,8 @@
   fflush( file);
 #endif
   if (opt_outfile)
+    va_end(args);
+    va_start(args, fmt);
     (void) vfprintf(OUTFILE, fmt, args);
   va_end(args);
 }
[11 Mar 2005 18:55] Sergey Kostyliov
Oops, that was a wrong patch (stupid typo). The correct one is:
===== client/mysql.cc 1.199 vs edited =====
--- 1.199/client/mysql.cc       2005-03-07 11:47:18 +03:00
+++ edited/client/mysql.cc      2005-03-11 21:51:24 +03:00
@@ -3073,8 +3073,11 @@
 #ifdef OS2
   fflush( file);
 #endif
-  if (opt_outfile)
+  if (opt_outfile) {
+    va_end(args);
+    va_start(args, fmt);
     (void) vfprintf(OUTFILE, fmt, args);
+  }
   va_end(args);
 }
[11 Mar 2005 19:34] d di
Awesome.

If you want to make sure it scratches the original itch, I'd be happy to give it a whirl.

Don't have the time to set up a development environment though, so you'd have to email me a binary that matches MySQL-client-4.1.9-0.glibc23.x86_64....

If you're sure it's fixed, no need to bother though :-).
[16 Mar 2005 0:36] 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/internals/23067
[25 Mar 2005 20:37] Jim Winstead
Pushed, will be fixed in 4.1.11 and 5.0.4.
[31 Mar 2005 4:17] Paul DuBois
Noted in 4.1.11, 5.0.4 changelogs.