Complete the unit tests for sentinel-logging-slf4j module (#1358)

sentinel-logging/sentinel-logging-slf4j/pom.xml

@@ -16,7 +16,7 @@
         <java.source.version>1.7</java.source.version>
         <java.target.version>1.7</java.target.version>
         <slf4j.version>1.7.25</slf4j.version>
-        <log4j2.version>2.12.1</log4j2.version>
+        <slf4j-test.version>1.2.0</slf4j-test.version>
     </properties>
 
     <dependencies>
@@ -30,31 +30,22 @@
             <version>${slf4j.version}</version>
             <scope>provided</scope>
         </dependency>
+        <!-- for unit test -->
         <dependency>
-            <groupId>org.apache.logging.log4j</groupId>
+            <groupId>uk.org.lidalia</groupId>
-            <artifactId>log4j-core</artifactId>
+            <artifactId>slf4j-test</artifactId>
-            <version>${log4j2.version}</version>
+            <version>${slf4j-test.version}</version>
             <scope>test</scope>
         </dependency>
-        <dependency>
-            <groupId>org.apache.logging.log4j</groupId>
-            <artifactId>log4j-slf4j-impl</artifactId>
-            <version>${log4j2.version}</version>
-            <scope>test</scope>
-        </dependency>
-
         <dependency>
             <groupId>junit</groupId>
             <artifactId>junit</artifactId>
             <scope>test</scope>
         </dependency>
-
         <dependency>
-            <groupId>com.github.stefanbirkner</groupId>
+            <groupId>org.mockito</groupId>
-            <artifactId>system-rules</artifactId>
+            <artifactId>mockito-core</artifactId>
-            <version>1.16.1</version>
             <scope>test</scope>
         </dependency>
-
     </dependencies>
 </project>

sentinel-logging/sentinel-logging-slf4j/src/test/java/com/alibaba/csp/sentinel/logging/slf4j/AbstraceSlf4jLogTest.java

@@ -0,0 +1,185 @@
+/*
+ * Copyright 1999-2018 Alibaba Group Holding Ltd.
+ *
+ * Licensed 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 com.alibaba.csp.sentinel.logging.slf4j;
+
+import uk.org.lidalia.slf4jext.Level;
+import uk.org.lidalia.slf4jtest.TestLoggerFactory;
+
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Test;
+import static org.mockito.Mockito.*;
+
+import java.io.PrintStream;
+
+/**
+ * @author xue8
+ * @author jason
+ */
+public abstract class AbstraceSlf4jLogTest {
+    private static final class TestException extends Exception {
+        private static final long serialVersionUID = 1L;
+        
+    }
+    PrintStream mockStream;
+    PrintStream oldOutStream;
+    PrintStream oldErrStream;
+    
+    protected abstract String getLoggerName();
+    protected abstract void debug(String msg, Object... args);
+    protected abstract void trace(String msg, Object... args);
+    protected abstract void info(String msg, Object... args);
+    protected abstract void warn(String msg, Object... args);
+    protected abstract void error(String msg, Object... args);
+    
+    @Before
+    public void mockOutput() {
+        System.out.println("Try to mock System.out and System.err");
+        mockStream = mock(PrintStream.class);
+        oldOutStream = System.out;
+        oldOutStream = System.out;
+        System.setOut(mockStream);
+        System.setErr(mockStream);
+        TestLoggerFactory.getInstance().setPrintLevel(Level.TRACE);
+    }
+    
+    @After
+    public void restore() {
+        if (oldOutStream != null) {
+            System.setOut(oldOutStream);
+            System.setErr(oldErrStream);
+            oldOutStream = null;
+            oldErrStream = null;
+            System.out.println("Restore System.out and System.err");
+        }
+    }
+
+    @Test
+    public void testRecordLog() {
+        info("init");
+        verify(mockStream).println(contains("init"));
+        clearInvocations(mockStream);
+        int count = 0;
+
+        // info test
+        while (count < 1000) { // 0~999
+            info("Count {}.", count);
+            count ++;
+        }
+        verify(mockStream).println(contains("Count 0."));
+        verify(mockStream).println(contains("Count 1."));
+        verify(mockStream).println(contains("Count 99."));
+        verify(mockStream).println(contains("Count 123."));
+        verify(mockStream).println(contains("Count 888."));
+        verify(mockStream).println(contains("Count 999."));
+        verify(mockStream, times(1000)).println(contains(" INFO "));
+        verify(mockStream, times(1000)).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // warn test
+        while (count < 2000) { // 1000~1999
+            warn("Count {}.", count);
+            count ++;
+        }
+        verify(mockStream).println(contains("Count 1000."));
+        verify(mockStream).println(contains("Count 1223."));
+        verify(mockStream).println(contains("Count 1888."));
+        verify(mockStream).println(contains("Count 1999."));
+        verify(mockStream, times(1000)).println(contains(" WARN "));
+        verify(mockStream, times(1000)).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // trace test
+        while (count < 3000) { // 2000~2999
+            trace("Count {}.", count);
+            count ++;
+        }
+        verify(mockStream).println(contains("Count 2000."));
+        verify(mockStream).println(contains("Count 2999."));
+        verify(mockStream, times(1000)).println(contains(" TRACE "));
+        verify(mockStream, times(1000)).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // debug test
+        while (count < 4000) { // 3000~3999
+            debug("Count {}.", count);
+            count ++;
+        }
+        verify(mockStream).println(contains("Count 3000."));
+        verify(mockStream).println(contains("Count 3999."));
+        verify(mockStream, times(1000)).println(contains(" DEBUG "));
+        verify(mockStream, times(1000)).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // test error
+        while (count < 5000) { // 4000~4999
+            error("Count {}.", count);
+            count ++;
+        }
+        verify(mockStream).println(contains("Count 4000."));
+        verify(mockStream).println(contains("Count 4999."));
+        verify(mockStream, times(1000)).println(contains(" ERROR "));
+        verify(mockStream, times(1000)).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+    }
+
+
+    @Test
+    public void testLogException() {
+        info("init");
+        verify(mockStream).println(contains("init"));
+        verify(mockStream, atLeastOnce()).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+        
+        Exception e = new TestException();
+
+        // info test
+        info("some log", e);
+        verify(mockStream).println(contains("INFO"));
+        verify(mockStream).println(isA(TestException.class));
+        verify(mockStream).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // warn test
+        warn("some log", e);
+        verify(mockStream).println(contains("WARN"));
+        verify(mockStream).println(isA(TestException.class));
+        verify(mockStream).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // trace test
+        trace("some log", e);
+        verify(mockStream).println(contains("TRACE"));
+        verify(mockStream).println(isA(TestException.class));
+        verify(mockStream).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // debug test
+        debug("some log", e);
+        verify(mockStream).println(contains("DEBUG"));
+        verify(mockStream).println(isA(TestException.class));
+        verify(mockStream).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+
+        // error test
+        error("some log", e);
+        verify(mockStream).println(contains("ERROR"));
+        verify(mockStream).println(isA(TestException.class));
+        verify(mockStream).println(contains(getLoggerName()));
+        clearInvocations(mockStream);
+    }
+}

sentinel-logging/sentinel-logging-slf4j/src/test/java/com/alibaba/csp/sentinel/logging/slf4j/CommandCenterLogTest.java

@@ -1,11 +1,11 @@
 /*
- * Copyright 1999-2019 Alibaba Group Holding Ltd.
+ * Copyright 1999-2018 Alibaba Group Holding Ltd.
  *
  * Licensed 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
  *
- *      https://www.apache.org/licenses/LICENSE-2.0
+ *      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,
@@ -13,103 +13,43 @@
  * See the License for the specific language governing permissions and
  * limitations under the License.
  */
+
 package com.alibaba.csp.sentinel.logging.slf4j;
 
 import com.alibaba.csp.sentinel.transport.log.CommandCenterLog;
-import org.junit.*;
-import org.junit.contrib.java.lang.system.SystemOutRule;
 
 /**
- * @author xue8
+ * @author jason
  */
-@Ignore("https://github.com/stefanbirkner/system-rules/issues/45. You can only run one @Test at a time")
+public class CommandCenterLogTest extends AbstraceSlf4jLogTest {
-public class CommandCenterLogTest {
-    @Rule
-    public SystemOutRule log = new SystemOutRule().enableLog();
 
-    @Test
+    @Override
-    public void testLog() {
+    protected String getLoggerName() {
-        CommandCenterLog.info("init");
+        return CommandCenterLog.LOGGER_NAME;
-        log.clearLog();
-        int count = 0;
-
-        // info test
-        while (count++ < 1000) {
-            log.clearLog();
-            CommandCenterLog.info("Count {}", count);
-            String str = String.format("INFO  sentinelCommandCenterLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // warn test
+    @Override
-        while (count++ < 2000) {
+    protected void debug(String msg, Object... args) {
-            log.clearLog();
+        CommandCenterLog.debug(msg, args);
-            CommandCenterLog.warn("Count {}", count);
-            String str = String.format("WARN  sentinelCommandCenterLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // trace test
+    @Override
-        while (count++ < 3000) {
+    protected void trace(String msg, Object... args) {
-            log.clearLog();
+        CommandCenterLog.trace(msg, args);
-            CommandCenterLog.trace("Count {}", count);
-            String str = String.format("TRACE sentinelCommandCenterLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // debug test
+    @Override
-        while (count++ < 4000) {
+    protected void info(String msg, Object... args) {
-            log.clearLog();
+        CommandCenterLog.info(msg, args);
-            CommandCenterLog.debug("Count {}", count);
-            String str = String.format("DEBUG sentinelCommandCenterLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // test error
+    @Override
-        while (count++ < 5000) {
+    protected void warn(String msg, Object... args) {
-            log.clearLog();
+        CommandCenterLog.warn(msg, args);
-            CommandCenterLog.error("Count {}", count);
-            String str = String.format("ERROR sentinelCommandCenterLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
-        }
     }
 
-    @Test
+    @Override
-    public void testLogException() {
+    protected void error(String msg, Object... args) {
-        CommandCenterLog.info("init");
+        CommandCenterLog.error(msg, args);
-        log.clearLog();
-        Exception e = new Exception("ex");
-
-        // info test
-        CommandCenterLog.info("Error", e);
-        // split the log for test
-        String[] logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("INFO  sentinelCommandCenterLogger - Error", logSplit[0]);
-
-        // warn test
-        log.clearLog();
-        CommandCenterLog.warn("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("WARN  sentinelCommandCenterLogger - Error", logSplit[0]);
-
-        // trace test
-        log.clearLog();
-        CommandCenterLog.trace("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("TRACE sentinelCommandCenterLogger - Error", logSplit[0]);
-
-        // debug test
-        log.clearLog();
-        CommandCenterLog.debug("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("DEBUG sentinelCommandCenterLogger - Error", logSplit[0]);
-
-        // error test
-        log.clearLog();
-        CommandCenterLog.error("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("ERROR sentinelCommandCenterLogger - Error", logSplit[0]);
     }
-
-
 }

sentinel-logging/sentinel-logging-slf4j/src/test/java/com/alibaba/csp/sentinel/logging/slf4j/RecordLogTest.java

@@ -17,102 +17,39 @@
 package com.alibaba.csp.sentinel.logging.slf4j;
 
 import com.alibaba.csp.sentinel.log.RecordLog;
-import org.junit.Assert;
-import org.junit.Ignore;
-import org.junit.Rule;
-import org.junit.Test;
-import org.junit.contrib.java.lang.system.SystemOutRule;
 
 /**
- * @author xue8
+ * @author jason
  */
-@Ignore("https://github.com/stefanbirkner/system-rules/issues/45. You can only run one @Test at a time")
+public class RecordLogTest extends AbstraceSlf4jLogTest {
-public class RecordLogTest {
-    @Rule
-    public SystemOutRule log = new SystemOutRule().enableLog();
 
-    @Test
+    @Override
-    public void testLog() {
+    protected String getLoggerName() {
-        RecordLog.info("init");
+        return RecordLog.LOGGER_NAME;
-        log.clearLog();
-        int count = 0;
-
-        // info test
-        while (count++ < 1000) {
-            log.clearLog();
-            RecordLog.info("Count {}", count);
-            String str = String.format("INFO  sentinelRecordLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // warn test
+    @Override
-        while (count++ < 2000) {
+    protected void debug(String msg, Object... args) {
-            log.clearLog();
+        RecordLog.debug(msg, args);
-            RecordLog.warn("Count {}", count);
-            String str = String.format("WARN  sentinelRecordLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // trace test
+    @Override
-        while (count++ < 3000) {
+    protected void trace(String msg, Object... args) {
-            log.clearLog();
+        RecordLog.trace(msg, args);
-            RecordLog.trace("Count {}", count);
-            String str = String.format("TRACE sentinelRecordLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // debug test
+    @Override
-        while (count++ < 4000) {
+    protected void info(String msg, Object... args) {
-            log.clearLog();
+        RecordLog.info(msg, args);
-            RecordLog.debug("Count {}", count);
-            String str = String.format("DEBUG sentinelRecordLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
     }
 
-        // test error
+    @Override
-        while (count++ < 5000) {
+    protected void warn(String msg, Object... args) {
-            log.clearLog();
+        RecordLog.warn(msg, args);
-            RecordLog.error("Count {}", count);
-            String str = String.format("ERROR sentinelRecordLogger - Count %d" + System.lineSeparator(), count);
-            Assert.assertEquals(str, log.getLog());
-        }
     }
 
-
+    @Override
-    @Test
+    protected void error(String msg, Object... args) {
-    public void testLogException() {
+        RecordLog.error(msg, args);
-        RecordLog.info("init");
-        log.clearLog();
-        Exception e = new Exception("ex");
-
-        // info test
-        RecordLog.info("Error", e);
-        // split the log for test
-        String[] logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("INFO  sentinelRecordLogger - Error", logSplit[0]);
-
-        // warn test
-        log.clearLog();
-        RecordLog.warn("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("WARN  sentinelRecordLogger - Error", logSplit[0]);
-
-        // trace test
-        log.clearLog();
-        RecordLog.trace("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("TRACE sentinelRecordLogger - Error", logSplit[0]);
-
-        // debug test
-        log.clearLog();
-        RecordLog.debug("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("DEBUG sentinelRecordLogger - Error", logSplit[0]);
-
-        // error test
-        log.clearLog();
-        RecordLog.error("Error", e);
-        logSplit = log.getLog().split(System.lineSeparator());
-        Assert.assertEquals("ERROR sentinelRecordLogger - Error", logSplit[0]);
     }
 }

sentinel-logging/sentinel-logging-slf4j/src/test/resources/log4j2.xml

@@ -1,25 +0,0 @@
-<?xml version="1.0" encoding="UTF-8" ?>
-<Configuration>
-    <Appenders>
-        <Console name="Console" target="SYSTEM_OUT">
-            <PatternLayout pattern="%-5level %logger - %msg%n"/>
-        </Console>
-        <File name="FILE" fileName="sentinel-record.log" append="false">
-            <PatternLayout pattern="%-5level %logger - %msg%n"/>
-        </File>
-        <File name="FILE2" fileName="sentinel-command-center.log" append="false">
-            <PatternLayout pattern="%-5level %logger - %msg%n"/>
-        </File>
-    </Appenders>
-    <Loggers>
-        <Root level="info"/>
-        <logger name="sentinelRecordLogger" level="trace">
-            <appender-ref ref="Console" />
-            <appender-ref ref="FILE" />
-        </logger>
-        <logger name="sentinelCommandCenterLogger" level="trace">
-            <appender-ref ref="Console" />
-            <appender-ref ref="FILE2" />
-        </logger>
-    </Loggers>
-</Configuration>