Generator Performance Measuring

Settings -> Generator -> Model generation performance report

"Time spent in language generators" looks like this:

Hi Evgeny,

thanks for this tip. When i run my generators on my model, it takes exactly 1 minute - there seems to be something wrong. Please find attached the performance report. How do i have to analyze it?

• Objectflow.generator.template.main seems to consume a lot of time.
  
• a query in collections / dates language takes even longer?? Half of the whole generator time ??

What can i do to improve the performance?

---

[model uiframework]
steps: 42905.806623 ms  (real: 6540.718729 ms)
    reductions: 35095.072212 ms  (real: 5438.52267 ms)
        - [query in jetbrains.mps.baseLanguage.collections.generator.baseLanguage.template.main]: 10152.849584 ms
        - [query in jetbrains.mps.baseLanguage.dates.generator.baseLanguage.template.main]: 9066.500547 ms
        - [query in objectflow.generator.template.javaext]: 4585.533841 ms
        root mappings: 4547.715653 ms  (real: 2419.226039 ms)
            - [query in objectflow.generator.template.main]: 1032.225927 ms
            - [query in modelestic.generator.template.main]: 380.920221 ms
            - [query in jetbrains.mps.xml.generator.baseLanguage.template.main]: 313.812884 ms
            - [query in jetbrains.mps.xmlInternal.generator.baseLanguage.template.main]: 253.971144 ms
            - [query in modellwerkstatt.forms.generator.template.modelestic]: 100.528741 ms
            - [query in jetbrains.mps.baseLanguage.generator.java.closures]: 30.057181 ms
            - [query in objectflow.generator.template.service]: 16.973516 ms
        - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 1750.579371 ms
        - [query in objectflow.generator.template.main]: 1633.802889 ms
        - [query in jetbrains.mps.gtext.generator.baseLanguage.template.main]: 151.926281 ms
        - [query in jetbrains.mps.baseLanguage.generator.java.closures]: 69.301404 ms
        - [query in jetbrains.mps.baseLanguage.generator.java.main]: 38.745255 ms
        - [query in modellwerkstatt.forms.generator.template.modelestic]: 21.167852 ms
        - [query in jetbrains.mps.baseLanguage.generator.java.strings]: 18.181334 ms
        - [query in jetbrains.mps.baseLanguageInternal.generator.template.main]: 14.920409 ms
        - [query in modelestic.generator.template.main]: 11.260454 ms
        create root: 8.862238 ms  (real: 7.163114 ms)
            - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 1.409388 ms
            - [query in modellwerkstatt.forms.generator.template.modelestic]: 0.281195 ms
            - [query in modelestic.generator.template.main]: 0.004316 ms
            - [query in objectflow.generator.template.service]: 0.004225 ms
        - [query in objectflow.generator.template.service]: 5.231092 ms
        - [query in jetbrains.mps.xml.generator.baseLanguage.template.main]: 3.560403 ms
        - [query in jetbrains.mps.xmlInternal.generator.baseLanguage.template.main]: 2.800088 ms
    post-processing: 5141.695357 ms  (real: 0.238094 ms)
        - [query in jetbrains.mps.gtext.generator.baseLanguage.template.main]: 5141.457263 ms
    pre-processing: 1211.072461 ms  (real: 57.52451 ms)
        - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 1147.782648 ms
        - model clone: 55.27182 ms
        - [query in jetbrains.mps.baseLanguageInternal.generator.template.main]: 3.357444 ms
        - [query in objectflow.generator.template.service]: 2.407859 ms
        - recycling: 0.017421 ms
    restoring references: 533.835849 ms  (real: 146.198444 ms)
        - [query in modelestic.generator.template.main]: 377.920306 ms
        - [query in objectflow.generator.template.service]: 6.506997 ms
        - [query in modellwerkstatt.forms.generator.template.modelestic]: 2.864007 ms
        - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 0.301581 ms
        - [query in objectflow.generator.template.main]: 0.044514 ms
    weavings: 62.054571 ms  (real: 36.158838 ms)
        - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 25.895733 ms
    - recycling: 3.071567 ms
    - delayed mappings: 0.037618 ms

Can you please switch on more detailed tracing level ("Time spent in types calculation" option) and post result here?

Sometimes expensive types calculations can be triggered by generation process and in such cases you can improve generator performance by optimizing type system of the language.

Hi Alex,

i switched on a more detailed tracing level. Seems that my generators do not use extensive type calculations at all. Strange that the date language needs so much resources - i use them sparely ..

Thanks for your help,
Dan

---

[model uiframework]
steps: 49584.114427 ms  (real: 6407.171537 ms)
    reductions: 40672.908876 ms  (real: 5294.54152 ms)
        [query in jetbrains.mps.baseLanguage.collections.generator.baseLanguage.template.main]: 10884.322147 ms  (real: 3352.529888 ms)
            [coerce]: 5934.721149 ms  (real: 5848.603623 ms)
- [coerce]: 86.117526 ms
            [type computing]: 1597.07111 ms  (real: 706.752579 ms)
[coerce]: 890.318531 ms  (real: 881.043799 ms)
     - [coerce]: 9.274732 ms
        [query in jetbrains.mps.baseLanguage.dates.generator.baseLanguage.template.main]: 9525.79147 ms  (real: 198.496119 ms)
            [type computing]: 9181.085625 ms  (real: 4140.354625 ms)
[coerce]: 4647.78015 ms  (real: 4644.842203 ms)
     - [coerce]: 2.937947 ms
[is subtype]: 329.036357 ms  (real: 323.861593 ms)
     - [coerce]: 4.011711 ms
     - [is subtype]: 1.163053 ms
- [type computing]: 63.914493 ms
            - [is subtype]: 146.209726 ms
        root mappings: 8570.40724 ms  (real: 2404.254994 ms)
            [query in modellwerkstatt.forms.generator.template.modelestic]: 3381.442009 ms  (real: 3361.26735 ms)
- [type computing]: 20.174659 ms
            [query in objectflow.generator.template.main]: 1350.956293 ms  (real: 29.812743 ms)
[type computing]: 1321.14355 ms  (real: 441.038915 ms)
     [coerce]: 847.039653 ms  (real: 846.41803 ms)
         - [coerce]: 0.621623 ms
     [is subtype]: 33.064982 ms  (real: 31.629376 ms)
         - [coerce]: 1.215146 ms
         - [is subtype]: 0.22046 ms
            [query in modelestic.generator.template.main]: 766.460471 ms  (real: 751.072539 ms)
- [type computing]: 15.387932 ms
            - [query in jetbrains.mps.xml.generator.baseLanguage.template.main]: 342.660248 ms
            - [query in jetbrains.mps.xmlInternal.generator.baseLanguage.template.main]: 267.861865 ms
            - [query in jetbrains.mps.baseLanguage.generator.java.closures]: 30.180343 ms
            [query in objectflow.generator.template.service]: 26.591017 ms  (real: 15.379005 ms)
- [type computing]: 11.212012 ms
        [query in objectflow.generator.template.javaext]: 4758.946199 ms  (real: 88.659412 ms)
            [type computing]: 4453.444853 ms  (real: 1917.799029 ms)
[coerce]: 2377.841679 ms  (real: 2370.414887 ms)
     - [coerce]: 7.426792 ms
[is subtype]: 132.870507 ms  (real: 128.835157 ms)
     - [coerce]: 3.594368 ms
     [is subtype]: 0.440982 ms  (real: 0.384037 ms)
         - [coerce]: 0.056945 ms
- [type computing]: 24.933638 ms
            [is subtype]: 216.841934 ms  (real: 5.586767 ms)
[is subtype]: 211.255167 ms  (real: 205.171232 ms)
     - [coerce]: 6.083935 ms
        [query in objectflow.generator.template.main]: 2055.442233 ms  (real: 22.462713 ms)
            [type computing]: 2032.97952 ms  (real: 851.107526 ms)
[coerce]: 1138.52521 ms  (real: 1137.79178 ms)
     - [coerce]: 0.73343 ms
[is subtype]: 43.346784 ms  (real: 41.080287 ms)
     - [coerce]: 1.979076 ms
     - [is subtype]: 0.287421 ms
        [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 1569.832425 ms  (real: 346.740906 ms)
            [type computing]: 1223.091519 ms  (real: 343.467385 ms)
[coerce]: 868.411229 ms  (real: 866.898376 ms)
     - [coerce]: 1.512853 ms
- [type computing]: 11.053028 ms
- [is subtype]: 0.159877 ms
        - [query in jetbrains.mps.gtext.generator.baseLanguage.template.main]: 214.834734 ms
        - [query in jetbrains.mps.baseLanguage.generator.java.closures]: 69.479832 ms
        - [query in jetbrains.mps.baseLanguage.generator.java.main]: 41.357318 ms
        [query in modellwerkstatt.forms.generator.template.modelestic]: 26.336104 ms  (real: 9.331248 ms)
            - [type computing]: 17.004856 ms
        - [query in jetbrains.mps.baseLanguage.generator.java.strings]: 18.913366 ms
        - [query in jetbrains.mps.baseLanguageInternal.generator.template.main]: 16.2002 ms
        create root: 14.801122 ms  (real: 9.365804 ms)
            - [query in modellwerkstatt.forms.generator.template.modelestic]: 4.410287 ms
            - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 1.01418 ms
            - [query in objectflow.generator.template.service]: 0.006016 ms
            - [query in modelestic.generator.template.main]: 0.004835 ms
        - [query in modelestic.generator.template.main]: 12.133714 ms
        - [query in objectflow.generator.template.service]: 7.023282 ms
        - [query in jetbrains.mps.xml.generator.baseLanguage.template.main]: 3.477178 ms
        - [query in jetbrains.mps.xmlInternal.generator.baseLanguage.template.main]: 2.68959 ms
    post-processing: 6111.224697 ms  (real: 0.235104 ms)
        - [query in jetbrains.mps.gtext.generator.baseLanguage.template.main]: 6110.989593 ms
    pre-processing: 1389.952876 ms  (real: 67.073609 ms)
        [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 1301.30992 ms  (real: 351.648703 ms)
            [type computing]: 900.932609 ms  (real: 495.355907 ms)
[type computing]: 211.131588 ms  (real: 149.09657 ms)
     - [type computing]: 48.39238 ms
     - [coerce]: 13.642638 ms
[coerce]: 181.772679 ms  (real: 178.061874 ms)
     - [coerce]: 3.710805 ms
[is subtype]: 12.672435 ms  (real: 11.872979 ms)
     - [coerce]: 0.753627 ms
     - [is subtype]: 0.045829 ms
            - [coerce]: 48.728608 ms
        - model clone: 64.553263 ms
        - [query in objectflow.generator.template.service]: 19.566629 ms
        - [query in jetbrains.mps.baseLanguageInternal.generator.template.main]: 2.002718 ms
        - recycling: 0.018696 ms
    restoring references: 491.870502 ms  (real: 153.292191 ms)
        [query in modelestic.generator.template.main]: 324.96313 ms  (real: 317.972115 ms)
            - [type computing]: 6.991015 ms
        [query in objectflow.generator.template.service]: 10.398022 ms  (real: 5.588877 ms)
            - [type computing]: 4.809145 ms
        - [query in modellwerkstatt.forms.generator.template.modelestic]: 2.648667 ms
        - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 0.429382 ms
        - [query in objectflow.generator.template.main]: 0.13911 ms
    weavings: 63.293857 ms  (real: 37.165494 ms)
        - [query in jetbrains.mps.baseLanguage.closures.generator.baseLanguage.template.main]: 26.128363 ms
    - recycling: 2.793773 ms
    - delayed mappings: 0.033733 ms
- [type computing]: 13.346105 ms
- [coerce]: 0.020408 ms

I.e.

collections.generator: 3.3 secs own time, 7.5 sec in typesystem
dates.generator: 0.2 sec own time, 9.3 in typesystem (bad)
objectflow.generator.template.javaext: 4.5 sec in typesystem
objectflow.generator.template.main: 3.3 sec in typesystem (2 in reduction rules, 1.3 in root mapping rules)
gtext post-processing: 6.1 sec (bad)

It looks like dates and collections typesystem rules could be improved (unless you have thousands of nodes). How many roots do you have in the source model? What is the size in kilobytes of the generated code?

If your model is quite big, try to split it into several smaller ones. In our practice we are trying to keep models such small that regeneration takes less than 10 seconds.

Try to turn on parallel and incremental generation (including intermediate model caching). Ensure the code of your language is synchronized. When you do that, regenerate the biggest model serveral times and check that generated code stays the same. It may differ if your generator uses internal storage concurrently or doesn't sort "unordered" lists (like model.roots or model.nodes).

Avoid using typesystem in generators when it is not required, especially in conditions.

Hi Evgeny,

thanks for your response. I have aprox. 15-20 root nodes in my model which finally generate 150 files with a total size of 500kb.

Is that too much? It does not make sense to split up the model in smaller models since the nodes in there are related ...

Dan

Try parellel and incremental generation. I think output < 1Mb is ok.