Re: Bug inkvm_set_irq

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 :

quoted

On Wed, Mar 09, 2011 at 01:28:43PM +0100, Jean-Philippe Menil wrote:

quoted

Le 08/03/2011 12:13, Michael S. Tsirkin a écrit :

quoted

On Fri, Mar 04, 2011 at 10:39:05AM +0100, Jean-Philippe Menil wrote:

quoted

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 majordomo@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 majordomo@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
_______________________________________________
Virtualization mailing list
Virtualization@lists.linux-foundation.org
https://lists.linux-foundation.org/mailman/listinfo/virtualization