ActiveMQ由于Session is closed错误导致发送消息失败的问题回顾

天黑请闭眼 : 问题背景

在这样一个难得阳光灿烂的上午,大家都沐浴在清晨的清爽之中的时候……
好吧,我编不下去了,其实就是大清早被通知说我们的消息显示的不正确,然后开始排查问题,经由定位之后发现问题在于MQ消息没有发送成功,导致生成的信息有缺失,然而悲剧的是祸不单行,由于之前配置日志的问题导致了历史日志的丢失。唯一的线索就是当时的一个同事给另一个同事的错误信息截图,如下:

警察叔叔,就是这个人!

于是就此,我们展开了调查……


狼人请杀人 : 错误位置

首先我们开始对可疑的问题点开始反推,鉴于存在错误信息的线索,我们分析了MQ Client的源码,发现了抛出这个异常的位置:

    /**
     * Check if the session is closed. It is used for ensuring that the session
     * is open before performing various operations.
     *
     * @throws IllegalStateException if the Session is closed
     */
    protected void checkClosed() throws IllegalStateException {
        if (closed) {
            throw new IllegalStateException("The Session is closed");
        }
    }

结合我们具体的业务日志代码,以及数据库记录,反推具体的问题发生点应该在于我们对MQ发送消息的功能封装类位置:

        /**
         * 注意提交事务 方法commit()
         * 
         * queueName此处用于初始化,防止static对象先初始化时候出现空指针的问题
         * 
         * @param queueName
         * @param msg
         * @throws JMSException
         */
        public void sendMsg(String queueName, JSONObject messageJson) {
            try {
                if (null == producer) {
                    init(queueName);// 每一个queue分别实例化自己的参数
                }
                if (null != producer) {
                    //统一增加queueName
                    messageJson.put("queueName", queueName);
                    String msg = messageJson.toString();


                    // **警察叔叔,就是这里**
                    message = session.createTextMessage(msg);


                    if (null != message) {
                        producer.send(message);
                        mqLog.info("MQProducer, sendMsg succ, queueName:" + queueName + ", msg:" + msg);
                    } else {
                        throw new JMSException(" 消息未成功发送: " + msg);
                    }
                } else {
                    throw new JMSException(" 消息未成功发送: " + messageJson.toString());
                }
            } catch (Exception exp) {
                exp.printStackTrace();
                Log4jUtil.exception(exp);
                mqLog.error(messageJson.toString());
            }

        }

预言家请验人 : 错误原因

鉴于这里就明确了是Session的调用时,由于内部的closed值为TRUE导致了这个异常信息的打印,因此我们继续通过源码排查了这个值会被写为TRUE的情况,发现是在于如下释放(类似于析构的情况)的时候才会导致这个值的变化:

    public synchronized void dispose() throws JMSException {
        if (!closed) {

            try {
                executor.close();

                for (Iterator<ActiveMQMessageConsumer> iter = consumers.iterator(); iter.hasNext();) {
                    ActiveMQMessageConsumer consumer = iter.next();
                    consumer.setFailureError(connection.getFirstFailureError());
                    consumer.dispose();
                    lastDeliveredSequenceId = Math.max(lastDeliveredSequenceId, consumer.getLastDeliveredSequenceId());
                }
                consumers.clear();

                for (Iterator<ActiveMQMessageProducer> iter = producers.iterator(); iter.hasNext();) {
                    ActiveMQMessageProducer producer = iter.next();
                    producer.dispose();
                }
                producers.clear();

                try {
                    if (getTransactionContext().isInLocalTransaction()) {
                        rollback();
                    }
                } catch (JMSException e) {
                }

            } finally {
                connection.removeSession(this);
                this.transactionContext = null;

                // ** 警察叔叔,就是这个人! **
                closed = true;

            }
        }
    }

因此想到可能是由于链接被释放了才导致了这个问题,开始在MQ Server端找对应日志,于是发现了如下错误信息,由于心跳(或其它)的超时,导致服务器端主动释放了相关的链接:

由于超时释放了链接

天亮了 : 根因分析

由此我们得到大致的结论,由于我们本身的代码里面采用的是单例模式,造成了Session值只会在一开始创建Producer之后就保持住。因此虽然服务器端释放后,我们Client端的Session值还是使用了之前的值,导致了这个异常被抛出。
也就是说MQ本身的程序在发现异常之后开始清理相关的数据,并设置相关的状态(把Closed变量置为TRUE)。而我们的程序由于还是引用到了之前的对象上,因此在访问Closed变量时发现出错了,因此抛出异常,导致我们之后的发送失败

没错,我就是犯人

Session在Producer中的声明如下:

    // 这里的Producer是单例模式的
    // Session一旦创建之后是不会更新的
    protected class MQProducer {
        private ActiveMQConnectionFactory factory = null;
        private Connection connection = null;
        private Session session = null;     
        // 以下省略若干行
        ...

请投票 : 问题解决

那么问题清楚了之后,还是不明确为什么会导致这种异常释放,突然小伙伴们想起了之前收到的一封邮件,于是成功发现了凶手(核对日志时间和机器,完全一致)……
这个故事告诉我们一定要注意看邮件啊,以及阿里的监控系统好犀利啊!


凶手

当然我们自身的代码中,对这方面理解也不够深入,主要在于:

  1. 捕获这种异常之后,仅仅是简单的记录了相关的log,其实更优雅的方式是针对这种错误作出健壮性的反馈(当如具体的方式和策略还得再深入理解相关的机制和相关实现)
  2. 单例模式,有自身的好处,但是Session固定之后是否合适,还需要结合第1点来具体给出策略

结局 : 写在最后

仅以此记录一下的问题,防止之后忘记了。
也希望能给有类似问题发生的小伙伴们一些线索。
have fun~ :)

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 158,560评论 4 361
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,104评论 1 291
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 108,297评论 0 243
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,869评论 0 204
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,275评论 3 287
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,563评论 1 216
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,833评论 2 312
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,543评论 0 197
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,245评论 1 241
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,512评论 2 244
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 32,011评论 1 258
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,359评论 2 253
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 33,006评论 3 235
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,062评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,825评论 0 194
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,590评论 2 273
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,501评论 2 268

推荐阅读更多精彩内容