feat(api): support recording slow query log

apache · Oct 16, 2023 · 4bfd688 · 4bfd688
1 parent 073c479
commit 4bfd688
Show file tree

Hide file tree

Showing 6 changed files with 143 additions and 7 deletions.
diff --git a/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java b/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java
@@ -29,6 +29,8 @@
 import org.apache.hugegraph.config.HugeConfig;
 import org.apache.hugegraph.config.ServerOptions;
 import org.apache.hugegraph.metrics.MetricsUtil;
+import org.apache.hugegraph.metrics.SlowQueryLog;
+import org.apache.hugegraph.util.JsonUtil;
 import org.apache.hugegraph.util.Log;
 import org.slf4j.Logger;
 
@@ -48,8 +50,9 @@ public class AccessLogFilter implements ContainerResponseFilter {
     private static final String DELIMETER = "/";
     private static final String GRAPHS = "graphs";
     private static final String GREMLIN = "gremlin";
+    private static final String CYPHER = "cypher";
 
-    private static final Logger LOG = Log.logger(AuthenticationFilter.class);
+    private static final Logger LOG = Log.logger(AccessLogFilter.class);
 
     @Context
     private jakarta.inject.Provider<HugeConfig> configProvider;
@@ -86,13 +89,14 @@ public void filter(ContainerRequestContext requestContext, ContainerResponseCont
 
             HugeConfig config = configProvider.get();
             Boolean enableSlowQueryLog = config.get(ServerOptions.ENABLE_SLOW_QUERY_LOG);
-            Integer timeThreshold = config.get(ServerOptions.SLOW_QUERY_LOG_TIME_THRESHOLD);
+            Long timeThreshold = config.get(ServerOptions.SLOW_QUERY_LOG_TIME_THRESHOLD);
 
             // record slow query log
             if (enableSlowQueryLog && isSlowQueryLogWhiteAPI(requestContext) &&
                 timeThreshold < responseTime) {
-                LOG.info("{} slow query log {} execute time is longer than threshold {} ms, path {}",
-                         method, requestContext.getProperty(REQUEST_PARAMS_JSON), timeThreshold, path);
+                SlowQueryLog log = new SlowQueryLog(responseTime,
+                                                    (String) requestContext.getProperty(REQUEST_PARAMS_JSON), method, timeThreshold, path);
+                LOG.info("slow query log: {}", JsonUtil.toJson(log));
             }
         }
     }
@@ -109,10 +113,19 @@ public static boolean isSlowQueryLogWhiteAPI(ContainerRequestContext context) {
         String path = context.getUriInfo().getPath();
         String method = context.getRequest().getMethod();
 
+        // GraphsAPI
         if (path.startsWith(GRAPHS) && method.equals(HttpMethod.GET)) {
             return true;
         }
-
+        // CypherAPI
+        if (path.startsWith(GRAPHS) && path.endsWith(CYPHER)) {
+            return true;
+        }
+        // Job GremlinAPI
+        if (path.startsWith(GRAPHS) && path.endsWith(GREMLIN)) {
+            return true;
+        }
+        // Raw GremlinAPI
         return path.startsWith(GREMLIN);
     }
 }
diff --git a/hugegraph-api/src/main/java/org/apache/hugegraph/config/ServerOptions.java b/hugegraph-api/src/main/java/org/apache/hugegraph/config/ServerOptions.java
@@ -273,12 +273,12 @@ public static synchronized ServerOptions instance() {
                     "disable"
             );
 
-    public static final ConfigOption<Integer> SLOW_QUERY_LOG_TIME_THRESHOLD =
+    public static final ConfigOption<Long> SLOW_QUERY_LOG_TIME_THRESHOLD =
             new ConfigOption<>(
                     "log.slow_query_threshold",
                     "The slow query log time threshold(ms) of rest server.",
                     disallowEmpty(),
-                    1000
+                    1000L
             );
 
     public static final ConfigOption<Boolean> ENABLE_SLOW_QUERY_LOG =

diff --git a/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java b/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java
@@ -0,0 +1,40 @@
+/*
+ * 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.hugegraph.metrics;
+
+
+public class SlowQueryLog {
+
+    public Long executeTime;
+
+    public String rawQuery;
+
+    public String method;
+
+    public Long threshold;
+
+    public String path;
+
+    public SlowQueryLog(Long executeTime, String rawQuery, String method, Long threshold,
+                        String path) {
+        this.executeTime = executeTime;
+        this.rawQuery = rawQuery;
+        this.method = method;
+        this.threshold = threshold;
+        this.path = path;
+    }
+}
diff --git a/hugegraph-dist/src/assembly/static/conf/log4j2.xml b/hugegraph-dist/src/assembly/static/conf/log4j2.xml
@@ -76,6 +76,30 @@
                 </Delete>
             </DefaultRolloverStrategy>
         </RollingRandomAccessFile>
+
+        <!-- Slow query log config -->
+        <RollingRandomAccessFile name="slowQueryLog" fileName="${LOG_PATH}/slow_query.log"
+                                 filePattern="${LOG_PATH}/$${date:yyyy-MM}/slow_query_log-%d{yyyy-MM-dd}-%i.log"
+                                 immediateFlush="false">
+            <ThresholdFilter level="TRACE" onMatch="ACCEPT" onMismatch="DENY"/>
+            <PatternLayout pattern="%-d{yyyy-MM-dd HH:mm:ss} [%t] [%p] %c{1.} - %m%n"/>
+            <!-- Trigger after exceeding 1day or 50MB -->
+            <Policies>
+                <SizeBasedTriggeringPolicy size="50MB"/>
+                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
+            </Policies>
+            <!-- Keep 5 files per day & auto delete after over 2GB or 100 files -->
+            <DefaultRolloverStrategy max="5">
+                <Delete basePath="${LOG_PATH}" maxDepth="2">
+                    <IfFileName glob="*/*.log"/>
+                    <!-- Limit log amount & size -->
+                    <IfAny>
+                        <IfAccumulatedFileSize exceeds="2GB" />
+                        <IfAccumulatedFileCount exceeds="100" />
+                    </IfAny>
+                </Delete>
+            </DefaultRolloverStrategy>
+        </RollingRandomAccessFile>
     </appenders>
 
     <loggers>
@@ -113,5 +137,8 @@
         <AsyncLogger name="org.apache.hugegraph.api.filter.AuthenticationFilter" level="INFO" additivity="false">
             <appender-ref ref="audit"/>
         </AsyncLogger>
+        <AsyncLogger name="org.apache.hugegraph.api.filter.AccessLogFilter" level="INFO" additivity="false">
+            <appender-ref ref="slowQueryLog"/>
+        </AsyncLogger>
     </loggers>
 </configuration>
diff --git a/hugegraph-dist/src/main/resources/log4j2.xml b/hugegraph-dist/src/main/resources/log4j2.xml
@@ -76,6 +76,30 @@
                 </Delete>
             </DefaultRolloverStrategy>
         </RollingRandomAccessFile>
+
+        <!-- Slow query log config -->
+        <RollingRandomAccessFile name="slowQueryLog" fileName="${LOG_PATH}/slow_query.log"
+                                 filePattern="${LOG_PATH}/$${date:yyyy-MM}/slow_query_log-%d{yyyy-MM-dd}-%i.log"
+                                 immediateFlush="false">
+            <ThresholdFilter level="TRACE" onMatch="ACCEPT" onMismatch="DENY"/>
+            <PatternLayout pattern="%-d{yyyy-MM-dd HH:mm:ss} [%t] [%p] %c{1.} - %m%n"/>
+            <!-- Trigger after exceeding 1day or 50MB -->
+            <Policies>
+                <SizeBasedTriggeringPolicy size="50MB"/>
+                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
+            </Policies>
+            <!-- Keep 5 files per day & auto delete after over 2GB or 100 files -->
+            <DefaultRolloverStrategy max="5">
+                <Delete basePath="${LOG_PATH}" maxDepth="2">
+                    <IfFileName glob="*/*.log"/>
+                    <!-- Limit log amount & size -->
+                    <IfAny>
+                        <IfAccumulatedFileSize exceeds="2GB" />
+                        <IfAccumulatedFileCount exceeds="100" />
+                    </IfAny>
+                </Delete>
+            </DefaultRolloverStrategy>
+        </RollingRandomAccessFile>
     </appenders>
 
     <loggers>
@@ -124,5 +148,9 @@
             <appender-ref ref="console"/>
             <appender-ref ref="audit"/>
         </AsyncLogger>
+        <AsyncLogger name="org.apache.hugegraph.api.filter.AccessLogFilter" level="INFO" additivity="false">
+            <appender-ref ref="console"/>
+            <appender-ref ref="slowQueryLog"/>
+        </AsyncLogger>
     </loggers>
 </configuration>
diff --git a/hugegraph-test/src/main/resources/log4j2.xml b/hugegraph-test/src/main/resources/log4j2.xml
@@ -76,6 +76,30 @@
                 </Delete>
             </DefaultRolloverStrategy>
         </RollingRandomAccessFile>
+
+        <!-- Slow query log config -->
+        <RollingRandomAccessFile name="slowQueryLog" fileName="${LOG_PATH}/slow_query.log"
+                                 filePattern="${LOG_PATH}/$${date:yyyy-MM}/slow_query_log-%d{yyyy-MM-dd}-%i.log"
+                                 immediateFlush="false">
+            <ThresholdFilter level="TRACE" onMatch="ACCEPT" onMismatch="DENY"/>
+            <PatternLayout pattern="%-d{yyyy-MM-dd HH:mm:ss} [%t] [%p] %c{1.} - %m%n"/>
+            <!-- Trigger after exceeding 1day or 50MB -->
+            <Policies>
+                <SizeBasedTriggeringPolicy size="50MB"/>
+                <TimeBasedTriggeringPolicy interval="1" modulate="true" />
+            </Policies>
+            <!-- Keep 5 files per day & auto delete after over 2GB or 100 files -->
+            <DefaultRolloverStrategy max="5">
+                <Delete basePath="${LOG_PATH}" maxDepth="2">
+                    <IfFileName glob="*/*.log"/>
+                    <!-- Limit log amount & size -->
+                    <IfAny>
+                        <IfAccumulatedFileSize exceeds="2GB" />
+                        <IfAccumulatedFileCount exceeds="100" />
+                    </IfAny>
+                </Delete>
+            </DefaultRolloverStrategy>
+        </RollingRandomAccessFile>
     </appenders>
 
     <loggers>
@@ -124,5 +148,9 @@
             <appender-ref ref="console"/>
             <appender-ref ref="audit"/>
         </AsyncLogger>
+        <AsyncLogger name="org.apache.hugegraph.api.filter.AccessLogFilter" level="INFO" additivity="false">
+            <appender-ref ref="console"/>
+            <appender-ref ref="slowQueryLog"/>
+        </AsyncLogger>
     </loggers>
 </configuration>