search

Quuxplusone / LLVMBugzillaTest

0 stars 0 forks source link

Very slow reparsing for big header and even slower with preamble generation enabled #30326

Closed Quuxplusone closed 7 years ago

Quuxplusone commented 7 years ago
Bugzilla Link PR31353
Status RESOLVED FIXED
Importance P normal
Reported by Nikolai Kosjar (nikolai.kosjar@qt.io)
Reported on 2016-12-12 06:39:53 -0800
Last modified on 2017-02-20 03:07:19 -0800
Version 3.9
Hardware PC Windows 2000
CC arphaman@gmail.com, Erik.Verbruggen@Me.com, klimek@google.com, llvm-bugs@lists.llvm.org
Fixed by commit(s)
Attachments libclangclient_source_and_testinput.zip (955 bytes, application/zip)
Blocks
Blocked by
See also 
Created attachment 17748
libclangclient.cpp and testinput.cpp

Compile libclangclient.exe from the attached libclangclient.cpp.
Run libclangclient.exe with the attached testinput.cpp, which includes the
3.6MB windows header <Windows.UI.Xaml.Controls.h>.
The command line invocations here provide libclang with proper defines and
include paths from the MSVC2015 Update 3 toolchain, X86:

  > set LIBCLANG_TIMING=1
  > libclangclient.exe -m32 -target i686-pc-windows-msvc "-std=c++14" -fms-extensions -fcxx-exceptions -fexceptions "-D__MSVCRT__=" "-D__w64=" "-D__int64=long long" "-D__int32=long" "-D__int16=short" "-D__int8=char" "-D__ptr32=" "-D__ptr64=" "-D__COUNTER__=0" "-D_CPPRTTI=1" "-D_DEBUG=1" "-D_DLL=1" "-D__FUNCDNAME__= __FUNCDNAME__  " "-D__FUNCSIG__= __FUNCSIG__  " "-D__FUNCTION__= __FUNCTION__  " "-D_INTEGRAL_MAX_BITS=64" "-D_M_IX86=600" "-D_M_IX86_FP=2" "-D_MSC_BUILD=0" "-D_MSC_EXTENSIONS=1" "-D_MSC_FULL_VER=190024210" "-D_MSC_VER=1900" "-D_MT=1" "-D_NATIVE_WCHAR_T_DEFINED=1" "-D_WCHAR_T_DEFINED=1" "-D_WIN32=1" "-D__DATE__="\^""Dec 12 2016"\^""" "-D__TIME__="\^""12:20:52"\^""" "-D__TIMESTAMP__="\^""Mon Dec 12 12:20:52 2016"\^""" "-DUNICODE=1" "-DWIN32=1" "-DQT_NO_CAST_FROM_ASCII=1" "-D__WRL_NO_DEFAULT_LIB__=1" "-DQT_WINRT_LIMITED_DRAGANDDROP=1" "-DQT_QML_DEBUG=1" "-DQT_NO_EXCEPTIONS=1" "-DQT_PLUGIN=1" "-DQT_PLATFORMSUPPORT_LIB=1" "-DQT_GUI_LIB=1" "-DQT_CORE_LIB=1" "-DQT_OPENGL_ES_2=1" "-DQT_OPENGL_ES_2_ANGLE=1" -U__cpp_aggregate_nsdmi -U__cpp_alias_templates -U__cpp_attributes -U__cpp_binary_literals -U__cpp_constexpr -U__cpp_decltype -U__cpp_decltype_auto -U__cpp_delegating_constructors -U__cpp_digit_separators -U__cpp_generic_lambdas -U__cpp_inheriting_constructors -U__cpp_init_captures -U__cpp_initializer_lists -U__cpp_lambdas -U__cpp_nsdmi -U__cpp_range_based_for -U__cpp_raw_strings -U__cpp_ref_qualifiers -U__cpp_return_type_deduction -U__cpp_rtti -U__cpp_rvalue_references -U__cpp_static_assert -U__cpp_unicode_characters -U__cpp_unicode_literals -U__cpp_user_defined_literals -U__cpp_variable_templates -U__cpp_variadic_templates -nostdinc -undef -ID:\usr\qtcreator-4.2.0_689.exe\share\qtcreator\cplusplus\wrappedQtHeaders -ID:\usr\qtcreator-4.2.0_689.exe\share\qtcreator\cplusplus\wrappedQtHeaders\QtCore -ID:\dev\qt5\qtbase\src\plugins\platforms\winrt -ID:\dev\qt5\qtbase\src\3rdparty\freetype\include -ID:\dev\qt5\qtbase\include -ID:\dev\qt5\qtbase\include\QtPlatformSupport -ID:\dev\qt5\qtbase\include\QtPlatformSupport\5.7.1 -ID:\dev\qt5\qtbase\include\QtPlatformSupport\5.7.1\QtPlatformSupport -ID:\dev\qt5\qtbase\include\QtGui\5.7.1 -ID:\dev\qt5\qtbase\include\QtGui\5.7.1\QtGui -ID:\dev\qt5\qtbase\include\QtGui -ID:\dev\qt5\qtbase\include\QtANGLE -ID:\dev\qt5\qtbase\include\QtCore\5.7.1 -ID:\dev\qt5\qtbase\include\QtCore\5.7.1\QtCore -ID:\dev\qt5\qtbase\include\QtCore -ID:\dev\qt5\qtbase\src\plugins\platforms\winrt\.moc\debug -ID:\dev\qt5\qtbase\mkspecs\win32-msvc2015 -ID:\dev\qt5\qtbase\src\plugins\platforms\winrt\.uic "-IC:\Program Files (x86)\Microsoft Visual Studio 14.0\VC\INCLUDE" "-IC:\Program Files (x86)\Microsoft Visual Studio 14.0\VC\ATLMFC\INCLUDE" "-IC:\Program Files (x86)\Windows Kits\10\include\10.0.10240.0\ucrt" "-IC:\Program Files (x86)\Windows Kits\NETFXSDK\4.6.1\include\um" "-IC:\Program Files (x86)\Windows Kits\8.1\include\\shared" "-IC:\Program Files (x86)\Windows Kits\8.1\include\\um" "-IC:\Program Files (x86)\Windows Kits\8.1\include\\winrt" -IC:\Users\nik\AppData\Local\Temp\qtc-clang-uiheader-hk2hmc "-fms-compatibility-version=19.00" "-fmessage-length=0" -fdiagnostics-show-note-include-stack "-fmacro-backtrace-limit=0" -fretain-comments-from-system-headers "-ferror-limit=1000" -x c++ -Weverything -Wno-c++98-compat -Wno-c++98-compat-pedantic -Wno-unused-macros -Wno-newline-eof -Wno-exit-time-destructors -Wno-global-constructors -Wno-gnu-zero-variadic-macro-arguments -Wno-documentation -Wno-shadow -Wno-missing-prototypes D:\work\libclangclient.windows.slow_header\testinput.cpp
  Parsing D:\work\libclangclient.windows.slow_header\testinput.cpp:   7.3594 (100.0%)   0.1406 (100.0%)   7.5000 (100.0%)   7.5156 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:   7.7500 (100.0%)   0.1563 (100.0%)   7.9063 (100.0%)   7.9532 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:   7.4844 (100.0%)   0.1094 (100.0%)   7.5938 (100.0%)   7.6250 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:   7.5781 (100.0%)   0.0781 (100.0%)   7.6563 (100.0%)   7.7187 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:   7.5781 (100.0%)   0.1875 (100.0%)   7.7656 (100.0%)   7.8125 (100.0%)

Reparsing needs almost 8 seconds, which is already to much for IDE requirements.

Change the line from

    const unsigned options = /*CXTranslationUnit_PrecompiledPreamble*/ 0;

to

    const unsigned options = CXTranslationUnit_PrecompiledPreamble;

then, recompile and rerun (same command line invocation, but now shortened):

  > libclangclient.exe ... D:\work\libclangclient.windows.slow_header\testinput.cpp
  Parsing D:\work\libclangclient.windows.slow_header\testinput.cpp:   7.5156 (100.0%)   0.1563 (100.0%)   7.6719 (100.0%)   7.7657 (100.0%)
  Precompiling preamble:  10.0938 (100.0%)   0.2969 (100.0%)  10.3906 (100.0%)  10.6718 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:  22.2031 (100.0%)   0.3281 (100.0%)  22.5313 (100.0%)  22.8801 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:  12.1250 (100.0%)   0.0313 (100.0%)  12.1563 (100.0%)  12.2128 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:  12.2031 (100.0%)   0.0469 (100.0%)  12.2500 (100.0%)  12.2813 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:  12.2188 (100.0%)   0.0469 (100.0%)  12.2656 (100.0%)  12.2656 (100.0%)
  Reparsing D:\work\libclangclient.windows.slow_header\testinput.cpp:  12.0938 (100.0%)   0.0625 (100.0%)  12.1563 (100.0%)  12.1875 (100.0%)

The preamble, which is supposed to speep up reparsing, makes things here even
slower - reparsing takes about 12s now.
Quuxplusone commented 7 years ago

Attached libclangclient_source_and_testinput.zip (955 bytes, application/zip): libclangclient.cpp and testinput.cpp

Quuxplusone commented 7 years ago

What happens when save a preprocessed version of this header and then include that?

Quuxplusone commented 7 years ago 
> What happens when save a preprocessed version of this header and then include
that?

Without the preamble generation:

Parsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
2.9844 (100.0%)   0.0156 (100.0%)   3.0000 (100.0%)   3.0781 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
3.0469 (100.0%)   0.0156 (100.0%)   3.0625 (100.0%)   3.0782 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
3.1094 (100.0%)   0.0313 (100.0%)   3.1406 (100.0%)   3.2206 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
2.8750 (100.0%)   0.0938 (100.0%)   2.9688 (100.0%)   2.9659 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
3.0000 (100.0%)   0.0625 (100.0%)   3.0625 (100.0%)   3.0781 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
3.0625 (100.0%)   0.0313 (100.0%)   3.0938 (100.0%)   3.0938 (100.0%)

And with it enabled:

Parsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
3.0313 (100.0%)   0.0156 (100.0%)   3.0469 (100.0%)   3.0626 (100.0%)
Precompiling preamble:   8.1406 (100.0%)   0.0625 (100.0%)   8.2031 (100.0%)
8.2188 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
8.2500 (100.0%)   0.0625 (100.0%)   8.3125 (100.0%)   8.3281 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
0.1094 (100.0%)   0.1094 (100.0%)   0.1093 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
0.1094 (100.0%)   0.1094 (100.0%)   0.1094 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
0.0938 (100.0%)   0.0156 (100.0%)   0.1094 (100.0%)   0.1094 (100.0%)
Reparsing
D:\work\libclangclient.windows.slow_header\libclangclient_source_and_testinput\testinput.cpp:
0.0938 (100.0%)   0.0156 (100.0%)   0.1094 (100.0%)   0.1093 (100.0%)
Quuxplusone commented 7 years ago

I cannot reproduce this with trunk, can you verify that?

Quuxplusone commented 7 years ago

Ok, I managed to reproduce it. Turns out the time that a reparse-with-preamble is fully spend in ASTUnit::TranslateStoredDiagnostics.

Quuxplusone commented 7 years ago

Fix: https://reviews.llvm.org/D29755

Quuxplusone commented 7 years ago

Fixed in r295301.

Quuxplusone commented 7 years ago 
Yup, looks much better now (with preamble generation turned on):

Parsing D:\work\libclangclient_source_and_testinput\testinput.cpp:   7.6406
(100.0%)   0.1250 (100.0%)   7.7656 (100.0%)   7.8553 (100.0%)
Precompiling preamble:  12.5469 (100.0%)   0.2188 (100.0%)  12.7656 (100.0%)
12.9001 (100.0%)
Reparsing D:\work\libclangclient_source_and_testinput\testinput.cpp:  13.6875
(100.0%)   0.2500 (100.0%)  13.9375 (100.0%)  14.0979 (100.0%)
Reparsing D:\work\libclangclient_source_and_testinput\testinput.cpp:   1.1250
(100.0%)   0.0625 (100.0%)   1.1875 (100.0%)   1.1958 (100.0%)
Reparsing D:\work\libclangclient_source_and_testinput\testinput.cpp:   1.1719
(100.0%)   0.0469 (100.0%)   1.2188 (100.0%)   1.2085 (100.0%)
Reparsing D:\work\libclangclient_source_and_testinput\testinput.cpp:   1.2500
(100.0%)   0.0313 (100.0%)   1.2813 (100.0%)   1.2881 (100.0%)
Reparsing D:\work\libclangclient_source_and_testinput\testinput.cpp:   1.2031
(100.0%)   0.0313 (100.0%)   1.2344 (100.0%)   1.2232 (100.0%)