honzajavorek
commented
8 years ago Hi @zmorris, thanks for such elaborate investigation! We're aware of the fact Dredd is slow when booting and wanted to find out why is that. There are actually many factors that can play a significant role in it. As a first step to help with any kind of debugging, I'm preparing a version of Dredd with extensive verbose logging. Currently, as you noticed yourself, it doesn't help much to lower the logging level. So one option is to wait until new release with extended logging is out and see what takes the largest portion of time.
However, at the same time from what you write, it feels like the largest portion of time is taken by parsing your API Blueprint document. It's not very well documented, but we provide two ways to parse API Blueprint - by our C++11 parser and by our JS-only parser. Historically, the C++ parser was the only way to parse the documents, but it caused a lot of troubles when installing Dredd. That's why we provide the JS parser now as a fallback if installation of the C++ one fails. See https://github.com/apiaryio/drafter-npm/ for details.
Unfortunately, Dredd has no diagnostic tools as of now to tell you which parser you are using (see #625). However, it should be visible during the npm install dredd process - if there's failure in protagonist package installation, then you're using the JS parser. Try to make sure to have the C++ parser and compare the times if the C++ version happens to be faster - usually it's enough to install a C++11 compatible gcc (if you're on Windows, then... it can be a different story). To me it seems like natively you have C++11 available thus faster parser is used, but in the virtual box it's not provisioned, not available, so JS parser is used and thus parsing your rather large API Blueprint happens to be very slow. But that's just my theory.
Action points for us
- Document how people can use C++ parser instead of JS one - #634
- Enable diagnostics - #625
- Add logging to enable better debugging - #635
Action points for you
- Try to make sure C++11 can be used and
protagonistcan install, then see if times are lower
kuba-kubula
zmorris
o5
Hi I'm using Dredd with PHP hooks. It was running fine with a previous version (unfortunately I don't know which) but since upgrading, it takes over 2 minutes to begin testing. I tried putting an echo "starting"; die; at the top of my Tests/dredd/hooks.php but it doesn't print "starting" until after the delay.
dredd --versionshowsdredd v2.1.0 (Linux 3.19.0-25-generic; x64)anddredd --level=verbosedoesn't reveal anything. Node.js is at 6.6.0.top -o %CPUshows the processes pegged at 99%, which drops to 1% or less during testing. So only the loading stage is an issue (although there does seem to be an unrelated delay between tests that I'm not as concerned about).My blueprint.mp file is 835 kB with 111 endpoints which doesn't seem that large (most of the space goes to json request and response bodies). I decided to time it by cutting lines from the file, here are the results from time I type
dreddto when it gets past the loading stage toBeginning Dredd testing...:percentage kept -> # of endpoints tested -> seconds 25% -> 28 -> 10 33% -> 37 -> 17 50% -> 56 -> 39 100% -> 111 -> 144
This looks suspiciously exponential. If it was linear then 50% would take 20 seconds (not 39), and 100% would take 40 seconds (not 148, which is close to 160). It's most likely slowing by the square of the number of lines loaded.
I'm inside a
Vagrantbox withnfsdisabled because I was having synchronization issues. This makes files run much, much slower than they should. Maybe Dredd is reading the file a line or even a character at a time, and possibly re-reading the whole file up to each endpoint statement. So the exponential slowdown may not have been noticeable with native disk access.Just wanted to be thorough because testing is accounting for a large portion of my time late in a project. Other than that, Dredd is a great tool and I have no complaints, thanks for your efforts.
UPDATE: I ran dredd natively and the time dropped to 124 seconds so I don't think the issue is due to Vagrant file slowness. Smaller pieces of the file followed a similar curve, just ran a little faster.
UPDATE: I tracked the last fast version down to Dredd 1.0.11, see my comment below for details.