BUG at net/sunrpc/svc_xprt.c:921

BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

[-- Attachment #1: Type: text/plain, Size: 3221 bytes --]

Since upgrading to 3.7, and now 3.7.2, my AMD-450E based server
is getting these BUG complaints.  The .config file is gzip'd/attached.

------------[ cut here ]------------
kernel BUG at net/sunrpc/svc_xprt.c:921!
invalid opcode: 0000 [#1] SMP
Modules linked in: nfsv4 xt_state xt_tcpudp xt_recent xt_LOG xt_limit iptable_mangle iptable_nat
nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_filter ip_tables x_tables
sc520_wdt btusb snd_usb_audio snd_usbmidi_lib hid_generic ftdi_sio usbserial usbhid hid
snd_hda_codec_realtek psmouse snd_hda_codec_hdmi r8169 xhci_hcd mii snd_hda_intel snd_hda_codec
snd_hwdep snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_midi snd_rawmidi snd_seq_midi_event snd_seq bnep
snd_timer rfcomm snd_seq_device bluetooth snd nfsd auth_rpcgss binfmt_misc radeon nfs lockd sunrpc
soundcore ttm snd_page_alloc drm_kms_helper drm i2c_algo_bit it87 hwmon_vid k10temp hwmon microcode
CPU 0
Pid: 29613, comm: nfsv4.0-svc Not tainted 3.7.2 #1 System manufacturer System Product Name/E45M1-I
DELUXE
RIP: 0010:[<ffffffffa01696cd>]  [<ffffffffa01696cd>] svc_delete_xprt+0x23/0xeb [sunrpc]
RSP: 0018:ffff880234f05e38  EFLAGS: 00010286
RAX: 00000000ffffffff RBX: ffff8801b931b000 RCX: dead000000200200
RDX: dead000000100100 RSI: ffff8801b931b038 RDI: 0000000000000006
RBP: ffff880049125e40 R08: 0000000000000606 R09: ffff88023ec10fc0
R10: ffff88023ec10fc0 R11: ffff88023ec10fc0 R12: ffff880049125e40
R13: ffff8801b931b038 R14: 0000000000000000 R15: 0000000000000000
FS:  00007f5bef2fd700(0000) GS:ffff88023ec00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 00007f2f1800bfa0 CR3: 000000015ba2e000 CR4: 00000000000007f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process nfsv4.0-svc (pid: 29613, threadinfo ffff880234f04000, task ffff88021b51a280)
Stack:
 0000000000001cc7 ffff8801a5f2e000 ffff8801b931b000 ffff880049125e40
 ffff880049125e40 ffffffffa016a56a 0000000000010fc0 ffff880234f05fd8
 ffff880234f05fd8 ffff8801a5f2e000 ffff8801a5f2e000 ffff880234f05f08
Call Trace:
 [<ffffffffa016a56a>] ? svc_recv+0xcc/0x338 [sunrpc]
 [<ffffffffa0318bfc>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
 [<ffffffffa0318c19>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
 [<ffffffff810407e6>] ? kthread+0x81/0x89
 [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
 [<ffffffff812ea62c>] ? ret_from_fork+0x7c/0xb0
 [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
Code: c2 84 d2 74 02 eb a0 c3 41 55 4c 8d 6f 38 41 54 4c 89 ee 55 53 48 89 fb 50 48 8b 6f 40 bf 06
00 00 00 e8 77 fa ff ff 85 c0 74 02 <0f> 0b 48 8b 43 08 4c 8d 65 10 48 89 df ff 50 38 4c 89 e7 e8 6d
RIP  [<ffffffffa01696cd>] svc_delete_xprt+0x23/0xeb [sunrpc]
 RSP <ffff880234f05e38>
---[ end trace 916f6471c0b47e1d ]---


Here's the code with the BUG() at net/sunrpc/svc_xprt.c line 921:

/*
 * Remove a dead transport
 */
static void svc_delete_xprt(struct svc_xprt *xprt)
{
        struct svc_serv *serv = xprt->xpt_server;
        struct svc_deferred_req *dr;

        /* Only do this once */
        if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
                BUG();
...





[-- Attachment #2: config.txt.gz --]
[-- Type: application/x-gzip, Size: 17634 bytes --]

Re: BUG at net/sunrpc/svc_xprt.c:921

[J. Bruce Fields]

Thanks for the report.

On Mon, Jan 14, 2013 at 11:17:09AM -0500, Mark Lord wrote:
> Since upgrading to 3.7, and now 3.7.2, my AMD-450E based server

It's acting as an NFS client, right?

What did you upgrade from?

> is getting these BUG complaints.  The .config file is gzip'd/attached.

Is this easy to reproduce?

--b.

> 
> ------------[ cut here ]------------
> kernel BUG at net/sunrpc/svc_xprt.c:921!
> invalid opcode: 0000 [#1] SMP
> Modules linked in: nfsv4 xt_state xt_tcpudp xt_recent xt_LOG xt_limit iptable_mangle iptable_nat
> nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack iptable_filter ip_tables x_tables
> sc520_wdt btusb snd_usb_audio snd_usbmidi_lib hid_generic ftdi_sio usbserial usbhid hid
> snd_hda_codec_realtek psmouse snd_hda_codec_hdmi r8169 xhci_hcd mii snd_hda_intel snd_hda_codec
> snd_hwdep snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_midi snd_rawmidi snd_seq_midi_event snd_seq bnep
> snd_timer rfcomm snd_seq_device bluetooth snd nfsd auth_rpcgss binfmt_misc radeon nfs lockd sunrpc
> soundcore ttm snd_page_alloc drm_kms_helper drm i2c_algo_bit it87 hwmon_vid k10temp hwmon microcode
> CPU 0
> Pid: 29613, comm: nfsv4.0-svc Not tainted 3.7.2 #1 System manufacturer System Product Name/E45M1-I
> DELUXE
> RIP: 0010:[<ffffffffa01696cd>]  [<ffffffffa01696cd>] svc_delete_xprt+0x23/0xeb [sunrpc]
> RSP: 0018:ffff880234f05e38  EFLAGS: 00010286
> RAX: 00000000ffffffff RBX: ffff8801b931b000 RCX: dead000000200200
> RDX: dead000000100100 RSI: ffff8801b931b038 RDI: 0000000000000006
> RBP: ffff880049125e40 R08: 0000000000000606 R09: ffff88023ec10fc0
> R10: ffff88023ec10fc0 R11: ffff88023ec10fc0 R12: ffff880049125e40
> R13: ffff8801b931b038 R14: 0000000000000000 R15: 0000000000000000
> FS:  00007f5bef2fd700(0000) GS:ffff88023ec00000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> CR2: 00007f2f1800bfa0 CR3: 000000015ba2e000 CR4: 00000000000007f0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> Process nfsv4.0-svc (pid: 29613, threadinfo ffff880234f04000, task ffff88021b51a280)
> Stack:
>  0000000000001cc7 ffff8801a5f2e000 ffff8801b931b000 ffff880049125e40
>  ffff880049125e40 ffffffffa016a56a 0000000000010fc0 ffff880234f05fd8
>  ffff880234f05fd8 ffff8801a5f2e000 ffff8801a5f2e000 ffff880234f05f08
> Call Trace:
>  [<ffffffffa016a56a>] ? svc_recv+0xcc/0x338 [sunrpc]
>  [<ffffffffa0318bfc>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
>  [<ffffffffa0318c19>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
>  [<ffffffff810407e6>] ? kthread+0x81/0x89
>  [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
>  [<ffffffff812ea62c>] ? ret_from_fork+0x7c/0xb0
>  [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
> Code: c2 84 d2 74 02 eb a0 c3 41 55 4c 8d 6f 38 41 54 4c 89 ee 55 53 48 89 fb 50 48 8b 6f 40 bf 06
> 00 00 00 e8 77 fa ff ff 85 c0 74 02 <0f> 0b 48 8b 43 08 4c 8d 65 10 48 89 df ff 50 38 4c 89 e7 e8 6d
> RIP  [<ffffffffa01696cd>] svc_delete_xprt+0x23/0xeb [sunrpc]
>  RSP <ffff880234f05e38>
> ---[ end trace 916f6471c0b47e1d ]---
> 
> 
> Here's the code with the BUG() at net/sunrpc/svc_xprt.c line 921:
> 
> /*
>  * Remove a dead transport
>  */
> static void svc_delete_xprt(struct svc_xprt *xprt)
> {
>         struct svc_serv *serv = xprt->xpt_server;
>         struct svc_deferred_req *dr;
> 
>         /* Only do this once */
>         if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
>                 BUG();
> ...
> 
> 
> 
> 

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-14 03:37 PM, J. Bruce Fields wrote:
> Thanks for the report.
> 
> On Mon, Jan 14, 2013 at 11:17:09AM -0500, Mark Lord wrote:
>> Since upgrading to 3.7, and now 3.7.2, my AMD-450E based server
> 
> It's acting as an NFS client, right?

Client and server, with other Linux boxes all running 3.something kernels.

> What did you upgrade from?

3.4.something, I believe.

>> is getting these BUG complaints.  The .config file is gzip'd/attached.
> 
> Is this easy to reproduce?

So far, it seems to pop up within a day or so of any reboot.
I normally only reboot that system for a kernel upgrade,
but can do so a bit more often if there's useful info to collect.

Cheers

Re: BUG at net/sunrpc/svc_xprt.c:921

[J. Bruce Fields]

On Mon, Jan 14, 2013 at 11:16:00PM -0500, Mark Lord wrote:
> On 13-01-14 03:37 PM, J. Bruce Fields wrote:
> > Thanks for the report.
> > 
> > On Mon, Jan 14, 2013 at 11:17:09AM -0500, Mark Lord wrote:
> >> Since upgrading to 3.7, and now 3.7.2, my AMD-450E based server
> > 
> > It's acting as an NFS client, right?
> 
> Client and server, with other Linux boxes all running 3.something kernels.
> 
> > What did you upgrade from?
> 
> 3.4.something, I believe.
> 
> >> is getting these BUG complaints.  The .config file is gzip'd/attached.
> > 
> > Is this easy to reproduce?
> 
> So far, it seems to pop up within a day or so of any reboot.
> I normally only reboot that system for a kernel upgrade,
> but can do so a bit more often if there's useful info to collect.

So this means svc_delete_xprt was called on an xprt twice.

That could happen if server threads are still running (and calling
svc_recv) after we start shutting down the server: svc_shutdown_net
assumes that server threads are already shut down, but that isn't true
any more after the containerization work.

I thought that would only be a bug for users actually running multiple
containers, but looking at nfs_callback_down, I don't think that's
true--it seems to always shut down the thread last.

--b.

Re: BUG at net/sunrpc/svc_xprt.c:921

[Stanislav Kinsbursky]

16.01.2013 00:56, J. Bruce Fields пишет:
> On Mon, Jan 14, 2013 at 11:16:00PM -0500, Mark Lord wrote:
>> On 13-01-14 03:37 PM, J. Bruce Fields wrote:
>>> Thanks for the report.
>>>
>>> On Mon, Jan 14, 2013 at 11:17:09AM -0500, Mark Lord wrote:
>>>> Since upgrading to 3.7, and now 3.7.2, my AMD-450E based server
>>>
>>> It's acting as an NFS client, right?
>>
>> Client and server, with other Linux boxes all running 3.something kernels.
>>
>>> What did you upgrade from?
>>
>> 3.4.something, I believe.
>>
>>>> is getting these BUG complaints.  The .config file is gzip'd/attached.
>>>
>>> Is this easy to reproduce?
>>
>> So far, it seems to pop up within a day or so of any reboot.
>> I normally only reboot that system for a kernel upgrade,
>> but can do so a bit more often if there's useful info to collect.
>
> So this means svc_delete_xprt was called on an xprt twice.
>
> That could happen if server threads are still running (and calling
> svc_recv) after we start shutting down the server: svc_shutdown_net
> assumes that server threads are already shut down, but that isn't true
> any more after the containerization work.
>
> I thought that would only be a bug for users actually running multiple
> containers, but looking at nfs_callback_down, I don't think that's
> true--it seems to always shut down the thread last.
>

Thanks, Bruce. It reminds me the patch with additional protection for permanents sockets shutdown I've sent you a couple of mount ago...
Look like I should revisit this patch at least.

Mark, could you provide any call traces?

> --b.
>


-- 
Best regards,
Stanislav Kinsbursky

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-16 12:20 AM, Stanislav Kinsbursky wrote:
> 
> Mark, could you provide any call traces?

Call traces from where/what?
There's this one, posted earlier in the BUG report:

kernel BUG at net/sunrpc/svc_xprt.c:921!
Call Trace:
 [<ffffffffa016a56a>] ? svc_recv+0xcc/0x338 [sunrpc]
 [<ffffffffa0318bfc>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
 [<ffffffffa0318c19>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
 [<ffffffff810407e6>] ? kthread+0x81/0x89
 [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
 [<ffffffff812ea62c>] ? ret_from_fork+0x7c/0xb0
 [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-16 05:51 PM, Mark Lord wrote:
> On 13-01-16 12:20 AM, Stanislav Kinsbursky wrote:
>>
>> Mark, could you provide any call traces?
> 
> Call traces from where/what?
> There's this one, posted earlier in the BUG report:
> 
> kernel BUG at net/sunrpc/svc_xprt.c:921!
> Call Trace:
>  [<ffffffffa016a56a>] ? svc_recv+0xcc/0x338 [sunrpc]
>  [<ffffffffa0318bfc>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
>  [<ffffffffa0318c19>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
>  [<ffffffff810407e6>] ? kthread+0x81/0x89
>  [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
>  [<ffffffff812ea62c>] ? ret_from_fork+0x7c/0xb0
>  [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
..

This might be of some interest.
Here are the first few lines of the same BUG occurance,
with timestamps and the dmesg lines that immediately preceeded it.
Perhaps they might help indicate who's triggering the action
that results in the BUG(?).

Jan 14 10:58:05 zippy kernel: [66045.627952] NFS: Registering the id_resolver key type
Jan 14 10:58:05 zippy kernel: [66045.628014] Key type id_resolver registered
Jan 14 10:58:05 zippy kernel: [66045.628020] Key type id_legacy registered
Jan 14 10:58:05 zippy kernel: [66045.636302] ------------[ cut here ]------------
Jan 14 10:58:05 zippy kernel: [66045.648342] kernel BUG at net/sunrpc/svc_xprt.c:921!

Re: BUG at net/sunrpc/svc_xprt.c:921

[Stanislav Kinsbursky]

17.01.2013 02:51, Mark Lord пишет:
> On 13-01-16 12:20 AM, Stanislav Kinsbursky wrote:
>>
>> Mark, could you provide any call traces?
>
> Call traces from where/what?
> There's this one, posted earlier in the BUG report:
>
> kernel BUG at net/sunrpc/svc_xprt.c:921!
> Call Trace:
>   [<ffffffffa016a56a>] ? svc_recv+0xcc/0x338 [sunrpc]
>   [<ffffffffa0318bfc>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
>   [<ffffffffa0318c19>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
>   [<ffffffff810407e6>] ? kthread+0x81/0x89
>   [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
>   [<ffffffff812ea62c>] ? ret_from_fork+0x7c/0xb0
>   [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
>

Thanks!
I haven't seen the bug report.
Could you provide the link, please?

-- 
Best regards,
Stanislav Kinsbursky

Re: BUG at net/sunrpc/svc_xprt.c:921

[J. Bruce Fields]

On Thu, Jan 17, 2013 at 09:05:51AM +0400, Stanislav Kinsbursky wrote:
> 17.01.2013 02:51, Mark Lord пишет:
> >On 13-01-16 12:20 AM, Stanislav Kinsbursky wrote:
> >>
> >>Mark, could you provide any call traces?
> >
> >Call traces from where/what?
> >There's this one, posted earlier in the BUG report:
> >
> >kernel BUG at net/sunrpc/svc_xprt.c:921!
> >Call Trace:
> >  [<ffffffffa016a56a>] ? svc_recv+0xcc/0x338 [sunrpc]
> >  [<ffffffffa0318bfc>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
> >  [<ffffffffa0318c19>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
> >  [<ffffffff810407e6>] ? kthread+0x81/0x89
> >  [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
> >  [<ffffffff812ea62c>] ? ret_from_fork+0x7c/0xb0
> >  [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
> >
> 
> Thanks!
> I haven't seen the bug report.
> Could you provide the link, please?

There's no bz if that's what you're asking for.

See the first message in the thread for the original report:

	http://mid.gmane.org/<50F42F85.50907@teksavvy.com>

--b.

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-14 11:17 AM, Mark Lord wrote:
>
> Here's the code with the BUG() at net/sunrpc/svc_xprt.c line 921:
> 
> /*
>  * Remove a dead transport
>  */
> static void svc_delete_xprt(struct svc_xprt *xprt)
> {
>         struct svc_serv *serv = xprt->xpt_server;
>         struct svc_deferred_req *dr;
> 
>         /* Only do this once */
>         if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
>                 BUG();


Shouldn't there also be a return statement after the BUG() line,
inside the if-stmt ?

I mean, the comment says "only do this once", but it actually
appears to end up doing it twice, despite the test.

??

Re: BUG at net/sunrpc/svc_xprt.c:921

[Stanislav Kinsbursky]

17.01.2013 17:03, J. Bruce Fields пишет:
> On Thu, Jan 17, 2013 at 09:05:51AM +0400, Stanislav Kinsbursky wrote:
>> 17.01.2013 02:51, Mark Lord пишет:
>>> On 13-01-16 12:20 AM, Stanislav Kinsbursky wrote:
>>>>
>>>> Mark, could you provide any call traces?
>>>
>>> Call traces from where/what?
>>> There's this one, posted earlier in the BUG report:
>>>
>>> kernel BUG at net/sunrpc/svc_xprt.c:921!
>>> Call Trace:
>>>   [<ffffffffa016a56a>] ? svc_recv+0xcc/0x338 [sunrpc]
>>>   [<ffffffffa0318bfc>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
>>>   [<ffffffffa0318c19>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
>>>   [<ffffffff810407e6>] ? kthread+0x81/0x89
>>>   [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
>>>   [<ffffffff812ea62c>] ? ret_from_fork+0x7c/0xb0
>>>   [<ffffffff81040765>] ? kthread_freezable_should_stop+0x36/0x36
>>>
>>
>> Thanks!
>> I haven't seen the bug report.
>> Could you provide the link, please?
>
> There's no bz if that's what you're asking for.
>
> See the first message in the thread for the original report:
>
> 	http://mid.gmane.org/<50F42F85.50907@teksavvy.com>
>

Thanks, Bruce.
This looks like the old issue I was trying to fix with "SUNRPC: protect service sockets lists during per-net shutdown".
So, here is the problem as I see it: there is a transport, which is processed by service thread and it's processing is racing with per-net service shutdown:

CPU#0:							CPU#1:

svc_recv						svc_close_net
svc_get_next_xprt (list_del_init(xpt_ready))
							svc_close_list (set XPT_BUSY and XPT_CLOSE)
							svc_clear_pools(xprt was gained on CPU#0 already)
							svc_delete_xprt (set XPT_DEAD)
svc_handle_xprt (is XPT_CLOSE => svc_delete_xprt()
BUG()

So, from my POW, we need some way to:
1) Skip such in-progress transports on svc_close_net() call (there is not way to detect them, or at  least I don't see one)
2) Delete the transport after somewhere after svc_xprt_received()

But there is a problem with svc_xprt_received(): there is a call for svc_xprt_put() in it (svc_recv->svc_handle_xprt->svc_xprt_received->svc_xprt_put) . And if 
we are the only user - then the transport will be destroyed. But transport is dereferenced later in svc_recv() after the svc_handle_xprt call.

What do you think, Bruce?


> --b.
>


-- 
Best regards,
Stanislav Kinsbursky

Re: BUG at net/sunrpc/svc_xprt.c:921

[J. Bruce Fields]

On Thu, Jan 17, 2013 at 08:11:52AM -0500, Mark Lord wrote:
> On 13-01-14 11:17 AM, Mark Lord wrote:
> >
> > Here's the code with the BUG() at net/sunrpc/svc_xprt.c line 921:
> > 
> > /*
> >  * Remove a dead transport
> >  */
> > static void svc_delete_xprt(struct svc_xprt *xprt)
> > {
> >         struct svc_serv *serv = xprt->xpt_server;
> >         struct svc_deferred_req *dr;
> > 
> >         /* Only do this once */
> >         if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
> >                 BUG();
> 
> 
> Shouldn't there also be a return statement after the BUG() line,
> inside the if-stmt ?

BUG() kills the thread that calls it, so it never returns, and a
following statement wouldn't be executed--I may not understand your
question.

--b.

> 
> I mean, the comment says "only do this once", but it actually
> appears to end up doing it twice, despite the test.
> 
> ??

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-17 08:53 AM, J. Bruce Fields wrote:
> On Thu, Jan 17, 2013 at 08:11:52AM -0500, Mark Lord wrote:
>> On 13-01-14 11:17 AM, Mark Lord wrote:
>>>
>>> Here's the code with the BUG() at net/sunrpc/svc_xprt.c line 921:
>>>
>>> /*
>>>  * Remove a dead transport
>>>  */
>>> static void svc_delete_xprt(struct svc_xprt *xprt)
>>> {
>>>         struct svc_serv *serv = xprt->xpt_server;
>>>         struct svc_deferred_req *dr;
>>>
>>>         /* Only do this once */
>>>         if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
>>>                 BUG();
>>
>>
>> Shouldn't there also be a return statement after the BUG() line,
>> inside the if-stmt ?
> 
> BUG() kills the thread that calls it

Oh, does it?  Well, taken care of then, I guess.
With a sledgehammer.

:)

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-17 08:24 AM, Stanislav Kinsbursky wrote:
..
> This looks like the old issue I was trying to fix with "SUNRPC: protect service sockets lists during
> per-net shutdown".
> So, here is the problem as I see it: there is a transport, which is processed by service thread and
> it's processing is racing with per-net service shutdown:
> 
> CPU#0:                            CPU#1:
> 
> svc_recv                        svc_close_net
> svc_get_next_xprt (list_del_init(xpt_ready))
>                             svc_close_list (set XPT_BUSY and XPT_CLOSE)
>                             svc_clear_pools(xprt was gained on CPU#0 already)
>                             svc_delete_xprt (set XPT_DEAD)
> svc_handle_xprt (is XPT_CLOSE => svc_delete_xprt()
> BUG()
> 
> So, from my POW, we need some way to:
> 1) Skip such in-progress transports on svc_close_net() call (there is not way to detect them, or at 
> least I don't see one)
> 2) Delete the transport after somewhere after svc_xprt_received()
> 
> But there is a problem with svc_xprt_received(): there is a call for svc_xprt_put() in it
> (svc_recv->svc_handle_xprt->svc_xprt_received->svc_xprt_put) . And if we are the only user - then
> the transport will be destroyed. But transport is dereferenced later in svc_recv() after the
> svc_handle_xprt call.

Sounds like a reference count type of problem/solution (kref) (?)

Re: BUG at net/sunrpc/svc_xprt.c:921

[Stanislav Kinsbursky]

18.01.2013 03:41, Mark Lord пишет:
> On 13-01-17 08:24 AM, Stanislav Kinsbursky wrote:
> ..
>> This looks like the old issue I was trying to fix with "SUNRPC: protect service sockets lists during
>> per-net shutdown".
>> So, here is the problem as I see it: there is a transport, which is processed by service thread and
>> it's processing is racing with per-net service shutdown:
>>
>> CPU#0:                            CPU#1:
>>
>> svc_recv                        svc_close_net
>> svc_get_next_xprt (list_del_init(xpt_ready))
>>                              svc_close_list (set XPT_BUSY and XPT_CLOSE)
>>                              svc_clear_pools(xprt was gained on CPU#0 already)
>>                              svc_delete_xprt (set XPT_DEAD)
>> svc_handle_xprt (is XPT_CLOSE => svc_delete_xprt()
>> BUG()
>>
>> So, from my POW, we need some way to:
>> 1) Skip such in-progress transports on svc_close_net() call (there is not way to detect them, or at
>> least I don't see one)
>> 2) Delete the transport after somewhere after svc_xprt_received()
>>
>> But there is a problem with svc_xprt_received(): there is a call for svc_xprt_put() in it
>> (svc_recv->svc_handle_xprt->svc_xprt_received->svc_xprt_put) . And if we are the only user - then
>> the transport will be destroyed. But transport is dereferenced later in svc_recv() after the
>> svc_handle_xprt call.
>
> Sounds like a reference count type of problem/solution (kref) (?)
>

No, it would be very simple.
Unluckily, the problem is more complex. In few words, the problem is in dynamic resources (transports) creation/attaching
and destruction/detaching for running (!) SUNRPC service.
You have more than one NFS mount in different network namespaces, haven't you?

-- 
Best regards,
Stanislav Kinsbursky

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-18 12:37 AM, Stanislav Kinsbursky wrote:
>
> You have more than one NFS mount in different network namespaces, haven't you?
>

No, I don't (knowingly) use (multiple) namespaces at all.
Usually I disable them in the kernel .config,
though it appears the currently running kernel has this:

CONFIG_NAMESPACES=y
# CONFIG_UTS_NS is not set
# CONFIG_IPC_NS is not set
# CONFIG_PID_NS is not set
# CONFIG_NET_NS is not set

The full .config was attached to the first post in this thread.

Cheers

Re: BUG at net/sunrpc/svc_xprt.c:921

[J. Bruce Fields]

On Fri, Jan 18, 2013 at 10:48:02AM -0500, Mark Lord wrote:
> On 13-01-18 12:37 AM, Stanislav Kinsbursky wrote:
> >
> > You have more than one NFS mount in different network namespaces, haven't you?
> >
> 
> No, I don't (knowingly) use (multiple) namespaces at all.

Right, I don't think that's necessary.  Stanislav, look at
nfs_callback_down:

	nfs_callback_down_net(minorversion, cb_info->serv, net);
        cb_info->users--;
	if (cb_info->users == 0 && cb_info->task != NULL) {
		kthread_stop(cb_info->task);
		...

It's first destroying the service, then destroying the thread.  That's
the wrong order.  So we could still have the thread running svc_recv()
after the rpc service is destroyed.

--b.

> Usually I disable them in the kernel .config,
> though it appears the currently running kernel has this:
> 
> CONFIG_NAMESPACES=y
> # CONFIG_UTS_NS is not set
> # CONFIG_IPC_NS is not set
> # CONFIG_PID_NS is not set
> # CONFIG_NET_NS is not set
> 
> The full .config was attached to the first post in this thread.
> 
> Cheers
> 

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[Mark Lord]

Got it again, this time on a different system
running mostly the same software.

This time, I noticed when it happened:  on mounting another system's storage over NFS.
I was doing a "mount" command when suddenly this happened.  Linux-3.7.3.

[ 3342.841487] ------------[ cut here ]------------
[ 3342.841527] kernel BUG at net/sunrpc/svc_xprt.c:921!
[ 3342.841547] invalid opcode: 0000 [#1] PREEMPT SMP
[ 3342.841579] Modules linked in: nfsv3 nfsv4 sha1_generic ppp_mppe ppp_async crc_ccitt ppp_generic
slhc btusb hid_generic arc4 usbhid hid b43 coretemp kvm_intel kvm mac80211 cfg80211
snd_hda_codec_idt dell_wmi snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss snd_pcm
dell_laptop dcdbas snd_seq_dummy snd_seq_oss microcode snd_seq_midi psmouse snd_rawmidi
snd_seq_midi_event snd_seq nouveau ttm drm_kms_helper ssb drm bnep i2c_algo_bit snd_timer i2c_core
mxm_wmi snd_seq_device rfcomm snd bluetooth parport_pc soundcore snd_page_alloc ppdev video nfsd
auth_rpcgss nfs lockd binfmt_misc sunrpc lp parport firewire_ohci tg3 firewire_core crc_itu_t libphy
hwmon sdhci_pci sdhci
[ 3342.842104] CPU 1
[ 3342.842120] Pid: 4108, comm: nfsv4.0-svc Not tainted 3.7.3 #3 Dell Inc. Precision M6300
       /0JM680
[ 3342.842151] RIP: 0010:[<ffffffffa007ba6e>]  [<ffffffffa007ba6e>] svc_delete_xprt+0x23/0xf3 [sunrpc]
[ 3342.842206] RSP: 0018:ffff8801a680be38  EFLAGS: 00010286
[ 3342.842226] RAX: 00000000ffffffff RBX: ffff880215103000 RCX: dead000000200200
[ 3342.842247] RDX: dead000000100100 RSI: ffff880215103038 RDI: 0000000000000006
[ 3342.842270] RBP: ffff880215726900 R08: 0000000000000606 R09: ffff88021fd11280
[ 3342.842293] R10: 00000000004f9885 R11: ffff88021fd11280 R12: ffff880215726900
[ 3342.842315] R13: ffff880215103038 R14: 0000000000000000 R15: 0000000000000000
[ 3342.842337] FS:  0000000000000000(0000) GS:ffff88021fd00000(0000) knlGS:0000000000000000
[ 3342.842361] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 3342.842380] CR2: 0000000000b0d000 CR3: 00000001cf402000 CR4: 00000000000007e0
[ 3342.842402] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 3342.842425] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 3342.842448] Process nfsv4.0-svc (pid: 4108, threadinfo ffff8801a680a000, task ffff8802027cf080)
[ 3342.842476] Stack:
[ 3342.842488]  dead000000200200 ffff88020970a000 ffff880215103000 ffff880215726900
[ 3342.842527]  ffff880215726900 ffffffffa007c960 ffff8801a680bfd8 0000000000011280
[ 3342.842568]  ffff8801a680bfd8 ffff88020970a000 ffff88020970a000 ffff8801a680bf08
[ 3342.842608] Call Trace:
[ 3342.842644]  [<ffffffffa007c960>] ? svc_recv+0xcc/0x338 [sunrpc]
[ 3342.842678]  [<ffffffffa0488000>] ? nfs_callback_authenticate+0x20/0x20 [nfsv4]
[ 3342.842712]  [<ffffffffa048801d>] ? nfs4_callback_svc+0x1d/0x3c [nfsv4]
[ 3342.842739]  [<ffffffff8103dcf9>] ? kthread+0x81/0x89
[ 3342.842763]  [<ffffffff81040101>] ? posix_cpu_nsleep_restart+0x11/0x89
[ 3342.842787]  [<ffffffff8103dc78>] ? kthread_freezable_should_stop+0x31/0x31
[ 3342.842813]  [<ffffffff8130302c>] ? ret_from_fork+0x7c/0xb0
[ 3342.842835]  [<ffffffff8103dc78>] ? kthread_freezable_should_stop+0x31/0x31
[ 3342.842856] Code: c2 84 d2 74 02 eb a0 c3 41 55 4c 8d 6f 38 41 54 4c 89 ee 55 53 48 89 fb 51 48
8b 6f 40 bf 06 00 00 00 e8 62 fa ff ff 85 c0 74 02 <0f> 0b 48 8b 43 08 4c 8d 65 10 48 89 df ff 50 38
4c 89 e7 e8 2a
[ 3342.843192] RIP  [<ffffffffa007ba6e>] svc_delete_xprt+0x23/0xf3 [sunrpc]
[ 3342.843235]  RSP <ffff8801a680be38>
[ 3342.858471] ---[ end trace f0dbe9f9cd4029c3 ]---

Re: BUG at net/sunrpc/svc_xprt.c:921

[Stanislav Kinsbursky]

18.01.2013 19:56, J. Bruce Fields пишет:
> On Fri, Jan 18, 2013 at 10:48:02AM -0500, Mark Lord wrote:
>> On 13-01-18 12:37 AM, Stanislav Kinsbursky wrote:
>>>
>>> You have more than one NFS mount in different network namespaces, haven't you?
>>>
>>
>> No, I don't (knowingly) use (multiple) namespaces at all.
>
> Right, I don't think that's necessary.  Stanislav, look at
> nfs_callback_down:
>
> 	nfs_callback_down_net(minorversion, cb_info->serv, net);
>          cb_info->users--;
> 	if (cb_info->users == 0 && cb_info->task != NULL) {
> 		kthread_stop(cb_info->task);
> 		...
>
> It's first destroying the service, then destroying the thread.  That's
> the wrong order.  So we could still have the thread running svc_recv()
> after the rpc service is destroyed.
>

Sad, but no, this can't be done that easy in the way you are proposing. Have a look at lock_down_net() - it works in the same manner.
Moreover, service shutdown was significantly reworked to support work across multiple namespaces. We, actually, came to this solution in one of our previous 
discussions in the past because we were trying to reduce number of running threads and used memory for such non-heavily used services like lockd and nfs 
callback. And existent approach works good enough except in-progress transports.

Now we can't just move  shutdown thread after transports because other problems will arise (BUG_ON() in svc_destroy will trigger and that's just the beginning). 
I.e. to make it possible to shutdown service before transports, service should be rewritten to work in network namespace context (but not across all namespaces).


> --b.
>
>> Usually I disable them in the kernel .config,
>> though it appears the currently running kernel has this:
>>
>> CONFIG_NAMESPACES=y
>> # CONFIG_UTS_NS is not set
>> # CONFIG_IPC_NS is not set
>> # CONFIG_PID_NS is not set
>> # CONFIG_NET_NS is not set
>>
>> The full .config was attached to the first post in this thread.
>>
>> Cheers
>>


-- 
Best regards,
Stanislav Kinsbursky

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[J. Bruce Fields]

On Sun, Jan 20, 2013 at 05:51:12PM -0500, Mark Lord wrote:
> Got it again, this time on a different system
> running mostly the same software.

Mark, Paweł, Tom, could any of you confirm whether this helps?

--b.

diff --git a/net/sunrpc/svc.c b/net/sunrpc/svc.c
index dbf12ac..2d34b6b 100644
--- a/net/sunrpc/svc.c
+++ b/net/sunrpc/svc.c
@@ -515,15 +515,6 @@ EXPORT_SYMBOL_GPL(svc_create_pooled);
 
 void svc_shutdown_net(struct svc_serv *serv, struct net *net)
 {
-	/*
-	 * The set of xprts (contained in the sv_tempsocks and
-	 * sv_permsocks lists) is now constant, since it is modified
-	 * only by accepting new sockets (done by service threads in
-	 * svc_recv) or aging old ones (done by sv_temptimer), or
-	 * configuration changes (excluded by whatever locking the
-	 * caller is using--nfsd_mutex in the case of nfsd).  So it's
-	 * safe to traverse those lists and shut everything down:
-	 */
 	svc_close_net(serv, net);
 
 	if (serv->sv_shutdown)
diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index b8e47fa..ca71056 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -856,7 +856,6 @@ static void svc_age_temp_xprts(unsigned long closure)
 	struct svc_serv *serv = (struct svc_serv *)closure;
 	struct svc_xprt *xprt;
 	struct list_head *le, *next;
-	LIST_HEAD(to_be_aged);
 
 	dprintk("svc_age_temp_xprts\n");
 
@@ -877,25 +876,15 @@ static void svc_age_temp_xprts(unsigned long closure)
 		if (atomic_read(&xprt->xpt_ref.refcount) > 1 ||
 		    test_bit(XPT_BUSY, &xprt->xpt_flags))
 			continue;
-		svc_xprt_get(xprt);
-		list_move(le, &to_be_aged);
+		list_del_init(le);
 		set_bit(XPT_CLOSE, &xprt->xpt_flags);
 		set_bit(XPT_DETACHED, &xprt->xpt_flags);
-	}
-	spin_unlock_bh(&serv->sv_lock);
-
-	while (!list_empty(&to_be_aged)) {
-		le = to_be_aged.next;
-		/* fiddling the xpt_list node is safe 'cos we're XPT_DETACHED */
-		list_del_init(le);
-		xprt = list_entry(le, struct svc_xprt, xpt_list);
-
 		dprintk("queuing xprt %p for closing\n", xprt);
 
 		/* a thread will dequeue and close it soon */
 		svc_xprt_enqueue(xprt);
-		svc_xprt_put(xprt);
 	}
+	spin_unlock_bh(&serv->sv_lock);
 
 	mod_timer(&serv->sv_temptimer, jiffies + svc_conn_age_period * HZ);
 }
@@ -959,21 +948,24 @@ void svc_close_xprt(struct svc_xprt *xprt)
 }
 EXPORT_SYMBOL_GPL(svc_close_xprt);
 
-static void svc_close_list(struct svc_serv *serv, struct list_head *xprt_list, struct net *net)
+static int svc_close_list(struct svc_serv *serv, struct list_head *xprt_list, struct net *net)
 {
 	struct svc_xprt *xprt;
+	int ret = 0;
 
 	spin_lock(&serv->sv_lock);
 	list_for_each_entry(xprt, xprt_list, xpt_list) {
 		if (xprt->xpt_net != net)
 			continue;
+		ret++;
 		set_bit(XPT_CLOSE, &xprt->xpt_flags);
-		set_bit(XPT_BUSY, &xprt->xpt_flags);
+		svc_xprt_enqueue(xprt);
 	}
 	spin_unlock(&serv->sv_lock);
+	return ret;
 }
 
-static void svc_clear_pools(struct svc_serv *serv, struct net *net)
+static struct svc_xprt *svc_dequeue_net(struct svc_serv *serv, struct net *net)
 {
 	struct svc_pool *pool;
 	struct svc_xprt *xprt;
@@ -988,42 +980,46 @@ static void svc_clear_pools(struct svc_serv *serv, struct net *net)
 			if (xprt->xpt_net != net)
 				continue;
 			list_del_init(&xprt->xpt_ready);
+			spin_unlock_bh(&pool->sp_lock);
+			return xprt;
 		}
 		spin_unlock_bh(&pool->sp_lock);
 	}
+	return NULL;
 }
 
-static void svc_clear_list(struct svc_serv *serv, struct list_head *xprt_list, struct net *net)
+static void svc_clean_up_xprts(struct svc_serv *serv, struct net *net)
 {
 	struct svc_xprt *xprt;
-	struct svc_xprt *tmp;
-	LIST_HEAD(victims);
-
-	spin_lock(&serv->sv_lock);
-	list_for_each_entry_safe(xprt, tmp, xprt_list, xpt_list) {
-		if (xprt->xpt_net != net)
-			continue;
-		list_move(&xprt->xpt_list, &victims);
-	}
-	spin_unlock(&serv->sv_lock);
 
-	list_for_each_entry_safe(xprt, tmp, &victims, xpt_list)
+	while ((xprt = svc_dequeue_net(serv, net))) {
+		set_bit(XPT_CLOSE, &xprt->xpt_flags);
 		svc_delete_xprt(xprt);
+	}
 }
 
+/*
+ * Server threads may still be running (especially in the case where the
+ * service is still running in other network namespaces).
+ *
+ * So we shut down sockets the same way we would on a running server, by
+ * setting XPT_CLOSE, enqueuing, and letting a thread pick it up to do
+ * the close.  In the case there are no such other threads,
+ * threads running, svc_clean_up_xprts() does a simple version of a
+ * server's main event loop, and in the case where there are other
+ * threads, we may need to wait a little while and then check again to
+ * see if they're done.
+ */
 void svc_close_net(struct svc_serv *serv, struct net *net)
 {
-	svc_close_list(serv, &serv->sv_tempsocks, net);
-	svc_close_list(serv, &serv->sv_permsocks, net);
+	int delay = 0;
 
-	svc_clear_pools(serv, net);
-	/*
-	 * At this point the sp_sockets lists will stay empty, since
-	 * svc_xprt_enqueue will not add new entries without taking the
-	 * sp_lock and checking XPT_BUSY.
-	 */
-	svc_clear_list(serv, &serv->sv_tempsocks, net);
-	svc_clear_list(serv, &serv->sv_permsocks, net);
+	while (svc_close_list(serv, &serv->sv_permsocks, net) +
+	       svc_close_list(serv, &serv->sv_tempsocks, net)) {
+
+		svc_clean_up_xprts(serv, net);
+		msleep(delay++);
+	}
 }
 
 /*

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[Mark Lord]

On 13-02-12 03:52 PM, J. Bruce Fields wrote:
> On Sun, Jan 20, 2013 at 05:51:12PM -0500, Mark Lord wrote:
>> Got it again, this time on a different system
>> running mostly the same software.
> 
> Mark, Paweł, Tom, could any of you confirm whether this helps?
..

No, I cannot confirm one way or the other,
because I haven't noticed it again since the most recent
couple of occurrences I posted earlier here.

Cheers

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[J. Bruce Fields]

On Wed, Feb 13, 2013 at 10:00:58AM -0500, Mark Lord wrote:
> On 13-02-12 03:52 PM, J. Bruce Fields wrote:
> > On Sun, Jan 20, 2013 at 05:51:12PM -0500, Mark Lord wrote:
> >> Got it again, this time on a different system
> >> running mostly the same software.
> > 
> > Mark, Paweł, Tom, could any of you confirm whether this helps?
> ..
> 
> No, I cannot confirm one way or the other,
> because I haven't noticed it again since the most recent
> couple of occurrences I posted earlier here.

OK, I do have at least one report of someone who saw the bug before
running for a day without seeing it:

	https://bugzilla.redhat.com/show_bug.cgi?id=910457

Any more reports positive or negative welcome.

This looks like it should solve the problem, so for now I intend to
commit the following.

--b.

[PATCH 1/2] svcrpc: make svc_age_temp_xprts enqueue under sv_lock

[J. Bruce Fields]

svc_age_temp_xprts expires xprts in a two-step process: first it takes
the sv_lock and moves the xprts to expire off their server-wide list
(sv_tempsocks or sv_permsocks) to a local list.  Then it drops the
sv_lock and enqueues and puts each one.

I see no reason for this: svc_xprt_enqueue() will take sp_lock, but the
sv_lock and sp_lock are not otherwise nested anywhere (and documentation
at the top of this file claims it's correct to nest these with sp_lock
inside.)

Cc: stable@kernel.org
Tested-by: Jason Tibbitts <tibbs@math.uh.edu>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
---
 net/sunrpc/svc_xprt.c |   15 ++-------------
 1 file changed, 2 insertions(+), 13 deletions(-)

diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index 5a9d40c..11a33c8 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -863,7 +863,6 @@ static void svc_age_temp_xprts(unsigned long closure)
 	struct svc_serv *serv = (struct svc_serv *)closure;
 	struct svc_xprt *xprt;
 	struct list_head *le, *next;
-	LIST_HEAD(to_be_aged);
 
 	dprintk("svc_age_temp_xprts\n");
 
@@ -884,25 +883,15 @@ static void svc_age_temp_xprts(unsigned long closure)
 		if (atomic_read(&xprt->xpt_ref.refcount) > 1 ||
 		    test_bit(XPT_BUSY, &xprt->xpt_flags))
 			continue;
-		svc_xprt_get(xprt);
-		list_move(le, &to_be_aged);
+		list_del_init(le);
 		set_bit(XPT_CLOSE, &xprt->xpt_flags);
 		set_bit(XPT_DETACHED, &xprt->xpt_flags);
-	}
-	spin_unlock_bh(&serv->sv_lock);
-
-	while (!list_empty(&to_be_aged)) {
-		le = to_be_aged.next;
-		/* fiddling the xpt_list node is safe 'cos we're XPT_DETACHED */
-		list_del_init(le);
-		xprt = list_entry(le, struct svc_xprt, xpt_list);
-
 		dprintk("queuing xprt %p for closing\n", xprt);
 
 		/* a thread will dequeue and close it soon */
 		svc_xprt_enqueue(xprt);
-		svc_xprt_put(xprt);
 	}
+	spin_unlock_bh(&serv->sv_lock);
 
 	mod_timer(&serv->sv_temptimer, jiffies + svc_conn_age_period * HZ);
 }
-- 
1.7.9.5

[PATCH 2/2] svcrpc: fix rpc server shutdown races

[J. Bruce Fields]

Rewrite server shutdown to remove the assumption that there are no
longer any threads running (no longer true, for example, when shutting
down the service in one network namespace while it's still running in
others).

Do that by doing what we'd do in normal circumstances: just CLOSE each
socket, then enqueue it.

Since there may not be threads to handle the resulting queued xprts,
also run a simplified version of the svc_recv() loop run by a server to
clean up any closed xprts afterwards.

Cc: stable@kernel.org
Tested-by: Jason Tibbitts <tibbs@math.uh.edu>
Acked-by: Stanislav Kinsbursky <skinsbursky@parallels.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
---
 net/sunrpc/svc.c      |    9 --------
 net/sunrpc/svc_xprt.c |   57 +++++++++++++++++++++++++++----------------------
 2 files changed, 32 insertions(+), 34 deletions(-)

diff --git a/net/sunrpc/svc.c b/net/sunrpc/svc.c
index b9ba2a8..89a588b 100644
--- a/net/sunrpc/svc.c
+++ b/net/sunrpc/svc.c
@@ -515,15 +515,6 @@ EXPORT_SYMBOL_GPL(svc_create_pooled);
 
 void svc_shutdown_net(struct svc_serv *serv, struct net *net)
 {
-	/*
-	 * The set of xprts (contained in the sv_tempsocks and
-	 * sv_permsocks lists) is now constant, since it is modified
-	 * only by accepting new sockets (done by service threads in
-	 * svc_recv) or aging old ones (done by sv_temptimer), or
-	 * configuration changes (excluded by whatever locking the
-	 * caller is using--nfsd_mutex in the case of nfsd).  So it's
-	 * safe to traverse those lists and shut everything down:
-	 */
 	svc_close_net(serv, net);
 
 	if (serv->sv_shutdown)
diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
index 11a33c8..80a6640 100644
--- a/net/sunrpc/svc_xprt.c
+++ b/net/sunrpc/svc_xprt.c
@@ -955,21 +955,24 @@ void svc_close_xprt(struct svc_xprt *xprt)
 }
 EXPORT_SYMBOL_GPL(svc_close_xprt);
 
-static void svc_close_list(struct svc_serv *serv, struct list_head *xprt_list, struct net *net)
+static int svc_close_list(struct svc_serv *serv, struct list_head *xprt_list, struct net *net)
 {
 	struct svc_xprt *xprt;
+	int ret = 0;
 
 	spin_lock(&serv->sv_lock);
 	list_for_each_entry(xprt, xprt_list, xpt_list) {
 		if (xprt->xpt_net != net)
 			continue;
+		ret++;
 		set_bit(XPT_CLOSE, &xprt->xpt_flags);
-		set_bit(XPT_BUSY, &xprt->xpt_flags);
+		svc_xprt_enqueue(xprt);
 	}
 	spin_unlock(&serv->sv_lock);
+	return ret;
 }
 
-static void svc_clear_pools(struct svc_serv *serv, struct net *net)
+static struct svc_xprt *svc_dequeue_net(struct svc_serv *serv, struct net *net)
 {
 	struct svc_pool *pool;
 	struct svc_xprt *xprt;
@@ -984,42 +987,46 @@ static void svc_clear_pools(struct svc_serv *serv, struct net *net)
 			if (xprt->xpt_net != net)
 				continue;
 			list_del_init(&xprt->xpt_ready);
+			spin_unlock_bh(&pool->sp_lock);
+			return xprt;
 		}
 		spin_unlock_bh(&pool->sp_lock);
 	}
+	return NULL;
 }
 
-static void svc_clear_list(struct svc_serv *serv, struct list_head *xprt_list, struct net *net)
+static void svc_clean_up_xprts(struct svc_serv *serv, struct net *net)
 {
 	struct svc_xprt *xprt;
-	struct svc_xprt *tmp;
-	LIST_HEAD(victims);
-
-	spin_lock(&serv->sv_lock);
-	list_for_each_entry_safe(xprt, tmp, xprt_list, xpt_list) {
-		if (xprt->xpt_net != net)
-			continue;
-		list_move(&xprt->xpt_list, &victims);
-	}
-	spin_unlock(&serv->sv_lock);
 
-	list_for_each_entry_safe(xprt, tmp, &victims, xpt_list)
+	while ((xprt = svc_dequeue_net(serv, net))) {
+		set_bit(XPT_CLOSE, &xprt->xpt_flags);
 		svc_delete_xprt(xprt);
+	}
 }
 
+/*
+ * Server threads may still be running (especially in the case where the
+ * service is still running in other network namespaces).
+ *
+ * So we shut down sockets the same way we would on a running server, by
+ * setting XPT_CLOSE, enqueuing, and letting a thread pick it up to do
+ * the close.  In the case there are no such other threads,
+ * threads running, svc_clean_up_xprts() does a simple version of a
+ * server's main event loop, and in the case where there are other
+ * threads, we may need to wait a little while and then check again to
+ * see if they're done.
+ */
 void svc_close_net(struct svc_serv *serv, struct net *net)
 {
-	svc_close_list(serv, &serv->sv_tempsocks, net);
-	svc_close_list(serv, &serv->sv_permsocks, net);
+	int delay = 0;
 
-	svc_clear_pools(serv, net);
-	/*
-	 * At this point the sp_sockets lists will stay empty, since
-	 * svc_xprt_enqueue will not add new entries without taking the
-	 * sp_lock and checking XPT_BUSY.
-	 */
-	svc_clear_list(serv, &serv->sv_tempsocks, net);
-	svc_clear_list(serv, &serv->sv_permsocks, net);
+	while (svc_close_list(serv, &serv->sv_permsocks, net) +
+	       svc_close_list(serv, &serv->sv_tempsocks, net)) {
+
+		svc_clean_up_xprts(serv, net);
+		msleep(delay++);
+	}
 }
 
 /*
-- 
1.7.9.5

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[Paweł Sikora]

On Tuesday 12 of February 2013 15:52:17 J. Bruce Fields wrote:
> On Sun, Jan 20, 2013 at 05:51:12PM -0500, Mark Lord wrote:
> > Got it again, this time on a different system
> > running mostly the same software.
> 
> Mark, Paweł, Tom, could any of you confirm whether this helps?

with this patch i can confirm a 2 day uptime w/o any oopses.

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[Tom Horsley]

On Fri, 15 Feb 2013 14:22:29 -0500
J. Bruce Fields wrote:

> Any more reports positive or negative welcome.

Well, I don't have the time or energy to try patches on my
system at work, but these seem to be concerned with terminating
an NFS connection. My aborts all happen at boot when it
is trying to do the mount to begin with.

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[J. Bruce Fields]

On Fri, Feb 15, 2013 at 02:42:08PM -0500, Tom Horsley wrote:
> On Fri, 15 Feb 2013 14:22:29 -0500
> J. Bruce Fields wrote:
> 
> > Any more reports positive or negative welcome.
> 
> Well, I don't have the time or energy to try patches on my
> system at work, but these seem to be concerned with terminating
> an NFS connection. My aborts all happen at boot when it
> is trying to do the mount to begin with.

The rpc server it's tearing down is a callback server that runs on the
nfs client.

--b.

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[J. Bruce Fields]

On Fri, Feb 15, 2013 at 08:33:14PM +0100, Paweł Sikora wrote:
> On Tuesday 12 of February 2013 15:52:17 J. Bruce Fields wrote:
> > On Sun, Jan 20, 2013 at 05:51:12PM -0500, Mark Lord wrote:
> > > Got it again, this time on a different system
> > > running mostly the same software.
> > 
> > Mark, Paweł, Tom, could any of you confirm whether this helps?
> 
> with this patch i can confirm a 2 day uptime w/o any oopses.
> 

Thanks for the report.--b.

Re: BUG at net/sunrpc/svc_xprt.c:921 (another one)

[Paweł Sikora]

On Sunday 17 of February 2013 10:54:20 J. Bruce Fields wrote:
> On Fri, Feb 15, 2013 at 08:33:14PM +0100, Paweł Sikora wrote:
> > On Tuesday 12 of February 2013 15:52:17 J. Bruce Fields wrote:
> > > On Sun, Jan 20, 2013 at 05:51:12PM -0500, Mark Lord wrote:
> > > > Got it again, this time on a different system
> > > > running mostly the same software.
> > > 
> > > Mark, Paweł, Tom, could any of you confirm whether this helps?
> > 
> > with this patch i can confirm a 2 day uptime w/o any oopses.
> > 
> 
> Thanks for the report.--b.

please push this patch to the 3.7.y stable kernel.

Re: BUG at net/sunrpc/svc_xprt.c:921

[Mark Lord]

On 13-01-17 08:53 AM, J. Bruce Fields wrote:
> On Thu, Jan 17, 2013 at 08:11:52AM -0500, Mark Lord wrote:
>> On 13-01-14 11:17 AM, Mark Lord wrote:
>>>
>>> Here's the code with the BUG() at net/sunrpc/svc_xprt.c line 921:
>>>
>>> /*
>>>  * Remove a dead transport
>>>  */
>>> static void svc_delete_xprt(struct svc_xprt *xprt)
>>> {
>>>         struct svc_serv *serv = xprt->xpt_server;
>>>         struct svc_deferred_req *dr;
>>>
>>>         /* Only do this once */
>>>         if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
>>>                 BUG();
>>

Saw this again today on 3.7.9 -- dunno if your changes are in that kernel yet though.

Re: BUG at net/sunrpc/svc_xprt.c:921

[J. Bruce Fields]

On Mon, Feb 25, 2013 at 03:45:07PM -0500, Mark Lord wrote:
> On 13-01-17 08:53 AM, J. Bruce Fields wrote:
> > On Thu, Jan 17, 2013 at 08:11:52AM -0500, Mark Lord wrote:
> >> On 13-01-14 11:17 AM, Mark Lord wrote:
> >>>
> >>> Here's the code with the BUG() at net/sunrpc/svc_xprt.c line 921:
> >>>
> >>> /*
> >>>  * Remove a dead transport
> >>>  */
> >>> static void svc_delete_xprt(struct svc_xprt *xprt)
> >>> {
> >>>         struct svc_serv *serv = xprt->xpt_server;
> >>>         struct svc_deferred_req *dr;
> >>>
> >>>         /* Only do this once */
> >>>         if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
> >>>                 BUG();
> >>
> 
> Saw this again today on 3.7.9 -- dunno if your changes are in that kernel yet though.

Nope.  The nfsd changes for 3.9 should get merged in a few days and then
backported to stable kernels not much later.

--b.

Re: BUG at net/sunrpc/svc_xprt.c:921

[J. Bruce Fields]

On Thu, Feb 07, 2013 at 07:56:51AM -0500, Tom Horsley wrote:
> I noticed some previous messages with this subject, but the
> walkback I'm getting doesn't match exactly the ones shown
> in the threads I saw, so I figured I'd send this in.
> 
> This happens on both my Fedora 18 and Fedora 17 partitions
> when mounting filesystems from very old servers that
> need the proto=udp option to talk.
> 
> The redhat bugzilla is here:
> 
> https://bugzilla.redhat.com/show_bug.cgi?id=908451
> 
> There is a photo of the walkback in that bugzilla:
> 
> svc_delete_xprt+0x12a
> svc_recv+0x101
> ? nfs_callback_authenticate+0x50
> nfs4_callback_svc+0x3b
> kthread+0xc0
> ? ftrace_raw_event_xen_mmu_flush_tlb_others+0x50
> ? kthread_create_on_node+0x120
> ret_from_fork+0x7c
> ? kthread_create_on_node+0x120

OK, yes this is the

	if (test_and_set_bit(XPT_DEAD, &xprt->xpt_flags))
	      BUG();

in svc_delete_xprt() and is a known (but unfixed) problem.  Stanislav
has some patches, that should be fixed soon....

--b.

BUG at net/sunrpc/svc_xprt.c:921

[Tom Horsley]

I noticed some previous messages with this subject, but the
walkback I'm getting doesn't match exactly the ones shown
in the threads I saw, so I figured I'd send this in.

This happens on both my Fedora 18 and Fedora 17 partitions
when mounting filesystems from very old servers that
need the proto=udp option to talk.

The redhat bugzilla is here:

https://bugzilla.redhat.com/show_bug.cgi?id=908451

There is a photo of the walkback in that bugzilla:

svc_delete_xprt+0x12a
svc_recv+0x101
? nfs_callback_authenticate+0x50
nfs4_callback_svc+0x3b
kthread+0xc0
? ftrace_raw_event_xen_mmu_flush_tlb_others+0x50
? kthread_create_on_node+0x120
ret_from_fork+0x7c
? kthread_create_on_node+0x120