bitflicker64 opened a new pull request, #3177:
URL: https://github.com/apache/hugegraph/pull/3177
## Purpose
Replaces #2466 by @SunnyBoy-WYH (the head branch lives on a personal fork
and now conflicts with master). Fixes #2468.
The slow query log has printed `body=null` since #2347 commented out the
body capture added in #2327, because reading the body broke gzip batch imports
from hugegraph-loader. The TODO left in `AccessLogFilter` also asked for the
client IP.
## Changes
- `AccessLogFilter` now also runs as a (post-matching) request filter and
keeps a bounded preview of the request body for POST/PUT requests on slow-log
paths (`needRecordLog`). It reads at most `log.slow_query_body_limit` bytes (+1
to detect truncation) and replays them in front of the untouched remainder of
the entity stream with a `SequenceInputStream`, so the resource still receives
the whole body and per-request memory is bounded by the limit, not by the body
size.
- Nothing is read when the slow query log is off
(`log.slow_query_threshold=0`), when the limit is 0, for GET/DELETE, or for
paths that are never slow-logged. Loader batch imports (`.../vertices/batch`,
`.../edges/batch`) are not slow-log paths, so their entity stream is never
touched, gzip or not.
- When the matched resource method carries `@Decompress`
(`DecompressInterceptor` runs later as a ReaderInterceptor), the entity is not
read and the log shows `<encoded>`. The decision is based on the resource, not
on the `Content-Encoding` header, so a client cannot opt out of body recording
by sending a header, and no header value is echoed into the log.
- The preview is decoded with a `CharsetDecoder`, so a multi-byte character
cut by the limit is dropped rather than logged as U+FFFD. A truncated preview
ends with `...`.
- Path, query and body are CR/LF-escaped when the line is written, so one
request is one log line. Before this change `%0A` in a query string produced a
raw line break in `slow_query.log`.
- Client IP comes from the Grizzly `Request` peer address via
`Provider<Request>`, the same pattern `AuthenticationFilter` uses, with
`<unknown_ip>` as fallback. No DNS lookup on the log path.
- New option `log.slow_query_body_limit` (bytes, default 512, 0 disables
body recording, max 1 MiB). This answers the open question in #2466 about
making the 512 limit configurable and gives operators a switch when
gremlin/cypher bodies must not reach the log. The option description and
`rest-server.properties` say that the prefix is written as-is and may contain
sensitive literals. Body recording stays on by default, matching #2327, #2347
and #2466; note that the same file already receives full GET query strings
(`/gremlin?gremlin=...`) today.
- Log line: `[Slow Query] ip=..., execTime=...ms, method=..., path=...,
query=..., body=...`
- The unused `PathFilter.REQUEST_PARAMS_JSON` constant is removed;
`PathFilter` is otherwise untouched.
## Review threads from #2466
- javeme (naming, cut large bodies, PUT/DELETE, local variables,
`<unknown_ip>`): bodies are cut at the configured limit, PUT is handled, the
log call uses local variables, `<unknown_ip>` is the placeholder. DELETE is
left out on purpose: every `@DELETE` endpoint takes path or query parameters
only, so there is no body to record, and Copilot asked to drop it as well.
- javeme (GET and `REQUEST_PARAMS_JSON`): the original stored
`getPathParameters()` from a `@PreMatching` filter, before matching happens, so
it was always empty. GET requests log `query=` and the path, which carry the
parameters already.
- Copilot and VGalaxies (High, memory): the body is no longer read in full
before truncation. Reads are bounded and gated.
- Copilot and VGalaxies (Medium, client IP): `getRemoteAddr()` replaces
`InetAddress.getByName(uri.getHost())`, which resolved the server host name and
did a blocking DNS lookup on every slow query.
- VGalaxies (forwarded headers): not added. Trusting `X-Forwarded-For`
without a trusted-proxy list lets any client choose the logged IP. That needs
its own option and is left for a follow-up.
## Verification
- `AccessLogFilterTest` (new, 18 cases, added to `UnitTestSuite`): slow-log
path selection, bounded capture and full replay, truncation mark, exact-limit
body, multi-byte cut, CR/LF kept in the preview, empty body, `Content-Encoding`
header ignored, skips (log off, limit 0, GET/DELETE, batch import on a
`@Decompress` resource, `@Decompress` resource on a slow-log path), and the log
line (client IP, GET query, one line with CR/LF in path/query/body,
`<unknown_ip>`, fast requests, log off). The test swaps the module's log4j2
logger for the class under test and restores it, so it passes when run alone as
well as inside the suite.
- `mvn test -pl hugegraph-server/hugegraph-test -am -P unit-test` on JDK 11
(Linux x86_64): `UnitTestSuite` 679 tests, 0 failures, 0 errors, 1 skipped
(pre-existing `RocksDBSessionTest.testMergeWithStringList`).
`AccessLogFilterTest` also passes when run alone and when a single method is
run alone.
- Manual run of the packaged server (rocksdb, `log.slow_query_threshold=1`,
`log.slow_query_body_limit=64`):
- gzip batch POST and PUT to `/graphs/hugegraph/graph/vertices/batch`
return 201/200 (loader path, stream untouched, not logged)
- a 5000 byte gremlin body (Content-Length and chunked) returns the value
computed from its last bytes, the log shows the first 64 bytes plus `...`
- a CJK body cut mid-character logs cleanly, GET logs `query=limit=2,
body=null`, cypher logs the statement, a pretty-printed body with CR/LF is one
log line, a query string with `%0A` is one log line
- a request from another host logs its peer address (`ip=100.123.70.122`),
local ones log `ip=127.0.0.1`
- a `Content-Encoding: gzip` header on a plain `/gremlin` body neither
hides the body nor changes the result
- `log.slow_query_body_limit=0` logs `body=null`,
`log.slow_query_threshold=0` logs nothing, no exceptions from the filter
## Notes
- `path=` in the line still comes from the existing `normalizePath()` used
for metric names, which prints for example
`graphspaces/graphspace/graphs/hugegraph/graph/vertices`. Unchanged here.
- `log.slow_query_body_limit` is listed in `rest-server.properties`;
hugegraph-doc needs a line for it.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
