深入剖析:如何使用Pulsar和Arthas高效排查消息队列延迟问题

pulsar,arthas · 浏览次数 : 0

小编点评

## Summary of the text: This document provides a detailed explanation of the root cause of a performance issue in a Pulsar application. The issue was caused by a backlog of messages in the Pulsar message queue, leading to a bottleneck in the processing pipeline. **Key points:** * The issue occurred due to a backlog of messages in the Pulsar message queue. * The messages were not being processed due to the bottleneck. * The root cause was identified as a long running database query triggered by a cron job. * The database query was taking too long to execute, causing the queue to fill up. * The issue was resolved by disabling the cron job and stopping the background thread processing the query. **Additional insights:** * The document also provides useful tips and techniques for debugging Pulsar applications, such as using the `flamegraph` and `tunnel` tools for deeper insights into the performance. * The document also mentions the `thread-n` command to analyze CPU usage and identify threads with high CPU consumption. * The document provides relevant links to official Pulsar documentation and community resources. **Overall, this document provides a clear and concise explanation of the problem and its solution, along with valuable insights for debugging Pulsar applications.**

正文

背景

前两天收到业务反馈有一个 topic 的分区消息堆积了:

根据之前的经验来看,要么是业务消费逻辑出现问题导致消费过慢,当然也有小概率是消息队列的 Bug(我们使用的是 pulsar)。

排查


通过排查,发现确实是在一点多的时候消息堆积了(后面是修复之后堆积开始下降)。

于是我在刚才堆积处查看了一条堆积消息的列表:

获取到其中一条消息的 messageId.

这里本质上使用的是 pulsar-admin 的 API。
org.apache.pulsar.client.admin.Topics#peekMessages


再通过这条消息的 id (为了演示,这里的 messageId 可能不一样)在我们的 pulsar 消息链路系统中找到了消息的发送链路:

通过这个链路会发现消息一直在推送,但就是没有收到客户端的 ACK 响应。

相关的消息链路埋点可以参考这里:如何编写一个 Pulsar Broker Interceptor 插件

简单来说就是在以下几个 broker 提供的拦截器接口加上埋点数据即可:

  • messageProduced
  • messageDispatched
  • messageAcked

既然知道了是客户端没有响应 ACK,那就得知道客户端此时在干什么。

首先排查了 JVM 内存、CPU 等监控情况,发现一切都挺正常的,这段时间没有明显的尖刺。

Arthas 排查

于是便准备使用 arthas 查看下线程的运行情况。

我们进入到对应 Pod 的容器,执行:

java -jar arthas-boot.jar

因为 JVM 内存都没有啥异常,所以先看看 thread 的运行堆栈,考虑到是 pulsar 消费线程卡住了,所以我们需要加上线程状态已经过滤下线程的名称:

thread --state WAITING | grep pulsar

此时就会列出当前 Java 进程中状态为 WATING 并且线程名称以 pulsar 开头的线程。

我在之前的文章 从 Pulsar Client 的原理到它的监控面板 中分析过客户端的原理。

20230802224400.png

可以知道 pulsar 客户端在其中使用的是 pulsar-打头的线程名称,所以这样就列出了我们需要重点关注的线程。

我们以图中列出的线程 Id:320 为例:

thread 320


此时便会打印当前线程的堆栈。

从上述堆栈中会发现线程一直处于 IO 操作中,看起来是在操作数据库。

我们再往下翻一翻,会发现上层调用的业务代码:

查阅代码得知这是一个数据库的写入操作,看起来是在这个环节数据库响应过慢导致的 pulsar 线程被阻塞了;从而导致消息没有及时 ACK。

为了最终确认是否由数据库引起的,于是继续查询了当前应用的慢 SQL 情况:

发现其中有一个查询语句调用频次和平均耗时都比较高,而且正好这个表也是刚才在堆栈里操作的那张表。

经过业务排查发现这个慢 SQL 是由一个定时任务触发的,而这个定时任务由于某些原因一直也没有停止,所以为了快速解决这个问题,我们先尝试将这个定时任务停掉。

果然停掉没多久后消息就开始快速消费了:

从这个时间线也可以看得出来了,在服务端推送了多次之后终于收到了 ACK。

修复之后业务再去排查优化这个慢 SQL,这样这个问题就得到根本的解决了。

更多好用技巧

当然 arthas 好用的功能还远不止此,我觉得还有以下功能比较好用:

火焰图

profile:可以输出火焰图,在做性能分析的时候非常有用。

动态修改内存数据

还记得之前我们碰到过一个 pulsar 删除 topic 的 Bug,虽然最终修复了问题,但是在发布修复版本的时候为了避免再次触发老版本的 bug,需要在内存中将某个关键字段的值修改掉。

而且是不能重启应用的情况下修改,此时使用 arthas 就非常的方便:

curl -O https://arthas.aliyun.com/arthas-boot.jar && java -jar arthas-boot.jar 1 -c "vmtool -x 3 --action getInstances --className org.apache.pulsar.broker.ServiceConfiguration  --express 'instances[0].setTopicLevelPoliciesEnabled(false)'"

这里使用的是 vmtool 这个子命令来获取对象,最终再使用 express 表达式将其中的值改为了 false。

当然这是一个高危操作,不到万不得已不推荐这么使用。

Arthas Tunnel & Web Console

这是一个方便开发者通过网页就可以连接到 arthas 的功能,避免直接登录到服务器进行操作。

我们在研效普通也内置了该功能,让开发排查问题更加方便。

CPU 使用过多

cpu 异常使用排查也是一个非常有用的功能,虽然我们可以通过监控得知 JVM 的 cpu 使用情况,但是没法知道具体是哪个线程以及哪行代码造成的 cpu 过高。

thread -n 3

使用以上命令就可以将 cpu 排名前三的线程打印出来,并且列出他的堆栈情况,这样可以很直观的得知 cpu 消耗了在哪些地方了。

当然还有一些 trace 查询:

trace demo.MathGame run '#cost > 10'

比如这是将调用超过 10ms 的函数打印出来,不过如果我们接入了可观测系统(OpenTelemetry、skywalking等)这个功能就用不太上了。


还可以在运行的时候不停机修改日志级别,这种在线上排查一些疑难杂症的时候非常好用(通常情况下 debug 日志是不打印的),我们可以将日志级别调整为 debug 打印出更加详细的信息:

[arthas@2062]$ logger --name ROOT --level debug
update logger level success.

如果是在 kubernetes 环境中执行也有可能碰到 Java 进程启动后没有在磁盘中写入 PID 的情况:

$ java -jar arthas-boot.jar  
[INFO] arthas-boot version: 3.6.7  
[INFO] Can not find java process. Try to pass <pid> in command line.  
Please select an available pid.

导致直接运行的时候无法找到 Java 进程;此时就需要先 ps 拿到 PID 之后再传入 PID 连入 arthas:

$ java -jar arthas-boot.jar 1

更多关于 arthas 的用法可以参考官网。

参考链接:

与深入剖析:如何使用Pulsar和Arthas高效排查消息队列延迟问题相似的内容:

深入剖析:如何使用Pulsar和Arthas高效排查消息队列延迟问题

背景 前两天收到业务反馈有一个 topic 的分区消息堆积了: 根据之前的经验来看,要么是业务消费逻辑出现问题导致消费过慢,当然也有小概率是消息队列的 Bug(我们使用的是 pulsar)。 排查 通过排查,发现确实是在一点多的时候消息堆积了(后面是修复之后堆积开始下降)。 于是我在刚才堆积处查看了

Go代码包与引入:如何有效组织您的项目

本文深入探讨了Go语言中的代码包和包引入机制,从基础概念到高级应用一一剖析。文章详细讲解了如何创建、组织和管理代码包,以及包引入的多种使用场景和最佳实践。通过阅读本文,开发者将获得全面而深入的理解,进一步提升Go开发的效率和质量。 关注公众号【TechLeadCloud】,分享互联网架构、云服务技术

如何使用Java创建数据透视表并导出为PDF

摘要:本文由葡萄城技术团队原创并首发。转载请注明出处:葡萄城官网,葡萄城为开发者提供专业的开发工具、解决方案和服务,赋能开发者。 前言 数据透视分析是一种强大的工具,可以帮助我们从大量数据中提取有用信息并进行深入分析。而在Java开发中,可以借助PivotTable,通过数据透视分析揭示数据中的隐藏

从源码层面深度剖析Spring循环依赖

本文从源码层面介绍了Spring如何创建bean、如何解决循环依赖,同时也介绍了不能解决哪些循环依赖,同时在文章的最后解决循环依赖报错的几个方法

从源码层面深度剖析Spring循环依赖

作者:郭艳红 以下举例皆针对单例模式讨论 图解参考 https://www.processon.com/view/link/60e3b0ae0e3e74200e2478ce 1、Spring 如何创建Bean? 对于单例Bean来说,在Spring容器整个生命周期内,有且只有一个对象。 Sprin

Java对象拷贝原理剖析及最佳实践

作者:宁海翔 1 前言 对象拷贝,是我们在开发过程中,绕不开的过程,既存在于Po、Dto、Do、Vo各个表现层数据的转换,也存在于系统交互如序列化、反序列化。 Java对象拷贝分为深拷贝和浅拷贝,目前常用的属性拷贝工具,包括Apache的BeanUtils、Spring的BeanUtils、Cgli

慢SQL的致胜法宝

大促备战,最大的隐患项之一就是慢SQL,对于服务平稳运行带来的破坏性最大,也是日常工作中经常带来整个应用抖动的最大隐患,在日常开发中如何避免出现慢SQL,出现了慢SQL应该按照什么思路去解决是我们必须要知道的。本文主要介绍对于慢SQL的排查、解决思路,通过一个个实际的例子深入分析总结,以便更快更准确

解码Transformer:自注意力机制与编解码器机制详述与代码实现

> 本文全面探讨了Transformer及其衍生模型,深入分析了自注意力机制、编码器和解码器结构,并列举了其编码实现加深理解,最后列出基于Transformer的各类模型如BERT、GPT等。文章旨在深入解释Transformer的工作原理,并展示其在人工智能领域的广泛影响。 > 作者 TechLe

深入剖析C++多态的实现与原理-详解

目录多态基础虚函数虚函数的继承虚类/虚基类重写/覆盖条件:概念:多态的条件其他的多态行为多态中子类可以不写virtual协变代码举例继承遗留问题解决析构函数具体解决方式:题目1答案:解析:题目2答案:C++11 override和finalfinal功能1:禁用继承使用场景:功能2:禁用重写使用场景

【转帖】MySQL InnoDB存储原理深入剖析与技术分析

一、MySQL记录存储: MySQL InnoDB的数据由B+树来组织,数据记录存储在B+树数据页(page)中,每个数据页16kb,数据页 包括页头、虚记录、记录堆、自由空间链表、未分配空间、slot区、页尾七部分组成。 所有的非终端结点可以看成是索引部分,结点中仅含有其子树根结点中最大(或最小)