WIP: testing of Slf4jLog

This commit is contained in:
Joakim Erdfelt 2011-10-27 15:56:32 -07:00
parent 903c5dcbbf
commit a87286a17c
12 changed files with 510 additions and 161 deletions

View File

@ -66,13 +66,51 @@
<onlyAnalyze>org.eclipse.jetty.util.*</onlyAnalyze>
</configuration>
</plugin>
<!--
Copies the slf4j jars into a place where they can be used for a few targeted test cases.
and not infect the rest of the running tests due to automatic discovery in the org.eclipse.jetty.util.log.Log
class
-->
<plugin>
<groupId>org.apache.maven.plugins</groupId>
<artifactId>maven-dependency-plugin</artifactId>
<version>2.1</version>
<executions>
<execution>
<id>copy-slf4j-test-jars</id>
<phase>generate-resources</phase>
<goals>
<goal>copy</goal>
</goals>
<configuration>
<artifactItems>
<artifactItem>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.6.1</version>
<type>jar</type>
</artifactItem>
<artifactItem>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-jdk14</artifactId>
<version>1.6.1</version>
<type>jar</type>
</artifactItem>
</artifactItems>
<overWriteIfNewer>true</overWriteIfNewer>
<overWriteSnapshots>true</overWriteSnapshots>
<outputDirectory>${project.build.directory}/test-jars</outputDirectory>
</configuration>
</execution>
</executions>
</plugin>
</plugins>
</build>
<dependencies>
<dependency>
<groupId>org.eclipse.jetty.toolchain</groupId>
<artifactId>jetty-test-helper</artifactId>
<scope>test</scope>
<groupId>org.eclipse.jetty.toolchain</groupId>
<artifactId>jetty-test-helper</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>

View File

@ -24,13 +24,8 @@ import java.util.logging.Level;
* </p>
*
* <p>
* Honors the standard jetty system property <code>"org.eclipse.jetty.util.log.DEBUG"</code> to set logger into debug
* mode (defaults to false, set to "true" to enable)
* </p>
*
* <p>
* You can also set the logger level using <a href="http://java.sun.com/j2se/1.5.0/docs/guide/logging/overview.html">
* standard java.util.logging configuration</a> against the name <code>"org.eclipse.jetty.util.log"</code>.
* standard java.util.logging configuration</a>.
* </p>
*/
public class JavaUtilLog implements Logger

View File

@ -62,12 +62,16 @@ public class Log
public static boolean initialized()
{
if (LOG != null)
{
return true;
}
synchronized (Log.class)
{
if (__initialized)
{
return LOG != null;
}
__initialized = true;
}
@ -80,11 +84,14 @@ public class Log
LOG.debug("Logging to {} via {}", LOG, log_class.getName());
}
}
catch(ThreadDeath e)
{
// Let ThreadDeath pass through
throw e;
}
catch(Throwable e)
{
if (e instanceof ThreadDeath)
throw (ThreadDeath)e;
// Unable to load specified Logger implementation, default to standard logging.
initStandardLogging(e);
}
@ -95,7 +102,10 @@ public class Log
{
Class<?> log_class;
if(e != null && __ignored)
{
e.printStackTrace();
}
if (LOG == null)
{
log_class = StdErrLog.class;

View File

@ -25,7 +25,6 @@ public class Slf4jLog implements Logger
public Slf4jLog() throws Exception
{
this("org.eclipse.jetty.util.log");
}
public Slf4jLog(String name)
@ -42,6 +41,7 @@ public class Slf4jLog implements Logger
}
org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger( name );
// Fix LocationAwareLogger use to indicate FQCN of this class -
// https://bugs.eclipse.org/bugs/show_bug.cgi?id=276670
if (logger instanceof org.slf4j.spi.LocationAwareLogger)

View File

@ -600,6 +600,7 @@ public class StdErrLog implements Logger
sel.setPrintLongNames(_printLongNames);
// Let Level come from configured Properties instead - sel.setLevel(_level);
sel.setSource(_source);
sel._stderr = this._stderr;
logger = __loggers.putIfAbsent(fullname,sel);
if (logger == null)
{

View File

@ -0,0 +1,76 @@
package org.eclipse.jetty.util.log;
import static org.hamcrest.Matchers.*;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.ArrayList;
import java.util.List;
import java.util.logging.Handler;
import java.util.logging.LogRecord;
import org.eclipse.jetty.util.IO;
import org.junit.Assert;
public class CapturingJULHandler extends Handler
{
private List<String> lines = new ArrayList<String>();
@Override
public void publish(LogRecord record)
{
StringBuilder buf = new StringBuilder();
buf.append(record.getLevel().getName()).append("|");
String logname = record.getLoggerName();
int idx = logname.lastIndexOf('.');
if (idx > 0)
{
logname = logname.substring(idx + 1);
}
buf.append(logname);
buf.append("|");
buf.append(record.getMessage());
lines.add(buf.toString());
if (record.getThrown() != null)
{
StringWriter sw = new StringWriter(128);
PrintWriter capture = new PrintWriter(sw);
record.getThrown().printStackTrace(capture);
capture.flush();
lines.add(sw.toString());
IO.close(capture);
}
}
public void clear()
{
lines.clear();
}
@Override
public void flush()
{
/* do nothing */
}
@Override
public void close() throws SecurityException
{
/* do nothing */
}
public void dump()
{
for (String line : lines)
{
System.out.println(line);
}
}
public void assertContainsLine(String line)
{
Assert.assertThat(lines, contains(line));
}
}

View File

@ -0,0 +1,58 @@
package org.eclipse.jetty.util.log;
import java.util.logging.Handler;
import java.util.logging.LogManager;
import org.junit.AfterClass;
import org.junit.BeforeClass;
import org.junit.Test;
public class JavaUtilLogTest
{
private static Handler[] originalHandlers;
private static CapturingJULHandler jul;
@BeforeClass
public static void setJUL()
{
LogManager lmgr = LogManager.getLogManager();
java.util.logging.Logger root = lmgr.getLogger("");
// Remember original handlers
originalHandlers = root.getHandlers();
// Remove original handlers
for (Handler existing : originalHandlers)
{
root.removeHandler(existing);
}
// Set test/capturing handler
jul = new CapturingJULHandler();
root.addHandler(jul);
}
@AfterClass
public static void restoreJUL()
{
LogManager lmgr = LogManager.getLogManager();
java.util.logging.Logger root = lmgr.getLogger("");
// Remove test handlers
for (Handler existing : root.getHandlers())
{
root.removeHandler(existing);
}
// Restore original handlers
for (Handler original : originalHandlers)
{
root.addHandler(original);
}
}
@Test
public void testNamedLogger()
{
jul.clear();
JavaUtilLog log = new JavaUtilLog("test");
log.info("Info test");
jul.assertContainsLine("INFO|test|Info test");
}
}

View File

@ -13,165 +13,51 @@
package org.eclipse.jetty.util.log;
import static org.junit.Assert.*;
import static org.hamcrest.Matchers.*;
import java.io.ByteArrayOutputStream;
import java.io.PrintStream;
import junit.framework.Assert;
import org.junit.AfterClass;
import org.junit.BeforeClass;
import org.junit.Assert;
import org.junit.Ignore;
import org.junit.Test;
import org.junit.runner.RunWith;
@RunWith(Slf4jTestJarsRunner.class)
public class LogTest
{
static PrintStream _orig= System.err;
static ByteArrayOutputStream _out = new ByteArrayOutputStream();
static PrintStream _pout = new PrintStream(_out);
@BeforeClass
public static void setUp()
{
System.setErr(_pout);
}
@AfterClass
public static void tearDown()
{
System.setErr(_orig);
}
private void logNotContains(String text)
{
_pout.flush();
String err = _out.toString();
_out.reset();
if (err.indexOf(text)<0)
return;
_orig.println("FAIL '"+text+"' in '"+err+"'");
assertTrue(false);
}
private void logContains(String text)
{
_pout.flush();
String err = _out.toString();
_out.reset();
err = err.replaceAll("\r\n","\n");
text = text.replaceAll("\r\n","\n");
if (err.indexOf(text)>=0)
return;
_orig.println("FAIL '"+text+"' not in '"+err+"'");
assertTrue(false);
}
@Test
public void testStdErrLogFormat()
public void testNamedLogNamed_StdErrLog()
{
StdErrLog log = new StdErrLog(LogTest.class.getName());
Log.setLog(new StdErrLog());
log.info("testing:{},{}","test","format");
logContains("INFO:oejul.LogTest:testing:test,format");
log.info("testing:{}","test","format");
logContains("INFO:oejul.LogTest:testing:test format");
log.info("testing","test","format");
logContains("INFO:oejul.LogTest:testing test format");
log.info("testing:{},{}","test",null);
logContains("INFO:oejul.LogTest:testing:test,null");
log.info("testing {} {}",null,null);
logContains("INFO:oejul.LogTest:testing null null");
log.info("testing:{}",null,null);
logContains("INFO:oejul.LogTest:testing:null");
log.info("testing",null,null);
logContains("INFO:oejul.LogTest:testing");
assertNamedLogging(Red.class);
assertNamedLogging(Blue.class);
assertNamedLogging(Green.class);
}
@Test
public void testNamedLogNamed_JUL()
{
Log.setLog(new JavaUtilLog());
assertNamedLogging(Red.class);
assertNamedLogging(Blue.class);
assertNamedLogging(Green.class);
}
@Test
@Ignore
public void testNamedLogNamed_Slf4J() throws Exception
{
Log.setLog(new Slf4jLog());
assertNamedLogging(Red.class);
assertNamedLogging(Blue.class);
assertNamedLogging(Green.class);
}
@SuppressWarnings("deprecation")
@Test
public void testStdErrLogDebug()
private void assertNamedLogging(Class<?> clazz)
{
StdErrLog log = new StdErrLog("xxx");
log.setLevel(StdErrLog.LEVEL_DEBUG);
log.debug("testing {} {}","test","debug");
logContains("DBUG:xxx:testing test debug");
log.info("testing {} {}","test","info");
logContains("INFO:xxx:testing test info");
log.warn("testing {} {}","test","warn");
logContains("WARN:xxx:testing test warn");
log.setLevel(StdErrLog.LEVEL_INFO);
log.debug("YOU SHOULD NOT SEE THIS!",null,null);
logNotContains("YOU SHOULD NOT SEE THIS!");
// Test for backward compat with old (now deprecated) method
log.setDebugEnabled(true);
log.debug("testing {} {}","test","debug-deprecated");
logContains("DBUG:xxx:testing test debug-deprecated");
log.setDebugEnabled(false);
log.debug("testing {} {}","test","debug-deprecated-false");
logNotContains("DBUG:xxx:testing test debug-depdeprecated-false");
}
@Test
public void testStdErrLogName()
{
StdErrLog log = new StdErrLog("test");
log.setPrintLongNames(true);
Assert.assertEquals("test",log.getName());
Logger next=log.getLogger("next");
Assert.assertEquals("test.next",next.getName());
next.info("testing {} {}","next","info");
logContains(":test.next:testing next info");
}
@Test
public void testStdErrThrowable()
{
Throwable th = new Throwable("Message");
th.printStackTrace();
_pout.flush();
String ths = _out.toString();
_out.reset();
StdErrLog log = new StdErrLog("test");
log.warn("ex",th);
logContains(ths);
th = new Throwable("Message with \033 escape");
log.warn("ex",th);
logNotContains("Message with \033 escape");
log.info(th.toString());
logNotContains("Message with \033 escape");
log.warn("ex",th);
logContains("Message with ? escape");
log.info(th.toString());
logContains("Message with ? escape");
Logger lc = Log.getLogger(clazz);
Assert.assertThat("Named logging (impl=" + Log.getLog().getClass().getName() + ")",lc.getName(),is(clazz.getName()));
}
}

View File

@ -0,0 +1,42 @@
package org.eclipse.jetty.util.log;
import java.io.File;
import java.io.FileFilter;
import java.net.MalformedURLException;
import java.net.URL;
import java.net.URLClassLoader;
import org.eclipse.jetty.toolchain.test.MavenTestingUtils;
import org.junit.Assume;
public final class Slf4jHelper
{
public static ClassLoader createTestClassLoader(ClassLoader parentClassLoader) throws MalformedURLException
{
File testJarDir = MavenTestingUtils.getTargetFile("test-jars");
Assume.assumeTrue(testJarDir.exists()); // trigger @Ignore if dir not there
File jarfiles[] = testJarDir.listFiles(new FileFilter()
{
public boolean accept(File path)
{
if (!path.isFile())
{
return false;
}
return path.getName().endsWith(".jar");
}
});
Assume.assumeTrue(jarfiles.length > 0); // trigger @Ignore if no jar files.
URL urls[] = new URL[jarfiles.length];
for (int i = 0; i < jarfiles.length; i++)
{
urls[i] = jarfiles[i].toURI().toURL();
// System.out.println("Adding test-jar => " + urls[i]);
}
return new URLClassLoader(urls,parentClassLoader);
}
}

View File

@ -0,0 +1,107 @@
package org.eclipse.jetty.util.log;
import java.io.File;
import java.io.FileFilter;
import java.net.MalformedURLException;
import java.net.URL;
import java.net.URLClassLoader;
import java.util.ArrayList;
import java.util.List;
import org.eclipse.jetty.toolchain.test.MavenTestingUtils;
import org.junit.Assume;
import org.junit.runner.notification.RunNotifier;
import org.junit.runners.BlockJUnit4ClassRunner;
import org.junit.runners.model.FrameworkMethod;
import org.junit.runners.model.InitializationError;
public class Slf4jTestJarsRunner extends BlockJUnit4ClassRunner
{
private static class Slf4jTestClassLoader extends URLClassLoader
{
public Slf4jTestClassLoader(URL[] urls)
{
super(urls);
}
@Override
public Class<?> loadClass(String name) throws ClassNotFoundException
{
System.err.printf("[slf4j.cl] loadClass(%s)%n", name);
return super.loadClass(name);
}
@Override
protected Class<?> findClass(String name) throws ClassNotFoundException
{
System.err.printf("[slf4j.cl] findClass(%s)%n", name);
return super.findClass(name);
}
}
private ClassLoader original;
private URLClassLoader slf4jClassLoader;
public Slf4jTestJarsRunner(Class<?> klass) throws InitializationError
{
super(klass);
original = Thread.currentThread().getContextClassLoader();
File testJarDir = MavenTestingUtils.getTargetFile("test-jars");
Assume.assumeTrue(testJarDir.exists()); // trigger @Ignore if dir not there
File jarfiles[] = testJarDir.listFiles(new FileFilter()
{
public boolean accept(File path)
{
if (!path.isFile())
{
return false;
}
return path.getName().endsWith(".jar");
}
});
Assume.assumeTrue(jarfiles.length > 0); // trigger @Ignore if no jar files.
try
{
List<URL> urlist = new ArrayList<URL>();
for (File path : jarfiles)
{
urlist.add(path.toURI().toURL());
}
for (String entry : System.getProperty("java.class.path").split(File.pathSeparator))
{
File path = new File(entry);
if (path.exists())
{
urlist.add(path.toURI().toURL());
}
}
URL urls[] = urlist.toArray(new URL[urlist.size()]);
slf4jClassLoader = new Slf4jTestClassLoader(urls);
}
catch (MalformedURLException e)
{
throw new InitializationError(e);
}
}
@Override
protected void runChild(FrameworkMethod method, RunNotifier notifier)
{
try
{
Thread.currentThread().setContextClassLoader(slf4jClassLoader);
super.runChild(method,notifier);
}
finally
{
Thread.currentThread().setContextClassLoader(original);
}
}
}

View File

@ -0,0 +1,35 @@
package org.eclipse.jetty.util.log;
import static org.hamcrest.Matchers.*;
import java.io.ByteArrayOutputStream;
import java.io.PrintStream;
import org.junit.Assert;
public class StdErrCapture
{
private ByteArrayOutputStream test;
private PrintStream err;
public StdErrCapture(StdErrLog log)
{
test = new ByteArrayOutputStream();
err = new PrintStream(test);
log.setStdErrStream(err);
}
public void assertContains(String expectedString)
{
err.flush();
String output = new String(test.toByteArray());
Assert.assertThat(output, containsString(expectedString));
}
public void assertNotContains(String unexpectedString)
{
err.flush();
String output = new String(test.toByteArray());
Assert.assertThat(output, not(containsString(unexpectedString)));
}
}

View File

@ -17,6 +17,8 @@ import static org.hamcrest.Matchers.*;
import java.io.ByteArrayOutputStream;
import java.io.PrintStream;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.io.UnsupportedEncodingException;
import java.util.Properties;
@ -28,6 +30,105 @@ import org.junit.Test;
*/
public class StdErrLogTest
{
@Test
public void testStdErrLogFormat() throws UnsupportedEncodingException
{
StdErrLog log = new StdErrLog(LogTest.class.getName());
StdErrCapture output = new StdErrCapture(log);
log.info("testing:{},{}","test","format1");
log.info("testing:{}","test","format2");
log.info("testing","test","format3");
log.info("testing:{},{}","test",null);
log.info("testing {} {}",null,null);
log.info("testing:{}",null,null);
log.info("testing",null,null);
output.assertContains("INFO:oejul.LogTest:testing:test,format1");
output.assertContains("INFO:oejul.LogTest:testing:test,format1");
output.assertContains("INFO:oejul.LogTest:testing:test format2");
output.assertContains("INFO:oejul.LogTest:testing test format3");
output.assertContains("INFO:oejul.LogTest:testing:test,null");
output.assertContains("INFO:oejul.LogTest:testing null null");
output.assertContains("INFO:oejul.LogTest:testing:null");
output.assertContains("INFO:oejul.LogTest:testing");
}
@SuppressWarnings("deprecation")
@Test
public void testStdErrLogDebug()
{
StdErrLog log = new StdErrLog("xxx");
StdErrCapture output = new StdErrCapture(log);
log.setLevel(StdErrLog.LEVEL_DEBUG);
log.debug("testing {} {}","test","debug");
log.info("testing {} {}","test","info");
log.warn("testing {} {}","test","warn");
log.setLevel(StdErrLog.LEVEL_INFO);
log.debug("YOU SHOULD NOT SEE THIS!",null,null);
// Test for backward compat with old (now deprecated) method
log.setDebugEnabled(true);
log.debug("testing {} {}","test","debug-deprecated");
log.setDebugEnabled(false);
log.debug("testing {} {}","test","debug-deprecated-false");
output.assertContains("DBUG:xxx:testing test debug");
output.assertContains("INFO:xxx:testing test info");
output.assertContains("WARN:xxx:testing test warn");
output.assertNotContains("YOU SHOULD NOT SEE THIS!");
output.assertContains("DBUG:xxx:testing test debug-deprecated");
output.assertNotContains("DBUG:xxx:testing test debug-depdeprecated-false");
}
@Test
public void testStdErrLogName()
{
StdErrLog log = new StdErrLog("test");
log.setPrintLongNames(true);
StdErrCapture output = new StdErrCapture(log);
Assert.assertThat("Log.name", log.getName(), is("test"));
Logger next=log.getLogger("next");
Assert.assertThat("Log.name(child)", next.getName(), is("test.next"));
next.info("testing {} {}","next","info");
output.assertContains(":test.next:testing next info");
}
@Test
public void testStdErrThrowable()
{
// Common Throwable (for test)
Throwable th = new Throwable("Message");
// Capture raw string form
StringWriter tout = new StringWriter();
th.printStackTrace(new PrintWriter(tout));
String ths = tout.toString();
// Start test
StdErrLog log = new StdErrLog("test");
StdErrCapture output = new StdErrCapture(log);
log.warn("ex",th);
output.assertContains(ths);
th = new Throwable("Message with \033 escape");
log.warn("ex",th);
output.assertNotContains("Message with \033 escape");
log.info(th.toString());
output.assertNotContains("Message with \033 escape");
log.warn("ex",th);
output.assertContains("Message with ? escape");
log.info(th.toString());
output.assertContains("Message with ? escape");
}
/**
* Test to make sure that using a Null parameter on parameterized messages does not result in a NPE
*/