Log statement latency, fix latency calculation

[samikshya-db]

Description

• Add timed metrics latency calculator for metadata fields.
• Remove the manual latency checks
• Change System.toMillis to nano. This is because System.getTimeMillis might be incorrect. If the system clock changes here, elapsed time (despite the fact that it is only a difference) becomes inaccurate. Correct way is to do System.nanoTime
• Paved the way for capturing the operationStatus latency (Which will be raised as a followup)

Testing

• Tested locally, the metrics are being printed fine without manual logging.

2025-07-05 10:09:37 FINE com.databricks.jdbc.telemetry.latency.DatabricksMetricsTimedProcessor$TimedInvocationHandler#invoke - Method [createSession] with args [SQL Warehouse with warehouse ID {dd43ee29fedd958d}, null, default, {}] execution time: 2062ms
2025-07-05 10:09:38 FINE com.databricks.jdbc.telemetry.latency.DatabricksMetricsTimedProcessor$TimedInvocationHandler#invoke - Method [executeStatement] with args [Select 1, SQL Warehouse with warehouse ID {dd43ee29fedd958d}, {}, QUERY, DatabricksSession[compute='SQL Warehouse with warehouse ID {dd43ee29fedd958d}', schema='default', sessionID='01f05988-2869-10ab-01f0-5988286910ab'], DatabricksStatement[statementId=01f05988-289d-1c48-826d-2ee8b1e26bd9|338d529d-8272-46eb-8482-cb419466839d]] execution time: 768ms

NO_CHANGELOG=true

Additional Notes to the Reviewer

• I will be raising a follow up PR to include operationStatus latency and number of operation status calls into telemetry.
• Latency and memory overheads of metrics latency proxy :
  • Adds about 0.4% latency to connection.open (when compute is already running)
  • 1.5MB memory overhead

[jayantsing-db]

should we log if things are unexpectedly null?

[samikshya-db]

Makes sense, will add this.

[jayantsing-db]

in general, how expensive is this extra layer of proxy objects with respect to latency and memory?

[samikshya-db]

in general, how expensive is this extra layer of proxy objects with respect to latency and memory?

Good Q. I used the profiler and it consistently showed the following result :

• Adds about 0.4% latency to connection.open (when compute is already running)
• 1.5MB memory overhead

[jayantsing-db]

Adds about 0.4% latency to connection.open (when compute is already running)

this looks substantial for tail numbers and not considering network latency. is it of the order of 30-40ms? And do these proxy objects stay alive alongside objects like session, thrift-client? i guess they are not created repeatedly right?