Skip to content

Commit

Permalink
Fix Logger's name in stdlib (#11519)
Browse files Browse the repository at this point in the history
* Fix Logger's name in stdlib

Somehow SLF4J is able to recognize correctly the provided Logger's name
and print it to the user. Java's Logger is
not.
In addition, we setup SLF4J's configuration, meaning that log-levels are
correctly respected.

For a simple project:
```
from Standard.Base import all
from Standard.Base.Logging import all

type Foo

main =
    IO.println "Hello World!"
    Foo.log_message level=..Warning "I should warn you about something..."
    Foo.log_message level=..Info "Should be seen? By default we only show up-to warnings level"
    Foo.log_message level=..Severe "Something went really bad!"
```

This change demonstrates the fix.

Before:
```
> enso --run simple-logging.enso
Hello World!
Nov 08, 2024 6:08:07 PM com.oracle.truffle.host.HostMethodDesc$SingleMethod$MHBase invokeHandle
WARNING: I should warn you about something...
Nov 08, 2024 6:08:07 PM com.oracle.truffle.host.HostMethodDesc$SingleMethod$MHBase invokeHandle
INFO: Should be seen? By default we only show up-to warnings level
Nov 08, 2024 6:08:07 PM com.oracle.truffle.host.HostMethodDesc$SingleMethod$MHBase invokeHandle
SEVERE: Something went really bad!
Foo
```

After:
```
> enso --run simple-logging.enso
Hello World!
[WARN] [2024-11-08T18:03:37+01:00] [simple-logging.Foo] I should warn you about something...
[ERROR] [2024-11-08T18:03:37+01:00] [simple-logging.Foo] Something went really bad!
Foo
```

* Update distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso

Co-authored-by: Radosław Waśko <radoslaw.wasko@enso.org>

* Test stdlib logs by using MemoryAppender

Added `getEvents` member to `MemoryAppender` so that it is possible to
retrieve individual log messages from tests and test their presence.
Required opening up to some modules to retrieve internals of loggers.

* nit

* small tweaks to eliminate module warnings

---------

Co-authored-by: Radosław Waśko <radoslaw.wasko@enso.org>
  • Loading branch information
hubertp and radeusgd authored Nov 13, 2024
1 parent 75733c5 commit 2f2eeaf
Show file tree
Hide file tree
Showing 7 changed files with 110 additions and 16 deletions.
10 changes: 9 additions & 1 deletion build.sbt
Original file line number Diff line number Diff line change
Expand Up @@ -1098,11 +1098,14 @@ lazy val `logging-service-logback` = project
"org.slf4j" % "slf4j-api" % slf4jVersion,
"org.netbeans.api" % "org-openide-util-lookup" % netbeansApiVersion % "provided"
),
Compile / javaModuleName := "org.enso.logging.service.logback",
Compile / shouldCompileModuleInfoManually := true,
Compile / internalModuleDependencies := Seq(
(`logging-service` / Compile / exportedModule).value,
(`logging-config` / Compile / exportedModule).value
),
Test / shouldCompileModuleInfoManually := true,
Test / javaModuleName := "org.enso.logging.service.logback.test.provider",
Test / moduleDependencies ++= scalaLibrary,
Test / internalModuleDependencies := Seq(
(Compile / exportedModule).value
Expand Down Expand Up @@ -2914,6 +2917,8 @@ lazy val `runtime-integration-tests` =
//(`ydoc-server` / javaModuleName).value,
(`runtime-instrument-common` / javaModuleName).value,
(`text-buffer` / javaModuleName).value,
(`logging-service-logback` / Test / javaModuleName).value,
"ch.qos.logback.classic",
"truffle.tck.tests"
),
Test / addReads := {
Expand All @@ -2930,7 +2935,10 @@ lazy val `runtime-integration-tests` =
(`text-buffer` / javaModuleName).value,
(`semver` / javaModuleName).value,
"truffle.tck.tests",
"org.openide.util.lookup.RELEASE180"
"org.openide.util.lookup.RELEASE180",
"ch.qos.logback.classic",
(`logging-service-logback` / Compile / javaModuleName).value,
(`logging-service-logback` / Test / javaModuleName).value
),
testInstrumentsModName -> Seq(runtimeModName)
)
Expand Down
12 changes: 6 additions & 6 deletions distribution/lib/Standard/Base/0.0.0-dev/src/Logging.enso
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ import project.Data.Text.Text
import project.Meta
import project.Nothing.Nothing

polyglot java import java.util.logging.Logger
polyglot java import org.slf4j.LoggerFactory

## PRIVATE
Log a message.
Expand All @@ -12,13 +12,13 @@ polyglot java import java.util.logging.Logger
Any.log_message : Text -> Log_Level -> Any
Any.log_message self ~message:Text level:Log_Level=Log_Level.Info =
type_name = Meta.get_qualified_type_name self
logger = Logger.getLogger type_name
logger = LoggerFactory.getLogger type_name
case level of
Log_Level.Finest -> logger.finest message
Log_Level.Fine -> logger.fine message
Log_Level.Finest -> logger.trace message
Log_Level.Fine -> logger.debug message
Log_Level.Info -> logger.info message
Log_Level.Warning -> logger.warning message
Log_Level.Severe -> logger.severe message
Log_Level.Warning -> logger.warn message
Log_Level.Severe -> logger.error message
self

## PRIVATE
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,66 @@
package org.enso.interpreter.test;

import static org.junit.Assert.*;

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.spi.ILoggingEvent;
import java.util.List;
import org.enso.common.MethodNames;
import org.enso.interpreter.runtime.EnsoContext;
import org.enso.logging.service.logback.MemoryAppender;
import org.enso.test.utils.ContextUtils;
import org.graalvm.polyglot.Context;
import org.graalvm.polyglot.Value;
import org.junit.AfterClass;
import org.junit.BeforeClass;
import org.junit.Test;
import org.slf4j.LoggerFactory;

public class StdLibLogsTest {

private static Context ctx;
private static Value mod;
private static EnsoContext ensoContext;

@BeforeClass
public static void initEnsoContext() {
ctx = ContextUtils.createDefaultContext();
ensoContext = ContextUtils.leakContext(ctx);
mod =
ctx.eval(
"enso",
"""
from Standard.Base import IO
from Standard.Base.Logging import all
type Foo
test =
Foo.log_message level=..Warning "I should warn you about something..."
Foo.log_message level=..Info "Should be seen? By default we only show up-to warnings level"
Foo.log_message level=..Severe "Something went really bad!"
""");
}

@AfterClass
public static void disposeContext() {
ctx.close();
ctx = null;
ensoContext.shutdown();
ensoContext = null;
}

@Test
public void reportLogsInStdLib() {
mod.invokeMember(MethodNames.Module.EVAL_EXPRESSION, "test");
var context = (LoggerContext) LoggerFactory.getILoggerFactory();
var logger = context.getLogger(Logger.ROOT_LOGGER_NAME);
var appender = (MemoryAppender) logger.getAppender("memory");
var events = appender.getEvents().stream().map(ILoggingEvent::getMessage).toList();

assertTrue(
events.containsAll(
List.of("I should warn you about something...", "Something went really bad!")));
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -14,13 +14,12 @@ logging-service {
appenders = [
{
name = "memory"
forward-to = console
},
{
name = "console"
pattern = "[%level] [%d{yyyy-MM-ddTHH:mm:ssXXX}] [%logger] %msg%n"
}
]
default-appender = memory
log-level = "error"
log-level = "warn"
}
Original file line number Diff line number Diff line change
Expand Up @@ -19,8 +19,8 @@ private MemoryAppender(String forwardTo) {
}

public static MemoryAppender parse(Config config) {
String fowardTo = config.hasPath(forwardToKey) ? config.getString(forwardToKey) : "console";
return new MemoryAppender(fowardTo);
String forwardTo = config.hasPath(forwardToKey) ? config.getString(forwardToKey) : "";
return new MemoryAppender(forwardTo);
}

@Override
Expand Down Expand Up @@ -49,5 +49,14 @@ public String getName() {
return appenderName;
}

@Override
public String toString() {
if (this.forwardTo != null && !this.forwardTo.equals("")) {
return "MemoryAppender[forwardTo=" + forwardTo + "]";
} else {
return "MemoryAppender[forwardTo=<disabled>]";
}
}

private static final String forwardToKey = "forward-to";
}
Original file line number Diff line number Diff line change
Expand Up @@ -256,11 +256,10 @@ public boolean setupMemoryAppender(Level logLevel) {
default:
target = null;
}
if (target == null) {
throw new RuntimeException("unsupported appender " + appenderConfig.getTarget());
if (target != null) {
target.setContext(env.ctx);
target.start();
}
target.setContext(env.ctx);
target.start();
var memoryAppender = new MemoryAppender(target);
env.finalizeAppender(memoryAppender);
return true;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ public class MemoryAppender extends AppenderBase<ILoggingEvent> {
public MemoryAppender(Appender<ILoggingEvent> underlying) {
this.underlying = underlying;
this.events = new ArrayList<>();
this.forwardLogs = true;
this.forwardLogs = underlying != null;
}

protected void append(ILoggingEvent e) {
Expand Down Expand Up @@ -50,10 +50,23 @@ public void stopForwarding() {
this.underlying.stop();
}

public List<ILoggingEvent> getEvents() {
return events;
}

@Override
public String getName() {
return NAME;
}

@Override
public String toString() {
if (this.underlying != null) {
return "MemoryAppender[forwardTo=" + this.underlying.getName() + "]";
} else {
return "MemoryAppender[forwardTo=<disabled>]";
}
}

public static final String NAME = "memory";
}

0 comments on commit 2f2eeaf

Please sign in to comment.