ParsePauses.java

/*
 *   
 *
 * Copyright  1990-2009 Sun Microsystems, Inc. All Rights Reserved.
 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER
 * 
 * This program is free software; you can redistribute it and/or
 * modify it under the terms of the GNU General Public License version
 * 2 only, as published by the Free Software Foundation.
 * 
 * This program is distributed in the hope that it will be useful, but
 * WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
 * General Public License version 2 for more details (a copy is
 * included at /legal/license.txt).
 * 
 * You should have received a copy of the GNU General Public License
 * version 2 along with this work; if not, write to the Free Software
 * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA
 * 02110-1301 USA
 * 
 * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa
 * Clara, CA 95054 or visit www.sun.com if you need additional
 * information or have any questions.
 */

import java.io.*;
import java.util.*;

/**
 * This program parses the event.log generated by the VM and
 * calculates the extend "pause" that can be noticed by the user. The
 * algorithm moves a "sliding window" across the execution history of
 * a program. If the amount of "stop-the-world" activities in a
 * sliding window exceeds the threshold, we discover a pause.
 *
 * For example, if window_size is 30 and pause_thresh is 10, and the
 * first 30 ms of the execution time contains 7 msec of GC and 5 msec
 * of compilation for a total of 12 ms of stop-the-world activities,
 * we declare that the first sliding window contains a pause.
 */
public class ParsePauses {
    /**
     * The size of the sliding window, in milliseconds.
     */
    static int window_size = 30; 

    /**
     * How much stop-the-world activities can happen in a sliding window
     * before we declare that the sliding window contains a pause.
     */
    static int pause_thresh = 10;

    static boolean verbose = false;
    
    static class Node {
        double msec;
        boolean is_paused;
        String type;
        public String toString() {
            String s1 = new PrintfFormat("%10.3f").sprintf(msec);
            String s2 = new PrintfFormat("%-15s").sprintf(type);
            return s1 + (is_paused ? "**" : "  ") + s2;
        }
    }

    public static void main(String args[]) throws Throwable {
        try {
            int n = 0;
            if (args[0].equals("-v")) {
                n++;
                verbose = true;
            }
            window_size = Integer.parseInt(args[n+0]);
            pause_thresh = Integer.parseInt(args[n+1]);
        } catch (Throwable t) {;}

        FileInputStream in = new FileInputStream("event.log");
        BufferedReader reader = new BufferedReader(new InputStreamReader(in));
        String s;
        Vector v = new Vector();
        double last_msec = 0.0;
        int nestLevel = 0;
        while ((s = reader.readLine()) != null) {
            try {
                s = s.trim();
                String num = s.substring(0, s.indexOf(' '));
                double d = Double.parseDouble(num);
                Node n = new Node();
                n.msec = d;
                if (s.endsWith("END")) {
                    nestLevel --;
                } else {
                    nestLevel ++;
                }
                n.is_paused = (nestLevel) > 0;
                n.type = s.substring(s.lastIndexOf(' ')).intern();
                v.addElement(n);
                last_msec = d;
            } catch (Throwable t) {;}
        }

        int total_pauses = 0;
        int total_msecs = 0;
        int startIdx = 0;
        for (double msec = 0; msec < last_msec; msec += 1.0) {
            if ((startIdx = findStartIdx(v, startIdx, msec)) < 0) {
                break;
            }
            if (add_pauses(v, startIdx, msec)) {
                total_pauses ++;
            }
            total_msecs ++;
        }

        System.out.println("pauses = " + total_pauses + "/" +  total_msecs);
    }

    // Find the last index that precedes msec
    static int findStartIdx(Vector v, int startIdx, double msec) {
        boolean found = false;
        for (int i=startIdx; i<v.size(); i++) {
            Node n = (Node)v.elementAt(i);
            if (n.msec > msec) {
                if (!found) {
                    return startIdx;
                } else {
                    break;
                }
            }
            if (n.msec <= msec) {
                startIdx = i;
                found = true;
            }
        }
        if (!found) {
            return -1;
        } else {
            return startIdx;
        }
    }

    static boolean add_pauses(Vector v, int startIdx, double begin) {
        double end = begin + window_size;

        for (int pass = 0; pass < 2; pass++) {
            Node lastNode = null;
            double total_paused = 0.0;

            if (pass == 1 && verbose) {
                System.out.println("========================================");
                System.out.println("START" + begin);
            }
            for (int i=startIdx; i<v.size(); i++) {
                Node n = (Node)v.elementAt(i);

                if (pass == 1 && verbose) {
                    System.out.print("    " + n);
                }
                if (lastNode != null && lastNode.is_paused) {
                    double a = lastNode.msec;
                    double b = n.msec;
                    if (a < begin) {
                        a = begin;
                    }
                    if (b > end) {
                        b = end;
                    }
                    total_paused += (b - a);
                    if (pass == 1 && verbose) {
                        String s = new PrintfFormat("%7.3f").sprintf(b-a);
                        System.out.print(" += " + s);
                    }
                }
                if (pass == 1 && verbose) {
                    System.out.println();
                }
                lastNode = n;
                if (n.msec >= end) {
                    break;
                }
            }

            if (total_paused > pause_thresh) {
                if (pass == 1) {
                    String s = new PrintfFormat("%.3f").sprintf(total_paused);
                    if (verbose) {
                        System.out.println();
                    }
                    System.out.println("Pause at " + begin + " ms" + " = " + 
                                       s + " ms");
                    return true;
                }
            } else {
                return false;
            }
        }
        return true;
    }
}