Shashidhar Mruthyunjaya

Shashidhar Mruthyunjaya

DISCLAIMER:

In this article we may see an abnormal behaviors of weblogic. Which may not be necessarily a BUG but it is always to be aware of such behavior while using Weblogic. The idea behind making this page is just to make awareness among the WebLogic Admins to be alert specially when the some of these behaviors are related to WebLogic Security/JMS.

Some of the behaviors of WebLogic which may be due to inappropriate Security/JMS implementation in the Security/JMS system of WebLogic, Even if in some cases it is work as designed, Still it suggests to keep an eye on it and try to make those features more enhanced. Some of them are now fixed by the Application Server Vendor but still some need to be fixed or enhanced. The intentions here are not to point to the weak points of any Application Server but solely to make people aware about such strange or uncommon behaviors.

==========================================================================

We specially thank to “Mr. Shashidhar Mruthyunjaya” (MiddlewareMagic Subscriber) for making us aware about an abnormal behavior of WebLogic JMS subsystem as part of his comment in http://middlewaremagic.com/weblogic/?page_id=6231#comment-5504

The below code is shared by Shashidhar, we have just  made few changes in sending the messages just to make it more understanding for others and we have tested this code as well as were able to replicated this issue in WLS 10.3.0.

Again thanking Mr. Shashidhar for taking time for us and sharing the complete details about the issue and the steps to reproduce it. Shashidhar also proactively reported this issue to Oracle WebLogic Support team and it resulted in

Bug 13436706 – JMS MESSAGE DELIVERED TO BUSY INSTANCE OF CONSUMER

The Abnormal behavior is happening on weblogic 10.3.2, but I think this bug is lurking in all weblogic servers starting from weblogic 6.x onwards I think. Send 17 messages quickly in succession, 1st one as Long running and other 16 short running messages. You will notice that all the 16 messages run, but the 17th message gets stuck behind the 1st message which is a long running one (and is still running). This is because we have 16 sessions by default and due to weblogic bug, it just cycles around these 16 sessions without checking for free sessions (which there are plenty as short running messages complete quickly and free their JMS sessions)

Basic buggy behavior with weblogic jms code is that it is not looking for free JMS session (or consumer), but going around in a cycle allocating new JMS message arrived to the next session – NOT the next free session as expected. So if the session is already running a long-running message(transaction), the new message will get stuck behind this and will wait until the long-running message finishes. This was causing us frustration as we have some transaction running for hours together!!

==========================
Instructions to simulate
==========================
JMS Configuration: Create JMS step-up by using the WLST script given in the article Setup JMS with Unit-Of-Order using WLST , Script , however you can put “unit.of.order.value = 0″ in the domain.properties file.

Step1) You need to create an EJB project and include ResourceAdapterMDB.java in the same, deploy this

Step2) Create a new Java Project and include this TestMsgSender.java file within that project src.

Step3) Once all setup is done and checking that the EJB is active and listening to the Queue, run the TestMsgSender which has a main method,
which will send 17 messages, 1st one Long running (10 min) and other 16 short running messages. You will notice that the 17th message gets stuck behind the 1st message which is a long running one.

NOTE: Change the queue name and connection factory name and other values to match yours in both these files if required.

ResourceAdapterMDB.java:

import javax.ejb.ActivationConfigProperty;
import javax.ejb.MessageDriven;
import javax.ejb.TransactionAttribute;
import javax.ejb.TransactionAttributeType;
import javax.jms.JMSException;
import javax.jms.Message;
import javax.jms.MessageListener;
import javax.jms.TextMessage;

import weblogic.javaee.TransactionTimeoutSeconds;

/**
* Message driven bean for the Resource Adapter This bean is configured to
* listen to the ResAdptQueue queue
*
* @author Shashidhar Mruthyunjaya
*
*/
@MessageDriven(activationConfig = {
	@ActivationConfigProperty(propertyName = "messageListenerInterface", propertyValue = "javax.jms.MessageListener"),
	@ActivationConfigProperty(propertyName = "destinationType", propertyValue = "javax.jms.Queue"),
	@ActivationConfigProperty(propertyName = "MaxDeliveryCnt", propertyValue = "1"),
	@ActivationConfigProperty(propertyName = "ConnectionFactoryName", propertyValue="My_CF")
}
, mappedName="My_Q")
/*
* @TransactionTimeoutSeconds – Resource Adapter Transaction is set to 24 hours
* 24 x 60 x60 = 86400 seconds.
*/
@TransactionTimeoutSeconds(86400)
public class ResourceAdapterMDB implements MessageListener {

@TransactionAttribute(TransactionAttributeType.REQUIRED)
public void onMessage(Message message) {

TextMessage textMessage = (TextMessage) message;

long millisToSleep = 1000 * 2 ;//2 sec

try {
if("msg= LONG_RUNNING".equals(textMessage.getText())) {
 millisToSleep = 1000 * 60 * 1 ; // Sleep for 1 min
}
} catch (JMSException e) {
e.printStackTrace();
}

try {
Thread.sleep(millisToSleep);
System.out.println("t==> MyMDB Received: "+ textMessage.getText() +", time= "+ millisToSleep/1000 +" sec.");
}
catch (InterruptedException e) {
e.printStackTrace();
}
catch (JMSException e) {
            e.printStackTrace();
        }
}
}

Step4) Following is the code for the JMS Message Sender “TestMsgSender.java” :

import java.util.Date;
import javax.jms.JMSException;
import javax.jms.Queue;
import javax.jms.QueueConnection;
import javax.jms.QueueConnectionFactory;
import javax.jms.QueueSender;
import javax.jms.QueueSession;
import javax.jms.Session;
import javax.jms.TextMessage;
import javax.naming.Context;
import javax.naming.NamingException;
import weblogic.jndi.Environment;

/**
* Provides the capability to send asynchronous messages to the defined target
* queues
*
* @author Shashidhar Mruthyunjaya
*
*/
public class TestMsgSender {
private static final String QUEUE = "My_Q";
private static final String CONN_FACTORY = "My_CF";
private static final String WEBLOGIC_USER = "weblogic";
private static final String WEBLOGIC_PASSWORD = "weblogic";
private static final String WEBLOGIC_URL = "t3://localhost:7001";

public void sendMsg(String textMessage) {
QueueConnection connection = null;
QueueSender sender = null;
QueueSession session = null;

try {
QueueConnectionFactory qcf = (QueueConnectionFactory) jndiLookup(CONN_FACTORY);
Queue targetQ = (Queue) jndiLookup(QUEUE);
connection = qcf.createQueueConnection();
session = connection.createQueueSession(false, Session.AUTO_ACKNOWLEDGE);
connection.start();
sender = session.createSender(targetQ);
TextMessage textMsg = session.createTextMessage();
textMsg.setText(textMessage);
sender.send(textMsg);
System.out.println(textMsg+": Sent at "+(new Date()));
} catch (Exception e) {
System.out.println("Exception occurred while sending message: " + e.getMessage());
throw new RuntimeException(e);
} finally {
if (connection != null) {
try {
connection.close();
} catch (JMSException e) {
System.out.println("Exception occurred while closing jms connection " + e.getMessage());
throw new RuntimeException(e);
} finally {
connection = null;
}
}
}
}

/**
* Helper method to perform JNDI lookup
*
* @param name
* @return
* @throws NamingException
*/
private Object jndiLookup(String name) throws NamingException {
Environment env = new Environment();
env.setProviderUrl(WEBLOGIC_URL);
env.setSecurityPrincipal(WEBLOGIC_USER);
env.setSecurityCredentials(WEBLOGIC_PASSWORD);
Context ctx = env.getInitialContext();

// Context ctx = new InitialContext();
Object ret = ctx.lookup(name);
ctx.close();

return ret;
}

public static void main(String[] args) throws InterruptedException {
TestMsgSender genericMsgSender = new TestMsgSender();

String textMessage;

// Send a long running message here
textMessage = "msg= LONG_RUNNING";
genericMsgSender.sendMsg(textMessage);

// Send 16 short running message here
for (int i = 1; i < 17; i++) {
genericMsgSender.sendMsg("msg= "+i);
Thread.sleep(1000 * 1); // wait for 1 sec
}
System.out.println("++++++++++++++++++ DONE Sending all messages ++++++++++++++++++");
}
}

Out put of the above code can be seen in the below snap-short which would make things much more easier to understand

Now from the above snap-shot you can see that the first messages “msg= LONG_RUNNING” was sent which takes 60 seconds to get consumed and just after that 16 more messages are been sent which should get consumed within 2 seconds, that makes total of 17 messages are been sent. You would notice that the messages from msg=1 to msg=15 has been consumed by the MDB within 2 seconds for each, but as the first message is still not been consumed due to which the last messages msg=16 (i.e. 17th number message) is been stuck behind and only gets consumed when the first message get consumed.

Workaround/Solution for this Issue:

================================================
Updated on : 16-Dec-2011 Based on Comment: http://middlewaremagic.com/weblogic/?p=7653#comment-5662

We need to define connection-factory-jndi-name” in “weblogic-ejb-jar.xml” along with setting MaximumMessages to 1 . This somehow makes this issue go away. After these changes the messages get allocated to a free consumer!!
.

.
.
Thanks