2010-11-01 18:07:41

by Chuck Lever

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs


On Nov 1, 2010, at 1:58 PM, Nick Bowler wrote:

> After installing 2.6.37-rc1, attempting to use sqlite in any capacity on
> NFS gives a locking error:
>
> % echo 'select * from blah;' | sqlite3 blah.sqlite
> Error: near line 1: database is locked
>
> % echo 'create table blargh(INT);' | sqlite3 blargh.sqlite
> Error: near line 1: database is locked
>
> The result is that a lot of high-profile applications which make use of
> sqlite fail mysteriously. Bisection reveals the following, and
> reverting the implicated commit solves the issue:

Nick, thanks for the report. Is 2.6.37-rc1 running on your clients or on your server? Does anything interesting appear in the kernel log when your test case fails?

> 9247685088398cf21bcb513bd2832b4cd42516c4 is the first bad commit
> commit 9247685088398cf21bcb513bd2832b4cd42516c4
> Author: Chuck Lever <[email protected]>
> Date: Wed Oct 20 11:53:01 2010 -0400
>
> SUNRPC: Properly initialize sock_xprt.srcaddr in all cases
>
> The source address field in the transport's sock_xprt is initialized
> ONLY IF the RPC application passed a pointer to a source address
> during the call to rpc_create(). However, xs_bind() subsequently uses
> the value of this field without regard to whether the source address
> was initialized during transport creation or not.
>
> So far we've been lucky: the uninitialized value of this field is
> zeroes. xs_bind(), until recently, used only the sin[6]_addr field in
> this sockaddr, and all zeroes is a valid value for this: it means
> ANYADDR. This is a happy coincidence.
>
> However, xs_bind() now wants to use the sa_family field as well, and
> expects it to be initialized to something other than zero.
>
> Therefore, the source address sockaddr field should be fully
> initialized at transport create time in _every_ case, not just when
> the RPC application wants to use a specific bind address.
>
> Bruce added a workaround for this missing initialization by adjusting
> commit 6bc9638a, but the "right" way to do this is to ensure that the
> source address sockaddr is always correctly initialized from the
> get-go.
>
> This patch doesn't introduce a behavior change. It's simply a
> clean-up of Bruce's fix, to prevent future problems of this kind. It
> may look like overkill, but
>
> a) it clearly documents the default initial value of this field,
>
> b) it doesn't assume that the sockaddr_storage memory is first
> initialized to any particular value, and
>
> c) it will fail verbosely if some unknown address family is passed
> in
>
> Originally introduced by commit d3bc9a1d.
>
> Signed-off-by: Chuck Lever <[email protected]>
> Signed-off-by: J. Bruce Fields <[email protected]>
>
> :040000 040000 843e2423b5a45f7bc13b9e30cc8e5bcb072dbb8f 7148b5256ce78fd5c98a01f1bdcac46faa80f773 M net
>
> git bisect start
> # bad: [c8ddb2713c624f432fa5fe3c7ecffcdda46ea0d4] Linux 2.6.37-rc1
> git bisect bad c8ddb2713c624f432fa5fe3c7ecffcdda46ea0d4
> # good: [f6f94e2ab1b33f0082ac22d71f66385a60d8157f] Linux 2.6.36
> git bisect good f6f94e2ab1b33f0082ac22d71f66385a60d8157f
> # good: [33081adf8b89d5a716d7e1c60171768d39795b39] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound-2.6
> git bisect good 33081adf8b89d5a716d7e1c60171768d39795b39
> # bad: [00ebb6382b8d9c7c15b5f8ad230670d8161d38dd] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/cjb/mmc
> git bisect bad 00ebb6382b8d9c7c15b5f8ad230670d8161d38dd
> # bad: [520045db940a381d2bee1c1b2179f7921b40fb10] Merge branches 'upstream/xenfs' and 'upstream/core' of git://git.kernel.org/pub/scm/linux/kernel/git/jeremy/xen
> git bisect bad 520045db940a381d2bee1c1b2179f7921b40fb10
> # bad: [4390110fef9e5c64e10c6ca19d586932242c9a8a] Merge branch 'for-2.6.37' of git://linux-nfs.org/~bfields/linux
> git bisect bad 4390110fef9e5c64e10c6ca19d586932242c9a8a
> # good: [7b6181e06841f5ad15c4ff708b967b4db65a64de] Merge branch 'omap-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tmlind/linux-omap-2.6
> git bisect good 7b6181e06841f5ad15c4ff708b967b4db65a64de
> # good: [e0e170bd7ded2ec16e2813d63c0faff43193fde8] Merge branch 'next' of git://git.monstr.eu/linux-2.6-microblaze
> git bisect good e0e170bd7ded2ec16e2813d63c0faff43193fde8
> # good: [22f793268de3b4dff8abfcd873ba7afc1f34224f] sunrpc: Factor out v4 sockets creation
> git bisect good 22f793268de3b4dff8abfcd873ba7afc1f34224f
> # good: [a4dd8dce14014665862ce7911b38cb2c69e366dd] Merge branch 'nfs-for-2.6.37' of git://git.linux-nfs.org/projects/trondmy/nfs-2.6
> git bisect good a4dd8dce14014665862ce7911b38cb2c69e366dd
> # bad: [cd5b814458e5554457c6e62f17aed122145b065e] nfsd4: don't cache seq_misordered replies
> git bisect bad cd5b814458e5554457c6e62f17aed122145b065e
> # good: [8c14ff2aaf26d58aa2258a59bd419c906d105938] sunrpc: Remove UDP worker wrappers
> git bisect good 8c14ff2aaf26d58aa2258a59bd419c906d105938
> # good: [8f3a6de313391b6910aa7db185eb9f3e930a51cf] sunrpc: Turn list_for_each-s into the ..._entry-s
> git bisect good 8f3a6de313391b6910aa7db185eb9f3e930a51cf
> # good: [4232e8634ad82c5a53389e4016de15a8b15c09c3] SUNRPC: Use conventional switch statement when reclassifying sockets
> git bisect good 4232e8634ad82c5a53389e4016de15a8b15c09c3
> # bad: [9247685088398cf21bcb513bd2832b4cd42516c4] SUNRPC: Properly initialize sock_xprt.srcaddr in all cases
> git bisect bad 9247685088398cf21bcb513bd2832b4cd42516c4
>
> --
> Nick Bowler, Elliptic Technologies (http://www.elliptictech.com/)

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com






2010-11-01 19:48:51

by Myklebust, Trond

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On Mon, 2010-11-01 at 15:45 -0400, Chuck Lever wrote:
> On Nov 1, 2010, at 3:42 PM, Trond Myklebust wrote:
>
> > On Mon, 2010-11-01 at 15:22 -0400, Trond Myklebust wrote:
> >> I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
> >> thing in the kernel that actually sets this 'srcaddr' field, and it sets
> >> it to
> >>
> >> const struct sockaddr source = {
> >> .sa_family = AF_UNSPEC,
> >> };
> >>
> >> You triggered the bug by removing the line
> >>
> >> transport->srcaddr.ss_family = family;
> >>
> >> from xs_create_sock().
> >>
> >> Trond
> >
> > Does this fix the regression?
> >
> > Trond
> >
> > ----------------------------------------------------------------------------------------------
> > NLM: Fix a regression in lockd
> >
> > From: Trond Myklebust <[email protected]>
> >
> > Nick Bowler reports:
> > There are no unusual messages on the client... but I just logged into
> > the server and I see lots of messages of the following form:
> >
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> >
> > Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
> > Properly initialize sock_xprt.srcaddr in all cases)
> >
> > Apparently, removing the 'transport->srcaddr.ss_family = family' from
> > xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
> > initialising the srcaddr family to AF_UNSPEC.
> >
> > Reported-by: Nick Bowler <[email protected]>
> > Signed-off-by: Trond Myklebust <[email protected]>
> > ---
> >
> > fs/lockd/host.c | 5 -----
> > 1 files changed, 0 insertions(+), 5 deletions(-)
> >
> >
> > diff --git a/fs/lockd/host.c b/fs/lockd/host.c
> > index 25e21e4..9ff0c0e 100644
> > --- a/fs/lockd/host.c
> > +++ b/fs/lockd/host.c
> > @@ -238,9 +238,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
> > const char *hostname,
> > int noresvport)
> > {
> > - const struct sockaddr source = {
> > - .sa_family = AF_UNSPEC,
> > - };
> > struct nlm_lookup_host_info ni = {
> > .server = 0,
> > .sap = sap,
> > @@ -249,8 +246,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
> > .version = version,
> > .hostname = hostname,
> > .hostname_len = strlen(hostname),
> > - .src_sap = &source,
> > - .src_len = sizeof(source),
> > .noresvport = noresvport,
> > };
> >
> >
>
>
> What about that memcpy() in nlm_lookup_host()? With this patch, wouldn't it be copying garbage into the host's srcaddr field?
>

It shouldn't. ni->src_len is now zero.

Trond

2010-11-01 19:24:05

by Myklebust, Trond

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On Mon, 2010-11-01 at 14:30 -0400, Chuck Lever wrote:
> On Nov 1, 2010, at 2:19 PM, Nick Bowler wrote:
>
> > On 2010-11-01 14:07 -0400, Chuck Lever wrote:
> >> On Nov 1, 2010, at 1:58 PM, Nick Bowler wrote:
> >>> After installing 2.6.37-rc1, attempting to use sqlite in any capacity on
> >>> NFS gives a locking error:
> >>>
> >>> % echo 'select * from blah;' | sqlite3 blah.sqlite
> >>> Error: near line 1: database is locked
> >>>
> >>> % echo 'create table blargh(INT);' | sqlite3 blargh.sqlite
> >>> Error: near line 1: database is locked
> >>>
> >>> The result is that a lot of high-profile applications which make use of
> >>> sqlite fail mysteriously. Bisection reveals the following, and
> >>> reverting the implicated commit solves the issue:
> >>
> >> Nick, thanks for the report. Is 2.6.37-rc1 running on your clients or
> >> on your server?
> >
> > Sorry for not being clear: the client is running 2.6.37-rc1. The
> > server is running RHEL 5.5.
> >
> >> Does anything interesting appear in the kernel log when your test case
> >> fails?
> >
> > There are no unusual messages on the client... but I just logged into
> > the server and I see lots of messages of the following form:
> >
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> > nfsd: request from insecure port (192.168.8.199:35766)!
> >
> > (192.168.8.199 is the address of the failing client). I can only assume
> > that these are a result of my recent issues, since I don't have access
> > to the system log (with timestamps) on that machine.
>
> That's the problem this patch is supposed to prevent. I'll investigate further.
>

I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
thing in the kernel that actually sets this 'srcaddr' field, and it sets
it to

const struct sockaddr source = {
.sa_family = AF_UNSPEC,
};

You triggered the bug by removing the line

transport->srcaddr.ss_family = family;

from xs_create_sock().

Trond

2010-11-01 19:56:11

by Chuck Lever

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs


On Nov 1, 2010, at 3:48 PM, Trond Myklebust wrote:

> On Mon, 2010-11-01 at 15:45 -0400, Chuck Lever wrote:
>> On Nov 1, 2010, at 3:42 PM, Trond Myklebust wrote:
>>
>>> On Mon, 2010-11-01 at 15:22 -0400, Trond Myklebust wrote:
>>>> I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
>>>> thing in the kernel that actually sets this 'srcaddr' field, and it sets
>>>> it to
>>>>
>>>> const struct sockaddr source = {
>>>> .sa_family = AF_UNSPEC,
>>>> };
>>>>
>>>> You triggered the bug by removing the line
>>>>
>>>> transport->srcaddr.ss_family = family;
>>>>
>>>> from xs_create_sock().
>>>>
>>>> Trond
>>>
>>> Does this fix the regression?
>>>
>>> Trond
>>>
>>> ----------------------------------------------------------------------------------------------
>>> NLM: Fix a regression in lockd
>>>
>>> From: Trond Myklebust <[email protected]>
>>>
>>> Nick Bowler reports:
>>> There are no unusual messages on the client... but I just logged into
>>> the server and I see lots of messages of the following form:
>>>
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>>
>>> Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
>>> Properly initialize sock_xprt.srcaddr in all cases)
>>>
>>> Apparently, removing the 'transport->srcaddr.ss_family = family' from
>>> xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
>>> initialising the srcaddr family to AF_UNSPEC.
>>>
>>> Reported-by: Nick Bowler <[email protected]>
>>> Signed-off-by: Trond Myklebust <[email protected]>
>>> ---
>>>
>>> fs/lockd/host.c | 5 -----
>>> 1 files changed, 0 insertions(+), 5 deletions(-)
>>>
>>>
>>> diff --git a/fs/lockd/host.c b/fs/lockd/host.c
>>> index 25e21e4..9ff0c0e 100644
>>> --- a/fs/lockd/host.c
>>> +++ b/fs/lockd/host.c
>>> @@ -238,9 +238,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
>>> const char *hostname,
>>> int noresvport)
>>> {
>>> - const struct sockaddr source = {
>>> - .sa_family = AF_UNSPEC,
>>> - };
>>> struct nlm_lookup_host_info ni = {
>>> .server = 0,
>>> .sap = sap,
>>> @@ -249,8 +246,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
>>> .version = version,
>>> .hostname = hostname,
>>> .hostname_len = strlen(hostname),
>>> - .src_sap = &source,
>>> - .src_len = sizeof(source),
>>> .noresvport = noresvport,
>>> };
>>>
>>>
>>
>>
>> What about that memcpy() in nlm_lookup_host()? With this patch, wouldn't it be copying garbage into the host's srcaddr field?
>>
>
> It shouldn't. ni->src_len is now zero.

Yech. All this still assumes that ANYADDR is all zeroes, and that the memory this is going into is already initialized to zeroes. It's asking for trouble if we re-arrange all this someday.

I've got an untested one line patch that should fix this for any upper layer caller. Posting now.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com





2010-11-01 20:10:20

by Myklebust, Trond

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On Mon, 2010-11-01 at 15:48 -0400, Trond Myklebust wrote:
> On Mon, 2010-11-01 at 15:45 -0400, Chuck Lever wrote:
> > What about that memcpy() in nlm_lookup_host()? With this patch, wouldn't it be copying garbage into the host's srcaddr field?
> >
>
> It shouldn't. ni->src_len is now zero.
>

Urgh, but nlmclnt_bind_host() will still set .saddress.

OK. Here is take 2 of the patch...

Trond
---------------------------------------------------------------------------------------------------------------
NLM: Fix a regression in lockd

From: Trond Myklebust <[email protected]>

Nick Bowler reports:
There are no unusual messages on the client... but I just logged into
the server and I see lots of messages of the following form:

nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!

Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
Properly initialize sock_xprt.srcaddr in all cases)

Apparently, removing the 'transport->srcaddr.ss_family = family' from
xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
initialising the srcaddr family to AF_UNSPEC.

Reported-by: Nick Bowler <[email protected]>
Signed-off-by: Trond Myklebust <[email protected]>
---

fs/lockd/host.c | 11 ++++-------
include/linux/lockd/lockd.h | 1 +
2 files changed, 5 insertions(+), 7 deletions(-)


diff --git a/fs/lockd/host.c b/fs/lockd/host.c
index 25e21e4..cb57092 100644
--- a/fs/lockd/host.c
+++ b/fs/lockd/host.c
@@ -124,7 +124,7 @@ static struct nlm_host *nlm_lookup_host(struct nlm_lookup_host_info *ni)
continue;
if (host->h_server != ni->server)
continue;
- if (ni->server &&
+ if (ni->server && host->h_srcaddrlen != 0 &&
!rpc_cmp_addr(nlm_srcaddr(host), ni->src_sap))
continue;

@@ -167,6 +167,7 @@ static struct nlm_host *nlm_lookup_host(struct nlm_lookup_host_info *ni)
host->h_addrlen = ni->salen;
rpc_set_port(nlm_addr(host), 0);
memcpy(nlm_srcaddr(host), ni->src_sap, ni->src_len);
+ host->h_srcaddrlen = ni->src_len;
host->h_version = ni->version;
host->h_proto = ni->protocol;
host->h_rpcclnt = NULL;
@@ -238,9 +239,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
const char *hostname,
int noresvport)
{
- const struct sockaddr source = {
- .sa_family = AF_UNSPEC,
- };
struct nlm_lookup_host_info ni = {
.server = 0,
.sap = sap,
@@ -249,8 +247,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
.version = version,
.hostname = hostname,
.hostname_len = strlen(hostname),
- .src_sap = &source,
- .src_len = sizeof(source),
.noresvport = noresvport,
};

@@ -357,7 +353,6 @@ nlm_bind_host(struct nlm_host *host)
.protocol = host->h_proto,
.address = nlm_addr(host),
.addrsize = host->h_addrlen,
- .saddress = nlm_srcaddr(host),
.timeout = &timeparms,
.servername = host->h_name,
.program = &nlm_program,
@@ -376,6 +371,8 @@ nlm_bind_host(struct nlm_host *host)
args.flags |= RPC_CLNT_CREATE_HARDRTRY;
if (host->h_noresvport)
args.flags |= RPC_CLNT_CREATE_NONPRIVPORT;
+ if (host->h_srcaddrlen)
+ args.saddress = nlm_srcaddr(host),

clnt = rpc_create(&args);
if (!IS_ERR(clnt))
diff --git a/include/linux/lockd/lockd.h b/include/linux/lockd/lockd.h
index a34dea4..2dee05e 100644
--- a/include/linux/lockd/lockd.h
+++ b/include/linux/lockd/lockd.h
@@ -43,6 +43,7 @@ struct nlm_host {
struct sockaddr_storage h_addr; /* peer address */
size_t h_addrlen;
struct sockaddr_storage h_srcaddr; /* our address (optional) */
+ size_t h_srcaddrlen;
struct rpc_clnt *h_rpcclnt; /* RPC client to talk to peer */
char *h_name; /* remote hostname */
u32 h_version; /* interface version */


2010-11-01 19:43:45

by Chuck Lever

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs


On Nov 1, 2010, at 3:22 PM, Trond Myklebust wrote:

> On Mon, 2010-11-01 at 14:30 -0400, Chuck Lever wrote:
>> On Nov 1, 2010, at 2:19 PM, Nick Bowler wrote:
>>
>>> On 2010-11-01 14:07 -0400, Chuck Lever wrote:
>>>> On Nov 1, 2010, at 1:58 PM, Nick Bowler wrote:
>>>>> After installing 2.6.37-rc1, attempting to use sqlite in any capacity on
>>>>> NFS gives a locking error:
>>>>>
>>>>> % echo 'select * from blah;' | sqlite3 blah.sqlite
>>>>> Error: near line 1: database is locked
>>>>>
>>>>> % echo 'create table blargh(INT);' | sqlite3 blargh.sqlite
>>>>> Error: near line 1: database is locked
>>>>>
>>>>> The result is that a lot of high-profile applications which make use of
>>>>> sqlite fail mysteriously. Bisection reveals the following, and
>>>>> reverting the implicated commit solves the issue:
>>>>
>>>> Nick, thanks for the report. Is 2.6.37-rc1 running on your clients or
>>>> on your server?
>>>
>>> Sorry for not being clear: the client is running 2.6.37-rc1. The
>>> server is running RHEL 5.5.
>>>
>>>> Does anything interesting appear in the kernel log when your test case
>>>> fails?
>>>
>>> There are no unusual messages on the client... but I just logged into
>>> the server and I see lots of messages of the following form:
>>>
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>>
>>> (192.168.8.199 is the address of the failing client). I can only assume
>>> that these are a result of my recent issues, since I don't have access
>>> to the system log (with timestamps) on that machine.
>>
>> That's the problem this patch is supposed to prevent. I'll investigate further.
>>
>
> I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
> thing in the kernel that actually sets this 'srcaddr' field, and it sets
> it to
>
> const struct sockaddr source = {
> .sa_family = AF_UNSPEC,
> };
>
> You triggered the bug by removing the line
>
> transport->srcaddr.ss_family = family;
>
> from xs_create_sock().

Thanks. Actually that line was added by Bruce very recently because Pavel's patches changed xs_bind() so it can't tolerate an AF_UNSPEC address. My patch attempts to replace the workaround with something more permanent... but looks like I didn't find all the places that needed to be fixed.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com





2010-11-01 19:42:32

by Myklebust, Trond

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On Mon, 2010-11-01 at 15:22 -0400, Trond Myklebust wrote:
> I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
> thing in the kernel that actually sets this 'srcaddr' field, and it sets
> it to
>
> const struct sockaddr source = {
> .sa_family = AF_UNSPEC,
> };
>
> You triggered the bug by removing the line
>
> transport->srcaddr.ss_family = family;
>
> from xs_create_sock().
>
> Trond

Does this fix the regression?

Trond

----------------------------------------------------------------------------------------------
NLM: Fix a regression in lockd

From: Trond Myklebust <[email protected]>

Nick Bowler reports:
There are no unusual messages on the client... but I just logged into
the server and I see lots of messages of the following form:

nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!

Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
Properly initialize sock_xprt.srcaddr in all cases)

Apparently, removing the 'transport->srcaddr.ss_family = family' from
xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
initialising the srcaddr family to AF_UNSPEC.

Reported-by: Nick Bowler <[email protected]>
Signed-off-by: Trond Myklebust <[email protected]>
---

fs/lockd/host.c | 5 -----
1 files changed, 0 insertions(+), 5 deletions(-)


diff --git a/fs/lockd/host.c b/fs/lockd/host.c
index 25e21e4..9ff0c0e 100644
--- a/fs/lockd/host.c
+++ b/fs/lockd/host.c
@@ -238,9 +238,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
const char *hostname,
int noresvport)
{
- const struct sockaddr source = {
- .sa_family = AF_UNSPEC,
- };
struct nlm_lookup_host_info ni = {
.server = 0,
.sap = sap,
@@ -249,8 +246,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
.version = version,
.hostname = hostname,
.hostname_len = strlen(hostname),
- .src_sap = &source,
- .src_len = sizeof(source),
.noresvport = noresvport,
};



2010-11-02 14:06:50

by Nick Bowler

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On 2010-11-02 09:14 -0400, Trond Myklebust wrote:
> OK. Can you please try the following? It only differs from the last one
> by a small bugfix, and a WARN_ON() in order to try to catch other
> occurrences of the same bug.
[...]
> NLM: Fix a regression in lockd

Things seem to be working fine now, thanks.

Tested-by: Nick Bowler <[email protected]>

--
Nick Bowler, Elliptic Technologies (http://www.elliptictech.com/)

2010-11-02 13:15:06

by Myklebust, Trond

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On Mon, 2010-11-01 at 16:33 -0400, Nick Bowler wrote:
> On 2010-11-01 16:09 -0400, Trond Myklebust wrote:
> > Urgh, but nlmclnt_bind_host() will still set .saddress.
> >
> > OK. Here is take 2 of the patch...
> [...]
> > NLM: Fix a regression in lockd
>
> Problem occurs with this one (on top of 2.6.37-rc1), too :(
>

OK. Can you please try the following? It only differs from the last one
by a small bugfix, and a WARN_ON() in order to try to catch other
occurrences of the same bug.

Cheers
Trond
------------------------------------------------------------------------------------------------
NLM: Fix a regression in lockd

From: Trond Myklebust <[email protected]>

Nick Bowler reports:
There are no unusual messages on the client... but I just logged into
the server and I see lots of messages of the following form:

nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!

Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
Properly initialize sock_xprt.srcaddr in all cases)

Apparently, removing the 'transport->srcaddr.ss_family = family' from
xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
initialising the srcaddr family to AF_UNSPEC.

Reported-by: Nick Bowler <[email protected]>
Signed-off-by: Trond Myklebust <[email protected]>
---

fs/lockd/host.c | 11 ++++-------
include/linux/lockd/lockd.h | 1 +
net/sunrpc/clnt.c | 2 ++
3 files changed, 7 insertions(+), 7 deletions(-)


diff --git a/fs/lockd/host.c b/fs/lockd/host.c
index 25e21e4..ed0c59f 100644
--- a/fs/lockd/host.c
+++ b/fs/lockd/host.c
@@ -124,7 +124,7 @@ static struct nlm_host *nlm_lookup_host(struct nlm_lookup_host_info *ni)
continue;
if (host->h_server != ni->server)
continue;
- if (ni->server &&
+ if (ni->server && ni->src_len != 0 &&
!rpc_cmp_addr(nlm_srcaddr(host), ni->src_sap))
continue;

@@ -167,6 +167,7 @@ static struct nlm_host *nlm_lookup_host(struct nlm_lookup_host_info *ni)
host->h_addrlen = ni->salen;
rpc_set_port(nlm_addr(host), 0);
memcpy(nlm_srcaddr(host), ni->src_sap, ni->src_len);
+ host->h_srcaddrlen = ni->src_len;
host->h_version = ni->version;
host->h_proto = ni->protocol;
host->h_rpcclnt = NULL;
@@ -238,9 +239,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
const char *hostname,
int noresvport)
{
- const struct sockaddr source = {
- .sa_family = AF_UNSPEC,
- };
struct nlm_lookup_host_info ni = {
.server = 0,
.sap = sap,
@@ -249,8 +247,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
.version = version,
.hostname = hostname,
.hostname_len = strlen(hostname),
- .src_sap = &source,
- .src_len = sizeof(source),
.noresvport = noresvport,
};

@@ -357,7 +353,6 @@ nlm_bind_host(struct nlm_host *host)
.protocol = host->h_proto,
.address = nlm_addr(host),
.addrsize = host->h_addrlen,
- .saddress = nlm_srcaddr(host),
.timeout = &timeparms,
.servername = host->h_name,
.program = &nlm_program,
@@ -376,6 +371,8 @@ nlm_bind_host(struct nlm_host *host)
args.flags |= RPC_CLNT_CREATE_HARDRTRY;
if (host->h_noresvport)
args.flags |= RPC_CLNT_CREATE_NONPRIVPORT;
+ if (host->h_srcaddrlen)
+ args.saddress = nlm_srcaddr(host);

clnt = rpc_create(&args);
if (!IS_ERR(clnt))
diff --git a/include/linux/lockd/lockd.h b/include/linux/lockd/lockd.h
index a34dea4..2dee05e 100644
--- a/include/linux/lockd/lockd.h
+++ b/include/linux/lockd/lockd.h
@@ -43,6 +43,7 @@ struct nlm_host {
struct sockaddr_storage h_addr; /* peer address */
size_t h_addrlen;
struct sockaddr_storage h_srcaddr; /* our address (optional) */
+ size_t h_srcaddrlen;
struct rpc_clnt *h_rpcclnt; /* RPC client to talk to peer */
char *h_name; /* remote hostname */
u32 h_version; /* interface version */
diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index 9dab957..fba8b29 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -322,6 +322,8 @@ struct rpc_clnt *rpc_create(struct rpc_create_args *args)
args->servername = servername;
}

+ WARN_ON(args->saddress && args->saddress->sa_family != args->address->sa_family);
+
xprt = xprt_create_transport(&xprtargs);
if (IS_ERR(xprt))
return (struct rpc_clnt *)xprt;


2010-11-01 21:13:30

by Chuck Lever

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs


On Nov 1, 2010, at 4:35 PM, Trond Myklebust wrote:

> On Mon, 2010-11-01 at 15:55 -0400, Chuck Lever wrote:
>> On Nov 1, 2010, at 3:48 PM, Trond Myklebust wrote:
>>
>>> On Mon, 2010-11-01 at 15:45 -0400, Chuck Lever wrote:
>>>> On Nov 1, 2010, at 3:42 PM, Trond Myklebust wrote:
>>>>
>>>>> On Mon, 2010-11-01 at 15:22 -0400, Trond Myklebust wrote:
>>>>>> I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
>>>>>> thing in the kernel that actually sets this 'srcaddr' field, and it sets
>>>>>> it to
>>>>>>
>>>>>> const struct sockaddr source = {
>>>>>> .sa_family = AF_UNSPEC,
>>>>>> };
>>>>>>
>>>>>> You triggered the bug by removing the line
>>>>>>
>>>>>> transport->srcaddr.ss_family = family;
>>>>>>
>>>>>> from xs_create_sock().
>>>>>>
>>>>>> Trond
>>>>>
>>>>> Does this fix the regression?
>>>>>
>>>>> Trond
>>>>>
>>>>> ----------------------------------------------------------------------------------------------
>>>>> NLM: Fix a regression in lockd
>>>>>
>>>>> From: Trond Myklebust <[email protected]>
>>>>>
>>>>> Nick Bowler reports:
>>>>> There are no unusual messages on the client... but I just logged into
>>>>> the server and I see lots of messages of the following form:
>>>>>
>>>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>>>> nfsd: request from insecure port (192.168.8.199:35766)!
>>>>>
>>>>> Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
>>>>> Properly initialize sock_xprt.srcaddr in all cases)
>>>>>
>>>>> Apparently, removing the 'transport->srcaddr.ss_family = family' from
>>>>> xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
>>>>> initialising the srcaddr family to AF_UNSPEC.
>>>>>
>>>>> Reported-by: Nick Bowler <[email protected]>
>>>>> Signed-off-by: Trond Myklebust <[email protected]>
>>>>> ---
>>>>>
>>>>> fs/lockd/host.c | 5 -----
>>>>> 1 files changed, 0 insertions(+), 5 deletions(-)
>>>>>
>>>>>
>>>>> diff --git a/fs/lockd/host.c b/fs/lockd/host.c
>>>>> index 25e21e4..9ff0c0e 100644
>>>>> --- a/fs/lockd/host.c
>>>>> +++ b/fs/lockd/host.c
>>>>> @@ -238,9 +238,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
>>>>> const char *hostname,
>>>>> int noresvport)
>>>>> {
>>>>> - const struct sockaddr source = {
>>>>> - .sa_family = AF_UNSPEC,
>>>>> - };
>>>>> struct nlm_lookup_host_info ni = {
>>>>> .server = 0,
>>>>> .sap = sap,
>>>>> @@ -249,8 +246,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
>>>>> .version = version,
>>>>> .hostname = hostname,
>>>>> .hostname_len = strlen(hostname),
>>>>> - .src_sap = &source,
>>>>> - .src_len = sizeof(source),
>>>>> .noresvport = noresvport,
>>>>> };
>>>>>
>>>>>
>>>>
>>>>
>>>> What about that memcpy() in nlm_lookup_host()? With this patch, wouldn't it be copying garbage into the host's srcaddr field?
>>>>
>>>
>>> It shouldn't. ni->src_len is now zero.
>>
>> Yech. All this still assumes that ANYADDR is all zeroes, and that the memory this is going into is already initialized to zeroes. It's asking for trouble if we re-arrange all this someday.
>>
>> I've got an untested one line patch that should fix this for any upper layer caller. Posting now.
>>
>
> No! Upper layer callers should simply not be setting .saddress. Pretty
> much the only thing that _should_ be setting .saddress is the lockd
> callback, and possibly the nfsv4 server callback.

Then the take 2 patch description should be updated to reflect your actual intent. I don't think it's especially clear from your patch description why "nlmclnt_lookup_host() ... initialising the srcaddr family to AF_UNSPEC" is incorrect from an architectural standpoint. The specifics of "fixing bad behavior" are obvious already, but the architectural problem needs to be documented.

Otherwise I'm OK with the general idea of take 2, since it passes in a NULL pointer when no special bind address is desired, as other callers of rpc_create() do. Of course, take 2 has to pass Nick's test case too.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com





2010-11-01 18:19:40

by Nick Bowler

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On 2010-11-01 14:07 -0400, Chuck Lever wrote:
> On Nov 1, 2010, at 1:58 PM, Nick Bowler wrote:
> > After installing 2.6.37-rc1, attempting to use sqlite in any capacity on
> > NFS gives a locking error:
> >
> > % echo 'select * from blah;' | sqlite3 blah.sqlite
> > Error: near line 1: database is locked
> >
> > % echo 'create table blargh(INT);' | sqlite3 blargh.sqlite
> > Error: near line 1: database is locked
> >
> > The result is that a lot of high-profile applications which make use of
> > sqlite fail mysteriously. Bisection reveals the following, and
> > reverting the implicated commit solves the issue:
>
> Nick, thanks for the report. Is 2.6.37-rc1 running on your clients or
> on your server?

Sorry for not being clear: the client is running 2.6.37-rc1. The
server is running RHEL 5.5.

> Does anything interesting appear in the kernel log when your test case
> fails?

There are no unusual messages on the client... but I just logged into
the server and I see lots of messages of the following form:

nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!
nfsd: request from insecure port (192.168.8.199:35766)!

(192.168.8.199 is the address of the failing client). I can only assume
that these are a result of my recent issues, since I don't have access
to the system log (with timestamps) on that machine.

--
Nick Bowler, Elliptic Technologies (http://www.elliptictech.com/)

2010-11-01 20:35:43

by Myklebust, Trond

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On Mon, 2010-11-01 at 15:55 -0400, Chuck Lever wrote:
> On Nov 1, 2010, at 3:48 PM, Trond Myklebust wrote:
>
> > On Mon, 2010-11-01 at 15:45 -0400, Chuck Lever wrote:
> >> On Nov 1, 2010, at 3:42 PM, Trond Myklebust wrote:
> >>
> >>> On Mon, 2010-11-01 at 15:22 -0400, Trond Myklebust wrote:
> >>>> I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
> >>>> thing in the kernel that actually sets this 'srcaddr' field, and it sets
> >>>> it to
> >>>>
> >>>> const struct sockaddr source = {
> >>>> .sa_family = AF_UNSPEC,
> >>>> };
> >>>>
> >>>> You triggered the bug by removing the line
> >>>>
> >>>> transport->srcaddr.ss_family = family;
> >>>>
> >>>> from xs_create_sock().
> >>>>
> >>>> Trond
> >>>
> >>> Does this fix the regression?
> >>>
> >>> Trond
> >>>
> >>> ----------------------------------------------------------------------------------------------
> >>> NLM: Fix a regression in lockd
> >>>
> >>> From: Trond Myklebust <[email protected]>
> >>>
> >>> Nick Bowler reports:
> >>> There are no unusual messages on the client... but I just logged into
> >>> the server and I see lots of messages of the following form:
> >>>
> >>> nfsd: request from insecure port (192.168.8.199:35766)!
> >>> nfsd: request from insecure port (192.168.8.199:35766)!
> >>> nfsd: request from insecure port (192.168.8.199:35766)!
> >>> nfsd: request from insecure port (192.168.8.199:35766)!
> >>> nfsd: request from insecure port (192.168.8.199:35766)!
> >>>
> >>> Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
> >>> Properly initialize sock_xprt.srcaddr in all cases)
> >>>
> >>> Apparently, removing the 'transport->srcaddr.ss_family = family' from
> >>> xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
> >>> initialising the srcaddr family to AF_UNSPEC.
> >>>
> >>> Reported-by: Nick Bowler <[email protected]>
> >>> Signed-off-by: Trond Myklebust <[email protected]>
> >>> ---
> >>>
> >>> fs/lockd/host.c | 5 -----
> >>> 1 files changed, 0 insertions(+), 5 deletions(-)
> >>>
> >>>
> >>> diff --git a/fs/lockd/host.c b/fs/lockd/host.c
> >>> index 25e21e4..9ff0c0e 100644
> >>> --- a/fs/lockd/host.c
> >>> +++ b/fs/lockd/host.c
> >>> @@ -238,9 +238,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
> >>> const char *hostname,
> >>> int noresvport)
> >>> {
> >>> - const struct sockaddr source = {
> >>> - .sa_family = AF_UNSPEC,
> >>> - };
> >>> struct nlm_lookup_host_info ni = {
> >>> .server = 0,
> >>> .sap = sap,
> >>> @@ -249,8 +246,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
> >>> .version = version,
> >>> .hostname = hostname,
> >>> .hostname_len = strlen(hostname),
> >>> - .src_sap = &source,
> >>> - .src_len = sizeof(source),
> >>> .noresvport = noresvport,
> >>> };
> >>>
> >>>
> >>
> >>
> >> What about that memcpy() in nlm_lookup_host()? With this patch, wouldn't it be copying garbage into the host's srcaddr field?
> >>
> >
> > It shouldn't. ni->src_len is now zero.
>
> Yech. All this still assumes that ANYADDR is all zeroes, and that the memory this is going into is already initialized to zeroes. It's asking for trouble if we re-arrange all this someday.
>
> I've got an untested one line patch that should fix this for any upper layer caller. Posting now.
>

No! Upper layer callers should simply not be setting .saddress. Pretty
much the only thing that _should_ be setting .saddress is the lockd
callback, and possibly the nfsv4 server callback.

Trond

2010-11-01 19:45:46

by Chuck Lever

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs


On Nov 1, 2010, at 3:42 PM, Trond Myklebust wrote:

> On Mon, 2010-11-01 at 15:22 -0400, Trond Myklebust wrote:
>> I suspect nlmclnt_lookup_host() is to blame. It appears to be the _only_
>> thing in the kernel that actually sets this 'srcaddr' field, and it sets
>> it to
>>
>> const struct sockaddr source = {
>> .sa_family = AF_UNSPEC,
>> };
>>
>> You triggered the bug by removing the line
>>
>> transport->srcaddr.ss_family = family;
>>
>> from xs_create_sock().
>>
>> Trond
>
> Does this fix the regression?
>
> Trond
>
> ----------------------------------------------------------------------------------------------
> NLM: Fix a regression in lockd
>
> From: Trond Myklebust <[email protected]>
>
> Nick Bowler reports:
> There are no unusual messages on the client... but I just logged into
> the server and I see lots of messages of the following form:
>
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
>
> Bisected to commit 9247685088398cf21bcb513bd2832b4cd42516c4 (SUNRPC:
> Properly initialize sock_xprt.srcaddr in all cases)
>
> Apparently, removing the 'transport->srcaddr.ss_family = family' from
> xs_create_sock() triggers this due to nlmclnt_lookup_host() incorrectly
> initialising the srcaddr family to AF_UNSPEC.
>
> Reported-by: Nick Bowler <[email protected]>
> Signed-off-by: Trond Myklebust <[email protected]>
> ---
>
> fs/lockd/host.c | 5 -----
> 1 files changed, 0 insertions(+), 5 deletions(-)
>
>
> diff --git a/fs/lockd/host.c b/fs/lockd/host.c
> index 25e21e4..9ff0c0e 100644
> --- a/fs/lockd/host.c
> +++ b/fs/lockd/host.c
> @@ -238,9 +238,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
> const char *hostname,
> int noresvport)
> {
> - const struct sockaddr source = {
> - .sa_family = AF_UNSPEC,
> - };
> struct nlm_lookup_host_info ni = {
> .server = 0,
> .sap = sap,
> @@ -249,8 +246,6 @@ struct nlm_host *nlmclnt_lookup_host(const struct sockaddr *sap,
> .version = version,
> .hostname = hostname,
> .hostname_len = strlen(hostname),
> - .src_sap = &source,
> - .src_len = sizeof(source),
> .noresvport = noresvport,
> };
>
>


What about that memcpy() in nlm_lookup_host()? With this patch, wouldn't it be copying garbage into the host's srcaddr field?

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com





2010-11-01 18:30:03

by Chuck Lever

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs


On Nov 1, 2010, at 2:19 PM, Nick Bowler wrote:

> On 2010-11-01 14:07 -0400, Chuck Lever wrote:
>> On Nov 1, 2010, at 1:58 PM, Nick Bowler wrote:
>>> After installing 2.6.37-rc1, attempting to use sqlite in any capacity on
>>> NFS gives a locking error:
>>>
>>> % echo 'select * from blah;' | sqlite3 blah.sqlite
>>> Error: near line 1: database is locked
>>>
>>> % echo 'create table blargh(INT);' | sqlite3 blargh.sqlite
>>> Error: near line 1: database is locked
>>>
>>> The result is that a lot of high-profile applications which make use of
>>> sqlite fail mysteriously. Bisection reveals the following, and
>>> reverting the implicated commit solves the issue:
>>
>> Nick, thanks for the report. Is 2.6.37-rc1 running on your clients or
>> on your server?
>
> Sorry for not being clear: the client is running 2.6.37-rc1. The
> server is running RHEL 5.5.
>
>> Does anything interesting appear in the kernel log when your test case
>> fails?
>
> There are no unusual messages on the client... but I just logged into
> the server and I see lots of messages of the following form:
>
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
> nfsd: request from insecure port (192.168.8.199:35766)!
>
> (192.168.8.199 is the address of the failing client). I can only assume
> that these are a result of my recent issues, since I don't have access
> to the system log (with timestamps) on that machine.

That's the problem this patch is supposed to prevent. I'll investigate further.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com

2010-11-01 20:33:15

by Nick Bowler

[permalink] [raw]
Subject: Re: Regression, bisected: sqlite locking failure on nfs

On 2010-11-01 16:09 -0400, Trond Myklebust wrote:
> Urgh, but nlmclnt_bind_host() will still set .saddress.
>
> OK. Here is take 2 of the patch...
[...]
> NLM: Fix a regression in lockd

Problem occurs with this one (on top of 2.6.37-rc1), too :(

--
Nick Bowler, Elliptic Technologies (http://www.elliptictech.com/)