How do I see how many times code was called and how long it took?

← Code Quality · Ref: Q322

EK9 has built-in profiling. Append 'p' to any test flag to enable profiling data collection.

ENABLING PROFILING

  ek9 -tp myproject.ek9     Coverage summary, then the top functions by self-time.
  ek9 -t2p myproject.ek9    Profiling JSON in .ek9/coverage.json (for AI and CI tools).

Profiling is reported with the coverage results, so 'p' implies -tC.

  ek9 -t6p myproject.ek9    HTML dashboard with flame graph.

METRICS COLLECTED

For each function and method:
- Call count: how many times it was invoked.
- Total time: wall-clock time including callees.
- Self time: time spent in this function only, excluding callees.
- Average time per call.
- Minimum and maximum call times.
- Percentiles: p50, p95, p99 for latency distribution.

FLAME GRAPH (-t6p)
The HTML dashboard includes an interactive flame graph. Each frame represents a function. Width represents total time.
- Wide red frames: high self-time. These are the functions doing the most work. Optimise these first.
- Wide blue frames: orchestrators that call many other functions. High total time but low self-time. Optimising these means restructuring call patterns.
- Narrow frames: rarely called or fast functions. Usually not worth optimising.

HOT FUNCTION TABLE

Below the flame graph, a sorted table lists functions by self-time. The top entries are your optimisation targets. Each entry links to the source view.

JSON OUTPUT FOR CI

The -t2p flag writes .ek9/test-results.json and .ek9/coverage.json; the 'profiling' section of coverage.json is suitable for automated analysis:
- CI pipelines can fail builds if p99 latency exceeds thresholds.
- AI assistants can read JSON profiling data to suggest optimisations.
- Trend analysis tools can track performance over time.

See Q321 for the quality report dashboard. See Q157 for running tests. See Q252 for compiler flags. See Q207 for test output formats. See Q246 for debugging strategies. See Q627 for profiling deep dive. See Q629 for reading flame graphs. See Q630 for identifying hot methods. See Q631 for benchmarking approaches.
See Q694 for named arguments pattern. See Q696 for complexity within limits.
See Q728 for nesting depth boundary. See Q733 for combined complexity boundary.

Example

defines module qa.codequality.profiling

  defines function

    <?-
      Functions that would show different profiling characteristics.
      A frequently called helper vs a one-time orchestrator.
    -?>
    fibonacci() as pure
      -> position as Integer
      <- rtn as Integer: 0

      firstBase <- 0
      secondBase <- 1
      thresholdForRecursion <- 2
      if position == firstBase
        rtn: firstBase
      else if position == secondBase
        rtn: secondBase
      else if position >= thresholdForRecursion
        previousValue <- fibonacci(position - 1)
        beforePrevious <- fibonacci(position - 2)
        rtn: previousValue + beforePrevious

    formatResult() as pure
      ->
        label as String
        number as Integer
      <-
        rtn as String: `${label}: ${number}`

  defines program

    ProfilingDemo()
      stdout <- Stdout()

      targetPosition <- 10
      result <- fibonacci(targetPosition)
      output <- formatResult("Fibonacci", result)
      stdout.println(output)

Common mistakes

E11064 — The literal 2 in a comparison is a magic literal. Extract it into a named constant such as thresholdForRecursion. The literals 0 and 1 are exempt (as are -1, 0.0 and 1.0), so firstBase and secondBase are for readability only. See ek9 -h E11064 for details.

Incorrect:

if position == firstBase
        rtn: firstBase
      else if position == secondBase
        rtn: secondBase
      else if position >= 2

Correct:

thresholdForRecursion <- 2
      if position == firstBase
        rtn: firstBase
      else if position == secondBase
        rtn: secondBase
      else if position >= thresholdForRecursion

E50001 — Removing the variable declaration means later references to the variable become unresolved, triggering E50001. See ek9 -h E50001 for details.

Incorrect:

fibonacci(targetPosition)
      output <- formatResult("Fibonacci", result)

Correct:

result <- fibonacci(targetPosition)
      output <- formatResult("Fibonacci", result)

Coming from another language?

Java: JMH for microbenchmarks, async-profiler or JFR for profiling (all external tools). Python: cProfile, line_profiler, py-spy (all external). Rust: perf, flamegraph crate, criterion for benchmarks (all external). Go: go tool pprof built-in with -cpuprofile flag. JavaScript: Chrome DevTools profiler. EK9: append 'p' to any test flag for built-in profiling, flame graph in HTML dashboard, JSON output for AI/CI integration.

Keywords: call, quality, total, bottleneck, profiling, profile, p95, self, graph, count, p99, clean-code, performance, metric, time, flame