回顾
大家好，我是老马。
最近 dubbo3.x 在公司内部分享，于是想系统梳理一下。
总体思路是官方文档入门+一些场景的问题思考+源码解析学习。
当Dubbo遇上Arthas：排查问题的实践
Apache Dubbo是Alibaba开源的高性能RPC框架，在国内有非常多的用户。
Arthas是Alibaba开源的应用诊断利器，9月份开源以来，Github Star数三个月超过6000。
当Dubbo遇上Arthas，会碰撞出什么样的火花呢？下面来分享Arthas排查Dubbo问题的一些经验。
dubbo-arthas-demo
下面的排查分享基于这个dubbo-arthas-demo
，非常简单的一个应用，浏览器请求从Spring MVC到Dubbo Client，再发送到Dubbo Server。
Demo里有两个spring boot应用，可以先启动server-demo
，再启动client-demo
。
[plaintext]
1
2/user/{id} -> UserService -> UserServiceImpl
Browser Dubbo Client Dubbo Server
Client端：
[java]
1
2
3
4
5
6
7
8
9@RestController
public class UserController {
@Reference(version = "1.0.0")
private UserService userService;
@GetMapping("/user/{id}")
public User findUserById(@PathVariable Integer id) {
return userService.findUser(id);
}
}
Server端：
[java]
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15@Service(version = "1.0.0")
public class UserServiceImpl implements UserService {
@Override
public User findUser(int id) {
if (id < 1) {
throw new IllegalArgumentException("user id < 1, id: " + id);
}
for (User user : users) {
if (user.getId() == id) {
return user;
}
}
throw new RuntimeException("Can not find user, id: " + id);
}
}
Arthas快速开始
[shell]
1
2$ wget [https://arthas.aliyun.com/arthas-boot.jar ](https://arthas.aliyun.com/arthas-boot.jar )
$ java -jar arthas-boot.jar
启动后，会列出所有的java进程，选择1，然后回车，就会连接上ServerDemoApplication
[shell]
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20$ java -jar arthas-boot.jar
* [1]: 43523 ServerDemoApplication
[2]: 22342
[3]: 44108 ClientDemoApplication
1
[INFO] arthas home: /Users/hengyunabc/.arthas/lib/3.0.5/arthas
[INFO] Try to attach process 43523
[INFO] Attach process 43523 success.
[INFO] arthas-client connect 127.0.0.1 3658
,---. ,------. ,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'
wiki: [https://arthas.aliyun.com/doc ](https://arthas.aliyun.com/doc )
version: 3.0.5
pid: 43523
time: 2018-12-05 16:23:52
$
Dubbo线上服务抛出异常，怎么获取调用参数？
在Arthas里执行 watch com.example.UserService * -e -x 2 '{params,throwExp}'
[shell]
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15$ watch com.example.UserService * -e -x 2 '{params,throwExp}'
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:4) cost in 230 ms.
ts=2018-12-05 16:26:44; [cost=3.905523ms] result=@ArrayList[
@Object[][
@Integer[0],
],
java.lang.IllegalArgumentException: user id < 1, id: 0
at com.example.UserServiceImpl.findUser(UserServiceImpl.java:24)
at com.alibaba.dubbo.common.bytecode.Wrapper1.invokeMethod(Wrapper1.java)
at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:45)
at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:71)
at com.alibaba.dubbo.config.invoker.DelegateProviderMetaDataInvoker.invoke(DelegateProviderMetaDataInvoker.java:48)
at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:52)
at com.alibaba.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:61)
怎样线上调试Dubbo服务代码?
[shell]
1
2$ redefine -p /tmp/UserServiceImpl.class
redefine success, size: 1
怎样动态修改Dubbo的logger级别?
[shell]
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$ ognl '@com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter@logger.logger'
@Log4jLogger[
FQCN=@String[com.alibaba.dubbo.common.logger.support.FailsafeLogger],
logger=@Logger[org.apache.log4j.Logger@2f19bdcf],
]
$ sc -d org.apache.log4j.Logger
class-info org.apache.log4j.Logger
code-source /Users/hengyunabc/.m2/repository/org/slf4j/log4j-over-slf4j/1.7.25/log4j-over-slf4j-1.7.25.jar
name org.apache.log4j.Logger
isInterface false
isAnnotation false
isEnum false
isAnonymousClass false
isArray false
isLocalClass false
isMemberClass false
isPrimitive false
isSynthetic false
simple-name Logger
modifier public
annotation
interfaces
super-class +-org.apache.log4j.Category
+-java.lang.Object
class-loader +-sun.misc.Launcher$AppClassLoader@5c647e05
+-sun.misc.Launcher$ExtClassLoader@59878d35
classLoaderHash 5c647e05
Affect(row-cnt:1) cost in 126 ms.
$ ognl '@org.slf4j.LoggerFactory@getLogger("root").setLevel(@ch.qos.logback.classic.Level@DEBUG)'
null
$ ognl '@org.slf4j.LoggerFactory@getLogger("root").getLevel().toString()'
@String[DEBUG]
怎样减少测试小姐姐重复发请求的麻烦?
[shell]
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24$ tt -t com.example.UserServiceImpl findUser
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 145 ms.
INDEX TIMESTAMP COST(ms) IS-RET IS-EXP OBJECT CLASS METHOD
--------------------------------------------------------------------------------------------------------------------------------
1000 2018-12-05 17:47:52 1.56523 true false 0x3233483 UserServiceImpl findUser
1001 2018-12-05 17:48:03 0.286176 false true 0x3233483 UserServiceImpl findUser
1002 2018-12-05 17:48:11 90.324335 true false 0x3233483 UserServiceImpl findUser
$ tt --play -i 1000
RE-INDEX 1000
GMT-REPLAY 2018-12-05 17:55:50
OBJECT 0x3233483
CLASS com.example.UserServiceImpl
METHOD findUser
PARAMETERS[0] @Integer[1]
IS-RETURN true
IS-EXCEPTION false
RETURN-OBJ @User[
id=@Integer[1],
name=@String[Deanna Borer],
]
Time fragment[1000] successfully replayed.
Affect(row-cnt:1) cost in 4 ms.
Dubbo运行时有哪些Filter? 耗时是多少?
[shell]
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17$ trace com.alibaba.dubbo.rpc.Filter *
Press Ctrl+C to abort.
Affect(class-cnt:19 , method-cnt:59) cost in 1441 ms.
`---ts=2018-12-05 19:07:26;thread_name=DubboServerHandler-30.5.125.152:20880-thread-10;id=3e;is_daemon=true;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@5c647e05
`---[8.435844ms] com.alibaba.dubbo.rpc.filter.EchoFilter:invoke()
+---[0.124572ms] com.alibaba.dubbo.rpc.Invocation:getMethodName()
+---[0.065123ms] java.lang.String:equals()
`---[7.762928ms] com.alibaba.dubbo.rpc.Invoker:invoke()
`---[7.494124ms] com.alibaba.dubbo.rpc.filter.ClassLoaderFilter:invoke()
+---[min=0.00355ms,max=0.049922ms,total=0.057637ms,count=3] java.lang.Thread:currentThread()
+---[0.0126ms] java.lang.Thread:getContextClassLoader()
+---[0.02188ms] com.alibaba.dubbo.rpc.Invoker:getInterface()
+---[0.004115ms] java.lang.Class:getClassLoader()
+---[min=0.003906ms,max=0.014058ms,total=0.017964ms,count=2] java.lang.Thread:setContextClassLoader()
`---[7.033486ms] com.alibaba.dubbo.rpc.Invoker:invoke()
`---[6.869488ms] com.alibaba.dubbo.rpc.filter.GenericFilter:invoke()
+---[0.01481ms] com.alibaba.dubbo.rpc.Invocation:getMethodName()
Dubbo动态代理是怎样实现的?
[java]
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$ jad com.alibaba.dubbo.common.bytecode.Wrapper1
ClassLoader:
+-sun.misc.Launcher$AppClassLoader@5c647e05
+-sun.misc.Launcher$ExtClassLoader@59878d35
Location:
/Users/hengyunabc/.m2/repository/com/alibaba/dubbo/2.5.10/dubbo-2.5.10.jar
package com.alibaba.dubbo.common.bytecode;
public class Wrapper1
extends Wrapper
implements ClassGenerator.DC {
public Object invokeMethod(Object object, String string, Class[] arrclass, Object[] arrobject) throws InvocationTargetException {
UserServiceImpl userServiceImpl;
try {
userServiceImpl = (UserServiceImpl)object;
}
catch (Throwable throwable) {
throw new IllegalArgumentException(throwable);
}
try {
if ("findUser".equals(string) && arrclass.length == 1) {
return userServiceImpl.findUser(((Number)arrobject[0]).intValue());
}
if ("listUsers".equals(string) && arrclass.length == 0) {
return userServiceImpl.listUsers();
}
if ("findUserByName".equals(string) && arrclass.length == 1) {
return userServiceImpl.findUserByName((String)arrobject[0]);
}
}
获取Spring context
[shell]
1
2
3
4
5$ ognl '#context=@com.alibaba.dubbo.config.spring.extension.SpringExtensionFactory@contexts.iterator.next, #context.getBean("userServiceImpl").findUser(1)'
@User[
id=@Integer[1],
name=@String[Deanna Borer],
]
总结
本篇文章来自杭州Dubbo Meetup的分享《当DUBBO遇上Arthas - 排查问题的实践》，希望对大家线上排查Dubbo问题有帮助。
分享的PDF可以在 https://github.com/alibaba/arthas/issues/327 里下载。
