Dredd redirects server output

[aledeg]

Unlike many tools available, I cannot have a nice progress output with dredd on CLI.

I am thinking of a dot progress like you can find with tools like behat or phpunit.
We could have something like:

.....F..E...S............F..E...S............F..E...S................. 70
...............F..E...S............F..E...S............F..E...S....... 140
.....
145 tests (121 passed, 6 failed, 6 errored, 6 skipped)

This would be great especially when using with travis.

Bonus will be with colors :)

[ecordell]

I think you want the --reporter=dot argument to get that output. Other options are: junit, nyan, dot, markdown, html, and apiary. See: https://dredd.readthedocs.io/en/latest/usage-cli/#-reporter-r

[honzajavorek]

Ha, I forgot about --reporter=dot. @aledeg Would that work for you?

[aledeg]

@ecordell I wasn't aware of that option. Good catch!
@honzajavorek Sure! as soon as I can make it work. So far, no luck.

[aledeg]

I think the dot reporter is not working. Dredd stall when used with that reporter.

[aledeg]

I am using the dot reporter, but for some reason, the output is not what I am expecting.

Instead of having something like

...F..

I have something like:

[Tue Aug 23 11:51:39 2016] 127.0.0.1:44062 [200]: /dredd.php/book
.[Tue Aug 23 11:51:39 2016] 127.0.0.1:44062 [201]: /dredd.php/book
.[Tue Aug 23 11:51:39 2016] 127.0.0.1:44062 [400]: /dredd.php/book
.[Tue Aug 23 11:51:39 2016] 127.0.0.1:44062 [200]: /dredd.php/book/1
F[Tue Aug 23 11:51:39 2016] 127.0.0.1:44062 [400]: /dredd.php/book/1

How should I configure dredd to get the output I'd like?

[honzajavorek]

Seems like a bug to me. My fault, I should have better check if everything works as expected when closing #594.

Looks like the dot reporter never properly worked and you are digging it up from its tomb. I'm sorry for the issues, but many thanks for going through this! I'll try to look into it in following days.

[aledeg]

@honzajavorek Thanks!

[honzajavorek]

@aledeg I wasn't able to reproduce this. What exactly is your setup? This is what I get:

$ dredd apiary.apib http://localhost --reporter=dot
info: Beginning Dredd testing...
F..F.F
info: Displaying failed tests...
fail: POST /machines duration: 336ms
...

How do you run Dredd, what is your dredd.yml, version, etc.? Do you use --level?

[aledeg]

@honzajavorek I use dredd 2.0

Here is my config file:

dry-run: null
hookfiles: [tests/dredd/*Hook.php]
language: vendor/bin/dredd-hooks-php
sandbox: false
server: 'php -S 127.0.0.1:8888 -t web/'
server-wait: 3
init: true
custom: {}
names: false
only: []
reporter: dot
output: []
header: []
sorted: false
user: null
inline-errors: false
details: false
method: []
color: true
level: info
timestamp: false
silent: false
path: []
hooks-worker-timeout: 50000
hooks-worker-connect-timeout: 15000
hooks-worker-connect-retry: 500 
hooks-worker-after-connect-wait: 1000
hooks-worker-term-timeout: 50000
hooks-worker-term-retry: 500 
hooks-worker-handler-host: localhost
hooks-worker-handler-port: 61321
blueprint: apiary.apib
endpoint: 'http://127.0.0.1:8888/app_dredd.php'

When I wrote that ticket, it was with the previous stable version. But I did reproduced the same behavior. It might be linked to my environment though.
I run it on Ubuntu 16.04, with Bash 4.3.46. I either use Terminator 0.98 or GNOME terminal 3.18.3.

[honzajavorek]

Thanks for getting back! Do you think it's possible that PHP hooks produce the extra output? What is the output if you run Dredd without them? Or maybe the server (php -S 127.0.0.1:8888 -t web/)? Could you try it out with a different one, e.g. http://example.com? (Mind that we don't need the test run to pass, just see what's on the output.)

[aledeg]

@honzajavorek Here are the tests I ran:

• without hooks: same output
• change server to http://example.com: it does not work at all
• change endpoint to http://example.com: I don't see the output anymore.

It looks like I need some changes on my end. I'll keep you posted

[honzajavorek]

Ah, I'm sorry for advicing you to use http://example.com as a server. It was 7 PM and my brain was probably already turned off. Server needs to be a command.

If you have Python, you can use this for a server: python -m SimpleHTTPServer (for Python 3, use python -m http.server).

[aledeg]

No problem. We all have the same problem in the morning :P

I replaced 'php -S 127.0.0.1:8888 -t web/' by 'python -m http.server' and it works as expected.
I need to find out what is logging in the console on my end. But I have no ideas at the moment.

FYI, I am testing an API written in PHP using Symfony 3 and API platform

[honzajavorek]

Then the logging comes from the server. The question is, whether Dredd should mute the server output or redirect it. Is it useful? Maybe it would be better if it was debug output level and could be turned on for debugging, but would be muted by default. What do you think?

[aledeg]

In my use case, I don't need the output when it's normal. But if there is an error, I want to see it.
So I think the way dredd works now is adequate. I have to figure how to change the output in my project.

[honzajavorek]

@aledeg Any updates on this?

[aledeg]

@honzajavorek unfortunately no :( I didn't have the time to investigate. I'll keep you posted though

[aledeg]

@honzajavorek I found the culprit. It's the PHP server launched by dredd. I need to find how to silent it.

[ddelnano]

@aledeg what is the problem with the php server??

[aledeg]

@ddelnano Everytime you call the server, it outputs something like [Tue Aug 23 11:51:39 2016] 127.0.0.1:44062 [200]: /dredd.php/book
You can try by starting the built-in server with the following command php -S 127.0.0.1:8888 and requesting any file.

@honzajavorek As I am using Symfony for my developments, I've changed php -S 127.0.0.1:8888 -t web/ by bin/console server:start 127.0.0.1:8888 and it works fine. I think in a non-Symfony environment you have to use a router file with php built-in server.
You can have an example here.

I still have a problem with the output, though.

If I keep the default level, I have the following output:

info: Connected to the hook handler, waiting 1s to start testing.
.....info: Sending SIGTERM to the hooks handler

complete: 5 passing, 0 failing, 0 errors, 0 skipped
complete: Tests took 10321ms

If I set the level to warning, I have the following output:

.....

I wish I could have something in between, for instance:

.....
complete: 5 passing, 0 failing, 0 errors, 0 skipped

Maybe adding a level ci that shows warnings and errors but also the tests summary. That would be really nice when using with travis or other CI systems.

[ddelnano]

@aledeg ok I see. So I am thinking that would probably be a concern of Dredd's. It should properly swallow the server's stdout / stderr in order to print clean dot reporting.

[honzajavorek]

@aledeg @ddelnano That's a question. Should Dredd generally swallow server output or not? In current codebase, it's hard to swallow the output just for a certain reporter (moreover, you can have multiple reporters). I see three options:

1. Dredd should just silence all server output.
2. Dredd should redirect all server output as it happens and have switch for silencing it.
3. Dredd should capture all server output and after testing it should output it separately. There should be switch for silencing it.

What would be most useful, in your opinion?

@aledeg Regarding the logging level, the priority goes like this, but I'm not sure if it's possible to achieve what you want. Which is not good, since that's what people probably expect from dot reporter.

Thanks again for this "dot reporter adopter" job, it really helps! We think of revamping reporters and logging output in the future and these limitations, while it might not be possible to fix them easily right away, can help us to design it the right way at least for future.

[ddelnano]

@honzajavorek I am thinking that option 3 makes the most sense. 2 is obviously bad from the context of this situation because it is responsible for causing what @aledeg is trying to avoid. Oops did not finish reading all of two and missed the "silencing" part. 1 I think would be ok but it might be helpful to enable it during certain debugging times.

[aledeg]

@ddelnano @honzajavorek
I think that option 1 is not good especially during debug sessions.
I really don't have a preference for the 2 other options as long as there is a switch to swallow everything.

[aledeg]

@honzajavorek So I made a test where I set the level to complete and I've almost got the output I wanted :)
Not perfect but quite close. Here is an example:

info: Configuration 'tests/dredd/dredd.yml' found, ignoring other arguments.

 [OK] Web server listening on http://127.0.0.1:8888

.....
complete: 5 passing, 0 failing, 0 errors, 0 skipped
complete: Tests took 9388ms

[aledeg]

I also added the quiet flag to start the Symfony command. Now, I have the following output:

info: Configuration 'tests/dredd/dredd.yml' found, ignoring other arguments.
.....
complete: 5 passing, 0 failing, 0 errors, 0 skipped
complete: Tests took 9388ms

Which is much nicer.

[honzajavorek]

Good! Thanks for sharing! I hope this helps also to other dot reporter users.

I think this should be qualified as improvement of Dredd's CLI output. We plan to rethink it a bit in the future and the inconvenience of how dot reporter works is definitely something we should address.

[IllyaMoskvin]

Just wanted to share my workaround, with the caveat that I'm new to Ruby. I think this will be useful for anyone using servers that don't have a working quiet flag. I'm using Grape, which runs on Rack via Shotgun. I tried doing something like...

server: 'shotgun > /dev/null 2>&1'

...but Dredd would fail when trying to spawn the process. Here's the workaround:

1. Create server.sh in the project's folder, containing something like this:

   # Run shotgun, redirect all output to null (stdout and stderr)
   # Launch it as forked, backgrounded child process
   shotgun > /dev/null 2>&1 &
   
   # Save its process id
   PID=$!
   
   # Kill shotgun on exit
   function cleanup {
      kill $PID
   }
   
   trap cleanup EXIT
   
   # Keep this script running until Dredd sends SIGKILL
   cat
   

2. Run chmod +x server.sh

3. In the project's dredd.yml, use the script as the server:

   server: './server.sh'
   

Everything seems to be working fine! I do wish there was an intermediate level between warn and info. I'm glad you guys are working on improving the CLI output. Thanks for the great tool!

Edit 1: Updating server.sh to run in the background until closed by Dredd, then kill shotgun.
Edit 2: Updated! shotgun successfully exits after testing.

[artem-zakharchenko]

It would be nice to address the output split in Dredd, since it currently has 2 instances of winston logger dedicated to Dredd's output and any external output. Once this is settled, and reporters communicate output through stdout/stderr, this can be worked on.