[konlue]

Fixes #7643

Modifications

• AbstractShenyuPlugin: the two unconditional INFO lines in defaultMatchSelector and defaultMatchRule are removed; match-success diagnostics stay in printLog, which sits behind the explicit logged/loged switch and carries the selector or rule name.
• ShenyuWebsocketClient#handleResult: the full payload moves to DEBUG; INFO carries only groupType / eventType / namespaceId / payload size in UTF-8 bytes, logged after parsing succeeds.

Two commits: the change itself, and a self-review follow-up (byte-accurate payload size instead of String.length(), plus test-helper cleanup).

Why the two match lines are removed rather than demoted

printLog already sits behind the explicit setting — it checks selectorData.getLogged() and ruleData.getLoged(), and it carries the selector or rule name. defaultMatchSelector and defaultMatchRule logged the same event a second time with no switch at all, so a user who had not enabled logging still received one INFO line per matched request, while the same request arriving through the cache path stayed quiet.

Both lines were added by the same refactor that introduced printLog (#4578), and printLog runs on the result of both methods unconditionally afterwards, so the two lines described an event that was already covered. Demoting them to DEBUG would have left two DEBUG lines for a single match — the duplication the scope asks to avoid — so they are removed. The surviving INFO line is the one that names the selector or rule, which is the more useful of the two.

This also matches the "or the explicit matching-log setting" half of the scope: the diagnostics now live in exactly one place and that place is gated.

Why handleResult moves its metadata line after parsing

The payload used to be logged before GsonUtils.fromJson, so a frame that turned out to be malformed was written out in full before the catch discarded it. groupType is needed for the new INFO line and is only available once parsing has succeeded, so the line is emitted after the parse. Consequence: a malformed frame produces only its WARN, which is the intended outcome — an unparseable frame should not reach INFO at all. The size is counted as UTF-8 bytes rather than String.length(), which would count UTF-16 chars and understate non-ASCII configuration content.

Volume

The two removed lines cost 51 and 44 bytes of message text per match (95 bytes before logback's own line prefix) for a default plugin name. That figure is derived from the message constants, not measured.

What I cannot give you is the measured side of the comparison — a before/after rate, an allocation rate, a CPU share or a p99. The repo has no JMH infrastructure and I don't have a bare-metal Linux box, so a number I produced here would reflect one laptop rather than the workload you care about. If that measurement is the gate for this one, I understand it, and the change is small enough to re-measure wherever the baseline infrastructure lands.

Tests

AbstractShenyuPluginTest gains five cases:

• defaultStrategySelectorMatchShouldNotLogWhenLoggingDisabled / ...RuleMatch... — no selector or rule line reaches INFO when the flag is false.
• defaultStrategySelectorMatchShouldLogExactlyOnceWhenLoggingEnabled / ...Rule... — exactly one line reaches INFO when the flag is true, and it is the name-carrying one. These are what pin the de-duplication.
• defaultStrategyMatchLogsShouldNotChangeRoutingResults — doExecute still receives the same selector and rule.

Removing the two getLogged() / getLoged() guards makes the disabled cases fail, so the tests do pin the behaviour rather than merely passing alongside it.

The cases use a small LogCapture helper (a logback ListAppender wrapper that attaches to one logger and detaches on close), so no logging state leaks between tests.

logback-classic is added with test scope, matching shenyu-plugin-wasm-api and shenyu-sync-data-http — this module had only slf4j-api on the test classpath, so there was no logging implementation to assert against.

ShenyuWebsocketClientTest already exercises the handleResult paths (malformed frame, unknown group type, unknown event type) and passes unchanged, which is the evidence that the behaviour is the same and only the level and message content moved.

Scope

Log output only. No new configuration flag, no change to matching or routing logic, and no getLoged() spelling change — that is #7589's scope, keeping this PR clean.

Verifying this change

shenyu-plugin-base:         Tests run: 239, Failures: 0, Errors: 0, Skipped: 0
shenyu-sync-data-websocket: Tests run: 120, Failures: 0, Errors: 0, Skipped: 0
maven-checkstyle-plugin:    0 Checkstyle violations
Rat check:                  Unapproved: 0

(after the self-review follow-up commit: AbstractShenyuPluginTest 13/13 and ShenyuWebsocketClientTest 34/34 re-run green)

[Aias00]

Summary

Good log-volume reduction that keeps the useful, opt-in logging intact.

I initially worried the new tests asserting a "selector success match" / "rule success match" line contradicted the removal of the unconditional from default strategy logs — but I confirmed against the code: master already has the logged/loged-gated lines (if (selectorData.getLogged()) ..., if (ruleData.getLoged()) ...), and this PR only removes the unconditional duplicate lines. So the behaviour becomes:

• logged=false: nothing logged (was: one unconditional line) — volume reduced.
• logged=true: exactly one conditional line (was: two lines) — redundancy removed.

The five new tests cover both flag states plus a routing-unaffected assertion, and LogCapture is a tidy test helper scoped to the AbstractShenyuPlugin logger. The ShenyuWebsocketClient.handleResult change moves the raw payload dump from INFO to LogUtils.debug and adds a structured summary line, which is the right direction for config-sync volume.

CI note (not blocking)

The current run shows several build (shenyu-integrated-test-*) jobs (http, grpc, combination, apache-dubbo) plus build-docker-images / e2e in a failed state, while pr_build, Analyze (java), rat_check, changes, and the k8s-ingress-* builds all pass. Since the changed modules (shenyu-plugin-base, shenyu-sync-data-websocket) compile cleanly and the failing jobs are compose/e2e suites unrelated to the diff, these look like stale/infrastructure failures. Please rerun the failed jobs to get a clean signal before merge, but I'm not blocking on them.

Non-blocking

• LogCapture casts LoggerFactory.getLogger(type) to logback's Logger and uses ListAppender; it is fine for the current logback backend but couples the test to the concrete logging implementation. Acceptable.

Approving.

[Aias00]

Review — APPROVE

Clean, tightly-scoped log-volume reduction for #7643. The PR body is unusually thorough and — unusually — almost every claim in it checks out against the source. I verified the root cause, the test mechanism, and (by re-adding the deleted lines) that the new tests genuinely pin the behaviour. No blocking issues.

✅ Root cause and fix location confirmed

AbstractShenyuPlugin logged each match twice, once ungated and once gated:

Site	Gate	Message
defaultMatchSelector (:291, deleted)	none	SHENYU selector match success from default strategy
defaultMatchRule (:310, deleted)	none	SHENYU rule match path from default strategy
printLog(SelectorData, …) (:334-338)	selectorData.getLogged()	SHENYU selector success match , selector name :{}
printLog(RuleData, …) (:346-350)	ruleData.getLoged()	SHENYU rule success match , rule name :{}

printLog is invoked at :103 and :131 on the very same objects, so the two deleted lines described an event that was already covered — and a user who never enabled logging still received one INFO line per matched request, while the same request arriving via the cache path stayed quiet. Removing the ungated duplicates leaves exactly one gated emitter. Verified by reading head source.

✅ The capture mechanism is sound

LogUtils.info(logger, format, objects) (LogUtils.java:84-88) delegates straight to logger.info(...), so the deleted lines and the surviving printLog lines all go through LoggerFactory.getLogger(AbstractShenyuPlugin.class) — precisely the logger LogCapture.attach(AbstractShenyuPlugin.class) binds to. ListAppender is started with the logger's context and detached + stopped in close(), and every test uses try-with-resources, so no state leaks.

✅ The tests really do exercise the default-strategy path

• @BeforeEach/@AfterEach clear both BaseDataCache and MatchDataCache (cleanSelectorData() + cleanRuleDataData()), so obtainSelectorDataCacheIfEnabled / obtainRuleDataCacheIfEnabled return null on the first execute and both defaultMatchSelector and defaultMatchRule are genuinely invoked.
• SelectorData.continued defaults to Boolean.TRUE (SelectorData.java:49) behind a null-safe getter (:196-199), so control flows past the selector into the rule path rather than short-circuiting into defaultRuleData.
• Every new test sets logged/loged explicitly, which also avoids the NPE that printLog's unboxing would otherwise hit.

✅ The new tests are load-bearing — proven by reverting the fix locally

I ran the suite on the head tree, then re-added exactly the two deleted statements (and the LogUtils import) to simulate master, and re-ran:

head tree:            Tests run: 13, Failures: 0, Errors: 0
two lines re-added:   Tests run: 13, Failures: 4, Errors: 0
  defaultStrategySelectorMatchShouldNotLogWhenLoggingDisabled
      -> got: [SHENYU selector match success from default strategy, ...]
  defaultStrategyRuleMatchShouldNotLogWhenLoggingDisabled
      -> got: [..., SHENYU rule match path from default strategy]
  defaultStrategySelectorMatchShouldLogExactlyOnceWhenLoggingEnabled
      -> expected 1 selector line, got 2
  defaultStrategyRuleMatchShouldLogExactlyOnceWhenLoggingEnabled
      -> expected 1 rule line, got 2

Four of the five new cases fail without the fix, so the de-duplication is pinned rather than merely accompanied by tests. The fifth (defaultStrategyMatchLogsShouldNotChangeRoutingResults) is a routing-invariance guard and correctly passes either way.

✅ The #4578 attribution is literally true

gh pr diff 4578 adds LogUtils.info(LOG, "{} selector match success from default strategy", named()) and LOG.info("{} rule match path from default strategy", named()) in the same hunk series that introduces the typed printLog(SelectorData, …) / printLog(RuleData, …) overloads. The PR body's history is accurate.

✅ handleResult change is correct

• Payload moves to DEBUG via LogUtils.debug (:441), so the full frame is still recoverable when debug is on.
• The new INFO line (:452-454) is emitted after the JSON parse succeeds and before group/event resolution, carrying groupType / eventType / namespaceId / size.
• result.getBytes(StandardCharsets.UTF_8).length is the correct byte count (the self-review follow-up the PR mentions) rather than String.length(), which would understate non-ASCII configuration content.
• WebsocketData.getGroupType() / getEventType() / getNamespaceId() all exist (WebsocketData.java:110/130/80), so it compiles.
• A malformed frame now produces only its WARN (:449) and never reaches INFO — exactly as claimed.
• Existing ShenyuWebsocketClientTest already drives onMessage with valid frames, malformed JSON, unknown group type and unknown event type (:122-184), i.e. the control-flow paths through handleResult, and passes unchanged.

✅ Test counts are real

Local run (offline, -pl <both modules> -am): shenyu-plugin-base 239/239, shenyu-sync-data-websocket 120/120, 0 failures, 0 errors. CI pr_build reports the identical numbers plus AbstractShenyuPluginTest 13/13 and 0 Checkstyle violations.

logback-classic at test scope is safe: the module ships no logback.xml / logback-test.xml, so logback falls back to BasicConfigurator (root at DEBUG) and isInfoEnabled() is true; test scope is non-transitive, so no downstream module is affected.

⚠️ CI attribution — all 12 failures are Maven Central flakes

The job that matters passed; everything red is infrastructure:

Job	Real cause
build-docker-images (20s)	Plugin org.jacoco:jacoco-maven-plugin:0.8.12 ... could not be resolved ... Connection reset
build (shenyu-integrated-test-*) ×10	Could not transfer artifact org.codehaus.groovy:groovy-bom:pom:3.0.10 from/to central: status code: 502 Bad Gateway; the job log also shows maven cache is not found, i.e. no cache restore, so every artifact was fetched fresh and fully exposed to Central hiccups. Several of these are conclusion=cancelled (fail-fast siblings).
e2e (3s)	fail-fast aggregator; e2e-storage / e2e-case were skipped because build-docker-images failed

Meanwhile pr_build — which runs mvn -pl shenyu-plugin/shenyu-plugin-base,shenyu-sync-data-center/shenyu-sync-data-websocket -am, i.e. exactly the two changed modules — passed with all tests green, as did Analyze (java), CodeQL, rat_check, check-license-header, changes and scope.

📝 Non-blocking observations

1. LogCapture depends on the logger's effective level. It adds an appender but never sets a level. The module currently has no logback config, so root defaults to DEBUG and INFO passes. If a future logback-test.xml raises the threshold above INFO, the two negative assertions would pass vacuously while the positive ones fail loudly. A logger.setLevel(Level.INFO) in attach(...), or an assertion that at least one event was captured, would make the negative cases robust.

2. The handleResult log-level change has no direct test. The PR is honest about this, and the control flow is covered, but nothing pins the new INFO content or the DEBUG demotion. Since the whole point is volume reduction, a LogCapture-style assertion on ShenyuWebsocketClient (INFO carries metadata but not the payload; a malformed frame emits no INFO) would pin it — the helper already exists and could be lifted into a shared test utility.

3. Minor test-shape looseness: defaultStrategySelectorMatchShouldNotLogWhenLoggingDisabled sets selectorData.setLogged(false) but leaves ruleData.loged at the setUp() default of true, so a rule INFO line is still emitted (visible in the revert run's failure output as SHENYU rule success match , rule name :null). The assertion only filters on "selector", so it is correct, but the captured list would surprise a reader. Setting ruleData.setLoged(false) as well would make the case self-contained.

4. The volume figures are derived, not measured — the PR states this plainly ("51 and 44 bytes ... derived from the message constants, not measured"), which is the right call. Just worth not quoting those numbers as measurements in release notes.

Verdict

APPROVE. Correct root cause, minimal diff, no behavioural change to matching or routing, and tests I verified actually fail without the fix. The four notes above are optional polish.

[yuluo-yx]

/retest