Mailing List Archive

drbd on virtio: WARNING: at block/blk-core.c
Hello,


For testing purposes only I test our software and drbd stuff on two
Virtual Machines (kvm, virtio-net, virtio-blk)
I'm using Kernel 2.6.32.25.

Since using drbd-8.3.9 I get following messages (or similar), again and
again, when DRBD is starting to sync:


[ 3830.713476] block drbd0: Began resync as SyncSource (will sync
7814892 KB [1953723 bits set]).
[ 3829.057557] block drbd0: helper command: /sbin/drbdadm
before-resync-target minor-0
[ 3830.739016] ------------[ cut here ]------------
[ 3830.739143] WARNING: at block/blk-core.c:337 blk_start_queue+0x29/0x42()
[ 3830.739145] Hardware name: Bochs
[ 3830.739147] Modules linked in: ocfs2 jbd2 ocfs2_nodemanager
ocfs2_stack_user ocfs2_stackglue dlm bonding dummy drbd cn 8021q garp
bridge stp llc rpcsec_gss_krb5 nfsd exportfs nfs lockd fscache nfs_acl
auth_rpcgss sunrpc xt_NOTRACK xt_TCPMSS xt_connmark xt_conntrack
xt_CONNMARK xt_state xt_policy iptable_nat nf_nat_tftp nf_conntrack_tftp
nf_nat_pptp nf_nat_proto_gre nf_conntrack_pptp nf_conntrack_proto_gre
nf_nat_irc nf_conntrack_irc nf_nat_sip nf_conntrack_sip nf_nat_ftp
nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_conntrack_ftp nf_conntrack
autofs4 xfrm_user ipmi_devintf ipmi_msghandler 8139too lcd_module ppdev
parport_pc parport st tpm_tis virtio_net tpm tpm_bios virtio_balloon
i2c_piix4 rtc_cmos i2c_core rtc_core rtc_lib evdev button sg [last
unloaded: ocfs2_stackglue]
[ 3830.739351] Pid: 22400, comm: path_id Not tainted 2.6.32.25 #1
[ 3830.739353] Call Trace:
[ 3830.739355] <IRQ> [<ffffffff81183265>] ? blk_start_queue+0x29/0x42
[ 3830.739416] [<ffffffff8104ccdb>] warn_slowpath_common+0x77/0x8f
[ 3830.739420] [<ffffffff8104cd02>] warn_slowpath_null+0xf/0x11
[ 3830.739422] [<ffffffff81183265>] blk_start_queue+0x29/0x42
[ 3830.739475] [<ffffffff81239462>] blk_done+0xe0/0xfa
[ 3830.739514] [<ffffffff81090d6e>] ? __rcu_process_callbacks+0xf2/0x2a6
[ 3830.739557] [<ffffffff811f7a67>] vring_interrupt+0x27/0x30
[ 3830.739572] [<ffffffff8108d3e9>] handle_IRQ_event+0x2d/0xb7
[ 3830.739575] [<ffffffff8108f005>] handle_edge_irq+0xc1/0x102
[ 3830.739607] [<ffffffff810133b5>] handle_irq+0x89/0x94
[ 3830.739610] [<ffffffff8101326b>] do_IRQ+0x5a/0xab
[ 3830.739613] [<ffffffff81011593>] ret_from_intr+0x0/0x11
[ 3830.739624] <EOI>
[ 3830.739627] ---[ end trace a9e0f5d8de037953 ]---
[ 3830.739628] ------------[ cut here ]------------


I don't get any message like this on real hardware.

This is absolutely reproducable and still exists in git head
(drbd-8.3.9-5-g7fed7c2).

It didn't exist in 8.3.8.1.

Except for the warning DRBD is syncing fine.

Any clues?


Thomas

_______________________________________________
drbd-user mailing list
drbd-user@lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-user
Re: drbd on virtio: WARNING: at block/blk-core.c [ In reply to ]
On Mon, Nov 08, 2010 at 01:56:43PM +0100, Thomas Vögtle wrote:
> Hello,
>
>
> For testing purposes only I test our software and drbd stuff on two
> Virtual Machines (kvm, virtio-net, virtio-blk)
> I'm using Kernel 2.6.32.25.
>
> Since using drbd-8.3.9 I get following messages (or similar), again and
> again, when DRBD is starting to sync:
>
>
> [ 3830.713476] block drbd0: Began resync as SyncSource (will sync
> 7814892 KB [1953723 bits set]).
> [ 3829.057557] block drbd0: helper command: /sbin/drbdadm
> before-resync-target minor-0
> [ 3830.739016] ------------[ cut here ]------------
> [ 3830.739143] WARNING: at block/blk-core.c:337 blk_start_queue+0x29/0x42()

void blk_start_queue(struct request_queue *q)
{
WARN_ON(!irqs_disabled()); <=== there

queue_flag_clear(QUEUE_FLAG_STOPPED, q);
__blk_run_queue(q);
}

> [ 3830.739145] Hardware name: Bochs
> [ 3830.739147] Modules linked in: ocfs2 jbd2 ocfs2_nodemanager
> ocfs2_stack_user ocfs2_stackglue dlm bonding dummy drbd cn 8021q garp
> bridge stp llc rpcsec_gss_krb5 nfsd exportfs nfs lockd fscache nfs_acl
> auth_rpcgss sunrpc xt_NOTRACK xt_TCPMSS xt_connmark xt_conntrack
> xt_CONNMARK xt_state xt_policy iptable_nat nf_nat_tftp nf_conntrack_tftp
> nf_nat_pptp nf_nat_proto_gre nf_conntrack_pptp nf_conntrack_proto_gre
> nf_nat_irc nf_conntrack_irc nf_nat_sip nf_conntrack_sip nf_nat_ftp
> nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_conntrack_ftp nf_conntrack
> autofs4 xfrm_user ipmi_devintf ipmi_msghandler 8139too lcd_module ppdev
> parport_pc parport st tpm_tis virtio_net tpm tpm_bios virtio_balloon
> i2c_piix4 rtc_cmos i2c_core rtc_core rtc_lib evdev button sg [last
> unloaded: ocfs2_stackglue]
> [ 3830.739351] Pid: 22400, comm: path_id Not tainted 2.6.32.25 #1
> [ 3830.739353] Call Trace:
> [ 3830.739355] <IRQ> [<ffffffff81183265>] ? blk_start_queue+0x29/0x42
> [ 3830.739416] [<ffffffff8104ccdb>] warn_slowpath_common+0x77/0x8f
> [ 3830.739420] [<ffffffff8104cd02>] warn_slowpath_null+0xf/0x11

> [ 3830.739422] [<ffffffff81183265>] blk_start_queue+0x29/0x42
> [ 3830.739475] [<ffffffff81239462>] blk_done+0xe0/0xfa

static void blk_done(struct virtqueue *vq)
{
struct virtio_blk *vblk = vq->vdev->priv;
struct virtblk_req *vbr;
unsigned int len;
unsigned long flags;

spin_lock_irqsave(&vblk->lock, flags);
while ((vbr = vblk->vq->vq_ops->get_buf(vblk->vq, &len)) != NULL) {
int error;

switch (vbr->status) {
case VIRTIO_BLK_S_OK:
error = 0;
break;
case VIRTIO_BLK_S_UNSUPP:
error = -ENOTTY;
break;
default:
error = -EIO;
break;
}

if (blk_pc_request(vbr->req)) {
vbr->req->resid_len = vbr->in_hdr.residual;
vbr->req->sense_len = vbr->in_hdr.sense_len;
vbr->req->errors = vbr->in_hdr.errors;
}

__blk_end_request_all(vbr->req, error);
list_del(&vbr->list);
mempool_free(vbr, vblk->pool);
}
/* In case queue is stopped waiting for more buffers. */
blk_start_queue(vblk->disk->queue); <<<==== THERE
spin_unlock_irqrestore(&vblk->lock, flags);
}


If your kernel source looks like mine, then this would indicate something in
between spin_lock_irqsave and spin_unlock_irqrestore above would enable
spinlocks again, where is must not.

If that something is some part of DRBD, then that would be a serious bug.

If you run with spin lock debug enabled, that may provide some more insight.
We'll try to reproduce here anyways.
You say you simply start drbd 8 in a VM with virtio-blk,
and that warning triggers?

> [ 3830.739514] [<ffffffff81090d6e>] ? __rcu_process_callbacks+0xf2/0x2a6
> [ 3830.739557] [<ffffffff811f7a67>] vring_interrupt+0x27/0x30
> [ 3830.739572] [<ffffffff8108d3e9>] handle_IRQ_event+0x2d/0xb7
> [ 3830.739575] [<ffffffff8108f005>] handle_edge_irq+0xc1/0x102
> [ 3830.739607] [<ffffffff810133b5>] handle_irq+0x89/0x94
> [ 3830.739610] [<ffffffff8101326b>] do_IRQ+0x5a/0xab
> [ 3830.739613] [<ffffffff81011593>] ret_from_intr+0x0/0x11
> [ 3830.739624] <EOI>
> [ 3830.739627] ---[ end trace a9e0f5d8de037953 ]---
> [ 3830.739628] ------------[ cut here ]------------
>
>
> I don't get any message like this on real hardware.
>
> This is absolutely reproducable and still exists in git head
> (drbd-8.3.9-5-g7fed7c2).
>
> It didn't exist in 8.3.8.1.
>
> Except for the warning DRBD is syncing fine.
>
> Any clues?
>
>
> Thomas

Thanks,

--
: Lars Ellenberg
: LINBIT | Your Way to High Availability
: DRBD/HA support and consulting http://www.linbit.com

DRBD® and LINBIT® are registered trademarks of LINBIT, Austria.
__
please don't Cc me, but send to list -- I'm subscribed
_______________________________________________
drbd-user mailing list
drbd-user@lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-user
Re: drbd on virtio: WARNING: at block/blk-core.c [ In reply to ]
Lars Ellenberg wrote:
>
> If your kernel source looks like mine, then this would indicate something in
> between spin_lock_irqsave and spin_unlock_irqrestore above would enable
> spinlocks again, where is must not.


My kernel source is 2.6.32.25 (vanilla).


> If that something is some part of DRBD, then that would be a serious bug.
>
> If you run with spin lock debug enabled, that may provide some more insight.
> We'll try to reproduce here anyways.

Switched on:
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_SPINLOCK_SLEEP=y

Hope this helps:

[ 1196.324309] block drbd0: Began resync as SyncSource (will sync
7814892 KB [1953723 bits set]).
[ 1196.325278] ------------[ cut here ]------------
[ 1196.325486] WARNING: at block/blk-core.c:337 blk_start_queue+0x29/0x42()
[ 1196.325489] Hardware name: Bochs
[ 1196.325495] Modules linked in: ocfs2 jbd2 ocfs2_nodemanager
ocfs2_stack_user ocfs2_stackglue dlm bonding dummy drbd cn 8021q garp
bridge stp llc autofs4 rpcsec_gss_krb5 nfsd exportfs nfs lockd fscache
nfs_acl auth_rpcgss sunrpc xt_NOTRACK xt_TCPMSS xt_connmark xt_conntrack
xt_CONNMARK xt_state xt_policy iptable_nat nf_nat_tftp nf_conntrack_tftp
nf_nat_pptp nf_nat_proto_gre nf_conntrack_pptp nf_conntrack_proto_gre
nf_nat_irc nf_conntrack_irc nf_nat_sip nf_conntrack_sip nf_nat_ftp
nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_conntrack_ftp nf_conntrack
xfrm_user ipmi_devintf ipmi_msghandler 8139too ppdev parport_pc parport
st virtio_net virtio_balloon tpm_tis tpm tpm_bios rtc_cmos rtc_core
rtc_lib floppy evdev i2c_piix4 sg button i2c_core [last unloaded:
ocfs2_stackglue]
[ 1196.325589] Pid: 0, comm: swapper Not tainted 2.6.32.25 #1
[ 1196.325592] Call Trace:
[ 1196.325594] <IRQ> [<ffffffff811871c1>] ? blk_start_queue+0x29/0x42
[ 1196.325698] [<ffffffff8104d006>] warn_slowpath_common+0x77/0x8f
[ 1402.406817] block drbd0: helper command: /sbin/drbdadm
before-resync-target minor-0
[ 1196.325702] [<ffffffff8104d02d>] warn_slowpath_null+0xf/0x11
[ 1196.325705] [<ffffffff811871c1>] blk_start_queue+0x29/0x42
[ 1196.325797] [<ffffffff81239fae>] blk_done+0xe0/0xfa
[ 1196.325860] [<ffffffff8101683e>] ? sched_clock+0x9/0xd
[ 1196.325923] [<ffffffff811f7e85>] vring_interrupt+0x27/0x30
[ 1196.325988] [<ffffffff8108df65>] handle_IRQ_event+0x2d/0xb7
[ 1196.326007] [<ffffffff8108f7d2>] handle_edge_irq+0xc6/0x10c
[ 1196.326010] [<ffffffff81013534>] handle_irq+0x89/0x94
[ 1196.326013] [<ffffffff8101326b>] do_IRQ+0x5a/0xab
[ 1196.326016] [<ffffffff81011593>] ret_from_intr+0x0/0x11
[ 1196.326018] <EOI> [<ffffffff8102c718>] ? native_safe_halt+0x6/0x8
[ 1196.326054] [<ffffffff810175b1>] ? need_resched+0x1e/0x28
[ 1196.326057] [<ffffffff810175e0>] ? default_idle+0x25/0x42
[ 1196.326060] [<ffffffff8100fc3b>] ? cpu_idle+0xa8/0xca
[ 1196.326194] [<ffffffff814dd342>] ? rest_init+0x66/0x68
[ 1196.326315] [<ffffffff81867d35>] ? start_kernel+0x3a5/0x3b1
[ 1196.326318] [<ffffffff81867140>] ? early_idt_handler+0x0/0x71
[ 1196.326321] [<ffffffff818672c3>] ? x86_64_start_reservations+0xae/0xb2
[ 1196.326324] [<ffffffff818673c5>] ? x86_64_start_kernel+0xfe/0x10d
[ 1196.326327] ---[ end trace d73380a0fa08d83a ]---
[ 1196.326329] ------------[ cut here ]------------



> You say you simply start drbd 8 in a VM with virtio-blk,
> and that warning triggers?

Yes, using drbd 8.3.9 and virtio-blk.
drbd 8.3.8.1 and previous didn't trigger the warning.


Thomas
_______________________________________________
drbd-user mailing list
drbd-user@lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-user
Re: drbd on virtio: WARNING: at block/blk-core.c [ In reply to ]
Sorry this post spent so much time in some moderation queue,
apparently you don't post from your subscription address,
or you are not subscribed. Anyways, see below.

On Tue, Nov 09, 2010 at 05:40:02PM +0100, Thomas Vögtle wrote:
> Lars Ellenberg wrote:
> >
> > If your kernel source looks like mine, then this would indicate something in
> > between spin_lock_irqsave and spin_unlock_irqrestore above would enable
> > spinlocks again, where is must not.
>
>
> My kernel source is 2.6.32.25 (vanilla).
>
>
> > If that something is some part of DRBD, then that would be a serious bug.
> >
> > If you run with spin lock debug enabled, that may provide some more insight.
> > We'll try to reproduce here anyways.
>
> Switched on:
> CONFIG_DEBUG_SPINLOCK=y
> CONFIG_DEBUG_SPINLOCK_SLEEP=y
>
> Hope this helps:

No it does not...
no new information than in your previous post.


Anyways,
we do it wrong...

commit 7f9c6c210158d212cc2c7be6d6b4d289078ab735
Author: Lars Ellenberg <lars.ellenberg@linbit.com>
Date: Wed Nov 10 10:33:21 2010 +0100

drbd: use irqsave in bio endio callback

We used spin_lock_irq, spin_unlock_irq. The later may re-enable irq too
early if we have been called with irq disabled, opening up a window
for all sorts of problems.

diff --git a/drbd/drbd_req.h b/drbd/drbd_req.h
index 2260e4f..f759b05 100644
--- a/drbd/drbd_req.h
+++ b/drbd/drbd_req.h
@@ -338,18 +338,21 @@ static inline int _req_mod(struct drbd_request *req, enum drbd_req_event what)
return rv;
}

-/* completion of master bio is outside of spinlock.
- * If you need it irqsave, do it your self! */
+/* completion of master bio is outside of our spinlock.
+ * We still may or may not be inside some irqs disabled section
+ * of the lower level driver completion callback, so we need to
+ * spin_lock_irqsave here. */
static inline int req_mod(struct drbd_request *req,
enum drbd_req_event what)
{
+ unsigned long flags;
struct drbd_conf *mdev = req->mdev;
struct bio_and_error m;
int rv;

- spin_lock_irq(&mdev->req_lock);
+ spin_lock_irqsave(&mdev->req_lock, flags);
rv = __req_mod(req, what, &m);
- spin_unlock_irq(&mdev->req_lock);
+ spin_unlock_irqrestore(&mdev->req_lock, flags);

if (m.bio)
complete_master_bio(mdev, &m);


only, we do it wrong for a long time already.
So I don't really see, why it would only show up in 8.3.9...

Hm. Wait.
No, we used to do it correct. My bad.
in
commit 9b7f76dc37919ea36caa9680a3f765e5b19b25fb
Author: Lars Ellenberg <lars.ellenberg@linbit.com>
Date: Wed Aug 11 23:40:24 2010 +0200

drbd: new configuration parameter c-min-rate

We now track the data rate of locally submitted resync related requests,
and can thus detect non-resync activity on the lower level device.

If the current sync rate is above c-min-rate, and the lower level device
appears to be busy, we throttle the resyncer.


a bad chunk slipped through, replacing the correct
spin_lock_irqsave;__req_mod; etc..
with a plain req_mod(), which only does spin_lock_irq.
Sorry.

I'll revert req_mod to plain spin_lock_irq,
and revert the endio callback to use the spin_lock_irqsave.

I think that should do it.

Thanks.

--
: Lars Ellenberg
: LINBIT | Your Way to High Availability
: DRBD/HA support and consulting http://www.linbit.com

DRBD® and LINBIT® are registered trademarks of LINBIT, Austria.
__
please don't Cc me, but send to list -- I'm subscribed
_______________________________________________
drbd-user mailing list
drbd-user@lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-user
Re: drbd on virtio: WARNING: at block/blk-core.c [ In reply to ]
On Sat, Nov 13, 2010 at 02:24:05PM +0000, Stefan Hajnoczi wrote:
> Does this fix the issue? Compiled but not tested.
>
> Subject: [PATCH] drbd: Use irqsave/irqrestore for req_mod() in drbd_endio_pri()
>
> It is not safe to call req_mod() from drbd_endio_pri() since it uses
> spin_lock_irq()/spin_unlock_irq(). Instead use irqsave/irqrestore and
> call __req_mod() so that local irq mode is preserved.

Right, thanks for your work.

See also my other post.

I previously only "fixed" req_mod(),
wondering why that would show up only now.
But then found the other commit that broke it, back in August, which
contained a chunk that basically looks like your below patch, reversed
:(

So it's fixed in our internal git already,
the fix should show up in public git early next week.

> Signed-off-by: Stefan Hajnoczi <stefanha@linux.vnet.ibm.com>
> ---
> drivers/block/drbd/drbd_worker.c | 9 ++++++++-
> 1 files changed, 8 insertions(+), 1 deletions(-)
>
> diff --git a/drivers/block/drbd/drbd_worker.c b/drivers/block/drbd/drbd_worker.c
> index b0551ba..b136fb8 100644
> --- a/drivers/block/drbd/drbd_worker.c
> +++ b/drivers/block/drbd/drbd_worker.c
> @@ -197,6 +197,8 @@ void drbd_endio_pri(struct bio *bio, int error)
> struct drbd_request *req = bio->bi_private;
> struct drbd_conf *mdev = req->mdev;
> enum drbd_req_event what;
> + struct bio_and_error m;
> + unsigned long flags;
> int uptodate = bio_flagged(bio, BIO_UPTODATE);
>
> if (!error && !uptodate) {
> @@ -221,7 +223,12 @@ void drbd_endio_pri(struct bio *bio, int error)
> bio_put(req->private_bio);
> req->private_bio = ERR_PTR(error);
>
> - req_mod(req, what);
> + spin_lock_irqsave(&mdev->req_lock, flags);
> + __req_mod(req, what, &m);
> + spin_unlock_irqrestore(&mdev->req_lock, flags);
> +
> + if (m.bio)
> + complete_master_bio(mdev, &m);
> }
>
> int w_read_retry_remote(struct drbd_conf *mdev, struct drbd_work *w, int cancel)
> --
> 1.7.2.3
>

--
: Lars Ellenberg
: LINBIT | Your Way to High Availability
: DRBD/HA support and consulting http://www.linbit.com

DRBD® and LINBIT® are registered trademarks of LINBIT, Austria.
__
please don't Cc me, but send to list -- I'm subscribed
_______________________________________________
drbd-user mailing list
drbd-user@lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-user
Re: drbd on virtio: WARNING: at block/blk-core.c [ In reply to ]
On Sat, Nov 13, 2010 at 11:32:47PM +0100, Lars Ellenberg wrote:
> On Sat, Nov 13, 2010 at 02:24:05PM +0000, Stefan Hajnoczi wrote:
> > Does this fix the issue? Compiled but not tested.
> >
> > Subject: [PATCH] drbd: Use irqsave/irqrestore for req_mod() in drbd_endio_pri()
> >
> > It is not safe to call req_mod() from drbd_endio_pri() since it uses
> > spin_lock_irq()/spin_unlock_irq(). Instead use irqsave/irqrestore and
> > call __req_mod() so that local irq mode is preserved.
>
> Right, thanks for your work.
>
> See also my other post.
>
> I previously only "fixed" req_mod(),
> wondering why that would show up only now.
> But then found the other commit that broke it, back in August, which
> contained a chunk that basically looks like your below patch, reversed
> :(
>
> So it's fixed in our internal git already,
> the fix should show up in public git early next week.

Great!

Stefan
_______________________________________________
drbd-user mailing list
drbd-user@lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-user
Re: drbd on virtio: WARNING: at block/blk-core.c [ In reply to ]
Lars Ellenberg wrote:
...
> a bad chunk slipped through, replacing the correct
> spin_lock_irqsave;__req_mod; etc..
> with a plain req_mod(), which only does spin_lock_irq.
> Sorry.
>
> I'll revert req_mod to plain spin_lock_irq,
> and revert the endio callback to use the spin_lock_irqsave.
>
> I think that should do it.


I get no warnings anymore.
Used git head, fcb735260c6d8f0cb372ab176bae25e31aa67ae2

Thanks,

Thomas
_______________________________________________
drbd-user mailing list
drbd-user@lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-user