A recent customer on RedHat Enterprise Linux 6 (RHEL6) was running WAS 8, 64-bit. We noticed that the virtual size of the process was over 14GB (ps -p $PID -o vsz,rss). The maximum heap (-Xmx) was 5.5GB, so we were concerned there was a native memory leak. In IBM Java 626 (which ships with WAS 8), javacores have a NATIVEMEMINFO structure which tracks most JVM native allocations, including -Xmx itself, classes, classloaders, JIT, shared classes, and even some SDK native allocations like DirectByteBuffers. These are the most common things to leak... [More]
In what will probably become a 10 part series before we figure things out, I wanted to share more information I've learned about Linux core dumps. Part 1 successfully found how much was malloc'ed in a core, and part 2 failed to find the total virtual memory usage in a core. A colleague recently pointed me to more information in the most obvious of places: 'man core' !
Since kernel 2.6.23, the Linux-specific /proc/PID/coredump_filter file can be used to control which memory segments are written to the core dump file in the... [More]
The Memory Analyzer Tool (MAT) is the recommended tool for analyzing heapdumps and system dumps, whether to find the cause of an OutOfMemoryError (OOM) or memory leak, to size a JVM, or other types of debugging . The tool is available for free with the IBM Support Assistant Workbench (ISA) or it can be downloaded from eclipse.org and extended with updates to support IBM dump types.
One common memory issue is a Java memory leak. This is not like a traditional memory leak in C/C++ where memory is mis-managed, but rather that the application... [More]
Update: For WAS 8, see https://www.ibm.com/developerworks/mydeveloperworks/blogs/kevgrig/entry/using_visual_configuration_explorer_with_was_8
Visual Configuration Explorer (VCE) is a free tool available in the IBM Support Assistant . The major features I like about it are: 1) it can visualize parts of a WAS configuration such as servers, core groups, etc., 2) it can run the configuration against a database of common issues, and 3) it can compare parts of a configuration to each other (e.g. compare two nodes or servers), or compare two or... [More]
This is part four in the series on understanding total virtual memory usage from a core dump on Linux ( part 1 , part 2 , part 3 ).
Previously, I recommended using a script to add a timestamp to a core file name when using gcore so that MAT could know when the dump was taken. Now, I'll make the case for a stronger recommendation to completely avoid using gcore and use IBM Java's built-in capabilities of taking a core dump instead.
Gcore is simply a shell script available on some flavors of Linux:
$ whereis gcore
It is generally a malpractice for an application to call System.gc() or Runtime.gc() (hereafter referring to both as System.gc(), since the former simply calls the latter). By default, these calls instruct the JVM to perform a full garbage collection, including tenured spaces and a full compaction. These calls may be unnecessary and may increase the proportion of time spent in garbage collection than otherwise would have occurred if the garbage collector was left alone.
The generic JVM arguments -Xdisableexplicitgc (IBM) and... [More]
Wireshark supports automation through a scripting language called Lua . I've created a simple Lua script which extracts all HTTP requests and responses to a file. For example:
["Dec 8, 2011 10:33:30.267266000 PST" src:127.0.0.1:37204 dst:127.0.0.1:9094 stream:0] HTTP Request: POST localhost:9094/ibm/console/j_security_check
["Dec 8, 2011 10:33:30.292939000 PST" src:127.0.0.1:9094 dst:127.0.0.1:37204 stream:0] HTTP Response: 302 Found
Here's how to run the script:
tshark -r $FILE.pcap -X lua_script:printhttp.lua... [More]
A previous post covered an older way of gathering configuration for Visual Configuration Explorer (VCE) using the VCE Headless Runtime, exported from ISA. The newer and preferred approach is to use the IBM Support Assistant Lite data collector, and this will work with WAS 8 (I've also tested this on 7). It does not work on V8.5.
Download the ISA Lite script: https://www14.software.ibm.com/webapp/iwm/web/preLogin.do?source=swg-isalite&S_PKG=wasunixwin
Extract the ISA Lite script into the <WAS> root directory.
This error can occur on Windows, particularly around socket operations. The error is translated from the Winsock error code WSAENOBUFS , 10055. The most common cause of this error is that Windows is configured for the default maximum of 5,000 in-use ports. This can be monitored by watching netstat or perfmon and can be changed with the MaxUserPort registry parameter .
A more advanced cause for this error is non-paged pool exhaustion. The paged and nonpaged pools are areas of memory for certain Windows kernel-mode allocations such as the... [More]
WebSphere Application Server comes with a built-in HTTP(S) server. This post covers different methods of printing the response times of HTTP(S) requests. If all you need are averages, then the built-in Performance Monitoring Infrastructure (PMI) provides average statistics for HTTP(S) response times. However, if you need information on particular requests, then averages may not help . The most robust solution is to use a monitoring product such as ITCAM . This article will cover the basic capabilities that are built-in to WAS. Method #0: Web... [More]
The IBM Java HealthCenter is a low overhead agent shipped with the JVM that can provide deep insight into JVM activity for IBM Java 5 and above: http://www.ibm.com/developerworks/java/jdk/tools/healthcenter/ . HealthCenter is similar to VisualVM . HealthCenter can provide information on classloading, JVM arguments, garbage collection, file I/O, locking, native memory, threads, and profiling. The last item, profiling, is my favorite feature of HealthCenter -- it is a very low overhead, sampling profiler that can pinpoint high CPU issues or... [More]
The following is my attempt at understanding how much memory has been malloc'ed at the time of a Linux coredump using gdb. I'm not aware of any built-in way to get this from gdb, surprisingly (or even better, the total virtual memory used by the process). This investigation is assuming a recent version of Linux and the default glibc malloc implementation, the latest source code of which is located here: http://sourceware.org/git/?p=glibc.git;a=blob_plain;f=malloc/malloc.c;hb=HEAD . You'll need the debuginfo packages of glibc and glibc-common... [More]
When using IBM Java in 64-bit mode and with a maximum heap size less than 25GB, then Compressed References technology (-Xcompressedrefs) is enabled by default (defaults may be different on older versions of Java on some operating systems): http://pic.dhe.ibm.com/infocenter/java7sdk/v7r0/topic/com.ibm.java.zos.71.doc/diag/appendixes/cmdline/Xcompressedrefs.html
This option will "decrease the size of Java objects and make more effective use of the available space. The result is less frequent garbage collection and improved memory... [More]
Wireshark (formerly called Ethereal) is a great, free, open source tool to analyze network packet captures. To gather packet captures on various operating systems, see http://www-01.ibm.com/support/docview.wss?uid=swg21175744 . Wireshark supports decrypting some types of SSL traffic: http://wiki.wireshark.org/SSL . The following developerWorks article covers the basics of using this feature: http://www.ibm.com/developerworks/web/tutorials/wa-tomcat/section4.html . In this post, I'll cover some WAS specific tips.
By default , WAS uses... [More]
One simple and very useful indicator of process health and load is its TCP activity. The following script takes a set of ports and summarizes how many TCP sockets are established, opening, and closing for each port. It has been tested on Linux and AIX. Example output:
$ portstats.sh 80 443
PORT ESTABLISHED OPENING CLOSING
80 3 0 0
443 10 0 2
Total 13 0 2
echo "usage:... [More]
I'm not sure how this applies to modern computer chips and operating systems, but here is interesting research from Liedtke in 1995 and 1997 showing the overhead of system calls:
For measuring the system-call overhead, getpid, the shortest Linux system call, was examined. To measure its cost under ideal circumstances, it was repeatedly invoked in a tight loop. Table 2 shows the consumed cycles and the time per invocation derived from the cycle numbers. The numbers were obtained using the cycle counter register of the Pentium processor. Linux... [More]
I was recently at a customer who believed that they had a Java memory leak. They compared heapdumps and couldn't find anything. They had experienced production OutOfMemoryErrors (OOMs) before (for a different reason), and they were so worried about what they perceived, that they increased the maximum heap size to 4GB so that the JVM could handle a day's worth of work, and then they put in a process to restart the JVMs every night.
At a first glance of verbose garbage collection, I agreed with them (loaded in the wonderful Garbage... [More]
At a recent customer, we improved throughput by 50% simply by restarting with the AIX environment variable MALLOCOPTIONS=multiheap. This only applies to situations where there is heavy, concurrent malloc usage, and in many cases of WAS/Java, this is not the case.
The multiheap option does have costs, particularly increased virtual and physical memory usage. The primary reason is that each heap's free tree is independent, so fragmentation is more likely. There is also some additional metadata overhead.
malloc is often a... [More]
Surprisingly, even the latest version of HP-UX does not provide a simple tool (such as "ps") to print the full command line of a running program (no equivalent of Solaris /usr/ucb/ps). The -x parameter of ps only prints the first 1024 characters , which is often insufficient for Java programs: Only a subset of the command line is saved by the kernel; as much of the command line will be displayed as is available... The value of DEFAULT_CMD_LINE_WIDTH should be between 64 and 1020 (... [More]
In a previous post , I covered some of the ways to log per-HTTP response time information in WAS. Good news -- a new and more standard approach has been added in WAS 184.108.40.206 through PM46717 . WAS has had NCSA logging -- which is most commonly know through the LogFormat that httpd/IHS uses by default in its access/error logs -- but the format in WAS was not customizable, and did not have response times. WAS 220.127.116.11 introduces a customizable format which includes %D: "The elapsed time of the request. Millisecond accuracy, microsecond... [More]
The IBM HTTP Server (IHS) ships with a cool little command line utility called Apache Bench (ab) because IHS is based on httpd . At its simplest, you pass the number of requests you want to send (-n), at what concurrency (-c) and the URL to benchmark. ab will return various statistics on the responses (mean, median, max, standard deviation, etc.). This is really useful when you want to "spot check" backend server performance or compare two different environments, because you do not need to install complex load testing software, and... [More]
Update : ActiveCount has been made a part of the PMI Basic collection (enabled by default) in WAS 18.104.22.168 and 22.214.171.124 .
WebSphere Application Server comes with the "Basic" level enabled in the Performance Monitoring Infrastructure (PMI) on every server by default . This usually has an overhead of about 2-3% . The Basic level comes with one statistic for all thread pools: PoolSize (see the "Level" column in the link). This is defined as "the average number of threads in pool." This is a bit confusing: it is... [More]
It may be useful to understand what PID is sending a kill signal to a process on AIX. You can use this kernel trace:
Login as root
# rm -rf /tmp/aixtrace; mkdir /tmp/aixtrace/; cd /tmp/aixtrace/
# trace -C all -a -T 10M -L 20M -n -j 134,139,465,14e,46c -o ./trc
... Reproduce the problem ... e.g. kill -3 7667754
# cp /etc/trcfmt .
# trcnm -a > trace.nm
# LDR_CNTRL=MAXDATA=0x80000000 gensyms > trace.syms
# LDR_CNTRL=MAXDATA=0x80000000 gennames -f > gennames.out
# pstat -i > trace.inode
# ls -al /dev >... [More]
The default Linux native memory allocator on most distributions is Glibc malloc (which is based on ptmalloc and dlmalloc). Glibc malloc either allocates like a classic heap allocator (from sbrk or mmap'ed arenas) or directly using mmap, depending on a sliding threshold ( M_MMAP_THRESHOLD ). In the former case, the basic idea of a heap allocator is to request a large block of memory from the operating system and dole out chunks of it to the program. When the program frees these chunks, the memory is not returned to the operating system, but... [More]
I'm proud to announce a new tool I've been cooking recently: IBM Runtime Diagnostic Code Injection for the Java™ Platform (RDCI). The tool is an extensible command line JAR that uses the Late Attach API to inject Java code into a running JVM, allowing both exploratory and invasive surgery on a Java process. It uses a custom classloader to minimize the "scar" left on the process. Example commands include: Run a full garbage collection, execute a static method, perform a javacore, heapdump or system dump on IBM JVMs, and... [More]
In a previous post , I discussed the importance of symbols for native libraries. Not only are they needed, but you may be actively deceived by the guesses of stack walkers if you don't have them. On Linux, although it is recommended to simply compile executables and libraries with symbols and ship them unstripped, even the operating system vendors do not do this (the simple reason is the size of the symbol data). For example, Fedora and RedHat do not ship binaries unstripped, but instead they separate the symbols into matching debuginfo... [More]
In my last post , I wrote about understanding how much has been malloc'ed in a coredump through gdb, which was successful. In this post, I'll describe my investigations into total virtual memory usage in a core, which was unsuccessful.
First, I used the same program as before which calls malloc with various sizes and I changed it to sleep at the end. While it was sleeping, I took OS statistics and a core dump.
The first thing I ran was 'ps -o pid,vsz,rss -p 14062':
PID VSZ RSS
14062 44648 42508
VSZ is the total virtual... [More]
This is part five in the series on understanding total virtual memory usage from a core dump on Linux ( part 1 , part 2 , part 3 , part 4 ).
In part 4, I alluded to the fact that the gcore command in gdb actually walks the memory regions itself when writing the core dump. This got me thinking: what if this is different than how the kernel writes the core? To get the kernel to produce a core, the only way seems to be to destructively kill the process (e.g. kill -6 or kill -11). By default, IBM Java will catch these signals before the process... [More]
I've wanted to write this for a long time and I finally had a situation that called for it. The following tshark Lua script searches network packet captures for anomalous TCP delays in handshakes (long response time to a SYN, response not a SYN/ACK, missing response to a SYN, duplicate SYN) and delays between packets after a handshake. The latter is disabled by default because connections are often re-used, so there may be legitimate delays between the end of one part of a conversation and the beginning of another, so that requires more... [More]
The latest version of the Interactive Diagnostic Data Explorer (IDDE) tool, available in the IBM Support Assistant , supports a subset of the IBM Extensions for Memory Analyzer plugins (if installed) by typing Ctrl+Space a second time after typing the first !, and it also supports the old DumpAnalyzer plugins by typing Ctrl+Space a second time. For example, running the old DumpAnalyzer basic analyzer:
If you are using a HotSpot-based JVM, and you are producing HPROF heapdumps that have more than 4GB of object data, and you are using the Memory Analyzer Tool to analyze those heapdumps, then make sure you check the Error Log for any warnings when first loading the dump. We recently discovered that some HotSpot JVMs write an incorrect length field in the HPROF file. MAT will end up reading only part of the heapdump, but other than the warning, there's no sign that you're only looking at a subset of the dump.
You can find more... [More]
IBM Research recently made its WAIT tool (Whole-system Analysis of Idle Time) available to the public: https://wait.researchlabs.ibm.com/
The WAIT tool takes javacores and operating system statistics snapshots for a period of time as input, and produces a rich webpage as output that visualizes this data. Since WAIT only uses javacores and operating system scripts, you don't need to install anything or even restart the Java processes to use WAIT. For administrators familiar with the performance, hang, and high CPU MustGathers , the... [More]
Before WAS 8.5, the "thread ID" printed in WAS logs (the hexadecimal number after the timestamp) comes from the java/util/logging/LogRecord.getThreadID method. This number was not in javacores, so there was no easy way to correlate javacores with log and trace messages. Moreover, this thread ID was different from java/lang/Thread.getID which might be printed in other components, and that thread ID also wasn't in javacores. (Note: see Mapping Underlying Java Thread Identifiers to those in Logging and Trace for a method to map these values using... [More]
Our SWAT team's common customer malpractices document has been refreshed and published as an IBM Redpaper: http://www.redbooks.ibm.com/redpieces/abstracts/redp5033.html?Open .
After most of our engagements, we consider what customer practices caused or contributed to the critical situation. The biggest one? No test environment is equal to the production environment: 35.1%.
Please read this paper and pass it on to incentivize management to invest in the right areas to help avoid critical situations.
We are working to add PDB symbols for WAS native libraries and we ran into a subtle issue. As Microsoft states :
PDB files are generated if a project is built by using the /Zi or /ZI (Produce PDB Information) compiler switch... Generating PDB files for release executables does not affect any optimizations, or significantly alter the size of the generated files... For this reason, you should always produce PDB files...
We added /Zi to the compiler (cl.exe) and it produced a PDB file; however, when we grabbed a dump of the process and... [More]
Excessive native memory usage by java.nio.DirectByteBuffers is a classic problem with any generational garbage collector such as gencon (which is the default starting in IBM Java 6.26/WAS 8), particularly on 64-bit. DirectByteBuffers (DBBs) are Java objects that allocate and free native memory. DBBs use a PhantomReference which is essentially a more flexible finalizer and they allow the native memory of the DBB to be freed once there are no longer any live Java references. Finalizers and their ilk are generally not recommended because... [More]
Someone asked me how to find who is sending a SIGABRT to a process and below is one technique. If there are better techniques, please leave a comment!
Attach to the process using gdb and immediately "continue." When the SIGABRT hits the process, gdb will break execution and leave you at a prompt. Then, simply handle the particular signal you want and print $_siginfo._sifields._kill.si_pid and detach:
$ java HelloWorld
Hello World. Waiting indefinitely...
$ ps -elf | grep HelloWorld | grep -v grep
0 S kevin 23947... [More]
Additional trace points for tracking DirectByteBuffer allocations and frees, and the stack traces of who is calling for those have been added in IBM Java 6 SR11 (WAS 126.96.36.199), IBM Java 626 SR3 (WAS 188.8.131.52/184.108.40.206/220.127.116.11), and IBM Java 7 SR3 (WAS 18.104.22.168/22.214.171.124).
Note: The overhead of -Xtrace with tpnid should not be significant (unless the rate of DBB allocates and frees is very large); but, as always, you should test the impact in a test environment first.
1. Add the following generic JVM argument... [More]
This is a simple wsadmin script that can start or stop binary PMI/TPV logs (of infinite duration and up to 200MB rolled over 20 files) across a cell. The two parameters required are -action (start, stop or list) and -userprefs with your user name (I couldn't find a way to query the user name that was passed in). With no other arguments, this will start PMI logging (at whatever level configured for, which by default is PMI Basic) on every application server in the cell. If you pass -node, it will only do it on the application servers on that... [More]
The IBM Memory Analyzer Tool (MAT) is my preferred tool for analyzing Java heapdumps and core dumps. Sometimes you'll see a dump where there are no obvious causes of high memory usage in the dominator tree nor the top consumers report - the two places I recommend going to first when investigating memory. This post will show how to do advanced analysis using the histogram, retained sets, and incoming references by class.
Here is a dump retaining 4.2GB of Java heap without any large dominators:
This post covers how to graph arbitrary data from the command line. My requirements are: 1) command line input (e.g. piping straight from file), 2) generate PNG graph, 3) generate ASCII art graph, and 4) UNIX friendly. There are a few popular libraries to do this including gnuplot ( http://www.gnuplot.info/ ) and rrdtool ( http://oss.oetiker.ch/rrdtool/ ); however, I've chosen the R project ( http://www.r-project.org/ ) because I think it's more general purpose.
As an example, I will show how to graph IBM HTTP Server mpmstats... [More]
A customer recently gave me a very large heapdump which I tried to open in the Memory Analyzer Tool. It chugged for a while and then my computer overheated and suddenly shut itself off. I suspect this is a bug in the Linux kernel which improperly ramps the i7 processor and the fan can't keep up (or maybe my fan just needs a cleaning). The workaround for this on Linux was to reduce the maximum speed of my processors before opening the dump:
for i in `ls /sys/devices/system/cpu/cpu*/cpufreq/scaling_max_freq`; do sudo bash -c "echo 1500000... [More]
Whether you're using the older listener ports or the newer activation specifications, tuning the relevant thread pools is a key aspect of MDB performance. Thread pools are configured at a server level, while the number and concurrency of the MDBs is configured independently. Therefore, if your maximum thread pool size is too small, messages may queue unnecessarily. Below are equations for the most common setups which define how to setup the relevant thread pool maximums to avoid queuing. The x=1..n items are all the items of that type... [More]
IBM Support Assistant Version version 5 (Team Server) has officially launched . Unlike IBM Support Assistant version 4 which was a heavy, desktop application, ISA5 is fully web-based and either runs from a local application server or you can install its EARs into an existing application server.
In addition to a platform for installing and launching tools ( full tools list ), ISA5 comes with a very strong log analysis engine . For example, you can upload a set of WAS logs, click Scan this Case , and it will search for warnings, errors, and... [More]
Update (May 30, 2013) : Note that it is preferable to use IBM Java's capabilities to produce system dumps instead of gcore. See why .
The Linux gcore command (also part of gdb) is a very useful command to create a coredump of a running process without killing the process. This is particularly useful starting with WAS 126.96.36.199 and 188.8.131.52 as a core dump can be read directly by the Memory Analyzer Tool, without running jextract, so that core dumps become as easy to use as PHD heapdumps, while providing much more information .
A common aspect to a problem is that an application worked and then the environment (WAS, etc.) was upgraded and the application stopped working. Many customers then say, "therefore, the product is the root cause." It is easy to show that this is a fallacy (neither necessary nor sufficient) with a real world example: A recent customer upgraded from WAS 6.1 to WAS 7 without changing the application and it started to throw various exceptions. It turned out that the performance improvements in WAS 7 and Java 6 exposed existing... [More]
I'll be presenting a WebSphere Technical Exchange on November 12th @ 11AM Eastern . It is free for all to join and includes a remote presentation and a question & answer session. The topic will be Linux Native Memory Problem Determination Techniques and Tools for WebSphere Application Server. Slides are available here: http://www-01.ibm.com/support/docview.wss?uid=swg27039764&aid=1
Update: I discussed this issue with Nigel Griffiths (the 'n' in nmon) and he has posted information on mpstat -d which is much easier to use and gives basically the same (and in some senses more) information about process and memory affinity: https://www.ibm.com/developerworks/mydeveloperworks/blogs/aixpert/entry/mpstat_d_and_the_undocumented_stats133?lang=en . You should also read his multi-part series on local, near & far memory: https://www.ibm.com/developerworks/mydeveloperworks/blogs/aixpert/tags/entitlement?lang=en .
When using... [More]
In computing history, there was a famous crusade by Larry Tesler -- a titan of the industry; he worked at Xerox PARC (Smalltalk), Apple, Amazon, and Yahoo -- which he called "no modes." He said, for example, that you shouldn't have to enter a "mode" just to type text. You should be able to click and type. It was a revolutionary idea back then. There are still some popular modal programs today such as vi and Emacs, and the mode combinations make their users look like wizards, but in general, modes are dead.
However, I have... [More]