I'm trying to learn more about the Spring Framework (without using SpringBoot) and currently i already have a basic RestController setup with embedded Tomcat server (version 10).
Everything works fine but i would like to customize the Catalina's Log object so i could do stuff like JSON serializing of console logs.
I'm coming from a Nest.JS background and there it is very easy. Just register a new Logger with Nest and that's it. I was hoping i could do something similar.
Apparently, Catalina uses a kind of wrapper around java.util.logging with it's LogFactory. When creating the singleton for this class, it verifies if there is any service that implements the Log interface and uses that. If not, then it uses a default implementation (which is what im trying to override)
private LogFactory() {
FileSystems.getDefault();
// Look via a ServiceLoader for a Log implementation that has a
// constructor taking the String name.
ServiceLoader<Log> logLoader = ServiceLoader.load(Log.class);
Constructor<? extends Log> m=null;
for (Log log: logLoader) {
Class<? extends Log> c=log.getClass();
try {
m=c.getConstructor(String.class);
break;
}
catch (NoSuchMethodException | SecurityException e) {
throw new Error(e);
}
}
discoveredLogConstructor=m;
}
public Log getInstance(String name) throws LogConfigurationException {
if (discoveredLogConstructor == null) {
return DirectJDKLog.getInstance(name);
}
try {
return discoveredLogConstructor.newInstance(name);
} catch (ReflectiveOperationException | IllegalArgumentException e) {
throw new LogConfigurationException(e);
}
}
I have implemented this Log interface (it is only a test class), but i cannot find out how i would make this ServiceLoader use it.
class CatalinaLogger implements Log {
private Logger logger;
private String name;
public CatalinaLogger(String name) {
this.name = name;
this.logger = Logger.getLogger(name);
}
@Override
public boolean isDebugEnabled() {
return true;
}
@Override
public boolean isErrorEnabled() {
return true;
}
@Override
public boolean isFatalEnabled() {
return true;
}
@Override
public boolean isInfoEnabled() {
return true;
}
@Override
public boolean isTraceEnabled() {
return true;
}
@Override
public boolean isWarnEnabled() {
return true;
}
@Override
public void trace(Object message) {
logger.log(Level.FINER, String.valueOf(message));
}
@Override
public void trace(Object message, Throwable t) {
logger.log(Level.FINER, String.valueOf(message));
}
@Override
public void debug(Object message) {
logger.log(Level.FINE, String.valueOf(message));
}
@Override
public void debug(Object message, Throwable t) {
logger.log(Level.FINE, String.valueOf(message));
}
@Override
public void info(Object message) {
logger.log(Level.INFO, String.valueOf(message));
}
@Override
public void info(Object message, Throwable t) {
logger.log(Level.INFO, String.valueOf(message));
}
@Override
public void warn(Object message) {
logger.log(Level.WARNING, String.valueOf(message));
}
@Override
public void warn(Object message, Throwable t) {
logger.log(Level.WARNING, String.valueOf(message));
}
@Override
public void error(Object message) {
logger.log(Level.SEVERE, String.valueOf(message));
}
@Override
public void error(Object message, Throwable t) {
logger.log(Level.SEVERE, String.valueOf(message));
}
@Override
public void fatal(Object message) {
logger.log(Level.SEVERE, String.valueOf(message));
}
@Override
public void fatal(Object message, Throwable t) {
logger.log(Level.SEVERE, String.valueOf(message));
}
}
Is my understanding of this problem correct? Either way, how could i solve this problem?
I found a way to somewhat acomplish what i was trying. Basically, Catalina's default Log implementation uses the same Loggers provided by java.util.logging. This includes configurations made for this class, such as Formatters.
If Catalina detects that there is a configuration file for this package, it will not auto-customize the class, which lets us customize it ourselves:
class DirectJDKLog implements Log {
// no reason to hide this - but good reasons to not hide
public final Logger logger;
// Alternate config reader and console format
private static final String SIMPLE_FMT="java.util.logging.SimpleFormatter";
private static final String FORMATTER="org.apache.juli.formatter";
static {
if (System.getProperty("java.util.logging.config.class") == null &&
System.getProperty("java.util.logging.config.file") == null) {
...default configurations
I could not use my own Log implementation, but i could configure a custom formatter using the logging.properties file in the ${CATALINA_HOME} directory:
handlers=java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level=INFO
java.util.logging.ConsoleHandler.formatter=com.springtutorial.httpconfig.LoggerFormatter
Then, it was a matter of customizing stuff:
package com.springtutorial.httpconfig;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.logging.Formatter;
import java.util.logging.LogRecord;
import com.fasterxml.jackson.annotation.JsonProperty;
import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.ObjectMapper;
public class LoggerFormatter extends Formatter {
private ObjectMapper JSON = new ObjectMapper();
private static String kubernetesEnvironment = "false";
public LoggerFormatter() {
String kubeEnvEnabled = System.getProperty("com.springtutorial.httpconfig.kubernetesEnvironment");
if (kubeEnvEnabled != null) {
kubernetesEnvironment = kubeEnvEnabled;
}
}
@Override
public String format(LogRecord record) {
if (LoggerFormatter.kubernetesEnvironment == "false") {
return formatForDevelopment(record);
}
return formatForKubernetes(record);
}
public String formatForDevelopment(LogRecord record) {
// [{Level} | {DateTime} | {Class} -> {Method}] - {Message}
Date eventDate = new Date(record.getMillis());
String[] fullClassName = record.getSourceClassName().split("\\.");
String shortClassName = fullClassName[fullClassName.length - 1];
return "[" + record.getLevel() + " | " +
new SimpleDateFormat("dd/MM/yyyy HH:mm:ss").format(eventDate) + " | " +
shortClassName + " -> " +
record.getSourceMethodName() + "] - " +
record.getMessage() + '\n';
}
public String formatForKubernetes(LogRecord record) {
// {level: $level$, date: $date$, sourceClass: $class$, sourceMethod: $method$, businessData: $businessDataObj$}
Date eventDate = new Date(record.getMillis());
String[] fullClassName = record.getSourceClassName().split("\\.");
String shortClassName = fullClassName[fullClassName.length - 1];
BusinessData<?> receivedBusinessData;
if (fullClassName[1].equals("springframework") || fullClassName[1].equals("apache")) {
// Server is logging so we must format the businessData object by hand
receivedBusinessData = new BusinessData<Object>(new Object() {
@JsonProperty
String serverInfo = record.getMessage();
});
} else {
// Message was logged by the application so i will assume it was made from the application i wrote
receivedBusinessData = (BusinessData<?>) record.getParameters()[0];
}
var log = new Object() {
@JsonProperty
String level = record.getLevel().toString();
@JsonProperty
String date = new SimpleDateFormat("dd/MM/yyyy HH:mm:ss").format(eventDate);
@JsonProperty
String sourceClass = shortClassName;
@JsonProperty
String sourceMethod = record.getSourceMethodName();
@JsonProperty
BusinessData<?> businessData = receivedBusinessData;
};
try {
return JSON.writeValueAsString(log) + '\n';
} catch (JsonProcessingException exp) {
return exp.getMessage();
}
}
}
Still a lot of room for improvements (i'd love to hear some feedback honestly, cause some things here be feeling like coding war crimes) but works as expected:
Logging made from the server (Catalina, Tomcat, Coyote, etc) are formatted according to the mode chosen (development or cluster deployment mode):
// Development
[INFO | 11/05/2024 21:11:12 | AbstractProtocol -> init] - Initializing ProtocolHandler ["http-nio-8080"]
[INFO | 11/05/2024 21:11:12 | StandardService -> startInternal] - Starting service [Tomcat]
[INFO | 11/05/2024 21:11:12 | StandardEngine -> startInternal] - Starting Servlet engine: [Apache Tomcat/10.1.23]
// Cluster deployed
{"level":"INFO","date":"11/05/2024 21:11:51","sourceClass":"AbstractProtocol","sourceMethod":"init","businessData":{"data":{"serverInfo":"Initializing ProtocolHandler [\"http-nio-8080\"]"}}}
{"level":"INFO","date":"11/05/2024 21:11:51","sourceClass":"StandardService","sourceMethod":"startInternal","businessData":{"data":{"serverInfo":"Starting service [Tomcat]"}}}
Logging made from the application can be done using the default java.util.logging.Logger implementation:
// This could be wrapped in the custom Log implementation maybe...?
Logger.getLogger("com.springtutorial").logp(Level.INFO, this.getClass().getPackageName(), "onStartup", "anymsg", new BusinessData<Object>(new Object(){
@JsonProperty
String myCustomObjectData = "this is some custom data";
}));
The result is the same:
{"level":"INFO","date":"11/05/2024 21:15:29","sourceClass":"springtutorial","sourceMethod":"onStartup","businessData":{"data":{"myCustomObjectData":"this is some custom data"}}}