城的灯

生产环境难题解决方案

生产环境调试难题

当我们的代码运行在生产环境时,各种千奇百怪的事情都有可能发生,而此时我们已经离开了舒服的开发环境,不能使用自己习惯的IDE来单步调试。当我们生产环境出现问题时,我们需要第一时间知道问题出在哪里。因此我们需要未雨绸缪做好准备,否者等问题发生时才通过漫无目的的查找日志,不但时间成本太高,并且不见得有效。

SOA,分布式,微服务….虽然带来了高可用和可扩展,但是同时也将系统架构的复杂度提升了好几个等级。经常我们会发现一个服务的不可用,是由于例外一个它依赖的服务导致的。持续交付和代码的不断更改,生产环境错误被找到的速度越来越快。然而如今,我们面对更大的困难是当错误发生时,我们如何提取错误的状态,比如变量值,错误,甚至逻辑代码块。

目前主流的解决方案有如下几种:

  1. 分布式日志
  2. 高级的jstack
  3. Btrack
  4. 定制的JVM代理

分布式日志

分布式日志,就是我们每行日志都有清楚的上下文,我们只需要通过这行日志就能知道整个RPC调用链上发生的整个情况。对于分布式日志系统,业界成熟的产品有淘宝的鹰眼点评的cat。原理就是RPC的第一跳,就生成一个全局唯一的UUID,该UUID会在整个RPC调用链中传递,并在需要打印日志的地方表现出来。很多日志库可以修改MDC(Mapped Diagnostic Context)来实现,如果没有也可以通过ThreadLocal来实现。至于该UUID如何在RPC调用链上传递,就需要自己在协议层面完善了。于此同时我们还可以结合Logstash或者Loggly等日志管理工具,来简化日志管理。当然也有很多公司,通过rsyslogsyslog-ng甚至通过rsync来实现日志的集中化管理。

导致线程终结的未捕获异常点,通常包含许多有用信息。绝大多数的框架能够将这些异常信息打印出来,如果要自己实现,可以通过一个全局的Exception Handler来实现。在未捕获的异常发生时,我们在打印日志时,注意以下的3点。

  1. 线程名字:根据你请求的参数来修改线程名,比如RPCID或者事务ID,这样我们查找日志时,便能一眼知道该线程在干嘛。
  2. ThreadLocal(TLS):在未捕获异常发生时,我们最好将ThreadLocal中的数据打印出来。因为除了数据和线程的名字,没有太多的程序能够到达异常点来记录TLS中的数据。这些现场数据保留的越多越好,当你追查问题时,便会从中受益。
  3. MDC:它类似与TLS,MDC是Log4j或者Logback日志框架的一部分。它就是在指定的日志级别上创建了一个静态Map,相比TLS,它的功能更高级些。

先发制人的Jstack

jstack作为一款jdk自带的强大工具,被大多数的程序员所熟悉。它能够hook进正在运行的程序和输出被hook程序的堆栈,数据帧,Java虚拟机或者native,锁以及其它各种各样的元数据,它还能分析已经dump出来的堆栈信息。

虽然它很强大,但是我们都主要用在问题已出的事后,通过它来寻找蛛丝马迹定位问题所在。如果说能够在问题发生前或者问题发生中,我们就能够知道,并且将现场给保存下来,那么这无疑会降低问题的定位难度。下面给出一个当吞吐量达到一定阀值,自动jstack的例子。具体代码详见链接

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
public void startScheduleTask() {


scheduler.scheduleAtFixedRate(new Runnable() {

public void run() {


checkThroughput();


}

}, APP_WARMUP, POLLING_CYCLE, TimeUnit.SECONDS);

}


private void checkThroughput()

{

int throughput = adder.intValue(); //the adder is inc’d when a message is processed


if (throughput < MIN_THROUGHPUT) {

Thread.currentThread().setName("Throughput jstack thread: " + throughput);

System.err.println("Minimal throughput failed: executing jstack");

executeJstack(); // See the code on GitHub to learn how this is done

}


adder.reset();

}

有状态的Jstack

Jstack存在的例外一个问题就是,虽然他提供了非常丰富的元数据,但是我们缺乏导致错误的实际状态。我们可以设置线程名称来解决。为了能够找到错误的根源,我们需要的不仅仅是一个堆栈追踪信息。我们以数据库查询为例,我们在程序中加入这样一行代码:

1
Thread.currentThread().setName(Context + TID + Params + current Time, ...);

没有设置前,数据的元数据如下:

1
“ pool-1-thread-1 ″ #17 prio=5 os_prio=31 tid=0x00007f9d620c9800 nid=0x6d03 in Object.wait() [0x000000013ebcc000]

现在看起来是这样的:

1
”Queue Processing Thread, MessageID: AB5CAD, type: AnalyzeGraph, queue: ACTIVE_PROD, Transaction_ID: 5678956, Start Time: 10/8/2014 18:34″ #17 prio=5 os_prio=31 tid=0x00007f9d620c9800 nid=0x6d03 in Object.wait() [0x000000013ebcc000]

现在的输出可以帮助我们更好的了解程序到底发生了什么。现在我们可以知道线程接收的参数,事务ID,消息ID。有了这些参数,我们就可以追溯问题,发现错误和解决问题。

BTrace

不论是日志还是jstack都不能对JVM的运行状态进行很好的可视化,BTrace使用Java的Attach技术,可以让我们无缝的将我们BTrace脚本挂到JVM上。通过脚本你可以获取到任何你想拿到的数据,在侵入性和安全性上都非常可靠,特别是定位线上问题的神器。BTrace的详细使用,可以见我的例外一篇文章

让我们简单的看一段BTrace脚本:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
@BTrace
class Profiling {
@Property
Profiler profiler = BTraceUtils.Profiling.newProfiler();

@OnMethod(clazz = "/info\\.yangguo\\..*/", method = "/.*/")
void entry(@ProbeMethodName(fqn = true) String probeMethod) {
BTraceUtils.Profiling.recordEntry(profiler, probeMethod);
}

@OnMethod(clazz = "/info\\.yangguo\\..*/", method = "/.*/", location = @Location(value = Kind.RETURN))
void exit(@ProbeMethodName(fqn = true) String probeMethod, @Duration long duration) {
BTraceUtils.Profiling.recordExit(profiler, probeMethod, duration);
}

@OnTimer(5000)
void timer() {
BTraceUtils.Profiling.printSnapshot("Performance profile", profiler);
}
}

BTrace是定位具体问题的有效工具,但是它的开销是非常显著的,使用的时候要小心,避免过高的开销影响重要业务。

自定义代理

跟BTrace一样,我们也可以自己定义Java代理。在Java SE5中,Instrument就已经被加入,Java SE6中,更是实现了动态Instrument。Instrument功能从本地代码中解放出来,使之可以使用使用Java代码在不改变现有代码的前提下,在不重启应用的前提下实现对JVM的监测甚至替换和修改某些类的定义。它有点类似于虚拟机级别的AOP,使开发者不用对jdk做任何改动,就可以实现AOP功能。BTrace的实现就是依靠该功能实现的。

“java.lang.instrument”包的具体实现,依赖于 JVMTI。JVMTI(Java Virtual Machine Tool Interface)是一套由 Java 虚拟机提供的,为 JVM 相关的工具提供的本地编程接口集合。JVMTI 是从 Java SE 5 开始引入,整合和取代了以前使用的 Java Virtual Machine Profiler Interface (JVMPI) 和 the Java Virtual Machine Debug Interface (JVMDI),而在 Java SE 6 中,JVMPI 和 JVMDI 已经消失了。JVMTI 提供了一套”代理”程序机制,可以支持第三方工具程序以代理的方式连接和访问 JVM,并利用 JVMTI 提供的丰富的编程接口,完成很多跟 JVM 相关的功能。

另外,对 native 的 Instrumentation 也是 Java SE 6 的一个崭新的功能,这使以前无法完成的功能 —— 对 native 接口的 instrumentation 可以在 Java SE 6 中,通过一个或者一系列的 prefix 添加而得以完成。

测试代码可以具体参考该项目中的attch_api包下面的代码。

结论

很多时候个人价值的体现就是当有问题发生时,看谁能够更快速的解决问题。今天对于一个需要提供7*24小时服务的应用来说,别说停机,就是部分服务出现问题都是不可容忍的。谁能在最短的时间修复问题,并且快速部署,谁就更能创造价值。