Re: [Qemu-devel] [PULL 6/6] Monitor: Make output buffer dynamic

[Anthony Liguori <aliguori@us.ibm.com>]

Luiz Capitulino <lcapitulino@redhat.com> writes:

> Commit f628926bb423fa8a7e0b114511400ea9df38b76a changed monitor_flush()
> to retry on qemu_chr_fe_write() errors. However, the Monitor's output
> buffer can keep growing while the retry is not issued and this can
> cause the buffer to overflow.
>
> To reproduce this issue, just start qemu and type on the Monitor:
>
> (qemu) ?
>
> This will cause the assertion to trig.
>
> To fix this problem this commit makes the Monitor buffer dynamic,
> which means that it can grow as much as needed.
>
> Signed-off-by: Luiz Capitulino <lcapitulino@redhat.com>

This breaks hotplug according to git bisect.  The test output is:

[aliguori@ccnode4 qemu-test]$ QEMU_TEST_SEED=6381 ./qemu-test ~/build/qemu/x86_64-softmmu/qemu-system-x86_64 tests/device-add.sh
Using RANDOM seed 6381
Formatting '.tmp-13653/disk.img', fmt=qcow2 size=10737418240 encryption=off cluster_size=65536 lazy_refcounts=off 
/home/aliguori/build/qemu/x86_64-softmmu/qemu-system-x86_64 -kernel /usr/local/share/qemu-jeos/kernel-x86_64-pc -initrd .tmp-13653/initramfs-13653.img.gz -device isa-debug-exit -append console=ttyS0 seed=6381 -nographic -enable-kvm -pidfile .tmp-13653/pidfile-13653.pid -qmp unix:.tmp-13653/qmpsock-13653.sock,server,nowait
<snip>
[    0.863523] Freeing unused kernel memory: 1724k freed
Setting guest RANDOM seed to 6381
*** Running tests ***
/tests/device-add.sh
Running test /tests/device-add.sh...
** waiting for hotplug **
Traceback (most recent call last):
  File "../..//QMP/qmp", line 126, in <module>
    sys.exit(main(sys.argv[1:]))
  File "../..//QMP/qmp", line 122, in main
    rsp = do_command(srv, command, **arguments)
  File "../..//QMP/qmp", line 81, in do_command
./qemu-test: line 99: 13685 Segmentation fault      "$@"
AttributeError: 'NoneType' object has no attribute 'has_key'
./tests/device-add.sh: line 22: test: !=: unary operator expected
Traceback (most recent call last):
  File "../..//QMP/qmp", line 126, in <module>
    sys.exit(main(sys.argv[1:]))
  File "../..//QMP/qmp", line 77, in main
    srv.connect()
  File "/home/aliguori/git/qemu-test/QMP/qmp.py", line 84, in connect
    self.__sock.connect(self.__address)
  File "/usr/lib64/python2.7/socket.py", line 224, in meth
    return getattr(self._sock,name)(*args)
socket.error: [Errno 111] Connection refused
** waiting for guest to see device **

The test is failing because QEMU is SEGV'ing.  The backtrace from the
core is:

Core was generated by `/home/aliguori/build/qemu/x86_64-softmmu/qemu-system-x86_64 -kernel /usr/local/'.
Program terminated with signal 11, Segmentation fault.
#0  capacity_increase (qstring=qstring@entry=0x0, len=len@entry=1)
    at /home/aliguori/git/qemu/qobject/qstring.c:77
77	    if (qstring->capacity < (qstring->length + len)) {
Missing separate debuginfos, use: debuginfo-install bzip2-libs-1.0.6-7.fc18.x86_64 glib2-2.34.2-2.fc18.x86_64 glibc-2.16-28.fc18.x86_64 libaio-0.3.109-6.fc18.x86_64 libfdt-1.3.0-5.fc18.x86_64 libgcc-4.7.2-8.fc18.x86_64 pixman-0.26.2-5.fc18.x86_64 xen-libs-4.2.1-5.fc18.x86_64 xz-libs-5.1.2-2alpha.fc18.x86_64 zlib-1.2.7-9.fc18.x86_64
(gdb) bt
#0  capacity_increase (qstring=qstring@entry=0x0, len=len@entry=1)
    at /home/aliguori/git/qemu/qobject/qstring.c:77
#1  0x00007f610c43e32d in qstring_append_chr (qstring=0x0, c=79)
    at /home/aliguori/git/qemu/qobject/qstring.c:110
#2  0x00007f610c398357 in monitor_puts (mon=mon@entry=0x7fff2d5d7040, str=
    0x7f610f064c01 "K\n", str@entry=0x7f610f064c00 "OK\n")
    at /home/aliguori/git/qemu/monitor.c:309
#3  0x00007f610c399379 in monitor_vprintf (ap=<optimized out>, 
    fmt=<optimized out>, mon=0x7fff2d5d7040)
    at /home/aliguori/git/qemu/monitor.c:328
#4  monitor_vprintf (mon=0x7fff2d5d7040, fmt=<optimized out>, 
    ap=<optimized out>) at /home/aliguori/git/qemu/monitor.c:316
#5  0x00007f610c399504 in monitor_printf (mon=<optimized out>, 
    fmt=<optimized out>) at /home/aliguori/git/qemu/monitor.c:336
#6  0x00007f610c39e809 in handle_user_command (mon=mon@entry=0x7fff2d5d7040, 
    cmdline=cmdline@entry=
    0x7f610f064530 "drive_add auto file=.tmp-21330/disk.img,if=none,id=hd0")
    at /home/aliguori/git/qemu/monitor.c:4005
#7  0x00007f610c39e9da in qmp_human_monitor_command (command_line=
    0x7f610f064530 "drive_add auto file=.tmp-21330/disk.img,if=none,id=hd0", 
    has_cpu_index=false, cpu_index=140054840363424, errp=errp@entry=
    0x7fff2d5d71c8) at /home/aliguori/git/qemu/monitor.c:697
#8  0x00007f610c2ff969 in qmp_marshal_input_human_monitor_command (
    mon=<optimized out>, qdict=<optimized out>, ret=0x7fff2d5d7250)
    at qmp-marshal.c:1624
#9  0x00007f610c398ff8 in qmp_call_cmd (cmd=<optimized out>, params=
    0x7f610f023980, mon=0x7f610efbb220)
    at /home/aliguori/git/qemu/monitor.c:4506
#10 handle_qmp_command (parser=<optimized out>, tokens=<optimized out>)
    at /home/aliguori/git/qemu/monitor.c:4572
#11 0x00007f610c44051a in json_message_process_token (lexer=0x7f610efbb2c0, 
    token=0x7f610f064320, type=JSON_OPERATOR, x=156, y=0)
    at /home/aliguori/git/qemu/qobject/json-streamer.c:87
#12 0x00007f610c45211f in json_lexer_feed_char (lexer=lexer@entry=
    0x7f610efbb2c0, ch=125 '}', flush=flush@entry=false)
    at /home/aliguori/git/qemu/qobject/json-lexer.c:303
#13 0x00007f610c452266 in json_lexer_feed (lexer=0x7f610efbb2c0, 
    buffer=<optimized out>, size=<optimized out>)
    at /home/aliguori/git/qemu/qobject/json-lexer.c:356
#14 0x00007f610c440731 in json_message_parser_feed (parser=<optimized out>, 
    buffer=<optimized out>, size=<optimized out>)
    at /home/aliguori/git/qemu/qobject/json-streamer.c:110
#15 0x00007f610c3974ab in monitor_control_read (opaque=<optimized out>, 
    buf=<optimized out>, size=<optimized out>)
    at /home/aliguori/git/qemu/monitor.c:4593
#16 0x00007f610c2f6d29 in qemu_chr_be_write (len=<optimized out>, buf=
    0x7fff2d5d7440 "}", s=0x7f610efb2640)
    at /home/aliguori/git/qemu/qemu-char.c:187
#17 tcp_chr_read (chan=<optimized out>, cond=<optimized out>, opaque=
    0x7f610efb2640) at /home/aliguori/git/qemu/qemu-char.c:2530
#18 0x00007f610b83fa55 in g_main_context_dispatch ()
   from /lib64/libglib-2.0.so.0
#19 0x00007f610c2cfe39 in glib_pollfds_poll ()
    at /home/aliguori/git/qemu/main-loop.c:187
#20 os_host_main_loop_wait (timeout=<optimized out>)
    at /home/aliguori/git/qemu/main-loop.c:207
#21 main_loop_wait (nonblocking=<optimized out>)
    at /home/aliguori/git/qemu/main-loop.c:443
#22 0x00007f610c1c4385 in main_loop () at /home/aliguori/git/qemu/vl.c:2043
#23 main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>)
    at /home/aliguori/git/qemu/vl.c:4429

The script for the test is at:

http://git.qemu.org/?p=qemu-test.git;a=blob;f=tests/device-add.sh;h=52ffbf0e10a546d15a2108bba46d97215103b34a;hb=HEAD

The failure is 100% reproducible so if you have any trouble reproducing,
let me know.

Regards,

Anthony Liguori

> ---
>  monitor.c | 42 +++++++++++++++++++++++++-----------------
>  1 file changed, 25 insertions(+), 17 deletions(-)
>
> diff --git a/monitor.c b/monitor.c
> index 5dfae2a..4da45c0 100644
> --- a/monitor.c
> +++ b/monitor.c
> @@ -188,8 +188,7 @@ struct Monitor {
>      int reset_seen;
>      int flags;
>      int suspend_cnt;
> -    uint8_t outbuf[1024];
> -    int outbuf_index;
> +    QString *outbuf;
>      ReadLineState *rs;
>      MonitorControl *mc;
>      CPUArchState *mon_cpu;
> @@ -271,45 +270,52 @@ static gboolean monitor_unblocked(GIOChannel *chan, GIOCondition cond,
>  void monitor_flush(Monitor *mon)
>  {
>      int rc;
> +    size_t len;
> +    const char *buf;
> +
> +    buf = qstring_get_str(mon->outbuf);
> +    len = qstring_get_length(mon->outbuf);
>  
> -    if (mon && mon->outbuf_index != 0 && !mon->mux_out) {
> -        rc = qemu_chr_fe_write(mon->chr, mon->outbuf, mon->outbuf_index);
> -        if (rc == mon->outbuf_index) {
> +    if (mon && len && !mon->mux_out) {
> +        rc = qemu_chr_fe_write(mon->chr, (const uint8_t *) buf, len);
> +        if (rc == len) {
>              /* all flushed */
> -            mon->outbuf_index = 0;
> +            QDECREF(mon->outbuf);
> +            mon->outbuf = qstring_new();
>              return;
>          }
>          if (rc > 0) {
>              /* partinal write */
> -            memmove(mon->outbuf, mon->outbuf + rc, mon->outbuf_index - rc);
> -            mon->outbuf_index -= rc;
> +            QString *tmp = qstring_from_str(buf + rc);
> +            QDECREF(mon->outbuf);
> +            mon->outbuf = tmp;
>          }
>          qemu_chr_fe_add_watch(mon->chr, G_IO_OUT, monitor_unblocked, mon);
>      }
>  }
>  
> -/* flush at every end of line or if the buffer is full */
> +/* flush at every end of line */
>  static void monitor_puts(Monitor *mon, const char *str)
>  {
>      char c;
>  
>      for(;;) {
> -        assert(mon->outbuf_index < sizeof(mon->outbuf) - 1);
>          c = *str++;
>          if (c == '\0')
>              break;
> -        if (c == '\n')
> -            mon->outbuf[mon->outbuf_index++] = '\r';
> -        mon->outbuf[mon->outbuf_index++] = c;
> -        if (mon->outbuf_index >= (sizeof(mon->outbuf) - 1)
> -            || c == '\n')
> +        if (c == '\n') {
> +            qstring_append_chr(mon->outbuf, '\r');
> +        }
> +        qstring_append_chr(mon->outbuf, c);
> +        if (c == '\n') {
>              monitor_flush(mon);
> +        }
>      }
>  }
>  
>  void monitor_vprintf(Monitor *mon, const char *fmt, va_list ap)
>  {
> -    char buf[4096];
> +    char *buf;
>  
>      if (!mon)
>          return;
> @@ -318,8 +324,9 @@ void monitor_vprintf(Monitor *mon, const char *fmt, va_list ap)
>          return;
>      }
>  
> -    vsnprintf(buf, sizeof(buf), fmt, ap);
> +    buf = g_strdup_vprintf(fmt, ap);
>      monitor_puts(mon, buf);
> +    g_free(buf);
>  }
>  
>  void monitor_printf(Monitor *mon, const char *fmt, ...)
> @@ -4740,6 +4747,7 @@ void monitor_init(CharDriverState *chr, int flags)
>      }
>  
>      mon = g_malloc0(sizeof(*mon));
> +    mon->outbuf = qstring_new();
>  
>      mon->chr = chr;
>      mon->flags = flags;
> -- 
> 1.8.1.4