Report generation is taking more time > 30 minutes

[vaidhyanathan-ananthakrishnan]

using builtin_takeover and codecov. Codecov report was fast as before, but we wanted to have branch coverage so ran deep-cover report. But unfortunately it is taking more than 30 minutes and still not completed.

We had
1.3K files in total. 90K relevant lines

Is there any way to speed it up.

[marcandre]

Hi!
Sorry you're having trouble with DeepCover. Generating a report should be very quick. There's either an infinite loop going on, or some strange situation. We are very interested in finding out how to reproduce this. I imagine you can't share the code, but it might be instructive to have the stacktrace when you interrupt deep-cover report, if you can share it.

Maybe we could produce a version with a debugging option that would give feedback on the progress, so we could know which part of the code causes the issue.

PS: Sorry for the delay, I'm currently traveling...

[vaidhyanathan-ananthakrishnan]

Thanks @marcandre

I have attached the trace for your reference

I tried multiple times, but the following are the stack trace which ends up taking a long time. Also attached as txt file

^C/Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/range.rb:296:in `<=>': Interrupt from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:91:in `==' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:91:in `relationship_with' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:64:in `block in place_in_hierachy' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:64:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:64:in `group_by' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:64:in `place_in_hierachy' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:59:in `do_combine' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter/action.rb:31:in `combine' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter.rb:270:in `combine' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/parser-2.5.1.0/lib/parser/source/tree_rewriter.rb:142:in `wrap' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/source.rb:120:in `wrap' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/source.rb:73:in `block (2 levels) in insert_node_tags' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/source.rb:72:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/source.rb:72:in `block in insert_node_tags' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:70:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:77:in `block in each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/analyser/base.rb:76:in `each_node' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/source.rb:70:in `insert_node_tags' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/source.rb:29:in `convert_source' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/source.rb:18:in `format_source' from (erb):26:in `block in render_template' from /Users/vaidhyanathana/.rvm/rubies/ruby-2.3.7/lib/ruby/2.3.0/erb.rb:864:in `eval' from /Users/vaidhyanathana/.rvm/rubies/ruby-2.3.7/lib/ruby/2.3.0/erb.rb:864:in `result' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/tools/render_template.rb:10:in `render_template' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/site.rb:52:in `render_source' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/site.rb:59:in `block in save_pages' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/base.rb:25:in `block in each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/coverage.rb:54:in `block in each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/coverage.rb:48:in `each_key' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/coverage.rb:48:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/base.rb:24:in `each' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/site.rb:56:in `save_pages' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/site.rb:21:in `save' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html/site.rb:64:in `save' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/reporter/html.rb:11:in `report' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-core-0.7.5/lib/deep_cover/coverage.rb:91:in `report' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-0.7.5/lib/deep_cover/cli/commands/report.rb:11:in `report' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/thor-0.20.3/lib/thor/command.rb:27:in `run' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/thor-0.20.3/lib/thor/invocation.rb:126:in `invoke_command' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-0.7.5/lib/deep_cover/cli.rb:81:in `invoke_command' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/thor-0.20.3/lib/thor.rb:387:in `dispatch' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/thor-0.20.3/lib/thor/base.rb:466:in `start' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/gems/deep-cover-0.7.5/exe/deep-cover:12:in `<top (required)>' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/bin/deep-cover:23:in `load' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/bin/deep-cover:23:in `<main>' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/bin/ruby_executable_hooks:24:in `eval' from /Users/vaidhyanathana/.rvm/gems/ruby-2.3.7/bin/ruby_executable_hooks:24:in `<main>'

stack_Trace.txt

[marcandre]

Thank you for the stacktrace.

It doesn't look like there's anything strange going on. I did some testing on activesupport's code and got a similar stacktrace on the second attempt.

FWIW, activesupport is about 25k loc and deep-cover report takes 30 seconds on my 5 year old Macbook air...

If you look at the timestamps of ls -l coverage/** do you see files that are generated a few seconds apart? Does the reporting always seem to hang after processing the same file?

[vaidhyanathan-ananthakrishnan]

It didn't struct in any file but file generation is slow about 6-7 files per minutes. Will dig further in my free time.

[MaxLap]

No idea if that could be an issue, but could you take a look at your memory usage while its running? If you were to get into swap for some reason, that would explain this very slow throughput.

[marcandre]

I have a reproductible case with #68, I will be looking into this asap.

[marcandre]

Updating to the latest parser gem should resolve the issue