This service will be undergoing maintenance at 00:00 UTC, 2016-08-01. It is expected to last about 1 hours
Bug 876685 - Spice server aborts when spice client is connected
Spice server aborts when spice client is connected
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: spice-server (Show other bugs)
6.4
Unspecified Unspecified
unspecified Severity high
: rc
: ---
Assigned To: Yonit Halperin
Desktop QE
: Regression
: 879159 880887 (view as bug list)
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-11-14 12:41 EST by Marian Krcmarik
Modified: 2013-07-03 08:13 EDT (History)
12 users (show)

See Also:
Fixed In Version: spice-server-0.12.0-6.el6
Doc Type: Bug Fix
Doc Text:
I think this bug was found and fixed in 6.4 development phase. But I'm not sure so: Using lz compression on server self-made images (*), resulted with bad stride values (**). This caused spice-server to abort. Fixed by not using lz compression for such images. (*) if example for such images is wanted see comment #11 (**) if more information is wanted: stride > bpp*width, which spice treats as bad values for images that go through lz compression.
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-02-21 05:03:48 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)
spice-server-0.12.0-3 for rhpkg (1.73 KB, patch)
2012-11-15 06:06 EST, Alon Levy
no flags Details | Diff
spice-server-0.12.0-4 for rhpkg (actual fix proposed) (2.98 KB, patch)
2012-11-15 15:53 EST, Alon Levy
no flags Details | Diff

  None (edit)
Description Marian Krcmarik 2012-11-14 12:41:45 EST
Description of problem:
Spice server aborts when spice client is connected while using by a user. I haven't observed any specific reproducer, I have a suspect It's related to arbitrary resolution change but I hit the bug even when typing in gnome terminal on the guest. 

QEMU stdout:
((null):15058): SpiceWorker-CRITICAL **: red_worker.c:5467:lz_usr_error: stride != width*bytes_per_pixel (rgb) 12 != 10 * 1 (11)

or

((null):15058): SpiceWorker-CRITICAL **: red_worker.c:5467:lz_usr_error: stride != width*bytes_per_pixel (rgb) 412 != 410 * 1 (11)


BT:
(gdb) thread apply all bt

Thread 7 (Thread 0x7fcb0dffa700 (LWP 15136)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:216
#1  0x00007fcb664524b7 in cond_timedwait (unused=<value optimized out>)
    at posix-aio-compat.c:102
#2  aio_thread (unused=<value optimized out>) at posix-aio-compat.c:329
#3  0x00007fcb65d6d851 in start_thread (arg=0x7fcb0dffa700)
    at pthread_create.c:301
#4  0x00007fcb63e2c90d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 4 (Thread 0x7fcb5d2dd700 (LWP 15082)):
#0  0x00007fcb63e24a47 in ioctl () at ../sysdeps/unix/syscall-template.S:82
#1  0x00007fcb6643637a in kvm_run (env=0x7fcb679ce0b0)
    at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:1015
#2  0x00007fcb66436829 in kvm_cpu_exec (env=<value optimized out>)
    at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:1743
#3  0x00007fcb6643770d in kvm_main_loop_cpu (_env=0x7fcb679ce0b0)
    at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:2004
#4  ap_main_loop (_env=0x7fcb679ce0b0)
    at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:2060
#5  0x00007fcb65d6d851 in start_thread (arg=0x7fcb5d2dd700)
    at pthread_create.c:301
#6  0x00007fcb63e2c90d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 3 (Thread 0x7fcb0e9fb700 (LWP 15083)):
#0  0x00007fcb63d768a5 in raise (sig=6)
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x00007fcb63d78085 in abort () at abort.c:92
#2  0x00007fcb645d0c35 in spice_logv (log_domain=0x7fcb6464cd9c "SpiceWorker", 
    log_level=SPICE_LOG_LEVEL_CRITICAL, 
    strloc=0x7fcb6464d159 "red_worker.c:5467", 
    function=0x7fcb6464eeae "lz_usr_error", format=0x7fcb6465918a "%s", 
    args=0x7fcb0e9fa490) at log.c:109
#3  0x00007fcb645d0d6a in spice_log (log_domain=<value optimized out>, 
    log_level=<value optimized out>, strloc=<value optimized out>, 
    function=<value optimized out>, format=<value optimized out>) at log.c:123
#4  0x00007fcb645956d4 in lz_usr_error (usr=0x7fcb081d7720, 
    fmt=<value optimized out>) at red_worker.c:5467
#5  0x00007fcb645d5aae in lz_encode (lz=0x7fcb66361010, type=LZ_IMAGE_TYPE_A8, 
    width=10, height=9, top_down=1, lines=0x0, num_lines=0, stride=12, 
    io_ptr=0x7fcb09a77bc0 "  ZL", num_io_bytes=65536) at lz.c:524
#6  0x00007fcb6459cdc0 in red_lz_compress_image (dcc=0x7fcaf9daf290, 
    dest=0x7fcb0e9fa8a0, src=0x7fcb0e9fa8e0, o_comp_data=0x7fcb0e9fa910, 
    group_id=<value optimized out>) at red_worker.c:6038
#7  0x00007fcb645aa736 in red_marshall_image (rcc=0x7fcaf9daf290, 
    pipe_item=0x7fcb09c17960) at red_worker.c:8600
#8  display_channel_send_item (rcc=0x7fcaf9daf290, pipe_item=0x7fcb09c17960)
    at red_worker.c:8911
#9  0x00007fcb6458a583 in red_channel_client_send_item (rcc=0x7fcaf9daf290)
    at red_channel.c:507
#10 red_channel_client_push (rcc=0x7fcaf9daf290) at red_channel.c:1088
#11 0x00007fcb6458a9cb in red_channel_client_handle_message (
    rcc=0x7fcaf9daf290, size=1, type=<value optimized out>, 
    message=0x7fcaf9ea47e0) at red_channel.c:1175
#12 0x00007fcb6458a20b in red_peer_handle_incoming (rcc=0x7fcaf9daf290)
    at red_channel.c:272
#13 red_channel_client_receive (rcc=0x7fcaf9daf290) at red_channel.c:294
#14 0x00007fcb6458aa9c in red_channel_client_event (fd=<value optimized out>, 
    event=<value optimized out>, data=0x7fcaf9daf290) at red_channel.c:1204
#15 0x00007fcb645af88e in red_worker_main (arg=<value optimized out>)
    at red_worker.c:11782
#16 0x00007fcb65d6d851 in start_thread (arg=0x7fcb0e9fb700)
    at pthread_create.c:301
#17 0x00007fcb63e2c90d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 1 (Thread 0x7fcb66382980 (LWP 15058)):
#0  0x00007fcb63e254f3 in select () at ../sysdeps/unix/syscall-template.S:82
#1  0x00007fcb66412880 in main_loop_wait (timeout=1000)
    at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:3968
#2  0x00007fcb664348ca in kvm_main_loop ()
    at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:2244
#3  0x00007fcb66415678 in main_loop (argc=56, argv=<value optimized out>, 
    envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:4187
#4  main (argc=56, argv=<value optimized out>, envp=<value optimized out>)
    at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:6524

Version-Release number of selected component (if applicable):
RHEL6.4 Alpha host/client/guest
# rpm -qa | egrep "qemu-kvm|spice-server|spice-gtk|virt-viewer"
qemu-kvm-0.12.1.2-2.334.el6.x86_64
qemu-kvm-debuginfo-0.12.1.2-2.334.el6.x86_64
virt-viewer-0.5.2-16.el6.x86_64
spice-gtk-0.14-4.el6.x86_64
spice-gtk-python-0.14-4.el6.x86_64
spice-server-debuginfo-0.12.0-1.el6.x86_64
spice-server-0.12.0-1.el6.x86_64

How reproducible:
Very often (matter of time)

Steps to Reproduce:
1. Connect to RHEL6.4 machine with remote-viewer
2. Perform usual user actions
  
Actual results:
Abort hit

Expected results:
No abort

Additional info:
Comment 3 Alon Levy 2012-11-15 06:05:59 EST
Marian,

 Could you test the attached two patches for rhpkg? (the first is just something I already had there, the second actually should fix the problem)

Alon
(attaching momentarily)
Comment 4 Alon Levy 2012-11-15 06:06:58 EST
Created attachment 645592 [details]
spice-server-0.12.0-3 for rhpkg
Comment 6 Alon Levy 2012-11-15 15:53:47 EST
Created attachment 645982 [details]
spice-server-0.12.0-4 for rhpkg (actual fix proposed)
Comment 7 Alon Levy 2012-11-15 15:55:56 EST
Marian,

 Sorry - I sort of forgot in the middle, the patch you used is absolutely not related, I just attached the actual one that may solve it - it basically just tries to let the encoder continue on, if it actually uses width & stride correctly it may even work (and if the decoder does the same). I'll appreciate if you can test again, sorry for the double work!

Alon
Comment 8 Marian Krcmarik 2012-11-16 14:22:40 EST
(In reply to comment #7)
> Marian,
> 
>  Sorry - I sort of forgot in the middle, the patch you used is absolutely
> not related, I just attached the actual one that may solve it - it basically
> just tries to let the encoder continue on, if it actually uses width &
> stride correctly it may even work (and if the decoder does the same). 

It seems It does not, now remote-viewer crashing on decompressing.

(/usr/bin/remote-viewer:7438): Spice-ERROR **: lz_decompress_tmpl.c:273:lz_a8_decompress: assertion `op + len <= op_limit' failed
#0  0x000000364f40e530 in __read_nocancel () at ../sysdeps/unix/syscall-template.S:82
#1  0x00000039bcc418d0 in read () at /usr/include/bits/unistd.h:45
#2  spice_backtrace_gstack () at backtrace.c:100
#3  0x00000039bcc49a00 in spice_logv (log_domain=0x39bccc9406 "Spice", log_level=SPICE_LOG_LEVEL_ERROR, strloc=0x39bccd530d "lz_decompress_tmpl.c:273", function=0x39bccd57a0 "lz_a8_decompress", format=0x39bccc9da7 "assertion `%s' failed", args=0x7f78743e4680) at log.c:108
#4  0x00000039bcc49b3a in spice_log (log_domain=<value optimized out>, log_level=<value optimized out>, strloc=<value optimized out>, function=<value optimized out>, format=<value optimized out>) at log.c:123
#5  0x00000039bcc4a95c in lz_a8_decompress (encoder=0x2ed4f50, out_buf=0x3351c00, size=<value optimized out>) at lz_decompress_tmpl.c:273
#6  0x00000039bcc53d84 in lz_decode (lz=0x2ed4f50, to_type=<value optimized out>, buf=0x3351c00 "") at lz.c:725
#7  0x00000039bcc3af7e in canvas_get_lz (canvas=0x2ec3c60, image=0x2bb17a0, invers=0, want_original=0) at ../spice-common/common/canvas_base.c:821
#8  0x00000039bcc3b46f in canvas_get_image_internal (canvas=0x2ec3c60, image=0x2bb17a0, want_original=0, real_get=1) at ../spice-common/common/canvas_base.c:1093
#9  0x00000039bcc3ce2b in canvas_get_image (spice_canvas=0x2ec3c60, bbox=0x2bb1744, clip=<value optimized out>, copy=0x2bb1768) at ../spice-common/common/canvas_base.c:1268
#10 canvas_draw_copy (spice_canvas=0x2ec3c60, bbox=0x2bb1744, clip=<value optimized out>, copy=0x2bb1768) at ../spice-common/common/canvas_base.c:2198
#11 0x00000039bcc21c25 in display_handle_draw_copy (channel=0x836840 [SpiceDisplayChannel], in=<value optimized out>) at channel-display.c:1367
#12 0x00000039bcc19e54 in spice_channel_recv_msg (channel=0x836840 [SpiceDisplayChannel], msg_handler=0x39bcc1f7c0 <spice_display_handle_msg>, data=0x0) at spice-channel.c:1848
#13 0x00000039bcc1c931 in spice_channel_iterate_read (channel=0x836840 [SpiceDisplayChannel]) at spice-channel.c:2005
#14 0x00000039bcc18e84 in spice_channel_iterate (data=0x836840) at spice-channel.c:2063
#15 spice_channel_coroutine (data=0x836840) at spice-channel.c:2225
#16 0x00000039bcc4091b in coroutine_trampoline (cc=0x8368f8) at coroutine_ucontext.c:56
#17 0x00000039bcc408d3 in continuation_trampoline (i0=<value optimized out>, i1=<value optimized out>) at continuation.c:49
#18 0x000000364ec43b70 in ?? () from /lib64/libc.so.6
#19 0x0000000000836cc0 in ?? ()
#20 0x0000000000000000 in ?? ()
>I'll
> appreciate if you can test again, sorry for the double work!
> 
> Alon
Comment 9 Marian Krcmarik 2012-11-22 04:46:25 EST
*** Bug 879159 has been marked as a duplicate of this bug. ***
Comment 11 Yonit Halperin 2012-11-28 14:19:45 EST
This bug is related to server self-created images that are sent to the client - e.g., surfaces that are sent to the client after it disconnects and reconnects, or images that are resent losslessly to the client when lossy compression is enabled (i.e, in LOW bandwidth conditions).

For rhel6.4 guest I was able to reproduce it easily by opening browser and terminal windows, moving them around, and disconnecting and reconnecting the client.
For Windows guest, it can be reproduced when using 16 bit color depth.

Both scenarios trigger images with stride > width * bpp (where bpp= bytes per pixel): in rhel6.4, due to A8 bitmaps, in Windows, due to 16 bit bitmaps with odd width.

I've posted a fix.
Comment 13 Marian Krcmarik 2012-12-03 03:56:56 EST
*** Bug 880887 has been marked as a duplicate of this bug. ***
Comment 16 errata-xmlrpc 2013-02-21 05:03:48 EST
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2013-0529.html

Note You need to log in before you can comment on or make changes to this bug.