Skip to content

fix(server): fix server slow log, support loader import & client IP - #2466

Open
SunnyBoy-WYH wants to merge 3 commits into
apache:masterfrom
SunnyBoy-WYH:slow-log-fix
Open

fix(server): fix server slow log, support loader import & client IP#2466
SunnyBoy-WYH wants to merge 3 commits into
apache:masterfrom
SunnyBoy-WYH:slow-log-fix

Conversation

@SunnyBoy-WYH

@SunnyBoy-WYH SunnyBoy-WYH commented Mar 1, 2024

Copy link
Copy Markdown
Contributor

fix #2468

we support slow log before ,but it cause bug when loader batch import data, the feat PR see #2327

and later we downgrade it ,see pr : #2347

the bug due to:

  1. we need get post body from req, and we need set it back to request, so it changed.
  2. the loader request use the "GZIP" header, after get post body, server cant read it

so we ready to resolve it , use BufferedInputStream to cache the stream:

` BufferedInputStream bufferedStream = new BufferedInputStream(context.getEntityStream());

        bufferedStream.mark(Integer.MAX_VALUE);

        context.setProperty(REQUEST_PARAMS_JSON,
                            IOUtils.toString(bufferedStream, Charsets.toCharset(CHARSET)));

        bufferedStream.reset();

        context.setEntityStream(bufferedStream);

`
case:
[Slow Query] ip=127.0.0.1 execTime=22ms, body={"gremlin":"hugegraph.backendStoreFeatures() .supportsSharedStorage();","bindings":{},"language":"gremlin-groovy","aliases":{"g":"__g_hugegraph"}}, method=POST, path=/gremlin, query=null

and then i test it
image

image

@dosubot dosubot Bot added size:M This PR changes 30-99 lines, ignoring generated files. api Changes of API bug Something isn't working labels Mar 1, 2024
@codecov

codecov Bot commented Mar 1, 2024

Copy link
Copy Markdown

Codecov Report

Attention: Patch coverage is 92.30769% with 2 lines in your changes missing coverage. Please review.

Project coverage is 49.91%. Comparing base (506850c) to head (071943c).
Report is 1 commits behind head on master.

Files Patch % Lines
...g/apache/hugegraph/api/filter/AccessLogFilter.java 77.77% 2 Missing ⚠️
Additional details and impacted files
@@             Coverage Diff              @@
##             master    #2466      +/-   ##
============================================
- Coverage     56.94%   49.91%   -7.03%     
+ Complexity      827      741      -86     
============================================
  Files           612      612              
  Lines         49672    49697      +25     
  Branches       6681     6685       +4     
============================================
- Hits          28284    24806    -3478     
- Misses        18572    22317    +3745     
+ Partials       2816     2574     -242     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.


// TODO: temporarily comment it to fix loader bug, handle it later
/*// record the request json
private void recordRequestJson(ContainerRequestContext context) throws IOException {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

prefer collectRequestParams(), seems 'record' means output to log

bufferedStream.mark(Integer.MAX_VALUE);

context.setProperty(REQUEST_PARAMS_JSON,
IOUtils.toString(bufferedStream, Charsets.toCharset(CHARSET)));

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

maybe it's very large for batch-write, can we cut part of the content?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

maybe we can cut the special length? like 512?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

or we will make it can be config? like 512/1024/2048 and default will be 512? @imbajin @liuxiaocs7 @VGalaxies

.getPathParameters();
requestParamsJson = pathParameters.toString();
context.setProperty(REQUEST_PARAMS_JSON,
context.getUriInfo().getPathParameters().toString());

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

can we also add all other branchs like PUT/DELETE

LOG.info("[Slow Query] ip={} execTime={}ms, body={}, method={}, path={}, query={}",
getClientIP(requestContext), executeTime,
requestContext.getProperty(REQUEST_PARAMS_JSON), method, path,
uri.getQuery());

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

are they repeated when GET: uri.getQuery() and REQUEST_PARAMS_JSON

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

for GET , REQUEST_PARAMS_JSON will extract the id info from /example/{id} ; uri.getQuery() will extract id=1 from http://example.com/resource?id=1

@imbajin
imbajin requested review from imbajin and javeme June 24, 2024 16:04
executeTime, null, method, path, uri.getQuery());

LOG.info("[Slow Query] ip={} execTime={}ms, body={}, method={}, path={}, query={}",
getClientIP(requestContext), executeTime,

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

prefer this style: defining a local var for better readability:
for both: getClientIP and REQUEST_PARAMS_JSON.

private String getClientIP(ContainerRequestContext requestContext) {
try {
UriInfo uriInfo = requestContext.getUriInfo();
String host = uriInfo.getRequestUri().getHost();

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

return here if host is an ip or empty?

String host = uriInfo.getRequestUri().getHost();
return InetAddress.getByName(host).getHostAddress();
} catch (UnknownHostException e) {
return "unknown";

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

prefer "<unknown_ip>"

.getPathParameters();
requestParamsJson = pathParameters.toString();
context.setProperty(REQUEST_PARAMS_JSON,
context.getUriInfo().getPathParameters().toString());

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

can we also add all other branchs like PUT/DELETE -- seems still missing

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Pull request overview

Restores capture of request bodies in PathFilter (previously commented out because it broke loader GZIP batch imports) using a BufferedInputStream with mark/reset, and extends AccessLogFilter's [Slow Query] log line to include the request body and a client IP.

Changes:

  • PathFilter now captures request bodies for POST/PUT/DELETE via a buffered, mark/reset-able stream, truncating to 512 chars, and stores it as REQUEST_PARAMS_JSON.
  • AccessLogFilter includes the captured body and a "client IP" (derived from the request URI host) in the slow-query log line.
  • A new constant MAX_SLOW_LOG_BODY_LENGTH = 512 is introduced in PathFilter.

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated 2 comments.

File Description
hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/PathFilter.java Re-enables request-body capture using BufferedInputStream.mark/reset so the entity stream can be replayed by downstream readers (e.g. GZIP-decoded loader batches), with a 512-char truncation.
hugegraph-server/hugegraph-api/src/main/java/org/apache/hugegraph/api/filter/AccessLogFilter.java Adds body and ip= fields to the slow-query log line, with a new getClientIP helper resolving an address from the request URI host.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines +137 to +145
private String getClientIP(ContainerRequestContext requestContext) {
try {
UriInfo uriInfo = requestContext.getUriInfo();
String host = uriInfo.getRequestUri().getHost();
return InetAddress.getByName(host).getHostAddress();
} catch (UnknownHostException e) {
return "unknown";
}
}
Comment on lines +55 to +69
if (method.equals(HttpMethod.POST) || method.equals(HttpMethod.PUT) ||
method.equals(HttpMethod.DELETE)) {
BufferedInputStream bufferedStream = new BufferedInputStream(context.getEntityStream());

bufferedStream.mark(Integer.MAX_VALUE);
String body = IOUtils.toString(bufferedStream,
Charsets.toCharset(CHARSET));
body = body.length() > MAX_SLOW_LOG_BODY_LENGTH ?
body.substring(0, MAX_SLOW_LOG_BODY_LENGTH) : body;

context.setProperty(REQUEST_PARAMS_JSON, body);

bufferedStream.reset();

context.setEntityStream(bufferedStream);

@VGalaxies VGalaxies left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Review summary

  • Blocking: yes
  • Summary: The PR compiles, but it adds request-body logging in a way that can buffer large loader/batch imports in memory and logs the server host instead of the client IP.
  • Evidence:
    • git diff origin/master...HEAD, mvn -pl hugegraph-server/hugegraph-api -DskipTests compile passed
    • no focused filter tests found

BufferedInputStream bufferedStream = new BufferedInputStream(context.getEntityStream());

bufferedStream.mark(Integer.MAX_VALUE);
String body = IOUtils.toString(bufferedStream,

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

High: Slow-log capture reads full request bodies before truncating

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

Evidence

  • collectRequestParams() wraps every POST/PUT/DELETE entity stream, calls bufferedStream.mark(Integer.MAX_VALUE), then IOUtils.toString(bufferedStream, ...), and only truncates the resulting String afterward. Batch loader paths such as VertexAPI/EdgeAPI batch imports are POST/PUT request bodies and can be large.

Impact

  • Large loader imports are fully read and retained by the filter before the resource method runs, causing avoidable latency and possible heap exhaustion. The 512-byte limit does not limit memory usage because truncation happens after the full body is loaded.

Requested fix

  • Read at most MAX_SLOW_LOG_BODY_LENGTH bytes/chars for the log preview and replay the consumed prefix plus the remaining original stream, or skip body capture for large/batch/import endpoints and non-slow-loggable paths.

private String getClientIP(ContainerRequestContext requestContext) {
try {
UriInfo uriInfo = requestContext.getUriInfo();
String host = uriInfo.getRequestUri().getHost();

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Medium: Slow logs resolve the request URI host, not the client IP

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

Evidence

  • getClientIP() uses requestContext.getUriInfo().getRequestUri().getHost(), which is the host in the server URL requested by the client. Existing surrounding code in AuthenticationFilter uses Request.getRemoteAddr() for the actual peer address.

Impact

  • Slow-query logs will attribute requests to the HugeGraph server/listener hostname or proxy target instead of the originating client, making the new client-IP field misleading.

Requested fix

  • Inject/use the servlet request and log getRemoteAddr() or a validated forwarded header only when HugeGraph is behind a trusted proxy.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

api Changes of API bug Something isn't working size:M This PR changes 30-99 lines, ignoring generated files.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[Bug] server slow log, support loader import & client IP

4 participants