Sunday, November 23, 2014

Investigate into why key cache in apache cassandra 1.0.8 gets reduced

Today, we will investigate into apache cassandra 1.0.8 when and why it reduce configured key cache. If you run the command nodetool cfstats. One of the statistics would probably interest you. I paste the snippet below.
Key cache capacity: 200000
Key cache size: 200000
Key cache hit rate: 0.9655797101449275
Row cache: disabled

After cassandra instance has been running for sometime, and you start to notice that the key cache capacity has gone down.
Key cache capacity: 150000
Key cache size: 150000
Key cache hit rate: 0.962251615630851
Row cache: disabled

As seen above, the initial capacity for this column family has 20,000 total key for cache. Currently, all object (that is 20,000) occupied fully in the key cache assigned. The hit rate is 96% which is very good statistics. So after a while, what had happened and why was it reduce? Let's investigate into the log file.
 WARN [ScheduledTasks:1] 2014-02-02 00:46:46,384 AutoSavingCache.java (line 187) Reducing MyColumnFamily KeyCache capacity from 200000 to 150000 to reduce memory pressure

Apparently memory is not enough at this point of time and the key cache is reduced to free up more memory for the cassandra instance. Let's look at the cassandra yaml file if there is any description for the key cache.
# emergency pressure valve #2: the first time heap usage after a full
# (CMS) garbage collection is above this fraction of the max,
# Cassandra will reduce cache maximum _capacity_ to the given fraction
# of the current _size_. Should usually be set substantially above
# flush_largest_memtables_at, since that will have less long-term
# impact on the system.
#
# Set to 1.0 to disable. Setting this lower than
# CMSInitiatingOccupancyFraction is not likely to be useful.
reduce_cache_sizes_at: 0.85
reduce_cache_capacity_to: 0.6

There are two configurations that reduce the cache size. When memory heap usage at 85%, key cache is reduced to 60% of its initial value. So now we dive deeper into the code to see what happened. Let's read into class GCInspector.
double usage = (double) memoryUsed / memoryMax;

if (memoryUsed > DatabaseDescriptor.getReduceCacheSizesAt() * memoryMax && !cacheSizesReduced)
{
cacheSizesReduced = true;
logger.warn("Heap is " + usage + " full. You may need to reduce memtable and/or cache sizes. Cassandra is now reducing cache sizes to free up memory. Adjust reduce_cache_sizes_at threshold in cassandra.yaml if you don't want Cassandra to do this automatically");
StorageService.instance.reduceCacheSizes();
}

When memory used is greater than reduce_cache_sizes_at (configured in cassanra.yaml, value at 0.85) multiply maximum memory in the heap and cache has not been reduced before. For example, if jvm is assigned with 8GB of heap, so the if statement evaluation become valid under such arithmetic, memory usage greater than 6.8GB when cache size has not been reduced before.

When the condition become true, StorageService will start to reduce cache size. A simple for loop over all column families to reduce the cache size. As seen here, there are two caches are being reduced. The rowcache and the keycache. Because we did not enable row cache and also not a focus on this study, I'll leave as an exercise for you. The investigation continue on the keyCache.reduceCacheSize();. As the snippet of code below shown.
public void reduceCacheSize()
{
if (getCapacity() > 0)
{
int newCapacity = (int) (DatabaseDescriptor.getReduceCacheCapacityTo() * size());
logger.warn(String.format("Reducing %s %s capacity from %d to %s to reduce memory pressure",
cfName, cacheType, getCapacity(), newCapacity));
setCapacity(newCapacity);
}
}

So if the capacity is initially assigned to a value larger than 0, then a new capacity is set. The new capacity is such that, reduce_cache_capacity_to (default at cassandra yaml, 0.60) multiply with the current size of the cache. For example, if the cache is occupied at 20000 x 0.60, the new value will be the new cache capacity at 12000.

This wrap up the investigation. Final thought, because the memory consumption is exceed certain amount of threshold, this emergency pressure valve kicked in. To fix immediate, an increase heap for cassandra instance will solve, but the correct would probably reduce node load or increase node for the cluster. When cache capacity is reduced, expect read become slower too and in data storage perspective, speed and performance is everything and reduced cache is definitely an impact to the cluster.

Saturday, November 22, 2014

Gnome goodies: How to set gnome-screenshot default saved directory. How to add network speed applet on gnome panel.

This is another gnome3 applet howto blog. The reason pretty much stated in the previous blog. Read it here. So today, we will configured two more applets.

How to set gnome-screenshot default saved directory


When you pressed the 'Print Screen' button on your keyboard, you start to wondering where has the screenshot saved to by gnome-screenshot. The configuration in org.gnome.gnome-screenshot.auto-save-directory in dconf-editor no longer seem to take effect. See the screenshot below. No matter what value you configured, the value just won't take effect if you print screen.

dconf-editor-gnome-screenshot

Apparently there is a change in gnome3. Let's see the keyboard shortcuts in gnome-control-center. See screenshot below, apparently all screen shots are saved to Pictures. You can change the shortcut here but can you change where it saved to?

keyboard-shortcut-screenshot

To do that, you need to change the value in a configuration file in $HOME/.config/user-dirs.dirs . Hence, XDG_PICTURES_DIR="$HOME/Pictures" always point to user home directory and a folder called Pictures. You can change the value in this configuration file or you can change using xdg-user-dirs-update command. I choose the latter.
user@localhost:~$ xdg-user-dirs-update --set PICTURES "$HOME/myScreenShot"

Logout and login again to the gnome environment. Now when you print screen, the screenshot will saved to $HOME/myScreenShot. :-)

 

How to add network speed applet on gnome panel.


For some reason, there is no network applet for gnome3 in debian repository. Not sure what was the reason but hey, we are not going to pursue the why and why not. Rather, I find an alternative gnome3 network applet from ubuntu. There are some network applets and I will list them down unfortunately not all of them work. At least not at the time this blog is written. But I suggest you revisit this network applet, someone nice out there might put efforts to include it into debian repository.

As you can read, there are many network applets listed above and it could be at this point of time, someone else written one for debian too. So choose whichever one suit you best but today, we are going to install the package indicator-multiload from ubuntu repository.

So get the package from the repository and install. You can visit this link. Pick the latest version and at this time of writing, I'm using version 0.5-0~131~31~25~ubuntu14.10.1. To install, run the command $ sudo dpkg -i indicator-multiload_0.5-0~131~31~25~ubuntu14.10.1_amd64.deb . If there is any unsatisfying dependency, you can apt-get install the dependency. My system does not have libappindicator3-1 installed, so I installed using command $ sudo apt-get install libappindicator3-1 . Repeat the same steps for any library that is required by indicator-multiload.

Then launch dconf-editor and go to the entry de->mh21->indicator-multiload->general . If the property autostart is not check, then check it. See screenshot below.

dconf-editor-indicator-multiload

It's such a pity, this applet is not showing on the top gnome panel. Rather, it is hidden under message tray. You can bring up the message tray by pointing mouse cursor on bottom right and click or using keyboard shortcut key super+m. See screenshot below, it show statistics of cpu, mem, net (the one we want in this howto), swap, load and disk.

indicator-multiload

There is a nice gnome extension known as TopIcons where it will place legacy tray icons on top panel. Unfortunately, it does not work for me. I have download the master version at of this writing, according to description, it mentioned it support gnome version 3.14. I extracted the zip to /usr/share/gnome-shell/extensions/topicons-master. User logout and login, reboot unfortunately it does not work. If you know how to get it to work, please leave a comment below.

Thank you and that's it. Happy gnome-ing. :)

Friday, November 21, 2014

Gnome goodies: How to sort directory and then file. How to enable weather in the gnome panel

Today we will take a look at two gnome3 applets. I used to have these settings back in gnome and gnome2 and I think this is a very nice goody that should remain in gnome3.

How to sort directory and then file

In gnome3, file and folders are mixed, that's if the folder is sort by modification dates. See example screenshot below.

folders_files_mixed

Well, for personal preference would be, folders are group first and then with normal files. See example screenshot below.

folders_then_files

In order to achieve this behaviour, gnome configuration need to be alter. Launch dconf-editor in the command line and navigate in such a fashion. Go to org -> gnome -> nautilus -> preferences . Then check sort-directories-first. See screenshot below. Easy :)

dconf_editor-sort-directories-first

 

How to enable weather in the gnome panel

During gnome2, it is as easy as adding a location and in the drop down of the date/time applet. See screenshot below.

timezone_world_map

However, thing get changed in gnome3. Date/time applet no longer showing weather information. There is an alternative, gnome-shell-extension-weather package add weather information to the gnome panel. See screenshot below.

gnome-shell-extension-openweather

To install this extension, it is as easy as apt-get install gnome-shell-extension-weather

To enable gnome-shell-extension-weather in the gnome panel, you need to enable it. To enable, launch gnome-shell-extension-prefs from the command line and then search for OpenWeather and flip the switch to on position. See screenshot below.

gnome-shell-extension-prefs

Now the weather information should shown in the gnome panel! Start adding more places of interest in the applet! :)

To end this article, try to add places of interest in the weather applet :) I will leave this as an exercise for you.

Saturday, November 15, 2014

Implementing DNSSEC and DANE for email - Step by step

Note, this article is written and contributed by a good friend gryphius, so all credit goes to him. I'm just copy and paste his awesome work here. :-)

After various breaches at the certificate authorities it has become clear that we need a way to authenticate a server certificate without the need to trust a third party. “DNS-based Authentication of Named Entities“ (DANE) makes this possible by publishing the certificate in the DNS. Find more information about DANE here.

In this tutorial we show an example implementation of DANE for email delivery.

What you need

  • a DNSSEC capable nameserver (in this example: powerdns)
  • a DNSSEC capable registrar  (in this example: gandi.net)
  • a mail server with TLS Support (in this example: postfix )
  • to test the secured email delivery: a second mailserver with DANE support ( postfix >=2.11, DNSSEC capable resolver )
We start off with a postfix server already configured to accept mail for our domain, but no TLS support so far. Let’s add this now by generating a self-signed certificate:
in this state, a sending server can encrypt the transmission, but it can not verify the self-signed server certificate, so it  will treat the TLS connection as anonymous:
postfix/smtp[13330]: Anonymous TLS connection established to mail.example.com[...]:25: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
In order to enable DANE support, our domain’s DNS zone must be secured with DNSSEC. Our example domain is hosted on a powerdns authoritative server securing a zone on a current powerdns is pretty easy:

The key from the last command must be copied to the registrar. At gandi.net the form to add a DNSSEC key looks like this:

dnssec-gandinet

Once the key is added and synchronized on the registry’s DNS servers, you can test DNSSEC funconality at http://dnssec-debugger.verisignlabs.com/

Now, back on the mailserver hosting our domain we have to create a hash of the SSL-certificate:

Using this value  we can add the DANE TLSA record for our mailserver in the DNS zone:

In powerdns, add a record:
Name_25._tcp.mail.example.com (replace mail.example.com with your real mx hostname)
TypeTLSA
Content3 0 1 02059728e52f9a58a235584e1ed70bd2b51a44024452ec2ba0166e8fb1d1d32b

the “3 0 1” means: “we took a full domain-issued certificate, and created a sha256 hash of it”. For other possible values see RFC6698 section 7.2 – 7.4.

Now we can test the new DANE TLSA records at https://www.tlsa.info

And finally, let’s test it from another postfix box. For this to work, the sending server must use a DNSSEC resolver (for example unbound) and postfix >=2.11 with DANE enabled:

and voilĂ , our connection is now verified even though we’re using a self-signed certificate:

postfix/smtp[17787]: Verified TLS connection established to mail.example.com[...]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)

References:

Sunday, November 9, 2014

gnome-clocks alternative to gnome2 world timezone map

During gnome2 time, I like the world map where it show the earth timezone information. Take a look at the below screenshot. It shown the part of earth on day and part of earth on night. Then you can see the countries weather information like temperature, wind speed, sunrise and sunset.

timezone_world_map

In gnome3, however, all these information are lost. I don't know why upgrade to gnome3, it became a detrimental step. A lot of useful information applets get lost. Not only a lot of useful applets got lost, the window animation constantly keep the cpu busy and application response sometime get slow. Something to ponder if I should choose different window manager.

Anyway, in the meantime, let's take a look at alternative to gnome2 world timezone country information. I google and found out gnome-clocks.

Simple GNOME app with stopwatch, timer, and world clock support GNOME Clocks is a simple application to show the time and date in multiple locations and set alarms or timers. A stopwatch is also included.
user@localhost:~$ sudo apt-get install gnome-clocks
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following package was automatically installed and is no longer required:
linux-image-amd64
Use 'apt-get autoremove' to remove it.
The following NEW packages will be installed:
gnome-clocks
0 upgraded, 1 newly installed, 0 to remove and 691 not upgraded.
Need to get 326 kB of archives.
After this operation, 1,193 kB of additional disk space will be used.
Get:1 http://cdn.debian.net/debian/ unstable/main gnome-clocks amd64 3.14.0-1 [326 kB]
Fetched 326 kB in 4s (66.8 kB/s)
Selecting previously unselected package gnome-clocks.
(Reading database ... 320953 files and directories currently installed.)
Preparing to unpack .../gnome-clocks_3.14.0-1_amd64.deb ...
Unpacking gnome-clocks (3.14.0-1) ...
Processing triggers for libglib2.0-0:i386 (2.42.0-2) ...
Processing triggers for libglib2.0-0:amd64 (2.42.0-2) ...
Processing triggers for hicolor-icon-theme (0.13-1) ...
Processing triggers for gnome-menus (3.13.3-2) ...
Processing triggers for mime-support (3.57) ...
Processing triggers for desktop-file-utils (0.22-1) ...
Setting up gnome-clocks (3.14.0-1) ...

So all goods, let's launch it. You can either launch gnome-clocks using command line or you can launch it from date/time panel. See screenshot below and click on Open Clocks.

gnome-clock

As seen below, I have configure a few countries. How to add time for a country is left as an exercise for you and I promise it will not that difficult ;). Unfortunately it does not show information other that just clock. It was a pity anyway. Anyway, better than none until sometime generous enough to develop additional information like weather and graphical earth day and night.

gnome-clock-main-window

That's it people, I hope you get some nice replacement when you transition into gnome3 environment.

Saturday, November 8, 2014

Set date in gnome3 gnome-shell panel

If you came from gnome2 or before, you can easily alter configuration date and time in the panel. I don't know why the changes in gnome3 make everything so painfully to configure. It supposed to be easy and intuitive and can be achieve in few seconds but this is not the case anymore. Today, we will change the default configuration to something we used to. See screenshot below.

dconf_editor_datetime_config_before

Introducing dconf-editor.

The dconf-editor program provides a graphical interface for editing settings that are stored in the dconf database. The gsettings(1) utility provides similar functionality on the commandline.

So install this package if it is not available. Let's launch the app.
user@localhost:~$ dconf-editor

dconf-editor window popup. On the left tree menu, expand in this succession. org -> gnome -> desktop -> interface . Check the button for the field you would like to enable. In the screenshot below, I have enable my use to desktop setting, show the date and show seconds.

dconf_editor_datetime_config_after

That's it, in the next article, we will probably look into the earth daylight map on the date / time calendar. I like that feature too but somehow it is not available in gnome3.

Friday, November 7, 2014

How to set java thread name, thread pool name, get stack dump and heap dump

If you have been developing java application and one of the exception could be shown in the log, "java.lang.OutOfMemoryError: unable to create new native thread". This is what we are going to learn today. We will learn how to set thread a name, set a thread pool name, get the stack dump and get java heap dump and so we know why the exception aforementioned is thrown. This is in response to doing exercises after read the article http://code.nomad-labs.com/2012/12/20/some-tips-on-java-lang-outofmemoryerror-unable-to-create-new-native-thread/

I will divide these exercises into sub topics and we will learn one by one. We will start with simple exercise first.

How to name a thread?
To set a name for a thread, you will need to call method setName(), then show the currently running thread using Thread.currentThread().getName(). See example below.
public class Minion implements Runnable {

private String name = null;

public Minion(String name) {
this.name = name;
}

@Override
public void run() {
Thread.currentThread().setName(name);
System.out.printf("minion %s eating banana", Thread.currentThread().getName());
}

}

Another modified version as below. Note that we do not set thread name here, we set it in the class ThreadFactory. Read on to find out why later in this article.
import java.util.Random;


public class Minion implements Runnable {

private static String[] fruits = {"apple", "banana"};

public Minion() {

}

@Override
public void run() {
try {
// banana or apple
int idx = new Random().nextInt(fruits.length);
System.out.printf("minion %s eating %s %n", Thread.currentThread().getName(), fruits[idx]);
Thread.sleep((idx * 1000) + 10000);
StackTraceElement[] ste =Thread.currentThread().getStackTrace();

System.out.printf("minion %s done eat %s %n", Thread.currentThread().getName(), fruits[idx]);
} catch (InterruptedException e) {
e.printStackTrace();
}

}

}

You can pass the task in the constructor as a parameter but for the sake of simplicity, I hard coded task within this worker thread, two fruits; apple and banana. Longer thread sleep because later in this article, we will using this class for getting heap dump and thread dump.

How to name the thread pool?

To change name of a thread pool, you will need to implement ThreadFactory and then override namePrefix in the constructor. There are some other libraries which is easier and do that for you but we will not look in other libraries but only java native libraries. Let's do the work, see example below.
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.atomic.AtomicInteger;


public class GruThreadFactory implements ThreadFactory {

static final AtomicInteger poolNumber = new AtomicInteger(1);
final ThreadGroup group;
final AtomicInteger threadNumber = new AtomicInteger(1);
final String namePrefix;

public GruThreadFactory() {
SecurityManager s = System.getSecurityManager();
group = (s != null) ? s.getThreadGroup() : Thread.currentThread().getThreadGroup();
namePrefix = "GruPool-" + poolNumber.getAndIncrement() + "-thread-";
}

@Override
public Thread newThread(Runnable r) {
final Thread t = new Thread(group, r, namePrefix + threadNumber.getAndIncrement(), 0);
if (t.isDaemon())
t.setDaemon(false);
if (t.getPriority() != Thread.NORM_PRIORITY)
t.setPriority(Thread.NORM_PRIORITY);
return t;
}

}

and the modified version. As you can see, minions are passed into GruThreadFactory constructor and then each time a newThread() is called, the thread name is named as random to the String array minions.
import java.util.Random;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.atomic.AtomicInteger;


public class GruThreadFactory implements ThreadFactory {

static final AtomicInteger poolNumber = new AtomicInteger(1);
final ThreadGroup group;
final AtomicInteger threadNumber = new AtomicInteger(1);
final String namePrefix;
final String[] minions;

public GruThreadFactory(String[] minions) {
SecurityManager s = System.getSecurityManager();
group = (s != null) ? s.getThreadGroup() : Thread.currentThread().getThreadGroup();
namePrefix = "GruPool-" + poolNumber.getAndIncrement() + "-thread-";
this.minions = minions;
}

@Override
public Thread newThread(Runnable r) {
int index = new Random().nextInt(minions.length);
final Thread t = new Thread(group, r, namePrefix + minions[index], 0);
if (t.isDaemon())
t.setDaemon(false);
if (t.getPriority() != Thread.NORM_PRIORITY)
t.setPriority(Thread.NORM_PRIORITY);
return t;
}

}

and then out main app to bind the ThreadFactory and the workers.
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.ThreadFactory;


public class MainApp {

/**
* @param args
* @throws InterruptedException
*/
public static void main(String[] args) throws InterruptedException {
ThreadFactory GruFactory = null;
ExecutorService exec = null;

try {
String[] minions = {"Dave", "Stuart", "Kevin", "Jerry", "Carl", "Phil", "Paul", "Mike", "Jorge"};
GruFactory = new GruThreadFactory(minions);
exec = Executors.newFixedThreadPool(minions.length, GruFactory);

for (int i = 0; i < 90; i++) {
Minion m = new Minion();
exec.execute(m);
}
exec.shutdown();
while (!exec.isTerminated()) {

}

} catch (Exception e) {
e.printStackTrace();
} finally {

System.out.println("done");
}

}

}

Now to check. Output below is from the modified version. Note that you may have different output than mine but that is as expected. I paste only a few lines below.
minion GruPool-1-thread-Mike eating banana 
minion GruPool-1-thread-Phil eating banana
minion GruPool-1-thread-Mike eating apple
minion GruPool-1-thread-Stuart eating banana
minion GruPool-1-thread-Mike done eat apple
minion GruPool-1-thread-Paul eating banana
minion GruPool-1-thread-Stuart done eat banana
minion GruPool-1-thread-Stuart eating apple
minion GruPool-1-thread-Stuart done eat apple
minion GruPool-1-thread-Stuart eating apple
minion GruPool-1-thread-Stuart done eat apple
minion GruPool-1-thread-Stuart eating banana
..
..
minion GruPool-1-thread-Paul done eat apple
minion GruPool-1-thread-Jorge eating apple
minion GruPool-1-thread-Jorge done eat apple
minion GruPool-1-thread-Mike done eat banana
minion GruPool-1-thread-Paul done eat banana
minion GruPool-1-thread-Mike done eat banana
minion GruPool-1-thread-Jerry done eat banana
minion GruPool-1-thread-Stuart done eat banana
minion GruPool-1-thread-Mike done eat banana
done

So far so good, our app work.

How to get a stack dump?

In order to get a stack dump, you can use jstack. When you install jdk, jstack came with it. To get the stack dump,
jstack -F 19557  &> jstack.log

where 19557 is the pid of the java process and we redirected stdout and stderr to a file. There are several command to get the process id, you can either use ps or java jps. Output as attached.
Attaching to process ID 19557, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 20.6-b01
Deadlock Detection:

No deadlocks found.

Thread 19586: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19585: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19584: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19583: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19582: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19581: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19580: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19579: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19578: (state = BLOCKED)
- java.lang.Thread.sleep(long) @bci=0 (Interpreted frame)
- Minion.run() @bci=55, line=18 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.runTask(java.lang.Runnable) @bci=59, line=886 (Interpreted frame)
- java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=908 (Interpreted frame)
- java.lang.Thread.run() @bci=11, line=662 (Interpreted frame)


Thread 19573: (state = BLOCKED)


Thread 19572: (state = BLOCKED)
- java.lang.Object.wait(long) @bci=0 (Interpreted frame)
- java.lang.ref.ReferenceQueue.remove(long) @bci=44, line=118 (Interpreted frame)
- java.lang.ref.ReferenceQueue.remove() @bci=2, line=134 (Interpreted frame)
- java.lang.ref.Finalizer$FinalizerThread.run() @bci=3, line=159 (Interpreted frame)


Thread 19571: (state = BLOCKED)
- java.lang.Object.wait(long) @bci=0 (Interpreted frame)
- java.lang.Object.wait() @bci=2, line=485 (Interpreted frame)
- java.lang.ref.Reference$ReferenceHandler.run() @bci=46, line=116 (Interpreted frame)


Thread 19564: (state = IN_JAVA)
- MainApp.main(java.lang.String[]) @bci=119, line=28 (Compiled frame; information may be imprecise)

jstack output show

  • it has 9 threads with Minion.run().

  • no deadlocks

  • individual thread state was blocked because it was sleeping.

  • main thread state is in IN_JAVA which is running in Java or in stub code.


Another useful information could probably be thread dump. With visualvm, you can actually see the thread running over time, I recorded a video and you should try to watch it.

http://www.youtube.com/watch?v=REoi6sbcIUY

Also see the thread dump capture using VisualVM
2014-10-07 22:58:32
Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.6-b01 mixed mode):

"RMI TCP Connection(2)-127.0.0.1" daemon prio=10 tid=0x00007fd5c0003000 nid=0x646c runnable [0x00007fd618af8000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
- locked <0x00000007d7ece620> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:66)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:517)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d79e3908> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"JMX server connection timeout 22" daemon prio=10 tid=0x00007fd5b4008000 nid=0x6464 in Object.wait() [0x00007fd618bf9000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007d7b6ddb8> (a [I)
at com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(ServerCommunicatorAdmin.java:150)
- locked <0x00000007d7b6ddb8> (a [I)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- None

"RMI Scheduler(0)" daemon prio=10 tid=0x00007fd5b4004800 nid=0x6463 waiting on condition [0x00007fd618cfa000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007d799dc18> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2025)
at java.util.concurrent.DelayQueue.take(DelayQueue.java:164)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:609)
at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:602)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- None

"RMI TCP Connection(1)-127.0.0.1" daemon prio=10 tid=0x00007fd5c0001800 nid=0x6462 runnable [0x00007fd618efc000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
- locked <0x00000007d7b1e8f8> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(FilterInputStream.java:66)
at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:517)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d79e3430> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"RMI TCP Accept-0" daemon prio=10 tid=0x00007fd5bc424800 nid=0x6460 runnable [0x00007fd618ffd000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:408)
- locked <0x00000007d79ac788> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:462)
at java.net.ServerSocket.accept(ServerSocket.java:430)
at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:34)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- None

"Attach Listener" daemon prio=10 tid=0x00007fd5f4001000 nid=0x645e waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"GruPool-1-thread-Paul" prio=10 tid=0x00007fd61c0f8000 nid=0x6451 waiting on condition [0x00007fd620898000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706f6c8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Carl" prio=10 tid=0x00007fd61c0f6000 nid=0x6450 waiting on condition [0x00007fd620999000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706f3f0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Jorge" prio=10 tid=0x00007fd61c0f4000 nid=0x644f waiting on condition [0x00007fd620a9a000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706f168> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Dave" prio=10 tid=0x00007fd61c0f2000 nid=0x644e waiting on condition [0x00007fd620b9b000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706eee0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Phil" prio=10 tid=0x00007fd61c0f0000 nid=0x644d waiting on condition [0x00007fd620c9c000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706ec58> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Jorge" prio=10 tid=0x00007fd61c0ee000 nid=0x644c waiting on condition [0x00007fd620d9d000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706e9a0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Carl" prio=10 tid=0x00007fd61c0ec800 nid=0x644b waiting on condition [0x00007fd620e9e000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706e718> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Dave" prio=10 tid=0x00007fd61c0eb000 nid=0x644a waiting on condition [0x00007fd620f9f000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706e490> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"GruPool-1-thread-Mike" prio=10 tid=0x00007fd61c0e9800 nid=0x6449 waiting on condition [0x00007fd6210a0000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at Minion.run(Minion.java:18)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)

Locked ownable synchronizers:
- <0x00000007d706d8e8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"Low Memory Detector" daemon prio=10 tid=0x00007fd61c094000 nid=0x6447 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"C2 CompilerThread1" daemon prio=10 tid=0x00007fd61c092000 nid=0x6446 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"C2 CompilerThread0" daemon prio=10 tid=0x00007fd61c08f000 nid=0x6445 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Signal Dispatcher" daemon prio=10 tid=0x00007fd61c08d000 nid=0x6444 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Finalizer" daemon prio=10 tid=0x00007fd61c071000 nid=0x6443 in Object.wait() [0x00007fd62182f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007d7001300> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x00000007d7001300> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

Locked ownable synchronizers:
- None

"Reference Handler" daemon prio=10 tid=0x00007fd61c06f000 nid=0x6442 in Object.wait() [0x00007fd621930000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007d70011d8> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x00000007d70011d8> (a java.lang.ref.Reference$Lock)

Locked ownable synchronizers:
- None

"main" prio=10 tid=0x00007fd61c00a800 nid=0x643c runnable [0x00007fd623a7f000]
java.lang.Thread.State: RUNNABLE
at MainApp.main(MainApp.java:28)

Locked ownable synchronizers:
- None

"VM Thread" prio=10 tid=0x00007fd61c068800 nid=0x6441 runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fd61c01d800 nid=0x643d runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fd61c01f800 nid=0x643e runnable

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007fd61c021000 nid=0x643f runnable

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007fd61c023000 nid=0x6440 runnable

"VM Periodic Task Thread" prio=10 tid=0x00007fd61c09e800 nid=0x6448 waiting on condition

JNI global references: 948

How to get a heap dump?

To get a heap dump, we will use jmap. Just like jstack, jmap also come with jdk installation. To get a heap dump, run the command such as below.
user@localhost:~$ jmap -dump:format=b,file=myapp.hprof 26266
Dumping heap to /home/user/myapp.hprof ...
Heap dump file created

Then you can inspect using visualvm. See the following screenshot.

visualvm_instances visualvm_classes visualvm_mainAs you can see, the classes and instance give a lot of information about how much instances it created and it occupied for the size.

With all these method written out, I hope the next time this exception happen to you, get know what are the tools and steps needed to start investigating into the cause.

Good luck!