[PROFILE] added timers for serialization/deserialization

[ExtReMLapin]

Just a demo pr for

gemma 27b wrote all of it, ref #3864 (comment)

Protocol Overhead:
- Deserialization: 0,042 ms
- Engine Execution: 7,789 ms
- Serialization: 78,219 ms
- Total Overhead: 78,262 ms
OpenCypher Query Profile
========================

Execution Time: 3,302 ms
Rows Returned: 1906

Execution Plan (Cost-Based Optimizer):
+ NodeByLabelScan(n:NER) [cost=1906.00, rows=1906]

Estimated Cost: 1906,00
Estimated Rows: 1906

[codacy-production]

Not up to standards ⛔

🔴 Issues 1 medium

Alerts:
⚠ 1 issue (≤ 0 issues of at least minor severity)

Results:
1 new issue

Category	Results
BestPractice	1 medium

View in Codacy

🟢 Metrics 966 complexity

Metric	Results
Complexity	966

View in Codacy

_{TIP This summary will be updated as you push new changes. Give us feedback}

[gemini-code-assist]

Code Review

This pull request introduces performance profiling to measure protocol overhead—specifically deserialization, engine execution, and serialization times—across the Bolt, Gremlin, gRPC, and HTTP interfaces. While the addition of these metrics is valuable for debugging, several issues were identified regarding the accuracy and implementation of the timers. Specifically, some timers measure negligible operations or are misplaced relative to the actual work being performed. Additionally, there is unused code in the Gremlin implementation and duplicated string formatting logic in the HTTP handler that should be refactored for better maintainability.

[gemini-code-assist]

This timer is misleading as it measures almost no operation (only the time between two consecutive System.nanoTime() calls). The actual deserialization of the BOLT message occurs earlier in BoltMessage.parse (line 180). Furthermore, the "map creation" mentioned in the comment happened at line 508, before this timer started. To provide accurate metrics, the start time should be captured before the message is read from the input stream in the main loop.

[gemini-code-assist]

The serializationTime variable is calculated but never used. Additionally, the timer at line 123 only measures the instantiation of IteratorResultSet, not the actual serialization of results, which happens during iteration. The empty if block and the unused variable should be removed to clean up the code.

Suggested change

	long serializationTime = System.nanoTime() - serializationStart;
	if (profileExecution && executionPlan != null) {
	// We can't easily modify the executionPlan object because it's an anonymous inner class
	// and prettyPrint is called later. But we could potentially store the times
	// and use them in the prettyPrint implementation (which we already did).
	// To include serialization time, we'd need to pass it into the anonymous class.
	}
	return result;
	return result;

[gemini-code-assist]

Setting serializationTime to a hardcoded 0 is inconsistent with the if (returnRows) branch. Even when rows are not returned, the ResultSet is still drained (lines 356-367), which involves processing overhead. Reporting exactly 0.000 ms in the profile output is misleading; the time should be measured around the loop that consumes the results.

[gemini-code-assist]

The logic for formatting the Protocol Overhead string is duplicated here and at lines 157-159. This should be refactored into a private helper method to improve maintainability and ensure consistency in the output format across different execution paths.

[lvca]

This is a great idea. I'll sue this concept to draft a commit quickly.