llvm dev - Mar 2016 - Where is the time going? - update

Further to my previous email, I now have some answers.  The culprit is the
IR verifier.

1. opt -time-passes does not report time spent in the IR verifier.

If I add -disable-verify, opt's run time drops from 71 seconds to 37
seconds.

2. -disable-verify doesn't disable all verification runs.

The IR verifier is run 3 times: once prior to any optimization work, once
between running the module passes and running the function passes, and
finally at the end of all optimization prior to writing out optimized IR.

-disable-verify knocks out the first and last invocations of the verifier,
but leaves the middle invocation in. You can see this by throwing
-debug-pass=Executions and running in a debugger. There is a noticeable
pause between running the module and function passes. If you backtrace
during this pause, you will see that you are in the verifier.

If I account for time spent in the middle invocation of the verifier, the
non-verifier run time agrees with the output of -time-passes.
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<http://lists.llvm.org/pipermail/llvm-dev/attachments/20160309/f166f9e6/attachment.html>

> On Mar 9, 2016, at 12:09 PM, David Jones via llvm-dev <llvm-dev at
lists.llvm.org> wrote:
> 
> Further to my previous email, I now have some answers.  The culprit is the
IR verifier.
> 
> 1. opt -time-passes does not report time spent in the IR verifier.
> 
> If I add -disable-verify, opt's run time drops from 71 seconds to 37
seconds.
> 
> 2. -disable-verify doesn't disable all verification runs.
> 
> The IR verifier is run 3 times: once prior to any optimization work, once
between running the module passes and running the function passes, and finally
at the end of all optimization prior to writing out optimized IR.
> 
> -disable-verify knocks out the first and last invocations of the verifier,
but leaves the middle invocation in.
Could you point us to this middle invocation?

It really does seem like we should check for -disable-verify before
any calls to llvm::verifyModule and friends.

vedant

> You can see this by throwing -debug-pass=Executions and running in a
debugger. There is a noticeable pause between running the module and function
passes. If you backtrace during this pause, you will see that you are in the
verifier.
> 
> If I account for time spent in the middle invocation of the verifier, the
non-verifier run time agrees with the output of -time-passes.
> 
> _______________________________________________
> LLVM Developers mailing list
> llvm-dev at lists.llvm.org
> http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev

Thanks, fixed in r263090.

vedant
> On Mar 9, 2016, at 6:27 PM, David Jones <djones at xtreme-eda.com>
wrote:
> 
> I believe the offender is (LLVM 3.7.1 sources) tools/opt/opt.cpp line 209.
> 
> For LLVM 3.8.0, we've moved down to line 215.
> 
> 
> On Wed, Mar 9, 2016 at 6:01 PM, Vedant Kumar <vsk at apple.com>
wrote:
> 
> > On Mar 9, 2016, at 12:09 PM, David Jones via llvm-dev <llvm-dev at
lists.llvm.org> wrote:
> >
> > Further to my previous email, I now have some answers.  The culprit is
the IR verifier.
> >
> > 1. opt -time-passes does not report time spent in the IR verifier.
> >
> > If I add -disable-verify, opt's run time drops from 71 seconds to
37 seconds.
> >
> > 2. -disable-verify doesn't disable all verification runs.
> >
> > The IR verifier is run 3 times: once prior to any optimization work,
once between running the module passes and running the function passes, and
finally at the end of all optimization prior to writing out optimized IR.
> >
> > -disable-verify knocks out the first and last invocations of the
verifier, but leaves the middle invocation in.
> 
> Could you point us to this middle invocation?
> 
> It really does seem like we should check for -disable-verify before
> any calls to llvm::verifyModule and friends.
> 
> vedant
> 
> 
> > You can see this by throwing -debug-pass=Executions and running in a
debugger. There is a noticeable pause between running the module and function
passes. If you backtrace during this pause, you will see that you are in the
verifier.
> >
> > If I account for time spent in the middle invocation of the verifier,
the non-verifier run time agrees with the output of -time-passes.
> >
> > _______________________________________________
> > LLVM Developers mailing list
> > llvm-dev at lists.llvm.org
> > http://lists.llvm.org/cgi-bin/mailman/listinfo/llvm-dev
> 
>