通过原始日志快速分析和定位问题

更新时间:

本文介绍基于云消息队列 RabbitMQ 版当前日志快速查询和分析问题的方法。当您遇到消息不符合预期、消费异常、消息堆积时,通过该方法可以帮助您高效识别出异常、保证业务正常运行。

前提条件

推送云消息队列 RabbitMQ 版实例的消息操作日志到日志服务。具体操作,请参见配置消息日志

操作步骤

  1. 登录日志服务控制台,配置日志字段索引。

    具体操作,请参见创建索引。除自动生成的普通字段之外,还需手动添加__tag__:__receive_time__字段,并设置别名为timestamp,如下图所示。配置日志索引

  2. 设置查询的时间段,在搜索框输入SLS查询语句,查询消息日志。

    根据以下消息内容,查询对应的消息日志:

查询消息轨迹

在日志搜索框中输入查询语句,查询消息轨迹。

  • 通过Message ID查询

    在搜索框输入SLS查询语句,查询实例ID和Vhost下的msgId的日志。

    InstanceId:amqp-cn-i7m29o3s**** and VHost:cycle**** and ResourceName:msgId=27127757-44dc-4373-afc5-f8ea12f****

    image

    客户端调用BasicConsume订阅,可以查询到消息的发送和服务端的推送轨迹,SendMessage对应客户端调用BasicPublishPushMessage对应服务端推送消息给客户端;如果客户端采用的BasicGet拉取消息,则ActionBasicGet而不是PushMessage

    说明
    • 如果日志结果中SendMessage只有一条,但是PushMessage(BasicGet)对应多条,可能是客户端没有在首条PushMessage(BasicGet)的消费超时时间内调用BasicAck确认消息,导致服务端以为客户端没有消费成功而重新推送该条消息。消费超时时间说明请参见实例重试策略参数说明

    • 如果日志结果中除了SendMessagePushMessage之外,还存在SendDlqMessage日志,SendDlqMessage日志表示当前消息转入死信。

  • 查询消息是否被消费

    InstanceId:amqp-cn-i7m29o3s**** and VHost:cycle**** and Queue:cycleCheckQueue**** and ConnectionId:00163efffe08281f-00004e11-0009732f-799c0af9bc4e4913-96b3**** and  ChannelId:1 and (ResourceName:deliveryTag=90 or Property:deliveryTag=90) and RemoteAddress:"/192.168.XX.XX:XXXX"            

    其中,ConnectionIdChannelIddeliveryTagRemoteAddress都是通过PushMessage日志填写。RemoteAddress是客户端的IP地址,ConnectionId是当前Connection的唯一标识,ChannelId是当前Channel的唯一标识,deliveryTag是服务端对当前消息的唯一标识;DeleteMessage日志则是客户端成功消费消息的标记。

    查询消息是否被消费

    说明
    • 如果客户端调用BasicConsume时设置autoAck=false,则需要客户端调用BasicAck服务端才能确认消息被客户端正常消费并删除,而且BasicAck必须在PushMessage时间戳之后的消费超时时间内调用,超过消费超时时间服务端则认为客户端消费失败,并会重新推送该消息到客户端。具体请参见实例重试策略参数说明

    • 客户端已经调用BasicAck,但是查询消息是否被消费的时候,发现日志中并没有DeleteMessage日志,说明当前消息并没有成功消费,可以观察PushMessageBasicAck时间差,大于消费超时时间则表示当前BasicAck是无效调用。

    • 如果只查询到PushMessageDeleteMessage,没有查到BasicAck,可能是BasicAck(deliveryTag, multiple=true),一次性Ack了deliveryTag之前的所有消息。

查询Queue的消费情况

在日志搜索框中输入查询语句,查询SendMessagePushMessage(BasicGet)BasicAckDeleteMessage。当四者的百分比相同的时候,表示客户端的发送与消费速度基本持平,当前Queue无消息堆积或是有极少消息堆积。

InstanceId:amqp-cn-i7m29o3s**** and Vhost:cycle**** and Queue: cycleCheckQueue**** and (SendMessage or PushMessage or BasicAck  or DeleteMessage)

image

如果查询的日志出现以下几种情况,请根据可能的原因分析:

  • 日志搜索结果中没有DeleteMessage,可能是由于客户端在调用BasicConsumeBasicGet时,设置了autoAck=true,或者是客户端所有的BasicAck请求时间已经超过了消费超时时间,导致这些调用无效。消费超时时间说明请参见实例重试策略参数说明

  • 日志搜索结果中发现PushMessage的百分比相比SendMessage较少,可能是客户端的订阅者过少,建议多开Connection并创建新的Consumer。

  • 日志搜索结果中发现SendMessagePushMessage的日志百分比相当,但是DeleteMessage的百分比则相对较少,可能是客户端存在大量BasicAck的请求时间已经超过了消费超时时间,变成无效请求。消费超时时间说明请参见实例重试策略参数说明

  • 日志搜索结果中发现SendMessagePushMessageDeleteMessage日志百分比大致相同,但是BasicAck日志相对较少,考虑是否代码中使用了BasicAck(multiple=true)

死信消息查询

日志搜索框输入查询语句,查询对应消息。

  • 消息TTL到期进入死信队列

    InstanceId:amqp-cn-i7m29o3s**** and VHost:dlq**** and ResourceName:msgId=02a162ba-f842-440f-bfd4-2595dd19****

    image

    SendMessage对应用户调用BasicPublish发送消息,SendDlqMessage对应该消息ttl过期后发送到对应的死信队列中。

    说明

    如果用户配置了死信队列才会有该条日志。

  • Queue的TTL到期进入死信队列

    1. 设置Queue的死信属性以及TTL。

      Map<String, Object> argument = new HashMap<>();
      argument.put("x-dead-letter-exchange", [exchangeName]);
      argument.put("x-dead-letter-routing-key", [routingKey]);
      argument.put("x-message-ttl", [ttl]);
      channel.queueDeclare([queueName], true, false, false, argument);
    2. 日志搜索框输入如下,可以得到SendMessageSendDlqMessage日志。

      InstanceId:amqp-cn-i7m29o3s**** and VHost:dlq**** and ResourceName:msgId=034a75c5-d957-422f-822e-72dfad2a****

      image

  • 调用BasicRejectBasicNack时,requeue=false

    InstanceId:amqp-cn-i7m29o3s**** and VHost:dlq**** and (ResourceName:msgId=034a75c5-d957-422f-822e-72dfad2a**** or ResourceName:deliveryTag=1)

    image

    其中PushMessage日志表示服务端推送消息到客户端,客户端在收到消息后调用BasicReject(requeue=false),对应SendDlqMessage日志表示消息被路由到死信队列中。