Groovy 闭包执行异常答案

【问题标题】：Groovy Closure Execution OddityGroovy 闭包执行异常
【发布时间】：2016-04-16 12:25:42
【问题描述】：

我有一个基本上使用 JMS 消息的类，然后继续使用这些消息调用闭包。消息侦听器在单独的线程中运行。

import groovy.util.logging.Slf4j
import javax.jms.*

@Slf4j
class JMSProducer {

    Connection connection
    List<Queue> queues
    private Session session
    private List<MessageConsumer> messageConsumers

    @Override
    void init() {
        connection.start()
        session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE)
        messageConsumers = queues.collect { session.createConsumer(it) }
    }

    @Override
    void produce(final Closure closure) {

        def listener = new MessageListener() {
            @Override
            void onMessage(Message message) {
                if (message instanceof ObjectMessage) {
                    try {
                        log.info("Calling");
                        closure.call(message.object);
                        log.info("Called");
                    } catch(e) {
                        log.error("Error")
                    } finally {
                        log.info("Finally");
                    }
                } else {
                    log.error("Unrecognized message")
                }
            }
        }
        messageConsumers.each {
            it.messageListener = listener
        }
    }
}

上面代码的问题是，我看到我放入队列中的所有消息都是“正在调用”、“被调用”和“最终”，但闭包本身只被调用了其中的一小部分。

//Assume 5 messages have been put into queue, and 
// JMSProducer has been configured to read from queue*

new JMSProducer().produce { message ->
    log.info("Received Message");        
}

“收到的消息”只记录了两次（即使我看到“正在呼叫”/“已呼叫”/“最后”各五次）。

就好像闭包被忽略或跳过一样。

当我在我的 IDE 中运行它时，我没有这个问题，只有在运行时 ./gradlew clean test 来自命令行。

最终这似乎是一个竞争条件，但我看不到如何在闭包执行之前和之后记录日志，也看不到应该在闭包内部发生的日志记录。

作为更新，我添加了代码以在运行时注销闭包对象，我看到以下输出（代码在调试中略有更改，但问题仍然存在）：

2016-01-12 14:56:04 INFO  JMSProducer - Calling: StreamUtil$2@1edef6f9
2016-01-12 14:56:04 INFO  JMSProducer - Calling:JMSProducerTest$_verifyJMSProducer_closure1@fa11e9d
2016-01-12 14:56:04 INFO  JMSProducer - Called
2016-01-12 14:56:04 INFO  JMSProducer - Finally
2016-01-12 14:56:04 INFO  JMSProducer - Called
2016-01-12 14:56:04 INFO  JMSProducer - Finally
2016-01-12 14:56:04 INFO  JMSProducer - Calling: StreamUtil$2@1edef6f9
2016-01-12 14:56:04 INFO  JMSProducer - Calling: JMSProducerTest$_verifyJMSProducer_closure1@fa11e9d
2016-01-12 14:56:04 INFO  JMSProducer - Called
2016-01-12 14:56:04 INFO  JMSProducer - Finally
2016-01-12 14:56:04 INFO  JMSProducer - Called
2016-01-12 14:56:04 INFO  JMSProducer - Finally
2016-01-12 14:56:04 INFO  JMSProducer - Calling: JMSProducerTest$_verifyJMSProducer_closure1@fa11e9d
2016-01-12 14:56:04 INFO  JMSProducer - Called
2016-01-12 14:56:04 INFO  JMSProducer - Finally

看起来回调不是一回事。只有当我得到 StreamUtil$2@1edef6f9 时，回调才会执行。

【问题讨论】：

除了使用记录器来确认闭包正在运行之外，您是否尝试过其他方法？比如println。这可能是日志记录而不是运行闭包的问题。
可以调试代码吗？看看final closure 在实现MessageListener 接口的匿名类中的行为会非常有趣。
代码实际上是递增一个原子整数（并打印），但两者都没有发生。我最初认为它也可能是 IO 缓冲。此外，我还没有找到在我的 IDE 之外进行调试的好方法（没有出现问题的地方）。我正要查看 Java 字节码，看看是否有什么东西出现。我开始认为我在 Groovy 中遇到了一个极端情况。

标签： groovy closures

【解决方案1】：

好的，显然 JMS 中存在竞争条件，并且之前的测试以某种方式能够覆盖消息侦听器（但仅限于部分迭代）。不完全确定这是如何发生的，但与异步测试和 JUnit 有关。

【讨论】：