[Spice-devel] screen freezed for 2-3 minutes on spice connect on xen windows 7 domU's with qxl after save/restore

Fabio Fantoni fabio.fantoni at m2r.biz
Fri Nov 21 06:43:44 PST 2014


Il 21/11/2014 12:05, Fabio Fantoni ha scritto:
> Il 20/11/2014 12:21, Fabio Fantoni ha scritto:
>> Il 13/11/2014 13:22, Fabio Fantoni ha scritto:
>>> Il 13/11/2014 11:14, Fabio Fantoni ha scritto:
>>>> Il 19/09/2014 15:18, Fabio Fantoni ha scritto:
>>>>> Il 12/09/2014 16:46, Fabio Fantoni ha scritto:
>>>>>> Il 08/07/2014 12:34, Fabio Fantoni ha scritto:
>>>>>>> Il 08/07/2014 12:06, Fabio Fantoni ha scritto:
>>>>>>>> Il 08/07/2014 10:53, David Jaša ha scritto:
>>>>>>>>> Hi,
>>>>>>>>>
>>>>>>>>> On Út, 2014-07-08 at 10:13 +0200, Fabio Fantoni wrote:
>>>>>>>>>> On xen 4.5 (tried with qemu 2.0.0/2.1-rc0, spice 0.12.5 and 
>>>>>>>>>> client with
>>>>>>>>>> spice-gtk 0.23/0.25) windows 7 domUs with qxl vga works good 
>>>>>>>>>> as kvm
>>>>>>>>>> except for one problem after xl save/restore, when after 
>>>>>>>>>> restore on
>>>>>>>>>> spice client connect  the domU's screen freezed for 2-3 
>>>>>>>>>> minutes (and
>>>>>>>>>> seems also windows), after this time seems that all return to 
>>>>>>>>>> works
>>>>>>>>>> correctly.
>>>>>>>>>> This problem happen also if spice client connect long time 
>>>>>>>>>> after restore.
>>>>>>>>>> With stdvga not have this problem but stdvga has many missed 
>>>>>>>>>> resolutions
>>>>>>>>>> and bad refresh performance.
>>>>>>>>>>
>>>>>>>>>> If you need more tests/informations tell me and I'll post them.
>>>>>>>>> Client and server logs would certainly help. Please run:
>>>>>>>>>    * virt-viewer with --spice-debug option
>>>>>>>>>    * spice-server with SPICE_DEBUG_LEVEL environment variable set
>>>>>>>>>      to 4 or 5 (if you use qemu+libvirt, use qemu:env element:
>>>>>>>>> http://libvirt.org/drvqemu.html#qemucommand )
>>>>>>>>> and note the location in the logs where the freeze takes place.
>>>>>>>>>
>>>>>>>>> Regards,
>>>>>>>>>
>>>>>>>>> David
>>>>>>>>
>>>>>>>> Thanks for your reply, in attachments:
>>>>>>>> - domU's xl cfg: W7.cfg
>>>>>>>> - xl -vvv create/save/restore: xen logs.txt
>>>>>>>> - remote-viewer with --spice-debug after domU's start until xl 
>>>>>>>> save: spicelog-1.txt (zipped)
>>>>>>>> - remote-viewer with --spice-debug after domU's xl restore: 
>>>>>>>> spicelog-2.txt
>>>>>>>
>>>>>>> Sorry for my forgetfulness, here also qemu's log:
>>>>>>> - after domU's start until xl save: qemu-dm-W7.log.1
>>>>>>> - after domU's xl restore: qemu-dm-W7.log
>>>>>>>
>>>>>>>>
>>>>>>>> If you need more tests/informations tell me and I'll post them.
>>>>>>>>
>>>>>>>>
>>>>>>>>> Thanks for any reply and sorry for my bad english.
>>>>>>>>>
>>>>>>>>> _______________________________________________
>>>>>>>>> Spice-devel mailing list
>>>>>>>>> Spice-devel at lists.freedesktop.org
>>>>>>>>> http://lists.freedesktop.org/mailman/listinfo/spice-devel
>>>>>>>
>>>>>>
>>>>>> The problem persist, this time I saw these in xl dmesg after 
>>>>>> restore:
>>>>>>
>>>>>> (XEN) HVM2 restore: CPU 0
>>>>>> (XEN) HVM2 restore: CPU 1
>>>>>> (XEN) HVM2 restore: PIC 0
>>>>>> (XEN) HVM2 restore: PIC 1
>>>>>> (XEN) HVM2 restore: IOAPIC 0
>>>>>> (XEN) HVM2 restore: LAPIC 0
>>>>>> (XEN) HVM2 restore: LAPIC 1
>>>>>> (XEN) HVM2 restore: LAPIC_REGS 0
>>>>>> (XEN) HVM2 restore: LAPIC_REGS 1
>>>>>> (XEN) HVM2 restore: PCI_IRQ 0
>>>>>> (XEN) HVM2 restore: ISA_IRQ 0
>>>>>> (XEN) HVM2 restore: PCI_LINK 0
>>>>>> (XEN) HVM2 restore: PIT 0
>>>>>> (XEN) HVM2 restore: RTC 0
>>>>>> (XEN) HVM2 restore: HPET 0
>>>>>> (XEN) HVM2 restore: PMTIMER 0
>>>>>> (XEN) HVM2 restore: MTRR 0
>>>>>> (XEN) HVM2 restore: MTRR 1
>>>>>> (XEN) HVM2 restore: VIRIDIAN_DOMAIN 0
>>>>>> (XEN) HVM2 restore: VIRIDIAN_VCPU 0
>>>>>> (XEN) HVM2 restore: VIRIDIAN_VCPU 1
>>>>>> (XEN) HVM2 restore: VMCE_VCPU 0
>>>>>> (XEN) HVM2 restore: VMCE_VCPU 1
>>>>>> (XEN) HVM2 restore: TSC_ADJUST 0
>>>>>> (XEN) HVM2 restore: TSC_ADJUST 1
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77579 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7757a invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7757b invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7757c invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7757d invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7757e invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7757f invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77580 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77581 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77582 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77583 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77584 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77585 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77586 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77587 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77588 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77589 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7758a invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7758b invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7758c invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7758d invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7758e invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 7758f invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77590 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77591 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77592 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77593 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77594 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77595 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77596 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77597 invalid
>>>>>> (XEN) memory.c:216:d2v0 Domain 2 page number 77598 invalid
>>>>>> (XEN) grant_table.c:1272:d2v0 Expanding dom (2) grant table from 
>>>>>> (4) to (32) frames.
>>>>>> (XEN) irq.c:380: Dom2 callback via changed to GSI 24
>>>>>>
>>>>>> Tested on latest staging (commit 
>>>>>> 7d203b337fb2dcd148d2df850e25b67c792d4d0b) plus the spice patches:
>>>>>> https://github.com/Fantu/Xen/commits/rebase/m2r-staging
>>>>>>
>>>>>> If you need more informations or tests tell me and I'll post them.
>>>>>> Thanks for any reply and sorry for my bad english.
>>>>>
>>>>> I did another tests updating to latest git staging (commit 
>>>>> 3e2331d271cc0882e4013c8f20398c46c35f90a1) and is nomore problem of 
>>>>> "only" 2-3 minutes but now when it appears to restart (after 2-3 
>>>>> minutes) windows domUs undefinitely hangs instead.
>>>>> No further details in xen and domU's logs.
>>>>>
>>>>> If you need more tests/details tell me and I'll do them.
>>>>>
>>>>> Thanks for any reply.
>>>>
>>>> I did a new test with xen build based on tag 4.5.0-rc2 and on xl 
>>>> dmesg show these errors:
>>>>> *(XEN) hvm.c:6119:d5v0 Bad HVM op 23.*
>>>> Before and after save/restore, with stdvga instead not show them.
>>>
>>> Sorry, I found that was introduced by new winpv drivers update 
>>> instead and I solved applying this patch:
>>> x86/hvm: Add per-vcpu evtchn upcalls v3 
>>> http://lists.xen.org/archives/html/xen-devel/2014-11/msg00752.html
>>> About save/restore problem with qxl I still not found a solution or 
>>> at least the exact cause :(
>>
>> I tried a strace on qemu process when windows (in domU) is in temp. 
>> freeze and still does many operations (seems similar), I post below a 
>> small part if can be useful.
>> I noted for example some of these lines:
>> read(8, 0x7fffb5d09ac0, 16)             = -1 EAGAIN (Resource 
>> temporarily unavailable)
>> Is it normal?
>>
>> ...
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 4197512}, NULL, 8) = 
>> 2 ([{fd=30, revents=POLLIN}, {fd=8, revents=POLLIN}], left {0, 4193071})
>> read(8, "\2\0\0\0\0\0\0\0", 16)         = 8
>> read(30, "W\0\0\0", 4)                  = 4
>> write(30, "W\0\0\0", 4)                 = 4
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 89449721}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 89526013}) = 0
>> gettimeofday({1416480295, 28658}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 89678802}) = 0
>> gettimeofday({1416480295, 28811}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 0}, NULL, 8) = 1 
>> ([{fd=6, revents=POLLIN}], left {0, 0})
>> *read(8, 0x7fffb5d09ac0, 16)             = -1 EAGAIN (Resource 
>> temporarily unavailable)*
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1000) = 0x7f4a3b435000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x2000) = 0x7f4a3b434000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x3000) = 0x7f4a3b433000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x4000) = 0x7f4a3b432000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x5000) = 0x7f4a3b2db000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x6000) = 0x7f4a3b2da000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x7000) = 0x7f4a3b2d9000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x8000) = 0x7f4a3b2d8000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x9000) = 0x7f4a3b2d7000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xa000) = 0x7f4a3b2d6000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xb000) = 0x7f4a3b2d5000
>> clock_gettime(CLOCK_MONOTONIC, {699, 91880930}) = 0
>> futex(0x7f4a3d396708, FUTEX_WAKE_PRIVATE, 1) = 1
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xc000) = 0x7f4a3b2d4000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xd000) = 0x7f4a3b2d3000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xe000) = 0x7f4a3b2d2000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xf000) = 0x7f4a3b2d1000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x10000) = 0x7f4a3b2d0000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x11000) = 0x7f4a3b2cf000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x12000) = 0x7f4a3b2ce000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x13000) = 0x7f4a3b2cd000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x14000) = 0x7f4a3b2cc000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x15000) = 0x7f4a3b2cb000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x16000) = 0x7f4a3b2ca000
>> clock_gettime(CLOCK_MONOTONIC, {699, 93792961}) = 0
>> futex(0x7f4a3d396708, FUTEX_WAKE_PRIVATE, 1) = 1
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x17000) = 0x7f4a3b2c9000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x18000) = 0x7f4a3b2c8000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x19000) = 0x7f4a3b2c7000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1a000) = 0x7f4a3b2c6000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1b000) = 0x7f4a3b2c5000
>> clock_gettime(CLOCK_MONOTONIC, {699, 94895166}) = 0
>> futex(0x7f4a3d396708, FUTEX_WAKE_PRIVATE, 1) = 1
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1c000) = 0x7f4a3b2c4000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1d000) = 0x7f4a3b2c3000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1e000) = 0x7f4a3b2c2000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1f000) = 0x7f4a3b2c1000
>> clock_gettime(CLOCK_MONOTONIC, {699, 95826884}) = 0
>> futex(0x7f4a3d396708, FUTEX_WAKE_PRIVATE, 1) = 1
>> read(6, "\1\0\0\0\0\0\0\0", 512)        = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 96084347}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 96160414}) = 0
>> gettimeofday({1416480295, 35292}, NULL) = 0
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 96389311}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 96463937}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 96539139}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 96614031}) = 0
>> gettimeofday({1416480295, 35746}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 96766312}) = 0
>> gettimeofday({1416480295, 35898}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 13233688}, NULL, 8) = 
>> 2 ([{fd=20, revents=POLLIN}, {fd=8, revents=POLLIN}], left {0, 13227138})
>> read(20, 
>> "\2\0\0\0\0\0\0\0\0\0x+\313q\231\354\0\35r\336\233\326\10\0E\0\0Mp\302@\0"..., 
>> 69632) = 101
>> clock_gettime(CLOCK_MONOTONIC, {699, 97192856}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 97267978}) = 0
>> gettimeofday({1416480295, 36400}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 97418924}) = 0
>> gettimeofday({1416480295, 36550}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 12581076}, NULL, 8) = 
>> 2 ([{fd=20, revents=POLLIN}, {fd=8, revents=POLLIN}], left {0, 12576281})
>> read(8, "\2\0\0\0\0\0\0\0", 16)         = 8
>> read(20, 
>> "\2\0\0\0\0\0\0\0\0\0x+\313q\231\354\0\35r\336\233\326\10\0E\0\0Mp\303@\0"..., 
>> 69632) = 101
>> clock_gettime(CLOCK_MONOTONIC, {699, 97915644}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 97990808}) = 0
>> gettimeofday({1416480295, 37123}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 98142454}) = 0
>> gettimeofday({1416480295, 37273}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 11857546}, NULL, 8) = 
>> 1 ([{fd=6, revents=POLLIN}], left {0, 9477611})
>> *read(8, 0x7fffb5d09ac0, 16)             = -1 EAGAIN (Resource 
>> temporarily unavailable)*
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> read(6, "\5\0\0\0\0\0\0\0", 512)        = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 101436871}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 101511629}) = 0
>> gettimeofday({1416480295, 40643}, NULL) = 0
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 101739580}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 101814222}) = 0
>> gettimeofday({1416480295, 40946}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 101966019}) = 0
>> gettimeofday({1416480295, 41097}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 0}, NULL, 8) = 1 
>> ([{fd=8, revents=POLLIN}], left {0, 0})
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d4000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d3000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d2000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d1000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d0000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2cf000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2ce000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2cd000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2cc000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2cb000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2ca000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 104926625}) = 0
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c9000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c8000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c7000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c6000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c5000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 106215131}) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b435000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b434000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b433000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b432000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2db000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2da000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d9000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d8000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d7000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d6000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d5000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 108790323}) = 0
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(30, EVIOCGKEYCODE or EVIOCSKEYCODE, 0x7fffb5d098b0) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 109101155}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 109197529}) = 0
>> gettimeofday({1416480295, 48329}, NULL) = 0
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 109425673}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 109500338}) = 0
>> gettimeofday({1416480295, 48632}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 109652242}) = 0
>> gettimeofday({1416480295, 48783}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 0}, NULL, 8) = 2 
>> ([{fd=8, revents=POLLIN}, {fd=6, revents=POLLIN}], left {0, 0})
>> read(8, "\4\0\0\0\0\0\0\0", 16)         = 8
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c4000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c3000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c2000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2c1000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 111044545}) = 0
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(30, EVIOCGKEYCODE or EVIOCSKEYCODE, 0x7fffb5d098b0) = 0
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x1000) = 0x7f4a3b435000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x2000) = 0x7f4a3b434000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x3000) = 0x7f4a3b433000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x4000) = 0x7f4a3b432000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x5000) = 0x7f4a3b2db000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x6000) = 0x7f4a3b2da000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x7000) = 0x7f4a3b2d9000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x8000) = 0x7f4a3b2d8000
>> clock_gettime(CLOCK_MONOTONIC, {699, 112505496}) = 0
>> futex(0x7f4a3d396708, FUTEX_WAKE_PRIVATE, 1) = 1
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> read(6, "\6\0\0\0\0\0\0\0", 512)        = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 112845620}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 112919875}) = 0
>> gettimeofday({1416480295, 52051}, NULL) = 0
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 113146496}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 113220805}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 113295291}) = 0
>> gettimeofday({1416480295, 52426}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 113444996}) = 0
>> gettimeofday({1416480295, 52576}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 0}, NULL, 8) = 1 
>> ([{fd=8, revents=POLLIN}], left {0, 0})
>> read(8, "\2\0\0\0\0\0\0\0", 16)         = 8
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x9000) = 0x7f4a3b2d7000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xa000) = 0x7f4a3b2d6000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xb000) = 0x7f4a3b2d5000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xc000) = 0x7f4a3b2d4000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xd000) = 0x7f4a3b2d3000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xe000) = 0x7f4a3b2d2000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0xf000) = 0x7f4a3b2d1000
>> clock_gettime(CLOCK_MONOTONIC, {699, 115162643}) = 0
>> futex(0x7f4a3d396708, FUTEX_WAKE_PRIVATE, 1) = 1
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x10000) = 0x7f4a3b2d0000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x11000) = 0x7f4a3b2cf000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x12000) = 0x7f4a3b2ce000
>> ioctl(31, GIGASET_REDIR, 0x7fffb5d09700) = 0
>> mmap(NULL, 4096, PROT_WRITE, MAP_SHARED, 31, 0x13000) = 0x7f4a3b2cd000
>> clock_gettime(CLOCK_MONOTONIC, {699, 115964897}) = 0
>> futex(0x7f4a3d396708, FUTEX_WAKE_PRIVATE, 1) = 1
>> clock_gettime(CLOCK_MONOTONIC, {699, 116134364}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 116209521}) = 0
>> gettimeofday({1416480295, 55341}, NULL) = 0
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 116437231}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 116519253}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 116594135}) = 0
>> gettimeofday({1416480295, 55725}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 116744907}) = 0
>> gettimeofday({1416480295, 55876}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 0}, NULL, 8) = 2 
>> ([{fd=8, revents=POLLIN}, {fd=6, revents=POLLIN}], left {0, 0})
>> read(8, "\2\0\0\0\0\0\0\0", 16)         = 8
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b435000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b434000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b433000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b432000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2db000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2da000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d9000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> ioctl(31, GIGASET_BRKCHARS, 0x7fffb5d098a0) = 0
>> munmap(0x7f4a3b2d8000, 4096)            = 0
>> ioctl(31, GIGASET_CONFIG, 0x7fffb5d09890) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 119055248}) = 0
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> write(6, "\1\0\0\0\0\0\0\0", 8)         = 8
>> ioctl(30, EVIOCGKEYCODE or EVIOCSKEYCODE, 0x7fffb5d098b0) = 0
>> read(6, "\6\0\0\0\0\0\0\0", 512)        = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 119599841}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 119676398}) = 0
>> gettimeofday({1416480295, 58810}, NULL) = 0
>> write(8, "\1\0\0\0\0\0\0\0", 8)         = 8
>> clock_gettime(CLOCK_MONOTONIC, {699, 119906131}) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 119981106}) = 0
>> gettimeofday({1416480295, 59114}, NULL) = 0
>> clock_gettime(CLOCK_MONOTONIC, {699, 120133916}) = 0
>> gettimeofday({1416480295, 59265}, NULL) = 0
>> ppoll([{fd=45, events=POLLIN|POLLERR|POLLHUP}, {fd=44, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=42, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=40, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=39, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=38, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=37, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=36, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=30, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=22, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=25, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=20, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=19, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=14, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=5, 
>> events=POLLIN|POLLERR|POLLHUP}, {fd=8, events=POLLIN}, {fd=9, 
>> events=POLLIN}, {fd=6, events=POLLIN}], 18, {0, 0}, NULL, 8) = 2 
>> ([{fd=20, revents=POLLIN}, {fd=8, revents=POLLIN}], left {0, 0})
>> ...
>>
>> Strace of domU's qemu process during freeze can be useful? I must do 
>> a more specific tests?
>> If you need more informations/tests tell me and I'll post them.
>
> xen save/restore seems don't save hvm domUs vga's videoram but 
> kvm/qemu save yes, is it correct?
> can be the cause of problem and/or other problem?

I tried also remote-viewer with --spice-debug and after restore 
connecting with it show initial screen image correct, freeze after with 
line:
     (remote-viewer:3300): GSpice-DEBUG: channel-main.c:1185 main-1:0: 
monitor config: #0 1364x668+0+0 @ 32 bpp
and after some second spice screen become black and show these:
     (remote-viewer:3300): GSpice-DEBUG: channel-cursor.c:480 
cursor-4:0: cursor_handle_reset, init_done: 1
     (remote-viewer:3300): GSpice-DEBUG: channel-display.c:1744 
display-2:0: 0: FIXME primary destroy, but is display really disabled?

this can be related to the "freeze" or is only a conseguence?

>
>>
>> Thanks for any reply and sorry for my bad english.
>>
>>
>>>
>>>>
>>>> Below I posted full xl dmesg of domU, if you need more 
>>>> informations/tests tell me and I'll post them.
>>>>
>>>>
>>>>> (d4) HVM Loader
>>>>> (d4) Detected Xen v4.5.0-rc
>>>>> (d4) Xenbus rings @0xfeffc000, event channel 1
>>>>> (d4) System requested SeaBIOS
>>>>> (d4) CPU speed is 2660 MHz
>>>>> (d4) Relocating guest memory for lowmem MMIO space disabled
>>>>> (XEN) irq.c:270: Dom4 PCI link 0 changed 0 -> 5
>>>>> (d4) PCI-ISA link 0 routed to IRQ5
>>>>> (XEN) irq.c:270: Dom4 PCI link 1 changed 0 -> 10
>>>>> (d4) PCI-ISA link 1 routed to IRQ10
>>>>> (XEN) irq.c:270: Dom4 PCI link 2 changed 0 -> 11
>>>>> (d4) PCI-ISA link 2 routed to IRQ11
>>>>> (XEN) irq.c:270: Dom4 PCI link 3 changed 0 -> 5
>>>>> (d4) PCI-ISA link 3 routed to IRQ5
>>>>> (d4) pci dev 01:3 INTA->IRQ10
>>>>> (d4) pci dev 02:0 INTA->IRQ11
>>>>> (d4) pci dev 03:0 INTA->IRQ5
>>>>> (d4) pci dev 04:0 INTA->IRQ5
>>>>> (d4) pci dev 05:0 INTA->IRQ10
>>>>> (d4) pci dev 06:0 INTA->IRQ11
>>>>> (d4) pci dev 1d:0 INTA->IRQ10
>>>>> (d4) pci dev 1d:1 INTB->IRQ11
>>>>> (d4) pci dev 1d:2 INTC->IRQ5
>>>>> (d4) pci dev 1d:7 INTD->IRQ5
>>>>> (d4) No RAM in high memory; setting high_mem resource base to 
>>>>> 100000000
>>>>> (d4) pci dev 05:0 bar 10 size 004000000: 0f0000000
>>>>> (d4) pci dev 05:0 bar 14 size 004000000: 0f4000000
>>>>> (d4) pci dev 02:0 bar 14 size 001000000: 0f8000008
>>>>> (d4) pci dev 06:0 bar 30 size 000040000: 0f9000000
>>>>> (d4) pci dev 05:0 bar 30 size 000010000: 0f9040000
>>>>> (d4) pci dev 03:0 bar 10 size 000004000: 0f9050000
>>>>> (d4) pci dev 05:0 bar 18 size 000002000: 0f9054000
>>>>> (d4) pci dev 04:0 bar 14 size 000001000: 0f9056000
>>>>> (d4) pci dev 1d:7 bar 10 size 000001000: 0f9057000
>>>>> (d4) pci dev 02:0 bar 10 size 000000100: 00000c001
>>>>> (d4) pci dev 06:0 bar 10 size 000000100: 00000c101
>>>>> (d4) pci dev 06:0 bar 14 size 000000100: 0f9058000
>>>>> (d4) pci dev 04:0 bar 10 size 000000020: 00000c201
>>>>> (d4) pci dev 05:0 bar 1c size 000000020: 00000c221
>>>>> (d4) pci dev 1d:0 bar 20 size 000000020: 00000c241
>>>>> (d4) pci dev 1d:1 bar 20 size 000000020: 00000c261
>>>>> (d4) pci dev 1d:2 bar 20 size 000000020: 00000c281
>>>>> (d4) pci dev 01:1 bar 20 size 000000010: 00000c2a1
>>>>> (d4) Multiprocessor initialisation:
>>>>> (d4)  - CPU0 ... 36-bit phys ... fixed MTRRs ... var MTRRs [1/8] 
>>>>> ... done.
>>>>> (d4)  - CPU1 ... 36-bit phys ... fixed MTRRs ... var MTRRs [1/8] 
>>>>> ... done.
>>>>> (d4) Testing HVM environment:
>>>>> (d4)  - REP INSB across page boundaries ... passed
>>>>> (d4)  - GS base MSRs and SWAPGS ... passed
>>>>> (d4) Passed 2 of 2 tests
>>>>> (d4) Writing SMBIOS tables ...
>>>>> (d4) Loading SeaBIOS ...
>>>>> (d4) Creating MP tables ...
>>>>> (d4) Loading ACPI ...
>>>>> (d4) S3 disabled
>>>>> (d4) S4 disabled
>>>>> (d4) vm86 TSS at fc00a100
>>>>> (d4) BIOS map:
>>>>> (d4)  10000-100d3: Scratch space
>>>>> (d4)  c0000-fffff: Main BIOS
>>>>> (d4) E820 table:
>>>>> (d4)  [00]: 00000000:00000000 - 00000000:000a0000: RAM
>>>>> (d4)  HOLE: 00000000:000a0000 - 00000000:000c0000
>>>>> (d4)  [01]: 00000000:000c0000 - 00000000:00100000: RESERVED
>>>>> (d4)  [02]: 00000000:00100000 - 00000000:78000000: RAM
>>>>> (d4)  HOLE: 00000000:78000000 - 00000000:fc000000
>>>>> (d4)  [03]: 00000000:fc000000 - 00000001:00000000: RESERVED
>>>>> (d4) Invoking SeaBIOS ...
>>>>> (d4) SeaBIOS (version 
>>>>> debian/1.7.5-1-0-g506b58d-20140603_102943-testVS01OU)
>>>>> (d4)
>>>>> (d4) Found Xen hypervisor signature at 40000100
>>>>> (d4) Running on QEMU (i440fx)
>>>>> (d4) xen: copy e820...
>>>>> (d4) Relocating init from 0x000df619 to 0x77fae600 (size 71995)
>>>>> (d4) CPU Mhz=2661
>>>>> (d4) Found 13 PCI devices (max PCI bus is 00)
>>>>> (d4) Allocated Xen hypercall page at 77fff000
>>>>> (d4) Detected Xen v4.5.0-rc
>>>>> (d4) xen: copy BIOS tables...
>>>>> (d4) Copying SMBIOS entry point from 0x00010010 to 0x000f0f40
>>>>> (d4) Copying MPTABLE from 0xfc001160/fc001170 to 0x000f0e40
>>>>> (d4) Copying PIR from 0x00010030 to 0x000f0dc0
>>>>> (d4) Copying ACPI RSDP from 0x000100b0 to 0x000f0d90
>>>>> (d4) Using pmtimer, ioport 0xb008
>>>>> (d4) Scan for VGA option rom
>>>>> (d4) Running option rom at c000:0003
>>>>> (XEN) stdvga.c:147:d4v0 entering stdvga and caching modes
>>>>> (d4) pmm call arg1=0
>>>>> (d4) Turning on vga text mode console
>>>>> (d4) SeaBIOS (version 
>>>>> debian/1.7.5-1-0-g506b58d-20140603_102943-testVS01OU)
>>>>> (d4) Machine UUID 9d836955-983f-4413-89c3-6893ea19d838
>>>>> (d4) EHCI init on dev 00:1d.7 (regs=0xf9057020)
>>>>> (d4) Found 0 lpt ports
>>>>> (d4) Found 0 serial ports
>>>>> (d4) ATA controller 1 at 1f0/3f4/0 (irq 14 dev 9)
>>>>> (d4) ATA controller 2 at 170/374/0 (irq 15 dev 9)
>>>>> (d4) ata0-0: QEMU HARDDISK ATA-7 Hard-Disk (50000 MiBytes)
>>>>> (d4) Searching bootorder for: /pci at i0cf8/*@1,1/drive at 0/disk at 0
>>>>> (d4) DVD/CD [ata0-1: QEMU DVD-ROM ATAPI-4 DVD/CD]
>>>>> (d4) Searching bootorder for: /pci at i0cf8/*@1,1/drive at 0/disk at 1
>>>>> (d4) UHCI init on dev 00:1d.0 (io=c240)
>>>>> (d4) UHCI init on dev 00:1d.1 (io=c260)
>>>>> (d4) UHCI init on dev 00:1d.2 (io=c280)
>>>>> (d4) PS2 keyboard initialized
>>>>> (d4) All threads complete.
>>>>> (d4) Scan for option roms
>>>>> (d4) Running option rom at c980:0003
>>>>> (d4) pmm call arg1=1
>>>>> (d4) pmm call arg1=0
>>>>> (d4) pmm call arg1=1
>>>>> (d4) pmm call arg1=0
>>>>> (d4) Searching bootorder for: /pci at i0cf8/*@6
>>>>> (d4)
>>>>> (d4) Press F12 for boot menu.
>>>>> (d4)
>>>>> (d4) Searching bootorder for: HALT
>>>>> (d4) drive 0x000f0d40: PCHS=16383/16/63 translation=lba 
>>>>> LCHS=1024/255/63 s=102400000
>>>>> (d4)
>>>>> (d4) Space available for UMB: ca800-ee800, f0000-f0ce0
>>>>> (d4) Returned 258048 bytes of ZoneHigh
>>>>> (d4) e820 map has 6 items:
>>>>> (d4)   0: 0000000000000000 - 000000000009fc00 = 1 RAM
>>>>> (d4)   1: 000000000009fc00 - 00000000000a0000 = 2 RESERVED
>>>>> (d4)   2: 00000000000f0000 - 0000000000100000 = 2 RESERVED
>>>>> (d4)   3: 0000000000100000 - 0000000077fff000 = 1 RAM
>>>>> (d4)   4: 0000000077fff000 - 0000000078000000 = 2 RESERVED
>>>>> (d4)   5: 00000000fc000000 - 0000000100000000 = 2 RESERVED
>>>>> (d4) enter handle_19:
>>>>> (d4)   NULL
>>>>> (d4) Booting from DVD/CD...
>>>>> (d4) Device reports MEDIUM NOT PRESENT
>>>>> (d4) scsi_is_ready returned -1
>>>>> (d4) Boot failed: Could not read from CDROM (code 0003)
>>>>> (d4) enter handle_18:
>>>>> (d4)   NULL
>>>>> (d4) Booting from Hard Disk...
>>>>> (d4) Booting from 0000:7c00
>>>>> (XEN) d4: VIRIDIAN GUEST_OS_ID: vendor: 1 os: 4 major: 6 minor: 1 
>>>>> sp: 1 build: 1db1
>>>>> (XEN) d4: VIRIDIAN HYPERCALL: enabled: 1 pfn: 3ffff
>>>>> (XEN) d4v0: VIRIDIAN APIC_ASSIST: enabled: 1 pfn: 3fffe
>>>>> (XEN) d4v1: VIRIDIAN APIC_ASSIST: enabled: 1 pfn: 3fffd
>>>>> (XEN) irq.c:270: Dom4 PCI link 0 changed 5 -> 0
>>>>> (XEN) irq.c:270: Dom4 PCI link 1 changed 10 -> 0
>>>>> (XEN) irq.c:270: Dom4 PCI link 2 changed 11 -> 0
>>>>> (XEN) irq.c:270: Dom4 PCI link 3 changed 5 -> 0
>>>>> *(XEN) hvm.c:6119:d4v1 Bad HVM op 23.**
>>>>> **(XEN) hvm.c:6119:d4v1 Bad HVM op 23.*
>>>>> (XEN) irq.c:380: Dom4 callback via changed to GSI 24
>>>>> (XEN) HVM4 save: CPU
>>>>> (XEN) HVM4 save: PIC
>>>>> (XEN) HVM4 save: IOAPIC
>>>>> (XEN) HVM4 save: LAPIC
>>>>> (XEN) HVM4 save: LAPIC_REGS
>>>>> (XEN) HVM4 save: PCI_IRQ
>>>>> (XEN) HVM4 save: ISA_IRQ
>>>>> (XEN) HVM4 save: PCI_LINK
>>>>> (XEN) HVM4 save: PIT
>>>>> (XEN) HVM4 save: RTC
>>>>> (XEN) HVM4 save: HPET
>>>>> (XEN) HVM4 save: PMTIMER
>>>>> (XEN) HVM4 save: MTRR
>>>>> (XEN) HVM4 save: VIRIDIAN_DOMAIN
>>>>> (XEN) HVM4 save: CPU_XSAVE
>>>>> (XEN) HVM4 save: VIRIDIAN_VCPU
>>>>> (XEN) HVM4 save: VMCE_VCPU
>>>>> (XEN) HVM4 save: TSC_ADJUST
>>>>> (XEN) HVM5 restore: CPU 0
>>>>> (XEN) HVM5 restore: CPU 1
>>>>> (XEN) HVM5 restore: PIC 0
>>>>> (XEN) HVM5 restore: PIC 1
>>>>> (XEN) HVM5 restore: IOAPIC 0
>>>>> (XEN) HVM5 restore: LAPIC 0
>>>>> (XEN) HVM5 restore: LAPIC 1
>>>>> (XEN) HVM5 restore: LAPIC_REGS 0
>>>>> (XEN) HVM5 restore: LAPIC_REGS 1
>>>>> (XEN) HVM5 restore: PCI_IRQ 0
>>>>> (XEN) HVM5 restore: ISA_IRQ 0
>>>>> (XEN) HVM5 restore: PCI_LINK 0
>>>>> (XEN) HVM5 restore: PIT 0
>>>>> (XEN) HVM5 restore: RTC 0
>>>>> (XEN) HVM5 restore: HPET 0
>>>>> (XEN) HVM5 restore: PMTIMER 0
>>>>> (XEN) HVM5 restore: MTRR 0
>>>>> (XEN) HVM5 restore: MTRR 1
>>>>> (XEN) HVM5 restore: VIRIDIAN_DOMAIN 0
>>>>> (XEN) HVM5 restore: VIRIDIAN_VCPU 0
>>>>> (XEN) HVM5 restore: VIRIDIAN_VCPU 1
>>>>> (XEN) HVM5 restore: VMCE_VCPU 0
>>>>> (XEN) HVM5 restore: VMCE_VCPU 1
>>>>> (XEN) HVM5 restore: TSC_ADJUST 0
>>>>> (XEN) HVM5 restore: TSC_ADJUST 1
>>>>> (XEN) irq.c:380: Dom5 callback via changed to None
>>>>> *(XEN) hvm.c:6119:d5v0 Bad HVM op 23.**
>>>>> **(XEN) hvm.c:6119:d5v0 Bad HVM op 23.**
>>>>> **(XEN) hvm.c:6119:d5v0 Bad HVM op 23.**
>>>>> **(XEN) hvm.c:6119:d5v0 Bad HVM op 23.*
>>>>> (XEN) irq.c:380: Dom5 callback via changed to GSI 24
>>>>
>>>>
>>>
>>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/spice-devel/attachments/20141121/a30467d6/attachment-0001.html>


More information about the Spice-devel mailing list