[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

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



Il 21/11/2014 15:43, Fabio Fantoni ha scritto:
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@xxxxxxxxxxxxxxxxxxxxx
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?

Ping for the question above.

I did another test today with xl save -p (or -c), with pause/unpause don't have problem.
Can this help to restrict the problem?

Thanks for any reply and sorry for my bad english.


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@i0cf8/*@1,1/drive@0/disk@0
(d4) DVD/CD [ata0-1: QEMU DVD-ROM ATAPI-4 DVD/CD]
(d4) Searching bootorder for: /pci@i0cf8/*@1,1/drive@0/disk@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@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







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

 


Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.