Bash – Pipe Fail (141) When Piping Output into Tee

bashtee

An example should clarify my question. This behavior makes sense to me:

$ echo hi | cat
hi
$ echo hi | tee >(cat)
hi
hi

The first case is obvious. In the 2nd case, we pipe "hi" into tee using command substitution, and one "hi" is printed by the tee'd cat, while another is printed by tee's pass through pipe. So far, so good…

But what happens to the first "hi" in this case:

$ echo hi | tee >(echo yo)
yo

The return code is 141, a pipe fail. What could be causing this?

I'm running Mac OSX El Capitain, bash in default terminal app

Best Answer

I think I’ve figured out how to tweak your experience to turn it into something other people will be able to reproduce:

$ (echo hello; sleep 1; echo world) | tee >(cat)
hello
hello                                                       … and, after a brief delay,
world
world

$ echo "$?"
0

$ (echo hello; sleep 1; echo world) | tee >(echo yo)
yo
hello

$ echo "$?"
141

As you hopefully understand, >(command) creates a pipe to a process running command. The standard input of command is connected to a pathname that other commands on the command line (in this case, tee) can open and write to. When command is cat, the process sits there and reads from stdin until it gets an EOF. In this case, tee has no problem writing all the data it reads from its stdin to the pipe.

But, when command is echo yo, the process writes yo to the stdout and immediately exits. This causes a problem for tee; when it writes to a pipe with no process at the other end, it gets a SIGPIPE signal.

Apparently OS X’s version of tee writes to the file(s) on the command line first, and then its stdout. So, in your example (echo hi | tee >(echo yo)), tee gets the pipe failure on its very first write. Whereas, the version of tee on Linux and Cygwin writes to the stdout first, so it manages to write hi to the screen before it dies. In my enhanced example, tee dies when it writes hello to the pipe, so it doesn’t get a chance to read and write world.

Process substitution¹ lets you transform a `script` typescript as it's written.

You can use script -q >(./dewtell >>outfile) brew args... instead of script -aq outfile brew args... to write a log with escape sequences removed, where ./dewtell is whatever command runs the script that removes them. On other systems than relatively recent versions of macOS or FreeBSD, the command will be slightly different, because different script implementations support different options. See below for full details.

The Story So Far (including alternative solutions)

Your solution

Your brew command runs numerous other output-generating programs as subprocesses, such as ./configure scripts and make, and you have found that piping brew's output to tee with brew args... 2>&1 | tee -a outfile causes the output (of at least some of those subprocesses) to be buffered and not to appear on your terminal in real time.

You found that using script, by running script -aq, solved this problem by keeping standard output a terminal², and that you can also pass -k if you want your own input logged even in situations when it is not echoed to the terminal as you type it. You found further that dewtell's extended version of Gilles's Perl script to remove escape sequences from files cleans up the the generated typescript effectively, transforming it into what you need.

The difference between Gilles's original script and dewtell's extended version is that, while they both remove escape sequences, including but not limited to those that specify color changes, dewtell's script also removes carriage return characters ($'\r', represented as ^M in vim and in the output of cat -v) as well as backspace characters ($'\b', represented as ^H in vim and in the output of cat -v) and whatever characters, if any, that they appear to have erased.

Problems with some Perl implementations

You reported that the script needs a "relatively recent" Perl interpreter. But it doesn't call for any newer features with use or otherwise appear to rely on them, and a friend of mine who runs macOS 10.11.6 El Capitan has verified that it works with the system-provided perl 5.8.12, so I don't know why (or if) you needed a newer perl. I expect most people can just use the perl they have.

But the script did fail on Mac OS X 10.4.11 Tiger (PPC) with the system-provided perl 5.8.6, which incorrectly believes (at least on my system) that m is not in the character class [@-~], even with LC_COLLATE=C or LC_ALL=C and even though the system-provided grep, sed, python, and ruby do not have this problem. This caused pieces of color-specifying escape sequences to remain in the output, as the sequences failed to match (?:\e\[|\x9b) [ -?]* [@-~] and matched the later alternative \e. instead. With perlbrew, I installed perl 5.27.5, 5.8.9, and even 5.6.2 on that system; none had the problem.

If one does need or want to run the script with a Perl interpreter installed elsewhere than /usr/bin/perl, then one can change the hashbang line at the top to the correct path; or one can change it to /usr/bin/env perl if the desired perl executable appears first in the path, i.e., if it would run if one typed perl and pressed Enter; or one can invoke the interpreter explicitly with the script's filename as its first argument, e.g., /usr/local/bin/perl dewtell instead of ./dewtell.

Ways to keep or replace the original typescript

Some users who need to remove escape sequences from a typescript will want to keep the old unprocessed typescript too. If such a user wishes to process a typescript called dirty.log and write the output to clean.log, they would run ./dewtell dirty.log > clean.log, if necessary replacing ./dewtell with whatever other command runs dewtell's script (or some other script they wish to use).

To modify the typescript "in place" instead, one can pass -i to perl, running perl -i.orig dewtell typescript where typescript is the typescript generated by script, .orig is any suffix to be used for the backup file, and dewtell is the Perl script. Or one may instead run perl -i dewtell typescript, which discards the original because no backup suffix is supplied. These methods don't work with all Perl scripts but they work with this one because it uses <> to read input, and <> in Perl respects -i.

You used sponge to write the changes back to the original typescript. This is also a good and reliable method, though it requires that moreutils be installed.

Preventing Escape Sequences From Ever Being Logged

The remaining question is how to write a log that has escape sequences removed in the first place. As you say:

[T]here may further be a way to string this all together into a single pipeline, but I haven't been able to figure that out as of this writing; additional comments or answers showing how...

Use process substitution instead of a pipeline.

The problem is that script on most (all?) systems does not have an option to support those transformations. Since script writes to a file whose name you either specify or defaults to typescript--not to standard output--piping from script would not affect what is written to the typescript.

Placing the script command on the right side of the pipe operator (|) to pipe to it is not a good idea either. In your case this is specifically because output from brew or its subprocesses was buffered when its standard output was a pipe, so it didn't appear when you needed to see it.

Even if that problem were solved, I don't know of any reasonable way to use a pipeline¹ together with script to accomplish this task.

But it can be done with process substitution.³ In process substitution¹ (also explained here), you write <(command...) or >(command...). The shell creates a named pipe and uses it as standard output or input, respectively, for a subshell in which command... is run. The text <(command...) or >(command...) is replaced with the filename of the named pipe--that's the substitution--so you can pass it as an argument to a program or use it as the target of a redirection.

Use <(command...) to run command... like its output is the contents of a file you'll read from.⁴
Use >(command...) to run command... like its input is the contents of a file you'll write to.⁴

Not all systems support named pipes, but most do. Not all shells support process substitution, but Bash does, so long as it's running on a system that is capable of supporting it, your build of Bash hasn't omitted support for it, and POSIX mode is turned off in the shell. In Bash you usually have access to process substitution, especially if you're using any remotely recent operating system. Even on my Mac OS X 10.4.11 Tiger (PPC) system where "$BASH_VERSION" is 2.05b.0(1)-release, process substitution works just fine.

Here's how to do that while using `script`'s syntax on a recent macOS system.

This should work on your macOS 10.11 El Capitan system--and, going by that manpage, any macOS system at least as far back as macOS 10.9 Mavericks and possibly earlier:

script -q >(./dewtell >>clean.log) brew args...

That logs everything written to the terminal, including your own input if it is echoed back to you, i.e., if it appears in the terminal, which it usually does. If you want your own input logged even if it doesn't appear, bearing in mind that the situation where this occurs is often that you are entering a password, then as you mentioned in your answer, add the -k option:

script -kq >(./dewtell >>clean.log) brew args...

In either case, replace ./dewtell with whatever command runs dewtell's script or any other program or script you want to use to filter the output, clean.log with name of the file you want to write the typescript to with escape sequences omitted, and brew args...⁵ with the command you are running and its arguments.

Overwriting or Appending to the Log

If you want to overwrite clean.log instead of appending to it then use >clean.log instead of >>clean.log. The actual file is being written by the command that is run via process substitution, so the > or >> redirection operator appears inside >( ).

Don't attempt to use >>( instead of >(, which is a syntax error as well as meaningless because the > in >( for process substitution does not mean redirection.

Don't pass -a to script with the intention that it would prevent your log file from being overwritten in this situation, because this would simply open the named pipe in append mode--which has the same effect as opening it for a normal write--and then either overwrite or append clean.log, still depending on whether >clean.log or >>clean.log is used in the subshell.

Similarly, don't use >& or &> or add 2>&1 inside >( ) (or anywhere), because if ./dewtell generates any errors or warnings, you would want to see those rather than having them written to clean.log. The script command automatically includes text from standard error in its typescript; you don't need to do anything special to achieve this.

On Other Operating Systems

As your answer says:

[S]ome versions of the script command have a different syntax; the one given is for OS X/macOS, so adjust as necessary.

GNU/Linux

Most GNU/Linux systems use the script implementation provided by util-linux. If you want to cause it to run a specific command rather than starting a shell, you must use the -c option and pass the entire command as a single command-line argument to script, which you can achieve by enclosing it in quotes. This is different from the version of script on recent macOS systems like yours, which allows you to pass the command naturally as multiple arguments placed after the output filename (with no option like -c).

So on Debian, Ubuntu, Fedora, CentOS, and most other GNU/Linux systems, you could use this command (if it had a brew command⁶, or replacing it with whatever command you want to run and log transformed output):

script >(./dewtell >>clean.log) -qc 'brew args...'

As with script on your system, on GNU/Linux remove -q if you want script to include more messages about how logging has begun and ended. Even with the -q option, this version of script does still include one line at the top saying when it started running, though it does not show you that line and it does not write or show anything about when it stopped running.

There is no -k option. Only text that appears in the terminal is recorded.⁷

FreeBSD

The script command in macOS originated in FreeBSD. All versions support -a to append instead of overwriting (though, as noted above, this does not help you append when you are writing through a named pipe using process substitution). -a was the only option up to and including FreeBSD 2.2.5. The -q option was added in FreeBSD 2.2.6. The -k option was added in FreeBSD 2.2.7.

Up through FreeBSD 2.2.5, the script command did not allow a specific command to be given, but instead always ran the user's shell, given by the SHELL environment variable, with /bin/sh as a fallback if the variable is unset. Starting in FreeBSD 2.2.6, a specific command could be given on the command line to script which it would run instead of a shell.

Thus later versions of FreeBSD, including those commonly encountered today, are similar to newer macOS systems such as yours in the way the script command may be invoked. Likewise, older versions of FreeBSD are similar to older versions of macOS (see below).

Note that perl is not part of FreeBSD's base system in any recent release, and bash never has been. Both may be readily installed using packages (such as with pkg install perl5 bash bash-completion) or ports. The system-provided /bin/sh in FreeBSD does not support process substitution.

Older Versions of macOS, and any other system with a less versatile `script`

I tested on Mac OS X 10.4 Tiger where script accepts only the -a option. It does not accept -q or -k. It includes only keystrokes shown in the terminal in its typescript⁷, as with the util-linux version on GNU/Linux systems.

At least until I can find a reliable source of documentation for script in every version of macOS (to my knowledge, only the 10.9 Mavericks manpages are readily available online), I recommend macOS users run man script to check what syntax their script command accepts, how it behaves by default, and what options it supports. You would want to use these commands on an old version of macOS like mine:

script >(./dewtell >>clean.log)
brew args...
exit

This also applies to script on any other OS where it doesn't support many options, or on OSes where other options are supported but you prefer not to use them. This method of using script to start a shell, running whatever command or commands in the shell that you need logged, and then exiting the shell, is the traditional way.

The ugly hack of pretending your command is your shell

If you really must use script to run a single command rather than a new instance of your shell, there is an ugly hack that you can sometimes use: you can fool it into thinking the command you want to run is actually your shell with SHELL=your-command script outfile. You should think twice before doing this, though, because if your-command itself actually consults the SHELL environment variable to check what actual shell you use, ~~hilarity~~ unfortunate behavior would ensue.

Furthermore, that will not readily work for a command consisting of multiple words--that is, a command to which you are passing one or more arguments. If you wrote SHELL='brew args...' before script on the same line, that would succeed at passing brew args... into script's environment as the value of SHELL, but that entire string would be used as the name of the command, rather than just the first word, and no arguments would be passed to the command, rather than all the other words being passed.

You could work around this by writing a shell script, called run-brew or whatever you want to call it, that runs brew with args..., and then passing that as the value of the SHELL environment variable. After you've made the run-brew shell script, running it via the script command could look like this:

SHELL=run-brew script >(./dewtell >>clean.log)

For the reasons given above, I recommend against using the method of assigning your command name to SHELL, unless the action you are performing is unimportant or you are sure it will not involve the use of SHELL. Since Homebrew performs numerous, quite complicated actions, I suggest against actually running a run-brew script like this. (There's nothing wrong with putting your long, complicated brew command in a run-brew script, only with using SHELL=run-brew to make script run it.)

I did find this method a bit useful when testing the techniques shown above with a simple program in place of brew args..., however.

Testing and Demonstrating the Technique

You may find it useful to try out some of these methods on a command less complicated than your long brew command. I know I did.

The demo program / test input generator, and the testing method used

I made this simple interactive Perl script that writes to standard error, prompts the user on standard output for their name, reads it from standard input, then writes a greeting to standard output with the user's name in color:

#!/usr/bin/perl

use strict;
use warnings;
use Term::ANSIColor;

print STDERR $0, ": warning: this program is boring\n";
print "What's your name?  ";
chomp(my $name = <STDIN>);
printf "Hello, %s!\n", colored($name, 'cyan');

I called it colorhi and put it in the same directory as dewtell's script, which I called dewtell.

In my own testing I replaced #!/usr/bin/perl with #!/usr/bin/env perl in both scripts.⁸ I tested in Ubuntu 16.04 LTS with the system-provided perl 5.22.1 and versions 5.6.2 and 5.8.9 provided by perlbrew; FreeBSD 11.1-RELEASE-p3 with the pkg-provided perl 5.24.3 and versions 5.6.2, 5.8.9, and 5.27.5 provided by perlbrew; and Mac OS X 10.4.11 Tiger with the system-provided perl 5.8.6 and versions 5.6.2, 5.8.9, and 5.27.5 provided by perlbrew.

I repeated the tests described below with each of those perl versions, first testing the system-provided⁹ version, then using perlbrew use to temporarily cause each perlbrew-provided perl binary to appear first in $PATH (e.g., to test perl 5.6.2, I ran perlbrew use 5.6.2, then the commands shown below for the system on which I was testing).

A friend tested it in macOS 10.11.6 El Capitan, with the original hashbang lines, causing the system-provided perl 5.18.2 to be used, and not testing any other interpreters. That test employed the same commands I ran while testing on FreeBSD.

All those tests succeeded except with the system-provided perl in Mac OS X 10.4.11 Tiger, which failed due to what appears to be a strange bug involving character classes in regular expressions, as I described earlier in detail, and as shown below in an example.

On Ubuntu

While in the directory that contained the scripts, I ran these commands on the Ubuntu system to produce a typescript with escape sequences and any backspace characters I might type:

printf 'Whatever header you want...\n\n' >dirty.log
script dirty.log -aqc ./colorhi

I typed Eliah, then behaved as though I had thought better of it, erasing it with backspaces and typing Bob from accounting instead. Then I pressed Enter and was greeted in color. Then I ran these commands to separately produce a typescript without escape sequences and without any signs of my real name, interacting with it in exactly the same way (including typing and erasing Eliah):

printf 'Whatever header you want...\n\n' >clean.log
script >(./dewtell >>clean.log) -qc ./colorhi

vim displays control characters symbolically like cat -v and offers the advantage of brightened or colored text. This is what the buffer shown by view dirty.log looked like, but with the representations of control characters italicized so they stand out here:

Whatever header you want...

Script started on Thu 09 Nov 2017 07:17:19 AM EST
./colorhi: warning: this program is boring^M
What's your name?  Eliah^H ^H^H ^H^H ^H^H ^H^H ^HBob from accounting^M
Hello, ^[[36mBob from accounting^[[0m!^M

And this is what the buffer looked like for view clean.log:

Whatever header you want...

Script started on Thu 09 Nov 2017 07:18:31 AM EST
./colorhi: warning: this program is boring
What's your name?  Bob from accounting
Hello, Bob from accounting!

Results were the same with each interpreter tested, except of course for the timestamp.

On FreeBSD (and macOS 10.11.6 El Capitan)

I carried out the test the same way on FreeBSD as on Ubuntu, except that I used these commands to produce dirty.log:

printf 'Whatever header you want...\n\n' >dirty.log
script -aq dirty.log ./colorhi

And I used these commands to produce clean.log:

printf 'Whatever header you want...\n\n' >clean.log
script -q >(./dewtell >>clean.log) ./colorhi

Those are the same commands my friend ran to test this on macOS 10.11, and although the input issued was slightly different from my Eliah/Bob from accounting input, a name was still typed, erased with backspaces, and replaced by another name. The output was thus similar except for the names and number of backspaces.

With all four of the Perl implementations tested on FreeBSD and the one (system-provided) implementation on macOS 10.11, both dirty.log and clean.log showed the expected output. Comparing the FreeBSD results with the Ubuntu results, the difference was the absence of any timestamps, due to -q. All escape sequences and carriage returns were successfully removed in clean.log, as were all backspaces and characters whose erasure the backspaces indicated.

On Mac OS X 10.4.11 Tiger

I carried out the test the same way on my old Tiger system as on Ubuntu and FreeBSD, except that I used these commands to produce dirty.log:

printf 'Whatever header you want...\n\n' >dirty.log
SHELL=colorhi script -a dirty.log

And I used these commands to produce clean.log:

printf 'Whatever header you want...\n\n' >clean.log
SHELL=colorhi script >(./dewtell >>clean.log)

Since this system's script command doesn't support -q, results included both (a) a Script started line appended after the header and (b) a newline followed by a Script done line appended at the very end of each typescript. Both those lines contained timestamps. Besides that, the results were the same as on Ubuntu and FreeBSD, except that the escape sequences to switch to and from cyan text were not fully removed with the system-provided perl. The relevant line from dirty.log always appeared this way in vim, as expected:

Hello, ^[[36mBob from accounting^[[0m!^M

With the system-provided perl 5.8.6, this was the corresponding line in clean.log, showing 6m and 0m, which should have been removed, left over:

Hello, 6mBob from accounting0m!

With each of the perlbrew-installed perls, all escape sequences were fully and correctly removed, and that line in clean.log looked like this, just as it did with all Perl interpreters I ran on Ubuntu and FreeBSD:

Hello, Bob from accounting!

Notes

¹ That manual is for Bash 2. Many Bash users are on major version 4 and will prefer to read about process substitution, pipelines, and other topics in the current Bash manual. Current versions of macOS ship with Bash 3.

² Standard error is almost always unbuffered, regardless of what type of file or device it is. There is no rule that programs cannot buffer writes to file descriptor 2, but there is a strong tradition not to do so, based in the need to actually see error and warning messages when they occur--and also the need to see them at all, even if the program terminates abnormally without ever properly closing or otherwise flushing its open file descriptors. It would usually be a bug for a program to buffer writes to standard error by default.

³ Process substitution uses a named pipe, also called a FIFO, which achieves the same general goal as the pipe operator | in shells, but is more versatile. However, even though this is a pipe, I consider that it is not a pipeline, which I take to refer to the specific syntactic construct and corresponding behavior of a shell.

⁴ If you consider a named pipe to be a file, which you should, then this is literally what is happening.

⁵ Although "$COMMAND" appears in your answer and passes an entire command as a single argument to script (because double quotes suppress word splitting), you were able to pass the command to script as multiple arguments.

⁶ Such as with Linuxbrew, which I should acknowledge you introduced me to.

⁷ However, I recommend that anyone who relies on this behavior to keep sensitive data secret test the behavior of their script command, and maybe even inspect generated typescripts to ensure no data that must be protected are present. To be extra safe, use an editor that shows characters that would ordinarily be hidden on screen, or use cat -v.

⁸ The versions with #!/usr/bin/perl, including the colorhi implementation shown, should work and do the right thing on most systems. I used #!/usr/bin/env perl in my own testing. But my friend who has the same OS that you (the original poster) are running used #!/usr/bin/perl. This achieved the goal of checking, with minimal complication or potential for doubt, that the system-provided perl would work.

⁹ On FreeBSD there is no system-provided perl in the strictest sense. I tested the version installed via pkg first.

Bash SIGPIPE – How to Suppress SIGPIPE in Bash

A 141 exit code indicates that the process failed with SIGPIPE; this happens to yes when the pipe closes. To mask this for your CI, you need to mask the error using something like

(yes phrase ||:) | make installer

This will run yes phrase, and if it fails, run : which exits with code 0. This is safe enough since yes doesn’t have much cause to fail apart from being unable to write.

To debug pipe issues such as these, the best approach is to look at PIPESTATUS:

yes phrase | make installer || echo ${PIPESTATUS[@]}

This will show the exit codes for all parts of the pipe on failure. Those which fail with exit code 141 can then be handled appropriately. The generic handling pattern for a specific error code is

(command; ec=$?; if [ "$ec" -eq 141 ]; then exit 0; else exit "$ec"; fi)

(thanks Hauke Laging); this runs command, and exits with code 0 if command succeeds or if it exits with code 141. Other exit codes are reflected as-is.