排查DataGrip的Mongo驱动执行慢的问题
排查DataGrip的Mongo驱动执行慢的问题
准备工作
- arthas
- DataGrip开源的mongo驱动
- 业务系统.
启动应用程序
xx.xxxx.xxxxx.utils.Application : Started Application in 10.313 seconds (JVM running for 10.995)
启动arthas
java -jar arthas-boot.jar
输入我们应用程序的编号 然后回车,我这里是输入1号,显示下边界面就是输入成功
,---. ,------. ,--------.,--. ,--. ,---. ,---.
/ O \ | .--. ''--. .--'| '--' | / O \ ' .-'
| .-. || '--'.' | | | .--. || .-. |`. `-.
| | | || |\ \ | | | | | || | | |.-' |
`--' `--'`--' '--' `--' `--' `--'`--' `--'`-----'
wiki https://arthas.aliyun.com/doc
tutorials https://arthas.aliyun.com/doc/arthas-tutorials.html
version 3.6.7
main_class
pid 12704
time 2023-02-02 20:21:54
我们可以直接命令行交互,也可以通过web页面交互
在浏览器输入 http://127.0.0.1:8563/ 进入web页面交互
排查思路
目前是在执行 orderExecute 这个方法非常慢
com.xxxx.xxx.utils.service.impl.MongoServiceImpl#orderExecute
我们使用arthas的 trace 命令来对这个函数进行分析排查
我们写一个trace命令来追踪这些方法
trace -E com.xxxx.xxx.utils.service.impl.MongoServiceImpl orderExecute
postman请求业务接口
先执行一次接口,让类加载一下
找到耗时的方法
执行我们上边写的trace命令
trace -E com.xxxx.xxx.utils.service.impl.MongoServiceImpl orderExecute
Press Q or Ctrl+C to abort.
Affect(class count: 2 , method count: 2) cost in 302 ms, listenerId: 6
然后多次执行我们的业务接口
可以发现这个方法占执行时间的百分之97-99(由于打了断点,正常情况下这个业务接口要4-7s左右)可以确定是这个方法在整个流程中执行时间较久
我们继续跟踪这个方法
–skipJDKMethod false 参数可以跟踪包含jdk内的方法
trace -E com.xxx.xxx.utils.service.impl.MongoServiceImpl execute --skipJDKMethod false
之后就继续跟踪耗时较久的方法
到这一步,大概就能看出来耗时出在哪里了。
我们去看一下对应的源码
查看源码
private MongoShell shell;
private Future<MongoShell> shellFuture;
public synchronized MongoShell getShell(@NotNull MongoConnection connection) throws SQLException {
if (this.shell == null) {
try {
//这里获取shell的耗时比较久
this.shell = (MongoShell)this.shellFuture.get();
this.shell.setClient(connection.getService().getMongoClient());
this.shell.eval("use " + connection.getSchema());
} catch (ExecutionException | InterruptedException var3) {
throw new SQLException(var3);
}
}
return this.shell;
}
发现在获取MongoShell的时候会比较慢。最高可能达到4s左右的时间。
class MongoShell(client: MongoClient? = null, engine: Engine? = null) {
private val context = MongoShellContext(engine)
private val wrapper = ValueWrapper(context)
private val converter = MongoShellConverter(context, wrapper)
private val evaluator = MongoShellEvaluator(client, context, converter, wrapper)
private val consoleLog = ConsoleLogSupport(context, converter)
fun setClient(client: MongoClient): Unit = evaluator.setClient(client)
fun eval(@Language("js") script: String): MongoShellResult<*> {
....
....
}
fun close() = evaluator.close()
}
private Future<MongoShell> submitNewShell() {
return executorService.submit(() -> {
//这里会每次都new 一个MongoShell
MongoShell shell = new MongoShell(null, engine);
shell.eval("'initial warm up'");
return shell;
});
}
大概看了下,这个mongoShell是node打包出来的一个用来执行mongo命令的引擎,按理说这个对象可以一直缓存在内存中使用,只需要保持执行的MongoClient不一样即可。
修改源码
public synchronized MongoShell getShell(@NotNull MongoConnection connection) {
if (shell == null) {
try {
//获取MongoShell
shell = MongoShellFactory.getMongoShell();
} catch (InterruptedException e) {
e.printStackTrace();
}
//设置MongoClient
shell.setClient(connection.getService().getMongoClient());
shell.eval("use " + connection.getSchema());
}
return shell;
}
把原来每次都new一个MongoShell改为从Factory获取。
public class MongoShellFactory {
private static Lock lock = new ReentrantLock();
private static Condition awaitCondition = lock.newCondition();
private static int defaultSize = 10;
private static int notUseListSize = 0;
private static int useListSize = 0;
private static Engine engine = Engine.create("js");
private static List<MongoShell> notUseList = new ArrayList<>();
private static List<MongoShell> useList = new ArrayList<>();
//初始化一定数量的MongoShell
public static void initPool(int maxSize){
lock.lock();
try {
defaultSize = maxSize;
for (int i = 0; i < defaultSize; i++) {
notUseList.add(new MongoShell(null,engine));
}
}finally {
notUseListSize = notUseList.size();
lock.unlock();
}
}
//获取未被正在使用的MongoShell
public static MongoShell getMongoShell() throws InterruptedException {
lock.lock();
try {
int diffSize = notUseListSize + useListSize - defaultSize;
if (diffSize > 0){
for (int i = 0; i < diffSize; i++) {
notUseList.add(new MongoShell(null,engine));
notUseListSize++;
}
}
if (notUseList.isEmpty()){
//wait
awaitCondition.await();
}
MongoShell mongoShell = notUseList.remove(0);
useList.add(mongoShell);
return mongoShell;
}finally {
useListSize++;
notUseListSize--;
lock.unlock();
}
}
//归还正在使用的MongoShell
public static void close(MongoShell mongoShell){
lock.lock();
try {
notUseList.add(mongoShell);
awaitCondition.signal();
for (int i = 0; i < useList.size(); i++) {
MongoShell useMongoShell = useList.get(i);
if (useMongoShell.toString().equals(mongoShell.toString())){
useList.remove(i);
}
}
}finally {
notUseListSize++;
useListSize--;
lock.unlock();
}
}
}
打包验证
我们再次追踪 orderExecute接口,可以发现,原先的 execute接口由 5-7s 降到了 平均的 1s 左右。
这这个平均 1s 是 js引擎本地执行mongo命令的时间。