search

cucumber / aruba

Test command-line applications with Cucumber-Ruby, RSpec or Minitest.
MIT License
949 stars 163 forks source link

background_process does does not flush $stdout #18

Closed byrnejb closed 13 years ago

byrnejb commented 14 years ago

When testing a background process that streams significant amounts of data to $stdout the test eventually blocks on a write to $stdout and the test process halts indefinitely. This problem is a result of the switch to the background_process gem to implement the run command. An issue respecting this matter has been raised with the gem author

http://github.com/timcharper/background_process/issues#issue/2

but no response has been forthcoming.

Attempts to work around this matter by manually flushing $stdout in the test process itself has no effect on the behaviour of the test. Initially I thought that this was strictly a Ruby-1.9.2 problem as all tests passed when run under 1.8.7. However, by slightly increasing the amount of data sent to $stdout the problem also arises in Ruby-1.8.7.

While this is, strictly speaking, a problem with the background_process gem itself, its presence makes the use of it in aruba somewhat problematic.

byrnejb commented 14 years ago

This feature will expose the problem, but it does not fail, it simply blocks completion:

Feature: run command should not limit size of STDOUT

  In order to specify commands that produce output to STDOUT
  As a developer using Cucumber
  I want all output in STDOUT to display  

@wip
  Scenario: Handle a large STDOUT data stream
    When I run "ruby -e \" 500.times { puts %Q(rword )* 30 }\""
    Then the stdout should contain "rword"
msassak commented 14 years ago

Can you run aruba with the following When steps?

When I run "ruby -e 'puts :a.to_s * 16383'"

and then

When I run "ruby -e 'puts :a.to_s * 16384'"

On my machine the first step passes and the second one hangs. I'm not sure yet why 16KB is the magic number. I'll look into this more soon.

byrnejb commented 14 years ago

For me (CentOS-5.5 on Core Duo Quad x86_64) the threshold values are

When I run "ruby -e 'puts :a.to_s * 65535'"  # passes = 2**16 − 1
When I run "ruby -e 'puts :b.to_s * 65536'"  # blocks and does not complete
msassak commented 14 years ago

Thanks byrnejb. I'll likely push a fix to my fork later tonight.

msassak commented 14 years ago

This should help: http://github.com/msassak/aruba/tree/18-background_process_not_flushing_output

Please test it if you can and let me know.

byrnejb commented 14 years ago

I built the aruba gem from your master branch, ran bundle install and then cucumber features/flushing.feature. The results were:

$ cucumber features/flushing.feature
Feature: Flushing output
  In order to test processes that output a lot of data
  As a developer using Aruba
  I want to make sure that large amounts of output aren't buffered

  Scenario: Tons of output                      # features/flushing.feature:7
    When I run "ruby -e 'puts :a.to_s * 65536'" # lib/aruba/cucumber.rb:90
    Then the output should contain "a"          # lib/aruba/cucumber.rb:106
    And the output should be 65537 bytes long   # features/step_definitions/aruba_dev_steps.rb:17

  Scenario: Tons of interactive output                                             # features/flushing.feature:12
    When I run "ruby -e 'len = gets.chomp; puts :a.to_s * len.to_i'" interactively # lib/aruba/cucumber.rb:98
    And I type "65536"                                                             # lib/aruba/cucumber.rb:102
    Then the output should contain "a"                                             # lib/aruba/cucumber.rb:106
    And the output should be 65536 bytes long                                      # features/step_definitions/aruba_dev_steps.rb:17

2 scenarios (2 passed)
7 steps (7 passed)
0m1.030s

However, If I build from your 18-background_process_not_flushing_output branch I get this:

$ cucumber features/flushing.feature
Feature: Flushing output
  In order to test processes that output a lot of data
  As a developer using Aruba
  I want to make sure that large amounts of output aren't buffered

  Scenario: Tons of output                      # features/flushing.feature:7
    When I run "ruby -e 'puts :a.to_s * 65536'" # lib/aruba/cucumber.rb:90
    Then the output should contain "a"          # lib/aruba/cucumber.rb:106
    And the output should be 65537 bytes long   # features/step_definitions/aruba_dev_steps.rb:17

  Scenario: Tons of interactive output                                             # features/flushing.feature:12
    When I run "ruby -e 'len = gets.chomp; puts :a.to_s * len.to_i'" interactively # lib/aruba/cucumber.rb:98
    And I type "65536"                                                             # lib/aruba/cucumber.rb:102
    Then the output should contain "a"                                             # lib/aruba/cucumber.rb:106
    And the output should be 65536 bytes long                                      # features/step_definitions/aruba_dev_steps.rb:17
      expected: 65536,
           got: 65537 (using ==) (RSpec::Expectations::ExpectationNotMetError)
      ./features/step_definitions/aruba_dev_steps.rb:18:in `/^the output should be (\d+) bytes long$/'
      features/flushing.feature:16:in `And the output should be 65536 bytes long'

Failing Scenarios:
cucumber features/flushing.feature:12 # Scenario: Tons of interactive output

2 scenarios (1 failed, 1 passed)
7 steps (1 failed, 6 passed)
0m1.019s

So, I infer that there is a difference in behaviour between run interactively between versions.

msassak commented 14 years ago

My master branch is the same as Aslak's, which is the same as v0.2.3 of the gem, so I'm not sure why that feature is passing with it, but whatever the case, I just pushed a tiny workaround fix to 18-background_process_not_flushing_output that should take care of the one-byte difference. Did you verify that this fixed the original problem?

byrnejb commented 14 years ago

Yes. Move the bgnd_process wait on exit to after the the read from stdout fixed the original problem and I have merged this with my fork. I discovered later that you added a chomp to the step definition to resolve the difference between a simple run and an interactive run. I altered the expectation in the feature file. The result is the same, the test passes.

aslakhellesoy commented 13 years ago

I ran into something similar. See #30. Did I just dupe this ticket?

msassak commented 13 years ago

We're not using background_process anymore, and we have some features for flushing large amounts of output in place. Can we close this ticket?

byrnejb commented 13 years ago

Yes.