Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[Chris Hofstaedtler]

[adding util-linux@vger.kernel.org to CC:]

Dear наб,

thank you for your report.

* наб <nabijaczleweli@nabijaczleweli.xyz> [220104 00:06]:
> Package: bsdutils
> Version: 1:2.37.2-5
> Severity: normal
> File: /usr/bin/script
> 
> Dear Maintainer,
> 
> Consider the following:
>   $ script -c 'for i in $(seq 10); do echo $i; done; read -r a; echo a=$a' < term-utils/script.c
> 
> What do you expect to happen here? Well, numbers 1-10, of course, then
> "a=/*" from the heading, right?
> 
> This is, of course, a trick question: that holds on 4.4BSD-Lite script.
>
> However, util-linux script returns:
>   Script started, output log file is 'typescript'.
>
> That's it, it hangs. Due to the funny nature of signal handling here,
> you have to terminate it from a different terminal.
> 
> Stracing it reveals the nature of this beast:
>   $ strace -eread,write,poll script -c 'for i in $(seq 10); do echo a; sleep 0.1; done; read -r a; echo a=$a' < term-utils/script.c
>   read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\22\0\0\0\0\0\0"..., 832) = 832
>   read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@n\2\0\0\0\0\0"..., 832) = 832
>   read(3, "# Locale name alias data base.\n#"..., 3072) = 2996
>   read(3, "", 3072)                       = 0
>   write(1, "Script started, output log file "..., 49Script started, output log file is 'typescript'.
>   ) = 49
>   read(4, "# /etc/nsswitch.conf\n#\n# Example"..., 512) = 510
>   read(4, "", 512)                        = 0
>   read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0003\0\0\0\0\0\0"..., 832) = 832
>   read(4, "root:x:0:\ndaemon:x:1:\nbin:x:2:\ns"..., 2048) = 1768
>   read(7, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\v\0\0\0\v\0\0\0\0"..., 3072) = 2696
>   read(7, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\v\0\0\0\v\0\0\0\0"..., 3072) = 1698
>   poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}, {fd=3, events=POLLIN|POLLERR|POLLHUP}, {fd=0, events=POLLIN|POLLERR|POLLHUP}], 3, -1) = 1 ([{fd=0, revents=POLLIN}])
>   read(0, "/*\n * Copyright (C) 1980      Re"..., 8192) = 8192
>   write(3, "/*\n * Copyright (C) 1980      Re"..., 8192) = 8192
>   poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}, {fd=3, events=POLLIN|POLLERR|POLLHUP}, {fd=0, events=POLLIN|POLLERR|POLLHUP}], 3, -1) = 2 ([{fd=3, revents=POLLIN}, {fd=0, revents=POLLIN}])
>   read(3, "/*\r\n * Copyright (C) 1980      R"..., 8192) = 499
>   write(1, "/*\r\n * Copyright (C) 1980      R"..., 499/*
>    * Copyright (C) 1980      Regents of the University of California.
>    * Copyright (C) 2013-2019 Karel Zak <kzak@redhat.com>
>    *
>    * All rights reserved.
>    *
>    * Redistribution and use in source and binary forms, with or without
>    * modification, are permitted provided that the following conditions
>    * are met:
>    * 1. Redistributions of source code must retain the above copyright
>    *    notice, this list of conditions and the following disclaimer.
>    * 2. Redistributions in binary form must r) = 499
>   read(0, "n log;\t/* already defined */\n\n\tl"..., 8192) = 8192
>   write(3, "n log;\t/* already defined */\n\n\tl"..., 8192
> 
> (This, at least, responds to ^\, but it also seems to function
>  slightly differently. Also, this is a race and you're more
>  likely to lose it under strace. The loopy thing seems
>  like it's pretty good at hitting it 100% of the time.)
> 
> script is deadlocked on writing to the master pty
> against the child writing its data.
> 
> I've found this when re-writing NetBSD script(1) to use a single process
> and poll(2), because I saw poll() in this implementation's strace.
> There are a few ways I see to potentially work around this:
>   1. poll() the master PTY on POLLOUT, too; this doesn't work on NetBSD,
>      because writes to ptys don't seem to shard there ‒ even if the
>      master pty is POLLOUT, writing 1024 bytes to it will block forever,
>      but maybe it will on Linux;
>   2. Forcibly interrupt the write call with an alarm. This sucks ass,
>      of course, but it's the least intrusive if it does work.
>   3. In the original implementation, there's two controlling processes:
>        leader       ‒ main()     ‒ copies stdin to the master pty
>          child      ‒ dooutput() ‒ copies master pty to stdout/fscript
>            subchild ‒ doshell()  ‒ execs $SHELL -i/sh -c "command"
> 
> The original implementation is fundamentally not susceptible to this,
> techically making this the rare "regression against 4.4BSD-Lite".


Alright. Some questions:

1) is this Debian-specific or already present upstream?

2) did this work with previous versions of util-linux?

> Best,
> наб

Best,
Chris

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[наб]

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

Control: tags -1 + upstream

On Tue, Jan 04, 2022 at 05:24:54PM +0100, Chris Hofstaedtler wrote:
> * наб <nabijaczleweli@nabijaczleweli.xyz> [220104 00:06]:
> > (This, at least, responds to ^\, but it also seems to function
> >  slightly differently. Also, this is a race and you're more
> >  likely to lose it under strace. The loopy thing seems
> >  like it's pretty good at hitting it 100% of the time.)
As an additional note, because it's a race, if you're using bash,
  script < some-photo.jpeg
also hangs, because setup takes long enough.

> 1) is this Debian-specific or already present upstream?
Debian doesn't patch script.c at all, so this is an upstream bug.

> 2) did this work with previous versions of util-linux?
The oldest one I fould from the site at Homepage: in d/control is
"util-linux-ng 2.13", dated 19.1.2012. It's much closer to the original
4.4BSD-Lite implementation and still forks twice. As expected, testing
reveals it does not have the bug.

Performing a simple manual bisect across the versions available therein
reveals that 2.25 is the first broken version. (Though, skimming the
source, with a slightly different code path (select(2)?), since it still
double-forks and is not so hard-stuck so as to be immune to ^\.)

The first version that does get hard-stuck (because it forks once
and only uses poll) is 2.27.

> Best,
> Chris
Best,
наб

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[Karel Zak]

On Tue, Jan 04, 2022 at 06:31:24PM +0100, наб wrote:
> Control: tags -1 + upstream
> 
> On Tue, Jan 04, 2022 at 05:24:54PM +0100, Chris Hofstaedtler wrote:
> > * наб <nabijaczleweli@nabijaczleweli.xyz> [220104 00:06]:
> > > (This, at least, responds to ^\, but it also seems to function
> > >  slightly differently. Also, this is a race and you're more
> > >  likely to lose it under strace. The loopy thing seems
> > >  like it's pretty good at hitting it 100% of the time.)
> As an additional note, because it's a race, if you're using bash,
>   script < some-photo.jpeg
> also hangs, because setup takes long enough.
> 
> > 1) is this Debian-specific or already present upstream?
> Debian doesn't patch script.c at all, so this is an upstream bug.
> 
> > 2) did this work with previous versions of util-linux?
> The oldest one I fould from the site at Homepage: in d/control is
> "util-linux-ng 2.13", dated 19.1.2012. It's much closer to the original
> 4.4BSD-Lite implementation and still forks twice. As expected, testing
> reveals it does not have the bug.
> 
> Performing a simple manual bisect across the versions available therein
> reveals that 2.25 is the first broken version. (Though, skimming the
> source, with a slightly different code path (select(2)?), since it still
> double-forks and is not so hard-stuck so as to be immune to ^\.)
> 
> The first version that does get hard-stuck (because it forks once
> and only uses poll) is 2.27.

Resolve the problem with the signal should be simple. Now it
ignores all when it write to the master. Something like:


diff --git a/lib/pty-session.c b/lib/pty-session.c
index 6f038e1c5..84ea33860 100644
--- a/lib/pty-session.c
+++ b/lib/pty-session.c
@@ -292,7 +292,20 @@ static int write_output(char *obuf, ssize_t bytes)
 
 static int write_to_child(struct ul_pty *pty, char *buf, size_t bufsz)
 {
-       return write_all(pty->master, buf, bufsz);
+       sigset_t set, org;
+       int rc;
+
+       sigemptyset(&set);
+       sigemptyset(&org);
+       sigaddset(&set, SIGINT);
+       sigaddset(&set, SIGTERM);
+
+       sigprocmask(SIG_UNBLOCK, &set, &org);
+
+       rc = write_all(pty->master, buf, bufsz);
+
+       sigprocmask(SIG_SETMASK, &org, NULL);
+       return rc;
 }


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

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[наб]

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

FTR: I've also reported this bug against FreeBSD, which uses a similar
model but with select(2):
  https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=260938

The proposed patch consists of requesting O_NONBLOCK on the master pty
and stashing the input received from the child into a buffer,
pending such a time that the write won't block:
  https://reviews.freebsd.org/D33789

This seems much easier to apply to the current single-process util-linux
model (which is to say: I've tried to cleave the current implementation
into two processes and failed miserably).

наб

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[наб]

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

Control: tag -1 + patch

Hi!

See scissor-patch, below, which fixes this.

I tortured it a bit and ironed out all the problems I could find;
both script and test_pty work (well, test_pty still doesn't process
newlines properly but it was like that when I found it).

Best,
наб

-- >8 --
Subject: Put master PTY into non-blocking mode and buffer its output
 to avoid deadlock

If we filled the script->child buffer before the child had a chance
to read any input, we'd sleep forever in write_all(pty->master),
and the child would sleep forever in write(1<pty->slave>)

By putting the master PTY in non-blocking mode, we can
poll(pty->master, POLLOUT) and keep supplying more data
as the child reads from the buffer

Fixes Debian bug #1003095
---
pty-session.h: +7
pty-session.c: +90 -23

--- util-linux-2.37.2.orig/include/pty-session.h
+++ util-linux-2.37.2/include/pty-session.h
@@ -81,6 +81,13 @@ struct ul_pty {
 
 	struct timeval	next_callback_time;
 
+	struct ul_pty_child_buffer {
+		struct ul_pty_child_buffer *next;
+		char buf[BUFSIZ];
+		size_t size, cursor;
+		unsigned int final_input:1;	/* drain child before writing */
+	} *child_buffer_head, *child_buffer_tail;
+
 	unsigned int isterm:1,		/* is stdin terminal? */
 		     slave_echo:1;	/* keep ECHO on pty slave */
 };
--- util-linux-2.37.2.orig/lib/pty-session.c
+++ util-linux-2.37.2/lib/pty-session.c
@@ -69,6 +69,10 @@ struct ul_pty *ul_new_pty(int is_stdin_t
 
 void ul_free_pty(struct ul_pty *pty)
 {
+	for(struct ul_pty_child_buffer *hd; (hd = pty->child_buffer_head);) {
+		pty->child_buffer_head = hd->next;
+		free(hd);
+	}
 	free(pty);
 }
 
@@ -182,7 +186,7 @@ int ul_pty_setup(struct ul_pty *pty)
 		cfmakeraw(&attrs);
 		tcsetattr(STDIN_FILENO, TCSANOW, &attrs);
 	} else {
-	        DBG(SETUP, ul_debugobj(pty, "create for non-terminal"));
+		DBG(SETUP, ul_debugobj(pty, "create for non-terminal"));
 
 		rc = openpty(&pty->master, &pty->slave, NULL, NULL, NULL);
 		if (rc)
@@ -198,6 +202,8 @@ int ul_pty_setup(struct ul_pty *pty)
 		tcsetattr(pty->slave, TCSANOW, &attrs);
 	}
 
+	fcntl(pty->master, F_SETFL, O_NONBLOCK);
+
 	sigfillset(&ourset);
 	if (sigprocmask(SIG_BLOCK, &ourset, NULL)) {
 		rc = -errno;
@@ -290,9 +296,21 @@ static int write_output(char *obuf, ssiz
 	return 0;
 }
 
-static int write_to_child(struct ul_pty *pty, char *buf, size_t bufsz)
+static int schedule_child_write(struct ul_pty *pty, char *buf, size_t bufsz, int final)
 {
-	return write_all(pty->master, buf, bufsz);
+	struct ul_pty_child_buffer *stash = calloc(1, sizeof(*stash));
+	if (!stash)
+		return -1;
+
+	memcpy(stash->buf, buf, bufsz);
+	stash->size = bufsz;
+	stash->final_input = final ? 1 : 0;
+
+	if (pty->child_buffer_head)
+		pty->child_buffer_tail = pty->child_buffer_tail->next = stash;
+	else
+		pty->child_buffer_head = pty->child_buffer_tail = stash;
+	return 0;
 }
 
 /*
@@ -311,16 +329,13 @@ static int write_to_child(struct ul_pty
  * maintains master+slave tty stuff within the session. Use pipe to write to
  * pty and assume non-interactive (tee-like) behavior is NOT well supported.
  */
-void ul_pty_write_eof_to_child(struct ul_pty *pty)
+static void drain(struct ul_pty *pty)
 {
 	unsigned int tries = 0;
-	struct pollfd fds[] = {
-	           { .fd = pty->slave, .events = POLLIN }
-	};
-	char c = DEF_EOF;
+	struct pollfd fd = { .fd = pty->slave, .events = POLLIN };
 
 	DBG(IO, ul_debugobj(pty, " waiting for empty slave"));
-	while (poll(fds, 1, 10) == 1 && tries < 8) {
+	while (poll(&fd, 1, 10) == 1 && tries < 8) {
 		DBG(IO, ul_debugobj(pty, "   slave is not empty"));
 		xusleep(250000);
 		tries++;
@@ -329,7 +344,51 @@ void ul_pty_write_eof_to_child(struct ul
 		DBG(IO, ul_debugobj(pty, "   slave is empty now"));
 
 	DBG(IO, ul_debugobj(pty, " sending EOF to master"));
-	write_to_child(pty, &c, sizeof(char));
+}
+
+static int flush_child_buffers(struct ul_pty *pty, int *anything)
+{
+	int ret = 0, any = 0;
+	while (pty->child_buffer_head) {
+		struct ul_pty_child_buffer *hd = pty->child_buffer_head;
+
+		if(hd->final_input)
+			drain(pty);
+
+		DBG(IO, ul_debugobj(hd, " stdin --> master trying %zu bytes", hd->size - hd->cursor));
+		ssize_t ret = write(pty->master, hd->buf + hd->cursor, hd->size - hd->cursor);
+		if (ret == -1) {
+			DBG(IO, ul_debugobj(hd, "   EAGAIN"));
+			if (!(errno == EINTR || errno == EAGAIN))
+				ret = -errno;
+			goto out;
+		}
+		DBG(IO, ul_debugobj(hd, "   wrote %zd", ret));
+		any = 1;
+		hd->cursor += ret;
+		if (hd->cursor == hd->size) {
+			pty->child_buffer_head = hd->next;
+			if(!hd->next)
+				pty->child_buffer_tail = NULL;
+			free(hd);
+		}
+	}
+
+out:
+	/* without sync write_output() will write both input &
+	 * shell output that looks like double echoing */
+	if (any)
+		fdatasync(pty->master);
+
+	if (anything)
+		*anything = any;
+	return ret;
+}
+
+void ul_pty_write_eof_to_child(struct ul_pty *pty)
+{
+	char c = DEF_EOF;
+	schedule_child_write(pty, &c, sizeof(char), 1);
 }
 
 static int mainloop_callback(struct ul_pty *pty)
@@ -362,7 +421,7 @@ static int handle_io(struct ul_pty *pty,
 	/* read from active FD */
 	bytes = read(fd, buf, sizeof(buf));
 	sigprocmask(SIG_BLOCK, &set, NULL);
-	if (bytes < 0) {
+	if (bytes == -1) {
 		if (errno == EAGAIN || errno == EINTR)
 			return 0;
 		return -errno;
@@ -375,15 +434,11 @@ static int handle_io(struct ul_pty *pty,
 
 	/* from stdin (user) to command */
 	if (fd == STDIN_FILENO) {
-		DBG(IO, ul_debugobj(pty, " stdin --> master %zd bytes", bytes));
+		DBG(IO, ul_debugobj(pty, " stdin --> master %zd bytes queued", bytes));
 
-		if (write_to_child(pty, buf, bytes))
+		if (schedule_child_write(pty, buf, bytes, 0))
 			return -errno;
 
-		/* without sync write_output() will write both input &
-		 * shell output that looks like double echoing */
-		fdatasync(pty->master);
-
 	/* from command (master) to stdout */
 	} else if (fd == pty->master) {
 		DBG(IO, ul_debugobj(pty, " master --> stdout %zd bytes", bytes));
@@ -567,6 +622,11 @@ int ul_pty_proxy_master(struct ul_pty *p
 		} else
 			timeout = pty->poll_timeout;
 
+		if (pty->child_buffer_head)
+			pfd[POLLFD_MASTER].events |= POLLOUT;
+		else
+			pfd[POLLFD_MASTER].events &= ~POLLOUT;
+
 		/* wait for input, signal or timeout */
 		DBG(IO, ul_debugobj(pty, "calling poll() [timeout=%dms]", timeout));
 		ret = poll(pfd, ARRAY_SIZE(pfd), timeout);
@@ -600,23 +660,30 @@ int ul_pty_proxy_master(struct ul_pty *p
 			if (pfd[i].revents == 0)
 				continue;
 
-			DBG(IO, ul_debugobj(pty, " active pfd[%s].fd=%d %s %s %s %s",
+			DBG(IO, ul_debugobj(pty, " active pfd[%s].fd=%d %s %s %s %s %s",
 						i == POLLFD_STDIN  ? "stdin" :
 						i == POLLFD_MASTER ? "master" :
 						i == POLLFD_SIGNAL ? "signal" : "???",
 						pfd[i].fd,
 						pfd[i].revents & POLLIN  ? "POLLIN" : "",
+						pfd[i].revents & POLLOUT ? "POLLOUT" : "",
 						pfd[i].revents & POLLHUP ? "POLLHUP" : "",
 						pfd[i].revents & POLLERR ? "POLLERR" : "",
 						pfd[i].revents & POLLNVAL ? "POLLNVAL" : ""));
 
 			if (i == POLLFD_SIGNAL)
 				rc = handle_signal(pty, pfd[i].fd);
-			else if (pfd[i].revents & POLLIN)
-				rc = handle_io(pty, pfd[i].fd, &eof); /* data */
+			else {
+				if (pfd[i].revents & POLLIN)
+					rc = handle_io(pty, pfd[i].fd, &eof); /* data */
+				if (pfd[i].revents & POLLOUT) /* i == POLLFD_MASTER */
+					rc = flush_child_buffers(pty, NULL);
+			}
 
 			if (rc) {
 				ul_pty_write_eof_to_child(pty);
+				for (int anything = 1; anything;)
+					flush_child_buffers(pty, &anything);
 				break;
 			}
 
@@ -631,11 +698,11 @@ int ul_pty_proxy_master(struct ul_pty *p
 			 */
 			if ((pfd[i].revents & POLLHUP) || (pfd[i].revents & POLLNVAL) || eof) {
 				DBG(IO, ul_debugobj(pty, " ignore FD"));
-				pfd[i].fd = -1;
 				if (i == POLLFD_STDIN) {
+					pfd[i].fd = -1;
 					ul_pty_write_eof_to_child(pty);
-					DBG(IO, ul_debugobj(pty, "  ignore STDIN"));
-				}
+				} else /* i == POLLFD_MASTER */
+					pfd[i].revents &= ~POLLIN;
 			}
 		}
 		if (rc)

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[наб]

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

Hi!

Bumping this patch after 2ish weeks :)

Best,

On Fri, Jan 14, 2022 at 12:28:12AM +0100, наб wrote:
> Subject: Put master PTY into non-blocking mode and buffer its output
>  to avoid deadlock
> 
> If we filled the script->child buffer before the child had a chance
> to read any input, we'd sleep forever in write_all(pty->master),
> and the child would sleep forever in write(1<pty->slave>)
> 
> By putting the master PTY in non-blocking mode, we can
> poll(pty->master, POLLOUT) and keep supplying more data
> as the child reads from the buffer
> 
> Fixes Debian bug #1003095

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[Karel Zak]

On Wed, Feb 02, 2022 at 03:49:38PM +0100, наб wrote:
> Bumping this patch after 2ish weeks :)

Sorry for my delay. 

Your solution seems elegant, but it seems to late for the next release
v2.38 (now rc1). I'll play with it next week and prepare it for v2.39.

   Karel

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

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[наб]

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

Hi!

On Thu, Feb 03, 2022 at 11:55:40AM +0100, Karel Zak wrote:
> Your solution seems elegant, but it seems to late for the next release
> v2.38 (now rc1). I'll play with it next week and prepare it for v2.39.

Bumping this now that 2.38 landed;
a quick test shows that it applies cleanly to HEAD
and works as-expected.

наб

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[Karel Zak]

On Fri, Jan 14, 2022 at 12:28:11AM +0100, наб wrote:
> -static int write_to_child(struct ul_pty *pty, char *buf, size_t bufsz)
> +static int schedule_child_write(struct ul_pty *pty, char *buf, size_t bufsz, int final)
>  {
> -	return write_all(pty->master, buf, bufsz);
> +	struct ul_pty_child_buffer *stash = calloc(1, sizeof(*stash));

It means that for each activity on the file descriptor it will
allocate a new buffer (in BUFSIZ). It seems pretty expensive.

Cannot we reuse the buffers? 

Maybe use include/list.h, define two lists, one for not-yet-written 
buffers and another for ready-to-use buffers and move from one list to
another in schedule_child_write() and flush_child_buffers().

> +	if (!stash)
> +		return -1;
> +
> +	memcpy(stash->buf, buf, bufsz);
> +	stash->size = bufsz;
> +	stash->final_input = final ? 1 : 0;
> +
> +	if (pty->child_buffer_head)
> +		pty->child_buffer_tail = pty->child_buffer_tail->next = stash;
> +	else
> +		pty->child_buffer_head = pty->child_buffer_tail = stash;
> +	return 0;
>  }
>  
>  /*
> @@ -311,16 +329,13 @@ static int write_to_child(struct ul_pty
>   * maintains master+slave tty stuff within the session. Use pipe to write to
>   * pty and assume non-interactive (tee-like) behavior is NOT well supported.
>   */
> -void ul_pty_write_eof_to_child(struct ul_pty *pty)
> +static void drain(struct ul_pty *pty)

drain_child_buffers() :-)


Anyway, it looks good.

    Karel



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

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[наб]

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

On Mon, Apr 11, 2022 at 12:08:06PM +0200, Karel Zak wrote:
> On Fri, Jan 14, 2022 at 12:28:11AM +0100, наб wrote:
> > -static int write_to_child(struct ul_pty *pty, char *buf, size_t bufsz)
> > +static int schedule_child_write(struct ul_pty *pty, char *buf, size_t bufsz, int final)
> >  {
> > -	return write_all(pty->master, buf, bufsz);
> > +	struct ul_pty_child_buffer *stash = calloc(1, sizeof(*stash));
> 
> It means that for each activity on the file descriptor it will
> allocate a new buffer (in BUFSIZ). It seems pretty expensive.
> 
> Cannot we reuse the buffers? 

Added pty->free_buffers where we put free-to-use (fully-written-out buffers)
instead of free()ing them; my testing indicates, that for interactive use
we allocate a single buffer and re-use 100% of the time.

> >  /*
> > @@ -311,16 +329,13 @@ static int write_to_child(struct ul_pty
> >   * maintains master+slave tty stuff within the session. Use pipe to write to
> >   * pty and assume non-interactive (tee-like) behavior is NOT well supported.
> >   */
> > -void ul_pty_write_eof_to_child(struct ul_pty *pty)
> > +static void drain(struct ul_pty *pty)
> 
> drain_child_buffers() :-)

Renamed; updated scissor-patch below.

Best,
наб

-- >8 --
Date: Fri, 14 Jan 2022 00:28:12 +0100
Subject: [PATCH v2] Put master PTY into non-blocking mode and buffer its
 output to avoid deadlock

If we filled the script->child buffer before the child had a chance
to read any input, we'd sleep forever in write_all(pty->master),
and the child would sleep forever in write(1<pty->slave>)

By putting the master PTY in non-blocking mode, we can
poll(pty->master, POLLOUT) and keep supplying more data
as the child reads from the buffer

Fixes Debian bug #1003095
---
 include/pty-session.h |   7 +++
 lib/pty-session.c     | 126 ++++++++++++++++++++++++++++++++++--------
 2 files changed, 110 insertions(+), 23 deletions(-)

diff --git a/include/pty-session.h b/include/pty-session.h
index 09eff43fd..7176d6ba7 100644
--- a/include/pty-session.h
+++ b/include/pty-session.h
@@ -81,6 +81,13 @@ struct ul_pty {
 
 	struct timeval	next_callback_time;
 
+	struct ul_pty_child_buffer {
+		struct ul_pty_child_buffer *next;
+		char buf[BUFSIZ];
+		size_t size, cursor;
+		unsigned int final_input:1;	/* drain child before writing */
+	} *child_buffer_head, *child_buffer_tail, *free_buffers;
+
 	unsigned int isterm:1,		/* is stdin terminal? */
 		     slave_echo:1;	/* keep ECHO on pty slave */
 };
diff --git a/lib/pty-session.c b/lib/pty-session.c
index 6f038e1c5..880f08d27 100644
--- a/lib/pty-session.c
+++ b/lib/pty-session.c
@@ -69,6 +69,15 @@ struct ul_pty *ul_new_pty(int is_stdin_tty)
 
 void ul_free_pty(struct ul_pty *pty)
 {
+	struct ul_pty_child_buffer *hd;
+	while((hd = pty->child_buffer_head)) {
+		pty->child_buffer_head = hd->next;
+		free(hd);
+	}
+	while((hd = pty->free_buffers)) {
+		pty->free_buffers = hd->next;
+		free(hd);
+	}
 	free(pty);
 }
 
@@ -182,7 +191,7 @@ int ul_pty_setup(struct ul_pty *pty)
 		cfmakeraw(&attrs);
 		tcsetattr(STDIN_FILENO, TCSANOW, &attrs);
 	} else {
-	        DBG(SETUP, ul_debugobj(pty, "create for non-terminal"));
+		DBG(SETUP, ul_debugobj(pty, "create for non-terminal"));
 
 		rc = openpty(&pty->master, &pty->slave, NULL, NULL, NULL);
 		if (rc)
@@ -198,6 +207,8 @@ int ul_pty_setup(struct ul_pty *pty)
 		tcsetattr(pty->slave, TCSANOW, &attrs);
 	}
 
+	fcntl(pty->master, F_SETFL, O_NONBLOCK);
+
 	sigfillset(&ourset);
 	if (sigprocmask(SIG_BLOCK, &ourset, NULL)) {
 		rc = -errno;
@@ -290,9 +301,27 @@ static int write_output(char *obuf, ssize_t bytes)
 	return 0;
 }
 
-static int write_to_child(struct ul_pty *pty, char *buf, size_t bufsz)
+static int schedule_child_write(struct ul_pty *pty, char *buf, size_t bufsz, int final)
 {
-	return write_all(pty->master, buf, bufsz);
+	struct ul_pty_child_buffer *stash;
+	if (pty->free_buffers) {
+		stash = pty->free_buffers;
+		pty->free_buffers = stash->next;
+		memset(stash, 0, sizeof(*stash));
+	} else
+		stash = calloc(1, sizeof(*stash));
+	if (!stash)
+		return -1;
+
+	memcpy(stash->buf, buf, bufsz);
+	stash->size = bufsz;
+	stash->final_input = final ? 1 : 0;
+
+	if (pty->child_buffer_head)
+		pty->child_buffer_tail = pty->child_buffer_tail->next = stash;
+	else
+		pty->child_buffer_head = pty->child_buffer_tail = stash;
+	return 0;
 }
 
 /*
@@ -311,16 +340,13 @@ static int write_to_child(struct ul_pty *pty, char *buf, size_t bufsz)
  * maintains master+slave tty stuff within the session. Use pipe to write to
  * pty and assume non-interactive (tee-like) behavior is NOT well supported.
  */
-void ul_pty_write_eof_to_child(struct ul_pty *pty)
+static void drain_child_buffers(struct ul_pty *pty)
 {
 	unsigned int tries = 0;
-	struct pollfd fds[] = {
-	           { .fd = pty->slave, .events = POLLIN }
-	};
-	char c = DEF_EOF;
+	struct pollfd fd = { .fd = pty->slave, .events = POLLIN };
 
 	DBG(IO, ul_debugobj(pty, " waiting for empty slave"));
-	while (poll(fds, 1, 10) == 1 && tries < 8) {
+	while (poll(&fd, 1, 10) == 1 && tries < 8) {
 		DBG(IO, ul_debugobj(pty, "   slave is not empty"));
 		xusleep(250000);
 		tries++;
@@ -329,7 +355,53 @@ void ul_pty_write_eof_to_child(struct ul_pty *pty)
 		DBG(IO, ul_debugobj(pty, "   slave is empty now"));
 
 	DBG(IO, ul_debugobj(pty, " sending EOF to master"));
-	write_to_child(pty, &c, sizeof(char));
+}
+
+static int flush_child_buffers(struct ul_pty *pty, int *anything)
+{
+	int ret = 0, any = 0;
+	while (pty->child_buffer_head) {
+		struct ul_pty_child_buffer *hd = pty->child_buffer_head;
+
+		if(hd->final_input)
+			drain_child_buffers(pty);
+
+		DBG(IO, ul_debugobj(hd, " stdin --> master trying %zu bytes", hd->size - hd->cursor));
+		ssize_t ret = write(pty->master, hd->buf + hd->cursor, hd->size - hd->cursor);
+		if (ret == -1) {
+			DBG(IO, ul_debugobj(hd, "   EAGAIN"));
+			if (!(errno == EINTR || errno == EAGAIN))
+				ret = -errno;
+			goto out;
+		}
+		DBG(IO, ul_debugobj(hd, "   wrote %zd", ret));
+		any = 1;
+		hd->cursor += ret;
+		if (hd->cursor == hd->size) {
+			pty->child_buffer_head = hd->next;
+			if(!hd->next)
+				pty->child_buffer_tail = NULL;
+
+			hd->next = pty->free_buffers;
+			pty->free_buffers = hd;
+		}
+	}
+
+out:
+	/* without sync write_output() will write both input &
+	 * shell output that looks like double echoing */
+	if (any)
+		fdatasync(pty->master);
+
+	if (anything)
+		*anything = any;
+	return ret;
+}
+
+void ul_pty_write_eof_to_child(struct ul_pty *pty)
+{
+	char c = DEF_EOF;
+	schedule_child_write(pty, &c, sizeof(char), 1);
 }
 
 static int mainloop_callback(struct ul_pty *pty)
@@ -362,7 +434,7 @@ static int handle_io(struct ul_pty *pty, int fd, int *eof)
 	/* read from active FD */
 	bytes = read(fd, buf, sizeof(buf));
 	sigprocmask(SIG_BLOCK, &set, NULL);
-	if (bytes < 0) {
+	if (bytes == -1) {
 		if (errno == EAGAIN || errno == EINTR)
 			return 0;
 		return -errno;
@@ -375,15 +447,11 @@ static int handle_io(struct ul_pty *pty, int fd, int *eof)
 
 	/* from stdin (user) to command */
 	if (fd == STDIN_FILENO) {
-		DBG(IO, ul_debugobj(pty, " stdin --> master %zd bytes", bytes));
+		DBG(IO, ul_debugobj(pty, " stdin --> master %zd bytes queued", bytes));
 
-		if (write_to_child(pty, buf, bytes))
+		if (schedule_child_write(pty, buf, bytes, 0))
 			return -errno;
 
-		/* without sync write_output() will write both input &
-		 * shell output that looks like double echoing */
-		fdatasync(pty->master);
-
 	/* from command (master) to stdout */
 	} else if (fd == pty->master) {
 		DBG(IO, ul_debugobj(pty, " master --> stdout %zd bytes", bytes));
@@ -567,6 +635,11 @@ int ul_pty_proxy_master(struct ul_pty *pty)
 		} else
 			timeout = pty->poll_timeout;
 
+		if (pty->child_buffer_head)
+			pfd[POLLFD_MASTER].events |= POLLOUT;
+		else
+			pfd[POLLFD_MASTER].events &= ~POLLOUT;
+
 		/* wait for input, signal or timeout */
 		DBG(IO, ul_debugobj(pty, "calling poll() [timeout=%dms]", timeout));
 		ret = poll(pfd, ARRAY_SIZE(pfd), timeout);
@@ -600,23 +673,30 @@ int ul_pty_proxy_master(struct ul_pty *pty)
 			if (pfd[i].revents == 0)
 				continue;
 
-			DBG(IO, ul_debugobj(pty, " active pfd[%s].fd=%d %s %s %s %s",
+			DBG(IO, ul_debugobj(pty, " active pfd[%s].fd=%d %s %s %s %s %s",
 						i == POLLFD_STDIN  ? "stdin" :
 						i == POLLFD_MASTER ? "master" :
 						i == POLLFD_SIGNAL ? "signal" : "???",
 						pfd[i].fd,
 						pfd[i].revents & POLLIN  ? "POLLIN" : "",
+						pfd[i].revents & POLLOUT ? "POLLOUT" : "",
 						pfd[i].revents & POLLHUP ? "POLLHUP" : "",
 						pfd[i].revents & POLLERR ? "POLLERR" : "",
 						pfd[i].revents & POLLNVAL ? "POLLNVAL" : ""));
 
 			if (i == POLLFD_SIGNAL)
 				rc = handle_signal(pty, pfd[i].fd);
-			else if (pfd[i].revents & POLLIN)
-				rc = handle_io(pty, pfd[i].fd, &eof); /* data */
+			else {
+				if (pfd[i].revents & POLLIN)
+					rc = handle_io(pty, pfd[i].fd, &eof); /* data */
+				if (pfd[i].revents & POLLOUT) /* i == POLLFD_MASTER */
+					rc = flush_child_buffers(pty, NULL);
+			}
 
 			if (rc) {
 				ul_pty_write_eof_to_child(pty);
+				for (int anything = 1; anything;)
+					flush_child_buffers(pty, &anything);
 				break;
 			}
 
@@ -631,11 +711,11 @@ int ul_pty_proxy_master(struct ul_pty *pty)
 			 */
 			if ((pfd[i].revents & POLLHUP) || (pfd[i].revents & POLLNVAL) || eof) {
 				DBG(IO, ul_debugobj(pty, " ignore FD"));
-				pfd[i].fd = -1;
 				if (i == POLLFD_STDIN) {
+					pfd[i].fd = -1;
 					ul_pty_write_eof_to_child(pty);
-					DBG(IO, ul_debugobj(pty, "  ignore STDIN"));
-				}
+				} else /* i == POLLFD_MASTER */
+					pfd[i].revents &= ~POLLIN;
 			}
 		}
 		if (rc)
-- 
2.30.2


[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Bug#1003095: /usr/bin/script: hangs when child doesn't read input fast enough

[Karel Zak]

On Tue, Apr 12, 2022 at 04:25:14PM +0200, наб wrote:
> Added pty->free_buffers where we put free-to-use (fully-written-out buffers)
> instead of free()ing them; my testing indicates, that for interactive use
> we allocate a single buffer and re-use 100% of the time.
 
Cool.

>  include/pty-session.h |   7 +++
>  lib/pty-session.c     | 126 ++++++++++++++++++++++++++++++++++--------
>  2 files changed, 110 insertions(+), 23 deletions(-)

Applied, thanks!

Please, next time use "Signed-off-by:" line :-)

    Karel


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