Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Support logging exception stack traces when the last argument is Throwable #3960

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open

Support logging exception stack traces when the last argument is Throwable #3960

wants to merge 1 commit into from

Conversation

raccoonback
Copy link

@raccoonback raccoonback commented Jan 2, 2025 •
edited
Loading

Motivation

Hello,

Reactor Core supports SLF4J, Console Logger, and JDK Logger.
In SLF4J implementations (e.g., Logback), when the last argument is of type Throwable, the exception stack trace is automatically logged, as shown below.
(ref. SLF4J FAQ)
(ref: Logback implementation)

log.info("An error occurred: {}", "details", new Exception("Sample exception"));

However, the Console Logger and JDK Logger supported by Reactor Core do not provide this functionality, and users must manually check for Throwable and handle it accordingly in their code.

	@Test
	void useVerboseConsoleLoggers() throws Exception {
		try {
			Loggers.useVerboseConsoleLoggers();
			Logger l = Loggers.getLogger("test");

			l.debug("Processing data for user: {}", "user123", new Exception("Sample exception"));
		}
		finally {
			Loggers.resetLoggerFactory();
		        ReactorLauncherSessionListener.resetLoggersFactory();
		}
	}
[DEBUG] (Test worker) Processing data for user: user123

This results in unnecessary branching in user code and decreases consistency across logging mechanisms.

Therefore, in this change, we have modified the ConsoleLogger and JdkLogger to detect if the last argument is of type Throwable and automatically log the exception stack trace.

Description

This PR enhances the logging functionality in Reactor Core to check if the last argument in logger methods is of type Throwable. If a Throwable is detected, the exception stack trace is included in the log output.

Key Changes

  1. Added logic to inspect the last argument in logger method calls.
  2. Automatically handles Throwable instances for improved debugging.
  3. Ensures compatibility with existing SLF4J-style message formatting for consistency across logging frameworks.

Example Usage

log.info("Processing data for user: {}", "user123", new Exception("Sample exception"));

Before

INFO: Processing data for user: user123

After

INFO: Processing data for user: user123
java.lang.Exception: Sample exception
    at ...

Benefits

  • Aligns Reactor's logging capabilities with familiar SLF4J-style formatting.
  • Simplifies exception handling for developers using JDK or Console Loggers.
  • Improves traceability and debugging in complex systems.

Testing

	@Test
	void useVerboseConsoleLoggers() throws Exception {
		try {
			Loggers.useVerboseConsoleLoggers();
			Logger l = Loggers.getLogger("test");

			l.debug("Processing data for user: {}", "user123", new Exception("Sample exception"));
		}
		finally {
			Loggers.resetLoggerFactory();
		        ReactorLauncherSessionListener.resetLoggersFactory();
		}
	}

	@Test
	void useJdkLoggers() throws Exception {
		try {
			Loggers.useJdkLoggers();
			Logger l = Loggers.getLogger("test");

			l.debug("Processing data for user: {}", "user123", new Exception("Sample exception"));
		}
		finally {
			Loggers.resetLoggerFactory();
		        ReactorLauncherSessionListener.resetLoggersFactory();
		}
	}

@raccoonback raccoonback requested a review from a team as a code owner January 2, 2025 15:49
@raccoonback
Log exception stack trace if the last argument is Throwable
d946148 
- Enhanced logger methods to check if the last argument is of type Throwable.
- If Throwable is detected, its stack trace is included in the log output.
- Improves debugging by seamlessly handling exception logging alongside message formatting.

ref. https://www.slf4j.org/faq.html#paramException
@raccoonback raccoonback force-pushed the log-with-optional-throable branch from e336792 to d946148 Compare January 2, 2025 15:51
raccoonback
raccoonback commented Jan 2, 2025
View reviewed changes
reactor-core/src/main/java/reactor/util/Loggers.java
Comment on lines +472 to +475
private boolean isLastElementThrowable(Object... arguments) {
int length = arguments.length;
return length > 0 && arguments[length - 1] instanceof Throwable;
}
Copy link
Author

Choose a reason for hiding this comment

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

Checks whether the last argements are of type Throwable.

reactor-core/src/main/java/reactor/util/Loggers.java
Comment on lines +459 to +470
private void logWithOptionalThrowable(Level level, String format, Object... arguments) {
if(isLastElementThrowable(arguments)) {
int lastIndex = arguments.length - 1;
Object[] args = Arrays.copyOfRange(arguments, 0, lastIndex);
Throwable t = (Throwable) arguments[lastIndex];

logger.log(level, format(format, args), t);
return;
}

logger.log(level, format(format, arguments));
}
Copy link
Author

Choose a reason for hiding this comment

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

In JdkLogger, if the last arguments are Throwable type, stacktrace is also logged.

reactor-core/src/main/java/reactor/util/Loggers.java
Comment on lines +557 to +560
private boolean isLastElementThrowable(Object... arguments) {
int length = arguments.length;
return length > 0 && arguments[length - 1] instanceof Throwable;
}
Copy link
Author

Choose a reason for hiding this comment

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

Checks whether the last argements are of type Throwable.

reactor-core/src/main/java/reactor/util/Loggers.java
Comment on lines +529 to +541
private synchronized void logWithOptionalThrowable(String level, String format, Object... arguments) {
if(isLastElementThrowable(arguments)) {
int lastIndex = arguments.length - 1;
Object[] args = Arrays.copyOfRange(arguments, 0, lastIndex);
Throwable t = (Throwable) arguments[lastIndex];

this.log.format("[%s] (%s) %s\n", level.toUpperCase(), Thread.currentThread().getName(), format(format, args));
t.printStackTrace(this.log);
return;
}

this.log.format("[%s] (%s) %s\n", level.toUpperCase(), Thread.currentThread().getName(), format(format, arguments));
}
Copy link
Author

Choose a reason for hiding this comment

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

In ConsoleLogger, if the last argument is of type Throwable, it also prints a stack trace.
(only use for TRACE, DEBUG, INFO level)

reactor-core/src/main/java/reactor/util/Loggers.java
Comment on lines +543 to +555
private synchronized void logErrorWithOptionalThrowable(String level, String format, Object... arguments) {
if(isLastElementThrowable(arguments)) {
int lastIndex = arguments.length - 1;
Object[] args = Arrays.copyOfRange(arguments, 0, lastIndex);
Throwable t = (Throwable) arguments[lastIndex];

this.err.format("[%s] (%s) %s\n", level.toUpperCase(), Thread.currentThread().getName(), format(format, args));
t.printStackTrace(this.err);
return;
}

this.err.format("[%s] (%s) %s\n", level.toUpperCase(), Thread.currentThread().getName(), format(format, arguments));
}
Copy link
Author

Choose a reason for hiding this comment

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

In ConsoleLogger, if the last arguments are Throwable type, it also prints a stack trace with the err PrintStream.
(only use for WARN, ERROR level)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
1 participant
@raccoonback