Profiler is reporting incorrect frames for nested closures

[DavyLandman]

Describe the bug

Profiler reports the top-level function even nested closures.

To Reproduce

import IO;

int () parent() {

    int child() {
        result = 0;
        for (i <- [0..1000000]) {
            result += i;
        }
        return result;
    }

    return child;
}

void main() {
    // we execute the child function explicitly outside the parent context
    println(parent()());
}

This results in the following report:

FRAMES PROFILE: 6 data points, 321 ticks, tick = 1 milliSecs
 Scope   Ticks        %  Source
parent     321   100.0%  |project://demo/Testing.rsc|(46,186,<5,0>,<16,1>)

ASTS PROFILE: 6 data points, 321 ticks, tick = 1 milliSecs
 Scope   Ticks        %  Source
 child     204    63.6%  |project://demo/Testing.rsc|(164,1,<10,22>,<10,23>)
 child      54    16.8%  |project://demo/Testing.rsc|(129,7,<9,22>,<9,29>)
 child      36    11.2%  |project://demo/Testing.rsc|(139,38,<9,32>,<11,9>)
 child      15     4.7%  |project://demo/Testing.rsc|(164,2,<10,22>,<10,24>)
 child      11     3.4%  |project://demo/Testing.rsc|(154,12,<10,12>,<10,24>)

Expected behavior The FRAMES PROFILE profile to list child as having the most ticks, not it's parent.

Additional context This bug was discovered while profiling a typepal based typechecker, which uses these nested closures a lot.

[jurgenvinju]

This is the reason:

while (env.getParent() != null && !env.getParent().isRootScope()) {
					env = env.getParent();
}

At Profiler.java#110

[jurgenvinju]

This is during a sample. The current environment is retrieved by calling into the IEvaluator API and then we pop the scope stack until we hit a first-level function (of which the parent is a root, a.k.a. module)

[jurgenvinju]

So to solve this bug we need another way to detect that the current environment is a function frame, as opposed to getParent().isRootScope()

[jurgenvinju]

Maybe Enviroment.getName() != null or something in that vain could work, assuming all the anonymous environments do not get names. Anonymous function environments get the name "Anonymous Function".

[DavyLandman]

Aah, right, thanks for diving in, I suspected you were the one that could fix this.

[jurgenvinju]

only because of the clear bug report ;-)

[jurgenvinju]

I see no other way to fix this than to reflect the function environments as an explicit class, or to add a boolean field to Environment isFunction=true. This would be a significant adaptation and scattered code changes throughout the interpreter.

For now I suggest to use the AST locations to find which function is hot; and let's leave this bug unresolved. Do you agree?

[DavyLandman]

Is it not possible to only add something specific for the function environments? so that the changes would be local?

The AST locations can hide a hot function quite well, especially when the time is spread over 10+ parts of that AST. I've always liked the frames view as it more clearly points to interesting functions to look at.

[jurgenvinju]

There is no such thing as a function environment, and there are many ways to create function frames in Rascal. So it would require a bit of a re-design or a simple hack that is spread over several locations.

[jurgenvinju]

please have a go with this and tell me where/if it breaks.