[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]
[or-cvs] r15110: Added log file parser for hidden service performance evaluat (projects/hidserv/trunk)
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);
+ }
+}