[
https://issues.apache.org/jira/browse/CASSSIDECAR-496?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Jon Haddad updated CASSSIDECAR-496:
-----------------------------------
Description:
{\{HttpServerOptionsProvider}} line 58 hardcodes \{{setLogActivity(true)}},
installing
Netty's \{{LoggingHandler}} on every HTTP connection with no way to disable it.
The only
hardcoded option in a method where everything else reads from
\{{SidecarConfiguration}}.
On a 3-node cluster running the \{{ghcr.io/apache/cassandra-sidecar}} image
this produced
8.6 million log lines in one hour, roughly 96% of all log volume, because
{\{ByteBufUtil.appendPrettyHexDump}} turns a single 95,504-byte response into
about 6,000
lines. The dumps include request and response bodies in cleartext, and since
schema
endpoints return DDL, CQL ends up in the logs too. It only fires when the
process starts
without \{{logback.configurationFile}} — supplied solely by the Gradle start
scripts — so a
directly-launched jar falls back to logback's default of root DEBUG and dumps
everything;
{\{server/src/test/resources/logback-test.xml}} pins \{{LoggingHandler}} to
info, which is
why CI never caught it.
Fix: make it configurable via \{{ServiceConfiguration}}, defaulting
to false, following the existing \{{tcp_keep_alive}} pattern, plus
{\{<logger name="io.netty" level="INFO"/>}} in \{{conf/logback.xml}} as defence
in depth.
was:
{\{HttpServerOptionsProvider}} hardcodes \{{setLogActivity(true)}}, which
installs Netty's
{\{LoggingHandler}} on every connection and hex-dumps every buffer in both
directions.
There is no way to turn it off. Every other option in that method is read from
{\{SidecarConfiguration}}; this is the only hardcoded one.
{code:java}
//
server/src/main/java/org/apache/cassandra/sidecar/server/HttpServerOptionsProvider.java:58
HttpServerOptions options = new HttpServerOptions().setLogActivity(true);
{code}
Measured on a 3-node cluster running the \{{ghcr.io/apache/cassandra-sidecar}}
image:
8.6 million log lines in one hour across three sidecar pods, roughly 96% of all
log
volume in the cluster (the next largest stream was 357k). A single 95,504-byte
response
becomes about 6,000 log lines, since \{{ByteBufUtil.appendPrettyHexDump}} emits
16 bytes
per line. Both the REST API and CQL traffic are dumped.
The ASCII column contains readable request and response bodies, so payloads are
logged
in cleartext:
{noformat}
|00016260| 66 61 63 74 6f 72 27 3a 20 27 31 27 20 7d 20 41 |factor': '1' } A|
|00016270| 4e 44 20 44 55 52 41 42 4c 45 5f 57 52 49 54 45 |ND DURABLE_WRITE|
|00016280| 53 20 3d 20 74 72 75 65 3b 5c 6e 5c 6e 43 52 45 |S = true;\n\nCRE|
{noformat}
Operators collecting container stdout are shipping request payloads to their
log store
without opting in.
Two conditions have to hold for this to fire, and containers satisfy both. The
hardcoded call always arms wire logging. Then \{{logback.configurationFile}} is
supplied
Two conditions have to hold for this to fire, and containers satisfy both. The
hardcoded call always arms wire logging. Then \{{logback.configurationFile}} is
supplied
only by the Gradle-generated start scripts (\{{build.gradle}} lines 202 and
217), so a
jar launched directly gets no logback config and falls back to logback's
default of root
DEBUG to ConsoleAppender, which fires the dumps. The shipped
\{{conf/logback.xml}} sets
{\{<root level="INFO">}}, so a Sidecar started via the start script does not
show this.
Proposed fix: make log activity configurable through \{{ServiceConfiguration}}
defaulting
to false, following the existing \{{tcp_keep_alive}} pattern; add
{\{<logger name="io.netty" level="INFO"/>}} to \{{conf/logback.xml}} as defence
in depth;
and fix the \{{SIDECAR_DEBUG}} appender, which is commented "all levels" but
carries an
INFO \{{ThresholdFilter}}, making \{{debug.log}} a near-duplicate of
\{{system.log}} with a
larger cap.
The call dates to the initial commit (Feb 2019).
> Sidecar unconditionally enables Netty wire logging, flooding logs with hex
> dumps of request payloads
> ------------------------------------------------------------------------------------------------------
>
> Key: CASSSIDECAR-496
> URL: https://issues.apache.org/jira/browse/CASSSIDECAR-496
> Project: Sidecar for Apache Cassandra
> Issue Type: Bug
> Components: Configuration
> Reporter: Jon Haddad
> Priority: Major
>
> {\{HttpServerOptionsProvider}} line 58 hardcodes \{{setLogActivity(true)}},
> installing
> Netty's \{{LoggingHandler}} on every HTTP connection with no way to disable
> it. The only
> hardcoded option in a method where everything else reads from
> \{{SidecarConfiguration}}.
> On a 3-node cluster running the \{{ghcr.io/apache/cassandra-sidecar}} image
> this produced
> 8.6 million log lines in one hour, roughly 96% of all log volume, because
> {\{ByteBufUtil.appendPrettyHexDump}} turns a single 95,504-byte response into
> about 6,000
> lines. The dumps include request and response bodies in cleartext, and since
> schema
> endpoints return DDL, CQL ends up in the logs too. It only fires when the
> process starts
> without \{{logback.configurationFile}} — supplied solely by the Gradle start
> scripts — so a
> directly-launched jar falls back to logback's default of root DEBUG and dumps
> everything;
> {\{server/src/test/resources/logback-test.xml}} pins \{{LoggingHandler}} to
> info, which is
> why CI never caught it.
> Fix: make it configurable via \{{ServiceConfiguration}}, defaulting
> to false, following the existing \{{tcp_keep_alive}} pattern, plus
> {\{<logger name="io.netty" level="INFO"/>}} in \{{conf/logback.xml}} as
> defence in depth.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
