#509 executor log normalization

saturn-core/src/main/java/com/vip/saturn/job/executor/ResetCountService.java

@@ -4,6 +4,8 @@
 package com.vip.saturn.job.executor;
 
 import com.vip.saturn.job.internal.statistics.ProcessCountResetTask;
+import com.vip.saturn.job.utils.LogEvents;
+import com.vip.saturn.job.utils.LogUtils;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
@@ -41,7 +43,7 @@ public void startRestCountTimer() {
 			date = startDT.getTime();
 		}
 		countResetTimer.schedule(countResetTask, date, 24 * 60 * 60 * 1000L); // 时间间隔(一天)
-		log.info("msg=start the task of resetting statistics data");
+		LogUtils.info(log, LogEvents.ExecutorEvent.INIT, "start the task of resetting statistics data");
 	}
 
 	public void shutdownRestCountTimer() {

saturn-core/src/main/java/com/vip/saturn/job/utils/LogUtils.java

@@ -6,6 +6,9 @@ public class LogUtils {
 
 	private static final String FORMAT_FOR_LOG = "[{}] msg={}";
 
+	private LogUtils() {
+	}
+
 	/**
 	 * @param logger slf4j logger
 	 * @param eventName 事件名

saturn-core/src/test/java/com/vip/saturn/job/utils/LogUtilsTest.java

@@ -0,0 +1,168 @@
+package com.vip.saturn.job.utils;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.AppenderBase;
+import com.google.common.collect.Lists;
+import org.junit.*;
+import org.slf4j.LoggerFactory;
+
+import java.util.List;
+
+import static org.junit.Assert.assertEquals;
+
+public class LogUtilsTest {
+
+	private static TestLogAppender testLogAppender = new TestLogAppender();
+
+	private static ch.qos.logback.classic.Logger log;
+
+	@BeforeClass
+	public static void before() {
+		log = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(LogUtilsTest.class);
+		if (testLogAppender != null) {
+			testLogAppender.clear();
+		}
+
+		log.addAppender(testLogAppender);
+	}
+
+	@AfterClass
+	public static void after() {
+		if (testLogAppender != null) {
+			log.detachAppender(testLogAppender);
+		}
+	}
+
+	@After
+	public void afterTest() {
+		testLogAppender.clear();
+	}
+
+	@Test
+	public void info() {
+		LogUtils.info(log, "event", "this is info");
+		assertEquals("[event] msg=this is info", testLogAppender.getLastMessage());
+
+		LogUtils.info(log, "event", "this is info {}", "info1");
+		assertEquals("[event] msg=this is info info1", testLogAppender.getLastMessage());
+
+		LogUtils.info(log, "event", "this is info {} {}", "info1", "info2");
+		assertEquals("[event] msg=this is info info1 info2", testLogAppender.getLastMessage());
+
+		LogUtils.info(log, "event", "this is info {} {}", "info1", "info2", new ClassNotFoundException("com.abc"));
+		assertEquals("[event] msg=this is info info1 info2", testLogAppender.getLastMessage());
+		assertEquals("com.abc", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+
+		LogUtils.info(log, "event", "this is error {}", "error1", new Error("com.def"));
+		assertEquals("[event] msg=this is error error1", testLogAppender.getLastMessage());
+		assertEquals("com.def", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+	}
+
+	@Test
+	public void debug() {
+		LogUtils.debug(log, "event", "this is debug");
+		assertEquals("[event] msg=this is debug", testLogAppender.getLastMessage());
+
+		LogUtils.debug(log, "event", "this is debug {}", "info1");
+		assertEquals("[event] msg=this is debug info1", testLogAppender.getLastMessage());
+
+		LogUtils.debug(log, "event", "this is debug {} {}", "info1", "info2");
+		assertEquals("[event] msg=this is debug info1 info2", testLogAppender.getLastMessage());
+
+		LogUtils.debug(log, "event", "this is debug {} {}", "info1", "info2", new ClassNotFoundException("com.abc"));
+		assertEquals("[event] msg=this is debug info1 info2", testLogAppender.getLastMessage());
+		assertEquals("com.abc", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+
+		LogUtils.debug(log, "event", "this is error {}", "error1", new Error("com.def"));
+		assertEquals("[event] msg=this is error error1", testLogAppender.getLastMessage());
+		assertEquals("com.def", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+	}
+
+	@Test
+	public void error() {
+		LogUtils.error(log, "event", "this is error");
+		assertEquals("[event] msg=this is error", testLogAppender.getLastMessage());
+
+		LogUtils.error(log, "event", "this is error {}", "info1");
+		assertEquals("[event] msg=this is error info1", testLogAppender.getLastMessage());
+
+		LogUtils.error(log, "event", "this is error {} {}", "info1", "info2");
+		assertEquals("[event] msg=this is error info1 info2", testLogAppender.getLastMessage());
+
+		LogUtils.error(log, "event", "this is error {} {}", "info1", "info2", new ClassNotFoundException("com.abc"));
+		assertEquals("[event] msg=this is error info1 info2", testLogAppender.getLastMessage());
+		assertEquals("com.abc", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+
+		LogUtils.error(log, "event", "this is error {}", "error1", new Error("com.def"));
+		assertEquals("[event] msg=this is error error1", testLogAppender.getLastMessage());
+		assertEquals("com.def", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+	}
+
+	@Test
+	public void warn() {
+		LogUtils.warn(log, "event", "this is warn");
+		assertEquals("[event] msg=this is warn", testLogAppender.getLastMessage());
+
+		LogUtils.warn(log, "event", "this is warn {}", "info1");
+		assertEquals("[event] msg=this is warn info1", testLogAppender.getLastMessage());
+
+		LogUtils.warn(log, "event", "this is warn {} {}", "info1", "info2");
+		assertEquals("[event] msg=this is warn info1 info2", testLogAppender.getLastMessage());
+
+		LogUtils.warn(log, "event", "this is warn {} {}", "info1", "info2", new ClassNotFoundException("com.abc"));
+		assertEquals("[event] msg=this is warn info1 info2", testLogAppender.getLastMessage());
+		assertEquals("com.abc", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+
+		LogUtils.warn(log, "event", "this is warn {}", "error1", new Error("com.def"));
+		assertEquals("[event] msg=this is warn error1", testLogAppender.getLastMessage());
+		assertEquals("com.def", testLogAppender.getLastEvent().getThrowableProxy().getMessage());
+	}
+
+
+	public static final class TestLogAppender extends AppenderBase<ILoggingEvent> {
+		private List<ILoggingEvent> events = Lists.newArrayList();
+		private List<String> messages = Lists.newArrayList();
+
+		@Override
+		public synchronized void doAppend(ILoggingEvent eventObject) {
+			super.doAppend(eventObject);
+			events.add(eventObject);
+			messages.add(eventObject.getFormattedMessage());
+		}
+
+		@Override
+		protected void append(ILoggingEvent eventObject) {
+			events.add(eventObject);
+			messages.add(eventObject.getFormattedMessage());
+		}
+
+		public void clear() {
+			events.clear();
+			messages.clear();
+		}
+
+		public ILoggingEvent getLastEvent() {
+			if (events.size() == 0) {
+				return null;
+			}
+
+			return events.get(events.size() - 1);
+		}
+
+		public List<ILoggingEvent> getEvents() {
+			return events;
+		}
+
+		public List<String> getMessages() {
+			return messages;
+		}
+
+		public String getLastMessage() {
+			if (messages.size() == 0) {
+				return null;
+			}
+
+			return messages.get(messages.size() - 1);
+		}
+	}
+}

saturn-core/src/test/resources/logback-test.xml

@@ -12,6 +12,10 @@
             <pattern>${log.pattern}</pattern>
         </encoder>
     </appender>
+
+    <logger name="com.vip.saturn.job.utils" additivity="false">
+        <level value="ALL"/>
+    </logger>
 
     <root>
         <level value="WARN" />