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

Dredd keeps failing to connect to hooks handler #26

Closed
driesvints opened this issue Jan 21, 2017 · 38 comments
Closed

Dredd keeps failing to connect to hooks handler #26

driesvints opened this issue Jan 21, 2017 · 38 comments

Comments

@driesvints
Copy link

driesvints commented Jan 21, 2017

Ok so, I've been pulling my hair out on this one. I keep getting the message below and have no clue what's going wrong. Tried increasing timeouts etc but I don't think that's the problem. Could it perhaps be file permissions related?

Here's the CLI output:

$ node_modules/.bin/dredd apiary.apib http://localhost:8001 --server "php -S 0.0.0.0:8001 -t public/" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php
info: Starting backend server process with command: php -S 0.0.0.0:8001 -t public/
info: Waiting 3 seconds for backend server process to start.
[Sat Jan 21 07:54:39 2017] Failed to listen on 0.0.0.0:8001 (reason: Address already in use)
info: Backend server process exited.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
warn: Error connecting to the hooks handler process. Is the handler running? Retrying.
info: Hooks handler stdout: Starting server

error: Connection timeout 1.5s to hooks handler on localhost:61321 exceeded. Try increasing the limit.
info: Sending SIGTERM to backend server process.

Here's the basic hookfile.php

<?php

use Dredd\Hooks;

require __DIR__.'/../../../vendor/autoload.php';

$app = require __DIR__.'/../../../bootstrap/app.php';
$app->make(Illuminate\Contracts\Console\Kernel::class)->bootstrap();

Hooks::beforeEach(function (&$transaction) use ($app) {
    echo "before each";
});

Does anyone have an idea what I'm missing or what I might be doing wrong? Running PHP 5.5 with Laravel 5.2 for this specific project.

@ddelnano
Copy link
Owner

ddelnano commented Jan 21, 2017

Just to rule out the possibility you have dredd-hooks-php installed via composer and it's in the vendor/bin directory?

@driesvints
Copy link
Author

Yep, it is.

@driesvints
Copy link
Author

When I add --hooks-worker-handler-port 8001 to the command I get the following output:

$ node_modules/.bin/dredd apiary.apib http://localhost:8001 --server "php -S 0.0.0.0:8001 -t public/" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php --hooks-worker-handler-port 8001
info: Starting backend server process with command: php -S 0.0.0.0:8001 -t public/
info: Waiting 3 seconds for backend server process to start.
[Sat Jan 21 08:16:43 2017] Failed to listen on 0.0.0.0:8001 (reason: Address already in use)
info: Backend server process exited.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
info: Successfully connected to hooks handler. Waiting 0.1s to start testing.
info: Hooks handler stdout: Starting server

warn: Hook handling timed out.
warn: Hook handling timed out.
warn: Hook handling timed out.
fail: GET /icons duration: 5013ms
warn: Hook handling timed out.
info: Sending SIGTERM to hooks handler process.
info: Displaying failed tests...
fail: GET /icons duration: 5013ms
fail: Failed in before hook: Hook timed out.
complete: 0 passing, 1 failing, 0 errors, 0 skipped, 1 total
complete: Tests took 21169ms
info: Sending SIGTERM to backend server process.

I added a logger inside the beforeEach method to check if it was run but it isn't.

@ddelnano
Copy link
Owner

Is this your first time using it? Might be helpful to run through the example in the wiki if you haven't already. Also the --language vendor/bin/dredd-hooks-php should work but since its integrated with dredd you can use --language php. I don't think that will change the behavior but just thought I would mention it.

@ddelnano
Copy link
Owner

I'm closing this for now. I don't mind helping you through this until you get it working but this is a user issue and not something that needs fixed.

@driesvints
Copy link
Author

Yes it is. I've run through multiple examples from the wiki and some blog posts.

When I use --language php I get:

error: PHP hooks handler command not found: dredd-hooks-php
Install php hooks handler by running:
$ composer require ddelnano/dredd-hooks-php --dev

No problem for closing the issue. Was just desperate for some help. Thanks for helping :)

@driesvints
Copy link
Author

Managed to solve the Address already in use issue for the server process already by using nohup.

$ node_modules/.bin/dredd apiary.apib http://localhost:3000 --server "nohup php -S localhost:3000 -t public/ &>/dev/null" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php
info: Starting backend server process with command: nohup php -S localhost:3000 -t public/ &>/dev/null
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
warn: Error connecting to the hooks handler process. Is the handler running? Retrying.
info: Hooks handler stdout: Starting server

error: Connection timeout 1.5s to hooks handler on localhost:61321 exceeded. Try increasing the limit.
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

Still can't connect to the handler though 😕

@ddelnano
Copy link
Owner

Is this a project that can be shared so I can take a look and poke around things?

@driesvints
Copy link
Author

@ddelnano unfortunately not :( it's a closed source project. I can provide as many code snippets within reason if you want.

@driesvints
Copy link
Author

I just tried setting up a vanilla Laravel project to try out Dredd but now I'm getting the following issue. It's a different one from above but it's weird that I can't even get the most basic setup to work 😕

$ dredd apiary.apib http://localhost:3000 --server "nohup php -S localhost:3000 -t public &>/dev/null"
info: Starting backend server process with command: nohup php -S localhost:3000 -t public &>/dev/null
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
error: GET /posts duration: 16ms
error: Error connecting to server under test!
info: Displaying failed tests...
fail: GET /posts duration: 16ms
fail: Error connecting to server under test!
request:
method: GET
uri: /posts
headers:
    User-Agent: Dredd/2.2.5 (Darwin 16.3.0; x64)

body:



expected:
headers:
    Content-Type: application/json

body:
[
  {
    "id": 1,
    "title": "Hello World"
  }
]
statusCode: 200


complete: 0 passing, 0 failing, 1 errors, 0 skipped, 1 total
complete: Tests took 24ms
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

@honzajavorek
Copy link
Contributor

Why do you run the server using nohup php -S localhost:3000 -t public &>/dev/null? I'm not really sure something like that will work with Dredd. Does php -S localhost:3000 -t public work?

@driesvints
Copy link
Author

Heya, I'm using nohup to prevent the Address already in use errors. This works fine and has nothing to do with the problems above. I got this tip from a friend who uses this in his Dredd workflow for a while now and he has no problems with using it. The problems above are the same if I don't use it.

@ddelnano
Copy link
Owner

ddelnano commented Jan 23, 2017

So given you were getting Address already in use errors I'm assuming you can verify that the hooks server successfully starts and binds to the port. Can you get it into the state where it would cause the Address already in use and make sure that you are able to connect to the server. You can use netcat like so to test the connection nc localhost 61321 -v.

@driesvints also what version of the php hooks are you using?

@driesvints
Copy link
Author

Heya, I can trigger an Address already in use error. Please note that this is a different one from the one above. I believe the one below happens when I run the command twice quickly after each other. It also specifically states that it's for the hooks handler and not the server command.

$ node_modules/.bin/dredd apiary.apib http://localhost:3000/api --server "php -S localhost:3000 -t public/" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php
info: Starting backend server process with command: php -S localhost:3000 -t public/
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
warn: Error connecting to the hooks handler process. Is the handler running? Retrying.
info: Hooks handler stdout: Starting server

info: Hooks handler stdout:

info: Hooks handler stdout:
  [ErrorException]
  stream_socket_server(): unable to connect to tcp://127.0.0.1:61321 (Address already in use)



error: Connection timeout 1.5s to hooks handler on localhost:61321 exceeded. Try increasing the limit.
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

I cannot seem to re-trigger the Address already in use error for the server command after removing the nohup part.

@driesvints
Copy link
Author

@ddelnano Using the latest 1.1.5 version of this package.

@ddelnano
Copy link
Owner

@driesvints the hook handler is what I am interested in and is what Dredd is having trouble connecting to. Basically I want to verify that you are able to connect to the hook server and rule out that the server is not functioning properly. Can you try to do what I described above with netcat?

@driesvints
Copy link
Author

@ddelnano ah yeah sorry. I actually tried it out but forgot to paste the result. I can't connect to it:

$ node_modules/.bin/dredd apiary.apib http://localhost:3000/api --server "php -S localhost:3000 -t public/" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php
info: Starting backend server process with command: php -S localhost:3000 -t public/
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
warn: Error connecting to the hooks handler process. Is the handler running? Retrying.
info: Hooks handler stdout: Starting server

error: Connection timeout 1.5s to hooks handler on localhost:61321 exceeded. Try increasing the limit.
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.
$ nc localhost 61321 -v
nc: connect to localhost port 61321 (tcp) failed: Connection refused
nc: connect to localhost port 61321 (tcp) failed: Connection refused

@driesvints
Copy link
Author

Btw @honzajavorek if you want me to open a separate issue for the second issue let me know.

@ddelnano
Copy link
Owner

ddelnano commented Jan 23, 2017

@driesvints can you try launching the server yourself and running the same test? If the following works than something is going on with how Dredd is launching the server potentially

vendor/bin/dredd-hooks-php

# separate terminal
nc localhost 61321 -v

@driesvints
Copy link
Author

@ddelnano getting the same result

@driesvints
Copy link
Author

Btw, I'm really sorry for not mentioning this earlier but I wasn't sure if it mattered: I'm running this on a Vagrant box and not on my local machine.

Using Ubuntu Trusty:

$ lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 14.04.2 LTS
Release:	14.04
Codename:	trusty

@driesvints
Copy link
Author

Hmm, when I use 127.0.0.1 it works...

$ nc 127.0.0.1 61321 -v
Connection to 127.0.0.1 61321 port [tcp/*] succeeded!

@ddelnano
Copy link
Owner

ddelnano commented Jan 23, 2017

@driesvints ah does your vagrant box not have localhost in its /etc/hosts file? Is dredd trying to connect to the hooks server using localhost? From the output above it looks like dredd uses localhost. Please make sure its in your /etc/hosts file and if not add the following entry.

localhost 127.0.0.1

@driesvints
Copy link
Author

I think so. When I also change localhost to 127.0.0.1 in the server command I get the following output:

$ node_modules/.bin/dredd apiary.apib http://127.0.0.1:3000/api --server "nohup php -S 127.0.0.1:3000 -t public/ &>/dev/null" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php --hooks-worker-handler-host 127.0.0.1
info: Starting backend server process with command: nohup php -S 127.0.0.1:3000 -t public/ &>/dev/null
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
info: Successfully connected to hooks handler. Waiting 0.1s to start testing.
info: Hooks handler stdout: Starting server

info: Hooks handler stdout:

info: Hooks handler stdout:
  [ErrorException]
  stream_socket_server(): unable to connect to tcp://127.0.0.1:61321 (Address already in use)



warn: Hook handling timed out.
warn: Hook handling timed out.
warn: Hook handling timed out.
fail: GET /icons duration: 5012ms
warn: Hook handling timed out.
info: Sending SIGTERM to hooks handler process.
info: Displaying failed tests...
fail: GET /icons duration: 5012ms
fail: Failed in before hook: Hook timed out.
complete: 0 passing, 1 failing, 0 errors, 0 skipped, 1 total
complete: Tests took 21165ms
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

I indeed just discovered that the 127.0.0.1 ip address is mapped to something different than localhost. I didn't know about this... Asking the people who set it up why this is set up like that.

Investigating further because after running it again it seems that the hooks are finally working. Although I still have no clue why the error above keeps happening.

@ddelnano
Copy link
Owner

ddelnano commented Jan 23, 2017

There is a previous hooks server listening on the port. Do the following. Dredd is supposed to clean those up but I am guessing since you are seeing some weird issues here maybe it did not get killed.

lsof -i tcp:61321

# find the pid of the process. You don't need to use -9 and probably shouldn't but that will get rid of it for sure
kill -9 pid

Then rerun your dredd command.

@driesvints
Copy link
Author

driesvints commented Jan 23, 2017

@ddelnano ok so now I'm getting the following.

Doing the following steps:

  1. I run the command and get the connection timeout error
  2. I run the command again and I get a failing test report (but the test seems to succeed.)

Result for the first run:

$ node_modules/.bin/dredd apiary.apib http://127.0.0.1:3000/api --server "nohup php -S 127.0.0.1:3000 -t public/ &>/dev/null" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php --hooks-worker-handler-host 127.0.0.1
info: Starting backend server process with command: nohup php -S 127.0.0.1:3000 -t public/ &>/dev/null
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
warn: Error connecting to the hooks handler process. Is the handler running? Retrying.
info: Hooks handler stdout: Starting server

error: Connection timeout 1.5s to hooks handler on 127.0.0.1:61321 exceeded. Try increasing the limit.
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

Result for the second run:

$ node_modules/.bin/dredd apiary.apib http://127.0.0.1:3000/api --server "nohup php -S 127.0.0.1:3000 -t public/ &>/dev/null" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd/hooks/hookfile.php --hooks-worker-handler-host 127.0.0.1
info: Starting backend server process with command: nohup php -S 127.0.0.1:3000 -t public/ &>/dev/null
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd/hooks/hookfile.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
info: Successfully connected to hooks handler. Waiting 0.1s to start testing.
fail: GET /icons duration: NaNms
info: Sending SIGTERM to hooks handler process.
info: Displaying failed tests...
fail: GET /icons duration: NaNms
fail: headers: Header 'content-type' has value 'text/html' instead of 'application/json'
body: Can't validate real media type 'text/plain' against expected media type 'application/json'.
statusCode: Status code is not '200'

request:
method: GET
uri: /icons
headers:
    User-Agent: Dredd/2.2.5 (Linux 3.16.0-30-generic; x64)

body:



expected:
headers:
    Content-Type: application/json

body:
{
  "data": [
    {
      "id": 1,
      "class": "bs-icon-list"
    },
    {
      "id": 2,
      "class": "bs-icon-globe"
    }
  ]
}
statusCode: 200


actual:
statusCode: 500
headers:
    host: 127.0.0.1:3000
    connection: close
    x-powered-by: PHP/5.5.9-1ubuntu4.17
    content-type: text/html

body:




complete: 0 passing, 1 failing, 0 errors, 0 skipped, 1 total
complete: Tests took 1338ms
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

The second try successfully made the connection and I suspect it fails because I still need to configure the setup in the hooks file properly.

I get the following result in the laravel.log file:

[2017-01-23 14:43:43] local.DEBUG: before each  
[2017-01-23 14:44:44] local.ERROR: exception 'ErrorException' with message 'stream_socket_accept(): accept failed: Connection timed out' in /var/www/html/promoter/current/vendor/ddelnano/dredd-hooks-php/src/Server.php:40
Stack trace:
#0 [internal function]: Illuminate\Foundation\Bootstrap\HandleExceptions->handleError(2, 'stream_socket_a...', '/var/www/html/p...', 40, Array)
#1 /var/www/html/promoter/current/vendor/ddelnano/dredd-hooks-php/src/Server.php(40): stream_socket_accept(Resource id #1033)
#2 /var/www/html/promoter/current/vendor/ddelnano/dredd-hooks-php/bin/dredd-hooks-php(47): Dredd\Server->run(false)
#3 {main}  

The DEBUG line is definitely for the second attempt. I'm not sure for which attempt the ERROR line is happening.

@driesvints
Copy link
Author

@ddelnano I did try to command you gave but it didn't give any result.

@driesvints
Copy link
Author

Success! I managed to get the tests passing and the hooks working. The &>/dev/null part was indeed causing some issues. Still getting the Address already in use issue though.

$ node_modules/.bin/dredd apiary.apib http://127.0.0.1:3000/api --server "php -S 127.0.0.1:3000 -t public/" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd.php --hooks-worker-handler-host 127.0.0.1
info: Starting backend server process with command: php -S 127.0.0.1:3000 -t public/
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
info: Successfully connected to hooks handler. Waiting 0.1s to start testing.
info: Hooks handler stdout: Starting server

info: Hooks handler stdout:

info: Hooks handler stdout:
  [ErrorException]
  stream_socket_server(): unable to connect to tcp://127.0.0.1:61321 (Address already in use)



[Mon Jan 23 08:42:59 2017] 127.0.0.1:59263 [200]: /api/icons
pass: GET /icons duration: NaNms
info: Sending SIGTERM to hooks handler process.
complete: 1 passing, 0 failing, 0 errors, 0 skipped, 1 total
complete: Tests took 4632ms
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

@ddelnano
Copy link
Owner

ddelnano commented Jan 23, 2017

you have a hooks server or something else bound to that port somehow. hm maybe I typed that command out wrong but it should have worked. You can also pass the --force option to the hook server and it will unbind anything on a previous hook server listening on that socket.

@honzajavorek
Copy link
Contributor

if you want me to open a separate issue for the second issue let me know

I got a bit lost in the discussion, but sure 😄

@driesvints
Copy link
Author

@ddelnano how do you pass the --force option in the example above?

Also: how would you handle passing environment variables to the command? Just set them before the command?

Btw, really appreciate all the help!

@driesvints
Copy link
Author

@ddelnano I rebooted the Vagrant machine to make sure all connections were closed and that did the trick. I also increased the hooks connect timeout to 3s and that also made sure that the worker could connect properly. I don't get the Address in use issue anymore now.

$ node_modules/.bin/dredd apiary.apib http://0.0.0.0:3000/api --server "env APP_ENV=testing php -S 0.0.0.0:3000 -t public/" --language vendor/bin/dredd-hooks-php --hookfiles tests/dredd.php --hooks-worker-handler-host 0.0.0.0 --hooks-worker-connect-timeout 3000
info: Starting backend server process with command: env APP_ENV=testing php -S 0.0.0.0:3000 -t public/
info: Waiting 3 seconds for backend server process to start.
info: Beginning Dredd testing...
info: Found Hookfiles: 0=tests/dredd.php
info: Spawning `vendor/bin/dredd-hooks-php` hooks handler process.
warn: Error connecting to the hooks handler process. Is the handler running? Retrying.
info: Hooks handler stdout: Starting server

warn: Error connecting to the hooks handler process. Is the handler running? Retrying.
info: Successfully connected to hooks handler. Waiting 0.1s to start testing.
[Mon Jan 23 10:25:08 2017] 127.0.0.1:35055 [200]: /api/icons
pass: GET /icons duration: NaNms
info: Sending SIGTERM to hooks handler process.
complete: 1 passing, 0 failing, 0 errors, 0 skipped, 1 total
complete: Tests took 5792ms
info: Sending SIGTERM to backend server process.
info: Backend server process was killed.

@ddelnano
Copy link
Owner

@driesvints either in your dredd.yml or you can probably add it in the language flag directly but you will need to add quotes around the vendor/bin/dredd-hooks-php --force

@ddelnano
Copy link
Owner

Never tried before so I am not sure about the environment variables.

@driesvints
Copy link
Author

@ddelnano I ended up using putenv in the hookfile to set the env variables.

Think I'm all set now. It's working both locally and on CircleCI. Thanks for all your help. And thanks for being so patient with me ^^

@ddelnano
Copy link
Owner

No worries glad you're setup

@driesvints
Copy link
Author

@honzajavorek heya, I managed to solve the second problem by recreating the project from scratch. There must have been some hiccup in the first attempt. Anyway, it's all working now. Thanks for your help :)

@honzajavorek
Copy link
Contributor

Good, you're welcome! Enjoy Dredd!

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

No branches or pull requests

3 participants