Skip to content

Commit a6e1f23

Browse files
imbajinimbajin
authored
fix(api): refactor/downgrade record logic for slow log (#2347)
* fix(api): refactor/downgrade record logic for slow log add some TODOs & assign @SunnyBoy-WYH to address it * fix typo * enhance the perf
1 parent a7ad7ea commit a6e1f23

File tree

3 files changed

+71
-69
lines changed

3 files changed

+71
-69
lines changed

‎hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java‎

Lines changed: 40 additions & 42 deletions
Original file line numberDiff line numberDiff line change
@@ -17,20 +17,18 @@
1717

1818
package org.apache.hugegraph.api.filter;
1919

20-
import static org.apache.hugegraph.api.filter.PathFilter.REQUEST_PARAMS_JSON;
2120
import static org.apache.hugegraph.api.filter.PathFilter.REQUEST_TIME;
2221
import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_FAILED_COUNTER;
2322
import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_RESPONSE_TIME_HISTOGRAM;
2423
import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_SUCCESS_COUNTER;
2524
import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_TOTAL_COUNTER;
2625

2726
import java.io.IOException;
27+
import java.net.URI;
2828

2929
import org.apache.hugegraph.config.HugeConfig;
3030
import org.apache.hugegraph.config.ServerOptions;
3131
import org.apache.hugegraph.metrics.MetricsUtil;
32-
import org.apache.hugegraph.metrics.SlowQueryLog;
33-
import org.apache.hugegraph.util.JsonUtil;
3432
import org.apache.hugegraph.util.Log;
3533
import org.slf4j.Logger;
3634

@@ -42,32 +40,52 @@
4240
import jakarta.ws.rs.core.Context;
4341
import jakarta.ws.rs.ext.Provider;
4442

45-
43+
// TODO: should add test for this class
4644
@Provider
4745
@Singleton
4846
public class AccessLogFilter implements ContainerResponseFilter {
4947

50-
private static final String DELIMETER = "/";
48+
private static final Logger LOG = Log.logger(AccessLogFilter.class);
49+
50+
private static final String DELIMITER = "/";
5151
private static final String GRAPHS = "graphs";
5252
private static final String GREMLIN = "gremlin";
5353
private static final String CYPHER = "cypher";
5454

55-
private static final Logger LOG = Log.logger(AccessLogFilter.class);
56-
5755
@Context
5856
private jakarta.inject.Provider<HugeConfig> configProvider;
5957

58+
public static boolean needRecordLog(ContainerRequestContext context) {
59+
// TODO: add test for 'path' result ('/gremlin' or 'gremlin')
60+
String path = context.getUriInfo().getPath();
61+
62+
// GraphsAPI/CypherAPI/Job GremlinAPI
63+
if (path.startsWith(GRAPHS)) {
64+
if (HttpMethod.GET.equals(context.getMethod()) || path.endsWith(CYPHER)) {
65+
return true;
66+
}
67+
}
68+
// Direct GremlinAPI
69+
return path.endsWith(GREMLIN);
70+
}
71+
72+
private String join(String path1, String path2) {
73+
return String.join(DELIMITER, path1, path2);
74+
}
75+
6076
/**
6177
* Use filter to log request info
6278
*
6379
* @param requestContext requestContext
6480
* @param responseContext responseContext
6581
*/
6682
@Override
67-
public void filter(ContainerRequestContext requestContext, ContainerResponseContext responseContext) throws IOException {
83+
public void filter(ContainerRequestContext requestContext,
84+
ContainerResponseContext responseContext) throws IOException {
6885
// Grab corresponding request / response info from context;
69-
String method = requestContext.getRequest().getMethod();
70-
String path = requestContext.getUriInfo().getPath();
86+
URI uri = requestContext.getUriInfo().getRequestUri();
87+
String path = uri.getRawPath();
88+
String method = requestContext.getMethod();
7189
String metricsName = join(path, method);
7290

7391
MetricsUtil.registerCounter(join(metricsName, METRICS_PATH_TOTAL_COUNTER)).inc();
@@ -77,48 +95,28 @@ public void filter(ContainerRequestContext requestContext, ContainerResponseCont
7795
MetricsUtil.registerCounter(join(metricsName, METRICS_PATH_FAILED_COUNTER)).inc();
7896
}
7997

80-
// get responseTime
8198
Object requestTime = requestContext.getProperty(REQUEST_TIME);
82-
if(requestTime != null){
99+
if (requestTime != null) {
83100
long now = System.currentTimeMillis();
84101
long start = (Long) requestTime;
85-
long responseTime = now - start;
102+
long executeTime = now - start;
86103

87-
MetricsUtil.registerHistogram(
88-
join(metricsName, METRICS_PATH_RESPONSE_TIME_HISTOGRAM))
89-
.update(responseTime);
104+
MetricsUtil.registerHistogram(join(metricsName, METRICS_PATH_RESPONSE_TIME_HISTOGRAM))
105+
.update(executeTime);
90106

91107
HugeConfig config = configProvider.get();
92108
long timeThreshold = config.get(ServerOptions.SLOW_QUERY_LOG_TIME_THRESHOLD);
93-
94-
// record slow query log
95-
if (timeThreshold > 0 && isSlowQueryLogWhiteAPI(requestContext) && responseTime > timeThreshold) {
96-
SlowQueryLog log = new SlowQueryLog(responseTime, start, (String) requestContext.getProperty(REQUEST_PARAMS_JSON),
97-
method, timeThreshold, path);
98-
LOG.info("Slow query: {}", JsonUtil.toJson(log));
109+
// Record slow query if meet needs, watch out the perf
110+
if (timeThreshold > 0 && executeTime > timeThreshold &&
111+
needRecordLog(requestContext)) {
112+
// TODO: set RequestBody null, handle it later & should record "client IP"
113+
LOG.info("[Slow Query] execTime={}ms, body={}, method={}, path={}, query={}",
114+
executeTime, null, method, path, uri.getQuery());
99115
}
100116
}
101117
}
102118

103-
private String join(String path1, String path2) {
104-
return String.join(DELIMETER, path1, path2);
105-
}
106-
107-
private boolean statusOk(int status){
108-
return status == 200 || status == 201 || status == 202;
109-
}
110-
111-
public static boolean isSlowQueryLogWhiteAPI(ContainerRequestContext context) {
112-
String path = context.getUriInfo().getPath();
113-
String method = context.getRequest().getMethod();
114-
115-
// GraphsAPI/CypherAPI/Job GremlinAPI
116-
if (path.startsWith(GRAPHS)) {
117-
if (method.equals(HttpMethod.GET) || path.endsWith(CYPHER) || path.endsWith(GREMLIN) ){
118-
return true;
119-
}
120-
}
121-
// Raw GremlinAPI
122-
return path.startsWith(GREMLIN);
119+
private boolean statusOk(int status) {
120+
return status >= 200 && status < 300;
123121
}
124122
}

‎hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java‎

Lines changed: 9 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -17,20 +17,12 @@
1717

1818
package org.apache.hugegraph.api.filter;
1919

20-
import static org.apache.hugegraph.api.API.CHARSET;
21-
2220
import java.io.IOException;
23-
import java.io.InputStream;
24-
25-
import org.apache.commons.io.Charsets;
26-
import org.apache.commons.io.IOUtils;
2721

2822
import jakarta.inject.Singleton;
29-
import jakarta.ws.rs.HttpMethod;
3023
import jakarta.ws.rs.container.ContainerRequestContext;
3124
import jakarta.ws.rs.container.ContainerRequestFilter;
3225
import jakarta.ws.rs.container.PreMatching;
33-
import jakarta.ws.rs.core.MultivaluedMap;
3426
import jakarta.ws.rs.ext.Provider;
3527

3628
@Provider
@@ -42,23 +34,25 @@ public class PathFilter implements ContainerRequestFilter {
4234
public static final String REQUEST_PARAMS_JSON = "request_params_json";
4335

4436
@Override
45-
public void filter(ContainerRequestContext context)
46-
throws IOException {
37+
public void filter(ContainerRequestContext context) throws IOException {
4738
context.setProperty(REQUEST_TIME, System.currentTimeMillis());
4839

49-
// record the request json
40+
// TODO: temporarily comment it to fix loader bug, handle it later
41+
/*// record the request json
5042
String method = context.getMethod();
5143
String requestParamsJson = "";
5244
if (method.equals(HttpMethod.POST)) {
53-
requestParamsJson = IOUtils.toString(context.getEntityStream(), Charsets.toCharset(CHARSET));
45+
requestParamsJson = IOUtils.toString(context.getEntityStream(),
46+
Charsets.toCharset(CHARSET));
5447
// replace input stream because we have already read it
5548
InputStream in = IOUtils.toInputStream(requestParamsJson, Charsets.toCharset(CHARSET));
5649
context.setEntityStream(in);
57-
} else if(method.equals(HttpMethod.GET)){
58-
MultivaluedMap<String, String> pathParameters = context.getUriInfo().getPathParameters();
50+
} else if (method.equals(HttpMethod.GET)) {
51+
MultivaluedMap<String, String> pathParameters = context.getUriInfo()
52+
.getPathParameters();
5953
requestParamsJson = pathParameters.toString();
6054
}
6155
62-
context.setProperty(REQUEST_PARAMS_JSON, requestParamsJson);
56+
context.setProperty(REQUEST_PARAMS_JSON, requestParamsJson);*/
6357
}
6458
}

‎hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java‎

Lines changed: 22 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -16,28 +16,38 @@
1616
*/
1717
package org.apache.hugegraph.metrics;
1818

19-
2019
public class SlowQueryLog {
2120

22-
public Long executeTime;
23-
24-
public Long startTime;
25-
2621
public String rawQuery;
2722

2823
public String method;
2924

30-
public Long threshold;
31-
3225
public String path;
3326

34-
public SlowQueryLog(Long executeTime, Long startTime, String rawQuery, String method, Long threshold,
35-
String path) {
36-
this.executeTime = executeTime;
37-
this.startTime = startTime;
27+
public long executeTime;
28+
29+
public long startTime;
30+
31+
public long thresholdTime;
32+
33+
public SlowQueryLog(String rawQuery, String method, String path,
34+
long executeTime, long startTime, long thresholdTime) {
3835
this.rawQuery = rawQuery;
3936
this.method = method;
40-
this.threshold = threshold;
4137
this.path = path;
38+
this.executeTime = executeTime;
39+
this.startTime = startTime;
40+
this.thresholdTime = thresholdTime;
41+
}
42+
43+
@Override
44+
public String toString() {
45+
return "SlowQueryLog{executeTime=" + executeTime +
46+
", startTime=" + startTime +
47+
", rawQuery='" + rawQuery + '\'' +
48+
", method='" + method + '\'' +
49+
", threshold=" + thresholdTime +
50+
", path='" + path + '\'' +
51+
'}';
4252
}
4353
}

0 commit comments

Comments
 (0)