ProfilerService for Langium

[ydaveluy]

Hi,

I started to implement a profiler for the parser. It is enabled by default when not in production mode.

Outputs are generated in the console after each parsing (maybe too verbose).

With DomainModel example it looks like:

┌─────────┬──────────────────────┬───────┬─────────┬───────────┐
│ (index) │ Rule                 │ Count │ Total % │ Time (ms) │
├─────────┼──────────────────────┼───────┼─────────┼───────────┤
│ 0       │ 'QualifiedName​'      │ 13    │ '22.80' │ '0.23'    │
│ 1       │ 'Entity​'             │ 5     │ '21.13' │ '0.22'    │
│ 2       │ 'Feature​'            │ 9     │ '19.80' │ '0.20'    │
│ 3       │ 'AbstractElement​'    │ 9     │ '11.07' │ '0.11'    │
│ 4       │ 'PackageDeclaration​' │ 3     │ '10.47' │ '0.11'    │
│ 5       │ 'Type​'               │ 6     │ '8.33'  │ '0.08'    │
│ 6       │ 'Domainmodel​'        │ 1     │ '4.82'  │ '0.05'    │
│ 7       │ 'DataType​'           │ 1     │ '1.58'  │ '0.02'    │
└─────────┴──────────────────────┴───────┴─────────┴───────────┘

@msujew and @cdietrich , can you give me some feedback about this functionality ?

[cdietrich]

nice. will have a look. will also try to adapt it in our codebase.
some ideas:

• move the profiler to a own service
• make the start/stop callable on the service to enable this scenario: enable profiler, parse a number of files, stop the profiler, get the aggregated report

[ydaveluy]

@cdietrich
I moved the profiler in a dedicated generic profiler service and I implemented a wrapper for the linker, validator and parser.

Below are some outputs taken from domain-model example:

Task parsing.domain-model executed in 20.00ms and ended at 2025-03-20T10:24:47.329Z
┌─────────┬───────────────────────────────────┬───────┬────────┬───────────┐
│ (index) │ Element                           │ Count │ Self % │ Time (ms) │
├─────────┼───────────────────────────────────┼───────┼────────┼───────────┤
│ 0       │ 'domain-model.Feature​'            │ 1746  │ 26.63  │ 5.33      │
│ 1       │ 'domain-model.QualifiedName​'      │ 2522  │ 20.45  │ 4.09      │
│ 2       │ 'domain-model.AbstractElement​'    │ 1746  │ 16.46  │ 3.29      │
│ 3       │ 'domain-model.Entity​'             │ 970   │ 16.45  │ 3.29      │
│ 4       │ 'domain-model.PackageDeclaration​' │ 582   │ 10.21  │ 2.04      │
│ 5       │ 'domain-model.Type​'               │ 1164  │ 6.66   │ 1.33      │
│ 6       │ 'domain-model.Domainmodel​'        │ 1     │ 1.66   │ 0.33      │
│ 7       │ 'domain-model.DataType​'           │ 194   │ 1.46   │ 0.29      │
│ 8       │ 'domain-model'                    │ 1     │ 0.02   │ 0         │
└─────────┴───────────────────────────────────┴───────┴────────┴───────────┘
Creating profiling task for 'linking.domain-model'.
Task linking.domain-model executed in 26.30ms and ended at 2025-03-20T10:24:47.362Z
┌─────────┬─────────────────────────────────┬───────┬────────┬───────────┐
│ (index) │ Element                         │ Count │ Self % │ Time (ms) │
├─────────┼─────────────────────────────────┼───────┼────────┼───────────┤
│ 0       │ 'domain-model.Feature:type'     │ 1746  │ 85.74  │ 22.55     │
│ 1       │ 'domain-model'                  │ 1     │ 12.96  │ 3.41      │
│ 2       │ 'domain-model.Entity:superType' │ 194   │ 1.3    │ 0.34      │
└─────────┴─────────────────────────────────┴───────┴────────┴───────────┘
Creating profiling task for 'validating.domain-model'.
Task validating.domain-model executed in 4.33ms and ended at 2025-03-20T10:24:47.371Z
┌─────────┬───────────────────────────────────┬───────┬────────┬───────────┐
│ (index) │ Element                           │ Count │ Self % │ Time (ms) │
├─────────┼───────────────────────────────────┼───────┼────────┼───────────┤
│ 0       │ 'domain-model'                    │ 1     │ 54.16  │ 2.34      │
│ 1       │ 'domain-model.Feature'            │ 1746  │ 18.85  │ 0.82      │
│ 2       │ 'domain-model.Entity'             │ 970   │ 17.26  │ 0.75      │
│ 3       │ 'domain-model.PackageDeclaration' │ 582   │ 6.34   │ 0.27      │
│ 4       │ 'domain-model.DataType'           │ 194   │ 3.32   │ 0.14      │
│ 5       │ 'domain-model.Domainmodel'        │ 1     │ 0.08   │ 0         │
└─────────┴───────────────────────────────────┴───────┴────────┴───────────┘

@msujew Can you have a look at the design ? There should be a very small runtime overhead when the profiler is disabled: when parsing/linking/validating a document an initial check (at root level) is done to check if the profiler is enabled or not.

[RGHenderson]

Is there any activity on this? We have found ourselves in need of a similar feature. Hopefully no one minds, I brought the branch up to date here, and toggled profiling off (with the ability to turn on via module constructor call, as well as the original start/stop). Tests seem to pass, and the profiling info is very useful!

[ydaveluy]

I've been pretty busy lately and don't have much time to revisit this topic.

You can take the lead on this topic if you'd like.

[msujew]

Superseeded by #1993.