feat: add DEBUG-level logs for SPI extension loading in ExtensionLoader by uuuyuqi · Pull Request #16231 · apache/dubbo

uuuyuqi · 2026-04-20T07:54:54Z

What is the purpose of the change?

Add DEBUG-level observability to ExtensionLoader for diagnosing SPI extension loading issues without external tools.

Motivation: In environments with many internal SPI extensions across different versions, along with custom class-isolation frameworks, dependency conflicts or misconfiguration can cause extensions to be silently skipped or loaded with unexpected wrapper chains. Currently the only way to observe this is via Arthas or remote debugging, which has high operational cost. With these DEBUG logs, users can simply enable DEBUG level for org.apache.dubbo.common.extension.ExtensionLoader to get full visibility into the SPI loading process.

Changes:

Log when extension class scanning starts and finishes (with timing, loaded names, adaptive class, wrappers)
Log each SPI class loaded (adaptive/wrapper/extension), including source resource URL
Log when an extension instance is created, including applied wrapper classes
Log when an extension class is skipped due to missing @Activate(onClass=...) dependencies, with the specific missing class names
Refactor loadClassIfActive to findMissingOnClass to return missing class names for diagnostic output

All logs are guarded by isDebugEnabled(), no performance impact in production.

Fixes #16230

Checklist

Make sure there is a GitHub_issue field for the change.
Write a pull request description that is detailed enough to understand what the pull request does, how, and why.
Write necessary unit-test to verify your logic correction.
Make sure GitHub actions can pass.

codecov-commenter · 2026-04-20T08:38:18Z

Codecov Report

❌ Patch coverage is 95.08197% with 3 lines in your changes missing coverage. Please review.
✅ Project coverage is 60.80%. Comparing base (21bdf49) to head (b9138f3).
⚠️ Report is 10 commits behind head on 3.3.

Files with missing lines	Patch %	Lines
...apache/dubbo/common/extension/ExtensionLoader.java	95.00%	0 Missing and 3 partials ⚠️

Additional details and impacted files

@@            Coverage Diff            @@
##                3.3   #16231   +/-   ##
=========================================
  Coverage     60.80%   60.80%           
- Complexity    11759    11779   +20     
=========================================
  Files          1953     1953           
  Lines         89186    89238   +52     
  Branches      13454    13472   +18     
=========================================
+ Hits          54227    54259   +32     
- Misses        29391    29403   +12     
- Partials       5568     5576    +8

Flag	Coverage Δ
integration-tests-java21	`32.21% <93.44%> (+0.10%)`	⬆️
integration-tests-java8	`32.22% <93.44%> (-0.02%)`	⬇️
samples-tests-java21	`32.16% <93.44%> (+0.02%)`	⬆️
samples-tests-java8	`29.90% <93.44%> (+0.14%)`	⬆️
unit-tests-java11	`59.03% <83.60%> (+0.02%)`	⬆️
unit-tests-java17	`58.54% <83.60%> (+0.04%)`	⬆️
unit-tests-java21	`58.54% <83.60%> (+0.04%)`	⬆️
unit-tests-java25	`58.47% <83.60%> (+0.01%)`	⬆️
unit-tests-java8	`59.01% <83.60%> (+<0.01%)`	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

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

🚀 New features to boost your workflow:

❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

zrlw

LGTM

uuuyuqi · 2026-04-22T08:46:26Z

Is there anything else needed from my side before this PR can be merged?

Copilot

Pull request overview

This PR adds DEBUG-level observability to org.apache.dubbo.common.extension.ExtensionLoader to make SPI extension discovery, class loading, and instance/wrapper creation diagnosable via logs (instead of requiring remote debugging tools).

Changes:

Add DEBUG logs for extension class loading (start/finish with timing, names, adaptive/wrapper info) and per-class load/skip reasons.
Add DEBUG log for extension instance creation, including whether wrapping occurred and which wrappers were applied.
Add a unit test that attaches a Log4j2 appender to validate the new “extension instance loaded” DEBUG log output.

Reviewed changes

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

File	Description
`dubbo-common/src/main/java/org/apache/dubbo/common/extension/ExtensionLoader.java`	Adds DEBUG logging around SPI class loading, inactivity skips (`@Activate(onClass=...)`), and extension instance creation/wrapper application.
`dubbo-common/src/test/java/org/apache/dubbo/common/extension/ExtensionLoaderTest.java`	Adds a Log4j2-based log collector and a new test asserting the DEBUG log emitted when an extension instance is created.

Comments suppressed due to low confidence (1)

dubbo-common/src/main/java/org/apache/dubbo/common/extension/ExtensionLoader.java:792

appliedWrapperClasses is allocated/populated on every wrapped extension creation, even when DEBUG logging is off. To keep overhead effectively zero when DEBUG is disabled, consider only tracking wrapper classes when logger.isDebugEnabled() and otherwise pass an empty list/null into the logging method.

            List<Class<?>> appliedWrapperClasses = Collections.emptyList();
            if (wrap) {
                List<Class<?>> wrapperClassesList = new ArrayList<>();
                if (cachedWrapperClasses != null) {
                    wrapperClassesList.addAll(cachedWrapperClasses);

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

Copilot · 2026-04-24T07:19:07Z

+            LoggerConfig loggerConfig = new LoggerConfig(loggerName, org.apache.logging.log4j.Level.DEBUG, false);
+            loggerConfig.addAppender(appender, org.apache.logging.log4j.Level.DEBUG, null);
+            configuration.addLogger(loggerName, loggerConfig);
+            context.updateLoggers();
+            return new LogCollector(context, configuration, loggerName, loggerConfig, appender);


LogCollector.attach installs a brand-new LoggerConfig for loggerName and close() removes it, which can clobber any pre-existing logger configuration for that name and cause cross-test side effects. Consider capturing the previous LoggerConfig (or using configuration.getLoggerConfig(loggerName) and only adding/removing an appender) and restoring the original level/additivity on close.

Repairing this is not necessary because it is in the test class.

🤖 Generated with [Qoder][https://qoder.com] Change-Id: I9775997a1233f13a1faead1391ee01b743796c6d Co-developed-by: Qoder CLI <noreply@qoder.com>

Refactor logging to only log extension instance loading and timing when debug is enabled.

Copilot

Pull request overview

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

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

Copilot · 2026-04-27T00:54:00Z

+    void test_getExtension_logsDebugWhenExtensionCreated() {
+        try (ExtensionLoaderTestContext<WrappedExt> testContext = createExtensionLoaderTestContext(WrappedExt.class);
+                LogCollector logCollector = LogCollector.attach(ExtensionLoader.class)) {
+            WrappedExt impl1 = testContext.extensionLoader.getExtension("impl1");


This test’s LogCollector only captures Log4j2 output, but ExtensionLoader logs through Dubbo’s LoggerFactory adapter, which is mutable global state and is set to non-log4j2 in other tests (e.g., LoggerFactoryTest, FailsafeErrorTypeAwareLoggerTest). That can make this test order-dependent/flaky because the DEBUG line may never reach Log4j2. Consider setting the logger adapter to log4j2 for the duration of this test (and restoring the previous adapter in close()/finally) before asserting on captured Log4j2 events.

Copilot · 2026-04-27T00:54:01Z

@@ -794,13 +795,15 @@ private T createExtension(String name, boolean wrap) {
                }

                if (CollectionUtils.isNotEmpty(wrapperClassesList)) {
+                    appliedWrapperClasses = new ArrayList<>(wrapperClassesList.size());
                    for (Class<?> wrapperClass : wrapperClassesList) {
                        Wrapper wrapper = wrapperClass.getAnnotation(Wrapper.class);
                        boolean match = (wrapper == null)
                                || ((ArrayUtils.isEmpty(wrapper.matches())
                                                || ArrayUtils.contains(wrapper.matches(), name))
                                        && !ArrayUtils.contains(wrapper.mismatches(), name));
                        if (match) {
+                            appliedWrapperClasses.add(wrapperClass);


appliedWrapperClasses is allocated and populated on every wrapped extension creation, even when DEBUG logging is disabled. This adds extra allocations and per-wrapper work on a hot path and contradicts the stated “no performance impact when DEBUG is off”. Consider only tracking appliedWrapperClasses when logger.isDebugEnabled() (e.g., keep it null otherwise and guard add calls), or reuse the existing wrapperClassesList only when needed for logging.

uuuyuqi · 2026-04-27T01:32:40Z


        if (logger.isDebugEnabled()) {
-            Long costMillis = startNanos != -1 ? (System.nanoTime() - startNanos) / 1_000_000L : null;
+            Long costMillis = (System.nanoTime() - startNanos) / 1_000_000L;


At this point, startNanos might be null, for example, if the application dynamically modifies the log level at runtime. This is quite common in online troubleshooting scenarios. To be on the safe side, it's probably best to assign an initial value of null or -1.

uuuyuqi · 2026-04-27T01:35:20Z

                                        && !ArrayUtils.contains(wrapper.mismatches(), name));
                        if (match) {
-                            appliedWrapperClasses.add(wrapperClass);
+                            if (logger.isDebugEnabled()) {


Dynamically modifying the log level might cause an NPE error. For performance optimization, consider adding a null check.

Removed unused Log4j imports and added preLoggerConfig to LogCollector.

Copilot

Pull request overview

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

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

Copilot

Pull request overview

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

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

…xtensionLoader.java Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

Added a method to retrieve the current logger adapter.

Removed unnecessary blank line in Javadoc comment.

Removed duplicate import statement for 'Prioritized'.

zrlw previously approved these changes Apr 21, 2026

View reviewed changes

zrlw added the status/wait for another approve label Apr 21, 2026

chickenlj requested a review from Copilot April 24, 2026 07:12

Copilot started reviewing on behalf of chickenlj April 24, 2026 07:13 View session

Copilot AI reviewed Apr 24, 2026

View reviewed changes

feat: add debug logs for SPI extension loading in ExtensionLoader

fb8aa51

🤖 Generated with [Qoder][https://qoder.com] Change-Id: I9775997a1233f13a1faead1391ee01b743796c6d Co-developed-by: Qoder CLI <noreply@qoder.com>

uuuyuqi dismissed zrlw’s stale review via fb8aa51 April 24, 2026 07:44

uuuyuqi force-pushed the extensionloader-log branch from 8fc12fd to fb8aa51 Compare April 24, 2026 07:44

zrlw added 2 commits April 26, 2026 22:54

Merge branch '3.3' into extensionloader-log

d662f03

Optimize logging in ExtensionLoader for debug mode

86e4be4

Refactor logging to only log extension instance loading and timing when debug is enabled.

zrlw requested a review from Copilot April 27, 2026 00:49

Copilot AI reviewed Apr 27, 2026

View reviewed changes

Add debug logging for wrapper class processing

6c0e7f8

uuuyuqi commented Apr 27, 2026

View reviewed changes

zrlw added 4 commits April 27, 2026 09:38

Refactor ExtensionLoaderTest by cleaning imports

813d269

Removed unused Log4j imports and added preLoggerConfig to LogCollector.

Add Log4j imports to ExtensionLoaderTest

ada8706

Add preLoggerConfig parameter to LogCollector

bb02b48

Optimize debug logging checks in ExtensionLoader

f559f66

zrlw requested a review from Copilot April 27, 2026 02:10

Copilot started reviewing on behalf of zrlw April 27, 2026 02:10 View session

Copilot AI reviewed Apr 27, 2026

View reviewed changes

Comment thread dubbo-common/src/test/java/org/apache/dubbo/common/extension/ExtensionLoaderTest.java Outdated

Fix logger configuration retrieval in tests

d7efe33

zrlw requested a review from Copilot April 27, 2026 02:25

Copilot started reviewing on behalf of zrlw April 27, 2026 02:25 View session

Copilot AI reviewed Apr 27, 2026

View reviewed changes

Comment thread dubbo-common/src/main/java/org/apache/dubbo/common/extension/ExtensionLoader.java Outdated

zrlw and others added 2 commits April 27, 2026 10:39

Update dubbo-common/src/main/java/org/apache/dubbo/common/extension/E…

b065dbe

…xtensionLoader.java Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

Add getCurrentLoggerAdapter method

17dccac

Added a method to retrieve the current logger adapter.

zrlw added 3 commits April 27, 2026 14:41

Add logging support for extension creation tests

bd73870

Fix Javadoc formatting in getCurrentLoggerAdapter

317b0cf

Removed unnecessary blank line in Javadoc comment.

Remove duplicate import of 'Prioritized'

b9138f3

Removed duplicate import statement for 'Prioritized'.

Conversation

uuuyuqi commented Apr 20, 2026

What is the purpose of the change?

Checklist

Uh oh!

codecov-commenter commented Apr 20, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

zrlw left a comment

Choose a reason for hiding this comment

Uh oh!

uuuyuqi commented Apr 22, 2026

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Reviewed changes

Uh oh!

Copilot AI Apr 24, 2026

Choose a reason for hiding this comment

Uh oh!

uuuyuqi Apr 24, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Copilot AI Apr 27, 2026

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Copilot AI Apr 27, 2026

Choose a reason for hiding this comment

Uh oh!

uuuyuqi Apr 27, 2026

Choose a reason for hiding this comment

Uh oh!

uuuyuqi Apr 27, 2026

Choose a reason for hiding this comment

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

codecov-commenter commented Apr 20, 2026 •

edited

Loading