JMS queue listener blocking and not doing anything

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

I've configured Hibernate Search to cluster using the JMS master/slave config. The slaves work great... I think. The appropriate number of messages are sent to my ActiveMQ queue when an entity is saved or updated. I can't read what the messages are because ActiveMQ complains that the content is serialized and it doesn't have the DeleteLuceneWork class in its classpath. Seems appropriate, though I only have DeleteLuceneWork serialized objects in the JMS message bodies. Is that right?

Anyway, I've created a listener exactly as described in section 10.3.1 in the Hibernate Search in Action book. Though I'm using Spring, so it's an MDPojo instead of an MDBean. The problem is the onMessage method just gets stuck and never returns. So my listener reads the first message from the queue and hangs. Any idea why? Also seems odd that only 1 MDP thread is reading from the queue, I would expect 10 onMessage method invocations:

Code:

public class HibernateSearchListener extends AbstractJMSHibernateSearchController implements MessageListener {
    private final Log log = LogFactory.getLog(getClass());

    @Autowired
    private SessionFactory sessionFactory;

    @Override
    public void onMessage(Message message) {
        log.debug("Received message: " + message);
        super.onMessage(message);
        log.debug("Done processing message: " + message);
    }

    @Override
    protected Session getSession() {
        log.debug("Retrieving session for processing message");
        return sessionFactory.getCurrentSession();
    }

    @Override
    protected void cleanSessionIfNeeded(Session session) {
        log.debug("Finished with session");
    }
}

The output I get is only:

Code:

DEBUG [QueueListener-1] HibernateSearchListener - Received message: ActiveMQObjectMessage {commandId = 5, responseRequired = true, messageId = ID:xxxxx-53941-1271212758168-0:129:1:1:1, originalDestination = null, originalTransactionId = null, producerId = ID:xxxxx-53941-1271212758168-0:129:1:1, destination = queue://HibernateSearchController, transactionId = null, expiration = 0, timestamp = 1271212877786, arrival = 0, brokerInTime = 1271212877786, brokerOutTime = 1271581732969, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@727a9fa7, marshalledProperties = null, dataStructure = null, redeliveryCounter = 3, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false}
DEBUG [QueueListener-1] HibernateSearchListener - Retrieving session for processing message
DEBUG [QueueListener-1] HibernateSearchListener - Finished with session

That's it, no "Done processing message"s ever...

The relevant portion of my Spring application-context.xml is:

Code:

    <amq:connectionFactory id="amqConnectionFactory" brokerURL="tcp://${jms.url}:61616?trace=true" userName="${jms.username}" password="${jms.password}"/>
    <bean id="connectionFactory" class="org.springframework.jms.connection.CachingConnectionFactory">
        <constructor-arg ref="amqConnectionFactory"/>
        <property name="exceptionListener" ref="jmsExceptionListener"/>
        <property name="sessionCacheSize" value="100"/>
    </bean>

    <bean id="jmsExceptionListener" class="search.JmsExceptionListener"/>

    <bean id="jmsTemplate" class="org.springframework.jms.core.JmsTemplate">
       <constructor-arg ref="connectionFactory"/>
    </bean>

    <bean id="hibernateSearchListener" class="search.HibernateSearchListener" autowire="byType"/>
    <jms:listener-container concurrency="10" transaction-manager="transactionManager">
        <jms:listener id="QueueListener" destination="HibernateSearchController" ref="hibernateSearchListener"/>
    </jms:listener-container>

    <bean id="sessionFactory" class="org.springframework.orm.hibernate3.LocalSessionFactoryBean">
        <property name="dataSource" ref="dataSource"/>
        <property name="eventListeners">
            <map>
                <entry key="post-update"><bean class="org.hibernate.search.event.FullTextIndexEventListener"/></entry>
                <entry key="post-insert"><bean class="org.hibernate.search.event.FullTextIndexEventListener"/></entry>
                <entry key="post-delete"><bean class="org.hibernate.search.event.FullTextIndexEventListener"/></entry>
                <entry key="post-collection-recreate"><bean class="org.hibernate.search.event.FullTextIndexEventListener"/></entry>
                <entry key="post-collection-remove"><bean class="org.hibernate.search.event.FullTextIndexEventListener"/></entry>
                <entry key="post-collection-update"><bean class="org.hibernate.search.event.FullTextIndexEventListener"/></entry>
            </map>
        </property>
        <property name="mappingResources">
            <list>
                <value>repository/my_entitities.hbm.xml</value>
            </list>
        </property>
        <property name="hibernateProperties">
            <value>
                hibernate.dialect=org.hibernate.dialect.MySQLInnoDBDialect
                hibernate.search.default.indexBase=indexes
                hibernate.search.worker.execution=async
                hibernate.search.worker.jms.connection_factory=java:comp/env/jms/ConnectionFactory
                hibernate.search.worker.jms.queue=java:comp/env/queue/hibernatesearch
                hibernate.search.worker.backend=jms
                hibernate.search.default.directory_provider=org.hibernate.search.store.FSMasterDirectoryProvider
                hibernate.search.default.sourceBase=indexes_source
            </value>
        </property>
    </bean>

When I shut down Tomcat, I have to forcefully kill it with this as its last output line in catalina.out:

Code:

WARN  [main] DefaultLifecycleProcessor - Failed to shut down 1 bean with phase value 2147483647 within timeout of 30000: [QueueListener]

Even if I do an indexAll type operation with over 100,000 test entities, nothing happens on the master server. Nothing at all happens, not even the indexing messages going out to ActiveMQ like they do on the slave servers. In any case, the indexes and indexes_source directories are never updated.

Please help :)

sanne.grinovero · **Posted:** Sun Apr 18, 2010 12:30 pm

Quote:

The problem is the onMessage method just gets stuck and never returns.

that's the usual behaviour of a message handler when it's waiting for messages. It's likely not receiving anything.

Quote:

I can't read what the messages are because ActiveMQ complains that the content is serialized and it doesn't have the DeleteLuceneWork class in its classpath.

Which party is that? of course they need the class if they have to deserialize the objects for Search, you're likely just missing a library somewhere.

It appears messages are sent but never received.. maybe you could try your JMS settings sending and receiving with something trivial, taking the Search backends out of the picture? unfortunately I never have setup ActiveMQ with Spring.

sviluppatorefico · **Joined:** Sun Apr 18, 2010 12:39 pm **Posts:** 1

Are you using it inside JBoss or standalone?

There is a few different spring configuration if you use JBoss
You have to use spring inside a .spring package.
If you use it externally it doesn't work there is a spring deployer for it but it should launch an exception if it is not configured properly

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

I'm using hibernate search within spring 3.0.2, tomcat 6.0.26 and activemq 5.3

sanne.grinovero · **Posted:** Sun Apr 18, 2010 6:41 pm

Quote:

All references I've found about JmsTemplate are highly discouraging to use it as it reopens a new session for each use, this is very bad for performance.
JmsTemplate appears to be meant for a quick prototype AFAIK, not really for production use. Please see the HornetQ forums for comments from more qualified people, as I'm myself not an expert on the subject (there are many references to the JmsTemplate there, as there are more people complaining about it).

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

I'm not even exactly sure what the jmsTemplate is for, but before I worry about performance I'd like to get this working. Any ideas why hibernate search blocks?

sanne.grinovero · **Posted:** Sun Apr 18, 2010 11:58 pm

mueller wrote:

I'm not even exactly sure what the jmsTemplate is for, but before I worry about performance I'd like to get this working. Any ideas why hibernate search blocks?

I'm no jms expert, but you appear to have a jms configuration problem.
totally agree that performance problems can wait, but as I wrote above the most likely cause is that hibernate search isn't receiving messages. I have no clue about this configuration, I just meant to suggest that you might want to change approach instead of fixing it as it might not be worth fixing this one as it uses the jmsTemplate.

amin-mc · **Joined:** Wed Oct 03, 2007 2:31 pm **Posts:** 205

I've done the JMS backend using Spring and haven't encountered this. Saying that I used 2.5.6 not with 3.0. I'll have a look and see if i can reproduce.

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

Thanks amin-mc. I'd LOVE to see your jms/hibernate search portions of your application-context.xml (or equivalent) file. My JMS configuration works in that the onMessage function of the AbstractJMSHibernateSearchController class is called, it just never returns...

Did you use Tomcat and ActiveMQ as well?

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

the jmsTemplate you were concerned with was not used at all in the message driven pojo of the master indexing server. I just removed that and still have the same problems...

s.grinovero wrote:

Quote:

The problem is the onMessage method just gets stuck and never returns.

that's the usual behaviour of a message handler when it's waiting for messages. It's likely not receiving anything.

Is that really the usual behavior? I'm not that familiar with JMS, but how would the AbstractJMSHibernateSearchController get the new messages if onMessage was only called once? Seems like the onMessage(message) method would be called each time a new message is ready to be processed. The onMessage method definitely gets called as my debug statements prove.

s.grinovero wrote:

Quote:

I can't read what the messages are because ActiveMQ complains that the content is serialized and it doesn't have the DeleteLuceneWork class in its classpath.

Which party is that? of course they need the class if they have to deserialize the objects for Search, you're likely just missing a library somewhere.

Yes I understood that ActiveMQ can't deserialize because it doesn't have the class... that's fine. I was just curious why all the messages are of the class DeleteLuceneWork. I would think they would be of a class with a name like, EntityReadyToIndex (just made up this name). Is this accurate?

s.grinovero wrote:

It appears messages are sent but never received.. maybe you could try your JMS settings sending and receiving with something trivial, taking the Search backends out of the picture? unfortunately I never have setup ActiveMQ with Spring.

You can see above my log statements in the onMessage method get printed, so it works... it's the onMessage method inside the AbstractJMSHibernateSearchController class that hangs.

amin-mc · **Joined:** Wed Oct 03, 2007 2:31 pm **Posts:** 205

I've used Tomcat, ActiveMQ and Spring 2.5.6 with Hibernate Search. I'll send you the xml context file when I get home. I have some example code which I should be able to get to you as well. But I can't understand the current siutation.

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

amin-mc wrote:

I've used Tomcat, ActiveMQ and Spring 2.5.6 with Hibernate Search. I'll send you the xml context file when I get home. I have some example code which I should be able to get to you as well. But I can't understand the current siutation.

You are using almost my exact stack (except the spring version) so this will be tremendously helpful. Thanks so much amin-mc.

amin-mc · **Joined:** Wed Oct 03, 2007 2:31 pm **Posts:** 205

I've got something like this:

Code:

 <bean id="hSearchMasterListener" class="com.amin.search.demo.master.HSearchMasterListener">
        <property name="sessionFactory"  ref="sessionFactory" />
    </bean>


    <jms:listener-container connection-factory="jmsConnectionFactory">
      <jms:listener destination="queue.index.update.layer" ref="hSearchMasterListener"  />
   </jms:listener-container>

HSearchMasterListener looks like this:

Code:

public class HSearchMasterListener extends AbstractJMSHibernateSearchController {

...

 @Override
    public void onMessage(Message message) {
       System.out.println("recieved message");
       super.onMessage(message);
    }
}

The above Listener works and I can see index being updated.

The other thing is how are you deploying the master node? Is this a standalone process running? if you can give me a day I'll knock up a sample app for your reference.

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

Amin, thanks for the help. As you can see, my code is very similar to yours. Though your jms:listener-container element does not specify a transaction-manager attribute. I guess you must be specifying the transaction in a tx:advice element elsewhere? Or annotated?

Maybe this is a spring 3.0.2 issue...

I'm deploying the master node as a webapp. Same as a webserver, but with the addition of the MDP specified as you have.

mueller · **Joined:** Mon Mar 10, 2008 6:40 pm **Posts:** 114

Amin, if you could also share what's in your tomcat's context.xml file to define your connectionFactory and Queue resources, that would be helpful. Thanks.