Skip to content
This repository was archived by the owner on Nov 8, 2024. It is now read-only.

All hooks always time out? #32

Closed
martijnarts opened this issue Mar 6, 2017 · 8 comments
Closed

All hooks always time out? #32

martijnarts opened this issue Mar 6, 2017 · 8 comments

Comments

@martijnarts
Copy link
Contributor

martijnarts commented Mar 6, 2017 •
edited
Loading 

import dredd_hooks as hooks


@hooks.before_all
def hook(transaction):
    print('this will time out')

Prints info: Hooks handler stdout: this will time out, sits for a while, and then claims that "Hook handling timed out."

Any idea what might be happening here?
@w-vi
Copy link
Contributor

w-vi commented Mar 6, 2017 •
edited
Loading

Strange behaviour ... what python version are you using? And also dredd version please.

@martijnarts
Copy link
Contributor Author

I'm using Python 3.6 with Dredd 3.2.0, with dredd_hooks 0.1.2

@w-vi
Copy link
Contributor

w-vi commented Mar 7, 2017

Thanks a lot. We are not currently testing against Python 3.6 so that might be the problem, let me investigate.

@honzajavorek
Copy link
Contributor

@TotempaaltJ Tests seem to pass for Python 3.6. Could you provide more info? How does your API description look like? Could you share at least an anonymized example of it (which hangs as well)?

@martijnarts
Copy link
Contributor Author

The tests don't work on my machine either! This is getting more interesting...

The "Message exchange for event afterAll", "Message exchange for event beforeAll", and "Message exchange for event afterEach" scenarios fail with a similar output:

  Scenario: Message exchange for event afterEach                        # features/tcp_server.feature:32
      Killing server...
      Killing handler...
    Given I run `dredd-hooks-python` interactively                      # aruba-0.6.2/lib/aruba/cucumber.rb:113
    When I wait for output to contain "Starting"                        # aruba-0.6.2/lib/aruba/cucumber.rb:131
      execution expired (Timeout::Error)
      features/tcp_server.feature:34:in `When I wait for output to contain "Starting"'
    And I connect to the server                                         # features/step_definitions/dredd_steps.rb:18
    And I send a JSON message to the socket:                            # features/step_definitions/dredd_steps.rb:22
      """
      {"event": "afterEach", "uuid": "3234-abcd", "data": {"key":"value"}}
      """
    And I send a newline character as a message delimiter to the socket # features/step_definitions/dredd_steps.rb:27
    Then I should receive same response                                 # features/step_definitions/dredd_steps.rb:31
    And I should be able to gracefully disconnect                       # features/step_definitions/dredd_steps.rb:40

@martijnarts
Copy link
Contributor Author

martijnarts commented Mar 8, 2017 •
edited
Loading

@tried to reproduce the original failing Dredd config, but couldn't.

Tests aren't failing consistently either, tried again and only afterEach failed. Then tried again, and then it was all three again.

Edit: getting failures again, will report back.

@martijnarts
Copy link
Contributor Author

martijnarts commented Mar 8, 2017 •
edited
Loading

dredd --level silly returns this:

verbose: Processing transaction #1: Foobar
verbose: Running 'beforeEach' hooks
debug: Running hooks...
verbose: Sending HTTP transaction data to hooks handler: b957526d-60a8-47a6-bfdb-53da1af88e1a
debug: TCP communication with hooks handler closed.
warn: Hook handling timed out.
verbose: Running 'before' hooks
debug: Emitting to reporters: test start
verbose: HTTP transaction was marked in hooks as to be failed. Reporting as failed
verbose: Running 'afterEach' hooks
debug: Running hooks...
verbose: Sending HTTP transaction data to hooks handler: e9435bcb-5d02-452a-94ca-b5b0107b5652
debug: TCP communication with hooks handler errored. Error: This socket has been ended by the other party
    at Socket.writeAfterFIN [as write] (net.js:297:12)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/hooks-worker-client.js:324:31
    at TransactionRunner.runHook (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:280:9)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:161:28
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1008:9
    at replenish (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:882:17)
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:886:9
    at _asyncMap (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1006:5)
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1092:16
    at timeLimit (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:4785:3)
    at Object.timesSeries (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:918:16)
    at TransactionRunner.runHooksForData (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:185:20)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:108:30
    at TransactionRunner.executeTransaction (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:520:14)
    at TransactionRunner.executeTransaction (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:3:57)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:103:28
    at TransactionRunner.runHooksForData (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:189:14)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:99:26
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:186:16
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1013:9
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:356:16
    at replenish (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:877:25)
    at iterateeCallback (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:867:17)
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:840:16
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1010:13
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:166:24
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:281:18
    at Timeout.handleTimeout [as _onTimeout] (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/hooks-worker-client.js:352:20)
    at ontimeout (timers.js:380:14)
    at tryOnTimeout (timers.js:244:5)
    at Timer.listOnTimeout (timers.js:214:5)

debug: TCP communication with hooks handler errored. Error: This socket has been ended by the other party
    at Socket.writeAfterFIN [as write] (net.js:297:12)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/hooks-worker-client.js:325:31
    at TransactionRunner.runHook (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:280:9)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:161:28
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1008:9
    at replenish (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:882:17)
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:886:9
    at _asyncMap (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1006:5)
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1092:16
    at timeLimit (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:4785:3)
    at Object.timesSeries (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:918:16)
    at TransactionRunner.runHooksForData (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:185:20)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:108:30
    at TransactionRunner.executeTransaction (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:520:14)
    at TransactionRunner.executeTransaction (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:3:57)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:103:28
    at TransactionRunner.runHooksForData (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:189:14)
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:99:26
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:186:16
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1013:9
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:356:16
    at replenish (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:877:25)
    at iterateeCallback (/Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:867:17)
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:840:16
    at /Users/martijn/.config/yarn/global/node_modules/async/dist/async.js:1010:13
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:166:24
    at /Users/martijn/.config/yarn/global/node_modules/dredd/lib/transaction-runner.js:281:18
    at Timeout.handleTimeout [as _onTimeout] (/Users/martijn/.config/yarn/global/node_modules/dredd/lib/hooks-worker-client.js:352:20)
    at ontimeout (timers.js:380:14)
    at tryOnTimeout (timers.js:244:5)
    at Timer.listOnTimeout (timers.js:214:5)

warn: Hook handling timed out.
verbose: Running 'after' hooks
debug: Evaluating results of transaction execution #1: Foobar
debug: Emitting to reporters: test fail

I'll continue trying different variations to see if I can find the real problem. It does seem like errors aren't actually printed to stderr though.

@martijnarts martijnarts mentioned this issue Mar 8, 2017
Merged
@martijnarts
Copy link
Contributor Author

My code was throwing an exception which wasn't being properly bubbled up. #34 fixes this 💃

@fgblomqvist fgblomqvist mentioned this issue Mar 20, 2018
Closed
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@martijnarts @honzajavorek @w-vi