subtle `echo' bug

subtle `echo' bug

[Alexey Tourbin]

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

Hello,

I believe this is a bug:

$ seq 1 3 |while read n; do { echo |echo } |/bin/echo $n; done
1
2
3
$ seq 1 3 |while read n; do { echo |echo } |echo $n; done
1
$

(I've got recent 4.3 snapshot, built without unicode support.)

[-- Attachment #2: Type: application/pgp-signature, Size: 189 bytes --]

Re: subtle `echo' bug

[Andrey Borzenkov]

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

On Tuesday 14 June 2005 21:27, Alexey Tourbin wrote:
> Hello,
>
> I believe this is a bug:
>
> $ seq 1 3 |while read n; do { echo |echo } |/bin/echo $n; done
> 1
> 2
> 3
> $ seq 1 3 |while read n; do { echo |echo } |echo $n; done
> 1
> $
>
> (I've got recent 4.3 snapshot, built without unicode support.)
>

This happens randomly:

{pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
1
2
3
{pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
1
{pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
1
{pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
1
2
3
{pts/3}% echo $ZSH_VERSION
4.2.5

-andrey

[-- Attachment #2: Type: application/pgp-signature, Size: 189 bytes --]

Re: subtle `echo' bug

[Alexey Tourbin]

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

On Tue, Jun 14, 2005 at 10:12:23PM +0400, Andrey Borzenkov wrote:
> This happens randomly:
> 
> {pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
> 1
> 2
> 3
> {pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
> 1
> {pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
> 1
> {pts/3}% seq 1 3 |while read n; do { echo |echo } |echo $n; done
> 1
> 2
> 3
> {pts/3}% echo $ZSH_VERSION
> 4.2.5

I can't reproduce this, I always get "1".  And here is even more subtle
bug: I cannot go into infinite loop in order to prove that I always get "1".

$ while :; do seq 1 3 |while read n; do { echo |echo } |echo $n; done ; done
1
$ while :; do seq 1 3 |while read n; do { echo |echo } |echo $n; done ; done
1
$ while :; do seq 1 3 |while read n; do { echo |echo } |echo $n; done ; done
1
$ while :; do seq 1 3 |while read n; do { echo |echo } |echo $n; done ; done
1
$ while :; do seq 1 3 |while read n; do { echo |echo } |echo $n; done ; done
1
$

But:

$ while :; do seq 1 3 |while read n; do { echo |echo } |/bin/echo $n; done ; done
1
2
3
1
2
3
1
2
3
1
2
3
1
2
3
1
2
3
...
^C
$

[-- Attachment #2: Type: application/pgp-signature, Size: 189 bytes --]

Re: subtle `echo' bug

[Bart Schaefer]

On Jun 14, 10:12pm, Andrey Borzenkov wrote:
}
} This happens randomly

It's not a bug in echo, and the strange construct with the curly braces
has nothing to do with it.  Try this:

i=0
j=0
repeat 10 do
  i=0
  ((++j))
  seq 1 3 |while read n; do ((++i)); set | : $n; done
  print $i
done
print $i $j $n

Note that both loops exit, without ever executing "print $i", often
after only one pass.  (It's also important that you use a newline, not
a semicolon, after the final "done", or even the last "print" is not
executed.)

This affects any builtin that writes to its standard output, so the
problem is almost certainly resulting from a write error on stdout
because the builtin on the rightmost end of the pipeline is never
reading from its stdin.  When you use an external command on the far
right, a process is forked and the OS allocates some buffer space for
the pipe, and thus silently swallows the output; but when a builtin
is on the far right, that command is executed in the parent shell and
no such buffer is created.

You can see this in action by forcing external execution of the final
command by putting parens around it:

  seq 1 3 |while read n; do ((++i)); { : | set } | (: $n); done

I's sure you could also get the loop to fail with /bin/echo on the far
right by having the stuff inside { } emit a large enough volume to
overflow the OS pipe buffer.

In short, if you write nonsense code, you get nonsense results.  Don't
try to feed input to a command that doesn't want it.

Re: subtle `echo' bug

[Alexey Tourbin]

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

On Wed, Jun 15, 2005 at 12:28:44AM +0000, Bart Schaefer wrote:
> In short, if you write nonsense code, you get nonsense results.  Don't
> try to feed input to a command that doesn't want it.

It was quite a real command!  It was something like:

sort -u +2 list |while read v1 v2 v3; do {
	echo "$v1 has problems with $v2..." |fmt; grep -w $v2 list; } |
	echo /path/to/my/script --opt1=$v1 --opt2="$v2...$v3"; done

My /path/to/my/script script uses both command line options and stdin.
Because the script performs some action (i.e. it is "destructive"),
I used "echo" as a comment to find out and check twice the commands that
were going to be executed.  No matter what -- it said that the script
was going to be executed only once!  After some mangling I realized that
this was rather zsh problem.

Of course my reduced version with `seq' looks like a nonsense code. :)

[-- Attachment #2: Type: application/pgp-signature, Size: 189 bytes --]

Re: subtle `echo' bug

[Bart Schaefer]

On Jun 15, 11:48am, Alexey Tourbin wrote:
> Subject: Re: subtle `echo' bug
>
> On Wed, Jun 15, 2005 at 12:28:44AM +0000, Bart Schaefer wrote:
> > In short, if you write nonsense code, you get nonsense results.  Don't
> > try to feed input to a command that doesn't want it.
> 
> It was quite a real command!

I don't doubt that.  The point is that " ... | echo" is nonsense, no
matter what good reason you may have had for attempting it, because
that's writing on the standard input of a command that does not read
from standard input.

In other words, even with " ... | /bin/echo" in your example here:

>       ... {
> 	echo "$v1 has problems with $v2..." |fmt; grep -w $v2 list; } |
> 	/bin/echo ...

If "grep -w $v2 list" generates a sufficient volume of output, the pipe
on /bin/echo's stdin can fill up and the command may fail.  It's not a
zsh problem, it's a fundamental problem with the nature of unix pipes
and the way you're using them.

Zsh happens to make the problem show up sooner because the first echo
gets a write error when the second echo fails to read; but that's not
a bug, unless echo is somehow required never to fail on write error.

> I used "echo" as a comment to find out and check twice the commands that
> were going to be executed.

The right thing would be something like this, which reads and throws
away its input:

    { ... } | { cat > /dev/null; echo /path/to/my/script ... }

You could make a function:

    notreally() {
       [[ -t 0 ]] || cat > /dev/null
       print -R "$@"
    }

And then

    ... | notreally /path/to/my/script ...

Or, better still, since your script is parsing command line options,
add an option to it that tells it to run without doing its destructive
thing, so that you don't have to wrap it in another command to test it.

    ... | /path/to/my/script --notreally --opt...

Re: subtle `echo' bug

[Peter Stephenson]

Bart Schaefer wrote:
> This affects any builtin that writes to its standard output, so the
> problem is almost certainly resulting from a write error on stdout
> because the builtin on the rightmost end of the pipeline is never
> reading from its stdin.

You can show this up with

trap '' PIPE

which causes zsh to report the error as a side effect (for reasons I
haven't investigated: possibly the error message isn't getting time to
emerge in the other case, which may be a bug).  Alexey's original
example now gives variations on:

% seq 1 3 | while read n; do { echo | echo } | echo $n ; done
1
echo: write error: broken pipe
zsh: write error: broken pipe
2
3

The numbers always come out because the error is trapped, but the
messages show where the write failed because of SIGPIPE.

-- 
Peter Stephenson <pws@csr.com>                  Software Engineer
CSR PLC, Churchill House, Cambridge Business Park, Cowley Road
Cambridge, CB4 0WZ, UK                          Tel: +44 (0)1223 692070


**********************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager.

**********************************************************************

Re: subtle `echo' bug

[Peter Stephenson]

Peter Stephenson wrote:
> You can show this up with
> 
> trap '' PIPE
> 
> which causes zsh to report the error as a side effect (for reasons I
> haven't investigated: possibly the error message isn't getting time to
> emerge in the other case, which may be a bug).

This is rather garbled: the error message shown was a write error which
you certainly wouldn't see if the process that failed to write received
a SIGPIPE.  The question is whether the rest of the shell should
indicate the failure.  I think some shells indicate when a child
received SIGPIPE.

Experimentation suggests a SIGPIPE to a subprocess in a pipeline in
other shells doesn't cause the shell to abort execution.  I'm not sure
where the logic in zsh is that's causing this.

-- 
Peter Stephenson <pws@csr.com>                  Software Engineer
CSR PLC, Churchill House, Cambridge Business Park, Cowley Road
Cambridge, CB4 0WZ, UK                          Tel: +44 (0)1223 692070


**********************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager.

**********************************************************************

Re: subtle `echo' bug

[Bart Schaefer]

On Jun 15,  2:56pm, Peter Stephenson wrote:
}
} This is rather garbled: the error message shown was a write error which
} you certainly wouldn't see if the process that failed to write received
} a SIGPIPE.

SIGPIPE is one of those signals that causes a process to exit if it is
not trapped, and zsh does not trap it.  So there's no opportunity for
the error message to be printed.

} Experimentation suggests a SIGPIPE to a subprocess in a pipeline in
} other shells doesn't cause the shell to abort execution.  I'm not sure
} where the logic in zsh is that's causing this.

Since SIGPIPE is causing the child process to exit, it's the SIGCHLD
handler in the parent that's at issue.  Ultimately I believe it's this
code in update_job():

		/* If we have `foo|while true; (( x++ )); done', and hit
		 * ^C, we have to stop the loop, too. */
		if ((val & 0200) && inforeground == 1) {
		    if (!errbrk_saved) {
			errbrk_saved = 1;
			prev_breaks = breaks;
			prev_errflag = errflag;
		    }
		    breaks = loops;
		    errflag = 1;
		    inerrflush();
		}

I've verified that (val & 0200) == 128 in this instance, which is not
distinguishable from the child having received a SIGINT.

Related may be this comment in zwaitjob():

	    /* Commenting this out makes ^C-ing a job started by a function
	       stop the whole function again.  But I guess it will stop
	       something else from working properly, we have to find out
	       what this might be.  --oberon

	    errflag = 0; */

(Golly, I'd completely forgotten about Oberon.  That comment goes back a
decade at least.)

So, we could try this patch:

Index: Src/jobs.c
===================================================================
RCS file: /extra/cvsroot/zsh/zsh-4.0/Src/jobs.c,v
retrieving revision 1.15
diff -c -r1.15 jobs.c
--- Src/jobs.c	26 Mar 2005 16:14:05 -0000	1.15
+++ Src/jobs.c	15 Jun 2005 15:26:07 -0000
@@ -383,7 +383,8 @@
 		}
 		/* If we have `foo|while true; (( x++ )); done', and hit
 		 * ^C, we have to stop the loop, too. */
-		if ((val & 0200) && inforeground == 1) {
+		if ((val & 0200) && inforeground == 1 &&
+		    (val - 128 != SIGPIPE)) {
 		    if (!errbrk_saved) {
 			errbrk_saved = 1;
 			prev_breaks = breaks;
@@ -399,7 +400,8 @@
 		adjustwinsize(0);
 	    }
 	}
-    } else if (list_pipe && (val & 0200) && inforeground == 1) {
+    } else if (list_pipe && (val & 0200) && inforeground == 1 &&
+	       (val - 128 != SIGPIPE)) {
 	if (!errbrk_saved) {
 	    errbrk_saved = 1;
 	    prev_breaks = breaks;

Re: subtle `echo' bug

[Peter Stephenson]

Bart Schaefer wrote:
> On Jun 15,  2:56pm, Peter Stephenson wrote:
> }
> } This is rather garbled: the error message shown was a write error which
> } you certainly wouldn't see if the process that failed to write received
> } a SIGPIPE.
> 
> SIGPIPE is one of those signals that causes a process to exit if it is
> not trapped, and zsh does not trap it.  So there's no opportunity for
> the error message to be printed.

That's what I was trying to say in a somewhat garbled fashion.

> } Experimentation suggests a SIGPIPE to a subprocess in a pipeline in
> } other shells doesn't cause the shell to abort execution.
>
> So, we could try this patch:

Seems OK so far; are the other signals we should be treating similarly?

Would it be safer to use WTERMSIG(val) instead of (val - 128)?

-- 
Peter Stephenson <pws@csr.com>                  Software Engineer
CSR PLC, Churchill House, Cambridge Business Park, Cowley Road
Cambridge, CB4 0WZ, UK                          Tel: +44 (0)1223 692070


**********************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager.

**********************************************************************

Re: subtle `echo' bug

[Bart Schaefer]

On Jun 15,  4:49pm, Peter Stephenson wrote:
}
} Seems OK so far; are the other signals we should be treating similarly?

Since this only affects interactive shells, we could consider breaking
the loop only on SIGINT and SIGQUIT (that is, on keyboard-generated
signals).  As is the loop ends on e.g. SIGSEGV, or any other process-
killing signal that hits a child.

I'm not sure what to say about SIGHUP, though.
 
} Would it be safer to use WTERMSIG(val) instead of (val - 128)?

Oh, yes, it would.  I've been doing this too long, I never think of
those newfangled macros. :-}

Re: subtle `echo' bug

[Peter Stephenson]

Bart Schaefer wrote:
> On Jun 15,  4:49pm, Peter Stephenson wrote:
> }
> } Seems OK so far; are the other signals we should be treating similarly?
> 
> Since this only affects interactive shells, we could consider breaking
> the loop only on SIGINT and SIGQUIT (that is, on keyboard-generated
> signals).  As is the loop ends on e.g. SIGSEGV, or any other process-
> killing signal that hits a child.
> 
> I'm not sure what to say about SIGHUP, though.

One might hope any well-behaved SIGHUP would go to the parent shell, too.
One might also wonder whether SIGTERM should behave like SIGINT.
However, the idea that only signals that come from the keyboard behave
differently in interactive and non-interactive shells does sound quite
attractive.

-- 
Peter Stephenson <pws@csr.com>                  Software Engineer
CSR PLC, Churchill House, Cambridge Business Park, Cowley Road
Cambridge, CB4 0WZ, UK                          Tel: +44 (0)1223 692070


**********************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager.

**********************************************************************

Re: subtle `echo' bug

[Peter Stephenson]

Bart Schaefer wrote:
> Since this only affects interactive shells, we could consider breaking
> the loop only on SIGINT and SIGQUIT (that is, on keyboard-generated
> signals).  As is the loop ends on e.g. SIGSEGV, or any other process-
> killing signal that hits a child.

Are we going to do this?


Index: Src/jobs.c
===================================================================
RCS file: /cvsroot/zsh/zsh/Src/jobs.c,v
retrieving revision 1.39
diff -u -r1.39 jobs.c
--- Src/jobs.c	1 Jun 2005 10:45:42 -0000	1.39
+++ Src/jobs.c	27 Jun 2005 10:01:24 -0000
@@ -383,7 +383,8 @@
 		}
 		/* If we have `foo|while true; (( x++ )); done', and hit
 		 * ^C, we have to stop the loop, too. */
-		if ((val & 0200) && inforeground == 1) {
+		if ((val & 0200) && inforeground == 1 &&
+		    (WTERMSIG(val) == SIGINT || WTERMSIG(val) == SIGQUIT)) {
 		    if (!errbrk_saved) {
 			errbrk_saved = 1;
 			prev_breaks = breaks;
@@ -399,7 +400,8 @@
 		adjustwinsize(0);
 	    }
 	}
-    } else if (list_pipe && (val & 0200) && inforeground == 1) {
+    } else if (list_pipe && (val & 0200) && inforeground == 1 &&
+	       (WTERMSIG(val) == SIGINT || WTERMSIG(val) == SIGQUIT)) {
 	if (!errbrk_saved) {
 	    errbrk_saved = 1;
 	    prev_breaks = breaks;

-- 
Peter Stephenson <pws@csr.com>                  Software Engineer
CSR PLC, Churchill House, Cambridge Business Park, Cowley Road
Cambridge, CB4 0WZ, UK                          Tel: +44 (0)1223 692070


**********************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager.

**********************************************************************

Re: subtle `echo' bug

[Bart Schaefer]

On Jun 27, 11:03am, Peter Stephenson wrote:
}
} Are we going to do this?

I don't see any harm in it, but I have one last question ...

In looking at the code earlier in this function, I find that it's zsh
that does (the equivalent of) val |= 0200 before testing (val & 0200).
This makes me wonder if we should be using (val & ~0200) rather than
WTERMSIG(val) here.
 
} +		if ((val & 0200) && inforeground == 1 &&
} +		    (WTERMSIG(val) == SIGINT || WTERMSIG(val) == SIGQUIT)) {

It *probably* doesn't matter either way ...

Re: subtle `echo' bug

[Peter Stephenson]

Bart Schaefer wrote:
> On Jun 27, 11:03am, Peter Stephenson wrote:
> }
> } Are we going to do this?
> 
> I don't see any harm in it, but I have one last question ...
> 
> In looking at the code earlier in this function, I find that it's zsh
> that does (the equivalent of) val |= 0200 before testing (val & 0200).
> This makes me wonder if we should be using (val & ~0200) rather than
> WTERMSIG(val) here.

What zsh is setting is (removing some tests)

val = 0200 | WTERMSIG(p->status)

so I suppose you're right.

Index: Src/jobs.c
===================================================================
RCS file: /cvsroot/zsh/zsh/Src/jobs.c,v
retrieving revision 1.39
diff -u -r1.39 jobs.c
--- Src/jobs.c	1 Jun 2005 10:45:42 -0000	1.39
+++ Src/jobs.c	27 Jun 2005 14:44:05 -0000
@@ -383,7 +383,8 @@
 		}
 		/* If we have `foo|while true; (( x++ )); done', and hit
 		 * ^C, we have to stop the loop, too. */
-		if ((val & 0200) && inforeground == 1) {
+		if ((val & 0200) && inforeground == 1 &&
+		    ((val & ~0200) == SIGINT || (val & ~0200) == SIGQUIT)) {
 		    if (!errbrk_saved) {
 			errbrk_saved = 1;
 			prev_breaks = breaks;
@@ -399,7 +400,8 @@
 		adjustwinsize(0);
 	    }
 	}
-    } else if (list_pipe && (val & 0200) && inforeground == 1) {
+    } else if (list_pipe && (val & 0200) && inforeground == 1 &&
+	       ((val & ~0200) == SIGINT || (val & ~0200) == SIGQUIT)) {
 	if (!errbrk_saved) {
 	    errbrk_saved = 1;
 	    prev_breaks = breaks;

-- 
Peter Stephenson <pws@csr.com>                  Software Engineer
CSR PLC, Churchill House, Cambridge Business Park, Cowley Road
Cambridge, CB4 0WZ, UK                          Tel: +44 (0)1223 692070


**********************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager.

**********************************************************************