Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Resolve several maintenance issues #81

Merged
merged 7 commits into from
Jan 2, 2017
Merged

Resolve several maintenance issues #81

merged 7 commits into from
Jan 2, 2017

Conversation

mbland
Copy link
Owner

@mbland mbland commented Jan 2, 2017

Closes #59, which turned out not to be too much of an issue after all. In fact, I've set the redirection to >/dev/null instead of &>/dev/null, since command -v typically prints nothing when the command isn't found, and I'd like to see any error output if it ever comes to exist.

Closes #69. Note that in cases where the \n is concatenated with a string that contains a variable expansion, the single $'\n' must stand, because variable expansion does not take place within $'...'.

Closes #76.

Fixes a test failure on Cygwin. Because group read permission wasn't disabled, the test case set_bats_output_and_lines_from_file fails if permission denied failed on Cygwin. As a rule, it's probably best to always set ugo- in tests. (Also considering updating the octal chmod arguments to the ugo- variety. But not today.)

Fulfills part of #62. @go.split and @go.join may come in a future commit.

Closes #59, which turned out not to be too much of an issue after all.
In fact, I've set the redirection to `>/dev/null` instead of
`&>/dev/null`, since `command -v` typically prints nothing when the
command isn't found, and I'd like to see any error output if it ever
comes to exist.
Closes #69. Note that in cases where the `\n` is concatenated with a
string that contains a variable expansion, the single `$'\n'` must
stand, because variable expansion does not take place within `$'...'`.
Because group read permission wasn't disabled, the test case
`set_bats_output_and_lines_from_file fails if permission denied` failed
on Cygwin. As a rule, it's probably best to always set `ugo-` in tests.

Also considering updating the octal `chmod` arguments to the `ugo-`
variety. But not today.
Fulfills part of #62. `@go.split` and `@go.join` may come in a future
commit.
@coveralls
Copy link

Coverage Status

Coverage decreased (-0.006%) to 94.287% when pulling bc45bd3 on maintenance into 66a5633 on master.

This definitively fixes the failing `log/log-command` tests for the
Travis Linux build. The breakage was due to a bug in Bash 4.2.25, and
not fixed until 4.2.41, in which process substitutions did not have
access to the temporary environment for a command. Moving `IFS=','` to a
`local` declaration in `_@go.log_level_file_descriptors` solves the
problem, but emphasizes the need for a `@go.split` function as described
in #62. I'll implement it and replace all `IFS='...' read -ra`
invocations with it shortly to protect against the same bug.

Details:
-------
Several `log/log-command` test cases failed for the Travis Linux build
for #81 prior to this commit:

- https://travis-ci.org/mbland/go-script-bash/builds/188272967
- https://travis-ci.org/mbland/go-script-bash/builds/188273548

These builds ran with Bash 4.2.25(1)-release, and I could not reproduce
the failures using 3.2.57(1)-release or 4.4.5(1)-release.

To reproduce the error, I downloaded the Bash 4.2 sources and patches
from:

- https://mirrors.ocf.berkeley.edu/gnu/bash/
- https://mirrors.ocf.berkeley.edu/gnu/bash/bash-4.2-patches/

To make life easier, I downloaded the patches via:

```bash
mkdir bash-source
cd bash-source
BASEURL='https://mirrors.ocf.berkeley.edu/gnu/bash/bash-4.2-patches/bash42-0'
for i in {1..9}; do
  curl -O "${BASEURL}0${i}"
done
for i in {10..53}; do
  curl -O "${BASEURL}${i}"
done
```

I then proceeded to build version 4.2.25 via:

```bash
gzip -dc bash-4.2.tar.gz | tar xf -
mv bash-4.2 bash-4.2.25
cd bash-4.2.25
for p in ../bash42-00* ../bash42-0{10..25}; do patch -p0 <"$p"; done
./configure --prefix=/usr/local/bash-builds/4.2.25 && make install
```

Then I returned to the go-script-bash project and ran:

```bash
PATH="/usr/local/bash-builds/4.2.25/bin:$PATH" ./go test log/log-command
```

This recreated the failure as seen on Travis. The relevant change
appeared to be the update to `_@go.log_level_file_descriptors` to use
`IFS=',' read -ra`. To debug, I instrumented the function like so (which
inspired me to file #82):

```bash
_@go.log_level_file_descriptors() {
  IFS=',' read -ra __go_log_level_file_descriptors \
    <<< "${__GO_LOG_LEVELS_FILE_DESCRIPTORS[$1]}"
  if [[ -n "$TEST_DEBUG" &&
        ${#__go_log_level_file_descriptors[@]} -eq '1' ]]; then
    echo "FDS: '${__go_log_level_file_descriptors[@]}'" >&2
    @go.print_stack_trace >&2
  fi
}
```

and then updated the first failing test suite thus:

```
@test "$SUITE: logging to a file doesn't repeat lines or skip other log files" {
  local info_log="$TEST_GO_ROOTDIR/info.log"

  TEST_DEBUG='true' run_log_script \
```

The test would then fail for 3.2.57 and 4.4.5, with the following as the
final `FDS: '...'` line:

```
   FDS: '1 4 5'
```

But for 4.2.25:

```
   FDS: '1,4,5'
```

This reflected the invocation taking place in `function_that_logs_info`,
which was executed within a process substitution via `@go.log_command`
and `_@go.log_command_invoke`. I built 4.2.53 (the last 4.2 patch level)
and ran the test, and it passed. After building intervening versions in
a `git bisect`-like fashion, I finally pinpointed the problem and the
fix in patch 41. From
https://mirrors.ocf.berkeley.edu/gnu/bash/bash-4.2-patches/bash42-041:

```
  Process substitution incorrectly inherited a flag that inhibited using the
  (local) temporary environment for variable lookups if it was providing the
  filename to a redirection.  The intent the flag is to enforce the Posix
  command expansion ordering rules.
```

From https://tiswww.case.edu/php/chet/bash/CHANGES:

```
  This document details the changes between this version, bash-4.3-alpha, and
  the previous version, bash-4.2-release.

  iii. Fixed a bug that caused commands in process substitutions to not look in
       the local temporary environment when performing word expansions.
```

And from bash-4.3/ChangeLog:

```
            12/2
            ----
  subst.c
    - process_substitute: turn off the `expanding_redir' flag, which controls
      whether or not variables.c:find_variable_internal uses the temporary
      environment to find variables.  We want to use the temp environment, since
      we don't have to worry about order of evaluation in a subshell.  Fixes bug
      reported by Andrey Borzenkov
```

Moving `IFS=','` to a local declaration fixed all test cases for 4.2.25,
and the full build passed as well. However, I allowed all the other
`IFS='...' read` invocations to stand for now, even though they're
technically all just as vulnerable as the one from
`_@go.log_level_file_descriptors`. I'll implement `@go.split` and then
replace all instances with a call to that function in a follow-up PR.
@coveralls
Copy link

Coverage Status

Coverage decreased (-0.05%) to 94.241% when pulling 99ab780 on maintenance into 66a5633 on master.

@mbland
Copy link
Owner Author

mbland commented Jan 2, 2017

The breakage was due to a bug in Bash 4.2.25 (Travis's Bash version on Linux), and not fixed until 4.2.41, in which process substitutions did not have access to the temporary environment for a command. Moving IFS=',' to a local declaration in _@go.log_level_file_descriptors solves the problem, but emphasizes the need for a @go.split function as described in #62. I'll implement it and replace all IFS='...' read -ra invocations with it shortly to protect against the same bug.

See the message for commit 99ab780 for the gory details of the root cause analysis.

@mbland mbland merged commit 5cd0211 into master Jan 2, 2017
@mbland mbland deleted the maintenance branch January 2, 2017 21:45
mbland added a commit that referenced this pull request Jan 3, 2017
Using `[[:space:]]` instead of just a single space character should make
line wrapping more robust. Thought about using the following trick from
https://stackoverflow.com/questions/369758/3352015#3352015, but there
was no perceptible performance difference, and I decided the code was
more readable using the pattern matching idiom:

  prefix="${prefix%"${prefix##*[![:space:]]}"}"
  line="${line#"${line%%[![:space:]]*}"}"

Hoising `IFS` from a `read`-specific temp variable to a `local`
declaration guards against the process substitution bug described in #81
and commit 99ab780.
mbland added a commit that referenced this pull request Jan 3, 2017
The intention was to refactor `@go.log_command` to hoist the temporary
`IFS=` assignment out of the `while IFS= read` loop by demonstrating how
this deeply nested series of `@go.log_command` invocations would fail
under Bash 4.2.25. However, the test continued to pass.

During the course of experimentation, I tried reverting
`_@go.log_level_file_descriptors` back to setting `IFS=, read` inline as
before #81, and the new test failed as expected, only producing the
output:

```
   RUN    outer_function
      Hello, World!
```

Then I replaced the implementation with this, and the test passed:

```
  _@go.log_level_file_descriptors() {
    while IFS=',' read -ra __go_log_level_file_descriptors; do
      break
    done <<< "${__GO_LOG_LEVELS_FILE_DESCRIPTORS[$1]}"
  }
```

So it appears that it's only single `IFS= read` statements that are
vulnerable to the bug, but `while IFS= read` statements are fine. Good
to know.
mbland added a commit that referenced this pull request Jan 3, 2017
Closes #62. The urgent need for `@go.split` in particular was made
apparent during the course of implementing #81, whereby Travis's Linux
build running Bash 4.2.25(1)-release caused the `log/log-command` test
to expose a bug whereby the temporary environment for `IFS=, read`
in `_@go.log_level_file_descriptors` wasn't honored inside of process
substitutions. Also see the message for commit
99ab780.

Since `@go.log_command` uses a process substitution to capture command
output, and thus potentially any `./go` script command could be so
captured, the need for `@go.split` to encapsulate (and document) the
workaround for this bug became a priority.

Strangely, `while IFS= read` invocations aren't affected by the bug, so
those don't require any special treatment. See the message for commit
2297b48.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants