SMP-ix86-threads-fork: Linux 2.4.x kernel problem identified [phantom read()]

SMP-ix86-threads-fork: Linux 2.4.x kernel problem identified [phantom read()]

[Wolfram Gloger]

[please CC me if you reply on the kernel mailing list, thx]

Hi,

After several months of tests and debugging, I believe I've _finally_
identified the nasty problem with my fork-malloc testcase,

http://www.malloc.de/tests/fork-malloc.c

which in turn I am pretty sure is equivalent to Brian McCorkle and
others' stressKernel problem.  The combination involved is
threads/clone() (via LinuxThreads) and fork().

On a variety of dual-ix86-SMP systems running Linux-2.4.[0-10pre]
kernels (compiled with gcc-2.95.2 and gcc-2.95.4) it eventually
happens that a read(fd, buf, sz) system call returns successfully but
it _actually hasn't read any bytes into buf_ (maybe the bytes go
somewhere else but I haven't determined where).  The file involved in
this case is the manager pipe employed by LinuxThreads.

When this occurs within LinuxThreads, the buffer that is read into
('request') in the manager is then _unchanged_ from the previous
'thread create' request, and so a 'phantom thread' is created (bad),
and the creating thread is restart()ed unconditionally (much worse,
f.e. if it's waiting on a mutex).  The resulting crashes are
practically impossible to debug, hiding the problem extremely well.

I've now created a patch for glibc-2.2.4 (appended below, but should
'work' for all recent glibcs), with which applied I'm eventually
seeing "*** Bug" being printed when I run fork-malloc (see the URL
above) on Dual-ix86 systems.  You can feel free to substitute any
value for '0x123456' in the patch if you want to convince yourself of
the bug.

I tried hard to create a test case independent of LinuxThreads but
have failed so far, sorry.  If you want to reproduce, you may have to
be patient, sometimes I've seen the bug strike in a few minutes, but
occasionally it can take up to 6 hours..

Regards,
Wolfram.

--- linuxthreads/manager.c.orig	Mon Jul 23 19:54:13 2001
+++ linuxthreads/manager.c	Mon Sep 10 11:48:49 2001
@@ -150,8 +150,18 @@
     }
     /* Read and execute request */
     if (n == 1 && (ufd.revents & POLLIN)) {
-      n = __libc_read(reqfd, (char *)&request, sizeof(request));
-      ASSERT(n == sizeof(request));
+      int sz_read;
+      request.req_kind = 0x123456;
+      for (sz_read=0; sz_read<sizeof(request); sz_read+=n) {
+	n = __libc_read(reqfd, (char *)&request + sz_read,
+			sizeof(request) - sz_read);
+	if (n < 0)
+	  continue;
+      }
+      if(request.req_kind == 0x123456) {
+	write(2, "*** Bug\n", 8);
+	abort();
+      }
       switch(request.req_kind) {
       case REQ_CREATE:
         request.req_thread->p_retcode =

Re: SMP-ix86-threads-fork: Linux 2.4.x kernel problem identified [phantom read()]

[Kaz Kylheku]

On Mon, 10 Sep 2001, Wolfram Gloger wrote:

> On a variety of dual-ix86-SMP systems running Linux-2.4.[0-10pre]
> kernels (compiled with gcc-2.95.2 and gcc-2.95.4) it eventually
> happens that a read(fd, buf, sz) system call returns successfully but
> it _actually hasn't read any bytes into buf_ (maybe the bytes go
> somewhere else but I haven't determined where).

Wow, that is nuts! :)

> --- linuxthreads/manager.c.orig	Mon Jul 23 19:54:13 2001
> +++ linuxthreads/manager.c	Mon Sep 10 11:48:49 2001
> @@ -150,8 +150,18 @@
>      }
>      /* Read and execute request */
>      if (n == 1 && (ufd.revents & POLLIN)) {
> -      n = __libc_read(reqfd, (char *)&request, sizeof(request));
> -      ASSERT(n == sizeof(request));
> +      int sz_read;
> +      request.req_kind = 0x123456;
> +      for (sz_read=0; sz_read<sizeof(request); sz_read+=n) {
> +	n = __libc_read(reqfd, (char *)&request + sz_read,
> +			sizeof(request) - sz_read);
> +	if (n < 0)
> +	  continue;
> +      }

Careful; when you continue, the increment expression sz_read += n
is still evaluated.

And please note that sz_read < sizeof(request) is a signed-unsigned
comparison!

So if sz_read is negative, its value will be converted to a positive
value of type size_t, and your loop may terminate prematurely.

So it's perfectly possible to observe the behavior you are seeing
if __libc_read() returns -1. Because then sz_read will acquire the
value -1, and the guard expresssion sz_read < sizeof(request) will yield
zero, terminating the loop.

Could you recode the test patch to eliminate these suspicions and re-test?

Re: SMP-ix86-threads-fork: Linux 2.4.x kernel problem identified [phantom read()]

[Wolfram Gloger]

Hi,

> So it's perfectly possible to observe the behavior you are seeing
> if __libc_read() returns -1. Because then sz_read will acquire the
> value -1, and the guard expresssion sz_read < sizeof(request) will yield
> zero, terminating the loop.

Argh!  That indeed seems to be the case, _no_ apparent kernel problem
is involved, sorry for the false alarm.  read() 'just' returns -1 with
errno becoming EINTR.  One should never code up a loop like that in
the last minute (I only found the effect yesterday)..

> Could you recode the test patch to eliminate these suspicions and re-test?

The analysis was nevertheless correct, LinuxThreads gets out of synch
with disastrous effects.  I was puzzled how read() could return -1,
however it may make sense with a __pthread_sig_cancel pending in the
manager thread due to a child exiting (?).  But then, why wasn't this
possibility discovered before?

Below is a corrected patch for glibc-2.2.4.  I've run fork-malloc with
this for a couple of hours.

Thanks,
Wolfram.

2001-09-11  Wolfram Gloger  <wg@malloc.de>

	* manager.c (__pthread_manager): When reading from pipe. account
	for possible error return from read().

--- linuxthreads/manager.c.orig	Mon Jul 23 19:54:13 2001
+++ linuxthreads/manager.c	Tue Sep 11 00:47:48 2001
@@ -150,8 +150,19 @@
     }
     /* Read and execute request */
     if (n == 1 && (ufd.revents & POLLIN)) {
-      n = __libc_read(reqfd, (char *)&request, sizeof(request));
-      ASSERT(n == sizeof(request));
+      int sz_read = 0;
+
+      while (sz_read < sizeof(request)) {
+	n = __libc_read(reqfd, (char *)&request + sz_read,
+			sizeof(request) - sz_read);
+	if (n < 0) {
+#ifdef DEBUG
+	  char d[64];
+	  sprintf(d, "*** read err %d\n", errno);
+#endif
+	} else
+	  sz_read += n;
+      }
       switch(request.req_kind) {
       case REQ_CREATE:
         request.req_thread->p_retcode =

Re: SMP-ix86-threads-fork: Linux 2.4.x kernel problem identified [phantom read()]

[Andreas Jaeger]

Wolfram Gloger <wg@malloc.de> writes:

> Hi,
>
>> So it's perfectly possible to observe the behavior you are seeing
>> if __libc_read() returns -1. Because then sz_read will acquire the
>> value -1, and the guard expresssion sz_read < sizeof(request) will yield
>> zero, terminating the loop.
>
> Argh!  That indeed seems to be the case, _no_ apparent kernel problem
> is involved, sorry for the false alarm.  read() 'just' returns -1 with
> errno becoming EINTR.  One should never code up a loop like that in
> the last minute (I only found the effect yesterday)..
>
>> Could you recode the test patch to eliminate these suspicions and re-test?
>
> The analysis was nevertheless correct, LinuxThreads gets out of synch
> with disastrous effects.  I was puzzled how read() could return -1,
> however it may make sense with a __pthread_sig_cancel pending in the
> manager thread due to a child exiting (?).  But then, why wasn't this
> possibility discovered before?

Because we never compiled with -DDEBUG so that the ASSERT was
triggered?

There's another such place (line 135) with __libc_read in
__pthread_manager:

  /* Synchronize debugging of the thread manager */
  n = __libc_read(reqfd, (char *)&request, sizeof(request));
  ASSERT(n == sizeof(request) && request.req_kind == REQ_DEBUG);

We should account for a return value of -1 here also, shouldn't we?

> Below is a corrected patch for glibc-2.2.4.  I've run fork-malloc with
> this for a couple of hours.

Is it still running? ;-)  That would be excellent!

Thanks a lot Wolfram,
Andreas

> Thanks,
> Wolfram.
>
> 2001-09-11  Wolfram Gloger  <wg@malloc.de>
>
> 	* manager.c (__pthread_manager): When reading from pipe. account
> 	for possible error return from read().
>
> --- linuxthreads/manager.c.orig	Mon Jul 23 19:54:13 2001
> +++ linuxthreads/manager.c	Tue Sep 11 00:47:48 2001
> @@ -150,8 +150,19 @@
>      }
>      /* Read and execute request */
>      if (n == 1 && (ufd.revents & POLLIN)) {
> -      n = __libc_read(reqfd, (char *)&request, sizeof(request));
> -      ASSERT(n == sizeof(request));
> +      int sz_read = 0;
> +
> +      while (sz_read < sizeof(request)) {
> +	n = __libc_read(reqfd, (char *)&request + sz_read,
> +			sizeof(request) - sz_read);
> +	if (n < 0) {
> +#ifdef DEBUG
> +	  char d[64];
> +	  sprintf(d, "*** read err %d\n", errno);
> +#endif
> +	} else
> +	  sz_read += n;
> +      }
>        switch(request.req_kind) {
>        case REQ_CREATE:
>          request.req_thread->p_retcode =
>

-- 
 Andreas Jaeger
  SuSE Labs aj@suse.de
   private aj@arthur.inka.de
    http://www.suse.de/~aj