PS4 with subshells causes erroneous extra hits to be registered #16

tomeon · 2016-01-12T14:43:48Z

For some reason I have not been able to determine, a PS4 whose expansion triggers subshell calls causes additional xtrace output for certain lines. This can be seen in case.sh, in which the line case $1 in is marked as having been executed six times rather than two. Interestingly, this only happens when BASH_XTRACEFD is set -- when unset, with xtrace output going to stderr, the case condition registers the correct two hits. Also, the number of additional hits appears to be proportional to the number of subshells -- with just one subshell, the case condition is shown as having executed four times.

I suspect that this is a bug in Bash itself, but as a workaround I've implemented a solution that uses a PS4 without subshells, plus Ruby code to do the pathname expansion that had previously been delegated to the dirname, cd, pwd, and basename calls in the original PS4. My changes are idempotent with respect to the existing test suite (except, of course, case.sh), but I can't say for certain whether the Ruby-based pathname expansion will always yield the same results as the prior Bash-based expansion. On the other hand, the new code's path expansion caching may provide a speed boost, and the changes also improve handling of corner cases like bashcov -- bash -c "/path/to/myscript", which previously would raise the error dirname: missing operand

which replaces use of subshells in PS4 to get the path(s) to the file(s) under test

…tance method that caches results. Also added testing of realpath and refactored const_redefine into a mixin for the Class and Module classes so that const_redefine isn't available on every single Object.

infertux · 2016-01-12T17:43:32Z

Thanks a lot for your efforts. Here's a little bit of background:

My initial implementation was using subshells but I replaced it with $BASH_SOURCE in 4130874 - quoting the commit message: This was way slower and was messing with the number of hits.
Then we changed it back to subshells in d045b33 for OS X compatibility (PR Fix rake tests on OS X #10).
Your solution seems to have the best of both worlds since it should be OS-independent in theory (I don't use OS X so I can't check for sure) and report the correct number of hits.

Anyway, that makes a lot of sense and I like your clean code 😃. Let me do a proper review/test and I'll merge that in soon.

infertux · 2016-01-12T18:08:13Z

Hmm I have a flaky test:

bundle exec rspec --seed 34100 always fails
bundle exec rspec --seed 54516 always passes

Investigating...

infertux · 2016-01-12T18:31:04Z

Probably related:

% ./bin/bashcov spec/test_app/test_suite.sh
[...]
Warning: /home/infertux/dev/bashcov/scripts/unicode.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/exit_non_zero.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/nested/simple.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/long_line.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/one_liner.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/process_substitution.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/source.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/sourced.txt was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/delete.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/tmp.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/multiline.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/executable was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/function.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/simple.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/infertux/dev/bashcov/scripts/case.sh was executed but has been deleted since then - it won't be reported in coverage.
Coverage report generated for bashcov v1.2.1 to /home/infertux/dev/bashcov/coverage. 2 / 57 LOC (3.51%) covered.

It should be:

[...]
Warning: /home/infertux/dev/bashcov/spec/test_app/tmp.sh was executed but has been deleted since then - it won't be reported in coverage.
Coverage report generated for bashcov v1.2.1 to /home/infertux/dev/bashcov/coverage. 46 / 59 LOC (77.97%) covered.

Looks like it doesn't detect we're changing directory at https://github.com/infertux/bashcov/blob/master/spec/test_app/test_suite.sh#L3

This works fine OTOH: cd spec/test_app && ../../bin/bashcov ./test_suite.sh

infertux · 2016-01-12T18:48:06Z

Interesting! bundle exec rspec --seed 34100 also fails in the master branch so this is not due to your changes :)

However the bunch of "was executed but has been deleted since then - it won't be reported in coverage" isn't present in master.

infertux · 2016-01-12T23:09:17Z

Alright the flaky test has been fixed in 9fdf1a3 but we still need to address the "bunch of warnings" issue, i.e. running ./bin/bashcov spec/test_app/test_suite.sh should output only 1 warning.

tomeon · 2016-01-13T00:04:25Z

So I've been poking around trying to find a solution to the "bunch of warnings" issue, and I'm not surei that there's going to be an easy fix. One thought I had was to set the PS4 like this:

PS4 = format %(%s%s/%s/%s: ),  PREFIX, '${PWD}', '${BASH_SOURCE##"${PWD}"}', '${LINENO}'

...but that still leads to test failures:

% ./bin/bashcov spec/test_app/test_suite.sh
Warning: /home/matt/git/bashcov/spec/test_app/spec/test_app/test_suite.sh was executed but has been deleted since then - it won't be reported in coverage.
Warning: /home/matt/git/bashcov/spec/test_app/tmp.sh was executed but has been deleted since then - it won't be reported in coverage.

Fewer failures, but failures nonetheless :(.

Another possibility might be to use the DEBUG trap to print the relevant information to Xtrace#read, but that's probably much more work to implement correctly, and this approach may also suffer from the "multiple-hits" issue. I will continue to look into possible avenues of attack.

and fixed rubocop errors

* master: Reset $SHELLOPTS after test to avoid side effect flaky test Update Ruby versions for Travis Run Travis with OS X as well Use recommended annotation syntax Update SimpleCov and relax dependency to allow 0.11+

infertux · 2016-01-22T18:18:34Z

Wow turns out this is much more complicated than it should be. Thanks again for your efforts. Sorry I don't have much time to explore other solutions at the moment. But it seems you made some good progress. I just tried commit 67e0807 and it seems to be working fine?

The latest release of Rubocop is complaining for me so I made a quick patch if you wanna apply it to your branch.

However, it seems the build is broken for older versions of Ruby: https://travis-ci.org/infertux/bashcov/jobs/103757216

in order to facilitate easy options resets

that catches Xtrace parsing errors and prints an error message

and avoids IndexErrors for one-liners where $LINENO == 0

and added tests for cases that break Xtrace parsing

* master: Reset $SHELLOPTS after test to avoid side effect flaky test

tomeon · 2016-01-23T18:03:23Z

Thanks for the patchset! I've applied it to my fork and rubocop has piped down :).

I have updated the safe-ps4 branch to separate PS4 fields using a randomly-generated UUID. My local machine now has Ruby 2.1.8, 2.2.4, and 2.3.0, and bundle exec rake is passing for each version. Nonetheless, Travis is still failing for all Ruby versions, OSes, etc. I am setting up a Docker container with Ubuntu Trusty Tahr to more closely replicate the Travis build environment; hopefully I'll be able to identify the source or sources of failure.

In the meantime, it's worth stepping back to assess the much greater scope that this PR now covers. The branch now implements a complete change to the Xtrace parsing logic, rather than a much more modest change to a PS4 field or two. On the plus side, bashcov now handles scripts with newlines in their names (at least, you know, on my machine :), and it also behaves well in cases in which I was previously getting no such file or directory errors from one or more of the subshell expansions. I'd love to know whether you think that this PR has spiraled out of all reason, or whether I should continue investigating why the Travis builds are failing.

Thanks very much!

and restores SHELLOPTS after completion. Also, #run is now sensitive to the availability of BASH_XTRACEFD

…ptions! in order to facilitate easier state resets under test. Also added BASH_XTRACEFD availability checking and the ability to specify the path to Bash in order to ensure that the availability checking is done against the correct Bash

…due to disappearing temp files

… instance variables

…igent by checking whether Bash does in fact truncated PS4

and factored out yielding of empty strings into a lambda so that it can be invoked at the end of .each_field once all xtrace output has been consumed

* safe-ps4-travis-failures: Added tests for FieldStream and factored out yielding of empty strings into a lambda so that it can be invoked at the end of .each_field once all xtrace output has been consumed Added default @options.bash_path and made .truncated_ps4? more intelligent by checking whether Bash does in fact truncated PS4 Added note about Bash 4.2 PS4 truncation bug Fixed up intermittent test failures caused by incautious messing with instance variables Implemented 4.2 fix. Still seeing intermittent test errors; probably due to disappearing temp files All tests passing -- now for 100% coverage... FieldStream classes working on 2.2; fixing for 2.1 Added DEBUG trap-based tracking -- WIP on FieldStream class [ci skip] More output testing Removed redundant instance of Xtrace::DELIM from beginning of Xtrace::PS4 Changing line ending format in Xtrace#read darnit, rubocop commit to check what Travis is seeing when bashcov runs

tomeon · 2016-01-30T20:24:08Z

Wow -- so this PR definitely ballooned a bit, and when I say "ballooned" I mean "would make the Montgolfier brothers red with envy" :).

I realize that the changes are quite a lot more extensive and require a more in-depth review than it would have been possible to anticipate at the initial submission of this PR. I've tried to document alterations at a reasonable level of detail; please let me know if there is anything I can clarify.

Thanks very much for taking the time to look this over! I hope the changes are to your liking.

infertux · 2016-02-04T13:15:25Z

lib/bashcov.rb

+          raise Errno::ENOENT, p unless File.file? p
+          options.bash_path = p
+        end
+        opts.on("--root PATH", "Project root directory") do |d|


When would we need to set this by hand? Is there any usecase when we can't rely on Dir.getwd?

I found this a useful shortcut when making changes to Bashcov and testing them against shell scripts in other directories. But that's a pretty slender use case! TBH the reason I added this was because I needed to make the project root configurable in order to properly test the temporary scripts created by the test suite, and I figured that there'd be little harm in exposing the setting as a command line option.

Sounds good, in fact I just remembered this feature was also suggested in #13 so let's keep it!

infertux · 2016-02-04T14:52:15Z

Wow -- so this PR definitely ballooned a bit, and when I say "ballooned" I mean "would make the Montgolfier brothers red with envy" :).

Haha, indeed!

I left some comments from reviewing the diff. Give me a few days to test all that on my machine and I'll get back to you.

I really appreciate your efforts! This is by far the biggest PR I got for Bashcov 😄

tomeon · 2016-02-04T22:13:01Z

Thanks very much for your feedback! I'll keep an eye out for more over the next few days.

PS4 with subshells causes erroneous extra hits to be registered

infertux · 2016-02-10T00:18:35Z

Alright, I finally merged your PR and did some housekeeping to prepare for an upcoming Gem release. I tried to summarize your work in the CHANGELOG but feel free to improve it.

On that note, I gave you push access to the repo as a token of gratitude. You must be familiar with most of the codebase by now and I trust you to write good code :). Don't feel obligated to contribute though! But if you have to make small tweaks or bug fixes to Bashcov in the future, feel free to push straight to master.

BTW can I ask what you use Bashcov for? I'm curious 😄

tomeon · 2016-02-10T02:02:40Z

Wow, thanks very much -- that is most kind of you! Thanks also for fixing my many remaining mistakes, and for writing Bashcov :).

I find myself writing a surprising amount of Bash -- so much so that it's become important to me to be able to write meaningful and (hopefully!) comprehensive tests. Bashcov is hugely helpful in that regard! Particularly for monstrosities like my dotfiles configuration management script, it is fantastic to have such a useful tool for figuring out where the spaghetti is most convoluted. So, thanks!

infertux · 2016-02-10T23:16:49Z

That's nice to hear! :)

I just pushed release 1.3.0 to RubyGems. Enjoy!

Matt Schreiber added 3 commits January 11, 2016 18:05

Added Xtrace#realpath helper method

ee5e5d0

which replaces use of subshells in PS4 to get the path(s) to the file(s) under test

Refactor realpath into a class method that does the lookup and an ins…

d810cca

…tance method that caches results. Also added testing of realpath and refactored const_redefine into a mixin for the Class and Module classes so that const_redefine isn't available on every single Object.

Fixed rubocop offenses

bd85f6c

Matt Schreiber added 4 commits January 20, 2016 19:57

Implemented newline-separated PS4 output parsing

63476f2

Implemented UUID-separated PS4 fields

4989134

Updated .rubocop.yml to fix Style/TrailingComma deprecation error

67e0807

and fixed rubocop errors

Merge branch 'master' into safe-ps4

b082e58

* master: Reset $SHELLOPTS after test to avoid side effect flaky test Update Ruby versions for Travis Run Travis with OS X as well Use recommended annotation syntax Update SimpleCov and relax dependency to allow 0.11+

Matt Schreiber and others added 12 commits January 23, 2016 09:38

Updated README with notes on Xtrace-parsing caveats and esoterica

460147c

Reconfigured module's eigenclass to delegate to regular old instance

d53db13

in order to facilitate easy options resets

Added error class for indicating failure to parse Xtrace output

d5f13b3

Added exception handling clause to #run

e224937

that catches Xtrace parsing errors and prints an error message

Fixed YARD carping

c071c0e

Xtrace#run now raises an exception when parsing errors are detected

bbf0e67

and avoids IndexErrors for one-liners where $LINENO == 0

DRYed up temporary script testing with shared_context

e56d0d5

and added tests for cases that break Xtrace parsing

Forgot to run rake before committing :(

073ddeb

Removed vestigial @todo [ci skip]

a529aa2

Reset $SHELLOPTS after test to avoid side effect flaky test

f893e0c

Merge branch 'master' into safe-ps4

1c7e70c

* master: Reset $SHELLOPTS after test to avoid side effect flaky test

Applying rubocop fix patch [ci skip]

27b3fe0

Matt Schreiber added 3 commits January 23, 2016 19:17

inject_xtrace_flag! now executes a provided block/proc

47911cc

and restores SHELLOPTS after completion. Also, #run is now sensitive to the availability of BASH_XTRACEFD

Expanded comment in xtrace.rb

2539e7a

Matt Schreiber added 8 commits January 29, 2016 04:18

All tests passing -- now for 100% coverage...

c45e674

Implemented 4.2 fix. Still seeing intermittent test errors; probably …

949dcb8

…due to disappearing temp files

Fixed up intermittent test failures caused by incautious messing with…

bf8af04

… instance variables

Added note about Bash 4.2 PS4 truncation bug

00df6f0

Added default @options.bash_path and made .truncated_ps4? more intell…

e060601

…igent by checking whether Bash does in fact truncated PS4

Added tests for FieldStream

9eef89d

and factored out yielding of empty strings into a lambda so that it can be invoked at the end of .each_field once all xtrace output has been consumed

Fleshed out documentation of public methods to 100%

33d32e4

Matt Schreiber added 5 commits January 31, 2016 11:46

Moved 'delimited stream' context to support/shared_context.rb

4811632

Added .program_name method for use in printing warnings

0d5864b

Added .program_name method for use in printing warnings

ff27e24

Fix for flaky tests when running with BASHCOV_BASH_PATH

8b9fc66

Testing fixes -- one liners++

66e02ad

infertux reviewed Feb 4, 2016
View reviewed changes

infertux added a commit that referenced this pull request Feb 9, 2016

Merge pull request #16 from BaxterStockman/safe-ps4

6f5e4fd

PS4 with subshells causes erroneous extra hits to be registered

infertux merged commit 6f5e4fd into infertux:master Feb 9, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

PS4 with subshells causes erroneous extra hits to be registered #16

PS4 with subshells causes erroneous extra hits to be registered #16

tomeon commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

tomeon commented Jan 13, 2016

infertux commented Jan 22, 2016

tomeon commented Jan 23, 2016

tomeon commented Jan 30, 2016

infertux Feb 4, 2016

tomeon Feb 4, 2016

infertux Feb 9, 2016

infertux commented Feb 4, 2016

tomeon commented Feb 4, 2016

infertux commented Feb 10, 2016

tomeon commented Feb 10, 2016

infertux commented Feb 10, 2016

PS4 with subshells causes erroneous extra hits to be registered #16

PS4 with subshells causes erroneous extra hits to be registered #16

Conversation

tomeon commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

infertux commented Jan 12, 2016

tomeon commented Jan 13, 2016

infertux commented Jan 22, 2016

tomeon commented Jan 23, 2016

tomeon commented Jan 30, 2016

infertux Feb 4, 2016

Choose a reason for hiding this comment

tomeon Feb 4, 2016

Choose a reason for hiding this comment

infertux Feb 9, 2016

Choose a reason for hiding this comment

infertux commented Feb 4, 2016

tomeon commented Feb 4, 2016

infertux commented Feb 10, 2016

tomeon commented Feb 10, 2016

infertux commented Feb 10, 2016