某次诊断网络问题的过程及思考

今天花了三个多小时去诊断一个线上的问题, 最终的解决方法只需要1分钟. 回头整理一下整个过程, 发现其中还是有很多机会.

其实这个问题昨天就被观察到了, 当时发现有些服务自动熔断了(Service client auto markdown), 一路追查到底, 发现最下层一个访问 Couchbase 的应用在访问 Couchbase 的时候 timeout 了. 大概几百次访问里, 会有那么1, 2次可能会 timeout. 那么这样问题已经确诊到最下层应用到 Couchbase 这些组件了.

从最下层应用到 Couchbase, 只涉及三段: 1) 最下层应用本身; 2) 网络; 3) Couchbase. 首先, 这个最下层应用本身除了 error 增加之外, 并没有发现可疑的地方, 但是也不能完全排除; 其次, 应用和 Couchbase 之间大概有8跳 (hop), 网络 team 查看他们的监控数据, 中间这些网络设备并无异常. 最后, DBA 从 Couchbase 的监控指标数据去看, 也没有发现异常. 尽管除了应用的 error 数量有异常, 查看了其它所有指标, 都看上去还是很平静.

进一步分析这个错误的数据, 可能会指明一些方向. 首先, 这个应用在三个数据中心分别有30多台机器, 只有一个数据中心的这个 timeout error 非常多, 其它数据中心也有, 但是相比之下, 几乎可以忽略. 那么可以断定, 这个问题只是局限于这个数据中心. 这个数据中心的应用代码和其它数据中心的是一样的, 所以不大可能是代码的问题. 这个数据中心的机器最近也没做过什么改动, 那么不大可能是这些应用有问题. 退一步讲, 如果这些机器有问题, 那么很有可能这个数据中心的其它应用机器也应该有问题, 或者说这个应用访问其它外部服务, 也很有可能有 timeout 的问题, 可是这个情况不存在. 对于网络问题, 可以做同样的假设, 如果是网络问题, 这个网络上走的其它服务, 也一样会遇到网络问题暴露出来, 可是并没有发生一样的网络问题. 那么排除下来, 最有可能的是 Couchbase 数据库那边有问题, 可是 Couchbase 的监控数据却显示, Couchbase 操作的延时( latency) 并没有任何波动.

既然是 timeout 问题, 就可以用 tcpdump 去确认到底是不是网络问题. 网络抓包最完全的是关键的每跳都抓, 今天在有限的权限的情况下, 只能在应用这边抓一下. 从应用这边看, 它连着同数据中心的 Couchbase 集群里的8台机器, 端口都是11211, 于是对涉及这端口的都抓一下. 从抓取的 tcp 包来看, 发现有些 tcp 包有乱序现象, 尽管这些乱序的 tcp 包在非常短的时间内都收到了, 可是 Couchbase 客户端却没有对这些乱序的包进行正确的组装, 生成 response 数据, 所以尽管 tcp 包都收到了, 因为没组装成功, 并返回给调用者, 导致调用者认为最终没有收到 response, 而 timeout. 进一步查看这种乱序的 tcp 包, 发现只局限于 Couchbase 那边的一台机器. 于是用 mtr -s 1040 去测试一把, 发现大概每80次, 就会有一次突然超过1s的延时, 正常情况下因为在一个数据中心延时都小于10ms. 另外一个值得注意的地方是, 从应用到 Couchbase 的 mtr 数据结果里, 最后这1跳可能发生大于1s 的延时, 前面所有跳都么有. 从 Couchbase 到应用这边, 如果哪次延迟高, 所有的跳都显示很高. 从这些数据可以看出, 基本是 Couchbase 这边的机器有问题.

使用 mtr 又继续验证了到其它 Couchbase 数据库的路径, 没有发现有这么长的延时问题. 所以最终怀疑是这个数据库所在机器的操作系统层面出了问题, 又或者因为这个机器是虚拟机, 这个虚拟机所在的宿主机出了问题. DBA 先把这台数据库移除集群, 然后 reboot 这个机器, 起来之后从新加入集群, 问题消失了. 尽管没有深入挖掘出为什么这个机器除了问题, 也因为它已经被重启, 没有了犯罪现场, 很难查清. 只能期望如果下次还有类似问题, 可以先保留现场, 查清一直在修复.

问题虽然通过重启解决, 仔细思考一下整个流程, 还是有些可以改进的地方:

  1. 从最上层应用一路追查到最底层的应用, 花了一些时间, 现阶段没有全量的 tracing 数据. 如果有全量 tracing 数据, 只需要找出一个最上层的 transaction, 那么就直接追查到导致延迟问题的最下层应用. 当然如果能追查到数据库层就更好了.

  2. 最下层的应用使用 RxJava, 里面的观察者等待1秒钟, 然后 timeout. 当 timeout 的时候, 它 new 了一个 TimeoutException(), 参数没有传入任何有意义的字符. 导致在 log 里面看到的是一个 RxJava 的出错栈, 最后给的 error message 是一个 null, 尽管能看到是 TimeoutException, 可是没有任何有意义的提示消息. 一个有意义的消息至少告诉别人是连接哪个 ip, 连接哪个端口, 花了多久 timeout 的.

  3. 如果有批量自动化的工具去做大量机器的 mtr 命令, 并合并在一起分析, 将加速诊断的过程;

  4. 仔细对问题进行分类, 对细节进行逻辑推理, 合理的猜测加论证, 能加速诊断的过程.

  5. 需要更完备的监控. 对于 service client, DB client, NoSQL client 都要搜集 metric 进行监控.

java.util.concurrent.ReentrantLock 与 synchronized 的对比

两者都可以实现同步, 在有些方面二者还是有很多区别. synchronized 是 java 的一个语法级别的特性, ReentrantLock 是 util 里面的一个辅助类.

相同点:

  1. 二者都可以实现锁;
  2. 二者都可以实现 生产者/消费者模式 wait/notify/notifyAll, await/signal/signalAll

不同点:

  1. synchronized 必须是一对 {} 中间的部分, 2 个 synchronized 的代码块无法交叉, ReentrantLock 的写法更灵活, 可以交叉;
  2. Lock 可以设置是否回应 interrupt;
  3. Lock 可以使用 tryLock() 如果不能获得锁, 立马返回;
  4. Lock 可以使用 tryLock(timeout) 可以设置尝试获得锁的最长等待时间;
  5. 一个 Lock 可以通过 newCondition 设置多个条件队列, 让他们等待不同的事件;
  6. ReentrantLock 可以设置是否是公平锁;
  7. synchronized 在 JDK 6 优化之后, 可以实现锁粗化, 偏向锁, 根据逃逸分析锁消除;

如何生成 java heap dump

Java heap 是某个时间点上 JVM 内存的一个瞬时镜像(snapshot), 通过工具查看内存里面的各种对象以及他们之间的关系, 对于分析内存问题非常有帮助. 常见的 heap dump 都是二进制的 hprof 格式, 获得之后一般通过 jhat, JVisualVM 或者 MAT 分析. 那么第一步, 如何获得 heap dump 呢? 本文将介绍常见的获得 heap dump 的一些方法.

  1. jcmd
    jcmd 是 jdk 自带的一个小工具, 推荐使用. 要通过 jcmd 获得 heap dump, 首先要得到该进程的 ID. 获得进程 ID 之后, 可以通过 jcmd 命令获得 heap dump.
    LM-SHC-16501315:Downloads xiatian$ jcmd
    42596 
    98797 sun.tools.jcmd.JCmd
    LM-SHC-16501315:Downloads xiatian$ jcmd 42596 GC.heap_dump /tmp/heap.hprof
    42596:
    Heap dump file created
  1. jmap
    jmap 是 JDK 从早期开始一直附带的一个小工具, 使用下面的命令来获取 heap dump:
    jmap -dump:[live],format=b,file=<file-path>
    其中的 live 是可选, 代表是否包含即将被 GC 的对象, 若包含 live, 则不包含即将被 GC 的对象.
    在我的使用经验中, 有时候 jmap 会出现不能 attach 到目标进程的问题.
    例子:
LM-SHC-16501315:Downloads xiatian$ jmap -dump:live,format=b,file=/tmp/heapdump.hprof 42596
Dumping heap to /private/tmp/heapdump.hprof ...
Heap dump file created
  1. JVisualVM
    若在桌面环境, 并且已经安装 JDK, 可以使用 JDK 自带 GUI 工具 JVisualVM.
    heap.png

  2. JConsole
    JConsole 也是 JDK 自带 GUI 工具
    jconsole.png

  3. 可以在 JVM 启动时添加如下参数, 当发生 OOM 时候, 自动产生 heap dump:

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=<file-or-dir-path>
  1. 编程的方式: 可以通过使用 MBean 去操作, 产生 heap dump.
public static void dumpHeap(String filePath, boolean live) throws IOException {
    MBeanServer server = ManagementFactory.getPlatformMBeanServer();
    HotSpotDiagnosticMXBean mxBean = ManagementFactory.newPlatformMXBeanProxy(
      server, "com.sun.management:type=HotSpotDiagnostic", HotSpotDiagnosticMXBean.class);
    mxBean.dumpHeap(filePath, live);
}

有时候, 你会看到 core dump 和 heap dump, 2个不一样的dump, 那么2个区别是什么呢?
Java 常见的三种 dump 文件: Core Dump, heap dump, thread dump

jstack

jstack 用来打印当前 Java 进程的所有 stacktrace 信息, 包括每层栈的类名, 方法名, 行号, 以及线程的状态, 当前线程拥有的锁, 还能打印部分 native stracktrace.

jstack [ option ] pid
jstack [ option ] executable core
jstack [ option ] [server-id@]remote-hostname-or-IP

最常使用的还是跟 pid 去打印当钱进程的栈. 比如:

jstack -l 42596
jstack -l 42596 > /tmp/stack.txt
jstack -m 42596 // 打印包括 native 栈在内的所有栈. 
jstack -F 42956 //Solaris & Linux 上 force 打印栈

这个功能可以通过最新的 jcmd 来实现.

jcmd  42596 Thread.print