New trace mechanism by vincent-botbol · Pull Request #1069 · CatalaLang/catala

vincent-botbol · 2026-06-25T10:02:00Z

This PR replaces the existing logging mechanism with a trace-like mechanism that outputs metadata for important program execution points.
The existing logging displayed scope calls, scope variables definitions, exceptions. We augment those with local bindings, conditionals pathing, function calls, and more. The trace is also organized as a tree so that we have a good idea of the callstacks.

For now, traces are supported by the OCaml and java backend but are disabled in python. Traces outputs in backends are only available as JSON objects. Although, it is still possible to access them through the API.
The "user-friendly" output is still available through the interpreter when --trace-format human (default) is specified.
The new output may be observed in the cram tests diffs.

We also plugged a --trace option in clerk run.

JSON trace outputs generated by the interpreter and backends aim to be equivalent but, in some specific cases, it will not be. E.g., functions in java are not represented as values and, hence, are not displayed ("<function>"), the OCaml or operator is still lazy compared to the "official" semantics that the other backends follows.

P.S. Sorry for the huge commit, the original git history was not salvageable.

Edit:

Catala-examples (hotfix) PR Temporarily disable java for aides-logements catala-examples#52 : generated java code with traces is too large.

Checklist

Update the CHANGELOG.md

If this PR adds a feature or has breaking changes

Complete or update the documentation for the feature on the Catala book at https://github.com/CatalaLang/catala-book.
- The corresponding PR is:
Update the Catala language server in case of breaking changes at https://github.com/CatalaLang/catala-language-server
- The corresponding PR is: New trace mechanism catala-language-server#241

denismerigoux

Congratulations Vincent, this is a major piece of work and very well-done!

denismerigoux · 2026-06-29T07:40:13Z

+let tag_to_runtime = function
+  | ScopeCall scope_name ->
+    let name = ScopeName.original_base scope_name in
+    let _, decl_pos = ScopeName.get_info scope_name in
+    Runtime.ScopeCall { name; decl_pos = Expr.pos_to_runtime decl_pos }
+  | ScopeVarDef { var; io } ->
+    let name = ScopeVar.to_string var in
+    let _, decl_pos = ScopeVar.get_info var in
+    Runtime.ScopeVarDef
+      { var = { name; decl_pos = Expr.pos_to_runtime decl_pos }; io }
+  | LocalVarDef { name } -> Runtime.LocalVarDef name
+  | LocalTupDef { names } -> Runtime.LocalTupDef names
+  | FunCall topdef ->
+    let name = TopdefName.original_base topdef in
+    let _, decl_pos = TopdefName.get_info topdef in
+    Runtime.FunCall { name; decl_pos = Expr.pos_to_runtime decl_pos }
+  | BranchingCondition -> BranchingCondition
+  | Branching None -> IfBranching
+  | Branching (Some constructor_name) -> MatchBranching { constructor_name }
+  | Exception { label; cons_pos } ->
+    let label =
+      match label with
+      | None -> None
+      | Some (l, p) -> Some (l, Expr.pos_to_runtime p)
+    in
+    Exception { label; cons_pos = Expr.pos_to_runtime cons_pos }
+  | Assertion -> Assertion
+


Is there a strong reason for the tags in Runtime to not be exactly the same as the tags in Definitions?

I wanted to keep track of the UIds so that the renaming traversal could also handle these. I'm not sure it's currently mandatory but I thought it would be more resilient this way.

AltGr

This is great, thanks! 👏🏿

AltGr · 2026-07-06T07:41:34Z

+    let cond = translate_expr ctx cond in
+    let etrue = translate_expr ctx etrue in
+    let efalse = translate_expr ctx efalse in
+    Expr.eifthenelse cond etrue efalse m


How is this different from the base case Expr.map ~f:(translate_expr ctx) ~op:Operator.translate (e, m) ?

The difference is 5 extra-lines :) Fixed up.

AltGr · 2026-07-06T07:56:52Z

+        match io.io_input with
+        | Runtime.NoInput -> "NoInput"
+        | Runtime.OnlyInput -> "OnlyInput"
+        | Runtime.Reentrant -> "Reentrant"


Maybe reuse Catala_runtime.Json.io_input ?
(it takes a Buffer.t but there already is a str wrapper for most of its siblings)

I removed this function altogether. Also, I tried to enforce snake case in the JSON so that won't do it.

AltGr · 2026-07-06T08:08:11Z

      typ : typ;
      io : Desugared.Ast.io;
-      e : 'm expr;
+      e : 'm expr; (* sub_scope_var: *)


Oops, some refactoring artifact got in there. I'll remove it.

AltGr · 2026-07-06T08:43:17Z

+    | Error (error, locs, message) as e
+    when trace_context.exception_handled = false
+    ->
+      trace_context.exception_handled <- true;


Maybe try to preserve the backtrace ?

I tried, I swear. But this wouldn't give a proper backtrace. I suspected weird intertwining with clerk with in the end I couldn't understand what happened. I didn't dig much more into it. Do you want me to get back at it ?

No need to stall the whole PR, we'll have a look later on if needed.

AltGr · 2026-07-06T08:48:52Z

-(** {3:instruments Logging instruments} *)
+    It also catches runtime's [error]s and insert a [single_trace] before
+    re-raising it. When it occurs, a flag is also set so that callers do not
+    catch it again. *)


I might expect this to return 'a * trace ; maybe at least make it clear that retrieve_trace can be called afterwards ?

Why would you expect that? The previous traces constructors all return unit, why would this one give you a trace ? Also, the val retrieve_trace : unit -> trace function is two lines below.
We could change the name from with_trace to wrap_trace or something if you'd prefer. I agree that it's not necessarily the best naming.

AltGr · 2026-07-06T08:58:33Z

+  let default
+      ~code_coverage
+      ~(trace : [ `FileName of Catala_utils.Global.raw_file | `Stdout ] option)
+      ~(trace_format : Catala_utils.Global.format_enum option)


I wish these two could be gathered in a single record (but that's in Catala CLI, outside of the scope of this PR).

Co-authored-by: Louis Gesbert <louis.gesbert@inria.fr>

github-project-automation Bot added this to Catala - language & tooling Jun 25, 2026

vincent-botbol self-assigned this Jun 25, 2026

vincent-botbol added ✨ enhancement New feature or request 🔧 compiler Issue concerns the compiler 🔚 backends Backend runtime or code generation labels Jun 25, 2026

vincent-botbol mentioned this pull request Jun 25, 2026

New trace mechanism CatalaLang/catala-language-server#241

Merged

denismerigoux moved this to In Progress in Catala - language & tooling Jun 29, 2026

denismerigoux approved these changes Jun 29, 2026

View reviewed changes

vincent-botbol added 5 commits June 29, 2026 16:16

Fix make usage message

8ec6b44

Add clerk run --trace option

65b7b33

Remove legacy logging from python runtime

b11ae3d

Add trace support in java runtime

8510410

Enable trace in java, disable in python

6ccc4a6

AltGr force-pushed the trace-everything branch from 68e0997 to 37268b1 Compare June 29, 2026 14:16

vincent-botbol force-pushed the trace-everything branch 2 times, most recently from 1329df9 to 192d7e0 Compare June 30, 2026 08:52

vincent-botbol added 4 commits June 30, 2026 10:55

Replace legacy logging with new traces

3d1114b

Add trace tests and reset existing test outputs

d238bea

Add changelog entry

ea63342

Extend OCaml runtime trace documentation

868730b

vincent-botbol force-pushed the trace-everything branch 2 times, most recently from 7b74d63 to 868730b Compare June 30, 2026 08:58

vincent-botbol mentioned this pull request Jun 30, 2026

Temporarily disable java for aides-logements CatalaLang/catala-examples#52

Merged

vincent-botbol added 2 commits June 30, 2026 15:05

Fix interpretation regression

a1fb83a

Fix trace file output path rewriting issues

b5c1a63

AltGr approved these changes Jul 6, 2026

View reviewed changes

vincent-botbol force-pushed the trace-everything branch 2 times, most recently from c3fb257 to f4797c3 Compare July 6, 2026 12:18

Integrate review's remarks

357dfef

Co-authored-by: Louis Gesbert <louis.gesbert@inria.fr>

vincent-botbol force-pushed the trace-everything branch from f4797c3 to 357dfef Compare July 6, 2026 13:45

denismerigoux merged commit 682c1f7 into master Jul 6, 2026
1 check passed

denismerigoux deleted the trace-everything branch July 6, 2026 14:49

github-project-automation Bot moved this from In Progress to Done in Catala - language & tooling Jul 6, 2026

Uh oh!

Conversation

vincent-botbol commented Jun 25, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Checklist

If this PR adds a feature or has breaking changes

Uh oh!

denismerigoux left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

AltGr left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

vincent-botbol commented Jun 25, 2026 •

edited

Loading