Version 3

    JBossAS7 will soon be available in the OpenShift (https://openshift.redhat.com/app/), and the Express version runs in a restricted environment that has limited memory and processes (= java threads). With the parallelism of the new AS7 kernel, startup of the server with several applications in the deployments directory could run into the process/thread limit with and throw a java.lang.OutOfMemory error with a message about not being able to create a native thread. I wanted to see what the thread creation and usage profile of the AS7 server was, and decided to try to use Byteman to gather this information.

     

    There was a useful starting point helper class and sample .btm script, org.jboss.byteman.sample.helper.ThreadMonitorHelper and ThreadMonitor.btm, but I wanted to have more control over how the thread events were captured and reported. I also wanted to register the helper as an MXBean so it could be queried via JMX and viewed using the jconsole tool. This article assumes you have some familiarity with byteman scripts and helpers. If you do not, check out the Programmer's Guide to bring yourself up to speed.

     

    The ThreadHistoryMonitorHelper

    /*
    * JBoss, Home of Professional Open Source
    * Copyright 2011 Red Hat and individual contributors
    * by the @authors tag. See the copyright.txt in the distribution for a
    * full listing of individual contributors.
    *
    * This is free software; you can redistribute it and/or modify it
    * under the terms of the GNU Lesser General Public License as
    * published by the Free Software Foundation; either version 2.1 of
    * the License, or (at your option) any later version.
    *
    * This software 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
    * Lesser General Public License for more details.
    *
    * You should have received a copy of the GNU Lesser General Public
    * License along with this software; if not, write to the Free
    * Software Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA
    * 02110-1301 USA, or see the FSF site: http://www.fsf.org.
    *
    * @author Andrew Dinn
    * @author Scott.Stark
    */
    package org.jboss.byteman.sample.helper;
    
    
    import org.jboss.byteman.rule.Rule;
    import org.jboss.byteman.rule.helper.Helper;
    
    
    import javax.management.MBeanServer;
    import javax.management.ObjectName;
    import java.io.FileWriter;
    import java.io.IOException;
    import java.io.StringWriter;
    import java.lang.management.ManagementFactory;
    import java.util.ArrayList;
    import java.util.Collection;
    import java.util.Formatter;
    import java.util.TreeMap;
    import java.util.TreeSet;
    import java.util.concurrent.ConcurrentHashMap;
    import java.util.concurrent.Executor;
    import java.util.concurrent.Executors;
    import java.util.concurrent.ScheduledExecutorService;
    import java.util.concurrent.ScheduledFuture;
    import java.util.concurrent.TimeUnit;
    
    
    /**
     * Helper class used by ThreadHistoryMonitorHelper script to trace thread operations. This
     * is essentially an extension of the ThreadMonitorHelper which uses maps to store the thread
     * history rather than writing it out.
     *
     * The helper also implements ThreadHistoryMonitorHelperMXBean to allow this class to be
     * registered as an mbean @see #registerHelperMBean(String).
     * 
     */
    public class ThreadHistoryMonitorHelper extends Helper
        implements ThreadHistoryMonitorHelperMXBean
    {
        private static ConcurrentHashMap<String, ThreadMonitorEvent> createMap = new ConcurrentHashMap<String, ThreadMonitorEvent>();
        private static ConcurrentHashMap<String, ThreadMonitorEvent> startMap = new ConcurrentHashMap<String, ThreadMonitorEvent>();
        private static ConcurrentHashMap<String, ThreadMonitorEvent> exitMap = new ConcurrentHashMap<String, ThreadMonitorEvent>();
        private static ConcurrentHashMap<String, ThreadMonitorEvent> runMap = new ConcurrentHashMap<String, ThreadMonitorEvent>();
        /** The first instance of ThreadHistoryMonitorHelper that will be used as the mbean
         * by {@link #registerHelperMBean(String)}.
         */
        private static ThreadHistoryMonitorHelper INSTANCE;
        /** org.jboss.byteman.sample.helper.debug system property debug mode flag */
        private static boolean DEBUG;
    
    
        /**
         * Looks to the org.jboss.byteman.sample.helper.debug system property to
         * set the class DEBUG mode flag.
         */
        public static void activated() {
            DEBUG = Boolean.getBoolean("org.jboss.byteman.sample.helper.debug");
            if(DEBUG)
                System.err.println("ThreadHistoryMonitorHelper.activated, ");
        }
        public static void installed(Rule rule) {
            if(DEBUG)
                System.err.println("ThreadHistoryMonitorHelper.installed, "+rule);
        }
        protected ThreadHistoryMonitorHelper(Rule rule) {
            super(rule);
            INSTANCE = this;
        }
    
    
        /**
         * Register the INSTANCE as an mbean under the given name.
         * @param name - the object name string to register the INSTANCE under
         */
        public void registerHelperMBean(String name) {
            synchronized (createMap) {
                MBeanServer mbs = ManagementFactory.getPlatformMBeanServer();
                try {
                    ObjectName oname = new ObjectName(name);
                    if(mbs.isRegistered(oname) == false)
                        mbs.registerMBean(INSTANCE, oname);
                } catch (Exception e) {
                    e.printStackTrace();
                }
            }
        }
    
    
        @Override
        public ThreadMonitorEvent[] getCreateEvents() {
            ThreadMonitorEvent[] events = new ThreadMonitorEvent[createMap.size()];
            return createMap.values().toArray(events);
        }
    
    
        @Override
        public ThreadMonitorEvent[] getStartEvents() {
            ThreadMonitorEvent[] events = new ThreadMonitorEvent[startMap.size()];
            return startMap.values().toArray(events);
        }
    
    
        @Override
        public ThreadMonitorEvent[] getExitEvents() {
            ThreadMonitorEvent[] events = new ThreadMonitorEvent[exitMap.size()];
            return exitMap.values().toArray(events);
        }
    
    
        @Override
        public ThreadMonitorEvent[] getRunEvents() {
            ThreadMonitorEvent[] events = new ThreadMonitorEvent[runMap.size()];
            return runMap.values().toArray(events);
        }
    
    
        @Override
        public String getEventReport() throws IOException {
            StringWriter sw = new StringWriter();
            Formatter format = new Formatter(sw);
            writeEvents(format, "Thread.create", createMap.values());
            writeEvents(format, "Thread.start", startMap.values());
            writeEvents(format, "Thread.exit", exitMap.values());
            writeEvents(format, "Runable.run", runMap.values());
            sw.close();
            return sw.toString();
        }
        @Override
        public void writeEventsToFile(String type, String path) throws IOException {
            FileWriter fw = new FileWriter(path);
            Formatter format = new Formatter(fw);
            if(type == null || type.length() == 0 || type.equalsIgnoreCase("create"))
                writeEvents(format, "Thread.create Events", createMap.values());
            if(type == null || type.length() == 0 || type.equalsIgnoreCase("start"))
                writeEvents(format, "Thread.start Events", startMap.values());
            if(type == null || type.length() == 0 || type.equalsIgnoreCase("exit"))
                writeEvents(format, "Thread.exit Events", exitMap.values());
            if(type == null || type.length() == 0 || type.equalsIgnoreCase("run"))
                writeEvents(format, "Runable.run Events", runMap.values());
            fw.close();
        }
    
    
        /**
         * Write all events to the file given by path
         *
         * @param path
         * @throws IOException
         */
        public void writeAllEventsToFile(String path) throws IOException {
            System.err.println("writeAllEventsToFile: "+path);
            writeAllEventsToFile(path, 0);
        }
    
    
        /**
         * Write all events to the file given by path, repeating sampleCount times
         * at 5 second intervals. The actual filename of each sample report will be either
         *  path-n where n = [0,sampleCount] if path does not contain a suffix, for example:
         *  /tmp/report-0
         *  /tmp/report-1
         *  /tmp/report-3
         * or
         *  pathbase-n.suffix if there is a '.' delimited suffix (.txt), for example:
         *  /tmp/report-0.txt
         *  /tmp/report-1.txt
         *  /tmp/report-3.txt
         * @param path - the path to the event report file
         * @param sampleCount - the number of samples to take
         * @throws IOException - thrown on any IO failure
         */
        public synchronized void writeAllEventsToFile(String path, int sampleCount) throws IOException {
            ScheduledExecutorService ses = Executors.newSingleThreadScheduledExecutor();
            ArrayList<ScheduledFuture> tasks = new ArrayList<ScheduledFuture>();
            // Look for path suffix
            String suffix = null;
            String base = path;
            int lastDot = path.lastIndexOf('.');
            if(lastDot > 0) {
                suffix = path.substring(lastDot);
                base = path.substring(0, lastDot);
            }
            for(int n = 0; n <= sampleCount; n ++) {
                final String samplePath = base + "-" + n + (suffix != null ? suffix : "");
                int delay = 5*n;
                ScheduledFuture future = ses.schedule(new Runnable() {
                    @Override
                    public void run() {
                        try {
                            doWriteAllEvents(samplePath);
                        } catch (IOException e) {
                            e.printStackTrace();
                        }
                    }
                }, delay, TimeUnit.SECONDS);
                tasks.add(future);
            }
            // Wait for tasks to complete
            for(ScheduledFuture future : tasks) {
                try {
                    future.get();
                } catch (Exception e) {
                    e.printStackTrace();
                }
            }
        }
        private void doWriteAllEvents(String path) throws IOException {
            FileWriter fw = new FileWriter(path);
            Formatter format = new Formatter(fw);
            writeEvents(format, "Thread.create", createMap.values());
            writeEvents(format, "Thread.start", startMap.values());
            writeEvents(format, "Thread.exit", exitMap.values());
            writeEvents(format, "Runable.run", runMap.values());
            fw.close();
            System.err.println("Wrote events to: "+path);
        }
        private void writeEvents(Formatter fw, String title, Collection<ThreadMonitorEvent> events) {
            int count = 0;
            TreeSet<String> threadNames = new TreeSet<String>();
            fw.format("+++ Begin %s Events, count=%d +++\n", title, events.size());
            for(ThreadMonitorEvent event : events) {
                if(event.getRunnableClass() != null) {
                    fw.format("#%d, %s(runnable=%s)\n%s\n", count++, event.getThreadName(), event.getRunnableClass(), event.getFullStack());
                } else {
                    fw.format("#%d, %s\n%s\n", count++, event.getThreadName(), event.getFullStack());
                }
                threadNames.add(event.getThreadName());
            }
            fw.format("+++ End %s Events +++\n", title);
            fw.format("+++ Begin %s Thread Names +++\n", title);
            for(String name : threadNames) {
                fw.format("%s\n", name);
            }
            fw.format("+++ End %s Thread Names +++\n", title);
        }
    
    
        /**
         * trace creation of the supplied thread to System.out
         *
         * this should only be triggered from the constructor for class java.lang.Thread"
         *
         * @param thread the newly created thread
         */
        public void traceCreate(Thread thread, int depth)
        {
            ThreadMonitorEvent event = newThreadEvent(thread, "create");
            createMap.put(event.getThreadName(), event);
    
    
        }
    
    
        /**
         * trace start of the supplied thread to System.out
         *
         * this should only be triggered from the call to java.lang.Thread.start"
         *
         * @param thread the newly starting thread
         */
        public void traceStart(Thread thread)
        {
            ThreadMonitorEvent event = newThreadEvent(thread, "start");
            startMap.put(event.getThreadName(), event);
        }
    
    
        /**
         * trace exit of the supplied thread to System.out
         *
         * this should only be triggered from the call to java.lang.Thread.exit"
         *
         * @param thread the exiting thread
         */
        public void traceExit(Thread thread)
        {
            ThreadMonitorEvent event = newThreadEvent(thread, "exit");
            exitMap.put(event.getThreadName(), event);
        }
    
    
        /**
         * trace run of the supplied Runnable to System.out
         *
         * this should only be triggered from a call to an implementation of java.lang.Runnable.run"
         *
         * @param runnable the runnable being run
         */
        public void traceRun(Runnable runnable)
        {
            Thread thread = Thread.currentThread();
            ThreadMonitorEvent event = newThreadEvent(thread, "run");
            event.setRunnableClass(runnable.getClass().toString());
            runMap.put(event.getThreadName(), event);
        }
    
    
        /**
         * Common ThreadMonitorEvent creation method.
         *
         * @param thread - the thread associated with the event
         * @param type - the type of the event.
         * @return the ThreadMonitorEvent instance for the event.
         */
        private ThreadMonitorEvent newThreadEvent(Thread thread, String type) {
            StringBuffer line = new StringBuffer();
            StringBuilder buffer = new StringBuilder();
            StackTraceElement[] stack = getStack();
            ArrayList<String> stackInfo = new ArrayList<String>();
            int l = stack.length;
            int t = super.triggerIndex(stack);
    
    
            line.append("*** Thread ");
            line.append(type);
            line.append(" ");
            line.append(thread.getName());
            line.append(" ");
            line.append(thread.getClass().getCanonicalName());
            line.append('\n');
            stackInfo.add(line.toString());
            line.setLength(0);
    
    
            for(int n = t; n < l; n ++) {
                StackTraceElement frame = stack[n];
                super.printlnFrame(line, frame);
                buffer.append(line);
                stackInfo.add(line.toString());
                line.setLength(0);
            }
            //
            String name = thread.getName();
            String fullStack = buffer.toString();
            ThreadMonitorEvent event = new ThreadMonitorEvent(type, name, stackInfo, fullStack);
            return event;
        }
    
    
    }
    
    

     

    A ThreadMonitorHistory.btm Script

    ########################################################################
    # JBoss, Home of Professional Open Source
    # Copyright 2011, Red Hat and individual contributors
    # by the @authors tag. See the copyright.txt in the distribution for a
    # full listing of individual contributors.
    #
    # This is free software; you can redistribute it and/or modify it
    # under the terms of the GNU Lesser General Public License as
    # published by the Free Software Foundation; either version 2.1 of
    # the License, or (at your option) any later version.
    #
    # This software 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
    # Lesser General Public License for more details.
    #
    # You should have received a copy of the GNU Lesser General Public
    # License along with this software; if not, write to the Free
    # Software Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA
    # 02110-1301 USA, or see the FSF site: http://www.fsf.org.
    #
    # @authors Andrew Dinn
    # @authors Scott Stark
    #
    # ThreadMonitorHistory
    #
    # A byteman script which stores thread creation, start, run and exit events
    #
    # to use ths script to trace execution of java program org.my.App execute
    #
    #  -- set the directory in which byteman has been installed
    #  BYTEMAN_HOME= ...
    #
    #   -- identify the samples helper jar to the boot path
    #   SAMPLE_JAR=${BYTEMAN_HOME}/sample/lib/byteman-sample.jar
    #
    #   -- identify this script
    #   SCRIPT={BYTEMAN_HOME}/sample/scripts/ThreadMonitorHistory.btm
    #
    #  ${BYTEMAN_HOME}/bin/bmjava.sh -l $SCRIPT -b $SAMPLE_JAR org.my.App
    #
    # alternatively to load the script dynamically
    #
    #   -- start the program with the agent
    #  ${BYTEMAN_HOME}/bin/bmjava.sh org.my.App
    #
    #   -- install the helper library into the bootstrap classpath
    #  ${BYTEMAN_HOME}/bin/bmsubmit.sh -b $SAMPLE_JAR
    #
    #   -- install the script
    #  ${BYTEMAN_HOME}/bin/bmsubmit.sh -l $SCRIPT
    
    
    ########################################################################
    #
    # Rule to trace thread creation
    #
    
    
    RULE ThreadMonitor trace create
    CLASS ^java.lang.Thread
    METHOD <init>
    HELPER org.jboss.byteman.sample.helper.ThreadHistoryMonitorHelper
    AT EXIT
    IF TRUE
    DO traceCreate($0, 5)
    ENDRULE
    
    
    ########################################################################
    #
    # Rule to trace thread start
    #
    
    
    RULE ThreadMonitor trace start
    CLASS ^java.lang.Thread
    METHOD start()
    HELPER org.jboss.byteman.sample.helper.ThreadHistoryMonitorHelper
    AT ENTRY
    IF TRUE
    DO traceStart($0)
    ENDRULE
    
    
    ########################################################################
    #
    # Rule to trace thread exit
    #
    
    
    RULE ThreadMonitor trace exit
    CLASS ^java.lang.Thread
    METHOD exit()
    HELPER org.jboss.byteman.sample.helper.ThreadHistoryMonitorHelper
    AT ENTRY
    IF TRUE
    DO traceExit($0)
    ENDRULE
    
    
    ########################################################################
    #
    # Interface rule to trace calls to implementations of Runnable.run
    # n.b. this is injected into overriding implementations of run as well
    # as direct implementations. In some cases the overriding method will
    # call the super method causing multiple trace lines to be displayed for
    # a given run call.
    #
    
    
    RULE ThreadMonitor trace Runnable run
    INTERFACE ^java.lang.Runnable
    METHOD run()
    HELPER org.jboss.byteman.sample.helper.ThreadHistoryMonitorHelper
    AT ENTRY
    IF TRUE
    DO traceRun($0)
    ENDRULE
    
    
    # A rule to trigger the registration of the ThreadHistoryMonitorHelper mbean.
    # This has to be done after the installation of the platform mbean to avoid
    # conflicts with installing the j.u.l.LogManager.
    RULE Register ThreadHistoryMonitorHelper mbean
    CLASS org.jboss.modules.Main
    METHOD main
    HELPER org.jboss.byteman.sample.helper.ThreadHistoryMonitorHelper
    AT EXIT
    IF TRUE
    DO registerHelperMBean("org.jboss.byteman:helper=ThreadHistoryMonitorHelper")
    ENDRULE
    
    
    # A rule to trigger a flush of the events after the initial server bootstrap
    RULE write ThreadHistoryMonitorHelper boot events
    CLASS org.jboss.as.server.ApplicationServerService
    METHOD start
    HELPER org.jboss.byteman.sample.helper.ThreadHistoryMonitorHelper
    AT EXIT
    IF TRUE
    do writeAllEventsToFile("/tmp/thread-boot.txt")
    ENDRULE
    
    
    # A rule to trigger a flush of the events after the server startup msg
    RULE write ThreadHistoryMonitorHelper to start msg events
    CLASS org.jboss.as.server.BootstrapListener
    METHOD finish
    HELPER org.jboss.byteman.sample.helper.ThreadHistoryMonitorHelper
    AT EXIT
    IF TRUE
    do writeAllEventsToFile("/tmp/thread-events.txt")
    ENDRULE
    

     

     

    Setup standalone.conf

    To enable byteman monitoring, you need to setup the java vm to load the byteman agent and associated classes. The first step is to configure a BYTEMAN_HOME environment variable. Since I was building a new byteman-sample.jar class for the usecase I needed, I set my BYTEMAN_HOME to the install directory of the byteman source tree build install directory:

    BYTEMAN_HOME=~/Dev/JBoss/Byteman/trunk/install
    

     

    To setup the server JVM to load the byteman agent, I added the following JAVA_OPTS settings at the end of the server bin/standalone.conf file:

     

    JAVA_OPTS="-javaagent:${BYTEMAN_HOME}/lib/byteman.jar=script:${BYTEMAN_HOME}/sample/scripts/ThreadMonitorHistory.btm\
    ,boot:${BYTEMAN_HOME}/lib/byteman.jar,boot:${BYTEMAN_HOME}/sample/lib/byteman-sample.jar,boot:../jboss-modules.jar ${JAVA_OPTS}"
    
    
    JAVA_OPTS="${JAVA_OPTS} -Dorg.jboss.byteman.transform.all"
    JAVA_OPTS="$JAVA_OPTS -Djboss.modules.system.pkgs=org.jboss.byteman"
    

     

    If you want to debug or see the behavior of byteman, you can also added the following:

     

    JAVA_OPTS="$JAVA_OPTS -Dorg.jboss.byteman.verbose=true"
    

     

    The various JAVA_OPTS values are:

    • -javaagent:${BYTEMAN_HOME}/lib/byteman.jar ; specifies the byteman.jar as the agent entry point to load the org.jboss.byteman.agent.Main agent class.
    • =script:${BYTEMAN_HOME}/sample/scripts/ThreadMonitorHistory.btm ; specifies that the first argument to the agent is the ThreadMonitorHistory.btm. This will be used to instrument the boot classes.
    • boot:${BYTEMAN_HOME}/lib/byteman.jar ; specifies that the byteman.jar must be included in the JVM bootstrap classpath. This is needed to instrument other bootstrap classes such as java.lang.Thread and java.lang.Runnable implementations.
    • ${BYTEMAN_HOME}/lib/byteman.jar,boot:${BYTEMAN_HOME}/sample/lib/byteman-sample.jar ; specifies that the byteman samples, which includes the helper class specified by the ThreadMonitorHistory.btm, must be added to the JVM bootstrap classpath.
    • boot:../jboss-modules.jar ; specifies the jboss-modules.jar entry point for the module system is to be added to the JVM bootstrap classpath.

     

    In addition, two system properties are needed:

    • -Dorg.jboss.byteman.transform.all - tells byteman that all classes, including those on the bootstrap classpath are to be transformed. This is needed when dealing with script that target java.lang.* classes.
    • -Djboss.modules.system.pkgs=org.jboss.byteman - tells the module system that byteman classes are to be loaded via the system class loader.

     

    The full standalone.conf is attached for reference.

     

    With these additions, the server starts up a little slower, but not signficantly so in terms of wall time:

    16:16:05,482 INFO  [org.jboss.as] (Controller Boot Thread) JBoss AS 7.0.0.Final "Lightning" started in 5702ms - Started 92 of 147 services (55 services are passive or on-demand)
    16:16:05,486 ERROR [stderr] (Controller Boot Thread) writeAllEventsToFile: /tmp/thread-events.txt
    16:16:05,504 ERROR [stderr] (pool-4-thread-1) Wrote events to: /tmp/thread-events-0.txt
    

     

    This is vs a 2.2 second startup time without the transformation and tracing:

    16:17:01,544 INFO  [org.jboss.as] (Controller Boot Thread) JBoss AS 7.0.0.Final "Lightning" started in 2207ms - Started 92 of 147 services (55 services are passive or on-demand)
    

     

    The outputs of the bootstrap thread event report, and the post startup msg report are attached as thread-boot-0.txt and thread-events-0.txt respectively.