Java whoops causes performance problem.

I had not realized how easy it is to write a bad MQ Java program. When I worked for IBM, I had seen java applications doing 1 million MQCONNs a day – and people complained because it was slow! I accidentally managed to recreate this when looking into another problem.

I’ll show the bad programming example – which may be typical of many applications, and I’ll show what MQ requests the various JMS methods do, and how you can tell if your application is misbehaving.

My bad java program

If I had a java program which does the following

public class ColinDemo{
  public static void doit(){
    while ( i< 100)
    {
      colinMQ(...)
    }
  } 
  colinMQ() { 
     MQQueueManager queueManager = new MQQueueManager("qMgrName");
  ...  
     queueManager.close()
  }
}

Every time colinMQ is entered it creates a new connection to MQ.   When queueManager.close() is executed, there will be an MQDISC

The program as written will cause 100 MQCONNs and 100 MQDISC… whoops.

QueueManager needs to be defined as a class variable for example

public class ColinDemo{
MQQueueManager queueManager = Null;

Then colinMQ() needs a check like
if queueManager == Null then
queueManager = new MQQueueManager(“qMgrName”);
or

public class ColinDemo{
  public static void doit(){
    MQQueueManager queueManager;
    queueManager = initColinMQ(...)
    while ( i< 100)
    {
       colinMQ(queueManager...)
    }
    closeqm(queueManager);
  }
  
  MQQueueManager initColinMQ(...){
  return MQQueueManager("qMgrName")
  } 
  colinMQ(qm... ) { 
  ...
  }
  closeqm(qm)
  {
    qm.close();
  }
}

That is all pretty basic stuff, which is obvious once you see it. The more subtle bug is when an application calls ColinDemo.doit() multiple times. On exit from ColinDemo queueManager  will be closed and will cause it do do an MQDISC, the next call to ColinDemo.doit() will require another MQCONN.

You need to have ColinDemo return instance data. For example in your highest level program you say

ColinDemo cd = new ColinDemo(“qMgrName”)

then you can use cd.doit()… instead of ColinDemo.doit(), and of course you need a cd.close() to close the connection once it has been finished with.

When you are using JMS you need to have
connection = cf.createConnection();
session = connection.createSession(…);
consumer = session.createConsumer(destination);
defined as instance variables so they are set when the thread is started in the morning, and are not changed or de-allocated at the end of the day when the high level program ends.

For example in your top level JMS program

ColinDemo cd = new ColinDemo(“MYQMGR”);
for (i=0 ;i <100;i++) 
{
Message m = cd.getMessage() 
}

with

public class ColinDemo{
  private Connection connection = null;
  private Session session = null;
  private Destination destination = null;
  private MessageConsumer consumer = null;
  private Context context = null;
  private JmsConnectionFactory cf = null;
  private String contextFactory = null; 
  private Hashtable<String, String> environment;

  ColinDemo(String QMGRNAME)
  {
  // Instantiate the initial context
  contextFactory = "com.sun.jndi.fscontext.RefFSContextFactory";
  environment = new Hashtable<String, String>();

  environment.put(Context.INITIAL_CONTEXT_FACTORY,contextFactory);
  environment.put(Context.PROVIDER_URL, initialContextUrl);
  context = new InitialDirContext(environment);
  cf = (JmsConnectionFactory)
  context.lookup(connectionFactoryFromJndi);
  // Lookup the destination
  destination = (JmsDestination) 
  context.lookup(destinationFromJndi);

  connection = cf.createConnection();
  session = connection.createSession(false,Session.AUTO_ACKNOWLEDGE);
  consumer = session.createConsumer(destination);

  // Start the connection
  connection.start();
  }

  public Message getMessage()
  { 
    Message message = consumer.receive(timeout);
  } 
}

What goes on under the covers.

A basic JMS program looks like

String contextFactory = "com.sun.jndi.fscontext.RefFSContextFactory";
Hashtable<String, String> environment = new Hashtable<String, String>();
environment.put(Context.INITIAL_CONTEXT_FACTORY, contextFactory);
environment.put(Context.PROVIDER_URL, initialContextUrl);
context = new InitialDirContext(environment);
cf = (JmsConnectionFactory) context.lookup(connectionFactoryFromJndi);

// Lookup the destination
destination = (JmsDestination) context.lookup(destinationFromJndi);

connection = cf.createConnection();
session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
consumer = session.createConsumer(destination);

// Start the connection
connection.start();
// get a message 
Message message = consumer.receive(timeout);

Using the distributed MQ activity trace we can see the various MQ verbs which are issued.
The program started at 09:00:30 and ended at 09:00:45

connection = cf.createConnection();
has the following accounting trace records
Tid Date       Time     Operation  CompCode MQRC    HObj (ObjName) 
001 2019-07-26 09:00:30 MQXF_CONNX MQCC_OK  0000    -
001 2019-07-26 09:00:30 MQXF_OPEN  MQCC_OK  0000    2    ( ) 
001 2019-07-26 09:00:30 MQXF_INQ   MQCC_OK  0000    2    ( )
001 2019-07-26 09:00:30 MQXF_CLOSE MQCC_OK  0000    2    ( )
001 2019-07-26 09:00:45 MQXF_DISC  MQCC_OK  0000    -

We can see the transaction starting at 09:00:30 and ending at 09:00:45.

This is querying the queue manager for

MQIA_COMMAND_LEVEL (31)
MQIA_PLATFORM (32)
MQIA_CODED_CHAR_SET_ID (2)
MQCA_Q_MGR_NAME (2015)
MQCA_Q_MGR_IDENTIFIER (2032)
MQIA_ADVANCED_CAPABILITY (273)
session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);

produces the following trace records

Tid Date       Time     Operation  CompCode MQRC    HObj (ObjName) 
001 2019-07-26 09:00:30 MQXF_CONNX MQCC_OK  0000 -
001 2019-07-26 09:00:45 MQXF_DISC  MQCC_OK  0000 -

consumer = session.createConsumer(destination);

adds the following to the session data.

Tid Date       Time     Operation  CompCode MQRC HObj (ObjName) 
001 2019-07-26 09:00:30 MQXF_OPEN  MQCC_OK  0000 2    (Q1 ) 
001 2019-07-26 09:00:45 MQXF_CLOSE MQCC_OK  0000 2    (Q1 )

connection.start();

adds nothing

Message message = consumer.receive(timeout);

adds the following tace data to the session data.

Tid Date       Time     Operation CompCode MQRC HObj (ObjName)
001 2019-07-26 09:00:30 MQXF_GET  MQCC_OK  0000 2    (Q1 )

So by having
connection = cf.createConnection();
session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
consumer = session.createConsumer(destination);

Issued just once, you will save many MQCONN, MQDISC, MQOPEN, MQCLOSE and MQINQ calls.
If you see a pattern of

Tid Date       Time     Operation  CompCode MQRC HObj (ObjName) 
001 2019-07-26 09:00:30 MQXF_CONNX MQCC_OK  0000 -
001 2019-07-26 09:00:30 MQXF_OPEN  MQCC_OK  0000 2    ( ) 
001 2019-07-26 09:00:30 MQXF_INQ   MQCC_OK  0000 2    ( )
001 2019-07-26 09:00:30 MQXF_CLOSE MQCC_OK  0000 2    ( )
001 2019-07-26 09:00:45 MQXF_DISC  MQCC_OK  0000 -

You are doing too many connects – and need to look into it!

I am working on some other posts for making your Message Driven Bean applications running in a web server more efficient.

 

Thanks to Roger Lacroix for helping me get the java right.  His comments reminded me of the rules of computing

  • If you open it, close it
  • If you allocate it, free it
  • Clean up after you.
  • Be a good citizen

On the web there are some good example, and some bad examples.  One good example had

try{
    queueManager = new MQQueueManager("qMgrName");
    doWork(queueManager)    
    ...
   } catch (Exception je)
   {...
   }
finally{
    try{ queueManager.close()}
    catch (Exception je){...}
   }

When the execution left the try{} statement, the statement in the finally was always executed, so you could be sure that the queueManager object will always closed.

Other examples did not have code to close the connection, and the connection was left open until the program terminated which could be months later!  Be a good citizen, free it when you do not need it.

 

 

3 thoughts on “Java whoops causes performance problem.

  1. > When colinMQ ends, variable queueManager will eventually be garbage collected, and this will cause an MQDISC to happen.

    Can you please remove that line from your blog because ‘technically’, it is not true. When you say something like that then programmers will use your idea, become lazy and not disconnect from the queue manager and bad things will happen.

    The MQQueueManager class does NOT have a finalize() method which would ensure that IF an instance in garbage collected, close() will be called first.

    Through my testing, I believe it is the JMQI that has hooks into the JVM shutdown, and it is the JMQI that is actually issuing the MQDISC and not the Garbage Collector.

    Add the following to your code at the very bottom of your main() method:

    System.gc(); // call the garbage collector
    try
    {
    Thread.sleep(30000); // sleep for 30 seconds
    }
    catch(Exception e)
    {}

    Now look in your activity trace. You will see that all 100 connections were still active until the sleep completed and the JVM terminated.

    Roger’s Programming 101: If your code opens it, then make sure your code closes it. And for MQ, if your code connects to it, then make sure your code disconnects from it.

    Also, I’m not a big fan of global variables. Your code should be passing the MQQueueManager and MQQueue objects to the child methods (sub-routines) rather than using global variables. i.e. change your initColinMQ() method to return the MQQueueManager object.

    Regards,
    Roger Lacroix
    Capitalware Inc.

    Like

  2. Hello Colin,

    > When colinMQ ends, variable queueManager will eventually be garbage collected, and this will cause an MQDISC to happen.

    Can you please remove that line from your blog because ‘technically’, it is not true. When you say something like that then programmers will use your idea, become lazy and not disconnect from the queue manager and bad things will happen.

    The MQQueueManager class does NOT have a finalize() method which would ensure that an instance in garbage collected, close() will be called first.

    Through my testing:
    – If the MQ client program connects in bindings mode then a disconnect will never be issued!!
    – If the MQ client program connects in client mode then a disconnect will be issued by the MCA listener process (amqrmppa) when the JVM terminates.

    Add the following to your code at the very bottom of your main() method:

    System.gc(); // call the garbage collector
    try
    {
    Thread.sleep(30000); // sleep for 30 seconds
    }
    catch(Exception e)
    {}

    Now look in your activity trace. You will see that all 100 connections were still active until the sleep completed and the JVM terminated.

    Roger’s Programming 101: If your code opens it, then make sure your code closes it. And for MQ, if your code connects to it, then make sure your code disconnects from it.

    Also, I’m not a big fan of global variables. Your code should be passing the MQQueueManager and MQQueue objects to the child methods (sub-routines) rather than using global variables. i.e. change your initColinMQ() method to return the MQQueueManager object.

    Like

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s