Saturday, April 27, 2013

Career, Work, and Health (5)

People who eat according to the rules of a traditional food culture are generally much healthier than people eating a contemporary Western diet.  Therefore, the author of four New York Times bestsellers Michael Pollan recommends us to:

Eat more like the French or the Italians or the Japanese or the Indians or the Greeks.


India has one of the most varied cuisines in the world.  Indians combine vegetables, legumes and grains with herbs, spices and dairy products to form the largest range of vegetable dishes in the world.  Read this article
for a glimpse of its varieties.


Read More

Sunday, April 21, 2013

Book Review: Getting Started with Oracle Event Processing 11g

Event processing is a method of tracking and analyzing (processing) streams of information (data) about things that happen (events),[1] and deriving a conclusion from them. Complex event processing, or CEP, is event processing that combines data from multiple sources[2] to infer events or patterns that suggest more complicated circumstances. The goal of complex event processing is to identify meaningful events (such as opportunities or threats)[3] and respond to them as quickly as possible.

Using airport as an example, events happening in the airport that may require tracking include missing luggages, passenger movements, etc.  An architecture combining Event Driven Architecture (EDA) and Service Oriented Architecture (SOA) can be deployed for such purpose.  A system utilizing Oracle products is illustrated in the following diagram:




In this book, it has covered the following topics and more:
  • Product history of Oracle CEP
  • Event Driven Architecture
  • Requirements of Complex Event Processing
  • Creating Event Driven Architecture (EDA) applications using Oracle CEP

History of Oracle Event Processing Solution 11gR1


A product initially named Elvis (or WebLogic Event Server) was developed by the Time and Event Driven (TED) team in early 2007 at BEA Systems Inc. After several "man years" of effort, this technology was first released on July 16, 2007 from BEA Systems.

In parallel, a Complex Event Processing "engine" was researched and developed separately within Oracle.   Starting from 2008, WebLogic Event Server and this CEP "engine" were integrated.  Finally, on July 1, 2009, these combined technologies were released as the Oracle Event Processing Solution 11gR1.  This product is claimed to be one of the most complete and powerful in-memory extensible event analytics technologies available in the market.

Limitations of Traditional Systems for Event Processing


After the emerging of social media, data are continuously created in vast quantities.  This proliferation of data (or Big Data grow) has brought challenges to traditional systems for tracking and analyzing streams of information (data) about things that happen (events).

First thought on supporting events is using traditional systems.  However, they have their limitations:
  • Traditional computing systems are mostly based on database
    • Information must be inserted and statically placed. Only after that, can users analyze and respond.  
    • Frequent disk reads and writes will quickly become system's performance bottlenecks.  
  • Traditional JEE Application Servers adopt the send/reply implementation paradigms
    • This has introduced delays that won't meet the real-time requirements needed for event processing.
So, a new Event Driven Architecture (EDA) was introduced, which processes event streams in memory using a defined window of time or other filtering options.

Event-Driven (Architecture) Based Systems


Event-driven architecture (EDA)[5] is a software architecture pattern promoting the production, detection, consumption of, and reaction to events.  Before systems can process any event, they need to normalize the incoming data stream by converting them into events and event types.  These representations are then processed downstream or upstream in the Event Processing Network (EPN).

Before proceeding further, let's introduce you the following definitions:
  • Event
    • In the context of this book, an event is an object that has a change in its state immediately, or over a period of time.
    • As these events continuously flow they need to be identified, have a response very quickly and are often "transported" only in memory, so using a database is not a recommended design option.
  • Event stream
    • Events arrive for processing in an event stream or streams and they are time ordered.
  • Event type
    • Event classification which defines the properties (i.e., name-value pairs) associated with the event.
  • Event Processing Network (EPN)
    • The EPN (aka Directed Flow Graph) is designed as a loosely-coupled collection of event nodes, each performing a unique action on the events as they pass through the network.
    • Event nodes could be one of the following types:
      • Event adapter
      • Event channel
      • Event cache and event POJO Bean node
      • Event processor
        • Filtering, correlation, aggregation, or pattern matching can be applied
To facilitate event processing, an in-memory extensible event technology built on EDA has been provided by Oracle, which is introduced in this book:



The Book[6]


This book is aimed for both developers and architects that need to learn about event processing, stream processing, and the event-driven architecture.  It uses tutorials and examples to help you create event-driven applications using Oracle CEP.  Finally, it covers some of the above components seen in the diagram in details.


References

  1. Luckham, David C. (2012). Event Processing for Business: Organizing the Real-Time Enterprise. Hoboken, New Jersey: John Wiley & Sons, Inc.,. p. 3.
  2. Schmerken, Ivy (May 15, 2008), Deciphering the Myths Around Complex Event Processing, Wall Street & Technology
  3. Bates, John, John Bates of Progress explains how complex event processing works and how it can simplify the use of algorithms for finding and capturing trading opportunities, Fix Global Trading, retrieved May 14, 2012
  4. Complex event processing (Wikipedia)
  5. Event-driven architecture (Wikipedia)
  6. Getting Started with Oracle Event Processing 11g (Reviewed book)
  7. All Book Reviews on XML and More

Saturday, April 20, 2013

Analyze Hanging Programs Using Java Thread Traces

In this article, we will discuss the following topics:
  • How to analyze hanging, deadlocked or frozen programs?
  • How to generate stack traces?
  • What is deadlock?

What to Do When Your Applications Hang?


If you think your program is hanging, generate a stack trace.  A stack trace of all threads can be useful when trying to diagnose a number of issues such as deadlocks or hangs.

When looking at stack traces, check the following:
  • If a thread waits on
    • A monitor lock
    • A condition variable
  • If system threads show up as the current threads
    • If the program is deadlocked then some of the system threads will probably show up as the current threads, because there is nothing else for the JVM to do

How to Generate Stack Traces?


With thread stack trace, you can analyze the source of deadlocks.  There are multiple approaches:
  • Using jstack command, it can 
    • attach to the specified process (or core file) and prints the stack traces of all threads that are attached to the virtual machine (this includes Java threads and VM internal threads).
      • For each Java frame, the full class name, method name, 'bci' (byte code index) and line number, if available, are printed.
    • Obtain stack traces from a core dump:
      • jstack $JAVA_HOME/bin/java core
    • Be used to print a mixed stack.  That is, it can print native stack frames in addition to the java stack
      • Native frames are the C/C++ frames associated with VM code, and JNI/native code.
      • To print a mixed stack the -m option is used.
  • When a deadlock occurs, doing a Ctrl + Break on Windows forces a Java level thread stack trace to print to standard output. On Solaris and Linux, sending a SIGQUIT signal to the Java process id does the same.
  • Beginning with Java 6, the bundled JConsole tool added the capability to attach to a hung Java process and analyze the root cause of the deadlock.

What Is Deadlock?


If you're working with a moderately complex multithreaded program, then sooner or later, you'll hit the problem of deadlock[2,3].  Deadlock is the phenomenon when, typically, two threads each hold an exclusive lock that the other thread needs in order to continue.  In principle, there could actually be more threads and locks involved. Most of the time, a deadlock is caused by acquiring locks in the wrong order.

Deadlock can occur with any locking primitive. It notably occurs with the synchronized keyword, but it's liable to occur with locks, Semaphores, blocking queues etc.

A Deadlock Example


We used jstack to generate Java thread traces as follows:
$ jstack 3554

Our VM is HotSpot Client from JDK 7:

Found one Java-level deadlock:
=============================
"RunLevelControllerThread-1377458723460":
  waiting to lock monitor 0x871756a8 (object 0x93480480, a java.util.logging.LogManager$LoggerContext),
  which is held by "RunLevelControllerThread-1388458723457"
"RunLevelControllerThread-1388458723457":
  waiting to lock monitor 0x87173448 (object 0x93472290, a java.util.logging.LogManager),
  which is held by "RunLevelControllerThread-1377458723460"

Java stack information for the threads listed above:
===================================================
"RunLevelControllerThread-1377458723460":
    at java.util.logging.LogManager$LoggerContext.findLogger(LogManager.java:489)
    - waiting to lock <0x93480480> (a java.util.logging.LogManager$LoggerContext)
    at java.util.logging.LogManager.getLogger(LogManager.java:910)
    at com.sun.enterprise.server.logging.LogManagerService.postConstruct(LogManagerService.java:412)
    - locked < x93472290> (a java.util.logging.LogManager)
    - locked <0x93465158> (a java.lang.Class for java.util.logging.Logger)


"RunLevelControllerThread-1388458723457":
    at java.util.logging.LogManager.drainLoggerRefQueueBounded(LogManager.java:811)
    - waiting to lock <0x93472290> (a java.util.logging.LogManager)
    at java.util.logging.LogManager$LoggerContext.addLocalLogger(LogManager.java:511)
    - locked < x93480480> (a java.util.logging.LogManager$LoggerContext)

In the above example, you can see that two threads:

  • RunLevelControllerThread-1377458723460 
  • RunLevelControllerThread-1388458723457 

were waiting for locks that were held by each other.  This have created a deadlock.

References

  1. jstack - Stack Trace
  2. Deadlock
  3. How to Avoid Deadlocks (Xml and More)

Sunday, April 7, 2013

Understanding CMS GC Logs

In this article, we will examine the following topics:
  • What's Mark and Sweep algorithm?
  • What's CMS Collector in HotSpot?
  • What's the format of CMS logs?

Mark and Sweep (MS) Algorithm


The mark-and-sweep algorithm consists of two phases[3]: In the first phase, it finds and marks all accessible objects. The first phase is called the mark phase. In the second phase, the garbage collection algorithm scans through the heap and reclaims all the unmarked objects. The second phase is called the sweep phase. The algorithm can be expressed as follows:

for each root variable r
    mark (r);
sweep ();

The computational complexity of mark and sweep is both a function of the amount of live data on the heap (for mark) and the actual heap size (for sweep).
  • Mark
    • Add each object in the root set to a queue
      • Typically, the root set contains all objects that are available without having to trace any references[5], which includes all Java objects on local frames in whatever methods the program is executing when it is halted for GC. This includes:
        • Everything we can obtain from the user stack and registers in the thread contexts of the halted program. 
        • Global data, such as static fields.
    • For each object X in the queue Mark X reachable
      • mark bit is typically associated with each reachable object. 
    • Add all objects referenced from X to the queue
    • Marking is the most critical of the stages, as it usually takes up around 90 percent of the total garbage collection time. 
      • Fortunately, marking is very parallelizable and large parts of a mark phase can also be run concurrently with executing Java code. 
  • Sweep
    • For each object X on the heap, 
      • If the X not marked, garbage collect it
    • Sweeping (or compaction which is not included in MS algorithm), however, tend to be more troublesome to be made to run concurrently with the executing Java program.

Concurrent Mark Sweep (CMS) Collector


CMS (Concurrent Mark Sweep) is one of garbage collectors implemented in HotSpot JVM.  It is enabled using:
  • -XX:+UseConcMarkSweepGC -XX:+UseParNewGC

Note that there are two different implementations of parallel collectors for the young generation:
  • UseParNewGC
  • UseParallelGC 

UseParNewGC should be used with CMS, and UseParallelGC should be used with the throughput collector.  Also that there is another collector named iCMS,[4] which is a variant of CMS.  You should not use iCMS anymore because it is (or will be) deprecated.

CMS is designed to be mostly concurrent, requiring just two quick stop-the-world pauses per old space garbage collection cycle.   These two phases are the initial mark phase (single-threaded) and the remark phase (multithreaded).  It attempts to minimize the pauses due to garbage collection by doing most of the garbage collection work concurrently with the application threads.

CMS does not perform compaction in normal CMS cycle.  However, an old generation overflow will trigger a stop-the-world compacting garbage collection.
  • Par new generation (or Young Gen)
    • Young generation space is further split into 
      • Eden 
      • Survivor spaces
    • On CMS, it would have defaulted to a maximum size 665 MB if you didn't explicitly set it.
    • Survivors from the young generation are evacuated to 
      • Other survivor space, or
      • Old generation space
  • Concurrent mark-sweep generation (or Tenured Gen)
    • Does in-place de-allocation (which can lead to heap fragmentation)
    • Is managed by free lists, which need synchronization
    • Concurrent marking phase
      • Two stop-the-world pauses
        • Initial mark
          • Marks reachable (live) objects
        • Remark
          • Unmarked objects are deducted to be unreachable (dead)
    • Concurrent sweeping phase
      • Sweeps over the heap
      • In-place de-allocated unmarked (dead) objects
      • End of concurrent sweeping--all unmarked objects have been de-allocated

Enabling Logging


We have used the following HotSpot VM options to generate the log file:
  • -Xloggc:/gc_0.log 
  • -verbose:gc 
  • -XX:+PrintGCDetails 
  • -XX:+PrintGCTimeStamps 
  • -XX:+PrintReferenceGC 

CMS GC Logs


Let's take a look at some of the CMS logs generated with 1.7.0_10:

2715.210: [GC 2715.210: [ParNew2715.282: [SoftReference, 0 refs, 0.0000120 secs]2715.282: [WeakReference, 2433 refs, 0.0004150 secs]2715.283: [FinalReference, 1947 refs, 0.0074410 secs]2715.290: [PhantomReference, 0 refs, 0.0000080 secs]2715.290: [JNI Weak Reference, 0.0000040 secs]: 310460K->27980K(318912K), 0.0804180 secs] 3828421K->3561073K(4158912K), 0.0805140 secs] [Times: user=0.36 sys=0.00, real=0.08 secs]
Young generation (ParNew) collection. Young generation capacity is 318912K and after the collection its occupancy drops down from 310460K to 27980K. This collection took 0.08 secs.

2715.294: [GC [1 CMS-initial-mark: 3533092K(3840000K)] 3564157K(4158912K), 0.0418950 secs] [Times: user=0.04 sys=0.00, real=0.04 secs]

Beginning of tenured generation collection with CMS collector. This is initial Marking phase of CMS where all the objects directly reachable from roots are marked and this is done with all the mutator threads stopped.

Capacity of tenured generation space is 3840000K and CMS was triggered at the occupancy of 3533092K

2715.337: [CMS-concurrent-mark-start]
Start of concurrent marking phase.

In Concurrent Marking phase, threads stopped in the first phase are started again and all the objects transitively reachable from the objects marked in first phase are marked here.

2717.428: [CMS-concurrent-mark: 2.091/2.091 secs] [Times: user=6.34 sys=0.08, real=2.09 secs]
Concurrent marking took total 2.091 econds cpu time and 2.091 seconds wall time that includes the yield to other threads also.

2717.428: [CMS-concurrent-preclean-start]
Start of precleaning.

Precleaning is also a concurrent phase. Here in this phase we look at the objects in CMS heap which got updated by promotions from young generation or new allocations or got updated by mutators while we were doing the concurrent marking in the previous concurrent marking phase. By rescanning those objects concurrently, the precleaning phase helps reduce the work in the next stop-the-world “remark” phase.

2717.428: [Preclean SoftReferences, 0.0000020 secs]2717.428: [Preclean WeakReferences, 0.0066370 secs]2717.434: [Preclean FinalReferences, 0.0011100 secs]2717.436: [Preclean PhantomReferences, 0.0003480 secs]2717.475: [CMS-concurrent-preclean: 0.045/0.048 secs] [Times: user=0.19 sys=0.00, real=0.04 secs]

Concurrent precleaning took 0.045 secs total cpu time and 0.048 wall time.


2717.475: [CMS-concurrent-abortable-preclean-start]

2717.876: [GC 2717.876: [ParNew2717.958: [SoftReference, 0 refs, 0.0000140 secs]2717.958: [WeakReference, 2683 refs, 0.0004340 secs]2717.959: [FinalReference, 1972 refs, 0.0069420 secs]2717.966: [PhantomReference, 0 refs, 0.0000080 secs]2717.966: [JNI Weak Reference, 0.0000050 secs]: 311500K->28150K(318912K), 0.0900310 secs] 3844593K->3577211K(4158912K), 0.0901370 secs] [Times: user=0.41 sys=0.01, real=0.09 secs]

2719.157: [CMS-concurrent-abortable-preclean: 1.582/1.681 secs] [Times: user=4.16 sys=0.07, real=1.68 secs]

2719.157: [GC[YG occupancy: 171027 K (318912 K)]2719.157: [Rescan (parallel) , 0.0680250 secs]2719.225: [weak refs processing2719.226: [SoftReference, 0 refs, 0.0000070 secs]2719.226: [WeakReference, 9940 refs, 0.0010950 secs]2719.227: [FinalReference, 10877 refs, 0.0226430 secs]2719.249: [PhantomReference, 0 refs, 0.0000050 secs]2719.249: [JNI Weak Reference, 0.0000110 secs], 0.0238550 secs]2719.249: [scrub string table, 0.0057930 secs] [1 CMS-remark: 3549060K(3840000K)] 3720087K(4158912K), 0.0989920 secs] [Times: user=0.40 sys=0.01, real=0.10 secs]
In the above log, after a preclean, 'abortable preclean' starts. After the young generation collection, the young gen occupancy drops down from 328912K to 28150K When young gen occupancy reaches 171027 K which is 52% of the total capacity, precleaning is aborted and 'remark' phase is started.
Note that in young generation occupancy also gets printed in the final remark phase.
Stop-the-world phase. This phase rescans any residual updated objects in CMS heap, retraces from the roots and also processes Reference objects. Here the rescanning work took 0.0680250 secs and weak reference objects processing took 0.0010950 secs. This phase took total 0.0238550 secs to complete.

2719.257: [CMS-concurrent-sweep-start]
Start of sweeping of dead/non-marked objects. Sweeping is concurrent phase performed with all other threads running.

2722.945: [CMS-concurrent-sweep: 3.606/3.688 secs] [Times: user=8.79 sys=0.12, real=3.69 secs]
Sweeping took 3.69 secs.

2722.945: [CMS-concurrent-reset-start]
Start of reset.

2722.973: [CMS-concurrent-reset: 0.028/0.028 secs] [Times: user=0.05 sys=0.00, real=0.03 secs]
In this phase, the CMS data structures are reinitialized so that a new cycle may begin at a later time. In this case, it took 0.03 secs.

This was how a normal CMS cycle runs.  Note that, in our experiment, we didn't see the "concurrent mode failure".  So, we didn't discuss it here.  For more information of it, read [1].

References

  1. Understanding CMS GC Logs
  2. Java GC, HotSpot's CMS and heap fragmentation
  3. Mark-and-Sweep Garbage Collection
  4. Really? iCMS? Really?
  5. Oracle JRockit--The Definitive Guide
  6. JRockit: Parallel vs Concurrent Collectors (Xml and More)
  7. The Unspoken - CMS and PrintGCDetails (Jon Masamitsu's Weblog)
  8. The Unspoken - Phases of CMS (Jon Masamitsu's Weblog)

Tuesday, April 2, 2013

java.lang.UnsupportedClassVersionError

When running an application named StoreFrontService, we have run into this exception:
  • java.lang.UnsupportedClassVersionError
In this article, we will examine what it is and how to resolve it.

Class Loading Phases


There are three phases in class loading[1]:
  • Loading
    • See below
  • Linking
    • Bytecode verification[6]
      • Checks the classfile semantics, checks the constant pool symbols, and does type checking
    • Preparation
      • Creates and initializes static fields to standard defaults and allocates method tables
  • Initializing
    •  Runs the class static initializers, and initializers for static fields
For a given Java class or Java interface, the load class phase takes its name, finds the binary in Java classfile format, defines the Java class, and creates a java.lang.Class object to represent that given Java class or Java interface.
The load class phase can throw a NoClassDefFound error if a binary representation of a Java class or Java interface cannot be found. In addition, the load class phase does format checking on the syntax of the classfile, which can throw a ClassFormatError or UnsupportedClassVersionError.

The Exception


In our expriement, we have seen the following exception being thrown:

####<Mar 21, 2013 8:16:43 AM PDT> <Error> <Class Loaders> <sfperf-x6250-10> <MS_1> <[ACTIVE] ExecuteThread: '8' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1363879003661> <BEA-2162500> <Class, oracle.fodemo.storefront.store.service.server.serviceinterface.StoreFrontServiceImpl, was compiled with an incompatible version of Java. Make sure that all the classes needed by the application have been compiled with a compatible java version. java.lang.UnsupportedClassVersionError: oracle/fodemo/storefront/store/service/server/serviceinterface/StoreFrontServiceImpl : unsupported classversion 51.0
java.lang.UnsupportedClassVersionError: oracle/fodemo/storefront/store/service/server/serviceinterface/StoreFrontServiceImpl : unsupported classversion 51.0
        at java.lang.ClassLoader.defineClass1(Native Method)
        at java.lang.ClassLoader.defineClassCond(ClassLoader.java:631)
        at java.lang.ClassLoader.defineClass(ClassLoader.java:615)
        at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:14

      
This turns out to be that our application StoreFrontService was compiled in JDK 7 (class version: 51)[7] and we were running it on JRockit bundled with Java 1.6 VM (class version: 50). The compiler is not backwards compatible[2] because bytecode generated with JDK 7 won't run in Java 1.6 VM (unless compiled with the -target 1.6 flag[3]). But the JVM is backwards compatible, as it can run older bytecodes.

References

  1. Java Performance by Charlie Hunt, Binu John, David Dagastine 
  2. Is JDK “upward” or “backward” compatible?
  3. Cross-Compilation Options
  4. Java SE 6 vs. JRE 1.6 vs. JDK 1.6 - What do these mean?
  5. JRockit Version Information
  6. Java Virtual Machine Specification
  7. Unsupported major.minor version 51.0