diff --git a/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java b/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java index 3b529cf0a3..0b864e4b22 100644 --- a/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java +++ b/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java @@ -17,7 +17,6 @@ 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 +24,11 @@ import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_TOTAL_COUNTER; import java.io.IOException; +import java.net.URI; 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; @@ -42,21 +40,39 @@ import jakarta.ws.rs.core.Context; import jakarta.ws.rs.ext.Provider; - +// TODO: should add test for this class @Provider @Singleton public class AccessLogFilter implements ContainerResponseFilter { - private static final String DELIMETER = "/"; + private static final Logger LOG = Log.logger(AccessLogFilter.class); + + private static final String DELIMITER = "/"; 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; + public static boolean needRecordLog(ContainerRequestContext context) { + // TODO: add test for 'path' result ('/gremlin' or 'gremlin') + String path = context.getUriInfo().getPath(); + + // GraphsAPI/CypherAPI/Job GremlinAPI + if (path.startsWith(GRAPHS)) { + if (HttpMethod.GET.equals(context.getMethod()) || path.endsWith(CYPHER)) { + return true; + } + } + // Direct GremlinAPI + return path.endsWith(GREMLIN); + } + + private String join(String path1, String path2) { + return String.join(DELIMITER, path1, path2); + } + /** * Use filter to log request info * @@ -64,10 +80,12 @@ public class AccessLogFilter implements ContainerResponseFilter { * @param responseContext responseContext */ @Override - public void filter(ContainerRequestContext requestContext, ContainerResponseContext responseContext) throws IOException { + public void filter(ContainerRequestContext requestContext, + ContainerResponseContext responseContext) throws IOException { // Grab corresponding request / response info from context; - String method = requestContext.getRequest().getMethod(); - String path = requestContext.getUriInfo().getPath(); + URI uri = requestContext.getUriInfo().getRequestUri(); + String path = uri.getRawPath(); + String method = requestContext.getMethod(); String metricsName = join(path, method); MetricsUtil.registerCounter(join(metricsName, METRICS_PATH_TOTAL_COUNTER)).inc(); @@ -77,48 +95,28 @@ public void filter(ContainerRequestContext requestContext, ContainerResponseCont MetricsUtil.registerCounter(join(metricsName, METRICS_PATH_FAILED_COUNTER)).inc(); } - // get responseTime Object requestTime = requestContext.getProperty(REQUEST_TIME); - if(requestTime != null){ + if (requestTime != null) { long now = System.currentTimeMillis(); long start = (Long) requestTime; - long responseTime = now - start; + long executeTime = now - start; - MetricsUtil.registerHistogram( - join(metricsName, METRICS_PATH_RESPONSE_TIME_HISTOGRAM)) - .update(responseTime); + MetricsUtil.registerHistogram(join(metricsName, METRICS_PATH_RESPONSE_TIME_HISTOGRAM)) + .update(executeTime); 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)); + // Record slow query if meet needs, watch out the perf + if (timeThreshold > 0 && executeTime > timeThreshold && + needRecordLog(requestContext)) { + // TODO: set RequestBody null, handle it later & should record "client IP" + LOG.info("[Slow Query] execTime={}ms, body={}, method={}, path={}, query={}", + executeTime, null, method, path, uri.getQuery()); } } } - private String join(String path1, String path2) { - return String.join(DELIMETER, path1, 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); + private boolean statusOk(int status) { + return status >= 200 && status < 300; } } diff --git a/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java b/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java index e1e449ef26..e7520f84fb 100644 --- a/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java +++ b/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java @@ -17,20 +17,12 @@ 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 @@ -42,23 +34,25 @@ public class PathFilter implements ContainerRequestFilter { public static final String REQUEST_PARAMS_JSON = "request_params_json"; @Override - public void filter(ContainerRequestContext context) - throws IOException { + public void filter(ContainerRequestContext context) throws IOException { context.setProperty(REQUEST_TIME, System.currentTimeMillis()); - // record the request json + // TODO: temporarily comment it to fix loader bug, handle it later + /*// record the request json String method = context.getMethod(); String requestParamsJson = ""; if (method.equals(HttpMethod.POST)) { - requestParamsJson = IOUtils.toString(context.getEntityStream(), Charsets.toCharset(CHARSET)); + 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(); + } else if (method.equals(HttpMethod.GET)) { + MultivaluedMap pathParameters = context.getUriInfo() + .getPathParameters(); requestParamsJson = pathParameters.toString(); } - context.setProperty(REQUEST_PARAMS_JSON, requestParamsJson); + context.setProperty(REQUEST_PARAMS_JSON, requestParamsJson);*/ } } diff --git a/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java b/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java index cb3f1c7125..e55316c39e 100644 --- a/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java +++ b/hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java @@ -16,28 +16,38 @@ */ 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; + public long executeTime; + + public long startTime; + + public long thresholdTime; + + public SlowQueryLog(String rawQuery, String method, String path, + long executeTime, long startTime, long thresholdTime) { this.rawQuery = rawQuery; this.method = method; - this.threshold = threshold; this.path = path; + this.executeTime = executeTime; + this.startTime = startTime; + this.thresholdTime = thresholdTime; + } + + @Override + public String toString() { + return "SlowQueryLog{executeTime=" + executeTime + + ", startTime=" + startTime + + ", rawQuery='" + rawQuery + '\'' + + ", method='" + method + '\'' + + ", threshold=" + thresholdTime + + ", path='" + path + '\'' + + '}'; } }