* Re: [Qemu-devel] [BUG] I/O thread segfault for QEMU on s390x [not found] ` <c4c4c483-d7aa-7361-774e-254c5517468b@de.ibm.com> @ 2018-03-05 19:08 ` Christian Borntraeger 2018-03-05 19:43 ` Farhan Ali 2018-03-06 6:34 ` Martin Schwidefsky 0 siblings, 2 replies; 4+ messages in thread From: Christian Borntraeger @ 2018-03-05 19:08 UTC (permalink / raw) To: Farhan Ali, Stefan Hajnoczi Cc: Cornelia Huck, Thomas Huth, Paolo Bonzini, mreitz, famz, QEMU Developers, qemu-s390x, Martin Schwidefsky, Heiko Carstens, linux-s390, Hendrik Brueckner Do you happen to run with a recent host kernel that has commit 7041d28115e91f2144f811ffe8a195c696b1e1d0 s390: scrub registers on kernel entry and KVM exit Can you run with this on top diff --git a/arch/s390/kernel/entry.S b/arch/s390/kernel/entry.S index 13a133a6015c..d6dc0e5e8f74 100644 --- a/arch/s390/kernel/entry.S +++ b/arch/s390/kernel/entry.S @@ -426,13 +426,13 @@ ENTRY(system_call) UPDATE_VTIME %r8,%r9,__LC_SYNC_ENTER_TIMER BPENTER __TI_flags(%r12),_TIF_ISOLATE_BP stmg %r0,%r7,__PT_R0(%r11) - # clear user controlled register to prevent speculative use - xgr %r0,%r0 mvc __PT_R8(64,%r11),__LC_SAVE_AREA_SYNC mvc __PT_PSW(16,%r11),__LC_SVC_OLD_PSW mvc __PT_INT_CODE(4,%r11),__LC_SVC_ILC stg %r14,__PT_FLAGS(%r11) .Lsysc_do_svc: + # clear user controlled register to prevent speculative use + xgr %r0,%r0 # load address of system call table lg %r10,__THREAD_sysc_table(%r13,%r12) llgh %r8,__PT_INT_CODE+2(%r11) To me it looks like that the critical section cleanup (interrupt during system call entry) might save the registers again into ptregs but we have already zeroed out r0. This patch moves the clearing of r0 after sysc_do_svc, which should fix the critical section cleanup. Adding Martin and Heiko. Will spin a patch. On 03/05/2018 07:54 PM, Christian Borntraeger wrote: > > > On 03/05/2018 07:45 PM, Farhan Ali wrote: >> >> >> On 03/05/2018 06:03 AM, Stefan Hajnoczi wrote: >>> Please include the following gdb output: >>> >>> (gdb) disas swapcontext >>> (gdb) i r >>> >>> That way it's possible to see which instruction faulted and which >>> registers were being accessed. >> >> >> here is the disas out for swapcontext, this is on a coredump with debugging symbols enabled for qemu. So the addresses from the previous dump is a little different. >> >> >> (gdb) disas swapcontext >> Dump of assembler code for function swapcontext: >> 0x000003ff90751fb8 <+0>: lgr %r1,%r2 >> 0x000003ff90751fbc <+4>: lgr %r0,%r3 >> 0x000003ff90751fc0 <+8>: stfpc 248(%r1) >> 0x000003ff90751fc4 <+12>: std %f0,256(%r1) >> 0x000003ff90751fc8 <+16>: std %f1,264(%r1) >> 0x000003ff90751fcc <+20>: std %f2,272(%r1) >> 0x000003ff90751fd0 <+24>: std %f3,280(%r1) >> 0x000003ff90751fd4 <+28>: std %f4,288(%r1) >> 0x000003ff90751fd8 <+32>: std %f5,296(%r1) >> 0x000003ff90751fdc <+36>: std %f6,304(%r1) >> 0x000003ff90751fe0 <+40>: std %f7,312(%r1) >> 0x000003ff90751fe4 <+44>: std %f8,320(%r1) >> 0x000003ff90751fe8 <+48>: std %f9,328(%r1) >> 0x000003ff90751fec <+52>: std %f10,336(%r1) >> 0x000003ff90751ff0 <+56>: std %f11,344(%r1) >> 0x000003ff90751ff4 <+60>: std %f12,352(%r1) >> 0x000003ff90751ff8 <+64>: std %f13,360(%r1) >> 0x000003ff90751ffc <+68>: std %f14,368(%r1) >> 0x000003ff90752000 <+72>: std %f15,376(%r1) >> 0x000003ff90752004 <+76>: slgr %r2,%r2 >> 0x000003ff90752008 <+80>: stam %a0,%a15,184(%r1) >> 0x000003ff9075200c <+84>: stmg %r0,%r15,56(%r1) >> 0x000003ff90752012 <+90>: la %r2,2 >> 0x000003ff90752016 <+94>: lgr %r5,%r0 >> 0x000003ff9075201a <+98>: la %r3,384(%r5) >> 0x000003ff9075201e <+102>: la %r4,384(%r1) >> 0x000003ff90752022 <+106>: lghi %r5,8 >> 0x000003ff90752026 <+110>: svc 175 > > sys_rt_sigprocmask. r0 should not be changed by the system call. > >> 0x000003ff90752028 <+112>: lgr %r5,%r0 >> => 0x000003ff9075202c <+116>: lfpc 248(%r5) > > so r5 is zero and it was loaded from r0. r0 was loaded from r3 (which is the 2nd parameter to this > function). Now this is odd. > >> 0x000003ff90752030 <+120>: ld %f0,256(%r5) >> 0x000003ff90752034 <+124>: ld %f1,264(%r5) >> 0x000003ff90752038 <+128>: ld %f2,272(%r5) >> 0x000003ff9075203c <+132>: ld %f3,280(%r5) >> 0x000003ff90752040 <+136>: ld %f4,288(%r5) >> 0x000003ff90752044 <+140>: ld %f5,296(%r5) >> 0x000003ff90752048 <+144>: ld %f6,304(%r5) >> 0x000003ff9075204c <+148>: ld %f7,312(%r5) >> 0x000003ff90752050 <+152>: ld %f8,320(%r5) >> 0x000003ff90752054 <+156>: ld %f9,328(%r5) >> 0x000003ff90752058 <+160>: ld %f10,336(%r5) >> 0x000003ff9075205c <+164>: ld %f11,344(%r5) >> 0x000003ff90752060 <+168>: ld %f12,352(%r5) >> 0x000003ff90752064 <+172>: ld %f13,360(%r5) >> 0x000003ff90752068 <+176>: ld %f14,368(%r5) >> 0x000003ff9075206c <+180>: ld %f15,376(%r5) >> 0x000003ff90752070 <+184>: lam %a2,%a15,192(%r5) >> 0x000003ff90752074 <+188>: lmg %r0,%r15,56(%r5) >> 0x000003ff9075207a <+194>: br %r14 >> End of assembler dump. >> >> (gdb) i r >> r0 0x0 0 >> r1 0x3ff8fe7de40 4396165881408 >> r2 0x0 0 >> r3 0x3ff8fe7e1c0 4396165882304 >> r4 0x3ff8fe7dfc0 4396165881792 >> r5 0x0 0 >> r6 0xffffffff88004880 18446744071696304256 >> r7 0x3ff880009e0 4396033247712 >> r8 0x27ff89000 10736930816 >> r9 0x3ff88001460 4396033250400 >> r10 0x1000 4096 >> r11 0x1261be0 19274720 >> r12 0x3ff88001e00 4396033252864 >> r13 0x14d0bc0 21826496 >> r14 0x1312ac8 19999432 >> r15 0x3ff8fe7dc80 4396165880960 >> pc 0x3ff9075202c 0x3ff9075202c <swapcontext+116> >> cc 0x2 2 ^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [Qemu-devel] [BUG] I/O thread segfault for QEMU on s390x 2018-03-05 19:08 ` [Qemu-devel] [BUG] I/O thread segfault for QEMU on s390x Christian Borntraeger @ 2018-03-05 19:43 ` Farhan Ali 2018-03-06 6:34 ` Martin Schwidefsky 1 sibling, 0 replies; 4+ messages in thread From: Farhan Ali @ 2018-03-05 19:43 UTC (permalink / raw) To: Christian Borntraeger, Stefan Hajnoczi Cc: Cornelia Huck, Thomas Huth, Paolo Bonzini, mreitz, famz, QEMU Developers, qemu-s390x, Martin Schwidefsky, Heiko Carstens, linux-s390, Hendrik Brueckner On 03/05/2018 02:08 PM, Christian Borntraeger wrote: > Do you happen to run with a recent host kernel that has > > commit 7041d28115e91f2144f811ffe8a195c696b1e1d0 > s390: scrub registers on kernel entry and KVM exit > > > Yes. > > > Can you run with this on top > diff --git a/arch/s390/kernel/entry.S b/arch/s390/kernel/entry.S > index 13a133a6015c..d6dc0e5e8f74 100644 > --- a/arch/s390/kernel/entry.S > +++ b/arch/s390/kernel/entry.S > @@ -426,13 +426,13 @@ ENTRY(system_call) > UPDATE_VTIME %r8,%r9,__LC_SYNC_ENTER_TIMER > BPENTER __TI_flags(%r12),_TIF_ISOLATE_BP > stmg %r0,%r7,__PT_R0(%r11) > - # clear user controlled register to prevent speculative use > - xgr %r0,%r0 > mvc __PT_R8(64,%r11),__LC_SAVE_AREA_SYNC > mvc __PT_PSW(16,%r11),__LC_SVC_OLD_PSW > mvc __PT_INT_CODE(4,%r11),__LC_SVC_ILC > stg %r14,__PT_FLAGS(%r11) > .Lsysc_do_svc: > + # clear user controlled register to prevent speculative use > + xgr %r0,%r0 > # load address of system call table > lg %r10,__THREAD_sysc_table(%r13,%r12) > llgh %r8,__PT_INT_CODE+2(%r11) > > > To me it looks like that the critical section cleanup (interrupt during system call entry) might > save the registers again into ptregs but we have already zeroed out r0. > This patch moves the clearing of r0 after sysc_do_svc, which should fix the critical > section cleanup. > Okay I will run with this. > Adding Martin and Heiko. Will spin a patch. > > > On 03/05/2018 07:54 PM, Christian Borntraeger wrote: >> >> >> On 03/05/2018 07:45 PM, Farhan Ali wrote: >>> >>> >>> On 03/05/2018 06:03 AM, Stefan Hajnoczi wrote: >>>> Please include the following gdb output: >>>> >>>> (gdb) disas swapcontext >>>> (gdb) i r >>>> >>>> That way it's possible to see which instruction faulted and which >>>> registers were being accessed. >>> >>> >>> here is the disas out for swapcontext, this is on a coredump with debugging symbols enabled for qemu. So the addresses from the previous dump is a little different. >>> >>> >>> (gdb) disas swapcontext >>> Dump of assembler code for function swapcontext: >>> 0x000003ff90751fb8 <+0>: lgr %r1,%r2 >>> 0x000003ff90751fbc <+4>: lgr %r0,%r3 >>> 0x000003ff90751fc0 <+8>: stfpc 248(%r1) >>> 0x000003ff90751fc4 <+12>: std %f0,256(%r1) >>> 0x000003ff90751fc8 <+16>: std %f1,264(%r1) >>> 0x000003ff90751fcc <+20>: std %f2,272(%r1) >>> 0x000003ff90751fd0 <+24>: std %f3,280(%r1) >>> 0x000003ff90751fd4 <+28>: std %f4,288(%r1) >>> 0x000003ff90751fd8 <+32>: std %f5,296(%r1) >>> 0x000003ff90751fdc <+36>: std %f6,304(%r1) >>> 0x000003ff90751fe0 <+40>: std %f7,312(%r1) >>> 0x000003ff90751fe4 <+44>: std %f8,320(%r1) >>> 0x000003ff90751fe8 <+48>: std %f9,328(%r1) >>> 0x000003ff90751fec <+52>: std %f10,336(%r1) >>> 0x000003ff90751ff0 <+56>: std %f11,344(%r1) >>> 0x000003ff90751ff4 <+60>: std %f12,352(%r1) >>> 0x000003ff90751ff8 <+64>: std %f13,360(%r1) >>> 0x000003ff90751ffc <+68>: std %f14,368(%r1) >>> 0x000003ff90752000 <+72>: std %f15,376(%r1) >>> 0x000003ff90752004 <+76>: slgr %r2,%r2 >>> 0x000003ff90752008 <+80>: stam %a0,%a15,184(%r1) >>> 0x000003ff9075200c <+84>: stmg %r0,%r15,56(%r1) >>> 0x000003ff90752012 <+90>: la %r2,2 >>> 0x000003ff90752016 <+94>: lgr %r5,%r0 >>> 0x000003ff9075201a <+98>: la %r3,384(%r5) >>> 0x000003ff9075201e <+102>: la %r4,384(%r1) >>> 0x000003ff90752022 <+106>: lghi %r5,8 >>> 0x000003ff90752026 <+110>: svc 175 >> >> sys_rt_sigprocmask. r0 should not be changed by the system call. >> >>> 0x000003ff90752028 <+112>: lgr %r5,%r0 >>> => 0x000003ff9075202c <+116>: lfpc 248(%r5) >> >> so r5 is zero and it was loaded from r0. r0 was loaded from r3 (which is the 2nd parameter to this >> function). Now this is odd. >> >>> 0x000003ff90752030 <+120>: ld %f0,256(%r5) >>> 0x000003ff90752034 <+124>: ld %f1,264(%r5) >>> 0x000003ff90752038 <+128>: ld %f2,272(%r5) >>> 0x000003ff9075203c <+132>: ld %f3,280(%r5) >>> 0x000003ff90752040 <+136>: ld %f4,288(%r5) >>> 0x000003ff90752044 <+140>: ld %f5,296(%r5) >>> 0x000003ff90752048 <+144>: ld %f6,304(%r5) >>> 0x000003ff9075204c <+148>: ld %f7,312(%r5) >>> 0x000003ff90752050 <+152>: ld %f8,320(%r5) >>> 0x000003ff90752054 <+156>: ld %f9,328(%r5) >>> 0x000003ff90752058 <+160>: ld %f10,336(%r5) >>> 0x000003ff9075205c <+164>: ld %f11,344(%r5) >>> 0x000003ff90752060 <+168>: ld %f12,352(%r5) >>> 0x000003ff90752064 <+172>: ld %f13,360(%r5) >>> 0x000003ff90752068 <+176>: ld %f14,368(%r5) >>> 0x000003ff9075206c <+180>: ld %f15,376(%r5) >>> 0x000003ff90752070 <+184>: lam %a2,%a15,192(%r5) >>> 0x000003ff90752074 <+188>: lmg %r0,%r15,56(%r5) >>> 0x000003ff9075207a <+194>: br %r14 >>> End of assembler dump. >>> >>> (gdb) i r >>> r0 0x0 0 >>> r1 0x3ff8fe7de40 4396165881408 >>> r2 0x0 0 >>> r3 0x3ff8fe7e1c0 4396165882304 >>> r4 0x3ff8fe7dfc0 4396165881792 >>> r5 0x0 0 >>> r6 0xffffffff88004880 18446744071696304256 >>> r7 0x3ff880009e0 4396033247712 >>> r8 0x27ff89000 10736930816 >>> r9 0x3ff88001460 4396033250400 >>> r10 0x1000 4096 >>> r11 0x1261be0 19274720 >>> r12 0x3ff88001e00 4396033252864 >>> r13 0x14d0bc0 21826496 >>> r14 0x1312ac8 19999432 >>> r15 0x3ff8fe7dc80 4396165880960 >>> pc 0x3ff9075202c 0x3ff9075202c <swapcontext+116> >>> cc 0x2 2 ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [Qemu-devel] [BUG] I/O thread segfault for QEMU on s390x 2018-03-05 19:08 ` [Qemu-devel] [BUG] I/O thread segfault for QEMU on s390x Christian Borntraeger 2018-03-05 19:43 ` Farhan Ali @ 2018-03-06 6:34 ` Martin Schwidefsky 2018-03-07 12:52 ` Farhan Ali 1 sibling, 1 reply; 4+ messages in thread From: Martin Schwidefsky @ 2018-03-06 6:34 UTC (permalink / raw) To: Christian Borntraeger Cc: Farhan Ali, Stefan Hajnoczi, Cornelia Huck, Thomas Huth, Paolo Bonzini, mreitz, famz, QEMU Developers, qemu-s390x, Heiko Carstens, linux-s390, Hendrik Brueckner On Mon, 5 Mar 2018 20:08:45 +0100 Christian Borntraeger <borntraeger@de.ibm.com> wrote: > Do you happen to run with a recent host kernel that has > > commit 7041d28115e91f2144f811ffe8a195c696b1e1d0 > s390: scrub registers on kernel entry and KVM exit > > Can you run with this on top > diff --git a/arch/s390/kernel/entry.S b/arch/s390/kernel/entry.S > index 13a133a6015c..d6dc0e5e8f74 100644 > --- a/arch/s390/kernel/entry.S > +++ b/arch/s390/kernel/entry.S > @@ -426,13 +426,13 @@ ENTRY(system_call) > UPDATE_VTIME %r8,%r9,__LC_SYNC_ENTER_TIMER > BPENTER __TI_flags(%r12),_TIF_ISOLATE_BP > stmg %r0,%r7,__PT_R0(%r11) > - # clear user controlled register to prevent speculative use > - xgr %r0,%r0 > mvc __PT_R8(64,%r11),__LC_SAVE_AREA_SYNC > mvc __PT_PSW(16,%r11),__LC_SVC_OLD_PSW > mvc __PT_INT_CODE(4,%r11),__LC_SVC_ILC > stg %r14,__PT_FLAGS(%r11) > .Lsysc_do_svc: > + # clear user controlled register to prevent speculative use > + xgr %r0,%r0 > # load address of system call table > lg %r10,__THREAD_sysc_table(%r13,%r12) > llgh %r8,__PT_INT_CODE+2(%r11) > > > To me it looks like that the critical section cleanup (interrupt during system call entry) might > save the registers again into ptregs but we have already zeroed out r0. > This patch moves the clearing of r0 after sysc_do_svc, which should fix the critical > section cleanup. > > Adding Martin and Heiko. Will spin a patch. Argh, yes. Thanks Chrisitan, this is it. I have been searching for the bug for days now. The point is that if the system call handler is interrupted after the xgr but before .Lsysc_do_svc the code at .Lcleanup_system_call repeats the stmg for %r0-%r7 but now %r0 is already zero. Please commit a patch for this and I'll will queue it up immediately. -- blue skies, Martin. "Reality continues to ruin my life." - Calvin. ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [Qemu-devel] [BUG] I/O thread segfault for QEMU on s390x 2018-03-06 6:34 ` Martin Schwidefsky @ 2018-03-07 12:52 ` Farhan Ali 0 siblings, 0 replies; 4+ messages in thread From: Farhan Ali @ 2018-03-07 12:52 UTC (permalink / raw) To: Martin Schwidefsky, Christian Borntraeger Cc: linux-s390, Thomas Huth, Cornelia Huck, famz, Heiko Carstens, QEMU Developers, mreitz, qemu-s390x, Hendrik Brueckner, Stefan Hajnoczi, Paolo Bonzini On 03/06/2018 01:34 AM, Martin Schwidefsky wrote: > On Mon, 5 Mar 2018 20:08:45 +0100 > Christian Borntraeger <borntraeger@de.ibm.com> wrote: > >> Do you happen to run with a recent host kernel that has >> >> commit 7041d28115e91f2144f811ffe8a195c696b1e1d0 >> s390: scrub registers on kernel entry and KVM exit >> >> Can you run with this on top >> diff --git a/arch/s390/kernel/entry.S b/arch/s390/kernel/entry.S >> index 13a133a6015c..d6dc0e5e8f74 100644 >> --- a/arch/s390/kernel/entry.S >> +++ b/arch/s390/kernel/entry.S >> @@ -426,13 +426,13 @@ ENTRY(system_call) >> UPDATE_VTIME %r8,%r9,__LC_SYNC_ENTER_TIMER >> BPENTER __TI_flags(%r12),_TIF_ISOLATE_BP >> stmg %r0,%r7,__PT_R0(%r11) >> - # clear user controlled register to prevent speculative use >> - xgr %r0,%r0 >> mvc __PT_R8(64,%r11),__LC_SAVE_AREA_SYNC >> mvc __PT_PSW(16,%r11),__LC_SVC_OLD_PSW >> mvc __PT_INT_CODE(4,%r11),__LC_SVC_ILC >> stg %r14,__PT_FLAGS(%r11) >> .Lsysc_do_svc: >> + # clear user controlled register to prevent speculative use >> + xgr %r0,%r0 >> # load address of system call table >> lg %r10,__THREAD_sysc_table(%r13,%r12) >> llgh %r8,__PT_INT_CODE+2(%r11) >> >> >> To me it looks like that the critical section cleanup (interrupt during system call entry) might >> save the registers again into ptregs but we have already zeroed out r0. >> This patch moves the clearing of r0 after sysc_do_svc, which should fix the critical >> section cleanup. >> >> Adding Martin and Heiko. Will spin a patch. > > Argh, yes. Thanks Chrisitan, this is it. I have been searching for the bug > for days now. The point is that if the system call handler is interrupted > after the xgr but before .Lsysc_do_svc the code at .Lcleanup_system_call > repeats the stmg for %r0-%r7 but now %r0 is already zero. > > Please commit a patch for this and I'll will queue it up immediately. > This patch does fix the QEMU crash. I haven't seen the crash after running the test case for more than a day. Thanks to everyone for taking a look at this problem :) Thanks Farhan ^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2018-03-07 12:52 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <079a5da7-6586-b974-6b99-e5de055b1bd1@linux.vnet.ibm.com>
[not found] ` <20180302092318.GA6026@stefanha-x1.localdomain>
[not found] ` <6a3461c2-368d-1aa1-5b86-a6a602251829@linux.vnet.ibm.com>
[not found] ` <20180305110356.GF7910@stefanha-x1.localdomain>
[not found] ` <12e1269c-6eae-a400-cc00-2c5c8e4bb8f9@linux.vnet.ibm.com>
[not found] ` <c4c4c483-d7aa-7361-774e-254c5517468b@de.ibm.com>
2018-03-05 19:08 ` [Qemu-devel] [BUG] I/O thread segfault for QEMU on s390x Christian Borntraeger
2018-03-05 19:43 ` Farhan Ali
2018-03-06 6:34 ` Martin Schwidefsky
2018-03-07 12:52 ` Farhan Ali
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox