[KYUUBI #3951] Support to audit the authentication http request

### _Why are the changes needed?_ Support to audit the http request. ``` 08:10:43.231 INFO AuthenticationAuditLogger: user=fwang12(auth:BASIC) ip=192.168.3.159 proxyIp=null method=GET uri=/api/v1/sessions/count protocol=HTTP/1.1 status=200 08:10:43.265 INFO AuthenticationAuditLogger: user=null(auth:BASIC) ip=192.168.3.159 proxyIp=null method=GET uri=/api/v1/sessions/count protocol=HTTP/1.1 status=403 08:10:43.273 INFO AuthenticationAuditLogger: user=null(auth:null) ip=192.168.3.159 proxyIp=null method=GET uri=/api/v1/sessions/count protocol=HTTP/1.1 status=401 08:10:43.320 INFO AuthenticationAuditLogger: user=client(auth:NEGOTIATE) ip=192.168.3.159 proxyIp=null method=GET uri=/api/v1/sessions/count protocol=HTTP/1.1 status=200 08:10:43.324 INFO AuthenticationAuditLogger: user=null(auth:NEGOTIATE) ip=192.168.3.159 proxyIp=null method=GET uri=/api/v1/sessions/count protocol=HTTP/1.1 status=403 08:10:43.331 INFO AuthenticationAuditLogger: user=null(auth:null) ip=192.168.3.159 proxyIp=null method=GET uri=/api/v1/sessions/count protocol=HTTP/1.1 status=401 08:10:47.940 INFO AuthenticationAuditLogger: user=client(auth:NEGOTIATE) ip=192.168.3.159 proxyIp=null method=POST uri=/api/v1/sessions protocol=HTTP/1.1 status=200 08:10:47.999 INFO AuthenticationAuditLogger: user=client(auth:NEGOTIATE) ip=192.168.3.159 proxyIp=null method=DELETE uri=/api/v1/sessions/86d3e4f5-2739-4759-9320-82a29914ab63 protocol=HTTP/1.1 status=200 ``` ### _How was this patch tested?_ - [ ] Add some test cases that check the changes thoroughly including negative and positive cases if possible - [x] Add screenshots for manual tests if appropriate <img width="1658" alt="image" src="https://user-images.githubusercontent.com/6757692/206594391-090594f5-a0dc-460a-ae05-e09bd938f6d7.png"> - [ ] [Run test](https://kyuubi.apache.org/docs/latest/develop_tools/testing.html#running-tests) locally before make a pull request Closes #3951 from turboFei/batch_log. Closes #3951 1f1c313d [fwang12] md 30b6e6d6 [fwang12] refactor log db2dff8a [fwang12] refactor c8e532f2 [fwang12] log format a8aa7825 [fwang12] update log4j2 xml 22905186 [fwang12] log4j2 629f93b9 [fwang12] add year db783eaa [fwang12] add log4j pattern 697f02fa [fwang12] save e9cd0bfc [fwang12] audit rest log Authored-by: fwang12 <fwang12@ebay.com> Signed-off-by: fwang12 <fwang12@ebay.com>
2022-12-09 20:58:43 +08:00 · 2022-12-09 20:58:43 +08:00 · 083fd383ae
commit 083fd383ae
parent 19775883b1
6 changed files with 97 additions and 4 deletions
--- a/conf/log4j2.xml.template
+++ b/conf/log4j2.xml.template
@ -20,6 +20,10 @@
 <!-- Extra logging related to initialization of Log4j.
 Set to debug or trace if log4j initialization is failing. -->
 <Configuration status="INFO">
+    <Properties>
+        <Property name="restAuditLogPath">rest-audit.log</Property>
+        <Property name="restAuditLogFilePattern">rest-audit-%d{yyyy-MM-dd}-%i.log</Property>
+    </Properties>
    <Appenders>
        <Console name="stdout" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %p %c: %m%n"/>
@ -27,6 +31,14 @@
                <RegexFilter regex=".*Thrift error occurred during processing of message.*" onMatch="DENY" onMismatch="NEUTRAL"/>
            </Filters>
        </Console>
+        <RollingFile name="restAudit" fileName="${sys:restAuditLogPath}"
+                     filePattern="${sys:restAuditLogFilePattern}">
+            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %p %c{1}: %m%n"/>
+            <Policies>
+                <SizeBasedTriggeringPolicy size="51200KB" />
+            </Policies>
+            <DefaultRolloverStrategy max="10"/>
+        </RollingFile>
    </Appenders>
    <Loggers>
        <Root level="INFO">
@ -43,5 +55,8 @@
        <Logger name="org.apache.hive.beeline.KyuubiBeeLine" level="error" additivity="false">
            <AppenderRef ref="stdout"/>
        </Logger>
+        <Logger name="org.apache.kyuubi.server.http.authentication.AuthenticationAuditLogger" additivity="false">
+            <AppenderRef ref="restAudit" />
+        </Logger>
    </Loggers>
 </Configuration>
--- a/docs/deployment/settings.md
+++ b/docs/deployment/settings.md
@ -607,6 +607,10 @@ Kyuubi uses [log4j](https://logging.apache.org/log4j/2.x/) for logging. You can
 <!-- Extra logging related to initialization of Log4j.
 Set to debug or trace if log4j initialization is failing. -->
 <Configuration status="INFO">
+    <Properties>
+        <Property name="restAuditLogPath">rest-audit.log</Property>
+        <Property name="restAuditLogFilePattern">rest-audit-%d{yyyy-MM-dd}-%i.log</Property>
+    </Properties>
    <Appenders>
        <Console name="stdout" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %p %c: %m%n"/>
@ -614,6 +618,14 @@ Kyuubi uses [log4j](https://logging.apache.org/log4j/2.x/) for logging. You can
                <RegexFilter regex=".*Thrift error occurred during processing of message.*" onMatch="DENY" onMismatch="NEUTRAL"/>
            </Filters>
        </Console>
+        <RollingFile name="restAudit" fileName="${sys:restAuditLogPath}"
+                     filePattern="${sys:restAuditLogFilePattern}">
+            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %p %c{1}: %m%n"/>
+            <Policies>
+                <SizeBasedTriggeringPolicy size="51200KB" />
+            </Policies>
+            <DefaultRolloverStrategy max="10"/>
+        </RollingFile>
    </Appenders>
    <Loggers>
        <Root level="INFO">
@ -630,6 +642,9 @@ Kyuubi uses [log4j](https://logging.apache.org/log4j/2.x/) for logging. You can
        <Logger name="org.apache.hive.beeline.KyuubiBeeLine" level="error" additivity="false">
            <AppenderRef ref="stdout"/>
        </Logger>
+        <Logger name="org.apache.kyuubi.server.http.authentication.AuthenticationAuditLogger" additivity="false">
+            <AppenderRef ref="restAudit" />
+        </Logger>
    </Loggers>
 </Configuration>
 ```
--- a/kyuubi-server/src/main/scala/org/apache/kyuubi/server/http/authentication/AuthenticationAuditLogger.scala
+++ b/kyuubi-server/src/main/scala/org/apache/kyuubi/server/http/authentication/AuthenticationAuditLogger.scala
@ -0,0 +1,42 @@
+/*
+ * 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.server.http.authentication
+
+import javax.servlet.http.{HttpServletRequest, HttpServletResponse}
+
+import org.apache.kyuubi.Logging
+import org.apache.kyuubi.server.http.authentication.AuthenticationFilter.{HTTP_AUTH_TYPE, HTTP_CLIENT_IP_ADDRESS, HTTP_CLIENT_USER_NAME, HTTP_PROXY_HEADER_CLIENT_IP_ADDRESS}
+
+object AuthenticationAuditLogger extends Logging {
+  final private val AUDIT_BUFFER = new ThreadLocal[StringBuilder]() {
+    override protected def initialValue: StringBuilder = new StringBuilder()
+  }
+
+  def audit(request: HttpServletRequest, response: HttpServletResponse): Unit = {
+    val sb = AUDIT_BUFFER.get()
+    sb.setLength(0)
+    sb.append(s"user=${HTTP_CLIENT_USER_NAME.get()}(auth:${HTTP_AUTH_TYPE.get()})").append("\t")
+    sb.append(s"ip=${HTTP_CLIENT_IP_ADDRESS.get()}").append("\t")
+    sb.append(s"proxyIp=${HTTP_PROXY_HEADER_CLIENT_IP_ADDRESS.get()}").append("\t")
+    sb.append(s"method=${request.getMethod}").append("\t")
+    sb.append(s"uri=${request.getRequestURI}").append("\t")
+    sb.append(s"protocol=${request.getProtocol}").append("\t")
+    sb.append(s"status=${response.getStatus}")
+    info(sb.toString())
+  }
+}
--- a/kyuubi-server/src/main/scala/org/apache/kyuubi/server/http/authentication/AuthenticationFilter.scala
+++ b/kyuubi-server/src/main/scala/org/apache/kyuubi/server/http/authentication/AuthenticationFilter.scala
@ -106,29 +106,34 @@ class AuthenticationFilter(conf: KyuubiConf) extends Filter with Logging {

    val authorization = httpRequest.getHeader(AUTHORIZATION_HEADER)
    val matchedHandler = getMatchedHandler(authorization).orNull
+    HTTP_CLIENT_IP_ADDRESS.set(httpRequest.getRemoteAddr)
+    HTTP_PROXY_HEADER_CLIENT_IP_ADDRESS.set(
+      httpRequest.getHeader(conf.get(FRONTEND_PROXY_HTTP_CLIENT_IP_HEADER)))

    if (matchedHandler == null) {
      debug(s"No auth scheme matched for url: ${httpRequest.getRequestURL}")
      httpResponse.setStatus(HttpServletResponse.SC_UNAUTHORIZED)
+      AuthenticationAuditLogger.audit(httpRequest, httpResponse)
      httpResponse.sendError(
        HttpServletResponse.SC_UNAUTHORIZED,
        s"No auth scheme matched for $authorization")
    } else {
-      HTTP_CLIENT_IP_ADDRESS.set(httpRequest.getRemoteAddr)
-      HTTP_PROXY_HEADER_CLIENT_IP_ADDRESS.set(
-        httpRequest.getHeader(conf.get(FRONTEND_PROXY_HTTP_CLIENT_IP_HEADER)))
+      HTTP_AUTH_TYPE.set(matchedHandler.authScheme.toString)
      try {
        val authUser = matchedHandler.authenticate(httpRequest, httpResponse)
        if (authUser != null) {
          HTTP_CLIENT_USER_NAME.set(authUser)
          doFilter(filterChain, httpRequest, httpResponse)
        }
+        AuthenticationAuditLogger.audit(httpRequest, httpResponse)
      } catch {
        case e: AuthenticationException =>
+          httpResponse.setStatus(HttpServletResponse.SC_FORBIDDEN)
+          AuthenticationAuditLogger.audit(httpRequest, httpResponse)
          HTTP_CLIENT_USER_NAME.remove()
          HTTP_CLIENT_IP_ADDRESS.remove()
          HTTP_PROXY_HEADER_CLIENT_IP_ADDRESS.remove()
-          httpResponse.setStatus(HttpServletResponse.SC_FORBIDDEN)
+          HTTP_AUTH_TYPE.remove()
          httpResponse.sendError(HttpServletResponse.SC_FORBIDDEN, e.getMessage)
      }
    }
@ -171,10 +176,15 @@ object AuthenticationFilter {
  final val HTTP_CLIENT_USER_NAME = new ThreadLocal[String]() {
    override protected def initialValue: String = null
  }
+  final val HTTP_AUTH_TYPE = new ThreadLocal[String]() {
+    override protected def initialValue(): String = null
+  }

  def getUserIpAddress: String = HTTP_CLIENT_IP_ADDRESS.get

  def getUserProxyHeaderIpAddress: String = HTTP_PROXY_HEADER_CLIENT_IP_ADDRESS.get()

  def getUserName: String = HTTP_CLIENT_USER_NAME.get
+
+  def getAuthType: String = HTTP_AUTH_TYPE.get()
 }
--- a/kyuubi-server/src/main/scala/org/apache/kyuubi/server/http/authentication/KyuubiHttpAuthenticationFactory.scala
+++ b/kyuubi-server/src/main/scala/org/apache/kyuubi/server/http/authentication/KyuubiHttpAuthenticationFactory.scala
@ -79,6 +79,8 @@ class KyuubiHttpAuthenticationFactory(conf: KyuubiConf) {
            }
            AuthenticationFilter.HTTP_CLIENT_USER_NAME.remove()
            AuthenticationFilter.HTTP_CLIENT_IP_ADDRESS.remove()
+            AuthenticationFilter.HTTP_PROXY_HEADER_CLIENT_IP_ADDRESS.remove()
+            AuthenticationFilter.HTTP_AUTH_TYPE.remove()
          }
        }

--- a/kyuubi-server/src/test/resources/log4j2-test.xml
+++ b/kyuubi-server/src/test/resources/log4j2-test.xml
@ -19,6 +19,9 @@
 <!-- Extra logging related to initialization of Log4j. 
 Set to debug or trace if log4j initialization is failing. -->
 <Configuration status="WARN">
+    <Properties>
+        <Property name="restAuditLogPath">target/rest-audit.log</Property>
+    </Properties>
    <Appenders>
        <Console name="stdout" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} %p %c: %m%n"/>
@ -33,11 +36,17 @@
                <RegexFilter regex=".*Thrift error occurred during processing of message.*" onMatch="DENY" onMismatch="NEUTRAL"/>
            </Filters>
        </File>
+        <File name="restAudit" fileName="${sys:restAuditLogPath}">
+            <PatternLayout pattern="%d{HH:mm:ss.SSS} %p %c{1}: %m%n"/>
+        </File>
    </Appenders>
    <Loggers>
        <Root level="INFO">
            <AppenderRef ref="stdout"/>
            <AppenderRef ref="file"/>
        </Root>
+        <Logger name="org.apache.kyuubi.server.http.authentication.AuthenticationAuditLogger" additivity="false">
+            <AppenderRef ref="restAudit" />
+        </Logger>
    </Loggers>
 </Configuration>