[Enhancement] json logging print filename and method (StarRocks#50375)

Signed-off-by: Kevin Xiaohua Cai <[email protected]>

fe/fe-core/src/main/java/com/starrocks/common/Log4jConfig.java

@@ -256,55 +256,20 @@ static String generateActiveLog4jXmlConfig() throws IOException {
  // appender layout
  final String jsonLoggingConfValue = "json";
  if (jsonLoggingConfValue.equalsIgnoreCase(Config.sys_log_format)) {
- // json logging
- String jsonLayoutFormatter =
- "<JsonTemplateLayout maxStringLength=\"%d\" locationInfoEnabled=\"true\">\n" +
- " <EventTemplate><![CDATA[\n{\n" +
- " \"@timestamp\": {\n" +
- " \"$resolver\": \"timestamp\",\n" +
- " \"pattern\": {\n" +
- " \"format\": \"yyyy-MM-dd HH:mm:ss.SSSXXX\",\n" +
- " \"timeZone\": \"UTC\"\n" +
- " }\n" +
- " },\n" +
- " \"level\": {\n" +
- " \"$resolver\": \"level\",\n" +
- " \"field\": \"name\"\n" +
- " },\n" +
- " \"thread.name\": {\n" +
- " \"$resolver\": \"thread\",\n" +
- " \"field\": \"name\"\n" +
- " },\n" +
- " \"thread.id\": {\n" +
- " \"$resolver\": \"thread\",\n" +
- " \"field\": \"id\"\n" +
- " },\n" +
- " \"method\": {\n" +
- " \"$resolver\": \"logger\",\n" +
- " \"field\": \"name\",\n" +
- " \"shorten\": {\n" +
- " \"length\": 1,\n" +
- " \"strategy\": \"tail\"\n" +
- " }\n" +
- " },\n" +
- " \"line\": {\n" +
- " \"$resolver\": \"source\",\n" +
- " \"field\": \"lineNumber\"\n" +
- " },\n" +
- " \"message\": {\n" +
- " \"$resolver\": \"message\",\n" +
- " \"stringfield\": \"true\"\n" +
- " },\n" +
- " \"exception\": {\n" +
- " \"$resolver\": \"exception\",\n" +
- " \"field\": \"stackTrace\",\n" +
- " \"stackTrace\": {\n" +
- " \"stringified\": true,\n" +
- " \"full\": true\n" +
- " }\n" +
- " }" +
- " }\n]]></EventTemplate>\n" +
- "</JsonTemplateLayout>";
+ // json logging, use `'` and replace them to `"` in batch to avoid too many escapes
+ String jsonConfig =
+ "{'@timestamp':{'$resolver':'timestamp','pattern':{'format':'yyyy-MM-dd HH:mm:ss.SSSXXX','timeZone':'UTC'}}," +
+ "'level':{'$resolver':'level','field':'name'}," +
+ "'thread.name':{'$resolver':'thread','field':'name'}," +
+ "'thread.id':{'$resolver':'thread','field':'id'}," +
+ "'line':{'$resolver':'source','field':'lineNumber'}," +
+ "'file':{'$resolver':'source','field':'fileName'}," +
+ "'method':{'$resolver':'source','field':'methodName'}," +
+ "'message':{'$resolver':'message','stringfield':'true'}," +
+ "'exception':{'$resolver':'exception','field':'stackTrace','stackTrace':{'stringified':true,'full':true}}}";
+ jsonConfig = jsonConfig.replace("'", "\"");
+ String jsonLayoutFormatter = "<JsonTemplateLayout maxStringLength=\"%d\" locationInfoEnabled=\"true\">\n" +
+ "<EventTemplate><![CDATA[" + jsonConfig + "]]></EventTemplate>\n" + "</JsonTemplateLayout>";
  String jsonLayoutDefault = String.format(jsonLayoutFormatter, Config.sys_log_json_max_string_length);
  String jsonLayoutProfile = String.format(jsonLayoutFormatter, Config.sys_log_json_profile_max_string_length);
  properties.put("syslog_default_layout", jsonLayoutDefault);

fe/fe-core/src/test/java/com/starrocks/common/Log4jConfigTest.java

@@ -14,27 +14,42 @@
 
 package com.starrocks.common;
 
+import com.google.gson.JsonObject;
+import com.google.gson.internal.Streams;
+import com.google.gson.stream.JsonReader;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 import org.junit.After;
 import org.junit.Assert;
 import org.junit.Before;
 import org.junit.Test;
 
+import java.io.ByteArrayInputStream;
+import java.io.ByteArrayOutputStream;
 import java.io.IOException;
+import java.io.InputStreamReader;
+import java.io.PrintStream;
+import java.io.Reader;
+import java.nio.charset.Charset;
 import java.util.regex.Matcher;
 import java.util.regex.Pattern;
 
 public class Log4jConfigTest {
+ private static final Logger LOG = LogManager.getLogger(Log4jConfigTest.class);
+
  private String logFormat;
 
  @Before
  public void setUp() throws IOException {
+ FeConstants.runningUnitTest = true;
  logFormat = Config.sys_log_format;
  Log4jConfig.initLogging();
  }
 
  @After
  public void tearDown() {
  Config.sys_log_format = logFormat;
+ FeConstants.runningUnitTest = false;
  }
 
  @Test
@@ -69,4 +84,41 @@ public void testJsonLoggingFormatConfig() throws IOException {
  }
  }
  }
+
+ @Test
+ public void testJsonLogOutputFormat() throws IOException {
+ // enable logging with json format to console
+ // with `sys_log_to_console = true`, the log will be written to System.err
+ Config.sys_log_format = "json";
+ Config.sys_log_to_console = true;
+ Config.sys_log_level = "INFO";
+ Log4jConfig.initLogging();
+
+ String logMessage = "Test log message from unit test";
+ // Hook System.err
+ PrintStream oldErr = System.err;
+ ByteArrayOutputStream byteOs = new ByteArrayOutputStream();
+ System.setErr(new PrintStream(byteOs, true));
+ // log a message
+ LOG.warn(logMessage);
+ // reset System.out
+ System.setErr(oldErr);
+ // reset logging
+ Config.sys_log_format = "plaintext";
+ Config.sys_log_to_console = false;
+ Log4jConfig.initLogging();
+
+ // validate log message
+ String logMsg = byteOs.toString(Charset.defaultCharset()).trim();
+ System.out.println("logMsg: " + logMsg);
+
+ Reader reader = new InputStreamReader(new ByteArrayInputStream(byteOs.toByteArray()));
+ JsonObject jsonObject = Streams.parse(new JsonReader(reader)).getAsJsonObject();
+
+ Assert.assertEquals("testJsonLogOutputFormat", jsonObject.get("method").getAsString());
+ Assert.assertEquals("Log4jConfigTest.java", jsonObject.get("file").getAsString());
+ Assert.assertEquals("WARN", jsonObject.get("level").getAsString());
+ Assert.assertEquals("main", jsonObject.get("thread.name").getAsString());
+ Assert.assertEquals(logMessage, jsonObject.get("message").getAsString());
+ }
 }