Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(api): refactor/downgrade record logic for slow log #2347

Merged
merged 5 commits into from
Nov 13, 2023
Merged

fix(api): refactor/downgrade record logic for slow log #2347

Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
034cca6
fix(api): refactor/downgrade record logic for slow log
imbajin Nov 10, 2023
e323784
fix typo
imbajin Nov 10, 2023
42ae00a
enhance the perf
imbajin Nov 12, 2023
572b808
Merge branch 'master' into fix-slowlog
imbajin Nov 13, 2023
c0d56b1
tiny fix
imbajin Nov 13, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
56 changes: 25 additions & 31 deletions hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/auth/LoginAPI.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,39 +17,40 @@

package org.apache.hugegraph.api.auth;

import io.swagger.v3.oas.annotations.tags.Tag;
import jakarta.inject.Singleton;
import javax.security.sasl.AuthenticationException;
import jakarta.ws.rs.BadRequestException;
import jakarta.ws.rs.Consumes;
import jakarta.ws.rs.DELETE;
import jakarta.ws.rs.GET;
import jakarta.ws.rs.HeaderParam;
import jakarta.ws.rs.NotAuthorizedException;
import jakarta.ws.rs.POST;
import jakarta.ws.rs.Path;
import jakarta.ws.rs.PathParam;
import jakarta.ws.rs.Produces;
import jakarta.ws.rs.core.Context;
import jakarta.ws.rs.core.HttpHeaders;

import org.apache.commons.lang3.StringUtils;
import org.apache.hugegraph.core.GraphManager;
import org.apache.hugegraph.define.Checkable;
import org.slf4j.Logger;

import org.apache.hugegraph.HugeGraph;
import org.apache.hugegraph.api.API;
import org.apache.hugegraph.api.filter.AuthenticationFilter;
import org.apache.hugegraph.api.filter.StatusFilter.Status;
import org.apache.hugegraph.auth.AuthConstant;
import org.apache.hugegraph.auth.UserWithRole;
import org.apache.hugegraph.core.GraphManager;
import org.apache.hugegraph.define.Checkable;
import org.apache.hugegraph.util.E;
import org.apache.hugegraph.util.Log;
import org.slf4j.Logger;

import com.codahale.metrics.annotation.Timed;
import com.fasterxml.jackson.annotation.JsonProperty;
import com.google.common.collect.ImmutableMap;

import io.swagger.v3.oas.annotations.tags.Tag;
import jakarta.inject.Singleton;
import jakarta.ws.rs.BadRequestException;
import jakarta.ws.rs.Consumes;
import jakarta.ws.rs.DELETE;
import jakarta.ws.rs.GET;
import jakarta.ws.rs.HeaderParam;
import jakarta.ws.rs.NotAuthorizedException;
import jakarta.ws.rs.POST;
import jakarta.ws.rs.Path;
import jakarta.ws.rs.PathParam;
import jakarta.ws.rs.Produces;
import jakarta.ws.rs.core.Context;
import jakarta.ws.rs.core.HttpHeaders;

@Path("graphs/{graph}/auth")
@Singleton
@Tag(name = "LoginAPI")
Expand All @@ -63,8 +64,7 @@
@Status(Status.OK)
@Consumes(APPLICATION_JSON)
@Produces(APPLICATION_JSON_WITH_CHARSET)
public String login(@Context GraphManager manager,
@PathParam("graph") String graph,
public String login(@Context GraphManager manager, @PathParam("graph") String graph,
JsonLogin jsonLogin) {
LOG.debug("Graph [{}] user login: {}", graph, jsonLogin);
checkCreatingBody(jsonLogin);
Expand Down Expand Up @@ -94,13 +94,10 @@
LOG.debug("Graph [{}] user logout: {}", graph, auth);

if (!auth.startsWith(AuthenticationFilter.BEARER_TOKEN_PREFIX)) {
throw new BadRequestException(
"Only HTTP Bearer authentication is supported");
throw new BadRequestException("Only HTTP Bearer authentication is supported");

Check warning on line 97 in hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/auth/LoginAPI.java

View check run for this annotation

Codecov / codecov/patch

hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/auth/LoginAPI.java#L97 

Added line #L97 was not covered by tests
}

String token = auth.substring(AuthenticationFilter.BEARER_TOKEN_PREFIX
.length());

String token = auth.substring(AuthenticationFilter.BEARER_TOKEN_PREFIX.length());
manager.authManager().logoutUser(token);
}

Expand All @@ -119,12 +116,10 @@
LOG.debug("Graph [{}] get user: {}", graph, token);

if (!token.startsWith(AuthenticationFilter.BEARER_TOKEN_PREFIX)) {
throw new BadRequestException(
"Only HTTP Bearer authentication is supported");
throw new BadRequestException("Only HTTP Bearer authentication is supported");

Check warning on line 119 in hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/auth/LoginAPI.java

View check run for this annotation

Codecov / codecov/patch

hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/auth/LoginAPI.java#L119 

Added line #L119 was not covered by tests
}

token = token.substring(AuthenticationFilter.BEARER_TOKEN_PREFIX
.length());
token = token.substring(AuthenticationFilter.BEARER_TOKEN_PREFIX.length());
UserWithRole userWithRole = manager.authManager().validateUser(token);

HugeGraph g = graph(manager, graph);
Expand All @@ -144,8 +139,7 @@

@Override
public void checkCreate(boolean isBatch) {
E.checkArgument(!StringUtils.isEmpty(this.name),
"The name of user can't be null");
E.checkArgument(!StringUtils.isEmpty(this.name), "The name of user can't be null");
E.checkArgument(!StringUtils.isEmpty(this.password),
"The password of user can't be null");
}
Expand Down
82 changes: 40 additions & 42 deletions ...h-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,20 +17,18 @@

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;
import static org.apache.hugegraph.metrics.MetricsUtil.METRICS_PATH_SUCCESS_COUNTER;
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;

Expand All @@ -42,32 +40,52 @@
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<HugeConfig> 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
*
* @param requestContext requestContext
* @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();
Expand All @@ -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 && timeThreshold < executeTime &&
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

prefer executeTime > timeThreshold

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

prefer to just update the small change in this PR so that we don’t have to keep track of it.
background: in order to make it easier to read/understand, prefer to determine whether the executeTime exceeds a threshold.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

prefer to just update the small change in this PR so that we don’t have to keep track of it. background: in order to make it easier to read/understand, prefer to determine whether the executeTime exceeds a threshold.

Done, already divide it, @SunnyBoy-WYH could address the background in next PR

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;
}
}
24 changes: 9 additions & 15 deletions hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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<String, String> pathParameters = context.getUriInfo().getPathParameters();
} else if (method.equals(HttpMethod.GET)) {
MultivaluedMap<String, String> pathParameters = context.getUriInfo()
.getPathParameters();
requestParamsJson = pathParameters.toString();
}

context.setProperty(REQUEST_PARAMS_JSON, requestParamsJson);
context.setProperty(REQUEST_PARAMS_JSON, requestParamsJson);*/
}
}
33 changes: 22 additions & 11 deletions hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,25 +19,36 @@

public class SlowQueryLog {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

to be removed?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

to be removed?

depends on whether to use it for subsequent optimization(could keep it now)


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 threshold;
imbajin marked this conversation as resolved.
Show resolved Hide resolved

public SlowQueryLog(String rawQuery, String method, String path,
long executeTime, long startTime, long threshold) {

Check warning on line 35 in hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java

View check run for this annotation

Codecov / codecov/patch

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

Added line #L35 was not covered by tests
this.rawQuery = rawQuery;
this.method = method;
this.threshold = threshold;
this.path = path;
this.executeTime = executeTime;
this.startTime = startTime;
this.threshold = threshold;
}

Check warning on line 42 in hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java

View check run for this annotation

Codecov / codecov/patch

hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java#L39-L42 

Added lines #L39 - L42 were not covered by tests

@Override
public String toString() {
return "SlowQueryLog{executeTime=" + executeTime +

Check warning on line 46 in hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/metrics/SlowQueryLog.java

View check run for this annotation

Codecov / codecov/patch

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

Added line #L46 was not covered by tests
", startTime=" + startTime +
", rawQuery='" + rawQuery + '\'' +
", method='" + method + '\'' +
", threshold=" + threshold +
imbajin marked this conversation as resolved.
Show resolved Hide resolved
", path='" + path + '\'' +
'}';
}
}
5 changes: 3 additions & 2 deletions hugegraph-server/hugegraph-test/src/main/java/org/apache/hugegraph/api/ArthasApiTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -46,8 +46,9 @@ public void testArthasApi() {
" \"execTimeout\": \"10000\"\n" +
"}";
RestClient arthasApiClient = new RestClient(ARTHAS_API_BASE_URL, false);
// If request header contains basic auth, and if we are not set auth when arthas attach hg,
// arthas will auth it and return 401. ref:https://arthas.aliyun.com/en/doc/auth.html#configure-username-and-password
// If the request header contains basic auth,
// and if we are not set auth when arthas attach hg, arthas will auth it and return 401.
// ref:https://arthas.aliyun.com/en/doc/auth.html#configure-username-and-password
Response r = arthasApiClient.post(ARTHAS_API_PATH, body);
String result = assertResponseStatus(200, r);
assertJsonContains(result, "state");
Expand Down
3 changes: 1 addition & 2 deletions hugegraph-server/hugegraph-test/src/main/java/org/apache/hugegraph/api/BaseApiTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -139,8 +139,7 @@ public Response get(String path, String id) {
return this.target.path(path).path(id).request().get();
}

public Response get(String path,
MultivaluedMap<String, Object> headers) {
public Response get(String path, MultivaluedMap<String, Object> headers) {
return this.target.path(path).request().headers(headers).get();
}

Expand Down
Loading
Loading