Audit kyuubi operation state change log

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">
@@ -50,6 +52,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">
@@ -72,5 +82,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>

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 = {

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())
+  }
+}

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"/>