You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@kyuubi.apache.org by fe...@apache.org on 2023/01/31 10:49:48 UTC
[kyuubi] branch master updated: [KYUUBI #4214] Trace ExecuteStatement operation exec time histogram
This is an automated email from the ASF dual-hosted git repository.
feiwang pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/kyuubi.git
The following commit(s) were added to refs/heads/master by this push:
new b0cd00fc4 [KYUUBI #4214] Trace ExecuteStatement operation exec time histogram
b0cd00fc4 is described below
commit b0cd00fc4114da41766f36657a55370d6241259a
Author: fwang12 <fw...@ebay.com>
AuthorDate: Tue Jan 31 18:49:40 2023 +0800
[KYUUBI #4214] Trace ExecuteStatement operation exec time histogram
### _Why are the changes needed?_
Trace statement exec time histogram to provide more insights.
### _How was this patch tested?_
- [x] Add some test cases that check the changes thoroughly including negative and positive cases if possible
- [ ] Add screenshots for manual tests if appropriate
- [x] [Run test](https://kyuubi.readthedocs.io/en/master/develop_tools/testing.html#running-tests) locally before make a pull request
Closes #4214 from turboFei/sql_exec.
Closes #4214
12f080597 [fwang12] remove min > 0, incase it is 0
1edd11c8c [fwang12] scale out
68ebe52d8 [fwang12] reforamt
73eb652ca [fwang12] operation.exec_time
41e7da736 [fwang12] reformat
3d071c6c8 [fwang12] docs
6c3e4abac [fwang12] ut
0b0fbd465 [fwang12] save
11bca028a [fwang12] histo
Authored-by: fwang12 <fw...@ebay.com>
Signed-off-by: fwang12 <fw...@ebay.com>
---
docs/monitor/metrics.md | 95 +++++++++++-----------
.../apache/kyuubi/metrics/MetricsConstants.scala | 1 +
.../org/apache/kyuubi/metrics/MetricsSystem.scala | 6 +-
.../apache/kyuubi/operation/ExecuteStatement.scala | 8 ++
.../operation/KyuubiOperationPerUserSuite.scala | 10 +++
5 files changed, 72 insertions(+), 48 deletions(-)
diff --git a/docs/monitor/metrics.md b/docs/monitor/metrics.md
index 5ae2b3ea7..1d1fa326a 100644
--- a/docs/monitor/metrics.md
+++ b/docs/monitor/metrics.md
@@ -40,53 +40,54 @@ The metrics system is configured via `$KYUUBI_HOME/conf/kyuubi-defaults.conf`.
These metrics include:
-| Metrics Prefix | Metrics Suffix | Type | Since | Description |
-|--------------------------------------------------|----------------------------------------|---------|-------|--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
-| `kyuubi.exec.pool.threads.alive` | | gauge | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> threads keepAlive in the backend executive thread pool</div> |
-| `kyuubi.exec.pool.threads.active` | | gauge | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> threads active in the backend executive thread pool</div> |
-| `kyuubi.connection.total` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative connection count</div> |
-| `kyuubi.connection.total` | `${sessionType}` | counter | 1.7.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative connection count with session type `${sessionType}`</div> |
-| `kyuubi.connection.opened` | | gauge | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current active connection count</div> |
-| `kyuubi.connection.opened` | `${user}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current active connections count requested by a `${user}`</div> |
-| `kyuubi.connection.opened` | `${sessionType}` | counter | 1.7.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current active connections count with session type `${sessionType}`</div> |
-| `kyuubi.connection.failed` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed connection count</div> |
-| `kyuubi.connection.failed` | `${user}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed connections for a `${user}`</div> |
-| `kyuubi.connection.failed` | `${sessionType}` | counter | 1.7.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed connection count with session type `${sessionType}`</div> |
-| `kyuubi.operation.total` | | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative opened operation count</div> |
-| `kyuubi.operation.total` | `${operationType}` | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative opened count for the operation `${operationType}`</div> |
-| `kyuubi.operation.opened` | | gauge | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current opened operation count</div> |
-| `kyuubi.operation.opened` | `${operationType}` | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current opened count for the operation `${operationType}`</div> |
-| `kyuubi.operation.failed` | `${operationType}`<br/>`.${errorType}` | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed count for the operation `${operationType}` with a particular `${errorType}`, e.g. `execute_statement.AnalysisException`</div> |
-| `kyuubi.operation.state` | `${operationState}` | meter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi operation state rate </div> |
-| `kyuubi.engine.total` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative created engines</div> |
-| `kyuubi.engine.timeout` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative timeout engines</div> |
-| `kyuubi.engine.failed` | `${user}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative explicitly failed engine count for a `${user}`</div> |
-| `kyuubi.engine.failed` | `${errorType}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative explicitly failed engine count for a particular `${errorType}`, e.g. `ClassNotFoundException`</div> |
-| `kyuubi.backend_service.open_session` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `openSession` method execution time and rate </div> |
-| `kyuubi.backend_service.close_session` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `closeSession` method execution time and rate </div> |
-| `kyuubi.backend_service.get_info` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getInfo` method execution time and rate </div> |
-| `kyuubi.backend_service.execute_statement` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `executeStatement` method execution time and rate </div> |
-| `kyuubi.backend_service.get_type_info` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getTypeInfo` method execution time and rate </div> |
-| `kyuubi.backend_service.get_catalogs` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getCatalogs` method execution time and rate </div> |
-| `kyuubi.backend_service.get_schemas` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getSchemas` method execution time and rate </div> |
-| `kyuubi.backend_service.get_tables` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getTables` method execution time and rate </div> |
-| `kyuubi.backend_service.get_table_types` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getTableTypes` method execution time and rate </div> |
-| `kyuubi.backend_service.get_columns` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getColumns` method execution time and rate </div> |
-| `kyuubi.backend_service.get_functions` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getFunctions` method execution time and rate </div> |
-| `kyuubi.backend_service.get_operation_status` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getOperationStatus` method execution time and rate </div> |
-| `kyuubi.backend_service.cancel_operation` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `cancelOperation` method execution time and rate </div> |
-| `kyuubi.backend_service.close_operation` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `closeOperation` method execution time and rate </div> |
-| `kyuubi.backend_service.get_result_set_metadata` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getResultSetMetadata` method execution time and rate </div> |
-| `kyuubi.backend_service.fetch_results` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `fetchResults` method execution time and rate </div> |
-| `kyuubi.backend_service.fetch_log_rows_rate` | | meter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `fetchResults` method that fetch log rows rate </div> |
-| `kyuubi.backend_service.fetch_result_rows_rate` | | meter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `fetchResults` method that fetch result rows rate </div> |
-| `kyuubi.backend_service.get_primary_keys` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `get_primary_keys` method execution time and rate </div> |
-| `kyuubi.backend_service.get_cross_reference` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `get_cross_reference` method execution time and rate </div> |
-| `kyuubi.operation.state` | `${operationType}`<br/>`.${state}` | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> The `${operationType}` with a particular `${state}` rate, e.g. `BatchJobSubmission.pending`, `BatchJobSubmission.finished`. Note that, the terminal states are cumulative, but the intermediate ones are not. </div> |
-| `kyuubi.metadata.request.opened` | | counter | 1.6.1 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current opened count for the metadata requests </div> |
-| `kyuubi.metadata.request.total` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> metadata requests time and rate </div> |
-| `kyuubi.metadata.request.failed` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> metadata requests failure time and rate </div> |
-| `kyuubi.metadata.request.retrying` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> retrying metadata requests time and rate, it is not cumulative </div> |
+| Metrics Prefix | Metrics Suffix | Type | Since | Description |
+|--------------------------------------------------|----------------------------------------|-----------|-------|--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
+| `kyuubi.exec.pool.threads.alive` | | gauge | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> threads keepAlive in the backend executive thread pool</div> |
+| `kyuubi.exec.pool.threads.active` | | gauge | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> threads active in the backend executive thread pool</div> |
+| `kyuubi.connection.total` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative connection count</div> |
+| `kyuubi.connection.total` | `${sessionType}` | counter | 1.7.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative connection count with session type `${sessionType}`</div> |
+| `kyuubi.connection.opened` | | gauge | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current active connection count</div> |
+| `kyuubi.connection.opened` | `${user}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current active connections count requested by a `${user}`</div> |
+| `kyuubi.connection.opened` | `${sessionType}` | counter | 1.7.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current active connections count with session type `${sessionType}`</div> |
+| `kyuubi.connection.failed` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed connection count</div> |
+| `kyuubi.connection.failed` | `${user}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed connections for a `${user}`</div> |
+| `kyuubi.connection.failed` | `${sessionType}` | counter | 1.7.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed connection count with session type `${sessionType}`</div> |
+| `kyuubi.operation.total` | | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative opened operation count</div> |
+| `kyuubi.operation.total` | `${operationType}` | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative opened count for the operation `${operationType}`</div> |
+| `kyuubi.operation.opened` | | gauge | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current opened operation count</div> |
+| `kyuubi.operation.opened` | `${operationType}` | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current opened count for the operation `${operationType}`</div> |
+| `kyuubi.operation.failed` | `${operationType}`<br/>`.${errorType}` | counter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative failed count for the operation `${operationType}` with a particular `${errorType}`, e.g. `execute_statement.AnalysisException`</div> |
+| `kyuubi.operation.state` | `${operationState}` | meter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi operation state rate </div> |
+| `kyuubi.operation.exec_time` | `${operationType}` | histogram | 1.7.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> execution time histogram for the operation `${operationType}`, now only `ExecuteStatement` is enabled. </div> |
+| `kyuubi.engine.total` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative created engines</div> |
+| `kyuubi.engine.timeout` | | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative timeout engines</div> |
+| `kyuubi.engine.failed` | `${user}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative explicitly failed engine count for a `${user}`</div> |
+| `kyuubi.engine.failed` | `${errorType}` | counter | 1.2.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> cumulative explicitly failed engine count for a particular `${errorType}`, e.g. `ClassNotFoundException`</div> |
+| `kyuubi.backend_service.open_session` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `openSession` method execution time and rate </div> |
+| `kyuubi.backend_service.close_session` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `closeSession` method execution time and rate </div> |
+| `kyuubi.backend_service.get_info` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getInfo` method execution time and rate </div> |
+| `kyuubi.backend_service.execute_statement` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `executeStatement` method execution time and rate </div> |
+| `kyuubi.backend_service.get_type_info` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getTypeInfo` method execution time and rate </div> |
+| `kyuubi.backend_service.get_catalogs` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getCatalogs` method execution time and rate </div> |
+| `kyuubi.backend_service.get_schemas` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getSchemas` method execution time and rate </div> |
+| `kyuubi.backend_service.get_tables` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getTables` method execution time and rate </div> |
+| `kyuubi.backend_service.get_table_types` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getTableTypes` method execution time and rate </div> |
+| `kyuubi.backend_service.get_columns` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getColumns` method execution time and rate </div> |
+| `kyuubi.backend_service.get_functions` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getFunctions` method execution time and rate </div> |
+| `kyuubi.backend_service.get_operation_status` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getOperationStatus` method execution time and rate </div> |
+| `kyuubi.backend_service.cancel_operation` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `cancelOperation` method execution time and rate </div> |
+| `kyuubi.backend_service.close_operation` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `closeOperation` method execution time and rate </div> |
+| `kyuubi.backend_service.get_result_set_metadata` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `getResultSetMetadata` method execution time and rate </div> |
+| `kyuubi.backend_service.fetch_results` | | timer | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `fetchResults` method execution time and rate </div> |
+| `kyuubi.backend_service.fetch_log_rows_rate` | | meter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `fetchResults` method that fetch log rows rate </div> |
+| `kyuubi.backend_service.fetch_result_rows_rate` | | meter | 1.5.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `fetchResults` method that fetch result rows rate </div> |
+| `kyuubi.backend_service.get_primary_keys` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `get_primary_keys` method execution time and rate </div> |
+| `kyuubi.backend_service.get_cross_reference` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> kyuubi backend service `get_cross_reference` method execution time and rate </div> |
+| `kyuubi.operation.state` | `${operationType}`<br/>`.${state}` | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> The `${operationType}` with a particular `${state}` rate, e.g. `BatchJobSubmission.pending`, `BatchJobSubmission.finished`. Note that, the terminal states are cumulative, but the intermediate ones are not. </div> |
+| `kyuubi.metadata.request.opened` | | counter | 1.6.1 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> current opened count for the metadata requests </div> |
+| `kyuubi.metadata.request.total` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> metadata requests time and rate </div> |
+| `kyuubi.metadata.request.failed` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> metadata requests failure time and rate </div> |
+| `kyuubi.metadata.request.retrying` | | meter | 1.6.0 | <div style='width: 150pt;word-wrap: break-word;white-space: normal'> retrying metadata requests time and rate, it is not cumulative </div> |
Before v1.5.0, if you use these metrics:
- `kyuubi.statement.total`
diff --git a/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsConstants.scala b/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsConstants.scala
index 3f967abe6..62c67266f 100644
--- a/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsConstants.scala
+++ b/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsConstants.scala
@@ -61,6 +61,7 @@ object MetricsConstants {
final val OPERATION_FAIL: String = OPERATION + "failed"
final val OPERATION_TOTAL: String = OPERATION + "total"
final val OPERATION_STATE: String = OPERATION + "state"
+ final val OPERATION_EXEC_TIME: String = OPERATION + "exec_time"
final private val BACKEND_SERVICE = KYUUBI + "backend_service."
final val BS_FETCH_LOG_ROWS_RATE = BACKEND_SERVICE + "fetch_log_rows_rate"
diff --git a/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsSystem.scala b/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsSystem.scala
index 2507eb773..99da1f1b0 100644
--- a/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsSystem.scala
+++ b/kyuubi-metrics/src/main/scala/org/apache/kyuubi/metrics/MetricsSystem.scala
@@ -20,7 +20,7 @@ package org.apache.kyuubi.metrics
import java.lang.management.ManagementFactory
import java.util.concurrent.TimeUnit
-import com.codahale.metrics.{Gauge, MetricRegistry}
+import com.codahale.metrics.{Gauge, MetricRegistry, Snapshot}
import com.codahale.metrics.jvm._
import org.apache.kyuubi.config.KyuubiConf
@@ -121,4 +121,8 @@ object MetricsSystem {
def meterValue(name: String): Option[Long] = {
maybeSystem.map(_.registry.meter(name).getCount)
}
+
+ def histogramSnapshot(name: String): Option[Snapshot] = {
+ maybeSystem.map(_.registry.histogram(name).getSnapshot)
+ }
}
diff --git a/kyuubi-server/src/main/scala/org/apache/kyuubi/operation/ExecuteStatement.scala b/kyuubi-server/src/main/scala/org/apache/kyuubi/operation/ExecuteStatement.scala
index 4e818355e..b09c2b174 100644
--- a/kyuubi-server/src/main/scala/org/apache/kyuubi/operation/ExecuteStatement.scala
+++ b/kyuubi-server/src/main/scala/org/apache/kyuubi/operation/ExecuteStatement.scala
@@ -19,11 +19,13 @@ package org.apache.kyuubi.operation
import scala.collection.JavaConverters._
+import com.codahale.metrics.MetricRegistry
import org.apache.hive.service.rpc.thrift.{TGetOperationStatusResp, TOperationState, TProtocolVersion}
import org.apache.hive.service.rpc.thrift.TOperationState._
import org.apache.kyuubi.KyuubiSQLException
import org.apache.kyuubi.config.KyuubiConf
+import org.apache.kyuubi.metrics.{MetricsConstants, MetricsSystem}
import org.apache.kyuubi.operation.FetchOrientation.FETCH_NEXT
import org.apache.kyuubi.operation.log.OperationLog
import org.apache.kyuubi.session.Session
@@ -131,6 +133,12 @@ class ExecuteStatement(
}
sendCredentialsIfNeeded()
}
+ MetricsSystem.tracing { ms =>
+ val execTime = System.currentTimeMillis() - startTime
+ ms.updateHistogram(
+ MetricRegistry.name(MetricsConstants.OPERATION_EXEC_TIME, opType),
+ execTime)
+ }
// see if anymore log could be fetched
fetchQueryLog()
} catch onError()
diff --git a/kyuubi-server/src/test/scala/org/apache/kyuubi/operation/KyuubiOperationPerUserSuite.scala b/kyuubi-server/src/test/scala/org/apache/kyuubi/operation/KyuubiOperationPerUserSuite.scala
index 2a8ca3a02..5e4796a87 100644
--- a/kyuubi-server/src/test/scala/org/apache/kyuubi/operation/KyuubiOperationPerUserSuite.scala
+++ b/kyuubi-server/src/test/scala/org/apache/kyuubi/operation/KyuubiOperationPerUserSuite.scala
@@ -349,4 +349,14 @@ class KyuubiOperationPerUserSuite
assert(MetricsSystem.meterValue(closedMetric).getOrElse(0L) > closedCount)
}
}
+
+ test("trace ExecuteStatement exec time histogram") {
+ withJdbcStatement() { statement =>
+ statement.executeQuery("select engine_name()")
+ }
+ val metric =
+ s"${MetricsConstants.OPERATION_EXEC_TIME}.${classOf[ExecuteStatement].getSimpleName}"
+ val snapshot = MetricsSystem.histogramSnapshot(metric).get
+ assert(snapshot.getMax > 0 && snapshot.getMedian > 0)
+ }
}