From 9442a51c112d8c3908e936224f30757bcbfb3a25 Mon Sep 17 00:00:00 2001 From: Lu Jiajing Date: Sat, 29 Aug 2020 23:17:29 +0800 Subject: [PATCH] JsonLogger implementation (#5356) (#5357) --- apm-commons/apm-datacarrier/pom.xml | 8 + apm-commons/apm-util/pom.xml | 8 + .../apm/util/ConfigInitializer.java | 2 +- apm-sniffer/apm-agent-core/pom.xml | 5 + .../apm/agent/core/conf/Config.java | 7 + .../core/conf/SnifferConfigInitializer.java | 18 +- .../core/logging/core/AbstractLogger.java | 185 ++++++++++++++++++ .../agent/core/logging/core/Converter.java | 4 +- .../core/logging/core/JsonLogResolver.java | 37 ++++ .../agent/core/logging/core/JsonLogger.java | 80 ++++++++ .../apm/agent/core/logging/core/Parser.java | 2 +- .../core/logging/core/PatternLogger.java | 148 +------------- .../agent/core/logging/core/ResolverType.java | 23 +++ .../AgentNameConverter.java | 7 +- .../ClassConverter.java | 7 +- .../DateConverter.java | 7 +- .../LevelConverter.java | 7 +- .../LiteralConverter.java | 7 +- .../MessageConverter.java | 7 +- .../ThreadConverter.java | 7 +- .../ThrowableConverter.java | 7 +- .../core/logging/core/JsonLoggerTest.java | 183 +++++++++++++++++ .../core/logging/core/LoggingBenchmark.java | 96 +++++++++ .../core/logging/core/PatternLoggerTest.java | 49 ++++- .../skywalking/apm/agent/SkyWalkingAgent.java | 34 ++-- .../apm-sdk-plugin/solrj-7.x-plugin/pom.xml | 6 + apm-sniffer/apm-test-tools/pom.xml | 5 + .../setup/service-agent/java-agent/README.md | 3 +- pom.xml | 11 +- 29 files changed, 798 insertions(+), 172 deletions(-) create mode 100644 apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/AbstractLogger.java create mode 100644 apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogResolver.java create mode 100644 apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogger.java create mode 100644 apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/ResolverType.java rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/AgentNameConverter.java (88%) rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/ClassConverter.java (88%) rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/DateConverter.java (89%) rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/LevelConverter.java (88%) rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/LiteralConverter.java (90%) rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/MessageConverter.java (88%) rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/ThreadConverter.java (88%) rename apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/{coverts => converters}/ThrowableConverter.java (92%) create mode 100644 apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLoggerTest.java create mode 100644 apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/LoggingBenchmark.java diff --git a/apm-commons/apm-datacarrier/pom.xml b/apm-commons/apm-datacarrier/pom.xml index 7fb14f49a6..2ba5a72351 100644 --- a/apm-commons/apm-datacarrier/pom.xml +++ b/apm-commons/apm-datacarrier/pom.xml @@ -27,4 +27,12 @@ apm-datacarrier + + + org.openjdk.jmh + jmh-generator-annprocess + test + + + diff --git a/apm-commons/apm-util/pom.xml b/apm-commons/apm-util/pom.xml index 0a1a6dfafd..93967be75e 100644 --- a/apm-commons/apm-util/pom.xml +++ b/apm-commons/apm-util/pom.xml @@ -33,4 +33,12 @@ UTF-8 + + + + org.openjdk.jmh + jmh-generator-annprocess + test + + diff --git a/apm-commons/apm-util/src/main/java/org/apache/skywalking/apm/util/ConfigInitializer.java b/apm-commons/apm-util/src/main/java/org/apache/skywalking/apm/util/ConfigInitializer.java index 163f46b6bc..d313ba8c84 100644 --- a/apm-commons/apm-util/src/main/java/org/apache/skywalking/apm/util/ConfigInitializer.java +++ b/apm-commons/apm-util/src/main/java/org/apache/skywalking/apm/util/ConfigInitializer.java @@ -149,7 +149,7 @@ public class ConfigInitializer { String propertyStringKey = propertyKey.toString(); if (propertyStringKey.startsWith(prefix) && propertyStringKey.endsWith(suffix)) { String itemKey = propertyStringKey.substring( - prefix.length(), propertyStringKey.length() - suffix.length()); + prefix.length(), propertyStringKey.length() - suffix.length()); Object keyObj; Object valueObj; diff --git a/apm-sniffer/apm-agent-core/pom.xml b/apm-sniffer/apm-agent-core/pom.xml index 375a94b3bb..0d1d27ff46 100644 --- a/apm-sniffer/apm-agent-core/pom.xml +++ b/apm-sniffer/apm-agent-core/pom.xml @@ -104,6 +104,11 @@ ${ststem-rules.version} test + + org.openjdk.jmh + jmh-generator-annprocess + test + diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/Config.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/Config.java index e43f11662f..47b8ebea33 100755 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/Config.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/Config.java @@ -20,9 +20,11 @@ package org.apache.skywalking.apm.agent.core.conf; import java.util.HashMap; import java.util.Map; + import org.apache.skywalking.apm.agent.core.context.trace.TraceSegment; import org.apache.skywalking.apm.agent.core.logging.core.LogLevel; import org.apache.skywalking.apm.agent.core.logging.core.LogOutput; +import org.apache.skywalking.apm.agent.core.logging.core.ResolverType; import org.apache.skywalking.apm.agent.core.logging.core.WriterFactory; import org.apache.skywalking.apm.agent.core.plugin.bytebuddy.ClassCacheMode; import org.apache.skywalking.apm.util.Length; @@ -249,6 +251,11 @@ public class Config { */ public static LogOutput OUTPUT = LogOutput.FILE; + /** + * The log resolver type. Default is PATTERN which will create PatternLogResolver later. + */ + public static ResolverType RESOLVER = ResolverType.PATTERN; + /** * The log patten. Default is "%level %timestamp %thread %class : %msg %throwable". Each conversion specifiers * starts with a percent sign '%' and fis followed by conversion word. There are some default conversion diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/SnifferConfigInitializer.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/SnifferConfigInitializer.java index d5fbd6a98e..06b82c488c 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/SnifferConfigInitializer.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/conf/SnifferConfigInitializer.java @@ -32,6 +32,8 @@ import org.apache.skywalking.apm.agent.core.boot.AgentPackageNotFoundException; import org.apache.skywalking.apm.agent.core.boot.AgentPackagePath; import org.apache.skywalking.apm.agent.core.logging.api.ILog; import org.apache.skywalking.apm.agent.core.logging.api.LogManager; +import org.apache.skywalking.apm.agent.core.logging.core.JsonLogResolver; +import org.apache.skywalking.apm.agent.core.logging.core.PatternLogResolver; import org.apache.skywalking.apm.util.ConfigInitializer; import org.apache.skywalking.apm.util.PropertyPlaceholderHelper; import org.apache.skywalking.apm.util.StringUtil; @@ -40,7 +42,7 @@ import org.apache.skywalking.apm.util.StringUtil; * The SnifferConfigInitializer initializes all configs in several way. */ public class SnifferConfigInitializer { - private static final ILog LOGGER = LogManager.getLogger(SnifferConfigInitializer.class); + private static ILog LOGGER = LogManager.getLogger(SnifferConfigInitializer.class); private static final String SPECIFIED_CONFIG_PATH = "skywalking_config"; private static final String DEFAULT_CONFIG_FILE_NAME = "/config/agent.config"; private static final String ENV_KEY_PREFIX = "skywalking."; @@ -90,6 +92,9 @@ public class SnifferConfigInitializer { } initializeConfig(Config.class); + // reconfigure logger after config initialization + configureLogger(); + LOGGER = LogManager.getLogger(SnifferConfigInitializer.class); if (StringUtil.isEmpty(Config.Agent.SERVICE_NAME)) { throw new ExceptionInInitializerError("`agent.service_name` is missing."); @@ -207,4 +212,15 @@ public class SnifferConfigInitializer { } throw new ConfigNotFoundException("Failed to load agent.config."); } + + static void configureLogger() { + switch (Config.Logging.RESOLVER) { + case JSON: + LogManager.setLogResolver(new JsonLogResolver()); + break; + case PATTERN: + default: + LogManager.setLogResolver(new PatternLogResolver()); + } + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/AbstractLogger.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/AbstractLogger.java new file mode 100644 index 0000000000..d58abf4095 --- /dev/null +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/AbstractLogger.java @@ -0,0 +1,185 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package org.apache.skywalking.apm.agent.core.logging.core; + +import org.apache.skywalking.apm.agent.core.conf.Config; +import org.apache.skywalking.apm.agent.core.logging.api.ILog; +import org.apache.skywalking.apm.agent.core.logging.core.converters.AgentNameConverter; +import org.apache.skywalking.apm.agent.core.logging.core.converters.ClassConverter; +import org.apache.skywalking.apm.agent.core.logging.core.converters.DateConverter; +import org.apache.skywalking.apm.agent.core.logging.core.converters.LevelConverter; +import org.apache.skywalking.apm.agent.core.logging.core.converters.MessageConverter; +import org.apache.skywalking.apm.agent.core.logging.core.converters.ThreadConverter; +import org.apache.skywalking.apm.agent.core.logging.core.converters.ThrowableConverter; + +import java.util.ArrayList; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.regex.Matcher; + +/** + * An abstract class to simplify the real implementation of the loggers. + * It hold the class name of the logger, and is responsible for log level check, + * message interpolation, etc. + */ +public abstract class AbstractLogger implements ILog { + public static final Map> DEFAULT_CONVERTER_MAP = new HashMap<>(); + protected List converters = new ArrayList<>(); + + static { + DEFAULT_CONVERTER_MAP.put("thread", ThreadConverter.class); + DEFAULT_CONVERTER_MAP.put("level", LevelConverter.class); + DEFAULT_CONVERTER_MAP.put("agent_name", AgentNameConverter.class); + DEFAULT_CONVERTER_MAP.put("timestamp", DateConverter.class); + DEFAULT_CONVERTER_MAP.put("msg", MessageConverter.class); + DEFAULT_CONVERTER_MAP.put("throwable", ThrowableConverter.class); + DEFAULT_CONVERTER_MAP.put("class", ClassConverter.class); + } + + protected final String targetClass; + + public AbstractLogger(String targetClass) { + this.targetClass = targetClass; + } + + @Override + public void info(String message) { + if (this.isInfoEnable()) { + this.logger(LogLevel.INFO, message, null); + } + } + + @Override + public void info(String message, Object... objects) { + if (this.isInfoEnable()) { + this.logger(LogLevel.INFO, replaceParam(message, objects), null); + } + } + + @Override + public void warn(String message, Object... objects) { + if (this.isWarnEnable()) { + this.logger(LogLevel.WARN, replaceParam(message, objects), null); + } + } + + @Override + public void warn(Throwable throwable, String message, Object... objects) { + if (this.isWarnEnable()) { + this.logger(LogLevel.WARN, replaceParam(message, objects), throwable); + } + } + + @Override + public void error(String message, Throwable throwable) { + if (this.isErrorEnable()) { + this.logger(LogLevel.ERROR, message, throwable); + } + } + + @Override + public void error(Throwable throwable, String message, Object... objects) { + if (this.isErrorEnable()) { + this.logger(LogLevel.ERROR, replaceParam(message, objects), throwable); + } + } + + @Override + public void error(String message) { + if (this.isErrorEnable()) { + this.logger(LogLevel.ERROR, message, null); + } + } + + @Override + public void debug(String message) { + if (this.isDebugEnable()) { + this.logger(LogLevel.DEBUG, message, null); + } + } + + @Override + public void debug(String message, Object... objects) { + if (this.isDebugEnable()) { + this.logger(LogLevel.DEBUG, replaceParam(message, objects), null); + } + } + + @Override + public void debug(Throwable throwable, String message, Object... objects) { + if (this.isDebugEnable()) { + this.logger(LogLevel.DEBUG, replaceParam(message, objects), throwable); + } + } + + public boolean isDebugEnable() { + return LogLevel.DEBUG.compareTo(Config.Logging.LEVEL) >= 0; + } + + public boolean isInfoEnable() { + return LogLevel.INFO.compareTo(Config.Logging.LEVEL) >= 0; + } + + public boolean isWarnEnable() { + return LogLevel.WARN.compareTo(Config.Logging.LEVEL) >= 0; + } + + public boolean isErrorEnable() { + return LogLevel.ERROR.compareTo(Config.Logging.LEVEL) >= 0; + } + + protected String replaceParam(String message, Object... parameters) { + if (message == null) { + return message; + } + int startSize = 0; + int parametersIndex = 0; + int index; + String tmpMessage = message; + while ((index = message.indexOf("{}", startSize)) != -1) { + if (parametersIndex >= parameters.length) { + break; + } + /** + * @Fix the Illegal group reference issue + */ + tmpMessage = tmpMessage.replaceFirst("\\{\\}", Matcher.quoteReplacement(String.valueOf(parameters[parametersIndex++]))); + startSize = index + 2; + } + return tmpMessage; + } + + protected void logger(LogLevel level, String message, Throwable e) { + WriterFactory.getLogWriter().write(this.format(level, message, e)); + } + + /** + * The abstract method left for real loggers. + * Any implementation MUST return string, which will be directly transferred to log destination, + * i.e. log files OR stdout + * + * @param level log level + * @param message log message, which has been interpolated with user-defined parameters. + * @param e throwable if exists + * @return string representation of the log, for example, raw json string for {@link JsonLogger} + */ + protected abstract String format(LogLevel level, String message, Throwable e); + +} diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Converter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Converter.java index 504d816d93..88fa58e6b4 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Converter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Converter.java @@ -19,10 +19,12 @@ package org.apache.skywalking.apm.agent.core.logging.core; /** - * The Converter, It is used to convert the LogEvent to the String. + * The Converter, it is used to convert the LogEvent to the String. + * For JsonLogger, the `getKey()` method is used to generate the key for json. */ public interface Converter { String convert(LogEvent logEvent); + String getKey(); } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogResolver.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogResolver.java new file mode 100644 index 0000000000..44dd8e2cd0 --- /dev/null +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogResolver.java @@ -0,0 +1,37 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package org.apache.skywalking.apm.agent.core.logging.core; + +import com.google.gson.Gson; +import org.apache.skywalking.apm.agent.core.logging.api.ILog; +import org.apache.skywalking.apm.agent.core.logging.api.LogResolver; + +public class JsonLogResolver implements LogResolver { + private static final Gson GSON = new Gson(); + + @Override + public ILog getLogger(Class aClass) { + return new JsonLogger(aClass, GSON); + } + + @Override + public ILog getLogger(String s) { + return new JsonLogger(s, GSON); + } +} diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogger.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogger.java new file mode 100644 index 0000000000..cffd493139 --- /dev/null +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLogger.java @@ -0,0 +1,80 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package org.apache.skywalking.apm.agent.core.logging.core; + +import com.google.gson.Gson; +import org.apache.skywalking.apm.agent.core.logging.core.converters.LiteralConverter; + +import java.util.HashMap; +import java.util.Map; + +/** + * An alternative logger for the SkyWalking agent. The default layout is + * { + * "@timestamp": "", // timestamp + * "logger": "", // name of the Logger + * "level": "", // info|debug|warn|error + * "thread": "", // thread where the log method is called + * "message": "", // your log message + * "throwable": "", + * "agent_name" "service_name" + * } + */ +public class JsonLogger extends AbstractLogger { + private final Gson gson; + + public JsonLogger(Class targetClass, Gson gson) { + this(targetClass.getSimpleName(), gson); + } + + /** + * In the Constructor, the instances of converters are created, + * except those {@link LiteralConverter} since this class is used + * only the literals in {@link PatternLogger} , + * and thus should not be added to the json log. + * + * @param targetClass the logger class + * @param gson instance of Gson works as json serializer + */ + public JsonLogger(String targetClass, Gson gson) { + super(targetClass); + this.gson = gson; + for (Map.Entry> entry : DEFAULT_CONVERTER_MAP.entrySet()) { + final Class converterClass = entry.getValue(); + try { + if (converters instanceof LiteralConverter) { + continue; + } + converters.add(converterClass.newInstance()); + } catch (IllegalAccessException | InstantiationException e) { + throw new IllegalStateException("Create Converter error. Class: " + converterClass, e); + } + } + } + + @Override + protected String format(LogLevel level, String message, Throwable e) { + LogEvent logEvent = new LogEvent(level, message, e, this.targetClass); + Map log = new HashMap<>(); + for (Converter converter : this.converters) { + log.put(converter.getKey(), converter.convert(logEvent)); + } + return this.gson.toJson(log); + } +} diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Parser.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Parser.java index 8f3fa9bb22..28b10f32bb 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Parser.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/Parser.java @@ -18,7 +18,7 @@ package org.apache.skywalking.apm.agent.core.logging.core; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.LiteralConverter; +import org.apache.skywalking.apm.agent.core.logging.core.converters.LiteralConverter; import java.util.ArrayList; import java.util.List; diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLogger.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLogger.java index 9bad76e913..6ebb002c53 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLogger.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLogger.java @@ -18,53 +18,25 @@ package org.apache.skywalking.apm.agent.core.logging.core; -import org.apache.skywalking.apm.agent.core.conf.Config; import org.apache.skywalking.apm.agent.core.logging.api.ILog; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.AgentNameConverter; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.ClassConverter; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.DateConverter; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.LevelConverter; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.MessageConverter; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.ThreadConverter; -import org.apache.skywalking.apm.agent.core.logging.core.coverts.ThrowableConverter; import org.apache.skywalking.apm.util.StringUtil; -import java.util.HashMap; -import java.util.List; -import java.util.Map; -import java.util.regex.Matcher; - /** * A flexible Logger configurable with pattern string. This is default implementation of {@link ILog} This can parse a * pattern to the List of converter with Parser. We package LogEvent with message, level,timestamp ..., passing around * to the List of converter to concat actually Log-String. */ -public class PatternLogger implements ILog { - - public static final Map> DEFAULT_CONVERTER_MAP = new HashMap>(); - - static { - DEFAULT_CONVERTER_MAP.put("thread", ThreadConverter.class); - DEFAULT_CONVERTER_MAP.put("level", LevelConverter.class); - DEFAULT_CONVERTER_MAP.put("agent_name", AgentNameConverter.class); - DEFAULT_CONVERTER_MAP.put("timestamp", DateConverter.class); - DEFAULT_CONVERTER_MAP.put("msg", MessageConverter.class); - DEFAULT_CONVERTER_MAP.put("throwable", ThrowableConverter.class); - DEFAULT_CONVERTER_MAP.put("class", ClassConverter.class); - } - +public class PatternLogger extends AbstractLogger { public static final String DEFAULT_PATTERN = "%level %timestamp %thread %class : %msg %throwable"; private String pattern; - private List converters; - private String targetClass; - public PatternLogger(Class targetClass, String pattern) { + public PatternLogger(Class targetClass, String pattern) { this(targetClass.getSimpleName(), pattern); } public PatternLogger(String targetClass, String pattern) { - this.targetClass = targetClass; + super(targetClass); this.setPattern(pattern); } @@ -77,122 +49,14 @@ public class PatternLogger implements ILog { pattern = DEFAULT_PATTERN; } this.pattern = pattern; - converters = new Parser(pattern, DEFAULT_CONVERTER_MAP).parse(); - } - - protected void logger(LogLevel level, String message, Throwable e) { - WriterFactory.getLogWriter().write(format(level, message, e)); - } - - private String replaceParam(String message, Object... parameters) { - if (message == null) { - return message; - } - int startSize = 0; - int parametersIndex = 0; - int index; - String tmpMessage = message; - while ((index = message.indexOf("{}", startSize)) != -1) { - if (parametersIndex >= parameters.length) { - break; - } - /** - * @Fix the Illegal group reference issue - */ - tmpMessage = tmpMessage.replaceFirst("\\{\\}", Matcher.quoteReplacement(String.valueOf(parameters[parametersIndex++]))); - startSize = index + 2; - } - return tmpMessage; - } - - @Override - public void info(String format) { - if (isInfoEnable()) - logger(LogLevel.INFO, format, null); - } - - @Override - public void info(String format, Object... arguments) { - if (isInfoEnable()) - logger(LogLevel.INFO, replaceParam(format, arguments), null); - } - - @Override - public void warn(String format, Object... arguments) { - if (isWarnEnable()) - logger(LogLevel.WARN, replaceParam(format, arguments), null); - } - - @Override - public void warn(Throwable e, String format, Object... arguments) { - if (isWarnEnable()) - logger(LogLevel.WARN, replaceParam(format, arguments), e); - } - - @Override - public void error(String format, Throwable e) { - if (isErrorEnable()) - logger(LogLevel.ERROR, format, e); - } - - @Override - public void error(Throwable e, String format, Object... arguments) { - if (isErrorEnable()) - logger(LogLevel.ERROR, replaceParam(format, arguments), e); - } - - @Override - public boolean isDebugEnable() { - return LogLevel.DEBUG.compareTo(Config.Logging.LEVEL) >= 0; - } - - @Override - public boolean isInfoEnable() { - return LogLevel.INFO.compareTo(Config.Logging.LEVEL) >= 0; - } - - @Override - public boolean isWarnEnable() { - return LogLevel.WARN.compareTo(Config.Logging.LEVEL) >= 0; - } - - @Override - public boolean isErrorEnable() { - return LogLevel.ERROR.compareTo(Config.Logging.LEVEL) >= 0; - } - - @Override - public void debug(String format) { - if (isDebugEnable()) { - logger(LogLevel.DEBUG, format, null); - } - } - - @Override - public void debug(String format, Object... arguments) { - if (isDebugEnable()) { - logger(LogLevel.DEBUG, replaceParam(format, arguments), null); - } + this.converters = new Parser(pattern, DEFAULT_CONVERTER_MAP).parse(); } @Override - public void error(String format) { - if (isErrorEnable()) { - logger(LogLevel.ERROR, format, null); - } - } - - @Override - public void debug(final Throwable t, final String format, final Object... arguments) { - if (isDebugEnable()) { - logger(LogLevel.DEBUG, replaceParam(format, arguments), t); - } - } - - String format(LogLevel level, String message, Throwable t) { + protected String format(LogLevel level, String message, Throwable t) { LogEvent logEvent = new LogEvent(level, message, t, targetClass); StringBuilder stringBuilder = new StringBuilder(); - for (Converter converter : converters) { + for (Converter converter : this.converters) { stringBuilder.append(converter.convert(logEvent)); } return stringBuilder.toString(); diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/ResolverType.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/ResolverType.java new file mode 100644 index 0000000000..25548b4f24 --- /dev/null +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/ResolverType.java @@ -0,0 +1,23 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package org.apache.skywalking.apm.agent.core.logging.core; + +public enum ResolverType { + JSON, PATTERN +} diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/AgentNameConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/AgentNameConverter.java similarity index 88% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/AgentNameConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/AgentNameConverter.java index 0c690a197f..67d74bb8da 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/AgentNameConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/AgentNameConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.conf.Config; import org.apache.skywalking.apm.agent.core.logging.core.Converter; @@ -27,4 +27,9 @@ public class AgentNameConverter implements Converter { public String convert(LogEvent logEvent) { return Config.Agent.SERVICE_NAME; } + + @Override + public String getKey() { + return "agent_name"; + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ClassConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ClassConverter.java similarity index 88% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ClassConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ClassConverter.java index 3bcf5a2cbb..150be54637 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ClassConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ClassConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.logging.core.Converter; import org.apache.skywalking.apm.agent.core.logging.core.LogEvent; @@ -30,4 +30,9 @@ public class ClassConverter implements Converter { public String convert(LogEvent logEvent) { return logEvent.getTargetClass(); } + + @Override + public String getKey() { + return "logger"; + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/DateConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/DateConverter.java similarity index 89% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/DateConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/DateConverter.java index 7487556fbb..8bfcdc623c 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/DateConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/DateConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.logging.core.Converter; import org.apache.skywalking.apm.agent.core.logging.core.LogEvent; @@ -33,4 +33,9 @@ public class DateConverter implements Converter { public String convert(LogEvent logEvent) { return new SimpleDateFormat("yyyy-MM-dd HH:mm:ss:SSS").format(new Date()); } + + @Override + public String getKey() { + return "@timestamp"; + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/LevelConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/LevelConverter.java similarity index 88% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/LevelConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/LevelConverter.java index f016cf3b87..2614b44b6c 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/LevelConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/LevelConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.logging.core.Converter; import org.apache.skywalking.apm.agent.core.logging.core.LogEvent; @@ -29,4 +29,9 @@ public class LevelConverter implements Converter { public String convert(LogEvent logEvent) { return logEvent.getLevel().name(); } + + @Override + public String getKey() { + return "level"; + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/LiteralConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/LiteralConverter.java similarity index 90% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/LiteralConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/LiteralConverter.java index 411b31a1ad..fd9d0355c1 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/LiteralConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/LiteralConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.logging.core.Converter; import org.apache.skywalking.apm.agent.core.logging.core.LogEvent; @@ -36,4 +36,9 @@ public class LiteralConverter implements Converter { public String convert(LogEvent logEvent) { return literal; } + + @Override + public String getKey() { + return ""; + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/MessageConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/MessageConverter.java similarity index 88% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/MessageConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/MessageConverter.java index 106c26630c..97a3f6fa65 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/MessageConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/MessageConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.logging.core.Converter; import org.apache.skywalking.apm.agent.core.logging.core.LogEvent; @@ -29,4 +29,9 @@ public class MessageConverter implements Converter { public String convert(LogEvent logEvent) { return logEvent.getMessage(); } + + @Override + public String getKey() { + return "message"; + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ThreadConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ThreadConverter.java similarity index 88% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ThreadConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ThreadConverter.java index 45e421dee6..888c237acd 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ThreadConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ThreadConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.logging.core.Converter; import org.apache.skywalking.apm.agent.core.logging.core.LogEvent; @@ -29,4 +29,9 @@ public class ThreadConverter implements Converter { public String convert(LogEvent logEvent) { return Thread.currentThread().getName(); } + + @Override + public String getKey() { + return "thread"; + } } diff --git a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ThrowableConverter.java b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ThrowableConverter.java similarity index 92% rename from apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ThrowableConverter.java rename to apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ThrowableConverter.java index 106782936a..f8cc316edf 100644 --- a/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/coverts/ThrowableConverter.java +++ b/apm-sniffer/apm-agent-core/src/main/java/org/apache/skywalking/apm/agent/core/logging/core/converters/ThrowableConverter.java @@ -16,7 +16,7 @@ * */ -package org.apache.skywalking.apm.agent.core.logging.core.coverts; +package org.apache.skywalking.apm.agent.core.logging.core.converters; import org.apache.skywalking.apm.agent.core.conf.Constants; import org.apache.skywalking.apm.agent.core.logging.core.Converter; @@ -46,4 +46,9 @@ public class ThrowableConverter implements Converter { } return Constants.LINE_SEPARATOR + expMessage; } + + @Override + public String getKey() { + return "throwable"; + } } diff --git a/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLoggerTest.java b/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLoggerTest.java new file mode 100644 index 0000000000..1747d2e880 --- /dev/null +++ b/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/JsonLoggerTest.java @@ -0,0 +1,183 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package org.apache.skywalking.apm.agent.core.logging.core; + +import com.google.gson.Gson; +import com.google.gson.JsonSyntaxException; +import com.google.gson.reflect.TypeToken; +import org.apache.skywalking.apm.agent.core.conf.Config; +import org.apache.skywalking.apm.agent.core.logging.core.converters.ThrowableConverter; +import org.hamcrest.Description; +import org.hamcrest.TypeSafeDiagnosingMatcher; +import org.junit.Assert; +import org.junit.BeforeClass; +import org.junit.Test; +import org.mockito.ArgumentCaptor; +import org.mockito.Mockito; + +import java.lang.reflect.Type; +import java.util.Map; + +import static org.mockito.Mockito.times; + +public class JsonLoggerTest { + @BeforeClass + public static void initAndHoldOut() { + Config.Agent.SERVICE_NAME = "testAppFromConfig"; + } + + @Test + public void testLog() { + final IWriter output = Mockito.mock(IWriter.class); + JsonLogger logger = new JsonLogger(JsonLoggerTest.class, new Gson()) { + @Override + protected void logger(LogLevel level, String message, Throwable e) { + output.write(format(level, message, e)); + } + }; + + Assert.assertTrue(logger.isDebugEnable()); + Assert.assertTrue(logger.isInfoEnable()); + Assert.assertTrue(logger.isWarnEnable()); + Assert.assertTrue(logger.isErrorEnable()); + + ArgumentCaptor argument = ArgumentCaptor.forClass(String.class); + logger.debug("hello world"); + Mockito.verify(output, times(1)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "DEBUG", null)); + logger.debug("hello {}", "world"); + Mockito.verify(output, times(2)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "DEBUG", null)); + logger.info("hello world"); + Mockito.verify(output, times(3)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "INFO", null)); + logger.info("hello {}", "world"); + Mockito.verify(output, times(4)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "INFO", null)); + + logger.warn("hello {}", "world"); + Mockito.verify(output, times(5)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "WARN", null)); + logger.warn("hello world"); + Mockito.verify(output, times(6)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "WARN", null)); + logger.error("hello world"); + Mockito.verify(output, times(7)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "ERROR", null)); + Throwable t = new NullPointerException(); + logger.error("hello world", t); + Mockito.verify(output, times(8)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "ERROR", t)); + logger.error(t, "hello {}", "world"); + Mockito.verify(output, times(9)).write(argument.capture()); + Assert.assertThat(argument.getValue(), createMatcher("hello world", "ERROR", t)); + } + + private static class LogMatcher extends TypeSafeDiagnosingMatcher { + private static final Gson GSON = new Gson(); + private static final Type MAP_TYPE = new TypeToken>() { + }.getType(); + + private final String agent; + private final String logger; + private final String message; + private final String level; + private final Throwable t; + + public LogMatcher(String agent, String logger, String message, String level, Throwable t) { + this.agent = agent; + this.logger = logger; + this.message = message; + this.level = level; + this.t = t; + } + + @Override + protected boolean matchesSafely(String item, Description mismatchDescription) { + try { + Map logMap = GSON.fromJson(item, MAP_TYPE); + if (!logMap.containsKey("agent_name")) { + mismatchDescription.appendText("agent_name did not exist"); + return false; + } + if (!this.agent.equals(logMap.get("agent_name"))) { + mismatchDescription.appendText("agent_name was " + this.agent); + return false; + } + if (!logMap.containsKey("message")) { + mismatchDescription.appendText("agent_name did not exist"); + return false; + } + if (!this.message.equals(logMap.get("message"))) { + mismatchDescription.appendText("message was " + this.message); + return false; + } + + if (!logMap.containsKey("@timestamp")) { + mismatchDescription.appendText("@timestamp did not exist"); + return false; + } + + if (!logMap.containsKey("level")) { + mismatchDescription.appendText("level did not exist"); + return false; + } + if (!this.level.equals(logMap.get("level"))) { + mismatchDescription.appendText("level was " + this.level); + return false; + } + + if (!logMap.containsKey("logger")) { + mismatchDescription.appendText("logger did not exist"); + return false; + } + if (!this.logger.equals(logMap.get("logger"))) { + mismatchDescription.appendText("logger was " + this.logger); + return false; + } + + if (!logMap.containsKey("throwable")) { + mismatchDescription.appendText("throwable did not exist"); + return false; + } + final String tStr = this.t == null ? "" : ThrowableConverter.format(this.t); + if (!tStr.equals(logMap.get("throwable"))) { + mismatchDescription.appendText("throwable was " + tStr); + return false; + } + + } catch (JsonSyntaxException ex) { + mismatchDescription.appendText("not a valid json string"); + return false; + } + return true; + } + + @Override + public void describeTo(Description expectation) { + expectation.appendText( + String.format("a valid json log format with {message=%s,level=%s,logger=%s,@timestamp=*,agent=%s}", + message, level, logger, agent)); + } + } + + public static LogMatcher createMatcher(String message, String level, Throwable t) { + return new LogMatcher("testAppFromConfig", JsonLoggerTest.class.getSimpleName(), message, level, t); + } +} diff --git a/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/LoggingBenchmark.java b/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/LoggingBenchmark.java new file mode 100644 index 0000000000..5e0b53fa08 --- /dev/null +++ b/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/LoggingBenchmark.java @@ -0,0 +1,96 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + */ + +package org.apache.skywalking.apm.agent.core.logging.core; + +import com.google.gson.Gson; +import org.openjdk.jmh.annotations.Benchmark; +import org.openjdk.jmh.annotations.BenchmarkMode; +import org.openjdk.jmh.annotations.Fork; +import org.openjdk.jmh.annotations.Mode; +import org.openjdk.jmh.annotations.OutputTimeUnit; + +import java.util.concurrent.TimeUnit; + +public class LoggingBenchmark { + private static final PatternLogger PATTERN_LOGGER = new PatternLogger(LoggingBenchmark.class, PatternLogger.DEFAULT_PATTERN) { + @Override + protected void logger(LogLevel level, String message, Throwable e) { + format(level, message, e); + } + }; + + private static final JsonLogger JSON_LOGGER = new JsonLogger(LoggingBenchmark.class, new Gson()) { + @Override + protected void logger(LogLevel level, String message, Throwable e) { + format(level, message, e); + } + }; + + @Benchmark + @Fork(value = 1, warmups = 1) + @OutputTimeUnit(TimeUnit.NANOSECONDS) + @BenchmarkMode(Mode.SampleTime) + public void jsonLogger() { + JSON_LOGGER.info("Hello World"); + } + + @Benchmark + @Fork(value = 1, warmups = 1) + @OutputTimeUnit(TimeUnit.NANOSECONDS) + @BenchmarkMode(Mode.SampleTime) + public void patternLogger() { + PATTERN_LOGGER.info("Hello World"); + } + + public static void main(String[] args) throws Exception { + org.openjdk.jmh.Main.main(args); + } + + /** + * # JMH version: 1.21 + * # VM version: JDK 1.8.0_265, OpenJDK 64-Bit Server VM, 25.265-b01 + * # VM invoker: /Library/Java/JavaVirtualMachines/adoptopenjdk-8.jdk/Contents/Home/jre/bin/java + * # VM options: -javaagent:/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar=61104:/Applications/IntelliJ IDEA.app/Contents/bin -Dfile.encoding=UTF-8 + * # Warmup: 5 iterations, 10 s each + * # Measurement: 5 iterations, 10 s each + * # Timeout: 10 min per iteration + * # Threads: 1 thread, will synchronize iterations + * # Benchmark mode: Sampling time + * + * Benchmark Mode Cnt Score Error Units + * LoggingBenchmark.jsonLogger sample 1400812 2305.088 ± 19.119 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p0.00 sample 1988.000 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p0.50 sample 2156.000 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p0.90 sample 2280.000 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p0.95 sample 2388.000 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p0.99 sample 3576.000 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p0.999 sample 18688.000 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p0.9999 sample 78072.717 ns/op + * LoggingBenchmark.jsonLogger:jsonLogger·p1.00 sample 1183744.000 ns/op + * LoggingBenchmark.patternLogger sample 1100999 1522.612 ± 23.720 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p0.00 sample 1270.000 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p0.50 sample 1378.000 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p0.90 sample 1452.000 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p0.95 sample 1548.000 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p0.99 sample 2188.000 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p0.999 sample 17696.000 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p0.9999 sample 589721.600 ns/op + * LoggingBenchmark.patternLogger:patternLogger·p1.00 sample 1259520.000 ns/op + */ +} diff --git a/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLoggerTest.java b/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLoggerTest.java index 933cbcaa1c..db58485987 100644 --- a/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLoggerTest.java +++ b/apm-sniffer/apm-agent-core/src/test/java/org/apache/skywalking/apm/agent/core/logging/core/PatternLoggerTest.java @@ -25,11 +25,11 @@ import org.hamcrest.core.StringContains; import org.junit.Assert; import org.junit.BeforeClass; import org.junit.Test; +import org.mockito.ArgumentCaptor; import org.mockito.Mockito; import java.util.List; -import static org.mockito.Matchers.anyString; import static org.mockito.Mockito.times; public class PatternLoggerTest { @@ -57,18 +57,38 @@ public class PatternLoggerTest { Assert.assertTrue(logger.isWarnEnable()); Assert.assertTrue(logger.isErrorEnable()); + ArgumentCaptor argument = ArgumentCaptor.forClass(String.class); logger.debug("hello world"); + Mockito.verify(output, times(1)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("DEBUG [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); logger.debug("hello {}", "world"); + Mockito.verify(output, times(2)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("DEBUG [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); + logger.info("hello world"); + Mockito.verify(output, times(3)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("INFO [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); logger.info("hello {}", "world"); + Mockito.verify(output, times(4)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("INFO [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); logger.warn("hello {}", "world"); + Mockito.verify(output, times(5)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("WARN [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); logger.warn("hello world"); + Mockito.verify(output, times(6)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("WARN [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); + logger.error("hello world"); + Mockito.verify(output, times(7)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("ERROR [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); logger.error("hello world", new NullPointerException()); + Mockito.verify(output, times(8)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("ERROR [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello world")); + Assert.assertThat(argument.getValue(), StringContains.containsString("java.lang.NullPointerException")); logger.error(new NullPointerException(), "hello {}", "world"); - - Mockito.verify(output, times(9)).write(anyString()); + Mockito.verify(output, times(9)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("java.lang.NullPointerException")); } @Test @@ -86,18 +106,37 @@ public class PatternLoggerTest { Assert.assertTrue(logger.isWarnEnable()); Assert.assertTrue(logger.isErrorEnable()); + ArgumentCaptor argument = ArgumentCaptor.forClass(String.class); logger.debug("$^!@#*()"); + Mockito.verify(output, times(1)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("DEBUG [testAppFromConfig,,,] [main] PatternLoggerTest:-1 $^!@#*()")); logger.debug("hello {}", "!@#$%^&*(),./[]:;"); + Mockito.verify(output, times(2)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("DEBUG [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello !@#$%^&*(),./[]:;")); + logger.info("{}{}"); + Mockito.verify(output, times(3)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("INFO [testAppFromConfig,,,] [main] PatternLoggerTest:-1 {}{}")); logger.info("hello {}", "{}{}"); + Mockito.verify(output, times(4)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("INFO [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello {}{}")); logger.warn("hello {}", "\\"); + Mockito.verify(output, times(5)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("WARN [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello \\")); logger.warn("hello \\"); + Mockito.verify(output, times(6)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("WARN [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello \\")); + logger.error("hello <>.."); + Mockito.verify(output, times(7)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("ERROR [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello <>..")); logger.error("hello ///\\\\", new NullPointerException()); + Mockito.verify(output, times(8)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("ERROR [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello ///\\\\")); logger.error(new NullPointerException(), "hello {}", "&&&**%%"); - - Mockito.verify(output, times(9)).write(anyString()); + Mockito.verify(output, times(9)).write(argument.capture()); + Assert.assertThat(argument.getValue(), StringContains.containsString("ERROR [testAppFromConfig,,,] [main] PatternLoggerTest:-1 hello &&&**%%")); } @Test diff --git a/apm-sniffer/apm-agent/src/main/java/org/apache/skywalking/apm/agent/SkyWalkingAgent.java b/apm-sniffer/apm-agent/src/main/java/org/apache/skywalking/apm/agent/SkyWalkingAgent.java index 7167d29c43..b32708931e 100644 --- a/apm-sniffer/apm-agent/src/main/java/org/apache/skywalking/apm/agent/SkyWalkingAgent.java +++ b/apm-sniffer/apm-agent/src/main/java/org/apache/skywalking/apm/agent/SkyWalkingAgent.java @@ -20,6 +20,7 @@ package org.apache.skywalking.apm.agent; import java.lang.instrument.Instrumentation; import java.util.List; + import net.bytebuddy.ByteBuddy; import net.bytebuddy.agent.builder.AgentBuilder; import net.bytebuddy.description.NamedElement; @@ -53,7 +54,7 @@ import static net.bytebuddy.matcher.ElementMatchers.not; * The main entrance of sky-walking agent, based on javaagent mechanism. */ public class SkyWalkingAgent { - private static final ILog LOGGER = LogManager.getLogger(SkyWalkingAgent.class); + private static ILog LOGGER = LogManager.getLogger(SkyWalkingAgent.class); /** * Main entrance. Use byte-buddy transform to enhance all classes, which define in plugins. @@ -62,7 +63,17 @@ public class SkyWalkingAgent { final PluginFinder pluginFinder; try { SnifferConfigInitializer.initializeCoreConfig(agentArgs); + } catch (Exception e) { + // try to resolve a new logger, and use the new logger to write the error log here + LogManager.getLogger(SkyWalkingAgent.class) + .error(e, "SkyWalking agent initialized failure. Shutting down."); + return; + } finally { + // refresh logger again after initialization finishes + LOGGER = LogManager.getLogger(SkyWalkingAgent.class); + } + try { pluginFinder = new PluginFinder(new PluginBootstrap().loadPlugins()); } catch (AgentPackageNotFoundException ape) { LOGGER.error(ape, "Locate agent.jar failure. Shutting down."); @@ -75,14 +86,15 @@ public class SkyWalkingAgent { final ByteBuddy byteBuddy = new ByteBuddy().with(TypeValidation.of(Config.Agent.IS_OPEN_DEBUGGING_CLASS)); AgentBuilder agentBuilder = new AgentBuilder.Default(byteBuddy).ignore( - nameStartsWith("net.bytebuddy.").or(nameStartsWith("org.slf4j.")) - .or(nameStartsWith("org.groovy.")) - .or(nameContains("javassist")) - .or(nameContains(".asm.")) - .or(nameContains(".reflectasm.")) - .or(nameStartsWith("sun.reflect")) - .or(allSkyWalkingAgentExcludeToolkit()) - .or(ElementMatchers.isSynthetic())); + nameStartsWith("net.bytebuddy.") + .or(nameStartsWith("org.slf4j.")) + .or(nameStartsWith("org.groovy.")) + .or(nameContains("javassist")) + .or(nameContains(".asm.")) + .or(nameContains(".reflectasm.")) + .or(nameStartsWith("sun.reflect")) + .or(allSkyWalkingAgentExcludeToolkit()) + .or(ElementMatchers.isSynthetic())); JDK9ModuleExporter.EdgeClasses edgeClasses = new JDK9ModuleExporter.EdgeClasses(); try { @@ -121,7 +133,7 @@ public class SkyWalkingAgent { } Runtime.getRuntime() - .addShutdownHook(new Thread(ServiceManager.INSTANCE::shutdown, "skywalking service shutdown thread")); + .addShutdownHook(new Thread(ServiceManager.INSTANCE::shutdown, "skywalking service shutdown thread")); } private static class Transformer implements AgentBuilder.Transformer { @@ -142,7 +154,7 @@ public class SkyWalkingAgent { EnhanceContext context = new EnhanceContext(); for (AbstractClassEnhancePluginDefine define : pluginDefines) { DynamicType.Builder possibleNewBuilder = define.define( - typeDescription, newBuilder, classLoader, context); + typeDescription, newBuilder, classLoader, context); if (possibleNewBuilder != null) { newBuilder = possibleNewBuilder; } diff --git a/apm-sniffer/apm-sdk-plugin/solrj-7.x-plugin/pom.xml b/apm-sniffer/apm-sdk-plugin/solrj-7.x-plugin/pom.xml index 153d5f4b5d..fb7983f0fd 100644 --- a/apm-sniffer/apm-sdk-plugin/solrj-7.x-plugin/pom.xml +++ b/apm-sniffer/apm-sdk-plugin/solrj-7.x-plugin/pom.xml @@ -42,6 +42,12 @@ ${solr-solrj.version} provided + + + org.openjdk.jmh + jmh-generator-annprocess + test + \ No newline at end of file diff --git a/apm-sniffer/apm-test-tools/pom.xml b/apm-sniffer/apm-test-tools/pom.xml index f13ce0f206..dc252632db 100644 --- a/apm-sniffer/apm-test-tools/pom.xml +++ b/apm-sniffer/apm-test-tools/pom.xml @@ -47,5 +47,10 @@ ${project.version} provided + + org.openjdk.jmh + jmh-generator-annprocess + test + diff --git a/docs/en/setup/service-agent/java-agent/README.md b/docs/en/setup/service-agent/java-agent/README.md index cbdf94e90e..44cb374acc 100755 --- a/docs/en/setup/service-agent/java-agent/README.md +++ b/docs/en/setup/service-agent/java-agent/README.md @@ -96,7 +96,8 @@ property key | Description | Default | `logging.file_name`|Log file name.|`skywalking-api.log`| `logging.output`| Log output. Default is FILE. Use CONSOLE means output to stdout. |`FILE`| `logging.dir`|Log files directory. Default is blank string, means, use "{theSkywalkingAgentJarDir}/logs " to output logs. {theSkywalkingAgentJarDir} is the directory where the skywalking agent jar file is located |`""`| -`logging.pattern `|logging format. There are all conversion specifiers:
  * `%level` means log level.
  * `%timestamp` means now of time with format `yyyy-MM-dd HH:mm:ss:SSS`.
  * `%thread` means name of current thread.
  * `%msg` means some message which user logged.
  * `%class` means SimpleName of TargetClass.
  * `%throwable` means a throwable which user called.
  * `%agent_name` means `agent.service_name` |`%level %timestamp %thread %class : %msg %throwable`| +`logging.resolver`|Logger resolver: `PATTERN` or `JSON`. The default is `PATTERN`, which uses `logging.pattern` to print traditional text logs. `JSON` resolver prints logs in JSON format. |`PATTERN`| +`logging.pattern `|Logging format. There are all conversion specifiers:
  * `%level` means log level.
  * `%timestamp` means now of time with format `yyyy-MM-dd HH:mm:ss:SSS`.
  * `%thread` means name of current thread.
  * `%msg` means some message which user logged.
  * `%class` means SimpleName of TargetClass.
  * `%throwable` means a throwable which user called.
  * `%agent_name` means `agent.service_name`. Only apply to the `PatternLogger`. |`%level %timestamp %thread %class : %msg %throwable`| `logging.max_file_size`|The max size of log file. If the size is bigger than this, archive the current file, and write into a new file.|`300 * 1024 * 1024`| `logging.max_history_files`|The max history log files. When rollover happened, if log files exceed this number,then the oldest file will be delete. Negative or zero means off, by default.|`-1`| `jvm.buffer_size`|The buffer size of collected JVM info.|`60 * 10`| diff --git a/pom.xml b/pom.xml index cad5f0d082..667fdcdc52 100755 --- a/pom.xml +++ b/pom.xml @@ -250,6 +250,7 @@ ${jmh.version} test + org.projectlombok lombok @@ -290,6 +291,12 @@ ${powermock.version} test + + org.openjdk.jmh + jmh-generator-annprocess + ${jmh.version} + test + @@ -588,7 +595,9 @@ org/apache/skywalking/oap/server/core/remote/grpc/proto/*.java, org/apache/skywalking/oal/rt/grammar/*.java, org/apache/skywalking/oap/server/exporter/grpc/*.java, - org/apache/skywalking/oap/server/configuration/service/*.java + org/apache/skywalking/oap/server/configuration/service/*.java, + **/generated/*_jmhType*.java, + **/generated/*_jmhTest.java import.control=apm-checkstyle/importControl.xml -- GitLab