org.apache.synapse.commons.jmx.ThreadingView.java Source code

Java tutorial

Introduction

Here is the source code for org.apache.synapse.commons.jmx.ThreadingView.java

Source

/*
 *  Licensed to the Apache Software Foundation (ASF) under one
 *  or more contributor license agreements.  See the NOTICE file
 *  distributed with this work for additional information
 *  regarding copyright ownership.  The ASF licenses this file
 *  to you under the Apache License, Version 2.0 (the
 *  "License"); you may not use this file except in compliance
 *  with the License.  You may obtain a copy of the License at
 *
 *   http://www.apache.org/licenses/LICENSE-2.0
 *
 *  Unless required by applicable law or agreed to in writing,
 *  software distributed under the License is distributed on an
 *   * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
 *  KIND, either express or implied.  See the License for the
 *  specific language governing permissions and limitations
 *  under the License.
 */

package org.apache.synapse.commons.jmx;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.apache.synapse.commons.util.MiscellaneousUtil;

import java.util.*;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;
import java.lang.management.ThreadMXBean;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;

/**
 * ThreadingView can be used to monitor a named thread group over JMX. Data
 * gathered by this monitor can be classified as short term data and long term data.
 * Short term data is the statistics related to last 15 minutes of execution and they
 * get updated every 2 seconds. Long term data is related to last 24 hours of execution
 * and they get updated every 5 minutes. This monitor can also be configured to log a
 * summary of the thread states periodically. If needed a margin can be set for the blocked
 * thread percentage, upon exceeding which a system alert will be logged as a warning. By
 * default both periodic logs and alerts are turned off.
 */
public class ThreadingView implements ThreadingViewMBean {

    private static final String SYNAPSE_THREADING_VIEW = "Threading";
    private static final int SHORT_SAMPLING_PERIOD = 2;
    private static final int LONG_SAMPLING_PERIOD = 5 * 60;
    private static final int SAMPLES_PER_MINUTE = 60 / SHORT_SAMPLING_PERIOD;
    private static final int SAMPLES_PER_HOUR = 3600 / LONG_SAMPLING_PERIOD;

    private String threadNamePrefix = null;
    private boolean periodicLogs = false;
    private double alertMargin = -1;

    private double avgBlockedWorkerPercentage = 0.0;
    private double avgUnblockedWorkerPercentage = 0.0;

    /**
     * The queue of samples taken by the short term data collector task. Maintained as a fixed
     * length queue. Only the data for the last 15 minutes of execution will be stored here.
     * Maximum length = (60/2) * 15 = 450
     */
    private Queue<Double> shortTermDataQueue = new LinkedList<Double>();

    /**
     * The queue of samples taken by the long term data collector task. Maintained as a fixed
     * length queue. Only the data for the last 24 hours of execution will be stored here.
     * Maximum length = (3600/5*60) * 24 = 288
     */
    private Queue<Double> longTermDataQueue = new LinkedList<Double>();

    private int samplesCount = 0;
    private int totalCount = 0;

    private Date resetTime = Calendar.getInstance().getTime();

    private static final Log log = LogFactory.getLog(ThreadingView.class);

    private static final ThreadMXBean threadBean = ManagementFactory.getThreadMXBean();

    private ScheduledExecutorService scheduler;

    private boolean threadJMXViewEnabled = true;

    public ThreadingView(final String threadNamePrefix) {
        this.threadNamePrefix = threadNamePrefix;
        this.scheduler = Executors.newSingleThreadScheduledExecutor(new ThreadFactory() {
            public Thread newThread(Runnable r) {
                return new Thread(r, "Thread-view-" + threadNamePrefix);
            }
        });
        initMBean();
    }

    public ThreadingView(String threadNamePrefix, boolean periodicLogs, double alertMargin) {
        this(threadNamePrefix);

        Properties props = MiscellaneousUtil.loadProperties("synapse.properties");
        String jmxEnabled = MiscellaneousUtil.getProperty(props, JmxConfigurationConstants.PROP_THREAD_JMX_ENABLE,
                "true");
        if ("false".equals(jmxEnabled)) {
            this.threadJMXViewEnabled = false;
        }

        this.periodicLogs = periodicLogs;
        if (alertMargin > 0 && alertMargin < 100) {
            this.alertMargin = alertMargin;
        } else {
            log.warn("Invalid alert margin for the thread group: " + threadNamePrefix + " - "
                    + "Using default value");
        }
    }

    public void destroy() {
        if (log.isDebugEnabled()) {
            log.debug("Un-registering the Synapse threading view for the thread group: " + threadNamePrefix);
        }
        MBeanRegistrar.getInstance().unRegisterMBean(SYNAPSE_THREADING_VIEW, threadNamePrefix);
        if (!scheduler.isShutdown()) {
            scheduler.shutdownNow();
        }
    }

    private void initMBean() {
        if (log.isDebugEnabled()) {
            log.debug("Starting a new Synapse threading view for the thread group: " + threadNamePrefix);
        }
        scheduler.scheduleAtFixedRate(new ThreadingDataCollectorTask(), SHORT_SAMPLING_PERIOD,
                SHORT_SAMPLING_PERIOD, TimeUnit.SECONDS);
        scheduler.scheduleAtFixedRate(new LongTermDataCollectorTask(), LONG_SAMPLING_PERIOD, LONG_SAMPLING_PERIOD,
                TimeUnit.SECONDS);
        boolean registered = false;
        try {
            registered = MBeanRegistrar.getInstance().registerMBean(this, SYNAPSE_THREADING_VIEW, threadNamePrefix);
        } finally {
            if (!registered) {
                scheduler.shutdownNow();
            }
        }
    }

    public int getTotalWorkerCount() {
        int count = 0;
        ThreadInfo[] threadInfo = dumpAllThreads();
        for (ThreadInfo ti : threadInfo) {
            if (ti != null && ti.getThreadName().startsWith(threadNamePrefix)) {
                count++;
            }
        }
        return count;
    }

    private double getBlockedWorkerPercentage() {
        int totalCount = 0;
        int blockedCount = 0;
        ThreadInfo[] threadInfo = dumpAllThreads();
        for (ThreadInfo ti : threadInfo) {
            // see if the thread name matches the prefix
            if (ti != null && ti.getThreadName().startsWith(threadNamePrefix)) {
                totalCount++;
                if (isBlocked(ti)) {
                    blockedCount++;
                }
            }
        }
        if (totalCount == 0) {
            return 0;
        }
        return ((double) blockedCount / (double) totalCount) * 100;
    }

    public String[] getDeadLockedWorkers() {
        String[] workers = null;
        // JDK 1.6 has a better implementation of this method but since we are on JDK 1.5
        // we have to stick with this for now
        long[] threads = threadBean.findMonitorDeadlockedThreads();
        if (threads != null) {
            ThreadInfo[] threadInfo = threadBean.getThreadInfo(threads);
            workers = new String[threadInfo.length];
            for (int i = 0; i < threadInfo.length; i++) {
                if (threadInfo[i] != null) {
                    workers[i] = threadInfo[i].getThreadName();
                } else {
                    workers[i] = null;
                }
            }
        }
        return workers;
    }

    public double getAvgBlockedWorkerPercentage() {
        return avgBlockedWorkerPercentage;
    }

    public double getAvgUnblockedWorkerPercentage() {
        return avgUnblockedWorkerPercentage;
    }

    public double getLastMinuteBlockedWorkerPercentage() {
        return getAverageBlockedThreads(1);
    }

    public double getLast5MinuteBlockedWorkerPercentage() {
        return getAverageBlockedThreads(5);
    }

    public double getLast15MinuteBlockedWorkerPercentage() {
        return getAverageBlockedThreads(15);
    }

    public double getLastHourBlockedWorkerPercentage() {
        return getAverageBlockedThreadsByHour(1);
    }

    public double getLast8HourBlockedWorkerPercentage() {
        return getAverageBlockedThreadsByHour(8);
    }

    public double getLast24HourBlockedWorkerPercentage() {
        return getAverageBlockedThreadsByHour(24);
    }

    public Date getLastResetTime() {
        return resetTime;
    }

    public void reset() {
        avgBlockedWorkerPercentage = 0.0;
        avgUnblockedWorkerPercentage = 0.0;
        shortTermDataQueue.clear();
        longTermDataQueue.clear();
        samplesCount = 0;
        totalCount = 0;
        resetTime = Calendar.getInstance().getTime();
    }

    private boolean isBlocked(ThreadInfo threadInfo) {
        // A thread is considered "Blocked" if it is in the BLOCKED state
        // or if it is in the WAITING state due to some reason other than
        // 'parking'.
        Thread.State state = threadInfo.getThreadState();
        if (state.equals(Thread.State.BLOCKED)) {
            return true;
        } else if (state.equals(Thread.State.WAITING) || state.equals(Thread.State.TIMED_WAITING)) {
            StackTraceElement[] stackTrace = threadInfo.getStackTrace();
            if (stackTrace.length > 0 && !"park".equals(stackTrace[0].getMethodName())) {
                return true;
            }
        }

        return false;
    }

    /**
     * Get a summary of all threads running in the JVM.
     *
     * @return an array of ThreadInfo objects
     */
    private ThreadInfo[] dumpAllThreads() {
        // JDK 1.6 has a built-in method for this
        // But since we are on JDK 1.5 we have to follow this 2-step approach
        if (threadJMXViewEnabled) {
            long[] ids = threadBean.getAllThreadIds();
            return threadBean.getThreadInfo(ids, 1);
        } else {
            return new ThreadInfo[0];
        }
    }

    /**
     * Calculates and returns the average blocked worker percentage during last 'n' minutes
     * of execution
     *
     * @param n Number of minutes in the execution history
     * @return the average blocked percentage as a double value
     */
    private double getAverageBlockedThreads(int n) {
        int samples = n * SAMPLES_PER_MINUTE;
        double sum = 0.0;
        Double[] array = shortTermDataQueue.toArray(new Double[shortTermDataQueue.size()]);

        if (samples > array.length) {
            // If we don't have enough samples in the queue, try to approximate
            // the value using all the available samples
            samples = array.length;
            for (Double anArray : array) {
                sum += anArray;
            }
        } else {
            for (int i = 0; i < samples; i++) {
                sum += array[array.length - 1 - i];
            }
        }

        if (samples == 0) {
            return 0.0;
        }
        return sum / samples;
    }

    /**
     * Calculates and returns the average blocked worker percentage during last 'n' hours
     * of execution
     *
     * @param n Number of hours in the execution history
     * @return the average blocked percentage as a double value
     */
    private double getAverageBlockedThreadsByHour(int n) {
        int samples = n * SAMPLES_PER_HOUR;
        double sum = 0.0;
        Double[] array = longTermDataQueue.toArray(new Double[longTermDataQueue.size()]);

        if (samples > array.length) {
            samples = array.length;
            for (Double anArray : array) {
                sum += anArray;
            }
        } else {
            for (int i = 0; i < samples; i++) {
                sum += array[array.length - 1 - i];
            }
        }

        if (samples == 0) {
            return 0.0;
        }
        return sum / samples;
    }

    private class ThreadingDataCollectorTask implements Runnable {

        public void run() {
            samplesCount++;

            double blocked = getBlockedWorkerPercentage();
            double unblocked = 100 - blocked;

            // calculate all time average values
            avgBlockedWorkerPercentage = (avgBlockedWorkerPercentage * totalCount + blocked)
                    / (double) (totalCount + 1);
            avgUnblockedWorkerPercentage = (avgUnblockedWorkerPercentage * totalCount + unblocked)
                    / (double) (totalCount + 1);

            if (shortTermDataQueue.size() == 15 * SAMPLES_PER_MINUTE) {
                shortTermDataQueue.remove();
            }
            shortTermDataQueue.offer(blocked);

            if (samplesCount == SAMPLES_PER_MINUTE) {
                samplesCount = 0;
                periodicDump();
            }
            totalCount++;
        }

        private void periodicDump() {
            if (periodicLogs && log.isDebugEnabled()) {
                StringBuffer buffer = new StringBuffer();
                buffer.append("Thread state summary for ").append(threadNamePrefix).append(" threads - Blocked: ")
                        .append(avgBlockedWorkerPercentage).append("%, Unblocked: ")
                        .append(avgUnblockedWorkerPercentage).append("%");
                log.debug(buffer.toString());
            }

            if (alertMargin > 0) {
                double blocked = getAverageBlockedThreads(1);
                if (blocked > alertMargin) {
                    log.warn("SYSTEM ALERT: " + blocked + "% of the " + threadNamePrefix
                            + " threads were in BLOCKED state during last minute!");
                }
            }
        }
    }

    private class LongTermDataCollectorTask implements Runnable {
        public void run() {
            double blocked = getBlockedWorkerPercentage();

            if (longTermDataQueue.size() == 24 * SAMPLES_PER_HOUR) {
                longTermDataQueue.remove();
            }
            longTermDataQueue.offer(blocked);
        }
    }
}