Re: Bug in x86 instruction emulator?

["William Z." <wogiz@openmailbox.org>]

[-- Attachment #1: Type: text/plain, Size: 2232 bytes --]

On 2016-05-18 11:12, Jan Beulich wrote:
>>>> On 06.04.16 at 01:38, <wogiz@openmailbox.org> wrote:
>> I'm running Xen 4.6.1 with Alpine Linux 3.3.3 in dom0. In a HVM domU
>> with vga="qxl", Xorg will segfault instantly if tried started. 
>> Multiple
>> Linux distros have been tested and Xorg segfaults in all.
>> 
>> Attached are a full backtrace from domU generated by Xorg, and a
>> assembler dump of function 'sse2_blt'.
> 
> Just FYI: Looks like I can repro this finally, and it also looks like 
> at
> least for me it isn't an SSE2 instruction that the issue is with.
> Instead I'm getting an #UD in the middle of an instruction a few
> lines down from the last SSE2 one, which suggests we're having
> an issue with sizing instructions (however odd that may seem).
> Now that I can repro it, at least I have something to actually
> debug ...
> 
> Jan

I have patched Xen 4.6.1 with commit 
2bb230972c5ddb1ca823f47750b5d46a9d302d0e
(x86emul: suppress writeback upon unsuccessful MMX/SSE/AVX insn 
emulation) and
tested with different Linux distros. I can say with confidence that the 
patch
has solved my initial problem as Xorg no longer segfaults when started. 
Thanks
to everyone that has helped with this.

However, while testing I have found a new problem. This may not be 
related to
my initial problem or even Xen, but I will try to describe it here as 
I'm hoping
someone can point me in the right direction.

Various actions will now raise the CPU usage of Xorg to 100% and freeze 
the
entire X Window System for some time. E.g.:

Starting xterm in a window manager or directly from .xinitrc and 
executing
dmesg. This will print a few lines per second while the Xorg CPU usage 
is 100%
and the X Window System is frozen for about 60 seconds until all dmesg 
output
has been printed.

I have run 'perf record -g -a sleep 60' while connected via SSH and then
executed dmesg in xterm. I have attached a few lines of 'perf report -g' 
with
the first one expanded.

I have also run 'strace -p $(pidof Xorg)' while dmesg was running in 
xterm. The
lines I have attached will repeat until all dmesg output has been 
printed. File
descriptor 8 is pointing on '/dev/dri/card0'.

Any ideas on what could cause this?

William Z.

[-- Attachment #2: perf_report.txt --]
[-- Type: text/plain, Size: 1485 bytes --]

Samples: 239K of event 'cpu-clock', Event count (approx.): 59992000000
  Children      Self  Command         Shared Object          Symbol
-   98.63%    98.53%  Xorg            libpixman-1.so.0.33.6  [.] sse2_blt.part.0
   - sse2_blt.part.0
      - 0.10% xen_hvm_callback_vector
           xen_evtchn_do_upcall
           irq_exit
           __do_softirq
           run_timer_softirq
           call_timer_fn
           rh_timer_func
         - usb_hcd_poll_rh_status
            - 0.10% uhci_hub_status_data
                 _raw_spin_unlock_irqrestore
              0.00% mod_timer
      - 0.00% retint_user
           prepare_exit_to_usermode
           exit_to_usermode_loop
           schedule
           __schedule
           finish_task_switch
+    0.57%     0.00%  Xorg            [kernel.kallsyms]      [k] entry_SYSCALL_64_fastpath
+    0.51%     0.00%  Xorg            libc-2.23.so           [.] __GI___ioctl
+    0.51%     0.00%  Xorg            [kernel.kallsyms]      [k] sys_ioctl
+    0.51%     0.00%  swapper         [kernel.kallsyms]      [k] rest_init
+    0.51%     0.00%  swapper         [kernel.kallsyms]      [k] start_kernel
+    0.51%     0.00%  swapper         [kernel.kallsyms]      [k] x86_64_start_reservations
+    0.51%     0.00%  swapper         [kernel.kallsyms]      [k] x86_64_start_kernel
+    0.50%     0.00%  swapper         [kernel.kallsyms]      [k] cpu_startup_entry
+    0.50%     0.00%  Xorg            [kernel.kallsyms]      [k] do_vfs_ioctl

[-- Attachment #3: strace.txt --]
[-- Type: text/plain, Size: 4554 bytes --]

--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965392016
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 13436, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x107931000) = 0x7f5489ddb000
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 48, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x107935000) = 0x7f5489dda000
ioctl(8, DRM_IOCTL_QXL_EXECBUFFER, 0x7ffce28a6830) = 0
munmap(0x7f5489ddb000, 13436)           = 0
ioctl(8, DRM_IOCTL_GEM_CLOSE, 0x7ffce28a6800) = 0
munmap(0x7f5489dda000, 48)              = 0
ioctl(8, DRM_IOCTL_GEM_CLOSE, 0x7ffce28a6860) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
select(512, [1 3 4 5 6 9], NULL, NULL, {0, 0}) = 0 (Timeout)
setitimer(ITIMER_REAL, {it_interval={0, 5000}, it_value={0, 5000}}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {5298, 406984775}) = 0
ioctl(8, DRM_IOCTL_QXL_UPDATE_AREA, 0x7ffce28a6820) = 0
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965411184
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965435536
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 4700, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x107936000) = 0x7f5489ddd000
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 48, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x107938000) = 0x7f5489ddc000
ioctl(8, DRM_IOCTL_QXL_EXECBUFFER, 0x7ffce28a6830) = 0
munmap(0x7f5489ddd000, 4700)            = 0
ioctl(8, DRM_IOCTL_GEM_CLOSE, 0x7ffce28a6800) = 0
munmap(0x7f5489ddc000, 48)              = 0
ioctl(8, DRM_IOCTL_GEM_CLOSE, 0x7ffce28a6860) = 0
clock_gettime(CLOCK_MONOTONIC, {5298, 419896630}) = 0
ioctl(8, DRM_IOCTL_QXL_UPDATE_AREA, 0x7ffce28a6820) = 0
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965399104
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965415424
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965431744
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965444432
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 6260, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x107939000) = 0x7f5489ddd000
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 48, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x10793b000) = 0x7f5489ddc000
ioctl(8, DRM_IOCTL_QXL_EXECBUFFER, 0x7ffce28a6830) = 0
munmap(0x7f5489ddd000, 6260)            = 0
ioctl(8, DRM_IOCTL_GEM_CLOSE, 0x7ffce28a6800) = 0
munmap(0x7f5489ddc000, 48)              = 0
ioctl(8, DRM_IOCTL_GEM_CLOSE, 0x7ffce28a6860) = 0
setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
select(512, [1 3 4 5 6 9], NULL, NULL, {0, 0}) = 0 (Timeout)
setitimer(ITIMER_REAL, {it_interval={0, 5000}, it_value={0, 5000}}, NULL) = 0
clock_gettime(CLOCK_MONOTONIC, {5298, 437495822}) = 0
ioctl(8, DRM_IOCTL_QXL_UPDATE_AREA, 0x7ffce28a6820) = 0
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965400096
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965408032
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965415904
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965420832
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965428768
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965436640
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 140000965444576
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 14060, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x10793d000) = 0x7f5489ddb000
ioctl(8, DRM_IOCTL_QXL_ALLOC, 0x7ffce28a6780) = 0
ioctl(8, DRM_IOCTL_QXL_MAP, 0x7ffce28a6780) = 0
mmap(NULL, 48, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0x107941000) = 0x7f5489dda000
ioctl(8, DRM_IOCTL_QXL_EXECBUFFER, 0x7ffce28a6830) = 0

[-- Attachment #4: Type: text/plain, Size: 126 bytes --]

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
http://lists.xen.org/xen-devel