RealTimeMessaging: ActiveMQ threads rise for every push operation

[claudiobosticco]

SmartClient Version: v9.0p_2014-01-05/PowerEdition Deployment (built 2014-01-05)
and
SmartClient Version: v9.1p_2014-03-09/PowerEdition Deployment (built 2014-03-09)

I'm using the realtime messaging with activemq as described here:
https://isomorphic.atlassian.net/wiki/display/Main/Real-Time+Messaging+with+Tomcat+and+ActiveMQ

this configuration is working, with the embedded broker option (activeMQ 5.8 with Tomcat 7 on ubuntu/JRockit).
But, using visualvm, I see peaks in the number of activemq threads, peaks which, strangely enough, gets higher every time a single push operation is invoked.

An example of this trend in the attachment.

Could it be a messaging bug? Or an activeMQ bug?

[Isomorphic]

Could you clarify what you mean by "a push operation". Messaging.send() initiated from the client? Server-initiated push using your own code? Something else?

Are you able to run this on Windows machine to test for platform-specific issues in ActiveMQ / Tomcat?

[claudiobosticco]

sorry, actually I mean this server code:

ISCMessageDispatcher dispatcher = ISCMessageDispatcher.instance();
        dispatcher.send(new ISCMessage("jms/updateOrdineChannel", dsResponse.getDataList()));

actually I'm planning to try activemq in a standalone install, instead of embedded in tomcat. Yes, windows could be an option.

[claudiobosticco]

now I've installed a 'standalone' activeMQ 5.9 broker on a windows machine.

on tomcat (UBUNTU/JRockit) I've got only the activeMQ client libraries.

But on this ubuntu server I still see the spikes in the number of threads (ActiveMQ Transport and Session Task threads): 4 more threads for every spike as you could see in the attached image.

But the chart is different: the daemon threads doesn't have spikes, and the 'base' number of live threads increase also.

[claudiobosticco]

also, I didn't understand the difference between the method
ISCMessageDispatcher.instance()
and
ISCMessageDispatcher.instance(RequestContext context)

which must I use ?

Edit: I just found this thread
http://forums.smartclient.com/showthread.php?t=19873
where you told the original poster to use the first method.

[claudiobosticco]

Hello, now I'm testing with this configuration:
- ActiveMQ broker installed on Windows 2003 Server 32bit w/JRockit
- the application is deployed on another Window 2003 server 32bit w/JRockit, tomcat 7. In the tomcat 7 libs I've got the activeMQ client jars.

For now, I don't have visualvm installed on this last server.
However, testing seems to confirm the same behaviour.
I'm doing the same operation which invokes a DMI (from a single client, when previous operation ends, I invoke another).
Each DMI call ends with a dispatcher.send().
What I see is that every operation is slower than the previous and the server CPU shows high utilization.

the tomcat context.xml contains:

    <Resource auth="Container"
              name="jms/ConnectionFactory"
              type="org.apache.activemq.ActiveMQConnectionFactory"
              description="JMS Connection Factory"
              factory="org.apache.activemq.jndi.JNDIReferenceFactory"
              brokerURL="tcp://svjuve19.juventus.priv:61616"
              useEmbeddedBroker="false"
              brokerName="svjuve19"/>
    <ResourceLink global="jms/ConnectionFactory" name="jms/ConnectionFactory"/>

the context.xml of the application contains:

    <Resource auth="Container"
              name="jms/updateOrdineChannel"
              type="org.apache.activemq.command.ActiveMQTopic"
              description="JMS Topic"
              factory="org.apache.activemq.jndi.JNDIReferenceFactory"
              physicalName="updateOrdineChannel"/>
    <ResourceLink global="jms/updateOrdineChannel" name="jms/updateOrdineChannel"/>

the server.properties contains this messaging settings:

messaging.keepaliveInterval: 3000
messaging.keepaliveReestablishDelay: 1000
messaging.connectTimeout: 4000
messaging.connectionTTL: 120000
messaging.flushBufferSize: 8096

messaging.dispatcherImplementer: com.isomorphic.messaging.JMSMessageDispatcher
messaging.jms.context: _container_
messaging.jms.jndiPrefix:
messaging.jms.topicConnectionFactory: jms/ConnectionFactory

jndi.messaging.java.naming.factory.initial: org.apache.activemq.jndi.ActiveMQInitialContextFactory
jndi.messaging.java.naming.provider.url: tcp://svjuve19.juventus.priv:61616

[Isomorphic]

We'll be taking a look at this. However, have you verified that threads will just keep going up indefinitely, until the system crashes? Because what you might be seeing is just ordinary initial population of a thread pool.

[claudiobosticco]

We'll be taking a look at this. However, have you verified that threads will just keep going up indefinitely, until the system crashes?

yes, actually this is the original motivation for this analisys.

Because what you might be seeing is just ordinary initial population of a thread pool.

but even before the server hangs, it slows down too much. The CPU usage goes entirely to garbage collecting. And even after the number of threads drops from 1000 to 500, another operation raises it to 1000 + 4 threads (and the operation takes forever, say 30 sec when normal execution would take less than 500msec.
Then a restart is required.

[claudiobosticco]

Because what you might be seeing is just ordinary initial population of a thread pool.

actually I'm wondering if with my configuration I'm using pooled connections (to the activeMQ broker).

I'm trying to use as ConnectionFactory a org.apache.activemq.jms.pool.PooledConnectionFactory, but I got a null pointer exception:

2014-03-27 17:46:50,178 ERROR [cbosticco 482] MessagingServlet MessagingServlet top-level exception 
java.lang.NullPointerException
	at com.isomorphic.messaging.JMSMessageDispatcher.reconnect(JMSMessageDispatcher.java:79)
	at com.isomorphic.messaging.JMSMessageDispatcher.ensureConnected(JMSMessageDispatcher.java:98)
	at com.isomorphic.messaging.JMSMessageDispatcher.subscribe(JMSMessageDispatcher.java:150)
	at com.isomorphic.messaging.ISCMessageDispatcher.subscribe(ISCMessageDispatcher.java:219)
	at com.isomorphic.messaging.MessagingConnectionHandler.registerSubscriber(MessagingConnectionHandler.java:341)
	at com.isomorphic.messaging.MessagingConnectionHandler.process(MessagingConnectionHandler.java:107)
	at com.isomorphic.messaging.MessagingServlet.doPost(MessagingServlet.java:107)
	at com.isomorphic.messaging.MessagingServlet.doGet(MessagingServlet.java:119)

[Isomorphic]

About the NPE, this suggests that your setting for the name of the TopicConnectionFactory (messaging.jms.topicConnectionFactory) is wrong.

[claudiobosticco]

but I changed only the type (org.apache.activemq.jms.pool.PooledConnectionFactory) of the connection factory, not the name...maybe the type is incorrect?

[Isomorphic]

No, the NPE indicates that what we got from JNDI was null, not just the wrong type.

Even though you just changed the type in ActiveMQ config, it appears ActiveMQ places this kind of ConnectionFactory under a different JNDI name.

[Isomorphic]

Could you please test this sample to verify whether you see the issue with this sample on your dev environment?. We did some tests, but we didn't see any issues related to increasing threads. We tested the sample on Tomcat 7.0.16 with a standalone ActiveMQ installation versions 5.5.1 and 5.9.0.

[claudiobosticco]

I'll try. For now I can say that I have the same behavior on Mac OSX with Oracle JDK 7 (and Tomcat 7).

Also, I don't know if it's important, but I switched to calling the send method from the client API and this doesn't make a difference.

[claudiobosticco]

Could you please test this sample to verify whether you see the issue with this sample on your dev environment?. We did some tests, but we didn't see any issues related to increasing threads. We tested the sample on Tomcat 7.0.16 with a standalone ActiveMQ installation versions 5.5.1 and 5.9.0.

is it the same for you if I test your simple_chat example from the SDK?
I've got this ready, just tested, and it does shows the increasing threads pattern.
With the help of a for loop, I managed to crash tomcat:

Exception in thread "ActiveMQ InactivityMonitor WriteCheckTimer" java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method)
	at java.lang.Thread.start(Thread.java:713)
	at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:949)
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1371)
	at org.apache.activemq.transport.AbstractInactivityMonitor.writeCheck(AbstractInactivityMonitor.java:165)
	at org.apache.activemq.transport.AbstractInactivityMonitor$2.run(AbstractInactivityMonitor.java:124)
	at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33)
	at java.util.TimerThread.mainLoop(Timer.java:555)
	at java.util.TimerThread.run(Timer.java:505)
2014-03-28 15:32:37.164 java[39898:d07] java.lang.OutOfMemoryError: unable to create new native thread
	at java.lang.Thread.start0(Native Method)
	at java.lang.Thread.start(Thread.java:713)
	at sun.awt.AWTAutoShutdown.activateBlockerThread(AWTAutoShutdown.java:334)
	at sun.awt.AWTAutoShutdown.setToolkitBusy(AWTAutoShutdown.java:254)
	at sun.awt.AWTAutoShutdown.notifyToolkitThreadBusy(AWTAutoShutdown.java:140)
2014-03-28 15:32:37.279 java[39898:d07] (
	0   CoreFoundation                      0x00007fff9624f25c __exceptionPreprocess + 172
	1   libobjc.A.dylib                     0x00007fff8d47de75 objc_exception_throw + 43
	2   CoreFoundation                      0x00007fff9624ee09 -[NSException raise] + 9
	3   JavaNativeFoundation                0x00000001ae25dc3f JNFCallStaticVoidMethod + 213
	4   liblwawt.dylib                      0x00000001af96bcaf setBusy + 121
	5   CoreFoundation                      0x00007fff9617fee7 __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__ + 23
	6   CoreFoundation                      0x00007fff9617fe57 __CFRunLoopDoObservers + 391
	7   CoreFoundation                      0x00007fff96171848 __CFRunLoopRun + 1368
	8   CoreFoundation                      0x00007fff961710b5 CFRunLoopRunSpecific + 309
	9   HIToolbox                           0x00007fff8ca2ba0d RunCurrentEventLoopInMode + 226
	10  HIToolbox                           0x00007fff8ca2b7b7 ReceiveNextEventCommon + 479
	11  HIToolbox                           0x00007fff8ca2b5bc _BlockUntilNextEventMatchingListInModeWithFilter + 65
	12  AppKit                              0x00007fff988eb3de _DPSNextEvent + 1434
	13  AppKit                              0x00007fff988eaa2b -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] + 122
	14  libosxapp.dylib                     0x00000001af0a76f4 -[NSApplicationAWT nextEventMatchingMask:untilDate:inMode:dequeue:] + 124
	15  AppKit                              0x00007fff988deb2c -[NSApplication run] + 553
	16  libosxapp.dylib                     0x00000001af0a7557 +[NSApplicationAWT runAWTLoopWithApp:] + 156
	17  liblwawt.dylib                      0x00000001af96bba9 -[AWTStarter starter:] + 873
	18  Foundation                          0x00007fff93d4013e __NSThreadPerformPerform + 229
	19  CoreFoundation                      0x00007fff96180731 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
	20  CoreFoundation                      0x00007fff96171ea2 __CFRunLoopDoSources0 + 242
	21  CoreFoundation                      0x00007fff9617162f __CFRunLoopRun + 831
	22  CoreFoundation                      0x00007fff961710b5 CFRunLoopRunSpecific + 309
	23  java                                0x0000000100bad3b0 CreateExecutionEnvironment + 871
	24  java                                0x0000000100ba7b5c JLI_Launch + 1952
	25  java                                0x0000000100bad70d main + 101
	26  java                                0x0000000100ba73b4 start + 52
)

tested on OSX 10.9.2, with Tomcat 7.0.32 and Oracle jdk1.7.0_45.jdk, activemq-all-5.8.0

My configuration:

in tomcat_home/conf/server.xml I've got:

	<Resource auth="Container"
              name="jms/ConnectionFactory"
              type="org.apache.activemq.ActiveMQConnectionFactory"
              description="JMS Connection Factory"
              factory="org.apache.activemq.jndi.JNDIReferenceFactory"
              brokerURL="tcp://svjuve19.juventus.priv:61616"
              useEmbeddedBroker="false"
              brokerName="svjuve19"/>

    <Resource auth="Container"
              name="jms/chatChannel"
              type="org.apache.activemq.command.ActiveMQTopic"
              description="JMS Topic"
              factory="org.apache.activemq.jndi.JNDIReferenceFactory"
              physicalName="chatChannel"/>

in tomcat_home/conf/context.xml:

	  <ResourceLink global="jms/ConnectionFactory" name="jms/ConnectionFactory" />
          <ResourceLink global="jms/chatChannel" name="jms/chatChannel" />

in tomcat_home/webapps/myApp/WEB-INF/classes/jndi.properties:

java.naming.factory.initial = org.apache.activemq.jndi.ActiveMQInitialContextFactory
java.naming.provider.url = tcp://svjuve19:61616
connectionFactoryNames = jms/ConnectionFactory

simpleChat.js:

<!--------------------------------------------------------------------
	SmartClient Real-Time Messaging option
	Simple Chat example
	
	Copyright 2001 and beyond Isomorphic Software, Inc. (www.isomorphic.com)
---------------------------------------------------------------------->


<%@ taglib uri="/WEB-INF/iscTaglib.xml" prefix="isomorphic" %>
<HTML><HEAD><TITLE>
	SmartClient Messaging option - Simple Chat example
</TITLE>
<isomorphic:loadISC includeModules="RealtimeMessaging"/>
<SCRIPT>
// Evaluation SDK doesn't support messaging on Safari
if (isc.Browser.isSafari && isc.Browser.safariVersion < 412) {
    alert("Messaging subsystem not currently supported on Safari\n" +
          "If you are interested in licensing this functionality for Safari, please contact" +
          " Isomorphic Software Support at http://forums.smartclient.com");
    window.location = "../../";
}
</SCRIPT>
</HEAD><BODY bgcolor=tan MARGINHEIGHT=0 MARGINWIDTH=0 LEFTMARGIN=0 TOPMARGIN=0>
<TABLE WIDTH=100% CELLSPACING=0 CELLPADDING=5 BORDER=0><TR><TD CLASS=pageHeader BGCOLOR=WHITE>
	SmartClient Messaging option - Simple Chat example
</TD><TD CLASS=pageHeader ALIGN=RIGHT BGCOLOR=WHITE>
	<A HREF=../../>Return to SDK Index</A>
</TD></TR></TABLE><TABLE WIDTH=100% CELLSPACING=0 CELLPADDING=0 BORDER=0><TR>
<TD BGCOLOR=336666><IMG SRC=images/blank.gif WIDTH=1 HEIGHT=4></TD></TR></TABLE>
<SCRIPT>



<isomorphic:XML>

<Canvas
	ID='chatLog'
	left='50' top='50'
	width='500' height='200'
	overflow='auto'
	backgroundColor='white'
	border='2px solid gray'
	contents='Chat Session&lt;br&gt;Open this page in multiple client browsers for multi-user chat.'
/>

<DynamicForm
	ID='chatForm'
	left='50' top='275'
>
	<fields>
		<field
			name='user'
			title='User name'
            required='true'
		/>
		<field
			name='msg'
			title='Message'
			editorType='textArea'
			width='400' height='50'
		/>
		<field
			editorType='button'
			colSpan='*'
			align='center'
			title='Send'
			click='sendChatMessage()'
		/>
	</fields>
</DynamicForm>

</isomorphic:XML>


function sendChatMessage() {
    // Ensure the required 'user' field is not empty
    if (!chatForm.validate()) return;
    
    var userName = chatForm.getValue('user'),
        messageText = chatForm.getValue('msg');

    // If no message was entered, avoid sending an empty message to the server.
    if (!messageText) return;
        
	// assemble the message
	var message =	'<b>' +
					userName +
					':</b> ' +
					messageText +
					'<br><br>';
					
	// and send it to the chatChannel
	Messaging.send('jms/chatChannel', message, "callback(rpcResponse)");
}


function callback(rpcResponse) {
    if (rpcResponse.status != isc.RPCResponse.STATUS_SUCCESS) {
        isc.say("Unable to send message");
    }
}

// receive messages from the chatChannel and add them to the chatLog
Messaging.subscribe("jms/chatChannel", "chatLog.setContents(data + chatLog.contents)");


</SCRIPT></BODY></HTML>