Sh fully echoes commands which error exit

[MarkDBlackwell]

CASE

FileUtils#sh truncates (to 42 characters) the echoing of failed shelled-out commands (as determined by their exit status). (BTW, even when the output is redirected to a file, it still truncates, in the same way.)

This isn't about shelled-out commands that succeed.

Why truncate the failed ones, anyhow? (And why to 42 characters?) What's the reason or rationale?

Every user wants to know (presumably) exactly which failed command their program was unable to handle, in order to obtain help to make their program work.

Passing a block to FileUtils#sh can avoid echoing any failed command, easily. So, any wish to provide some facility to avoid excessive echoing doesn't fully seem to justify this truncation.

This truncation of failed commands seems devoid of test coverage (because, if I comment this out, all tests still pass).

(BTW, the truncation seems related to ENV['RAKE_COLUMNS'], @terminal_columns, terminal_width(), and truncate_output?().)

If a program contains long shell commands (which incorporate fully-qualified paths), and if one of them fails, then 42 characters seems unhelpful.

I've been using a program which runs various program-generation recipes. Relatively unsophisticated people use it. It's (arguably) a good representative of a whole category of programs using Rake's FileUtils#sh.

Usually, when the program I'm using fails (because of external circumstances), the users don't rerun the program with --trace (despite Rake's recommendation—perhaps because the program is long-running) but instead simply submit the output as they first received it. And they themselves can't see the full, shelled-out command.

As a result, typically the (relatively newby) users aren't submitting the full details of the generated, failed shelled-out commands in their error reports—far from it. At that point, we typically ask them to rerun the program with --trace. Typically this delays our troubleshooting by one or more email cycles, or in some cases even blocks our users (they give up).

PLAN

Of course, I believe the program I'm using (and others like it—see above) should continue to use FileUtils#sh, yet (somehow) I'd like to influence this 42-character truncation.

I'd like to remove it.

Even if the truncation were to remain, then I'd like to be able to configure the 42 programmatically, perhaps with a Rake constant. Perhaps 0 (zero) could mean: don't truncate the command at all (for example).

For this purpose, a Rake command-line option would not be useful, because already the (relatively newby) users (of programs like the one mentioned above) don't use --trace.

Instead, because the relevant, shelled-out commands have failed, I believe they should be echoed in their entirety in any case. Does that make sense?

This pull request accomplishes this last goal. And it includes new tests to cover it.

HISTORY

2005-04-09 7:41:05 "updated changes" commit 5a3950d (toward Rake 0.5.3, and apparently referring to the later 7:41:07 change). File rake/CHANGES says "Fixed verbose flag bug in the testing task. Shortened some failure messages."

2005-04-09 7:41:07 "shortened error on task failure" commit f022aee. File rake/lib/rake.rb began truncating echoed failed commands to 42 characters.

2005-04-09 8:43 "updated documentation" commit cdd66db. File rake/doc/release_notes/rake-0.5.3.rdoc says "Fixed the verbose flag in the TestTask so that the test code is controlled by the flag. Also shortened up some failure messages. (Thanks to Tobias Luetke for the suggestion.)" (BTW, I believe this is @tobi.)

2006-08-12 "removed nested directory from CVS conversion" commit 8f9da2e (toward Rake 0.7.1.3). Renamed file rake/lib/rake.rb to lib/rake.rb.

2007-03-31 "added existing and existing! methods to FileList" commit 0c5500a (toward Rake 0.7.3). File lib/rake.rb began appending "..." always to echoed, failed commands (even to short ones). It also added a TODO, apparently for further investigation. The TODO includes the mysterious abbreviation "heref" (perhaps meaning "heretofore").

2009-03-06 "show all of the sh command if in trace mode" commit 14a4c32 (toward Rake 0.8.4.99). Initiated truncation unless in trace mode.

2009-03-28 "moved FileList to a separate file" commit 0d4416e (toward Rake 0.8.5). Created file lib/rake/file_utils.rb, and moved method sh to it (from lib/rake.rb).

2009-05-24 22:45 "fixed problem with :verbose=>false in sh and ruby commands" commit 6afd6fa (toward Rake 0.8.99.1). (This doesn't tell us much.)

2009-05-24 23:05 "refactoring the sh command a bit" commit 5f52524. File lib/rake/file_utils.rb removed the TODO; the relevant code was moved to a new private method create_shell_command, which still truncates failed command echoing to 42 characters.

2009-05-24 23:12 "changed nomenclature from shell_command to shell_runner" commit 2865311. Changed the method name to (the current) create_shell_runner.

[drbrain]

Who is going to do this TODO?

If exit behavior isn't going to be checked before merge just delete this comment.

[drbrain]

I like this idea.

I think a better implementation would be to print out the short command always as-is, then print out the full command again upon failure. If your terminal scroll back is limited the full command may have scrolled off the screen, so printing it again in the failure method would be the best way to ensure it shows up in your error reports.

PS: One other problem with rake printing out the command line is that it is not safe to cut and paste back into a shell line because it doesn't apply quoting.

[MarkDBlackwell]

I've addressed the review points.

I think a better implementation would be to print out the short command always as-is, then print out the full command again upon failure.

Currently, I'd suppose something in Rake already echoes commands given to sh before their execution when --trace is enabled. The particular program (on which I'm working) doesn't default to --trace.

One other problem with rake printing out the command line is that it is not safe to cut and paste back into a shell line because it doesn't apply quoting.

I noticed a distinction between single strings and multiple strings being passed to FileUtils#sh, like with Ruby's Kernel#system.

With both, in the case of multiple parameters, the first parameter is a program, and the shell isn't invoked. This causes the problem you mention (I think).

The program I'm working with always sends single strings to FileUtils#sh, thus the commands go to the shell. Of course, they're already shell-escaped, or they wouldn't work.

[drbrain]

I've addressed the review points.

Thanks, I'll check them later

I think a better implementation would be to print out the short command always as-is, then print out the full command again upon failure.

Currently, I'd suppose something in Rake already echoes commands given to sh before their execution when --trace is enabled. The particular program (on which I'm working) doesn't default to --trace.

Yeah, I think it's down in the verbose option (I worked on it a bit ago to allow sh to take the same keyword arguments as Kernel#system and Process#spawn). The "always as-is" above should have been written "as rake behaves presently".

With both, in the case of multiple parameters, the first parameter is a program, and the shell isn't invoked. This causes the problem you mention (I think).

Yes.

The program I'm working with always sends single strings to FileUtils#sh, thus the commands go to the shell. Of course, they're already shell-escaped, or they wouldn't work.

Yes. I don't expect it to be fixed here, just wanted to note it in case you decide to use the other way some time in the future.

[MarkDBlackwell]

One other problem with rake printing out the command line is that it is not safe to cut and paste back into a shell line because it doesn't apply quoting.

I noticed a distinction between single strings and multiple strings being passed to FileUtils#sh, like with Ruby's Kernel#system.

With both, in the case of multiple parameters, the first parameter is a program, and the shell isn't invoked. This causes the problem you mention (I think).

Yes. I don't expect it to be fixed here, just wanted to note it in case you decide to use the other way some time in the future.

Apparently, a long list of Ruby methods work in this Perlish way.

(That list seems to comprise: IO::popen, Kernel#exec, Kernel#spawn, Kernel#system, Open3#capture2, Open3#capture2e, Open3#capture3, Open3#pipeline, Open3#pipeline_r, Open3#pipeline_rw, Open3#pipeline_start, Open3#pipeline_w, Open3#popen2, Open3#popen2e, Open3#popen3, PTY::spawn, Process::spawn, and Shell::CommandProcessor#system. This is based on @jstorimer's article Process spawning patterns, section "Starting somewhere".) Whew!

Of course, Rake is capable of echoing any shelled-out command, even when it succeeds—I think this happens with --verbose. This PR only addresses the case when a command fails.

Anyway, I wonder what the general Ruby convention is (beyond Rake) for echoing or logging such commands, when they are passed as multiple string arguments, to any of the above list of methods.

Perhaps, conceivably, people print some indication of the fact that there are multiple arguments, and then echo or log the arguments in separate lines.

More probably, I would guess, people generally shell-escape these multiple strings with Shellwords#shelljoin (or something similar) before combining them into a single string, and then echoing or logging them in a single line.

I notice the relevant method sh_show_command doesn't follow the Shellwords#shelljoin approach for printing multiple string arguments; perhaps it would work.

If handled in that way, then an erroneous command, as printed, would be pasteable into the user's shell (so problems potentially could be troubleshot by the user, by easily repeating the command).

[MarkDBlackwell]

One other problem with rake printing out the command line is that it is not safe to cut and paste back into a shell line

I don't expect it to be fixed here

When you say, "not safe," do you mean merely that it won't work? Or does some issue of security arise?

I suppose the proper solution includes assembling multiple sh arguments in such a way that if the result is printed, a user can paste that into a Bourne shell line, and it will work the same way.

Since Bash (and many other shells) are upwardly compatible with Bourne, then they should work, too (of course).

To summarize, this PR covers the single-string calls to sh.

It doesn't shell-escape multiple string arguments to sh before printing them. It prints them out, all in one big line.

Before this PR, multiple string arguments are printed the same way, but are cut to 42 characters, with '...' invariably added. That doesn't stop some short multiple string arguments from being printed out fully (in effect), of course.

BTW, if sh is passed a single string argument, this string already must be shell-escaped (in effect) in order to work. Therefore, if users paste such a printed string (which has been passed to sh), this should work well.

Again, does a potential security issue exist here?

If so, then solving it should be included in this PR.

To put it more fully, regarding the issue of properly merging (before printing) multiple string arguments passed to sh: can this safely be left for some other pull request to handle (including tests)?

[drbrain]

With this rakefile:

task :default do
  sh 'echo', '; rm -rf .'
end

when run:

$ rake
echo ; rm -rf .
; rm -rf .

You see echo; rm -rf . as a log line. Copy-pasting it:

$ echo ; rm -rf .

rm: "." and ".." may not be removed

[drbrain]

When you say, "not safe," do you mean merely that it won't work?

It will depend on the command, some won't work, some will do wrong things.

Or does some issue of security arise?

It is possible, but only when the user copy-pastes rake's log line. I think rake can do better, but I don't think this is CVE-worthy.

I suppose the proper solution includes assembling multiple sh arguments in such a way that if the result is printed, a user can paste that into a Bourne shell line, and it will work the same way.

Since Bash (and many other shells) are upwardly compatible with Bourne, then they should work, too (of course).

Yes. Or into a Windows shell if they're running on Windows.

To summarize, this PR covers the single-string calls to sh.

[…]

Again, does a potential security issue exist here?

For this PR, no, thus "I don't expect it to be fixed here" because it's a separate issue. I'm sorry it caused confusion.

To put it more fully, regarding the issue of properly merging (before printing) multiple string arguments passed to sh: can this safely be left for some other pull request to handle (including tests)?

Yes, and it should.

[MarkDBlackwell]

left for some other pull request to handle (including tests)?

Yes, and it should.

Understood. :)

Just as a side comment: IMO good human-engineered log output from sh 'echo', '; rm -rf .' (to discourage people from pasting) perhaps might be:

NOT SHELL: "echo"  "; rm -rf ."

[hsbt]

I'm no opinion for this proposal.

@drbrain Can you handle this?

[deivid-rodriguez]

Hi, I just got bit by this and I believe it good be a good change 👍. It seems like the PR was ready to go at the time?

[deivid-rodriguez]

I tried to clone hoe and run its test suite. This is what I got:

$ rake
Run options: --seed 1581

# Running:

............................rake aborted!
Command failed with status (1): [/home/deivid/.rbenv/versions/2.7.2/bin/rub...]
/home/deivid/Code/hoe/lib/minitest/test_task.rb:164:in `block in define'
Tasks: TOP => default => test
(See full trace by running task with --trace)

Then I installed the rake version from this PR, and this is what I got:

$ rake
Run options: --seed 61814

# Running:

S.rake aborted!
Command failed with status (1): [/home/deivid/.rbenv/versions/2.7.2/bin/ruby -Ilib:test:. -w -e "require 'minitest/autorun'; require 'test/test_hoe_test.rb'; require 'test/test_hoe_gemcutter.rb'; require 'test/test_hoe_test.rb'; require 'test/test_hoe_publish.rb'; require 'test/test_hoe_debug.rb'; require 'test/test_hoe_package.rb'; require 'test/test_hoe.rb'" -- ]
/home/deivid/Code/hoe/lib/minitest/test_task.rb:164:in `block in define'
Tasks: TOP => default => test
(See full trace by running task with --trace)

Seems better, no?

[deivid-rodriguez]

It's been 4 years so I think it's safe to assume @drbrain won't handle this 😅. I think this trimming of commands at 42 characters is arbitrary and not helpful so I advocate for removing it.

[deivid-rodriguez]

@hsbt Can you reevaluate this proposal? Don't want to put any pressure of course, just put it under your radar! Thank you ❤️

[hsbt]

@deivid-rodriguez Thanks for your reminder. This change seems usefule to debug.

[deivid-rodriguez]

Indeed, thank you @hsbt!