[PATCH] deadlock in script

[PATCH] deadlock in script

[Csaba Kos]

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

Hi,

I use the "script" command to save the output of certain jobs on a
heavily loaded Linux cluster. Every now and then the "script" command
hangs.

I made some modifications to util-linux 2.23 and have been using the
patched "script" command without problems for about a year.

Attached I'm submitting the patches (updated to the current master) for review.

Best regards,

Csaba Kos

[-- Attachment #2: 0001-script-fix-a-rare-deadlock-after-child-termination.patch --]
[-- Type: text/x-diff, Size: 3273 bytes --]

From fad482427ddd819a92d1e636e20bbf8adaf721dd Mon Sep 17 00:00:00 2001
From: Csaba Kos <csaba.kos@gmail.com>
Date: Fri, 30 May 2014 14:33:32 +0900
Subject: [PATCH 1/2] script: fix a rare deadlock after child termination

---
 term-utils/script.c | 52 +++++++++++++++++++++++++++++++++++++++++++++-------
 1 file changed, 45 insertions(+), 7 deletions(-)

diff --git a/term-utils/script.c b/term-utils/script.c
index e5d239c..32906d0 100644
--- a/term-utils/script.c
+++ b/term-utils/script.c
@@ -36,6 +36,9 @@
  * - added Native Language Support
  *
  * 2000-07-30 Per Andreas Buer <per@linpro.no> - added "q"-option
+ *
+ * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
+ * - fixed a rare deadlock after child termination
  */
 
 /*
@@ -114,6 +117,8 @@ int	tflg = 0;
 int	forceflg = 0;
 int	isterm;
 
+sigset_t block_mask, unblock_mask;
+
 int die;
 int resized;
 
@@ -306,6 +311,7 @@ doinput(void) {
 	int errsv = 0;
 	ssize_t cc = 0;
 	char ibuf[BUFSIZ];
+	fd_set readfds;
 
 	/* close things irrelevant for this process */
 	if (fscript)
@@ -314,14 +320,27 @@ doinput(void) {
 		fclose(timingfd);
 	fscript = timingfd = NULL;
 
+	FD_ZERO(&readfds);
+
+	/* block SIGCHLD */
+	sigprocmask(SIG_SETMASK, &block_mask, &unblock_mask);
+
 	while (die == 0) {
-		if ((cc = read(STDIN_FILENO, ibuf, BUFSIZ)) > 0) {
-			if (write_all(master, ibuf, cc)) {
-				warn (_("write failed"));
-				fail();
+		FD_SET(STDIN_FILENO, &readfds);
+
+		/* wait for input or signal (including SIGCHLD) */
+		if ((cc = pselect(STDIN_FILENO + 1, &readfds, NULL, NULL, NULL,
+			&unblock_mask)) > 0) {
+
+			if ((cc = read(STDIN_FILENO, ibuf, BUFSIZ)) > 0) {
+				if (write_all(master, ibuf, cc)) {
+					warn (_("write failed"));
+					fail();
+				}
 			}
 		}
-		else if (cc < 0 && errno == EINTR && resized)
+
+		if (cc < 0 && errno == EINTR && resized)
 		{
 			/* transmit window change information to the child */
 			if (isterm) {
@@ -330,12 +349,15 @@ doinput(void) {
 			}
 			resized = 0;
 
-		} else {
+		} else if (cc <= 0) {
 			errsv = errno;
 			break;
 		}
 	}
 
+	/* unblock SIGCHLD */
+	sigprocmask(SIG_SETMASK, &unblock_mask, NULL);
+
 	/* To be sure that we don't miss any data */
 	wait_for_empty_fd(slave);
 	wait_for_empty_fd(master);
@@ -404,6 +426,7 @@ dooutput(void) {
 	struct timeval tv;
 	double oldtime=time(NULL), newtime;
 	int errsv = 0;
+	fd_set readfds;
 
 	close(STDIN_FILENO);
 #ifdef HAVE_LIBUTIL
@@ -416,6 +439,8 @@ dooutput(void) {
 	my_strftime(obuf, sizeof obuf, "%c\n", localtime(&tvec));
 	fprintf(fscript, _("Script started on %s"), obuf);
 
+	FD_ZERO(&readfds);
+
 	do {
 		if (die || errsv == EINTR) {
 			struct pollfd fds[] = {{ .fd = master, .events = POLLIN }};
@@ -423,10 +448,23 @@ dooutput(void) {
 				break;
 		}
 
+		/* block SIGCHLD */
+		sigprocmask(SIG_SETMASK, &block_mask, &unblock_mask);
+
+		FD_SET(master, &readfds);
 		errno = 0;
-		cc = read(master, obuf, sizeof (obuf));
+
+		/* wait for input or signal (including SIGCHLD) */
+		if ((cc = pselect(master+1, &readfds, NULL, NULL, NULL,
+			&unblock_mask)) > 0) {
+
+			cc = read(master, obuf, sizeof (obuf));
+		}
 		errsv = errno;
 
+		/* unblock SIGCHLD */
+		sigprocmask(SIG_SETMASK, &unblock_mask, NULL);
+
 		if (tflg)
 			gettimeofday(&tv, NULL);
 
-- 
1.8.5.rc3.2.gc302941


[-- Attachment #3: 0002-script-fix-spurious-exit-from-input-read-loop-on-EIN.patch --]
[-- Type: text/x-diff, Size: 891 bytes --]

From a2dd4df349f426c6605e4b151aafccce4b2ea8e7 Mon Sep 17 00:00:00 2001
From: Csaba Kos <csaba.kos@gmail.com>
Date: Fri, 30 May 2014 14:51:38 +0900
Subject: [PATCH 2/2] script: fix spurious exit from input read loop on EINTR.

---
 term-utils/script.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/term-utils/script.c b/term-utils/script.c
index 32906d0..63913c8 100644
--- a/term-utils/script.c
+++ b/term-utils/script.c
@@ -328,6 +328,7 @@ doinput(void) {
 	while (die == 0) {
 		FD_SET(STDIN_FILENO, &readfds);
 
+		errno = 0;
 		/* wait for input or signal (including SIGCHLD) */
 		if ((cc = pselect(STDIN_FILENO + 1, &readfds, NULL, NULL, NULL,
 			&unblock_mask)) > 0) {
@@ -349,7 +350,7 @@ doinput(void) {
 			}
 			resized = 0;
 
-		} else if (cc <= 0) {
+		} else if (cc <= 0 && errno != EINTR) {
 			errsv = errno;
 			break;
 		}
-- 
1.8.5.rc3.2.gc302941

Re: [PATCH] deadlock in script

[Karel Zak]

On Fri, May 30, 2014 at 03:30:45PM +0900, Csaba Kos wrote:
> diff --git a/term-utils/script.c b/term-utils/script.c
> index e5d239c..32906d0 100644
> --- a/term-utils/script.c
> +++ b/term-utils/script.c
> @@ -36,6 +36,9 @@
>   * - added Native Language Support
>   *
>   * 2000-07-30 Per Andreas Buer <per@linpro.no> - added "q"-option
> + *
> + * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
> + * - fixed a rare deadlock after child termination
>   */
>  
>  /*
> @@ -114,6 +117,8 @@ int	tflg = 0;
>  int	forceflg = 0;
>  int	isterm;
>  
> +sigset_t block_mask, unblock_mask;

 This declaration shadows declaration in main() where is also block_mask and 
 unblock_mask -- I guess it's not expected.

> +	/* block SIGCHLD */
> +	sigprocmask(SIG_SETMASK, &block_mask, &unblock_mask);

 the initialization is where? in main()?

> +		/* wait for input or signal (including SIGCHLD) */
> +		if ((cc = pselect(STDIN_FILENO + 1, &readfds, NULL, NULL, NULL,
> +			&unblock_mask)) > 0) {

 probably good idea, I have thought about something like this (or
 signalfd()), but I have never found time to try it... thanks!

> +			if ((cc = read(STDIN_FILENO, ibuf, BUFSIZ)) > 0) {
> +				if (write_all(master, ibuf, cc)) {
> +					warn (_("write failed"));
> +					fail();
> +				}

  Karel  


-- 
 Karel Zak  <kzak@redhat.com>
 http://karelzak.blogspot.com

Re: [PATCH] deadlock in script

[Csaba Kos]

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

On Fri, May 30, 2014 at 6:15 PM, Karel Zak <kzak@redhat.com> wrote:
> On Fri, May 30, 2014 at 03:30:45PM +0900, Csaba Kos wrote:
>> diff --git a/term-utils/script.c b/term-utils/script.c
>> index e5d239c..32906d0 100644
>> --- a/term-utils/script.c
>> +++ b/term-utils/script.c
>> @@ -36,6 +36,9 @@
>>   * - added Native Language Support
>>   *
>>   * 2000-07-30 Per Andreas Buer <per@linpro.no> - added "q"-option
>> + *
>> + * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
>> + * - fixed a rare deadlock after child termination
>>   */
>>
>>  /*
>> @@ -114,6 +117,8 @@ int       tflg = 0;
>>  int  forceflg = 0;
>>  int  isterm;
>>
>> +sigset_t block_mask, unblock_mask;
>
>  This declaration shadows declaration in main() where is also block_mask and
>  unblock_mask -- I guess it's not expected.

Sorry, I goofed when updating my patch to the current master. Thanks
for the careful review! Updated patch attached.

>> +     /* block SIGCHLD */
>> +     sigprocmask(SIG_SETMASK, &block_mask, &unblock_mask);
>
>  the initialization is where? in main()?

Yes, the sigprocmask() and sigaddset() calls initialize block_mask in main().

Best regards,

Csaba

>> +             /* wait for input or signal (including SIGCHLD) */
>> +             if ((cc = pselect(STDIN_FILENO + 1, &readfds, NULL, NULL, NULL,
>> +                     &unblock_mask)) > 0) {
>
>  probably good idea, I have thought about something like this (or
>  signalfd()), but I have never found time to try it... thanks!
>
>> +                     if ((cc = read(STDIN_FILENO, ibuf, BUFSIZ)) > 0) {
>> +                             if (write_all(master, ibuf, cc)) {
>> +                                     warn (_("write failed"));
>> +                                     fail();
>> +                             }
>
>   Karel
>
>
> --
>  Karel Zak  <kzak@redhat.com>
>  http://karelzak.blogspot.com

[-- Attachment #2: 0001-script-fix-a-rare-deadlock-after-child-termination.patch --]
[-- Type: text/x-diff, Size: 3421 bytes --]

From 852c6dae6e397937ea8bdad18b63046f169514e1 Mon Sep 17 00:00:00 2001
From: Csaba Kos <csaba.kos@gmail.com>
Date: Fri, 30 May 2014 14:33:32 +0900
Subject: [PATCH 1/2] script: fix a rare deadlock after child termination

---
 term-utils/script.c | 53 +++++++++++++++++++++++++++++++++++++++++++++--------
 1 file changed, 45 insertions(+), 8 deletions(-)

diff --git a/term-utils/script.c b/term-utils/script.c
index e5d239c..47bb186 100644
--- a/term-utils/script.c
+++ b/term-utils/script.c
@@ -36,6 +36,9 @@
  * - added Native Language Support
  *
  * 2000-07-30 Per Andreas Buer <per@linpro.no> - added "q"-option
+ *
+ * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
+ * - fixed a rare deadlock after child termination
  */
 
 /*
@@ -114,6 +117,8 @@ int	tflg = 0;
 int	forceflg = 0;
 int	isterm;
 
+sigset_t block_mask, unblock_mask;
+
 int die;
 int resized;
 
@@ -162,7 +167,6 @@ usage(FILE *out)
 
 int
 main(int argc, char **argv) {
-	sigset_t block_mask, unblock_mask;
 	struct sigaction sa;
 	int ch;
 
@@ -306,6 +310,7 @@ doinput(void) {
 	int errsv = 0;
 	ssize_t cc = 0;
 	char ibuf[BUFSIZ];
+	fd_set readfds;
 
 	/* close things irrelevant for this process */
 	if (fscript)
@@ -314,14 +319,27 @@ doinput(void) {
 		fclose(timingfd);
 	fscript = timingfd = NULL;
 
+	FD_ZERO(&readfds);
+
+	/* block SIGCHLD */
+	sigprocmask(SIG_SETMASK, &block_mask, &unblock_mask);
+
 	while (die == 0) {
-		if ((cc = read(STDIN_FILENO, ibuf, BUFSIZ)) > 0) {
-			if (write_all(master, ibuf, cc)) {
-				warn (_("write failed"));
-				fail();
+		FD_SET(STDIN_FILENO, &readfds);
+
+		/* wait for input or signal (including SIGCHLD) */
+		if ((cc = pselect(STDIN_FILENO + 1, &readfds, NULL, NULL, NULL,
+			&unblock_mask)) > 0) {
+
+			if ((cc = read(STDIN_FILENO, ibuf, BUFSIZ)) > 0) {
+				if (write_all(master, ibuf, cc)) {
+					warn (_("write failed"));
+					fail();
+				}
 			}
 		}
-		else if (cc < 0 && errno == EINTR && resized)
+
+		if (cc < 0 && errno == EINTR && resized)
 		{
 			/* transmit window change information to the child */
 			if (isterm) {
@@ -330,12 +348,15 @@ doinput(void) {
 			}
 			resized = 0;
 
-		} else {
+		} else if (cc <= 0) {
 			errsv = errno;
 			break;
 		}
 	}
 
+	/* unblock SIGCHLD */
+	sigprocmask(SIG_SETMASK, &unblock_mask, NULL);
+
 	/* To be sure that we don't miss any data */
 	wait_for_empty_fd(slave);
 	wait_for_empty_fd(master);
@@ -404,6 +425,7 @@ dooutput(void) {
 	struct timeval tv;
 	double oldtime=time(NULL), newtime;
 	int errsv = 0;
+	fd_set readfds;
 
 	close(STDIN_FILENO);
 #ifdef HAVE_LIBUTIL
@@ -416,6 +438,8 @@ dooutput(void) {
 	my_strftime(obuf, sizeof obuf, "%c\n", localtime(&tvec));
 	fprintf(fscript, _("Script started on %s"), obuf);
 
+	FD_ZERO(&readfds);
+
 	do {
 		if (die || errsv == EINTR) {
 			struct pollfd fds[] = {{ .fd = master, .events = POLLIN }};
@@ -423,10 +447,23 @@ dooutput(void) {
 				break;
 		}
 
+		/* block SIGCHLD */
+		sigprocmask(SIG_SETMASK, &block_mask, &unblock_mask);
+
+		FD_SET(master, &readfds);
 		errno = 0;
-		cc = read(master, obuf, sizeof (obuf));
+
+		/* wait for input or signal (including SIGCHLD) */
+		if ((cc = pselect(master+1, &readfds, NULL, NULL, NULL,
+			&unblock_mask)) > 0) {
+
+			cc = read(master, obuf, sizeof (obuf));
+		}
 		errsv = errno;
 
+		/* unblock SIGCHLD */
+		sigprocmask(SIG_SETMASK, &unblock_mask, NULL);
+
 		if (tflg)
 			gettimeofday(&tv, NULL);
 
-- 
1.8.5.rc3.2.gc302941


[-- Attachment #3: 0002-script-fix-spurious-exit-from-input-read-loop-on-EIN.patch --]
[-- Type: text/x-diff, Size: 891 bytes --]

From 657f138320afe1a5f1d55fb928ed11bed7817898 Mon Sep 17 00:00:00 2001
From: Csaba Kos <csaba.kos@gmail.com>
Date: Fri, 30 May 2014 18:40:15 +0900
Subject: [PATCH 2/2] script: fix spurious exit from input read loop on EINTR.

---
 term-utils/script.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/term-utils/script.c b/term-utils/script.c
index 47bb186..1ae3462 100644
--- a/term-utils/script.c
+++ b/term-utils/script.c
@@ -327,6 +327,7 @@ doinput(void) {
 	while (die == 0) {
 		FD_SET(STDIN_FILENO, &readfds);
 
+		errno = 0;
 		/* wait for input or signal (including SIGCHLD) */
 		if ((cc = pselect(STDIN_FILENO + 1, &readfds, NULL, NULL, NULL,
 			&unblock_mask)) > 0) {
@@ -348,7 +349,7 @@ doinput(void) {
 			}
 			resized = 0;
 
-		} else if (cc <= 0) {
+		} else if (cc <= 0 && errno != EINTR) {
 			errsv = errno;
 			break;
 		}
-- 
1.8.5.rc3.2.gc302941

Re: [PATCH] deadlock in script

[Karel Zak]

On Fri, May 30, 2014 at 06:52:20PM +0900, Csaba Kos wrote:
> On Fri, May 30, 2014 at 6:15 PM, Karel Zak <kzak@redhat.com> wrote:
> > On Fri, May 30, 2014 at 03:30:45PM +0900, Csaba Kos wrote:
> >> diff --git a/term-utils/script.c b/term-utils/script.c
> >> index e5d239c..32906d0 100644
> >> --- a/term-utils/script.c
> >> +++ b/term-utils/script.c
> >> @@ -36,6 +36,9 @@
> >>   * - added Native Language Support
> >>   *
> >>   * 2000-07-30 Per Andreas Buer <per@linpro.no> - added "q"-option
> >> + *
> >> + * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
> >> + * - fixed a rare deadlock after child termination
> >>   */
> >>
> >>  /*
> >> @@ -114,6 +117,8 @@ int       tflg = 0;
> >>  int  forceflg = 0;
> >>  int  isterm;
> >>
> >> +sigset_t block_mask, unblock_mask;
> >
> >  This declaration shadows declaration in main() where is also block_mask and
> >  unblock_mask -- I guess it's not expected.
> 
> Sorry, I goofed when updating my patch to the current master. Thanks
> for the careful review! Updated patch attached.

 All applied, thanks!

    Karel


-- 
 Karel Zak  <kzak@redhat.com>
 http://karelzak.blogspot.com

Re: [PATCH] deadlock in script

[Ruediger Meier]

On Monday 02 June 2014, Karel Zak wrote:
> On Fri, May 30, 2014 at 06:52:20PM +0900, Csaba Kos wrote:
> > On Fri, May 30, 2014 at 6:15 PM, Karel Zak <kzak@redhat.com> wrote:
> > > On Fri, May 30, 2014 at 03:30:45PM +0900, Csaba Kos wrote:
> > >> diff --git a/term-utils/script.c b/term-utils/script.c
> > >> index e5d239c..32906d0 100644
> > >> --- a/term-utils/script.c
> > >> +++ b/term-utils/script.c
> > >> @@ -36,6 +36,9 @@
> > >>   * - added Native Language Support
> > >>   *
> > >>   * 2000-07-30 Per Andreas Buer <per@linpro.no> - added
> > >> "q"-option + *
> > >> + * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
> > >> + * - fixed a rare deadlock after child termination
> > >>   */
> > >>
> > >>  /*
> > >> @@ -114,6 +117,8 @@ int       tflg = 0;
> > >>  int  forceflg = 0;
> > >>  int  isterm;
> > >>
> > >> +sigset_t block_mask, unblock_mask;
> > >
> > >  This declaration shadows declaration in main() where is also
> > > block_mask and unblock_mask -- I guess it's not expected.
> >
> > Sorry, I goofed when updating my patch to the current master.
> > Thanks for the careful review! Updated patch attached.
>
>  All applied, thanks!
>
>     Karel

Could this already fix the TODO in
tests/ts/script/race (6cae66ea)?:

# TODO see comments about script design
# https://github.com/karelzak/util-linux/pull/62
TS_KNOWN_FAIL="yes"


cu,
Rudi

Re: [PATCH] deadlock in script

[Karel Zak]

On Mon, Jun 02, 2014 at 11:37:59AM +0200, Ruediger Meier wrote:
> On Monday 02 June 2014, Karel Zak wrote:
> > On Fri, May 30, 2014 at 06:52:20PM +0900, Csaba Kos wrote:
> > > On Fri, May 30, 2014 at 6:15 PM, Karel Zak <kzak@redhat.com> wrote:
> > > > On Fri, May 30, 2014 at 03:30:45PM +0900, Csaba Kos wrote:
> > > >> diff --git a/term-utils/script.c b/term-utils/script.c
> > > >> index e5d239c..32906d0 100644
> > > >> --- a/term-utils/script.c
> > > >> +++ b/term-utils/script.c
> > > >> @@ -36,6 +36,9 @@
> > > >>   * - added Native Language Support
> > > >>   *
> > > >>   * 2000-07-30 Per Andreas Buer <per@linpro.no> - added
> > > >> "q"-option + *
> > > >> + * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
> > > >> + * - fixed a rare deadlock after child termination
> > > >>   */
> > > >>
> > > >>  /*
> > > >> @@ -114,6 +117,8 @@ int       tflg = 0;
> > > >>  int  forceflg = 0;
> > > >>  int  isterm;
> > > >>
> > > >> +sigset_t block_mask, unblock_mask;
> > > >
> > > >  This declaration shadows declaration in main() where is also
> > > > block_mask and unblock_mask -- I guess it's not expected.
> > >
> > > Sorry, I goofed when updating my patch to the current master.
> > > Thanks for the careful review! Updated patch attached.
> >
> >  All applied, thanks!
> >
> >     Karel
> 
> Could this already fix the TODO in
> tests/ts/script/race (6cae66ea)?:

 That's a good question, maybe, try it :-)

 Locally I don't see any issue (although the test takes a lot of time
 due to count=1000, I'm still curious if we really need so many
 iterations in the test).

    Karel

-- 
 Karel Zak  <kzak@redhat.com>
 http://karelzak.blogspot.com

Re: [PATCH] deadlock in script

[Ruediger Meier]

On Monday 02 June 2014, Karel Zak wrote:
> On Mon, Jun 02, 2014 at 11:37:59AM +0200, Ruediger Meier wrote:
> > On Monday 02 June 2014, Karel Zak wrote:
> > > On Fri, May 30, 2014 at 06:52:20PM +0900, Csaba Kos wrote:
> > > > On Fri, May 30, 2014 at 6:15 PM, Karel Zak <kzak@redhat.com> wrote:
> > > > > On Fri, May 30, 2014 at 03:30:45PM +0900, Csaba Kos wrote:
> > > > >> diff --git a/term-utils/script.c b/term-utils/script.c
> > > > >> index e5d239c..32906d0 100644
> > > > >> --- a/term-utils/script.c
> > > > >> +++ b/term-utils/script.c
> > > > >> @@ -36,6 +36,9 @@
> > > > >>   * - added Native Language Support
> > > > >>   *
> > > > >>   * 2000-07-30 Per Andreas Buer <per@linpro.no> - added
> > > > >> "q"-option + *
> > > > >> + * 2014-05-30 Csaba Kos <csaba.kos@gmail.com>
> > > > >> + * - fixed a rare deadlock after child termination
> > > > >>   */
> > > > >>
> > > > >>  /*
> > > > >> @@ -114,6 +117,8 @@ int       tflg = 0;
> > > > >>  int  forceflg = 0;
> > > > >>  int  isterm;
> > > > >>
> > > > >> +sigset_t block_mask, unblock_mask;
> > > > >
> > > > >  This declaration shadows declaration in main() where is also
> > > > > block_mask and unblock_mask -- I guess it's not expected.
> > > >
> > > > Sorry, I goofed when updating my patch to the current master.
> > > > Thanks for the careful review! Updated patch attached.
> > >
> > >  All applied, thanks!
> > >
> > >     Karel
> >
> > Could this already fix the TODO in
> > tests/ts/script/race (6cae66ea)?:
>
>  That's a good question, maybe, try it :-)
>
>  Locally I don't see any issue (although the test takes a lot of time
>  due to count=1000, I'm still curious if we really need so many
>  iterations in the test).
>

Hm, I could still catch one again:
--- tests/expected/script/race      2014-05-27 11:12:51.367615962 +0200
+++ tests/output/script/race  2014-06-02 11:34:54.509072271 +0200
@@ -1 +1 @@
-all bingos seen
+only 996 of 1000 bingos seen

Actually it seems to be easy to get it failed on NFS mount. But I've grepped
a lot of my other build logs and couldn't find any script failure within the
last weeks.

cu,
Rudi