On Wed, Mar 09, 2011 at 02:12:58PM +0100, Jean-Philippe Menil wrote:
> Le 09/03/2011 14:00, Michael S. Tsirkin a écrit :
> >On Wed, Mar 09, 2011 at 01:28:43PM +0100, Jean-Philippe Menil wrote:
> >>Le 08/03/2011 12:13, Michael S. Tsirkin a écrit :
> >>>On Fri, Mar 04, 2011 at 10:39:05AM +0100, Jean-Philippe Menil wrote:
> >>>>Yes, it's a 2.6.37.2 kernel.
> >>>OK, here's a debugging patch.
> >>>Please run with slab debugging as previously until you see
> >>>'eventfd bug detected!' in dmesg or until there is a crash.
> >>>It might be also useful to enable timestampts on printk with
> >>> Symbol: PRINTK_TIME [=y]
> >>> │ Type : boolean
> >>> │ Prompt: Show timing information on printks
> >>>
> >>>once you see the error, please upload the
> >>>full dmesg output somewhere to we can track what
> >>>goes on.
> >>>
> >>>Hopefully there won't be an oops this time which
> >>>should make it easier for you to test (no need to
> >>>reboot).
> >>>
> >>>
> >>>diff --git a/virt/kvm/eventfd.c b/virt/kvm/eventfd.c
> >>>index c1f1e3c..3cb679b 100644
> >>>--- a/virt/kvm/eventfd.c
> >>>+++ b/virt/kvm/eventfd.c
> >>>@@ -32,6 +32,7 @@
> >>> #include<linux/eventfd.h>
> >>> #include<linux/kernel.h>
> >>> #include<linux/slab.h>
> >>>+#include<linux/nmi.h>
> >>>
> >>> #include "iodev.h"
> >>>
> >>>@@ -43,6 +44,8 @@
> >>> * --------------------------------------------------------------------
> >>> */
> >>>
> >>>+#define KVM_BAD_PTR ((void*)(long)(0x6b6b6b6b6b6b6b6bull))
> >>>+
> >>> struct _irqfd {
> >>> struct kvm *kvm;
> >>> struct eventfd_ctx *eventfd;
> >>>@@ -61,6 +64,13 @@ irqfd_inject(struct work_struct *work)
> >>> {
> >>> struct _irqfd *irqfd = container_of(work, struct _irqfd, inject);
> >>> struct kvm *kvm = irqfd->kvm;
> >>>+ if (kvm == KVM_BAD_PTR) {
> >>>+ printk(KERN_ERR "Eventfd bug detected!\n");
> >>>+ printk(KERN_ERR "%s(work=%p,irqfd=%p,kvm=%p,gsi=%d)\n",
> >>>__func__,
> >>>+ work, irqfd, kvm, irqfd->gsi);
> >>>+ trigger_all_cpu_backtrace();
> >>>+ return;
> >>>+ }
> >>>
> >>> kvm_set_irq(kvm, KVM_USERSPACE_IRQ_SOURCE_ID, irqfd->gsi, 1);
> >>> kvm_set_irq(kvm, KVM_USERSPACE_IRQ_SOURCE_ID, irqfd->gsi, 0);
> >>>@@ -75,6 +85,8 @@ irqfd_shutdown(struct work_struct *work)
> >>> struct _irqfd *irqfd = container_of(work, struct _irqfd, shutdown);
> >>> u64 cnt;
> >>>
> >>>+ printk(KERN_ERR "%s(work=%p,irqfd=%p,kvm=%p, gsi=%d)\n", __func__,
> >>>+ work, irqfd, irqfd->kvm, irqfd->gsi);
> >>> /*
> >>> * Synchronize with the wait-queue and unhook ourselves to prevent
> >>> * further events.
> >>>@@ -91,6 +103,8 @@ irqfd_shutdown(struct work_struct *work)
> >>> * It is now safe to release the object's resources
> >>> */
> >>> eventfd_ctx_put(irqfd->eventfd);
> >>>+ printk(KERN_ERR "kfree at %s(work=%p,irqfd=%p)\n", __func__,
> >>>+ work, irqfd);
> >>> kfree(irqfd);
> >>> }
> >>>
> >>>@@ -111,6 +125,8 @@ static void
> >>> irqfd_deactivate(struct _irqfd *irqfd)
> >>> {
> >>> BUG_ON(!irqfd_is_active(irqfd));
> >>>+ printk(KERN_ERR "%s(irqfd=%p,kvm=%p, gsi=%d)\n", __func__,
> >>>+ irqfd, irqfd->kvm, irqfd->gsi);
> >>>
> >>> list_del_init(&irqfd->list);
> >>>
> >>>@@ -178,6 +194,8 @@ kvm_irqfd_assign(struct kvm *kvm, int fd, int gsi)
> >>>
> >>> irqfd->kvm = kvm;
> >>> irqfd->gsi = gsi;
> >>>+ printk(KERN_ERR "%s(irqfd=%p,kvm=%p, gsi=%d)\n", __func__,
> >>>+ irqfd, kvm, gsi);
> >>> INIT_LIST_HEAD(&irqfd->list);
> >>> INIT_WORK(&irqfd->inject, irqfd_inject);
> >>> INIT_WORK(&irqfd->shutdown, irqfd_shutdown);
> >>>@@ -264,6 +282,8 @@ kvm_irqfd_deassign(struct kvm *kvm, int fd, int gsi)
> >>> struct _irqfd *irqfd, *tmp;
> >>> struct eventfd_ctx *eventfd;
> >>>
> >>>+ printk(KERN_ERR "%s(kvm=%p, gsi=%d)\n", __func__,
> >>>+ kvm, gsi);
> >>> eventfd = eventfd_ctx_fdget(fd);
> >>> if (IS_ERR(eventfd))
> >>> return PTR_ERR(eventfd);
> >>>@@ -305,6 +325,7 @@ void
> >>> kvm_irqfd_release(struct kvm *kvm)
> >>> {
> >>> struct _irqfd *irqfd, *tmp;
> >>>+ printk(KERN_ERR "%s(kvm=%p)\n", __func__, kvm);
> >>>
> >>> spin_lock_irq(&kvm->irqfds.lock);
> >>>
> >>>--
> >>>To unsubscribe from this list: send the line "unsubscribe netdev" in
> >>>the body of a message to majord...@vger.kernel.org
> >>>More majordomo info at http://vger.kernel.org/majordomo-info.html
> >>Hi,
> >>
> >>I boot the host with the patched kernel yesterday.
> >>No crach until now, but two "Eventfd bug detected!" in the log at
> >>"Mar 9 02:04:31" and "Mar 9 02:15:17"
> >>You can find part of the log at the following adress:
> >>http://filex.univ-nantes.fr/get?k=jL4Fe7yfSMN57toAH7V
> >>
> >>It a split file of the kern.log (1,4G), so if you need another part
> >>of the log, let me know.
> >>
> >>Thanks for all.
> >>
> >>Regards.
> >Downloading, it's big :)
> >What about some 1000 lines before and after Eventfd bug detected! line?
> >--
> >To unsubscribe from this list: send the line "unsubscribe kvm" in
> >the body of a message to majord...@vger.kernel.org
> >More majordomo info at http://vger.kernel.org/majordomo-info.html
> Yes, sorry about that.
> I could have split my log into a smaller file.
>
> I was a little afraid of not transmit enough informations, and i was
> a bit wide.
> I hope you can find usefull trace anyway.
>
> Regards.
OK, use after free.
Mar 9 02:15:17 ayrshire.u06.univ-nantes.prive kernel: [37461.593681]
kvm_irqfd_assign(irqfd=ffff88045e8d6230,kvm=ffff88085151c000, gsi=26)
Mar 9 02:15:17 ayrshire.u06.univ-nantes.prive kernel: [37461.605359]
kvm_irqfd_deassign(kvm=ffff88085151c000, gsi=26)
Mar 9 02:15:17 ayrshire.u06.univ-nantes.prive kernel: [37461.605388]
irqfd_deactivate(irqfd=ffff88045e8d6230,kvm=ffff88085151c000, gsi=26)
Mar 9 02:15:17 ayrshire.u06.univ-nantes.prive kernel: [37461.605461]
irqfd_shutdown(work=ffff88045e8d62b0,irqfd=ffff88045e8d6230,kvm=ffff88085151c000,
gsi=26)
Mar 9 02:15:17 ayrshire.u06.univ-nantes.prive kernel: [37461.605509]
kfree at irqfd_shutdown(work=ffff88045e8d62b0,irqfd=ffff88045e8d6230)
Mar 9 02:15:17 ayrshire.u06.univ-nantes.prive kernel: [37461.605588]
Eventfd bug detected!
Mar 9 02:15:17 ayrshire.u06.univ-nantes.prive kernel: [37461.605612]
irqfd_inject(work=ffff88045e8d6290,irqfd=ffff88045e8d6230,kvm=6b6b6b6b6b6b6b6b,gsi=1802201963)
and 1802201963 is also 6b6b6b6b.
I suspect that somehow, we get an event from eventfd even
though we did eventfd_ctx_remove_wait_queue.
Could you please try the following patch on top?
When you see Eventfd bug or Wakeup bug, paste some
last lines.
For the full log file - better compress with xz.
diff --git a/virt/kvm/eventfd.c b/virt/kvm/eventfd.c
index 3cb679b..63aeba5 100644
--- a/virt/kvm/eventfd.c
+++ b/virt/kvm/eventfd.c
@@ -92,6 +92,8 @@ irqfd_shutdown(struct work_struct *work)
* further events.
*/
eventfd_ctx_remove_wait_queue(irqfd->eventfd, &irqfd->wait, &cnt);
+ printk(KERN_ERR "remove wq at %s(work=%p,irqfd=%p)\n", __func__,
+ work, irqfd);
/*
* We know no new events will be scheduled at this point, so block
@@ -142,6 +144,13 @@ irqfd_wakeup(wait_queue_t *wait, unsigned mode, int sync,
void *key)
struct _irqfd *irqfd = container_of(wait, struct _irqfd, wait);
unsigned long flags = (unsigned long)key;
+ if (irqfd->kvm == KVM_BAD_PTR) {
+ printk(KERN_ERR "Wakeup bug detected! flags 0x%lx\n", flags);
+ printk(KERN_ERR "%s(work=%p,irqfd=%p,kvm=%p,gsi=%d)\n",
__func__,
+ &irqfd->inject, irqfd, irqfd->kvm, irqfd->gsi);
+ trigger_all_cpu_backtrace();
+ return 0;
+ }
if (flags & POLLIN)
/* An event has been signaled, inject an interrupt */
schedule_work(&irqfd->inject);
@@ -153,6 +162,9 @@ irqfd_wakeup(wait_queue_t *wait, unsigned mode, int sync,
void *key)
spin_lock_irqsave(&kvm->irqfds.lock, flags);
+ printk(KERN_ERR
"%s(work=%p,irqfd=%p,kvm=%p,gsi=%d,active=%d)\n", __func__,
+ &irqfd->inject, irqfd, irqfd->kvm, irqfd->gsi,
+ irqfd_is_active(irqfd));
/*
* We must check if someone deactivated the irqfd before
* we could acquire the irqfds.lock since the item is
--
MST
--
To unsubscribe from this list: send the line "unsubscribe kvm" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
