Incorrect calling statistics

[borysl]

I have run zorka with a single application, put tracing to file and received not quite correct data:

Object org.springframework.web.context.request.AbstractRequestAttributesScope.get(String, ObjectFactory) took over 1 second and over 65% of entire time.
However it consists of only method that took less than 18%. The method itself is very simple

@Override
public Object get(String name, ObjectFactory<?> objectFactory) {
    RequestAttributes attributes = RequestContextHolder.currentRequestAttributes();
    Object scopedObject = attributes.getAttribute(name, getScope());
    if (scopedObject == null) {
        scopedObject = objectFactory.getObject();
        attributes.setAttribute(name, scopedObject, getScope());
    }
    return scopedObject;
}

This code doesn't seem to have anything that can slow down purely to 0,8 seconds.

Also there are AOP methods, but how can I trace how much do they take?

[jitlogic]

In some circumstances it can. For example if GC pause occurs when method is executing. Tracer simply registers current time at the beginning of method, at the end of method and records difference.

Now there is another issue: sometime method execution time is bigger than sum of all registered methods called from it. There can be several causes of such behavior: some classes/methods can be excluded from tracing or automatically filtered out by tracer. Also in some circumstances tracer overflow can occur, ie. tracer will stop registering methods in order to not eat too much memory. See tracer.max.trace.records setting in zorka.properties.