0

I've been having issues with MDB queue consumption speed with WildFly 8, java 1.8. To show the issues I've written a simple test application which does the following: servlet sends 100 messages to a MDB, MDB simulates some processing and moves on to the next message. The problem is that it takes over 40 ms for the MDB to start processing the next message (and it takes less then 5ms on other similar PCs with same WildFly).

Did anyone have a similar problem? I'm guessing it's some banal java configuration issue which I can't figure out. With more complex messages where consumption should take around 10-15ms for me it can take up to 150-200ms.

Servlet code:

String destinationName = "java:/queue/test";
    PrintWriter out = response.getWriter();
    Context ic = null;
    ConnectionFactory cf = null;
    Connection connection = null;

    try {
        ic = new InitialContext();

        cf = (ConnectionFactory) ic.lookup("/ConnectionFactory");
        Queue queue = (Queue) ic.lookup(destinationName);

        connection = cf.createConnection();
        Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
        MessageProducer publisher = session.createProducer(queue);

        connection.start();

        for (int i = 0; i < 100; i++) {
            TextMessage message = session.createTextMessage("Hello " + i);
            publisher.send(message);
            LOGGER.info("Sent msg " + i);
        }
        out.println("Message sento to the JMS Provider");

    } catch (Exception exc) {
        exc.printStackTrace();
    } finally {
        if (connection != null) {
            try {
                connection.close();
            } catch (JMSException e) {
                e.printStackTrace();
            }
        }
    }

MDB Code:

@MessageDriven(
    activationConfig = { 
            @ActivationConfigProperty(propertyName = "destination", propertyValue = "queue/test"), 
            @ActivationConfigProperty(propertyName = "destinationType", propertyValue = "javax.jms.Queue"),
            @ActivationConfigProperty(propertyName = "acknowledgeMode", propertyValue = "Auto-acknowledge"),
            @ActivationConfigProperty(propertyName = "maxSession", propertyValue = "1")
    }, 
    name = "ConsumerMdb")
public class ConsumerMdb implements MessageListener {
    private static final Logger LOGGER = Logger.getLogger(ConsumerMdb.class.getName());
    private static int globalId = 1;
    private int id;
    public ConsumerMdb() { 
        id = ++globalId;
        LOGGER.warning("created mdb " + id);
    }
    public void onMessage(Message message) {
        LOGGER.info("IN ON MSG " + id);
        try {
            Thread.sleep(50);
            TextMessage msg = (TextMessage) message;
            LOGGER.info("Proccessing: " + msg.getText());
        } catch (Exception e) {
            e.printStackTrace();
        }
        LOGGER.info("OUT ON MSG");
    }

}

And the logged problem is (time difference between 'OUT ON MSG' and 'IN ON MSG'):

21:36:24,414 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) IN ON MSG 4
21:36:24,465 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) Proccessing: Hello 91
21:36:24,465 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) OUT ON MSG
21:36:24,502 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) IN ON MSG 4
21:36:24,553 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) Proccessing: Hello 92
21:36:24,553 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) OUT ON MSG
21:36:24,587 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) IN ON MSG 4
21:36:24,637 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) Proccessing: Hello 93
21:36:24,637 INFO  [mdb.ConsumerMDB] (Thread-0 (HornetQ-client-global-threads-929329197)) OUT ON MSG
user3816378
  • 93
  • 14
  • Have you discounted a delay in the servlet firing the message? [Using `InitialContext` for resource lookup is costly](http://stackoverflow.com/a/6382465/1530938). Depending on the position of that bit of code in the servlet, this might just be the MDB waiting for the servlet to catch up – kolossus Jan 23 '16 at 00:37
  • The server fires all the messages, the issue is that for some reason it took the mdb around 40ms to consume a new message from the queue. Now, for some reason, it normalized to about 25ms which for me is still to slow. – user3816378 Jan 23 '16 at 15:08
  • Anything beyond 1ms is really pushing it as poll loop should be eagerly awaiting new messages on a opened socket. 25-50 ms seems like tcp connection is being opened every time a poll/receive/listen is triggered. I would recheck JMS ConnectionFactory configuration as it seems to me that you are not reusing connections. – Talijanac Mar 31 '22 at 10:41

0 Answers0