BUG—Nuget包版本不一致导致程序行为与预期不符

注:本文收录于《Bug集锦》,请点击此处查看全文目录

BUG起因

先介绍一下背景:

数周前的一个极其平常的下午,完成了本次迭代的开发工作,发布到QA提测,然后开始摸鱼。没几分钟,测试就来找我“麻烦”了:生产者的消息没有发送到RocketMQ的队列中

“简单,看下日志就能定位原因了”,心想着,随即打开日志,果然,报错了,可是,这个错误消息,啧啧啧,看不懂啊:

NewLife.RocketMQ.Protocol.ResponseException: 1: the custom field <c> is null   
在 NewLife.RocketMQ.ClusterClient.Invoke(RequestCode request, Object body, Object extFields, Boolean ignoreError) 
在 NewLife.RocketMQ.Producer.Publish(Message msg, Int32 timeout)
......

c是个什么玩意?我不记得有这东西啊!

BUG排查

问题没有头绪,只能先在本地环境测试一下了。先使用本地的生产者生产一条消息,发送到Dev环境的RocketMQ队列中,结果消息顺利到达,无异常。然后,将本地RocketMQ配置修改为QA环境配置,并生产一条消息,意外的是,消息也顺利到达了,并未出现异常。

这就奇怪了,既然无法快速解决,先启用“重启大法”,重新发个版本试试吧。发版后,果不其然,测试那边说没问题了。

可是,还没摸鱼一分钟,测试又来“找麻烦”了,问题又出现了:生产者的消息时而能够发送成功,时而发送失败。哎,最担心的问题还是出现了,这种时而报错时而正常的问题最难处理了。

RocketMQ版本升级了

不得不说,.NET对RocketMQ的支持确实不太好,NewLife.RocketMQ是为数不多的能用于生产环境的开源库,去github碰碰运气吧,万一其他人也遇到这个问题了呢。

运气不错!其中一条Issue引起了我的注意——调用出错,似乎版本不兼容 rocketmq v4.9.1

哦?难不成是有人偷偷的把QA环境的RocketMQ升级了?通过RocketMQ控制台看看:

靠!有一台broker版本升级为v4.9.2了,QA环境的Topic是不久前创建的,其中部分队列就分配到这台机器上了。

找到问题原因了,而且也有人提交pr 修复了这个bug:

var smrh = new SendMessageRequestHeader
{
    ProducerGroup = Group,
    Topic = Topic,
    QueueId = mq.QueueId,
    SysFlag = 0,
    BornTimestamp = (Int64)ts.TotalMilliseconds,
    Flag = msg.Flag,
    Properties = msg.GetProperties(),
    ReconsumeTimes = 0,
    UnitMode = UnitMode,
    DefaultTopic = "TBW102"  // 增加了该行
};

现在,我只需要通过Nuget升级一下包的版本就好了,当时的最新版本是1.5.2021.1204:

重新发版,准备继续摸鱼!可是,还没来得及高兴,测试说问题依然存在,错误仍旧是之前的错误。这不就见鬼了吗!

这一天,一直忙活到晚上十点多,问题终究还是没有解决…

程序集版本不一致

有时候,脑子长时间思考同一个问题,往往会陷入一个封闭的环境,导致思维会越来越狭隘。

第二天,准备换个思路解决问题——将QA的dll复制到本地来调试。不过,在准备复制dll的时候,发现了一个问题:NewLife.RocketMQ.dll的修改日期竟然还是6月份,也就是说实际上它还是老版本,不出问题才怪。

QA环境的RocketMQ是以集群方式部署的,共有三台Broker,其中一台是高版本v4.9.2,其它两台是低版本v4.4.0。QA环境的Topic也是今天刚刚创建的,这三台Broker上都有属于该Topic的队列。当生产者生产消息时,可能会发送到高版本的Broker,也可能会发送到低版本的Broker上,所以,才导致了“时而成功,时而失败”情况的发生。

可是,我明明已经升级版本了啊!

突然惊醒!其他Service的NewLife.RocketMQ版本并未同步升级, 导致出现了程序集版本不一致的问题!(PS:该项目是一个.net4.5的老项目,其他团队的许多Service也在该解决方案中,遇到该问题时未及时通知其他团队,这也让我充分意识到团队间沟通的重要性!)

查看程序集的生成顺序:右击“解决方案”,选择“项目生成顺序”即可查看。

知道问题原因了,现在有两种解决方式:

  1. 升级项目中所有程序集的NewLife.RocketMQ版本,代价是需要测试走一遍回归。
  2. 要求运维团队暂时不要升级RocketMQ版本,待研发、测试团队准备好后再升级。

因为迭代急着上线,其他团队也来不及回归测试,且RocketMQ的升级仅仅是为了适用一下新特性,并非强制要求,所以选择了稳妥的方案2。至此,问题终于解决完毕!

其他

1. 当项目中出现Nuget包版本不一致的情况时,最终生成的程序集版本是哪个呢?

参考nuget使用经验:复杂依赖关系下的包版本问题,并亲测无问题,总结如下:

  • 引用层级不同时,NuGet 将选择最接近入口程序集的版本
  • 引用层级相同时,NuGet 将选择满足所有版本要求的最低版本

建议一定要保证项目内引用包版本一致,尽量避免引用多版本的情况

2. 为什么我本地生产者生产消息到QA环境RocketMQ没出问题?

经过详细排查,我发现并非仅仅是版本不一致导致的问题。实际上,虽然项目中同时引用了多个版本的NewLife.RocketMQ,不过当项目编译后,入口程序集的bin目录下的NewLife.RocketMQ.dll实际上已经是最新的了,所以也就不会出问题。然而,由于QA的发布脚本有问题,导致QA服务器上的NewLife.RocketMQ.dll并未更新到,仍在使用老版本。

3. the custom field <c> is null 到底是什么意思?

事实上,这个c指的是生产者发送消息请求头中的Default Topic,对于不了解RocketMQ通信协议的我,是从Newlife.RocketMQ源码中得知的:

/// <summary>发送消息请求头</summary>
public class SendMessageRequestHeader
{
    /// <summary>默认主题</summary>
    [XmlElement("c")]
    public String DefaultTopic { get; set; }
    
    // ...
}

至于Default Topic的空校验,是由于在RocketMQ v4.9.1 中增加了decodeSendMessageHeaderV2方法,如果有兴趣,可以点击此pr查看完整提交记录。

static SendMessageRequestHeaderV2 decodeSendMessageHeaderV2(RemotingCommand request)
        throws RemotingCommandException {
    SendMessageRequestHeaderV2 r = new SendMessageRequestHeaderV2();
    HashMap<String, String> fields = request.getExtFields();
    if (fields == null) {
        throw new RemotingCommandException("the ext fields is null");
    }

    // ...

    s = fields.get("c");
    checkNotNull(s, "the custom field <c> is null");
    r.setC(s);
    
    // ...
}

总结

经过这次bug排查,有以下几点心得:

  • 中间件升级要慎重,一定要在所有使用到该中间件的系统的负责人得知的的情况下再升级。
  • 第三方程序集的版本升级要慎重,一定要保证项目中的程序集版本一致,并进行回归测试。
  • 对于系统中所使用到的中间件,一定要持续关注新版本的发布,了解其基本原理,这样才能快速定位问题所在。
  • 加强不同团队之间的沟通,思考问题尽量全面。