Adding timing function and fixes for logging the viz timings by jdunkerley · Pull Request #14827 · enso-org/enso

jdunkerley · 2026-03-03T13:17:35Z

Pull Request Description

Enhancing the existing visualization and widget profiling functionality. Allowing for a more full diagnostic of execution of a complex workflow.

Added Profile.time_execution as a single API for profiling functions onto Duration.time_execution.
Improved the logging format for the viz and widget timing messages so truncated entries to avoid the massive log messages.
Moved the existing SQL and Viz profiling to use the new API.
- New environment variables: ENSO_PROFILE_VIZZES, ENSO_PROFILE_SQL.
- Simplified old ENSO_SQL_LOG_PATH to still log the SQL but with a new timestamp.
Added profiling to Table functions controlled by ENSO_PROFILE_TABLE.
Fix for subseconds in table viz.
Fix for length error in Column default viz.

Checklist

Please ensure that the following checklist has been satisfied before submitting the PR:

The documentation has been updated, if necessary.
Screenshots/screencasts have been attached, if there are any visual changes. For interactive or animated visual changes, a screencast is preferred.
All code follows the
Scala,
Java,
TypeScript,
and
Rust
style guides. In case you are using a language not listed above, follow the Rust style guide.
Unit tests have been written where possible.
If meaningful changes were made to logic or tests affecting Enso Cloud integration in the libraries,
or the Snowflake database integration, a run of the Extra Tests has been scheduled.
- If applicable, it is suggested to paste a link to a successful run of the Extra Tests.

JaroslavTulach

Pull Request Description

Added Duration.log_execution_time.

Why do we need Duration.log_execution_time? I am asking as I don't understand motivation for this change.

Probably an important question to start with: Who will consume these logged messages?

I'd prefer if visualization logging would require less changes in Standard.Base. I may not get the motivation right, but seems to me that even the log_execution_time shouldn't be in Duration - it is not an essential method of Duration - shouldn't it be in some Profiling API?

To finish my heresy: Why should every visualization be forced to think about log_execution_time? Shouldn't it be a responsibility of those who invoke the visualization to do some performance measurement and some logging automatically?

Again, this last question probably demonstrates I don't have a slight idea why this change is needed...

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso

…ations.

Added `Profile` to `Logging`.

Use ENSO_PROFILE_SQL to get timing now.

Use ENSO_PROFILE_SQL to get timing now. Docs

Fixes. Bug fix for Nanoseconds in Table viz.

jdunkerley · 2026-03-04T17:00:25Z

Viz logs:

Table logs:

jdunkerley · 2026-03-04T18:25:32Z

SQL logging:

JaroslavTulach · 2026-03-05T06:26:00Z

distribution/lib/Standard/Visualization/0.0.0-dev/src/Helpers.enso

+   private: true
+   ---
+   Truncated display text for logging
+private short_display value = if value.is_error then "<ERROR>" else


This is yet another variant in addition to to_text, to_display_text, pretty. Can't we just redefine to_display_text (for example) instead?

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso

JaroslavTulach · 2026-03-05T06:37:51Z

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso

+   Should be control by an environment variable set to the log level:
+   - `ENSO_PROFILE_VIZZES` - for visualizations.
+   - `ENSO_PROFILE_SQL` - for SQL queries.
+   - `ENSO_PROFILE_TABLE` - for table function calls.


It is weird that a generic utility for profiling references SQL, Table, vizzes... but so far I know no better way...

JaroslavTulach · 2026-03-05T06:44:51Z

distribution/lib/Standard/Database/0.0.0-dev/src/Internal/JDBC_Connection.enso

+            # E.g. [Start] [End] [SQLite] SELECT * FROM "test"
+            padded_query = make_label.pad 100
+            log_line = "[" + start + "] [" + Date_Time.now.to_text + "] " + padded_query + '\n'
+            Context.Output.with_enabled <|


I don't like this manipulation with files in the profiled code at all!

what's the use case? Is it:

when Enso is launched with some special variable, then a dedicated file with profiling info for particular area of code is created?

if so, then I'd suggest to enhance the logging framework in the enso launcher itself to recognize such setting and act accordingly

something like:

$ ENSO_LOG_PROFILING=Standard.Table.Sql ./enso ... $ cat ~/.local/share/enso/logs/profiling-Standard.Table.Sql.log

You're correct, shouldn't have been in the profile time - have amended that.
The old SQL log function is used in a test and has been useful for diagnostics of DB work.

Removed from the profile, but leaving the old functionality as I don't want to rewrite the test at the moment.

JaroslavTulach · 2026-03-05T06:49:45Z

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso

+
+            duration = pair.first
+            suffix = if suffix_callback == Nothing then "" else suffix_callback pair.second
+            module.log_message ("Execution time for " + label + ": " + duration.to_text + suffix) level


I am puzzled: Why do we log here when the client code is also writing down files with similar messages by itself?

either the Profiling is inherently associated with Logging and then the client code shall not do any further processing of logged messages

or Profiling just measures time and then it should be disassociated form Logging completely and just measure time

jdunkerley requested review from 4e6, AdRiley and JaroslavTulach as code owners March 3, 2026 13:17

github-actions bot added the -libs-API-change-Base Marks a PR that changes the public API of Standard.Base label Mar 3, 2026

JaroslavTulach reviewed Mar 3, 2026

View reviewed changes

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso Outdated Show resolved Hide resolved

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso Outdated Show resolved Hide resolved

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso Outdated Show resolved Hide resolved

jdunkerley added 7 commits March 3, 2026 21:16

Add Duration.log_execution_time.

f94cc38

Add short_display to truncate entries in the log when timing visualiz…

649a185

…ations.

Docs and fix a mistake.

8969061

Tie Duration.log_execution_time into the viz timing code.

908ea35

Add timing into Table.enso.

5c22bf5

Merge viz and table to use a common profile approach.

ba8e33f

Added `Profile` to `Logging`.

Simplify the ENSO_SQL_LOG_PATH to just log the SQL.

109f06f

Use ENSO_PROFILE_SQL to get timing now.

jdunkerley force-pushed the wip/jd/time-table-fns branch from 63f0289 to 109f06f Compare March 4, 2026 12:06

jdunkerley added 5 commits March 4, 2026 12:45

Simplify the ENSO_SQL_LOG_PATH to just log the SQL.

3412ac7

Use ENSO_PROFILE_SQL to get timing now. Docs

Changelog.

e4b6805

Fix.

47992b1

Fix for Column.to_default_visualization_data.

8378d7a

Push Java version up for debugging.

d2764e3

Fixes. Bug fix for Nanoseconds in Table viz.

Fix for viz of an error.

98b445b

jdunkerley added 2 commits March 4, 2026 19:33

Fix for maintenance action.

b358628

Missing +

e4acd40

JaroslavTulach reviewed Mar 5, 2026

View reviewed changes

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso Show resolved Hide resolved

JaroslavTulach reviewed Mar 5, 2026

View reviewed changes

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso Outdated Show resolved Hide resolved

JaroslavTulach reviewed Mar 5, 2026

View reviewed changes

distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso Outdated Show resolved Hide resolved

JaroslavTulach reviewed Mar 5, 2026

View reviewed changes

jdunkerley added 2 commits March 5, 2026 09:00

Some PR comments.

158ea52

Tidy up old SQL logging API code.

965332d

AdRiley approved these changes Mar 5, 2026

View reviewed changes

jdunkerley added the CI: Ready to merge This PR is eligible for automatic merge label Mar 5, 2026

mergify bot merged commit 1a27616 into develop Mar 5, 2026
96 of 98 checks passed

mergify bot deleted the wip/jd/time-table-fns branch March 5, 2026 19:28

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Adding timing function and fixes for logging the viz timings#14827

Adding timing function and fixes for logging the viz timings#14827
mergify[bot] merged 17 commits intodevelopfrom
wip/jd/time-table-fns

jdunkerley commented Mar 3, 2026 •

edited

Loading

Uh oh!

JaroslavTulach left a comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

jdunkerley commented Mar 4, 2026

Uh oh!

jdunkerley commented Mar 4, 2026

Uh oh!

JaroslavTulach Mar 5, 2026

Uh oh!

Uh oh!

Uh oh!

Uh oh!

JaroslavTulach Mar 5, 2026

Uh oh!

JaroslavTulach Mar 5, 2026

Uh oh!

jdunkerley Mar 5, 2026

Uh oh!

JaroslavTulach Mar 5, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Conversation

jdunkerley commented Mar 3, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Pull Request Description

Checklist

Uh oh!

JaroslavTulach left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

jdunkerley commented Mar 4, 2026

Uh oh!

jdunkerley commented Mar 4, 2026

Uh oh!

JaroslavTulach Mar 5, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

JaroslavTulach Mar 5, 2026

Choose a reason for hiding this comment

Uh oh!

JaroslavTulach Mar 5, 2026

Choose a reason for hiding this comment

Uh oh!

jdunkerley Mar 5, 2026

Choose a reason for hiding this comment

Uh oh!

JaroslavTulach Mar 5, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

jdunkerley commented Mar 3, 2026 •

edited

Loading