[or-cvs] r15110: Added log file parser for hidden service performance evaluat (projects/hidserv/trunk)

kloesing at seul.org kloesing at seul.org
Tue Jun 10 22:49:36 UTC 2008


Author: kloesing
Date: 2008-06-10 18:49:36 -0400 (Tue, 10 Jun 2008)
New Revision: 15110

Added:
   projects/hidserv/trunk/LogFileParser.java
Log:
Added log file parser for hidden service performance evaluation.

Added: projects/hidserv/trunk/LogFileParser.java
===================================================================
--- projects/hidserv/trunk/LogFileParser.java	                        (rev 0)
+++ projects/hidserv/trunk/LogFileParser.java	2008-06-10 22:49:36 UTC (rev 15110)
@@ -0,0 +1,354 @@
+import java.io.BufferedReader;
+import java.io.BufferedWriter;
+import java.io.File;
+import java.io.FileReader;
+import java.io.FileWriter;
+import java.io.IOException;
+import java.text.ParsePosition;
+import java.text.SimpleDateFormat;
+import java.util.Calendar;
+import java.util.Date;
+import java.util.List;
+import java.util.Locale;
+import java.util.Map;
+import java.util.SortedMap;
+import java.util.TreeMap;
+import java.util.regex.Pattern;
+
+/**
+ * Usage: java LogFileParser <path to test-env/ directory> <output directory>
+ * 
+ * Example: java -cp bin/ LogFileParser test-env/ out/
+ * 
+ * @author kloesing
+ * 
+ */
+public class LogFileParser {
+	public static void main(String[] args) {
+		if (args.length != 2) {
+			System.err
+					.println("Usage: java LogFileParser <path to test-env/ directory> <output directory>");
+			System.exit(1);
+		}
+		File testenvDirectory = new File(args[0]);
+		if (!testenvDirectory.exists() || !testenvDirectory.isDirectory()) {
+			System.err.println(testenvDirectory.getAbsolutePath()
+					+ " does not exist or is not a directory.");
+		}
+		File outputDirectory = new File(args[1]);
+		if (!outputDirectory.exists() || !outputDirectory.isDirectory()) {
+			System.err.println(outputDirectory.getAbsolutePath()
+					+ " does not exist or is not a directory.");
+		}
+		// parse log files
+		for (File subdirectory : testenvDirectory.listFiles()) {
+			if (!subdirectory.isDirectory())
+				continue;
+			try {
+				parseServerTorLog(subdirectory);
+				parsePuppeTorLog(subdirectory);
+			} catch (IOException e) {
+				System.err
+						.println("IOException while parsing test case in directory + '"
+								+ subdirectory.getAbsolutePath()
+								+ "'. Exiting.");
+				e.printStackTrace();
+				System.exit(1);
+			}
+		}
+		// write CSV files
+		try {
+			BufferedWriter bw = new BufferedWriter(new FileWriter(
+					outputDirectory.getAbsolutePath() + File.separatorChar
+							+ "publtime.csv", false));
+			bw.write("# testid contains a unique test identifier that matches "
+					+ "with the identifiers \n# used in the other output "
+					+ "files, publtime is the time in millis that it \n# "
+					+ "takes to publish the first rendezvous service "
+					+ "descriptor.\n");
+			bw.write("testid,publtime\n");
+			for (Map.Entry<String, Long> e : publicationTimes.entrySet()) {
+				bw.write(e.getKey() + "," + e.getValue() + "\n");
+			}
+			bw.close();
+		} catch (IOException e) {
+			System.err
+					.println("IOException while writing output files! Exiting.");
+			e.printStackTrace();
+			System.exit(1);
+		}
+		try {
+			BufferedWriter bw = new BufferedWriter(new FileWriter(
+					outputDirectory.getAbsolutePath() + File.separatorChar
+							+ "conntime.csv", false));
+			bw.write("# testid contains a unique test identifier that matches "
+					+ "with the identifiers \n# used in the other output "
+					+ "files, opentime is the time in millis that it \n# "
+					+ "takes to open a connection, and duration is the time "
+					+ "in millis that the\n# connection is kept open.\n");
+			bw.write("testid,opentime,duration\n");
+			for (Map.Entry<String, PuppeTorEvent> e : puppeTorEvents.entrySet()) {
+				PuppeTorEvent event = e.getValue();
+				// if the connection has never correctly opened, no results are
+				// available
+				if (event.openedConnection == -1L
+						|| event.openingConnection == -1L) {
+					bw.write(e.getKey() + ",NA,NA\n");
+				} else {
+					// the connection has been opened, but we never observed
+					// it being closed. take last received response as closing
+					// time.
+					if (event.closedConnection == -1L)
+						event.closedConnection = event.receivedResponse
+								.get(event.receivedResponse.lastKey());
+					long opentime = event.openedConnection
+							- event.openingConnection;
+					if (opentime < 0)
+						opentime += 24L * 60L * 60L * 1000L;
+					long duration = event.closedConnection
+							- event.openedConnection;
+					if (duration < 0)
+						duration += 24L * 60L * 60L * 1000L;
+					// if the connection was kept open for at least 3:45
+					// hours, trim it to that time.
+					if (duration > ((3L * 60L) + 45L) * 60L * 1000L) {
+						bw.write(e.getKey() + "," + opentime + ","
+								+ (((3L * 60L) + 45L) * 60L * 1000L) + "\n");
+					} else {
+						// write the "real" connection time, which is a
+						// value between 0 seconds and 3:45 hours.
+						bw.write(e.getKey() + "," + opentime + "," + duration
+								+ "\n");
+					}
+				}
+			}
+			bw.close();
+		} catch (IOException e) {
+			System.err
+					.println("IOException while writing output files! Exiting.");
+			e.printStackTrace();
+			System.exit(1);
+		}
+		try {
+			BufferedWriter bw = new BufferedWriter(new FileWriter(
+					outputDirectory.getAbsolutePath() + File.separatorChar
+							+ "reqtimes.csv", false));
+			bw.write("# testid contains a unique test identifier that matches "
+					+ "with the identifiers \n# used in the other output "
+					+ "files, reqtimes are the times in millis that it \n# "
+					+ "takes to send a request from client to server.\n");
+			bw.write("testid,reqtimes...\n");
+			for (Map.Entry<String, PuppeTorEvent> e : puppeTorEvents.entrySet()) {
+				bw.write(e.getKey());
+				PuppeTorEvent event = e.getValue();
+				if (!event.receivedRequest.isEmpty()
+						&& !event.sendingRequest.isEmpty()) {
+					int last = Math.min(event.receivedRequest.lastKey(),
+							event.sendingRequest.lastKey());
+					for (int i = 0; i <= last; i++) {
+						if (event.sendingRequest.containsKey(i)
+								&& event.receivedRequest.containsKey(i)) {
+							long reqtime = event.receivedRequest.get(i)
+									- event.sendingRequest.get(i);
+							if (reqtime < 0)
+								reqtime += 24L * 60L * 60L * 1000L;
+							bw.write("," + reqtime);
+						} else {
+							bw.write(",NA");
+						}
+					}
+				}
+				bw.write("\n");
+			}
+			bw.close();
+		} catch (IOException e) {
+			System.err
+					.println("IOException while writing output files! Exiting.");
+			e.printStackTrace();
+			System.exit(1);
+		}
+		try {
+			BufferedWriter bw = new BufferedWriter(new FileWriter(
+					outputDirectory.getAbsolutePath() + File.separatorChar
+							+ "restimes.csv", false));
+			bw.write("# testid contains a unique test identifier that matches "
+					+ "with the identifiers \n# used in the other output "
+					+ "files, restimes are the times in millis that it \n# "
+					+ "takes to send a response from server to client.\n");
+			bw.write("testid,restimes...\n");
+			for (Map.Entry<String, PuppeTorEvent> e : puppeTorEvents.entrySet()) {
+				bw.write(e.getKey());
+				PuppeTorEvent event = e.getValue();
+				if (!event.receivedRequest.isEmpty()
+						&& !event.receivedResponse.isEmpty()) {
+					int last = Math.min(event.receivedRequest.lastKey(),
+							event.receivedResponse.lastKey());
+					for (int i = 0; i <= last; i++) {
+						if (event.receivedResponse.containsKey(i)
+								&& event.receivedRequest.containsKey(i)) {
+							long restime = event.receivedResponse.get(i)
+									- event.receivedRequest.get(i);
+							if (restime < 0)
+								restime += 24L * 60L * 60L * 1000L;
+							bw.write("," + restime);
+						} else {
+							bw.write(",NA");
+						}
+					}
+				}
+				bw.write("\n");
+			}
+			bw.close();
+		} catch (IOException e) {
+			System.err
+					.println("IOException while writing output files! Exiting.");
+			e.printStackTrace();
+			System.exit(1);
+		}
+	}
+
+	static SortedMap<String, Long> publicationTimes = new TreeMap<String, Long>();
+
+	static Pattern torLogPattern = Pattern
+			.compile("now have enough directory information|Uploaded rendezvous descriptor");
+
+	static void parseServerTorLog(File testcaseDirectory) throws IOException {
+		File torLog = new File(testcaseDirectory.getAbsolutePath()
+				+ File.separatorChar + "servertor" + File.separatorChar + "log");
+		if (!torLog.exists()) {
+			System.err.println("Server Tor log file does not exist: "
+					+ torLog.getAbsolutePath() + ". Exiting.");
+			System.exit(1);
+		}
+		BufferedReader br = new BufferedReader(new FileReader(torLog));
+		String line = null;
+		long started = 0L;
+		long firstDescriptorUploaded = 0L;
+		while ((line = br.readLine()) != null) {
+			if (!torLogPattern.matcher(line).find())
+				continue;
+
+			Calendar c = Calendar.getInstance();
+			int currentYear = c.get(Calendar.YEAR);
+			SimpleDateFormat sdf = new SimpleDateFormat("MMM dd HH:mm:ss.SSS",
+					Locale.US);
+			Date logTime = sdf.parse(line, new ParsePosition(0));
+			c.setTimeInMillis(logTime.getTime());
+			c.set(Calendar.YEAR, currentYear);
+			long t = c.getTimeInMillis();
+			if (started == 0L
+					&& line.contains("now have enough directory information")) {
+				started = t;
+			} else if (firstDescriptorUploaded == 0L
+					&& line.contains("Uploaded rendezvous descriptor")) {
+				firstDescriptorUploaded = t;
+			}
+			if (started > 0L && firstDescriptorUploaded > 0L) {
+				break;
+			}
+		}
+		long time = firstDescriptorUploaded - started;
+		publicationTimes.put(testcaseDirectory.getName(), time);
+	}
+
+	static SortedMap<String, PuppeTorEvent> puppeTorEvents = new TreeMap<String, PuppeTorEvent>();
+
+	static class PuppeTorEvent {
+		long openingConnection = -1L;
+		long openedConnection = -1L;
+		long closedConnection = -1L;
+		SortedMap<Integer, Long> sendingRequest = new TreeMap<Integer, Long>();
+		SortedMap<Integer, Long> receivedRequest = new TreeMap<Integer, Long>();
+		SortedMap<Integer, Long> receivedResponse = new TreeMap<Integer, Long>();
+	}
+
+	static Pattern puppeTorLogPattern = Pattern
+			.compile("CLIENT_OPENING_CONNECTION|CLIENT_OPENED_CONNECTION|"
+					+ "CLIENT_SENDING_REQUEST|"
+					+ "SERVER_RECEIVING_REQUEST_SENDING_REPLY|"
+					+ "CLIENT_REPLY_RECEIVED|CLIENT_CLOSING_CONNECTION");
+
+	static void parsePuppeTorLog(File testcaseDirectory) throws IOException {
+		File puppeTorLog = new File(testcaseDirectory.getAbsolutePath()
+				+ File.separatorChar + "log");
+		if (!puppeTorLog.exists()) {
+			System.err.println("PuppeTor log file does not exist: "
+					+ puppeTorLog.getAbsolutePath() + ". Exiting.");
+			System.exit(1);
+		}
+		BufferedReader br = new BufferedReader(new FileReader(puppeTorLog));
+		String line = null;
+		PuppeTorEvent event = new PuppeTorEvent();
+		while ((line = br.readLine()) != null) {
+			if (!puppeTorLogPattern.matcher(line).find())
+				continue;
+
+			Calendar c = Calendar.getInstance();
+			// we have no date information, only time; assume 1.1.1970 and
+			// correct possible traversal of midnight when writing results to
+			// file
+			SimpleDateFormat sdf = new SimpleDateFormat("HH:mm:ss.SSS");
+			// too late to correct typo in occurrence...
+			int timepos = line.indexOf("occurenceTime=");
+			if (timepos < 0) {
+				System.err
+						.println("Could not determine occurrence time in log statement: '"
+								+ line + "'. Exiting.");
+				System.exit(1);
+			}
+			timepos += "occurenceTime=".length();
+			Date logTime = sdf.parse(line, new ParsePosition(timepos));
+			c.setTimeInMillis(logTime.getTime());
+			long t = c.getTimeInMillis();
+			if (event.openingConnection == -1L
+					&& line.contains("CLIENT_OPENING_CONNECTION")) {
+				event.openingConnection = t;
+			} else if (event.openedConnection == -1L
+					&& line.contains("CLIENT_OPENED_CONNECTION")) {
+				event.openedConnection = t;
+			} else if (event.closedConnection == -1L
+					&& line.contains("CLIENT_CLOSING_CONNECTION")) {
+				event.closedConnection = t;
+			} else if (line.contains("CLIENT_SENDING_REQUEST")) {
+				int requestNumber = parseRequestNumber(line,
+						"Client sending request ");
+				if (requestNumber >= 0)
+					event.sendingRequest.put(requestNumber, t);
+			} else if (line.contains("SERVER_RECEIVING_REQUEST_SENDING_REPLY")) {
+				int requestNumber = parseRequestNumber(line,
+						"Server receiving request ");
+				if (requestNumber >= 0)
+					event.receivedRequest.put(requestNumber, t);
+			} else if (line.contains("CLIENT_REPLY_RECEIVED")) {
+				int requestNumber = parseRequestNumber(line,
+						"Client receiving response ");
+				if (requestNumber >= 0)
+					event.receivedResponse.put(requestNumber, t);
+			}
+		}
+		puppeTorEvents.put(testcaseDirectory.getName(), event);
+	}
+
+	static int parseRequestNumber(String logLine, String precedingString) {
+		int reqnumpos = logLine.indexOf(precedingString);
+		if (reqnumpos < 0) {
+			System.err
+					.println("Could not determine request number in log statement: '"
+							+ logLine + "'. Exiting.");
+			System.exit(1);
+		}
+		reqnumpos += precedingString.length();
+		String tmpline = logLine.substring(reqnumpos);
+		int dotpos = tmpline.indexOf(".");
+		if (dotpos < 0) {
+			System.err
+					.println("Could not determine request number in log statement: '"
+							+ logLine + "'. Exiting.");
+		}
+		tmpline = tmpline.substring(0, dotpos);
+		if (tmpline.startsWith("null"))
+			return -1;
+		else
+			return Integer.parseInt(tmpline);
+	}
+}



More information about the tor-commits mailing list