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 index ba9c981186..3b529cf0a3 100644 --- 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 @@ -17,6 +17,7 @@ package org.apache.hugegraph.api.filter; +import static org.apache.hugegraph.api.filter.PathFilter.REQUEST_PARAMS_JSON; import static org.apache.hugegraph.api.filter.PathFilter.REQUEST_TIME; import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_FAILED_COUNTER; import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_RESPONSE_TIME_HISTOGRAM; @@ -25,12 +26,20 @@ import java.io.IOException; +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; import jakarta.inject.Singleton; +import jakarta.ws.rs.HttpMethod; import jakarta.ws.rs.container.ContainerRequestContext; import jakarta.ws.rs.container.ContainerResponseContext; import jakarta.ws.rs.container.ContainerResponseFilter; +import jakarta.ws.rs.core.Context; import jakarta.ws.rs.ext.Provider; @@ -39,6 +48,14 @@ 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(AccessLogFilter.class); + + @Context + private jakarta.inject.Provider configProvider; /** * Use filter to log request info @@ -62,13 +79,24 @@ public void filter(ContainerRequestContext requestContext, ContainerResponseCont // get responseTime Object requestTime = requestContext.getProperty(REQUEST_TIME); - if(requestTime!=null){ + if(requestTime != null){ long now = System.currentTimeMillis(); - long responseTime = (now - (long)requestTime); + long start = (Long) requestTime; + long responseTime = now - start; MetricsUtil.registerHistogram( join(metricsName, METRICS_PATH_RESPONSE_TIME_HISTOGRAM)) .update(responseTime); + + HugeConfig config = configProvider.get(); + long timeThreshold = config.get(ServerOptions.SLOW_QUERY_LOG_TIME_THRESHOLD); + + // record slow query log + if (timeThreshold > 0 && isSlowQueryLogWhiteAPI(requestContext) && responseTime > timeThreshold) { + SlowQueryLog log = new SlowQueryLog(responseTime, start, (String) requestContext.getProperty(REQUEST_PARAMS_JSON), + method, timeThreshold, path); + LOG.info("Slow query: {}", JsonUtil.toJson(log)); + } } } @@ -79,4 +107,18 @@ private String join(String path1, String path2) { private boolean statusOk(int status){ return status == 200 || status == 201 || status == 202; } + + public static boolean isSlowQueryLogWhiteAPI(ContainerRequestContext context) { + String path = context.getUriInfo().getPath(); + String method = context.getRequest().getMethod(); + + // GraphsAPI/CypherAPI/Job GremlinAPI + if (path.startsWith(GRAPHS)) { + if (method.equals(HttpMethod.GET) || path.endsWith(CYPHER) || path.endsWith(GREMLIN) ){ + return true; + } + } + // Raw GremlinAPI + return path.startsWith(GREMLIN); + } } diff --git a/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java b/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java index 3414d6831b..e1e449ef26 100644 --- a/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java +++ b/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java @@ -17,12 +17,20 @@ package org.apache.hugegraph.api.filter; +import static org.apache.hugegraph.api.API.CHARSET; + import java.io.IOException; +import java.io.InputStream; + +import org.apache.commons.io.Charsets; +import org.apache.commons.io.IOUtils; import jakarta.inject.Singleton; +import jakarta.ws.rs.HttpMethod; import jakarta.ws.rs.container.ContainerRequestContext; import jakarta.ws.rs.container.ContainerRequestFilter; import jakarta.ws.rs.container.PreMatching; +import jakarta.ws.rs.core.MultivaluedMap; import jakarta.ws.rs.ext.Provider; @Provider @@ -31,10 +39,26 @@ public class PathFilter implements ContainerRequestFilter { public static final String REQUEST_TIME = "request_time"; + public static final String REQUEST_PARAMS_JSON = "request_params_json"; @Override public void filter(ContainerRequestContext context) throws IOException { context.setProperty(REQUEST_TIME, System.currentTimeMillis()); + + // record the request json + String method = context.getMethod(); + String requestParamsJson = ""; + if (method.equals(HttpMethod.POST)) { + requestParamsJson = IOUtils.toString(context.getEntityStream(), Charsets.toCharset(CHARSET)); + // replace input stream because we have already read it + InputStream in = IOUtils.toInputStream(requestParamsJson, Charsets.toCharset(CHARSET)); + context.setEntityStream(in); + } else if(method.equals(HttpMethod.GET)){ + MultivaluedMap pathParameters = context.getUriInfo().getPathParameters(); + requestParamsJson = pathParameters.toString(); + } + + context.setProperty(REQUEST_PARAMS_JSON, requestParamsJson); } } 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 index e8b999fb56..a8bbe5a5f2 100644 --- a/hugegraph-api/src/main/java/org/apache/hugegraph/config/ServerOptions.java +++ b/hugegraph-api/src/main/java/org/apache/hugegraph/config/ServerOptions.java @@ -304,4 +304,13 @@ public static synchronized ServerOptions instance() { null, "jad" ); + + public static final ConfigOption SLOW_QUERY_LOG_TIME_THRESHOLD = + new ConfigOption<>( + "log.slow_query_threshold", + "The threshold time(ms) of logging slow query, " + + "0 means logging slow query is disabled.", + nonNegativeInt(), + 1000L + ); } 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 new file mode 100644 index 0000000000..cb3f1c7125 --- /dev/null +++ b/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java @@ -0,0 +1,43 @@ +/* + * 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 Long startTime; + + public String rawQuery; + + public String method; + + public Long threshold; + + public String path; + + public SlowQueryLog(Long executeTime, Long startTime, String rawQuery, String method, Long threshold, + String path) { + this.executeTime = executeTime; + this.startTime = startTime; + 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 index 985ab78b2f..db58e89112 100644 --- a/hugegraph-dist/src/assembly/static/conf/log4j2.xml +++ b/hugegraph-dist/src/assembly/static/conf/log4j2.xml @@ -76,6 +76,30 @@ + + + + + + + + + + + + + + + + + + + + + + @@ -113,5 +137,8 @@ + + + diff --git a/hugegraph-dist/src/assembly/static/conf/rest-server.properties b/hugegraph-dist/src/assembly/static/conf/rest-server.properties index f6444f84fb..23f78c5824 100644 --- a/hugegraph-dist/src/assembly/static/conf/rest-server.properties +++ b/hugegraph-dist/src/assembly/static/conf/rest-server.properties @@ -48,3 +48,6 @@ rpc.server_port=8091 # lightweight load balancing (beta) server.id=server-1 server.role=master + +# slow query log +log.slow_query_threshold=1000 diff --git a/hugegraph-dist/src/main/resources/log4j2.xml b/hugegraph-dist/src/main/resources/log4j2.xml index bdd391e58b..5d80816291 100644 --- a/hugegraph-dist/src/main/resources/log4j2.xml +++ b/hugegraph-dist/src/main/resources/log4j2.xml @@ -76,6 +76,30 @@ + + + + + + + + + + + + + + + + + + + + + + @@ -124,5 +148,9 @@ + + + + diff --git a/hugegraph-test/src/main/resources/log4j2.xml b/hugegraph-test/src/main/resources/log4j2.xml index e830c6248e..284f53487c 100644 --- a/hugegraph-test/src/main/resources/log4j2.xml +++ b/hugegraph-test/src/main/resources/log4j2.xml @@ -76,6 +76,30 @@ + + + + + + + + + + + + + + + + + + + + + + @@ -124,5 +148,9 @@ + + + +