[KYUUBI apache#6185] Audit kyuubi operation state change log

# 🔍 Description ## Issue References 🔗 We meet some issue, I want to check the operation sessionHandle and the operation timeline. I found that, it is difficult for me to check it from kyuubi log. So, In this pr, I log the operation change log into separate file. ## Describe Your Solution 🔧 Please include a summary of the change and which issue is fixed. Please also include relevant motivation and context. List any dependencies that are required for this change. ## Types of changes 🔖 - [ ] Bugfix (non-breaking change which fixes an issue) - [x] New feature (non-breaking change which adds functionality) - [ ] Breaking change (fix or feature that would cause existing functionality to change) ## Test Plan 🧪 #### Behavior Without This Pull Request ⚰️ #### Behavior With This Pull Request 🎉 #### Related Unit Tests --- # Checklist 📝 - [x] This patch was not authored or co-authored using [Generative Tooling](https://www.apache.org/legal/generative-tooling.html) **Be nice. Be informative.** Closes apache#6185 from turboFei/audit_operation. Closes apache#6185 38b0192 [Wang, Fei] op audit Lead-authored-by: Fei Wang <[email protected]> Co-authored-by: Wang, Fei <[email protected]> Signed-off-by: Cheng Pan <[email protected]>
lsm1 · Mar 22, 2024 · a99e1a2 · a99e1a2
1 parent 3b9f25b
commit a99e1a2
Show file tree

Hide file tree

Showing 4 changed files with 60 additions and 0 deletions.
diff --git a/conf/log4j2.xml.template b/conf/log4j2.xml.template
@@ -26,6 +26,8 @@
         <Property name="restAuditLogFilePattern">rest-audit-%d{yyyy-MM-dd}-%i.log</Property>
         <Property name="k8sAuditLogPath">k8s-audit.log</Property>
         <Property name="k8sAuditLogFilePattern">k8s-audit-%d{yyyy-MM-dd}-%i.log</Property>
+        <Property name="opAuditLogPath">operation-audit.log</Property>
+        <Property name="opAuditLogFilePattern">operation-audit-%d{yyyy-MM-dd}-%i.log</Property>
     </Properties>
     <Appenders>
         <Console name="stdout" target="SYSTEM_OUT">
@@ -47,6 +49,14 @@
             </Policies>
             <DefaultRolloverStrategy max="10"/>
         </RollingFile>
+        <RollingFile name="opAudit" fileName="${sys:logDir}/${sys:opAuditLogPath}"
+                     filePattern="${sys:opAuditLogFilePattern}">
+            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %p %c{1}: %m%n%ex"/>
+            <Policies>
+                <SizeBasedTriggeringPolicy size="51200KB" />
+            </Policies>
+            <DefaultRolloverStrategy max="10"/>
+        </RollingFile>
     </Appenders>
     <Loggers>
         <Root level="INFO">
@@ -69,5 +79,8 @@
         <Logger name="org.apache.kyuubi.engine.KubernetesApplicationAuditLogger" additivity="false">
             <AppenderRef ref="k8sAudit" />
         </Logger>
+        <Logger name="org.apache.kyuubi.operation.OperationAuditLogger" additivity="false">
+            <AppenderRef ref="opAudit" />
+        </Logger>
     </Loggers>
 </Configuration>
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
@@ -74,6 +74,7 @@ abstract class AbstractOperation(session: Session) extends Operation with Loggin
 
   override def getOperationLog: Option[OperationLog] = None
 
+  OperationAuditLogger.audit(this, OperationState.INITIALIZED)
   @volatile protected var state: OperationState = INITIALIZED
   @volatile protected var startTime: Long = _
   @volatile protected var completedTime: Long = _
@@ -126,6 +127,7 @@ abstract class AbstractOperation(session: Session) extends Operation with Loggin
     }
     state = newState
     lastAccessTime = System.currentTimeMillis()
+    OperationAuditLogger.audit(this, state)
   }
 
   protected def isClosedOrCanceled: Boolean = {

diff --git a/kyuubi-common/src/main/scala/org/apache/kyuubi/operation/OperationAuditLogger.scala b/kyuubi-common/src/main/scala/org/apache/kyuubi/operation/OperationAuditLogger.scala
@@ -0,0 +1,38 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License.  You may obtain a copy of the License at
+ *
+ *    http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.apache.kyuubi.operation
+
+import org.apache.kyuubi.Logging
+import org.apache.kyuubi.operation.OperationState.OperationState
+
+object OperationAuditLogger extends Logging {
+  final private val AUDIT_BUFFER = new ThreadLocal[StringBuilder]() {
+    override protected def initialValue: StringBuilder = new StringBuilder()
+  }
+
+  def audit(operation: Operation, state: OperationState): Unit = {
+    val sb = AUDIT_BUFFER.get()
+    sb.setLength(0)
+    sb.append(s"operation=${operation.getHandle.identifier}").append("\t")
+    sb.append(s"opType=${operation.getClass.getSimpleName}").append("\t")
+    sb.append(s"state=$state").append("\t")
+    sb.append(s"user=${operation.getSession.user}").append("\t")
+    sb.append(s"session=${operation.getSession.handle.identifier}")
+    info(sb.toString())
+  }
+}
diff --git a/kyuubi-server/src/test/resources/log4j2-test.xml b/kyuubi-server/src/test/resources/log4j2-test.xml
@@ -21,6 +21,7 @@
 <Configuration status="WARN">
     <Properties>
         <Property name="restAuditLogPath">target/rest-audit.log</Property>
+        <Property name="opAuditLogPath">target/operation-audit.log</Property>
     </Properties>
     <Appenders>
         <Console name="stdout" target="SYSTEM_OUT">
@@ -39,6 +40,9 @@
         <File name="restAudit" fileName="${sys:restAuditLogPath}">
             <PatternLayout pattern="%d{HH:mm:ss.SSS} %p %c{1}: %m%n%ex"/>
         </File>
+        <File name="opAudit" fileName="${sys:opAuditLogPath}">
+            <PatternLayout pattern="%d{HH:mm:ss.SSS} %p %c{1}: %m%n%ex"/>
+        </File>
     </Appenders>
     <Loggers>
         <Root level="INFO">
@@ -48,6 +52,9 @@
         <Logger name="org.apache.kyuubi.server.http.authentication.AuthenticationAuditLogger" additivity="false">
             <AppenderRef ref="restAudit" />
         </Logger>
+        <Logger name="org.apache.kyuubi.operation.OperationAuditLogger" additivity="false">
+            <AppenderRef ref="opAudit" />
+        </Logger>
         <Logger name="org.apache.kyuubi.server.metadata.jdbc" level="DEBUG" additivity="false">
             <AppenderRef ref="stdout" />
             <AppenderRef ref="file"/>