Performance issue

[jeff-hykin]

Originally added to:
microsoft/vscode#76579

Code:
https://raw.githubusercontent.com/onqtam/doctest/master/doctest/doctest.h

@matter123 I haven't looked into the cause yet but I imagine its related to the repeated = or repeated ##.

[jeff-hykin]

#define DOCTEST_IMPLEMENT_FIXTURE(der, base, func, decorators)                                     \
    namespace {                                                                                    \
        struct der : public base                                                                   \
        {                                                                                          \
            void f();                                                                              \
        };                                                                                         \
        static void func() {                                                                       \
            der v;                                                                                 \
            v.f();                                                                                 \
        }                                                                                          \
        DOCTEST_REGISTER_FUNCTION(DOCTEST_EMPTY, func, decorators)                                 \
    }                                                                                              \
    inline DOCTEST_NOINLINE void der::f()

Looks like this is one of the problems, something with the macro syntax. Even just

#define DOCTEST_IMPLEMENT_FIXTURE(der, base, func, decorators)                                     \
    namespace {                                                                                    \

causes some problems

[matter123]

This looks like there are widespread slowness with this file. Though this may not be the grammars fault. The total tim according to perf is 468ms. The wall time was 11 seconds.

Additionally there are multiple lines from vscode-textmate of:

[2] - Grammar is in an endless loop - Grammar pushed the same rule without advancing

Perf report

match failure
pattern name average time total time
source.c:3632 0.035506 10.332
source.c:3732 0.027700 5.762
source.c:3655 0.013474 0.189
source.c:3782 0.005938 0.707
source.c:3654 0.004261 10.001
source.c:572 0.004209 0.034
source.c:2306 0.004178 65.073
source.c:2307 0.003124 0.078
source.c:3801 0.003094 0.006
source.c:369 0.002918 52.923
source.c:2152 0.002916 0.213
source.c:3843 0.002472 0.005
source.c:833 0.002298 64.517
source.c:2622 0.002041 59.519
source.c:875 0.001982 0.008
source.c:370 0.001899 0.118
source.c:3928 0.001772 0.012
source.c:2257 0.001760 33.669
source.c:791 0.001673 43.932
source.c:3593 0.001601 0.243

matched, not chosen
pattern name average time total time
source.c:442 0.016371 0.033
source.c:791 0.016138 31.986
source.c:833 0.015329 8.231
source.c:538 0.014586 0.204
source.c:3900 0.012095 5.092
source.c:3773 0.009022 0.812
source.c:3834 0.008606 0.181
source.c:382 0.008342 3.787
source.c:3801 0.007760 0.132
source.c:2517 0.007196 0.201
source.c:3732 0.007024 0.112
source.c:2306 0.006998 17.027
source.c:2631 0.006940 0.007
source.c:3782 0.006850 3.110
source.c:1898 0.006585 1.804
source.c:577 0.006466 0.026
source.c:369 0.006347 19.219
source.c:3632 0.006335 0.615
source.c:3655 0.006184 1.812
source.c:3654 0.006007 2.649

matched, chosen
pattern name average time total time
source.c:1968 0.016761 0.034
source.c:74 0.016256 8.274
source.c:2108 0.013673 8.245
source.c:2067 0.013327 0.413
source.c:2602 0.013223 0.145
source.c:833 0.013053 2.833
source.c:538 0.012523 0.050
source.c:791 0.010806 5.522
source.c:2347 0.010574 0.381
source.c:490 0.010561 0.760
source.c:442 0.009932 0.030
source.c:2880 0.009438 0.009
source.c:630 0.009113 0.036
source.c:661 0.008598 0.034
source.c:3593 0.007686 0.123
source.c:811 0.007520 0.105
source.c:853 0.007361 0.184
source.c:473 0.007171 0.022
source.c:3613 0.007160 0.165
source.c:213 0.007158 0.286

Edit: after getting a more accurate total time:
The total time to tokenize the file was 8801ms, the total time considering regular expressions 468ms. There is 8 seconds of unaccounted for time.

[jeff-hykin]

The total time to tokenize the file was 8801ms, the total time considering regular expressions 468ms

What would cause the tokenizer to take so long? I thought it was a pretty simple assignment.

[matter123]

I'm guessing it takes several hundred milliseconds to decide that there is a loop. It complains 13 times.

[jeff-hykin]

I'll have time to work on a fix tomorrow

[matter123]

There may be some loop going on with the macros

  token: |                                                                                    |
      * source.cpp
      * meta.preprocessor.macro.cpp
      * meta.function.definition.cpp
      * meta.head.function.definition.cpp
      * meta.preprocessor.macro.cpp
      * meta.function.definition.cpp
      * meta.head.function.definition.cpp
      * meta.preprocessor.macro.cpp
      * meta.function.definition.cpp
      * meta.head.function.definition.cpp
      * meta.block.namespace.cpp
      * meta.body.namespace.cpp
      * meta.block.namespace.cpp
      * meta.body.namespace.cpp
      * meta.block.struct.cpp
      * meta.tail.struct.cpp
      * meta.preprocessor.macro.cpp
      * meta.block.namespace.cpp
      * meta.body.namespace.cpp

[matter123]

Can the dependency switch back to microsoft's vscode-textmate. With the recent updates, they no longer behave the same.

[matter123]

Switching to using vscode-textmate gives a much more realistic report

Edit: this is beecause the full file was being parsed as source.c

Perf Results

match failure pattern name average time total time source.cpp:4887 0.187313 3.746 source.cpp:17154 0.105864 0.953 source.cpp:6514 0.035632 1.497 source.cpp:16874 0.021462 0.193 source.cpp:845 0.020405 0.939 source.cpp:16506 0.019823 0.178 source.cpp:5437 0.014897 0.298 source.cpp:7935 0.010306 0.433 source.cpp:1331 0.010014 0.421 source.cpp:4704 0.009266 0.389 source.cpp:812 0.008863 0.390 source.cpp:20607 0.008499 0.076 source.cpp:1052 0.008355 0.359 source.cpp:1085 0.007531 0.361 source.cpp:1286 0.007380 0.310 source.cpp:11124 0.006999 0.028 source.cpp:14855 0.006996 0.035 source.cpp:1253 0.006673 0.280 source.cpp:4632 0.006352 0.267 source.cpp:5356 0.006139 0.012

matched, not chosen
pattern name average time total time
source.cpp:6228 0.220867 0.883
source.cpp:11124 0.048327 0.048
source.cpp:2139 0.029790 0.089
source.cpp:5361 0.018922 0.038
source.cpp:6288 0.018801 0.038
source.cpp:18454 0.016797 0.034
source.cpp:812 0.015685 0.016
source.cpp:14834 0.009259 0.028
source.cpp:5356 0.008690 0.009
source.cpp:135 0.007629 0.015
source.cpp:20588 0.007058 0.007
source.cpp:15338 0.006980 0.293
source.cpp:14855 0.005622 0.022
source.cpp:15347 0.005200 0.031
source.cpp:15307 0.004573 0.005
source.cpp:14787 0.003459 0.003
source.cpp:112 0.002330 0.014
source.cpp:2319 0.001743 0.002

matched, chosen
pattern name average time total time
source.cpp:11467 48538.839217 48538.839
source.cpp:4887 0.118986 0.238
source.cpp:14792 0.055849 0.056
source.cpp:11124 0.041161 0.041
source.cpp:6228 0.031960 0.064
source.cpp:10498 0.021573 0.022
source.cpp:5361 0.020159 0.040
source.cpp:11565 0.018099 0.018
source.cpp:5379 0.017107 0.034
source.cpp:10638 0.016237 0.016
source.cpp:11599 0.016189 0.016
source.cpp:2139 0.014517 0.015
source.cpp:812 0.013819 0.041
source.cpp:18459 0.013035 0.013
source.cpp:11578 0.012968 0.013
source.cpp:15338 0.012052 0.145
source.cpp:14834 0.010654 0.043
source.cpp:11116 0.010194 0.010
source.cpp:139 0.008330 0.017
source.cpp:18445 0.008190 0.008

[matter123]

So line 11467 is the begin pattern for struct. This is likely another form of catastrophic backtracking.

[jeff-hykin]

Can the dependency switch back to microsoft's vscode-textmate. With the recent updates, they no longer behave the same.

Yeah, lets permanently switch back

[jeff-hykin]

#define DOCTEST_IMPLEMENT_FIXTURE(der, base, func, decorators)                                     \
    namespace {                                                                                    \
        struct def : public base                           \

it has something to do with the spaces after the public base

[matter123]

maybe(@spaces) is fairly popular (x8) in generateStructorClassBlock. Maybe try replacing that with @std_space?

[jeff-hykin]

🎊 that fixed it 100%