Profiler tweaks for JSON serialisation #4068

dondonz · 2025-07-30T22:14:40Z

We're putting the finishing touches on the Profiler. We expect users will use the Profiler to sample logs and we're giving that a try ourselves.

ExecutionId is better cast to a string for the output map, otherwise a logger can complain it doesn't know how to serialise this type to JSON

Also changing some formatted strings into map values that's easier to parse and analyse later

github-actions · 2025-07-30T22:28:47Z

Test Results

322 files 322 suites 3m 24s ⏱️
5 003 tests 4 997 ✅ 6 💤 0 ❌
5 092 runs 5 086 ✅ 6 💤 0 ❌

Results for commit 0f22f07.

♻️ This comment has been updated with latest results.

…in order

dondonz · 2025-07-31T06:20:36Z

src/main/java/graphql/ProfilerResult.java

        result.put("operation", operationType + ":" + operationName);
        result.put("startTime", startTime);
        result.put("endTime", endTime);
-        result.put("totalRunTime", (endTime - startTime) + "(" + (endTime - startTime) / 1_000_000 + "ms)");
-        result.put("engineTotalRunningTime", engineTotalRunningTime + "(" + engineTotalRunningTime / 1_000_000 + "ms)");


Change to nanoseconds only, if need be someone can convert to ms later

Remove string concatenation to make it easier to read

src/main/java/graphql/ProfilerResult.java

andimarek

See comments.

andimarek · 2025-07-31T09:53:13Z

src/main/java/graphql/ProfilerResult.java

@@ -273,12 +273,12 @@ public List<String> getInstrumentationClasses() {

    public Map<String, Object> shortSummaryMap() {
        Map<String, Object> result = new LinkedHashMap<>();
-        result.put("executionId", Assert.assertNotNull(executionId));
+        result.put("executionId", Assert.assertNotNull(executionId).toString());
        result.put("operation", operationType + ":" + operationName);
        result.put("startTime", startTime);


actually we should suffix startTime and endTime also with Ns to be clear here

andimarek · 2025-07-31T09:54:13Z

src/main/java/graphql/ProfilerResult.java

@@ -273,12 +273,12 @@ public List<String> getInstrumentationClasses() {

    public Map<String, Object> shortSummaryMap() {
        Map<String, Object> result = new LinkedHashMap<>();
-        result.put("executionId", Assert.assertNotNull(executionId));
+        result.put("executionId", Assert.assertNotNull(executionId).toString());
        result.put("operation", operationType + ":" + operationName);


should that be two fields? operation Type and operation name? or one Map inside "operation"?

Two fields are better, and better to be clearer on operation name vs type.

I see what you meant, should they be nested or not

We've done both: nesting some information, but keeping all the timing information at the top level. I think operation name is one of the most important keys and I'd like to have that at the top level.

dondonz · 2025-07-31T21:50:05Z

src/test/groovy/graphql/ProfilerTest.groovy


-        ExecutionInput ei = ExecutionInput.newExecutionInput()
+        ExecutionInput ei = newExecutionInput()


This doesn't change anything, only IDE complaints

dondonz · 2025-07-31T21:50:21Z

src/test/groovy/graphql/ProfilerTest.groovy

+        profilerResult.shortSummaryMap().get("dataFetcherResultTypes") == ["COMPLETABLE_FUTURE_COMPLETED"    : ["count":2, "invocations":4],
+                                                                           "COMPLETABLE_FUTURE_NOT_COMPLETED": ["count":2, "invocations":2],
+                                                                           "MATERIALIZED"                    : ["count":2, "invocations":4]]
+        profilerResult.shortSummaryMap().get("executionId") == "myExecutionId"


This is the only real test change

dondonz · 2025-07-31T22:03:16Z

src/main/java/graphql/ProfilerResult.java

-        result.put("endTime", endTime);
-        result.put("totalRunTime", (endTime - startTime) + "(" + (endTime - startTime) / 1_000_000 + "ms)");
-        result.put("engineTotalRunningTime", engineTotalRunningTime + "(" + engineTotalRunningTime / 1_000_000 + "ms)");
+        result.put("executionId", Assert.assertNotNull(executionId).toString());


Cast to string to serialise in JSON logs

Cast execution ID to string to make this easier to log

b69dd6b

Add test to for ExecutionId cast to string in profiler output

5de46cd

dondonz changed the title ~~WIP Profiler tweaks~~ Profiler tweaks for JSON serialisation Jul 31, 2025

andimarek-atlassian approved these changes Jul 31, 2025

View reviewed changes

More formatting updates and remove Map.of which is not deterministic …

eb90338

…in order

dondonz commented Jul 31, 2025

View reviewed changes

src/main/java/graphql/ProfilerResult.java Show resolved Hide resolved

dondonz added 2 commits July 31, 2025 17:22

Use a helper method instead

fde7f50

Update test and IDE warnings

1c76bec

andimarek approved these changes Jul 31, 2025

View reviewed changes

andimarek requested changes Jul 31, 2025

View reviewed changes

dondonz added 2 commits August 1, 2025 07:26

Add a few more tweaks and remove concatenation on operation name

7c5e387

Add assert

0f22f07

dondonz commented Jul 31, 2025

View reviewed changes

andimarek approved these changes Jul 31, 2025

View reviewed changes

dondonz merged commit d61c53a into master Jul 31, 2025
2 checks passed

dondonz added this to the 25.x breaking changes milestone Aug 2, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Profiler tweaks for JSON serialisation #4068

Profiler tweaks for JSON serialisation #4068

Uh oh!

dondonz commented Jul 30, 2025 •

edited

Loading

Uh oh!

github-actions bot commented Jul 30, 2025 •

edited

Loading

Uh oh!

dondonz Jul 31, 2025 •

edited

Loading

Uh oh!

Uh oh!

andimarek left a comment

Uh oh!

andimarek Jul 31, 2025

Uh oh!

andimarek Jul 31, 2025

Uh oh!

dondonz Jul 31, 2025

Uh oh!

dondonz Jul 31, 2025

Uh oh!

dondonz Jul 31, 2025

Uh oh!

dondonz Jul 31, 2025

Uh oh!

dondonz Jul 31, 2025

Uh oh!

Uh oh!

Uh oh!


		ExecutionInput ei = ExecutionInput.newExecutionInput()
		ExecutionInput ei = newExecutionInput()

Profiler tweaks for JSON serialisation #4068

Profiler tweaks for JSON serialisation #4068

Uh oh!

Conversation

dondonz commented Jul 30, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

github-actions bot commented Jul 30, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Test Results

Uh oh!

dondonz Jul 31, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

andimarek left a comment

Choose a reason for hiding this comment

Uh oh!

andimarek Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

andimarek Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

dondonz Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

dondonz Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

dondonz Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

dondonz Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

dondonz Jul 31, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

dondonz commented Jul 30, 2025 •

edited

Loading

github-actions bot commented Jul 30, 2025 •

edited

Loading

dondonz Jul 31, 2025 •

edited

Loading