Actually, the javadoc for OutputStreamWriter confirms this. http://download.oracle.com/javase/6/docs/api/java/io/OutputStreamWriter.html
Ralph On Mar 19, 2011, at 7:40 PM, Ralph Goers wrote: > > On Mar 18, 2011, at 3:59 PM, Ceki Gülcü wrote: > >> On 18/03/2011 10:35 PM, [email protected] wrote: >>> For multithreaded case I slightly modified the test to run with 100 >>> threads, each producing 10000 log events. >>> The profile data shows high lock contention in method >>> ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(java.lang.Object) >>> (same >>> as I mentioned in my previous mail) >>> and thread dumps always reveal one runnable thread doing some writing >>> while all other threads are waiting for it. >>> Run times are typically 2-3 times worse than with log4j with >>> immediateFlush=false (6.3-9s vs. 13-20s). >>> So some sort of write batching/buffering really helps in case of heavy >>> activity. >> >> The last time I checked the performance difference with and without >> immediate flush the difference was in the order of 10%. It has apparently >> ballooned to something much more significant. >> >> Thank you for bringing this up. > > I've spent the whole day testing the provided code on my Mac against Log4j, > Logback and my new Log4j 2 code and am getting results that don't seem to > make sense. Log4j uses a PrintWriter while Logback uses an OutputStream. > Looking at the JDK source code it doesn't look like that should affect things > much although I would expect the OutputStream to be slightly faster. So I > wrote the test below which got these results that show the FileWriter would > seem to be buffered. YourKit would seem to agree as log4j spends almost no > time in java.io.FileOutputStream.writeBytes while that is where the majority > of the time is spent in Logback. It isn't visible in the Sun source code so I > expect the buffering must be happening in sun.nio.cs.StreamEncoder. > > ############################################### > FileOutputStream: 5246 > BufferedOutputStream: 854 > FileWriter: 882 > FileChannel: 9330 > ############################################### > > > public class PerformanceComparison { > > // How many times should we try to log: > private static final int COUNT = 1000000; > > @Test > public void testRawPerformance() throws Exception { > OutputStream os = new FileOutputStream("target/testos.log", true); > long result1 = writeToStream(COUNT, os); > os.close(); > OutputStream bos = new BufferedOutputStream(new > FileOutputStream("target/testbuffer.log", true)); > long result2 = writeToStream(COUNT, bos); > bos.close(); > Writer w = new FileWriter("target/testwriter.log", true); > long result3 = writeToWriter(COUNT, w); > w.close(); > FileOutputStream cos = new FileOutputStream("target/testchannel.log", > true); > FileChannel channel = cos.getChannel(); > long result4 = writeToChannel(COUNT, channel); > cos.close(); > System.out.println("###############################################"); > System.out.println("FileOutputStream: " + result1); > System.out.println("BufferedOutputStream: " + result2); > System.out.println("FileWriter: " + result3); > System.out.println("FileChannel: " + result4); > System.out.println("###############################################"); > } > > private long writeToWriter(int loop, Writer w) throws Exception { > Integer j = new Integer(2); > long start = System.nanoTime(); > for (int i = 0; i < loop; i++) { > w.write("SEE IF THIS IS LOGGED " + j + "."); > } > return (System.nanoTime() - start) / loop; > } > > private long writeToStream(int loop, OutputStream os) throws Exception { > Integer j = new Integer(2); > long start = System.nanoTime(); > for (int i = 0; i < loop; i++) { > os.write(getBytes("SEE IF THIS IS LOGGED " + j + ".")); > } > return (System.nanoTime() - start) / loop; > } > > private long writeToChannel(int loop, FileChannel channel) throws > Exception { > Integer j = new Integer(2); > ByteBuffer buf = ByteBuffer.allocateDirect(8*1024); > long start = System.nanoTime(); > for (int i = 0; i < loop; i++) { > channel.write(getByteBuffer(buf, "SEE IF THIS IS LOGGED " + j + > ".")); > } > return (System.nanoTime() - start) / loop; > } > > private ByteBuffer getByteBuffer(ByteBuffer buf, String s) { > buf.clear(); > buf.put(s.getBytes()); > buf.flip(); > return buf; > } > > private byte[] getBytes(String s) { > return s.getBytes(); > }
_______________________________________________ Logback-user mailing list [email protected] http://qos.ch/mailman/listinfo/logback-user
