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

[close #156] Capture stderr from heroku run #187

Merged
merged 2 commits into from
Jul 12, 2021

Conversation

schneems
Copy link
Contributor

The rate limiting messages are delivered via the heroku cli to stderr which we're currently not capturing. This means that when we check stdout there will never be a rate limit message, so our rate limiting and retry code never fires. This is documented in #156.

This PR fixes this by moving from exec-ing the process via backpacks to using Open3.capture3 which captures stderr in addition to stdout. The biggest caveat is that it does not set the value for $? Which some tests are likely relying on. To prevent this change from breaking backwards compat we will exec an exit with the same status code. It's not ideal, but it will work.

In the future we may want to consider deprecating returning a string and moving to return an object that holds a status value instead.

@schneems schneems force-pushed the schneems/fix-shell-throttling branch from 35155d3 to 61ece1f Compare May 19, 2021 19:36
The rate limiting messages are delivered via the `heroku` cli to stderr which we're currently not capturing. This means that when we check stdout there will never be a rate limit message, so our rate limiting and retry code never fires. This is documented in #156.

This PR fixes this by moving from exec-ing the process via backpacks to using `Open3.capture3` which captures stderr in addition to stdout. The biggest caveat is that it does not set the value for $? Which some tests are likely relying on. To prevent this change from breaking backwards compat we will exec an `exit` with the same status code. It's not ideal, but it will work.

In the future we may want to consider deprecating returning a string and moving to return an object that holds a status value instead.
@schneems schneems force-pushed the schneems/fix-shell-throttling branch from 61ece1f to 54c50f2 Compare May 19, 2021 19:43
Heroku-16 is deprecated. Heroku-18 is not.

```
{"id":"unsupported","message":"Creating new apps on the heroku-16 stack is not supported. Please consider using heroku-20 instead: https://devcenter.heroku.com/articles/stack. If you need to create a new heroku-16 app, please open a support ticket: https://help.heroku.com/new/increase-limits."}
```
@schneems schneems requested a review from dzuelke May 19, 2021 19:59
@dzuelke
Copy link
Contributor

dzuelke commented May 28, 2021

So this changes the behavior of Hatchet - a test run will now no longer print all the "Running foobar on blahblah" messages at all anymore - I don't think that's a bad thing, as it means we don't clutter the "." output so much anymore, but I just wante to ensure that that's understood and accepted (my previous change in #158 / 423a557 explicitly still printed the output has it happened).

@dzuelke
Copy link
Contributor

dzuelke commented May 28, 2021

(I'm pointing this out as well because this very output is what helped initially diagnose the timeouts part of #158, and it would have been much harder to discover without any output - although if we fix those timeout things in separate PRs, we won't have to worry about it any longer anyway).

@schneems
Copy link
Contributor Author

I would say that if stderr to the CI output is helping to diagnose, that it's an accidental interface. Our team is the primary consumer of this gem, if something is hard to debug as a result of merging this in, I would like to annotate the output somehow. We already have the concept of catching test failures and adding extra information to the error. We could do something like that (if needed).

@dzuelke
Copy link
Contributor

dzuelke commented May 28, 2021

Yeah I agree.

Anyway, I just realized this is a breaking change PR - I have tests that rely on @output and @status from the run:

def expect_exit(expect: :to, operator: :eq, code: 0)
	raise ArgumentError, "Expected a block but none given" unless block_given?
	run_obj = yield
	expect(run_obj.status.exitstatus).method(expect).call(
		method(operator).call(code),
		"Expected exit code #{run_obj.status.exitstatus} #{expect} be #{operator} to #{code}; output:\n#{run_obj.output}"
	)
	run_obj # so that can be tested too
end
it "restricts the app to 6 GB of RAM", :if => series < "7.4" do
	expect(expect_exit(code: 0) { @app.run("./waitforit.sh 15 'ready for connections' heroku-php-#{server} --verbose", :return_obj => true, :heroku => {:size => "Performance-L"}) }.output)
		 .to match("Detected 15032385536 Bytes of RAM")
		.and match("Limiting to 6G Bytes of RAM usage")
		.and match("Starting php-fpm with 48 workers...")
end

Related discussion under "exit status" in #158

@schneems
Copy link
Contributor Author

@dzuelke it's not backwards breaking. The return_obj flag you're using there isn't on main it's in your branch. Same with calling output directly on the object run_obj.output

This is what the code returns in app.rb for run multi:

        yield run_obj.output, run_obj.status

This is what it returns for regular run:

      return run_obj.output

We only ever expose the string, never the actual object.

HerokuRun object does alias output already:

  class HerokuRun
    attr_reader :command

    def initialize(
      command,
      app: ,
      heroku: {},
      retry_on_empty: !ENV["HATCHET_DISABLE_EMPTY_RUN_RETRY"],
      raw: false,
      stderr: $stderr)

      @raw = raw
      @app = app
      @command = build_heroku_command(command, heroku || {})
      @retry_on_empty = retry_on_empty
      @stderr = stderr
      @result = nil
      @empty_fail_count = 0
    end

    def result
      raise "You must run `call` on this object first" unless @result
      @result
    end

    def output
      result.stdout # <======== HERE
    end

Which is why the existing tests are passing. I think this is good to go. Merging this is a blocker to working on the timeout stuff.

@schneems schneems merged commit 6c37340 into main Jul 12, 2021
@schneems schneems deleted the schneems/fix-shell-throttling branch July 12, 2021 15:25
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.

2 participants