You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@kyuubi.apache.org by ul...@apache.org on 2022/07/29 06:49:44 UTC
[incubator-kyuubi] branch master updated: [KYUUBI #3131] Improve operation state change logging
This is an automated email from the ASF dual-hosted git repository.
ulyssesyou pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-kyuubi.git
The following commit(s) were added to refs/heads/master by this push:
new 210d35673 [KYUUBI #3131] Improve operation state change logging
210d35673 is described below
commit 210d356732bae2fb102676918a1c33113c27418d
Author: ulysses-you <ul...@gmail.com>
AuthorDate: Fri Jul 29 14:49:37 2022 +0800
[KYUUBI #3131] Improve operation state change logging
### _Why are the changes needed?_
closes https://github.com/apache/incubator-kyuubi/issues/3131
- use \n to replace , in operation state change logging
- only log statement if the state is running
### _How was this patch tested?_
before:
```
2022-07-25 14:03:31.391 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing anonymous's query[183ee841-16b5-4444-a53f-3e8966e6af69]: INITIALIZED_STATE -> PENDING_STATE, statement: select 1
2022-07-25 14:03:31.410 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing anonymous's query[183ee841-16b5-4444-a53f-3e8966e6af69]: PENDING_STATE -> RUNNING_STATE, statement: select 1
2022-07-25 14:03:31.433 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing anonymous's query[183ee841-16b5-4444-a53f-3e8966e6af69]: RUNNING_STATE -> FINISHED_STATE, statement: select 1, time taken: 0.42 seconds
2022-07-25 14:03:31.446 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing anonymous's query[183ee841-16b5-4444-a53f-3e8966e6af69]: FINISHED_STATE -> CLOSED_STATE, statement: select 1
```
after:
```
2022-07-25 18:47:34.870 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing anonymous's query[c6a51097-5c38-4552-8c15-4b9466916d33]: PENDING_STATE -> RUNNING_STATE, statement:
select 1
2022-07-25 18:47:35.389 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing anonymous's query[c6a51097-5c38-4552-8c15-4b9466916d33]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.515 seconds
```
Closes #3132 from ulysses-you/improve-log.
Closes #3131
2b163c26 [ulysses-you] address comment
0c3f6b8f [ulysses-you] eliminate logging
6797f94a [ulysses-you] Improve server operation logging
Authored-by: ulysses-you <ul...@gmail.com>
Signed-off-by: ulysses-you <ul...@apache.org>
---
.../org/apache/kyuubi/operation/AbstractOperation.scala | 12 +++++++-----
1 file changed, 7 insertions(+), 5 deletions(-)
diff --git a/kyuubi-common/src/main/scala/org/apache/kyuubi/operation/AbstractOperation.scala b/kyuubi-common/src/main/scala/org/apache/kyuubi/operation/AbstractOperation.scala
index 1e68a283e..3369f318f 100644
--- a/kyuubi-common/src/main/scala/org/apache/kyuubi/operation/AbstractOperation.scala
+++ b/kyuubi-common/src/main/scala/org/apache/kyuubi/operation/AbstractOperation.scala
@@ -103,16 +103,18 @@ abstract class AbstractOperation(session: Session) extends Operation with Loggin
protected def setState(newState: OperationState): Unit = {
OperationState.validateTransition(state, newState)
- var timeCost = ""
newState match {
- case RUNNING => startTime = System.currentTimeMillis()
+ case RUNNING =>
+ info(s"Processing ${session.user}'s query[$statementId]: " +
+ s"${state.name} -> ${newState.name}, statement:\n$redactedStatement")
+ startTime = System.currentTimeMillis()
case ERROR | FINISHED | CANCELED | TIMEOUT =>
completedTime = System.currentTimeMillis()
- timeCost = s", time taken: ${(completedTime - startTime) / 1000.0} seconds"
+ val timeCost = s", time taken: ${(completedTime - startTime) / 1000.0} seconds"
+ info(s"Processing ${session.user}'s query[$statementId]: " +
+ s"${state.name} -> ${newState.name}$timeCost")
case _ =>
}
- info(s"Processing ${session.user}'s query[$statementId]: ${state.name} -> ${newState.name}," +
- s" statement: $redactedStatement$timeCost")
state = newState
lastAccessTime = System.currentTimeMillis()
}