Skip to content

Commit fb7d847

Browse files
rossabakerrossabaker
authored
Merge pull request #850 from morgen-peschke/expand-testing-for-SlfjLogger
Fix MDC handling in Slf4jLogger
2 parents d51d1ec + 61ee3e9 commit fb7d847

File tree

3 files changed

+643
-58
lines changed

3 files changed

+643
-58
lines changed

‎slf4j/src/main/scala/org/typelevel/log4cats/slf4j/internal/Slf4jLoggerInternal.scala‎

Lines changed: 51 additions & 39 deletions
Original file line numberDiff line numberDiff line change
@@ -16,12 +16,14 @@
1616

1717
package org.typelevel.log4cats.slf4j.internal
1818

19-
import org.typelevel.log4cats._
20-
import cats.syntax.all._
21-
import cats.effect._
22-
import org.slf4j.{Logger => JLogger}
19+
import org.typelevel.log4cats.*
20+
import cats.syntax.all.*
21+
import cats.effect.*
22+
import org.slf4j.Logger as JLogger
2323
import org.slf4j.MDC
2424

25+
import scala.annotation.nowarn
26+
2527
private[slf4j] object Slf4jLoggerInternal {
2628

2729
final val singletonsByName = true
@@ -34,21 +36,36 @@ private[slf4j] object Slf4jLoggerInternal {
3436
def apply(t: Throwable)(msg: => String): F[Unit]
3537
}
3638

39+
// Need this to make sure MDC is correctly cleared before logging
40+
private[this] def noContextLog[F[_]](isEnabled: F[Boolean], logging: () => Unit)(implicit
41+
F: Sync[F]
42+
): F[Unit] =
43+
contextLog[F](isEnabled, Map.empty, logging)
44+
3745
private[this] def contextLog[F[_]](
3846
isEnabled: F[Boolean],
3947
ctx: Map[String, String],
4048
logging: () => Unit
4149
)(implicit F: Sync[F]): F[Unit] = {
4250

4351
val ifEnabled = F.delay {
44-
val backup = MDC.getCopyOfContextMap()
52+
val backup =
53+
try MDC.getCopyOfContextMap()
54+
catch {
55+
case e: IllegalStateException =>
56+
// MDCAdapter is missing, no point in doing anything with
57+
// the MDC, so just hope the logging backend can salvage
58+
// something.
59+
logging()
60+
throw e
61+
}
4562

46-
for {
47-
(k, v) <- ctx
48-
} MDC.put(k, v)
49-
50-
try logging()
51-
finally
63+
try {
64+
// Once 2.12 is no longer supported, change this to MDC.setContextMap(ctx.asJava)
65+
MDC.clear()
66+
ctx.foreach { case (k, v) => MDC.put(k, v) }
67+
logging()
68+
} finally
5269
if (backup eq null) MDC.clear()
5370
else MDC.setContextMap(backup)
5471
}
@@ -59,6 +76,7 @@ private[slf4j] object Slf4jLoggerInternal {
5976
)
6077
}
6178

79+
@nowarn("msg=used")
6280
final class Slf4jLogger[F[_]](val logger: JLogger, sync: Sync.Type = Sync.Type.Delay)(implicit
6381
F: Sync[F]
6482
) extends SelfAwareStructuredLogger[F] {
@@ -76,53 +94,47 @@ private[slf4j] object Slf4jLoggerInternal {
7694
override def isErrorEnabled: F[Boolean] = F.delay(logger.isErrorEnabled)
7795

7896
override def trace(t: Throwable)(msg: => String): F[Unit] =
79-
isTraceEnabled
80-
.ifM(F.suspend(sync)(logger.trace(msg, t)), F.unit)
97+
noContextLog(isTraceEnabled, () => logger.trace(msg, t))
8198
override def trace(msg: => String): F[Unit] =
82-
isTraceEnabled
83-
.ifM(F.suspend(sync)(logger.trace(msg)), F.unit)
99+
noContextLog(isTraceEnabled, () => logger.trace(msg))
84100
override def trace(ctx: Map[String, String])(msg: => String): F[Unit] =
85101
contextLog(isTraceEnabled, ctx, () => logger.trace(msg))
102+
override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
103+
contextLog(isTraceEnabled, ctx, () => logger.trace(msg, t))
104+
86105
override def debug(t: Throwable)(msg: => String): F[Unit] =
87-
isDebugEnabled
88-
.ifM(F.suspend(sync)(logger.debug(msg, t)), F.unit)
106+
noContextLog(isDebugEnabled, () => logger.debug(msg, t))
89107
override def debug(msg: => String): F[Unit] =
90-
isDebugEnabled
91-
.ifM(F.suspend(sync)(logger.debug(msg)), F.unit)
108+
noContextLog(isDebugEnabled, () => logger.debug(msg))
92109
override def debug(ctx: Map[String, String])(msg: => String): F[Unit] =
93110
contextLog(isDebugEnabled, ctx, () => logger.debug(msg))
111+
override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
112+
contextLog(isDebugEnabled, ctx, () => logger.debug(msg, t))
113+
94114
override def info(t: Throwable)(msg: => String): F[Unit] =
95-
isInfoEnabled
96-
.ifM(F.suspend(sync)(logger.info(msg, t)), F.unit)
115+
noContextLog(isInfoEnabled, () => logger.info(msg, t))
97116
override def info(msg: => String): F[Unit] =
98-
isInfoEnabled
99-
.ifM(F.suspend(sync)(logger.info(msg)), F.unit)
117+
noContextLog(isInfoEnabled, () => logger.info(msg))
100118
override def info(ctx: Map[String, String])(msg: => String): F[Unit] =
101119
contextLog(isInfoEnabled, ctx, () => logger.info(msg))
120+
override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
121+
contextLog(isInfoEnabled, ctx, () => logger.info(msg, t))
122+
102123
override def warn(t: Throwable)(msg: => String): F[Unit] =
103-
isWarnEnabled
104-
.ifM(F.suspend(sync)(logger.warn(msg, t)), F.unit)
124+
noContextLog(isWarnEnabled, () => logger.warn(msg, t))
105125
override def warn(msg: => String): F[Unit] =
106-
isWarnEnabled
107-
.ifM(F.suspend(sync)(logger.warn(msg)), F.unit)
126+
noContextLog(isWarnEnabled, () => logger.warn(msg))
108127
override def warn(ctx: Map[String, String])(msg: => String): F[Unit] =
109128
contextLog(isWarnEnabled, ctx, () => logger.warn(msg))
129+
override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
130+
contextLog(isWarnEnabled, ctx, () => logger.warn(msg, t))
131+
110132
override def error(t: Throwable)(msg: => String): F[Unit] =
111-
isErrorEnabled
112-
.ifM(F.suspend(sync)(logger.error(msg, t)), F.unit)
133+
noContextLog(isErrorEnabled, () => logger.error(msg, t))
113134
override def error(msg: => String): F[Unit] =
114-
isErrorEnabled
115-
.ifM(F.suspend(sync)(logger.error(msg)), F.unit)
135+
noContextLog(isErrorEnabled, () => logger.error(msg))
116136
override def error(ctx: Map[String, String])(msg: => String): F[Unit] =
117137
contextLog(isErrorEnabled, ctx, () => logger.error(msg))
118-
override def trace(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
119-
contextLog(isTraceEnabled, ctx, () => logger.trace(msg, t))
120-
override def debug(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
121-
contextLog(isDebugEnabled, ctx, () => logger.debug(msg, t))
122-
override def info(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
123-
contextLog(isInfoEnabled, ctx, () => logger.info(msg, t))
124-
override def warn(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
125-
contextLog(isWarnEnabled, ctx, () => logger.warn(msg, t))
126138
override def error(ctx: Map[String, String], t: Throwable)(msg: => String): F[Unit] =
127139
contextLog(isErrorEnabled, ctx, () => logger.error(msg, t))
128140
}

‎slf4j/src/test/scala/org/typelevel/log4cats/slf4j/internal/JTestLogger.java‎

Lines changed: 207 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,207 @@
1+
/*
2+
* Copyright 2018 Typelevel
3+
*
4+
* Licensed under the Apache License, Version 2.0 (the "License");
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* http://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
17+
package org.typelevel.log4cats.slf4j.internal;
18+
19+
import org.slf4j.Logger;
20+
import org.slf4j.MDC;
21+
import org.slf4j.Marker;
22+
import org.typelevel.log4cats.extras.LogLevel;
23+
import scala.Option;
24+
25+
import java.util.ArrayList;
26+
import java.util.HashMap;
27+
import java.util.List;
28+
import java.util.Map;
29+
import java.util.concurrent.atomic.AtomicReference;
30+
import java.util.function.Function;
31+
import java.util.function.Supplier;
32+
33+
public class JTestLogger implements Logger {
34+
// Java -> Scala compat helpers
35+
36+
private static final scala.Option<Throwable> none = scala.Option$.MODULE$.empty();
37+
private static scala.Option<Throwable> some(Throwable t) { return scala.Option$.MODULE$.apply(t); }
38+
private static final LogLevel.Trace$ Trace = LogLevel.Trace$.MODULE$;
39+
private static final LogLevel.Debug$ Debug = LogLevel.Debug$.MODULE$;
40+
private static final LogLevel.Info$ Info = LogLevel.Info$.MODULE$;
41+
private static final LogLevel.Warn$ Warn = LogLevel.Warn$.MODULE$;
42+
private static final LogLevel.Error$ Error = LogLevel.Error$.MODULE$;
43+
44+
private Map<String, String> captureContext () {
45+
java.util.Map<String, String> mdc = MDC.getCopyOfContextMap();
46+
if (mdc == null) {
47+
return new HashMap<>();
48+
}
49+
return MDC.getCopyOfContextMap();
50+
}
51+
52+
public static class TestLogMessage {
53+
public final LogLevel logLevel;
54+
public final java.util.Map<String, String> context;
55+
public final Option<Throwable> throwableOpt;
56+
public final Supplier<String> message;
57+
58+
public TestLogMessage(LogLevel logLevel,
59+
java.util.Map<String, String> context,
60+
Option<Throwable> throwableOpt,
61+
Supplier<String> message) {
62+
this.logLevel = logLevel;
63+
this.context = context;
64+
this.throwableOpt = throwableOpt;
65+
this.message = message;
66+
}
67+
68+
@Override
69+
public String toString() {
70+
return new StringBuilder()
71+
.append("TestLogMessage(")
72+
.append("logLevel=").append(logLevel)
73+
.append(", ")
74+
.append("context=").append(context)
75+
.append(", ")
76+
.append("throwableOpt=").append(throwableOpt)
77+
.append(", ")
78+
.append("message=").append(message.get())
79+
.append(')')
80+
.toString();
81+
}
82+
83+
static TestLogMessage of(LogLevel logLevel,
84+
java.util.Map<String, String> context,
85+
Throwable throwable,
86+
Supplier<String> message) {
87+
return new TestLogMessage(logLevel, context, some(throwable), message);
88+
}
89+
90+
static TestLogMessage of(LogLevel logLevel,
91+
java.util.Map<String, String> context,
92+
Supplier<String> message) {
93+
return new TestLogMessage(logLevel, context, none, message);
94+
}
95+
}
96+
97+
private final String loggerName;
98+
private final boolean traceEnabled;
99+
private final boolean debugEnabled;
100+
private final boolean infoEnabled;
101+
private final boolean warnEnabled;
102+
private final boolean errorEnabled;
103+
private final AtomicReference<List<TestLogMessage>> loggedMessages;
104+
105+
106+
public JTestLogger(String loggerName,
107+
boolean traceEnabled,
108+
boolean debugEnabled,
109+
boolean infoEnabled,
110+
boolean warnEnabled,
111+
boolean errorEnabled) {
112+
this.loggerName = loggerName;
113+
this.traceEnabled = traceEnabled;
114+
this.debugEnabled = debugEnabled;
115+
this.infoEnabled = infoEnabled;
116+
this.warnEnabled = warnEnabled;
117+
this.errorEnabled = errorEnabled;
118+
loggedMessages = new AtomicReference<>(new ArrayList<TestLogMessage>());
119+
}
120+
121+
private void save(Function<Map<String, String>, TestLogMessage> mkLogMessage) {
122+
loggedMessages.updateAndGet(ll -> {
123+
ll.add(mkLogMessage.apply(captureContext()));
124+
return ll;
125+
});
126+
}
127+
128+
public List<TestLogMessage> logs() { return loggedMessages.get(); }
129+
public void reset() { loggedMessages.set(new ArrayList<>()); }
130+
131+
@Override public String getName() { return loggerName;}
132+
133+
@Override public boolean isTraceEnabled() { return traceEnabled; }
134+
@Override public boolean isDebugEnabled() { return debugEnabled; }
135+
@Override public boolean isInfoEnabled() { return infoEnabled; }
136+
@Override public boolean isWarnEnabled() { return warnEnabled; }
137+
@Override public boolean isErrorEnabled() { return errorEnabled; }
138+
139+
// We don't use them, so we're going to ignore Markers
140+
@Override public boolean isTraceEnabled(Marker marker) { return traceEnabled; }
141+
@Override public boolean isDebugEnabled(Marker marker) { return debugEnabled; }
142+
@Override public boolean isInfoEnabled(Marker marker) { return infoEnabled; }
143+
@Override public boolean isWarnEnabled(Marker marker) { return warnEnabled; }
144+
@Override public boolean isErrorEnabled(Marker marker) { return errorEnabled; }
145+
146+
@Override public void trace(String msg) { save(ctx -> TestLogMessage.of(Trace, ctx, () -> msg)); }
147+
@Override public void trace(String msg, Throwable t) { save(ctx -> TestLogMessage.of(Trace, ctx, t, () -> msg)); }
148+
149+
@Override public void debug(String msg) { save(ctx -> TestLogMessage.of(Debug, ctx, () -> msg)); }
150+
@Override public void debug(String msg, Throwable t) { save(ctx -> TestLogMessage.of(Debug, ctx, t, () -> msg)); }
151+
152+
@Override public void info(String msg) { save(ctx -> TestLogMessage.of(Info, ctx, () -> msg)); }
153+
@Override public void info(String msg, Throwable t) { save(ctx -> TestLogMessage.of(Info, ctx, t, () -> msg)); }
154+
155+
@Override public void warn(String msg) { save(ctx -> TestLogMessage.of(Warn, ctx, () -> msg)); }
156+
@Override public void warn(String msg, Throwable t) { save(ctx -> TestLogMessage.of(Warn, ctx, t, () -> msg)); }
157+
158+
@Override public void error(String msg) { save(ctx -> TestLogMessage.of(Error, ctx, () -> msg)); }
159+
@Override public void error(String msg, Throwable t) { save(ctx -> TestLogMessage.of(Error, ctx, t, () -> msg)); }
160+
161+
// We shouldn't need these for our tests, so we're treating these variants as if they were the standard method
162+
163+
@Override public void trace(String format, Object arg) { trace(format); }
164+
@Override public void trace(String format, Object arg1, Object arg2) { trace(format); }
165+
@Override public void trace(String format, Object... arguments) { trace(format); }
166+
@Override public void trace(Marker marker, String msg) { trace(msg); }
167+
@Override public void trace(Marker marker, String format, Object arg) { trace(format); }
168+
@Override public void trace(Marker marker, String format, Object arg1, Object arg2) { trace(format); }
169+
@Override public void trace(Marker marker, String format, Object... argArray) { trace(format); }
170+
@Override public void trace(Marker marker, String msg, Throwable t) { trace(msg, t); }
171+
172+
@Override public void debug(String format, Object arg) { debug(format); }
173+
@Override public void debug(String format, Object arg1, Object arg2) { debug(format); }
174+
@Override public void debug(String format, Object... arguments) { debug(format); }
175+
@Override public void debug(Marker marker, String msg) { debug(msg); }
176+
@Override public void debug(Marker marker, String format, Object arg) { debug(format); }
177+
@Override public void debug(Marker marker, String format, Object arg1, Object arg2) { debug(format); }
178+
@Override public void debug(Marker marker, String format, Object... arguments) { debug(format); }
179+
@Override public void debug(Marker marker, String msg, Throwable t) { debug(msg, t); }
180+
181+
@Override public void info(String format, Object arg) { info(format); }
182+
@Override public void info(String format, Object arg1, Object arg2) { info(format); }
183+
@Override public void info(String format, Object... arguments) { info(format); }
184+
@Override public void info(Marker marker, String msg) { info(msg); }
185+
@Override public void info(Marker marker, String format, Object arg) { info(format); }
186+
@Override public void info(Marker marker, String format, Object arg1, Object arg2) { info(format); }
187+
@Override public void info(Marker marker, String format, Object... arguments) { info(format); }
188+
@Override public void info(Marker marker, String msg, Throwable t) { info(msg, t); }
189+
190+
@Override public void warn(String format, Object arg) { warn(format); }
191+
@Override public void warn(String format, Object... arguments) { warn(format); }
192+
@Override public void warn(String format, Object arg1, Object arg2) { warn(format); }
193+
@Override public void warn(Marker marker, String msg) { warn(msg); }
194+
@Override public void warn(Marker marker, String format, Object arg) { warn(format); }
195+
@Override public void warn(Marker marker, String format, Object arg1, Object arg2) { warn(format); }
196+
@Override public void warn(Marker marker, String format, Object... arguments) { warn(format); }
197+
@Override public void warn(Marker marker, String msg, Throwable t) { warn(msg, t); }
198+
199+
@Override public void error(String format, Object arg) { error(format); }
200+
@Override public void error(String format, Object arg1, Object arg2) { error(format); }
201+
@Override public void error(String format, Object... arguments) { error(format); }
202+
@Override public void error(Marker marker, String msg) { error(msg); }
203+
@Override public void error(Marker marker, String format, Object arg) { error(format); }
204+
@Override public void error(Marker marker, String format, Object arg1, Object arg2) { error(format); }
205+
@Override public void error(Marker marker, String format, Object... arguments) { error(format); }
206+
@Override public void error(Marker marker, String msg, Throwable t) { error(msg, t); }
207+
}

0 commit comments

Comments
 (0)