2004-09-03 09:30:00

by Frank Steiner

[permalink] [raw]
Subject: read-error on utmp file

Hi,

I run into a strange problem which I was able to track down to the
following easy check:

Copy /var/run/utmp to some directory, export it with nfs and mount it on
a client, say at /mnt/tmp/

Then, run on the client:

while true; do /sbin/runlevel /mnt/tmp/utmp; done

which will repeatedly print the runlevel.
Now while the first loop is still running, start it a second time
in a second shell on the client.

One of the two loops immediately aborts with "unknown". Looking at
strace I can see this:

...
9377 open("/var/run/utmp", O_RDWR) = 5
9377 fcntl64(5, F_GETFD) = 0
9377 fcntl64(5, F_SETFD, FD_CLOEXEC) = 0
9377 _llseek(5, 0, [0], SEEK_SET) = 0
9377 brk(0) = 0x804a000
9377 brk(0x806b000) = 0x806b000
9377 brk(0) = 0x806b000
9377 alarm(0) = 0
9377 rt_sigaction(SIGALRM, {0x40147da0, [], SA_RESTORER, 0x40067aa8}, {SIG_DFL}, 8) = 0
9377 alarm(1) = 0
9377 fcntl64(5, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
9377 read(5, "\2\0\0\0\0\0\0\0~\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 384) = 384
9377 fcntl64(5, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
9377 alarm(0) = 1
9377 rt_sigaction(SIGALRM, {SIG_DFL}, NULL, 8) = 0
9377 alarm(0) = 0
9377 rt_sigaction(SIGALRM, {0x40147da0, [], SA_RESTORER, 0x40067aa8}, {SIG_DFL}, 8) = 0
9377 alarm(1) = 0
9377 fcntl64(5, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
9377 read(5, 0x401706e0, 384) = -1 EIO (Input/output error)
...

where the last line would usually look like
9061 read(5, "\10\0\0\0\262\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 384) = 384

This I/O error occurs only when running the two loops in parallel, and
only if the utmp file is accessed via NFS, not for a local disk.

I'm running kernel 2.6.8.1 on client and server (knfsd) and mounted with
"ro,hard,intr,tcp,lock", but ro/rw or lock/nolock don't make any difference.

Any idea what could be the problem here? How can parallel reading fail?

cu,
Frank

--
Dipl.-Inform. Frank Steiner Web: http://www.bio.ifi.lmu.de/~steiner/
Lehrstuhl f. Bioinformatik Mail: http://www.bio.ifi.lmu.de/~steiner/m/
LMU, Amalienstr. 17 Phone: +49 89 2180-4049
80333 Muenchen, Germany Fax: +49 89 2180-99-4049



-------------------------------------------------------
This SF.Net email is sponsored by BEA Weblogic Workshop
FREE Java Enterprise J2EE developer tools!
Get your free copy of BEA WebLogic Workshop 8.1 today.
http://ads.osdn.com/?ad_id=5047&alloc_id=10808&op=click
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs


2004-09-13 12:02:35

by Frank Steiner

[permalink] [raw]
Subject: Re: read-error on utmp file

Hi,

I don't mean to get on anybodies nerves, so please don't get mad if I
ask again :-)

I still consider it a bug if of two concurrent read processes on an utmp file
(performed on the same nfs client) one fails with I/O error. It's not
a big thing, I just would like to know if it is worth changing my ckconfig
algorithms or if this bug is likely to disappear.

So any answer out of the set

- we don't consider this a bug
- we consider it a bug but can't care about it at the moment
- we are working on it

would be helpful :-) Just that I can decide what to do...

cu,
Frank

--
Dipl.-Inform. Frank Steiner Web: http://www.bio.ifi.lmu.de/~steiner/
Lehrstuhl f. Bioinformatik Mail: http://www.bio.ifi.lmu.de/~steiner/m/
LMU, Amalienstr. 17 Phone: +49 89 2180-4049
80333 Muenchen, Germany Fax: +49 89 2180-99-4049



-------------------------------------------------------
This SF.Net email is sponsored by: YOU BE THE JUDGE. Be one of 170
Project Admins to receive an Apple iPod Mini FREE for your judgement on
who ports your project to Linux PPC the best. Sponsored by IBM.
Deadline: Sept. 13. Go here: http://sf.net/ppc_contest.php
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs

2004-09-03 16:52:10

by Trond Myklebust

[permalink] [raw]
Subject: Re: read-error on utmp file

P=E5 fr , 03/09/2004 klokka 05:29, skreiv Frank Steiner:

> One of the two loops immediately aborts with "unknown". Looking at
> strace I can see this:
>=20
> ...
> 9377 open("/var/run/utmp", O_RDWR) =3D 5
> 9377 fcntl64(5, F_GETFD) =3D 0
> 9377 fcntl64(5, F_SETFD, FD_CLOEXEC) =3D 0
> 9377 _llseek(5, 0, [0], SEEK_SET) =3D 0
> 9377 brk(0) =3D 0x804a000
> 9377 brk(0x806b000) =3D 0x806b000
> 9377 brk(0) =3D 0x806b000
> 9377 alarm(0) =3D 0
> 9377 rt_sigaction(SIGALRM, {0x40147da0, [], SA_RESTORER, 0x40067aa8}, {S=
IG_DFL}, 8) =3D 0
> 9377 alarm(1) =3D 0
> 9377 fcntl64(5, F_SETLKW, {type=3DF_RDLCK, whence=3DSEEK_SET, start=3D0,=
len=3D0}) =3D 0
> 9377 read(5, "\2\0\0\0\0\0\0\0~\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..=
., 384) =3D 384
> 9377 fcntl64(5, F_SETLKW, {type=3DF_UNLCK, whence=3DSEEK_SET, start=3D0,=
len=3D0}) =3D 0
> 9377 alarm(0) =3D 1
> 9377 rt_sigaction(SIGALRM, {SIG_DFL}, NULL, 8) =3D 0
> 9377 alarm(0) =3D 0
> 9377 rt_sigaction(SIGALRM, {0x40147da0, [], SA_RESTORER, 0x40067aa8}, {S=
IG_DFL}, 8) =3D 0
> 9377 alarm(1) =3D 0
> 9377 fcntl64(5, F_SETLKW, {type=3DF_RDLCK, whence=3DSEEK_SET, start=3D0,=
len=3D0}) =3D 0
> 9377 read(5, 0x401706e0, 384) =3D -1 EIO (Input/output error)

Binary "tcpdump -s 9000" please?

Cheers,
Trond


-------------------------------------------------------
This SF.Net email is sponsored by BEA Weblogic Workshop
FREE Java Enterprise J2EE developer tools!
Get your free copy of BEA WebLogic Workshop 8.1 today.
http://ads.osdn.com/?ad_id=5047&alloc_id=10808&op=click
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs

2004-09-06 07:18:02

by Frank Steiner

[permalink] [raw]
Subject: Re: read-error on utmp file

Trond Myklebust wrote:

> Binary "tcpdump -s 9000" please?

I did a "tcpdump -s 9000 -w <file> host <server>" on the client and accordingly on
the server. Hope this was ok. The client log should stop right after
the error, because I executed this on the client:

tcpdump -s 9000 -w <file> host curry & while runlevel /boot/utmp; do true; done; killall tcpdump

and started the second loop in another window which caused this first loop
to fail and stop the tcpdump...

The logs are here (1.5 and 3 MB, so I didn't want to mail them):
http://www.bio.ifi.lmu.de/~steiner/tcpdump.utmp.read.error.client
http://www.bio.ifi.lmu.de/~steiner/tcpdump.utmp.read.error.server

cu,
Frank

--
Dipl.-Inform. Frank Steiner Web: http://www.bio.ifi.lmu.de/~steiner/
Lehrstuhl f. Bioinformatik Mail: http://www.bio.ifi.lmu.de/~steiner/m/
LMU, Amalienstr. 17 Phone: +49 89 2180-4049
80333 Muenchen, Germany Fax: +49 89 2180-99-4049



-------------------------------------------------------
This SF.Net email is sponsored by BEA Weblogic Workshop
FREE Java Enterprise J2EE developer tools!
Get your free copy of BEA WebLogic Workshop 8.1 today.
http://ads.osdn.com/?ad_id=5047&alloc_id=10808&op=click
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs

2004-09-06 17:05:04

by Trond Myklebust

[permalink] [raw]
Subject: Re: read-error on utmp file

P=E5 m=E5 , 06/09/2004 klokka 03:17, skreiv Frank Steiner:

> tcpdump -s 9000 -w <file> host curry & while runlevel /boot/utmp; do true=
; done; killall tcpdump
>=20
> and started the second loop in another window which caused this first loo=
p
> to fail and stop the tcpdump...

Ah, right... Sorry, my head hasn't been screwed on correctly...

Although we wait on writes, we don't bother to wait on all *reads* to
complete when closing the file. This means that readahead (which can
schedule extra pageins asynchronously) may end up causing the file to be
kept open for longer.

That is why you are seeing sillyrenames here...

Now what I still don't understand is why they are being left behind, and
not cleaned up. That should normally only occur under the situations I
described earlier.

Cheers,
Trond



-------------------------------------------------------
This SF.Net email is sponsored by BEA Weblogic Workshop
FREE Java Enterprise J2EE developer tools!
Get your free copy of BEA WebLogic Workshop 8.1 today.
http://ads.osdn.com/?ad_id=5047&alloc_id=10808&op=click
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs

2004-09-07 06:43:27

by Frank Steiner

[permalink] [raw]
Subject: Re: read-error on utmp file

Hi Trond,

Trond Myklebust wrote:
> P=E5 m=E5 , 06/09/2004 klokka 03:17, skreiv Frank Steiner:
>=20
>=20
>>tcpdump -s 9000 -w <file> host curry & while runlevel /boot/utmp; do tr=
ue; done; killall tcpdump
>>
>>and started the second loop in another window which caused this first l=
oop
>>to fail and stop the tcpdump...
>=20
>=20
> Ah, right... Sorry, my head hasn't been screwed on correctly...
>=20
> Although we wait on writes, we don't bother to wait on all *reads* to
> complete when closing the file. This means that readahead (which can
> schedule extra pageins asynchronously) may end up causing the file to b=
e
> kept open for longer.
>=20
> That is why you are seeing sillyrenames here...

sorry, I don't understand what you are trying to tell me :-) I'm not sure=

what you mean by "silly renames". I didn't see any .nfsxxx files or sth.
similar like it is discussed in the "silly names" thread.
My problem was that two concurrent reads on with /sbin/runlevel on an
utmp file would cause one read to abort with I/O error.

However, the sentence I might understand is that a process could close
a file although some other process is still reading on it? So that the
process still reading gets an I/O error because the file is closed?
If that's what happening, wouldn't that be a bug? I can think of many
situations where two processes are reading from the same file, and
I feel that one process should not be able to close the file such that
the other process still reading aborts with I/O error?

But I might have missed the point of your answer... :-/

cu,
Frank


--=20
Dipl.-Inform. Frank Steiner Web: http://www.bio.ifi.lmu.de/~steiner/
Lehrstuhl f. Bioinformatik Mail: http://www.bio.ifi.lmu.de/~steiner/m/=

LMU, Amalienstr. 17 Phone: +49 89 2180-4049
80333 Muenchen, Germany Fax: +49 89 2180-99-4049
* Rekursion kann man erst verstehen, wenn man Rekursion verstanden hat. *=



-------------------------------------------------------
This SF.Net email is sponsored by BEA Weblogic Workshop
FREE Java Enterprise J2EE developer tools!
Get your free copy of BEA WebLogic Workshop 8.1 today.
http://ads.osdn.com/?ad_id=5047&alloc_id=10808&op=click
_______________________________________________
NFS maillist - [email protected]
https://lists.sourceforge.net/lists/listinfo/nfs

2004-09-07 17:21:18

by Ara.T.Howard

[permalink] [raw]
Subject: Re: read-error on utmp file

On Mon, 6 Sep 2004, Trond Myklebust wrote:

> P? m? , 06/09/2004 klokka 03:17, skreiv Frank Steiner:
>
>> tcpdump -s 9000 -w <file> host curry & while runlevel /boot/utmp; do true; done; killall tcpdump
>>
>> and started the second loop in another window which caused this first loop
>> to fail and stop the tcpdump...
>
> Ah, right... Sorry, my head hasn't been screwed on correctly...
>
> Although we wait on writes, we don't bother to wait on all *reads* to
> complete when closing the file. This means that readahead (which can
> schedule extra pageins asynchronously) may end up causing the file to be
> kept open for longer.
>
> That is why you are seeing sillyrenames here...

do you think this could contribute to my situation with sillyrenames too?

cheers.

-a
--
===============================================================================
| EMAIL :: Ara [dot] T [dot] Howard [at] noaa [dot] gov
| PHONE :: 303.497.6469
| A flower falls, even though we love it;
| and a weed grows, even though we do not love it.
| --Dogen
===============================================================================