[LOGBack-dev] svn commit: r508 - in logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net: . testObjectBuilders

noreply.seb at qos.ch noreply.seb at qos.ch
Tue Sep 5 18:19:17 CEST 2006


Author: seb
Date: Tue Sep  5 18:19:17 2006
New Revision: 508

Modified:
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/ExternalMockSocketServer.java
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SerializationPerfsTest.java
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/Builder.java
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEvent2Builder.java
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEventBuilder.java
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalExtBuilder.java
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalSerBuilder.java

Log:
improved performance tests

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/ExternalMockSocketServer.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/ExternalMockSocketServer.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/ExternalMockSocketServer.java	Tue Sep  5 18:19:17 2006
@@ -1,7 +1,6 @@
 package ch.qos.logback.classic.net;
 
-import java.io.BufferedInputStream;
-import java.io.ObjectInputStream;
+import java.io.InputStream;
 import java.net.ServerSocket;
 import java.net.Socket;
 import java.util.ArrayList;
@@ -16,7 +15,7 @@
 
 	static final int PORT = 4560;
 
-	static int loopLen;
+	//static int loopLen;
 	static int clientNumber;
 
 	static List<String> msgList = new ArrayList<String>();
@@ -25,10 +24,9 @@
 	String className = LOGGINGEVENT;
 
 	public static void main(String[] args) {
-		if (args.length == 2) {
+		if (args.length == 1) {
 			clientNumber = Integer.parseInt(args[0]);
-			loopLen = Integer.parseInt((args[1]));
-			System.out.println("Starting Server...");
+			//loopLen = Integer.parseInt((args[1]));
 			runServer();
 		} else {
 			usage("Wrong number of arguments.");
@@ -37,29 +35,39 @@
 
 	static void usage(String msg) {
 		System.err.println(msg);
-		System.err.println("Usage: java "
-				+ ExternalMockSocketServer.class.getName() + " clientNumber loopNumber");
+		System.err
+				.println("Usage: java " + ExternalMockSocketServer.class.getName()
+						+ " loopNumber");
 		System.exit(1);
 	}
 
 	static void runServer() {
-		ObjectInputStream ois;
-		Object readObject;
+
 		try {
-			System.out.println("Listening on port " + PORT);
+			System.out.println("Starting Server...");
 			ServerSocket serverSocket = new ServerSocket(PORT);
+			System.out.println("Listening on port " + PORT);
 			for (int j = 0; j < clientNumber; j++) {
 				Socket socket = serverSocket.accept();
 				System.out.println("New client accepted.");
 				System.out.println("Connected to client at " + socket.getInetAddress());
-				ois = new ObjectInputStream(new BufferedInputStream(socket
-						.getInputStream()));
-				for (int i = 0; i < loopLen; i++) {
-					readObject = ois.readObject();
-					//msgList.add(readObject.toString());
+
+				InputStream is = socket.getInputStream();
+				long sum = 0;
+			
+				while (true) {
+					// this call is blocking
+					int val = is.read();
+					if(val == -1) {
+						break;
+					}
+					// if a byte is available, we skip it.
+					// this allows to pass all available bytes in a quick manner.
+					int a = is.available();
+					sum += a + 1;
+					is.skip(a);
 				}
-				ois.close();
-				System.out.println("Finished with this client.");
+			  System.out.println(sum);
 			}
 			serverSocket.close();
 		} catch (Exception se) {

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SerializationPerfsTest.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SerializationPerfsTest.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/SerializationPerfsTest.java	Tue Sep  5 18:19:17 2006
@@ -18,6 +18,9 @@
 
 	int loopNumber = 10000;
 	int resetFrequency = 100;
+	int pauseFrequency = 200;
+	long pauseLengthInMillis = 50;
+	
 	/**
 	 * Run the test with a MockSocketServer or with a NOPOutputStream
 	 */
@@ -26,41 +29,54 @@
 	 * <p>
 	 * Run with external mock can be done using the
 	 * ExternalMockSocketServer. It needs to be launched
-	 * from a separate JVM.
+	 * from a separate JVM. The ExternalMockSocketServer does not
+	 * consume the events but passes through the available bytes
+	 * that it is recieving.
 	 * </p>
 	 * <p>
-	 * For example, with 4 test methods and a loopNumber of 10000,
+	 * For example, with 4 test methods,
 	 * you can launch the ExternalMockSocketServer this way:
 	 * </p>
 	 * <p>
-	 * <code>java ch.qos.logback.classic.net.ExternalMockSocketServer 4 20000</code>
-	 * </p>
-	 * <p>
-	 * (20000 because each methods iterate twice).
+	 * <code>java ch.qos.logback.classic.net.ExternalMockSocketServer 4</code>
 	 * </p>
 	 */
 	boolean runWithExternalMockServer = true;
 
 	/**
 	 * Last results:
+	 * Data sent mesured in bytes.
+	 * Avg time mesured in nanos.
 	 * 
 	 * NOPOutputStream: 
-	 * Minimal Object externalization: average time = 6511 after 10000 writes. 
-	 * Minimal Object serialization: average time = 7883 after 10000 writes. 
-	 * LoggingEvent object externalization: average time = 9641 after 10000 writes.
-	 * LoggingEvent object serialization: average time = 25729 after 10000 writes.
+	 *   |                |  Runs | Avg time | Data sent |
+	 *   | MinimalObj Ext | 10000 |  6511    |           |
+	 *   | MinimalObj Ser | 10000 |  7883    |           |
+	 *   | LoggEvent Ext  | 10000 |  9641    |           |
+	 *   | LoggEvent Ser  | 10000 | 25729    |           |
 	 * 
 	 * Internal MockServer: 
-	 * Minimal object externalization : average time = 62040 after 10000 writes.
-	 * Minimal object serialization : average time = 76237 after 10000 writes.
-	 * LoggingEvent object externalization : average time = 122714 after 10000 writes.
-	 * LoggingEvent object serialization : average time = 121711 after 10000 writes.
+	 * 	 |                |  Runs | Avg time | Data sent |
+	 *   | MinimalObj Ext | 10000 |  62040   |           |
+	 *   | MinimalObj Ser | 10000 |  76237   |           |
+	 *   | LoggEvent Ext  | 10000 | 122714   |           |
+	 *   | LoggEvent Ser  | 10000 | 121711   |           |
 	 * 
-	 * External MockServer: 
-	 * Minimal object externalization : average time = 55577 after 10000 writes.
-	 * Minimal object serialization : average time = 56669 after 10000 writes.
-	 * LoggingEvent object externalization : average time = 121477 after 10000 writes.
-	 * LoggingEvent object serialization : average time = 111148 after 10000 writes.
+	 * External MockServer with 45 letters-long message: 
+	 * 	 |                |  Runs | Avg time | Data sent |
+	 *   | MinimalObj Ext | 10000 |  70240   | 1171384   |
+	 *   | MinimalObj Ser | 10000 |  62754   | 1157584   |
+	 *   | LoggEvent Ext  | 10000 | 198910   | 1509984   |
+	 *   | LoggEvent Ser  | 10000 | 189970   | 1715984   |
+	 *	 pauseFrequency = 200 and pauseLengthInMillis = 50
+	 *
+	 * External MockServer with 2 letters-long message: 
+	 * 	 |                |  Runs | Avg time | Data sent |
+	 *   | MinimalObj Ext | 10000 |  43234   |  311384   |
+	 *   | MinimalObj Ser | 10000 |  31603   |  297584   |
+	 *   | LoggEvent Ext  | 10000 | 106442   |  649984   |
+	 *   | LoggEvent Ser  | 10000 |  93467   |  855984   |
+	 *	 pauseFrequency = 200 and pauseLengthInMillis = 50
 	 */
 
 	public void setUp() throws Exception {
@@ -85,15 +101,22 @@
 	}
 
 	public void runPerfTest(Builder builder, String label) throws Exception {
+		//long time1 = System.nanoTime();
 
 		// first run for just in time compiler
-		int counter = 0;
+		int resetCounter = 0;
+		int pauseCounter = 0;
 		for (int i = 0; i < loopNumber; i++) {
 			try {
 				oos.writeObject(builder.build(i));
 				oos.flush();
-				if (++counter >= resetFrequency) {
+				if (++resetCounter >= resetFrequency) {
 					oos.reset();
+					//resetCounter = 0;
+				}
+				if (++pauseCounter >= pauseFrequency) {
+					Thread.sleep(pauseLengthInMillis);
+					pauseCounter = 0;
 				}
 			} catch (IOException ex) {
 				fail(ex.getMessage());
@@ -102,24 +125,30 @@
 
 		// second run
 		Long t1;
-		Long t2;
+		Long t2 ;
 		Long total = 0L;
-		counter = 0;
-		// System.out.println("Beginning mesured run");
-		t1 = System.nanoTime();
+		resetCounter = 0;
+		pauseCounter = 0;
+		//System.out.println("Beginning mesured run");
 		for (int i = 0; i < loopNumber; i++) {
 			try {
+				t1 = System.nanoTime();
 				oos.writeObject(builder.build(i));
 				oos.flush();
-				if (++counter >= resetFrequency) {
+				t2 = System.nanoTime();
+				total += (t2 - t1);
+				if (++resetCounter >= resetFrequency) {
 					oos.reset();
+					//resetCounter = 0;
+				}
+				if (++pauseCounter >= pauseFrequency) {
+					Thread.sleep(pauseLengthInMillis);
+					pauseCounter = 0;
 				}
 			} catch (IOException ex) {
 				fail(ex.getMessage());
 			}
 		}
-		t2 = System.nanoTime();
-		total += (t2 - t1);
 		System.out.println(label + " : average time = " + total / loopNumber
 				+ " after " + loopNumber + " writes.");
 
@@ -127,6 +156,9 @@
 			mockServer.join(1000);
 			assertTrue(mockServer.finished);
 		}
+		
+		//long time2 = System.nanoTime();
+		//System.out.println("********* -> Time needed to run the test method: " + Long.toString(time2-time1));
 	}
 
 	public void testWithMinimalExternalization() throws Exception {

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/Builder.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/Builder.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/Builder.java	Tue Sep  5 18:19:17 2006
@@ -2,6 +2,7 @@
 
 public interface Builder {
 
+	//45 characters message
 	final String MSG_PREFIX = "aaaaabbbbbcccccdddddaaaaabbbbbcccccdddddaaaa";
 	//final String MSG_PREFIX = "a";
 	

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEvent2Builder.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEvent2Builder.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEvent2Builder.java	Tue Sep  5 18:19:17 2006
@@ -10,7 +10,6 @@
 		LoggingEvent2 le = new LoggingEvent2();
 		le.setLevel(Level.DEBUG);
 		le.setLogger(new LoggerContext().getLogger(LoggerContext.ROOT_NAME));
-		// 45 characters message
 		le.setMessage(MSG_PREFIX + i);
 		le.setThreadName("threadName");
 		return le;

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEventBuilder.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEventBuilder.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/LoggingEventBuilder.java	Tue Sep  5 18:19:17 2006
@@ -10,7 +10,6 @@
 		LoggingEvent le = new LoggingEvent();
 		le.setLevel(Level.DEBUG);
 		le.setLogger(new LoggerContext().getLogger(LoggerContext.ROOT_NAME));
-		// 45 characters message
 		le.setMessage(MSG_PREFIX + i);
 		le.setThreadName("threadName");
 		return le;

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalExtBuilder.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalExtBuilder.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalExtBuilder.java	Tue Sep  5 18:19:17 2006
@@ -25,7 +25,6 @@
 	}
 	
 	public MinimalExt(int i) {
-		// 45 characters message
 		message = Builder.MSG_PREFIX + i;
 	}
 

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalSerBuilder.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalSerBuilder.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/net/testObjectBuilders/MinimalSerBuilder.java	Tue Sep  5 18:19:17 2006
@@ -18,7 +18,6 @@
 	String message;
 
 	public MinimalSer(int i) {
-		// 45 characters message
 		message = Builder.MSG_PREFIX + i;
 	}
 }
\ No newline at end of file



More information about the logback-dev mailing list