検索
ホームページ運用・保守Linuxの運用と保守Linux コマンド収集用動的追跡ツール (詳細な例)

この記事では、strace、arthas、bpftrace など、仕事でよく使用される動的トレース ツールを含む Linux コマンド動的トレース ツールに関する知識を提供します。みんなが助けてくれることを願っています。

Linux コマンド収集用動的追跡ツール (詳細な例)

スレッドとメモリの分析では、プロセス全体の状況を観察することしかできません。メソッド test()、pass を呼び出すときなど、特定のメソッド レベルを観察する必要がある場合があります。 in パラメータは何ですか、戻り値は何ですか、そしてそれにかかる時間はどれくらいですか?この場合、strace、arthas、bpftrace、systemtap などの動的トレース ツールを使用する必要があります。

strace と ltrace

strace は、Linux のシステム コールを観察するために使用されるツールです。オペレーティング システムの原理を学習したことのある人なら誰でも知っています。アプリケーションは多数のシステム コール インターフェイスを公開しており、メモリ、ファイル、ネットワーク IO 操作の適用など、アプリケーションはこれらのシステム コール インターフェイスを通じてのみオペレーティング システムにアクセスできます。

使用法は次のとおりです:

# -T 打印系统调用花费的时间
# -tt 打印系统调用的时间点
# -s 输出的最大长度,默认32,对于调用参数较长的场景,建议加大
# -f 是否追踪fork出来子进程的系统调用,由于服务端服务普通使用线程池,建议加上
# -p 指定追踪的进程pid
# -o 指定追踪日志输出到哪个文件,不指定则直接输出到终端
$ strace -T -tt -f -s 10000 -p 87 -o strace.log

インスタンス: 実際に送信された SQL をキャプチャします

場合によっては、コード SQL にはまったく問題ありませんが、データが見つかりません。これはおそらく、プロジェクト内の一部の基礎となるフレームワークによって SQL が書き換えられ、送信される実際の SQL がコード内の SQL と異なることが原因であると考えられます。

この状況に遭遇した場合は、基礎となるフレームワーク コードを急いで掘り出さないでください。さらに時間がかかります。結局のところ、プログラマの時間は貴重です。そうしないと、残業しなければなりません。どうすればすぐに見つけられますか?これが原因かどうかを確認してください?毛糸ですか?

方法は 2 つあります。1 つ目は Wireshark を使用してパケットをキャプチャする方法で、2 つ目はこの記事で紹介した strace です。プログラムはネットワーク IO 関連のシステム コールを通じて SQL コマンドをデータベースに送信する必要があるため、必要な作業は、strace を使用してすべてのシステム コールを追跡し、次のように SQL を送信するシステム コールを grep するだけです。画像、mysql jdbc ドライバーは、sendto システム コールを介して SQL を送信し、recvfrom を介して戻り結果を取得します。SQL は文字列であるため、strace が自動的にそれを識別するのに役立ちますが、戻り結果を識別するのは簡単ではないことがわかります。これはバイナリであり、mysql プロトコルに精通している場合にのみ必要です。

また、SQLの実行に時間がかかることは、同じスレッド番号でsendtoとrecvfromの時間差を計算するだけで簡単にわかります。 Linux コマンド収集用動的追跡ツール (詳細な例)

ltrace

ほとんどのプロセスは基本的に、Linux の glibc、Windows の glibc、msvc などのシステム コールの代わりに基本的な C ライブラリを使用するためです。

$ strace -T -tt -f -s 10000 -p 87 |& tee strace.log
基本的な使用法は strace と同じです。一般的には、strace を使用するだけで十分です。

arthas

arthas は Java の動的追跡ツールで、Java メソッドの呼び出しパラメータや戻り値などを監視できます。さらに、逆コンパイル、スレッドプロファイリング、ヒープメモリダンプ、フレームグラフなど、多くの実用的な機能も提供します。 ダウンロードして使用してください

$ ltrace -T -tt -f -s 10000 -p 87 -o ltrace.log

監視、トレース、スタック

arthas では、 watch、trace、および stack コマンドは、次のようにメソッド呼び出しを監視できます。

# 下载arthas
$ wget https://arthas.aliyun.com/download/3.4.6?mirror=aliyun -O arthas-packaging-3.4.6-bin.zip
# 解压
$ unzip arthas-packaging-3.4.6-bin.zip -d arthas && cd arthas/
# 进入arthas命令交互界面
$ java -jar arthas-boot.jar `pgrep -n java`
[INFO] arthas-boot version: 3.4.6
[INFO] arthas home: /home/work/arthas
[INFO] Try to attach process 3368243
[INFO] Attach process 3368243 success.
[INFO] arthas-client connect 127.0.0.1 3658
  ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.
 /  O  \ |  .--. ''--.  .--'|  '--'  | /  O  \ '   .-'
|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.
|  | |  ||  |\  \    |  |   |  |  |  ||  | |  |.-'    |
`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'
wiki      https://arthas.aliyun.com/doc
tutorials https://arthas.aliyun.com/doc/arthas-tutorials.html
version   3.4.6
pid       3368243
time      2021-11-13 13:35:49
# help可查看arthas提供了哪些命令
[arthas@3368243]$ help
# help watch可查看watch命令具体用法
[arthas@3368243]$ help watch
ognl 式の構文が次のとおりである限り、watch、trace、および stack コマンドで条件式を指定できることがわかります。 met、ognl の完全な構文 これは非常に複雑です。一般的に使用されるものをいくつか示します:

##ognl

Linux コマンド収集用動的追跡ツール (詳細な例)

Through ognl コマンドを使用すると、次のように静的変数の値を直接表示できます。

# watch观测执行的查询SQL,-x 3指定对象展开层级
[arthas@3368243]$ watch org.apache.ibatis.executor.statement.PreparedStatementHandler parameterize '{target.boundSql.sql,target.boundSql.parameterObject}' -x 3
method=org.apache.ibatis.executor.statement.PreparedStatementHandler.parameterize location=AtExit
ts=2021-11-13 14:50:34; [cost=0.071342ms] result=@ArrayList[
    @String[select id,log_info,create_time,update_time,add_time from app_log where id=?],
    @ParamMap[
        @String[id]:@Long[41115],
        @String[param1]:@Long[41115],
    ],
]
# watch观测耗时超过200ms的SQL
[arthas@3368243]$ watch com.mysql.jdbc.PreparedStatement execute '{target.toString()}' 'target.originalSql.contains("select") && #cost > 200' -x 2
Press Q or Ctrl+C to abort.
Affect(class count: 3 , method count: 1) cost in 123 ms, listenerId: 25
method=com.mysql.jdbc.PreparedStatement.execute location=AtExit
ts=2021-11-13 14:58:42; [cost=1001.558851ms] result=@ArrayList[
    @String[com.mysql.jdbc.PreparedStatement@6283cfe6: select count(*) from app_log],
]
# trace追踪方法耗时,层层追踪,就可找到耗时根因,--skipJDKMethod false显示jdk方法耗时,默认不显示
[arthas@3368243]$ trace com.mysql.jdbc.PreparedStatement execute 'target.originalSql.contains("select") && #cost > 200'  --skipJDKMethod false
Press Q or Ctrl+C to abort.
Affect(class count: 3 , method count: 1) cost in 191 ms, listenerId: 26
---ts=2021-11-13 15:00:40;thread_name=http-nio-8080-exec-47;id=76;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@5a2d131d
    ---[1001.465544ms] com.mysql.jdbc.PreparedStatement:execute()
        +---[0.022119ms] com.mysql.jdbc.PreparedStatement:checkClosed() #1274
        +---[0.016294ms] com.mysql.jdbc.MySQLConnection:getConnectionMutex() #57
        +---[0.017862ms] com.mysql.jdbc.PreparedStatement:checkReadOnlySafeStatement() #1278
        +---[0.008996ms] com.mysql.jdbc.PreparedStatement:createStreamingResultSet() #1294
        +---[0.010783ms] com.mysql.jdbc.PreparedStatement:clearWarnings() #1296
        +---[0.017843ms] com.mysql.jdbc.PreparedStatement:fillSendPacket() #1316
        +---[0.008543ms] com.mysql.jdbc.MySQLConnection:getCatalog() #1320
        +---[0.009293ms] java.lang.String:equals() #57
        +---[0.008824ms] com.mysql.jdbc.MySQLConnection:getCacheResultSetMetadata() #1328
        +---[0.009892ms] com.mysql.jdbc.MySQLConnection:useMaxRows() #1354
        +---[1001.055229ms] com.mysql.jdbc.PreparedStatement:executeInternal() #1379
        +---[0.02076ms] com.mysql.jdbc.ResultSetInternalMethods:reallyResult() #1388
        +---[0.011517ms] com.mysql.jdbc.MySQLConnection:getCacheResultSetMetadata() #57
        +---[0.00842ms] com.mysql.jdbc.ResultSetInternalMethods:getUpdateID() #1404
        ---[0.008112ms] com.mysql.jdbc.ResultSetInternalMethods:reallyResult() #1409
# stack追踪方法调用栈,找到耗时SQL来源
[arthas@3368243]$ stack com.mysql.jdbc.PreparedStatement execute 'target.originalSql.contains("select") && #cost > 200'
Press Q or Ctrl+C to abort.
Affect(class count: 3 , method count: 1) cost in 138 ms, listenerId: 27
ts=2021-11-13 15:01:55;thread_name=http-nio-8080-exec-5;id=2d;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@5a2d131d
    @com.mysql.jdbc.PreparedStatement.execute()
        at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:493)
        at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:63)
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79)
        at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63)
        at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:326)
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
        at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:136)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)
        at sun.reflect.GeneratedMethodAccessor75.invoke(null:-1)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:433)
        at com.sun.proxy.$Proxy113.selectOne(null:-1)
        at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:166)
        at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:83)
        at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)
        at com.sun.proxy.$Proxy119.selectCost(null:-1)
        at com.demo.example.web.controller.TestController.select(TestController.java:57)
その他のコマンド

arthas は jvm ディスクも提供します、スレッド分析、ヒープ ダンプ、逆コンパイル、フレーム グラフ、その他の機能は次のとおりです:

# 调用System.getProperty静态函数,查看jvm默认字符编码
[arthas@3368243]$ ognl '@System@getProperty("file.encoding")'
@String[UTF-8]
# 找到springboot类加载器
[arthas@3368243]$ classloader -t
+-BootstrapClassLoader
+-sun.misc.Launcher$ExtClassLoader@492691d7
  +-sun.misc.Launcher$AppClassLoader@764c12b6
    +-org.springframework.boot.loader.LaunchedURLClassLoader@4361bd48
# 获取springboot中所有的beanName,-c指定springboot的classloader的hash值
# 一般Spring项目,都会定义一个SpringUtil的,用于获取bean容器ApplicationContext
[arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.beanFactory.beanDefinitionNames'
@String[][
    @String[org.springframework.context.annotation.internalConfigurationAnnotationProcessor],
    @String[org.springframework.context.annotation.internalAutowiredAnnotationProcessor],
    @String[org.springframework.context.annotation.internalCommonAnnotationProcessor],
    @String[testController],
    @String[apiController],
    @String[loginService],
    ...
]
# 获取springboot配置,如server.port是配置http服务端口的
[arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.getEnvironment().getProperty("server.port")'
@String[8080]
# 查看server.port定义在哪个配置文件中
# 可以很容易看到,server.port定义在application-web.yml
[arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.environment.propertySources.propertySourceList.{? containsProperty("server.port")}'
@ArrayList[
    @ConfigurationPropertySourcesPropertySource[ConfigurationPropertySourcesPropertySource {name='configurationProperties'}],
    @OriginTrackedMapPropertySource[OriginTrackedMapPropertySource {name='applicationConfig: [classpath:/application-web.yml]'}],
]
# 调用springboot中bean的方法,获取返回值
[arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.getBean("demoMapper").queryOne(12)' -x 2
@ArrayList[
    @HashMap[
        @String[update_time]:@Timestamp[2021-11-09 18:38:13,000],
        @String[create_time]:@Timestamp[2021-04-17 15:52:55,000],
        @String[log_info]:@String[TbTRNsh2SixuFrkYLTeb25a6zklEZj0uWANKRMe],
        @String[id]:@Long[12],
        @String[add_time]:@Integer[61],
    ],
]
# 查看springboot自带tomcat的线程池的情况
[arthas@3368243]$ ognl -c 4361bd48 '#context=@com.demo.example.web.SpringUtil@applicationContext, #context.webServer.tomcat.server.services[0].connectors[0].protocolHandler.endpoint.executor'
@ThreadPoolExecutor[
    sm=@StringManager[org.apache.tomcat.util.res.StringManager@16886f49],
    submittedCount=@AtomicInteger[1],
    threadRenewalDelay=@Long[1000],
    workQueue=@TaskQueue[isEmpty=true;size=0],
    mainLock=@ReentrantLock[java.util.concurrent.locks.ReentrantLock@69e9cf90[Unlocked]],
    workers=@HashSet[isEmpty=false;size=10],
    largestPoolSize=@Integer[49],
    completedTaskCount=@Long[10176],
    threadFactory=@TaskThreadFactory[org.apache.tomcat.util.threads.TaskThreadFactory@63c03c4f],
    handler=@RejectHandler[org.apache.tomcat.util.threads.ThreadPoolExecutor$RejectHandler@3667e559],
    keepAliveTime=@Long[60000000000],
    allowCoreThreadTimeOut=@Boolean[false],
    corePoolSize=@Integer[10],
    maximumPoolSize=@Integer[8000],
]
arthas はもはや単純な動的追跡ツールではないことがわかります。 jvm。

bpftrace

arthas は Java プログラムのみを追跡でき、ネイティブ プログラム (MySQL など) については何もできません。幸いなことに、Linux エコシステムは次のことを提供します。 perf、bpftrace、systemtap などのネイティブ プログラムの呼び出しを追跡するための仕組みとサポート ツールが多数あります。 bpftrace は使い方が比較的難しいため、この記事では主に使い方を紹介します。 bpftrace は、ebpf テクノロジーに基づく動的追跡ツールです。ebpf テクノロジーをカプセル化し、スクリプト言語を実装します。上で紹介した arthas が ognl に基づいているのと同じように、実装するスクリプト言語は awk に似ています。共通のステートメントをカプセル化します。次のようにブロックし、組み込み変数と組み込み関数を提供します。

# 显示耗cpu较多的前4个线程
[arthas@3368243]$ thread -n 4
"C2 CompilerThread0" [Internal] cpuUsage=8.13% deltaTime=16ms time=46159ms
"C2 CompilerThread1" [Internal] cpuUsage=4.2% deltaTime=8ms time=47311ms
"C1 CompilerThread2" [Internal] cpuUsage=3.06% deltaTime=6ms time=17402ms
"http-nio-8080-exec-40" Id=111 cpuUsage=1.29% deltaTime=2ms time=624ms RUNNABLE (in native)
    at java.net.SocketInputStream.socketRead0(Native Method)
    ...
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4113)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2818)
    ...
    at com.demo.example.web.controller.TestController.select(TestController.java:57)
# 堆转储
[arthas@3368243]$ heapdump
Dumping heap to /tmp/heapdump2021-11-13-15-117226383240040009563.hprof ...
Heap dump file created
# cpu火焰图,容器环境下profiler start可能用不了,可用profiler start -e itimer替代
[arthas@3368243]$ profiler start
Started [cpu] profiling
[arthas@3368243]$ profiler stop
OK
profiler output file: /home/work/app/arthas-output/20211113-151208.svg
# dashboard就类似Linux下的top一样,可看jvm线程、堆内存的整体情况
[arthas@3368243]$ dashboard
# jvm就类似Linux下的ps一样,可以看jvm进程的一些基本信息,如:jvm参数、类加载、线程数、打开文件描述符数等
[arthas@3368243]$ jvm
# 反编译
[arthas@3368243]$ jad com.demo.example.web.controller.TestController

例: 呼び出し側で遅い SQL を追跡する

前面我们用strace追踪过mysql的jdbc驱动,它使用sendto与recvfrom系统调用来与mysql服务器通信,因此,我们在sendto调用时,计下时间点,然后在recvfrom结束时,计算时间之差,就可以得到相应SQL的耗时了,如下:

先找到sendto与recvfrom系统调用在bpftrace中的追踪点,如下:

# 查找sendto|recvfrom系统调用的追踪点,可以看到sys_enter_开头的追踪点应该是进入时触发,sys_exit_开头的退出时触发
$ sudo bpftrace -l '*tracepoint:syscalls*' |grep -E 'sendto|recvfrom'
tracepoint:syscalls:sys_enter_sendto  
tracepoint:syscalls:sys_exit_sendto   
tracepoint:syscalls:sys_enter_recvfrom  
tracepoint:syscalls:sys_exit_recvfrom 
# 查看系统调用参数,方便我们编写脚本
$ sudo bpftrace -lv tracepoint:syscalls:sys_enter_sendto
tracepoint:syscalls:sys_enter_sendto
    int __syscall_nr;
    int fd;
    void * buff;
    size_t len;
    unsigned int flags;
    struct sockaddr * addr;
    int addr_len;

编写追踪脚本trace_slowsql_from_syscall.bt,脚本代码如下:

#!/usr/local/bin/bpftrace
BEGIN {
    printf("Tracing jdbc SQL slower than %d ms by sendto/recvfrom syscall\n", $1);
    printf("%-10s %-6s %6s %s\n", "TIME(ms)", "PID", "MS", "QUERY");
}
tracepoint:syscalls:sys_enter_sendto /comm == "java"/ {
    // mysql协议中,包开始的第5字节指示命令类型,3代表SQL查询
    $com = *(((uint8 *) args->buff)+4);
    if($com == (uint8)3){
        @query[tid]=str(((uint8 *) args->buff)+5, (args->len)-5);
        @start[tid]=nsecs;
    }
}
tracepoint:syscalls:sys_exit_recvfrom /comm == "java" && @start[tid]/ {
    $dur = (nsecs - @start[tid]) / 1000000;
    if ($dur > $1) {
        printf("%-10u %-6d %6d %s\n", elapsed / 1000000, pid, $dur, @query[tid]);
    }
    delete(@query[tid]);
    delete(@start[tid]);
}

其中,comm表示进程名称,tid表示线程号,@query[tid]与@start[tid]类似map,以tid为key的话,这个变量就像一个线程本地变量了。

调用上面的脚本,可以看到各SQL执行耗时,如下:

$ sudo BPFTRACE_STRLEN=80 bpftrace trace_slowsql_from_syscall.bt
Attaching 3 probes...
Tracing jdbc SQL slower than 0 ms by sendto/recvfrom syscall
TIME(ms)   PID        MS QUERY
6398       3368243    125 select sleep(0.1)
16427      3368243     22 select id from app_log al order by id desc limit 1
16431      3368243     20 select id,log_info,create_time,update_time,add_time from app_log where id=11692
17492      3368243     21 select id,log_info,create_time,update_time,add_time from app_log where id=29214

实例:在服务端追踪慢SQL

从调用端来追踪SQL耗时,会包含网络往返时间,为了得到更精确的SQL耗时,我们可以写一个追踪服务端mysql的脚本,来观测SQL耗时,如下:

确定mysqld服务进程的可执行文件与入口函数

$ which mysqld
/usr/local/mysql/bin/mysqld
# objdump可导出可执行文件的动态符号表,做几张mysqld的火焰图就可发现,dispatch_command是SQL处理的入口函数
# 另外,由于mysql是c++写的,方法名是编译器改写过的,这也是为啥下面脚本中要用*dispatch_command*模糊匹配
$ objdump -tT /usr/local/mysql/bin/mysqld | grep dispatch_command
00000000014efdf3 g     F .text  000000000000252e              _Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command
00000000014efdf3 g    DF .text  000000000000252e  Base        _Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command

使用uprobe追踪dispatch_command的调用,如下:

#!/usr/bin/bpftrace
BEGIN{
    printf("Tracing mysqld SQL slower than %d ms. Ctrl-C to end.\n", $1);
    printf("%-10s %-6s %6s %s\n", "TIME(ms)", "PID", "MS", "QUERY");
}
uprobe:/usr/local/mysql/bin/mysqld:*dispatch_command*{
    if (arg2 == (uint8)3) {
        @query[tid] = str(*arg1);
        @start[tid] = nsecs;
    }
}
uretprobe:/usr/local/mysql/bin/mysqld:*dispatch_command* /@start[tid]/{
    $dur = (nsecs - @start[tid]) / 1000000;
    if ($dur > $1) {
        printf("%-10u %-6d %6d %s\n", elapsed / 1000000, pid, $dur, @query[tid]);
    }
    delete(@query[tid]);
    delete(@start[tid]);
}

追踪脚本整体上与之前系统调用版本的类似,不过追踪点不一样而已。

实例:找出扫描大量行的SQL

众所周知,SQL执行时需要扫描数据,并且扫描的数据越多,SQL性能就会越差。

但对于一些中间情况,SQL扫描行数不多也不少,如2w条。且这2w条数据都在缓存中的话,SQL执行时间不会很长,导致没有记录在慢查询日志中,但如果这样的SQL并发量大起来的话,会非常耗费CPU。

对于mysql的话,扫描行的函数是row_search_mvcc(如果你经常抓取mysql栈的话,很容易发现这个函数),每扫一行调用一次,如果在追踪脚本中追踪此函数,记录下调用次数,就可以观测SQL的扫描行数了,如下:

#!/usr/bin/bpftrace
BEGIN{
    printf("Tracing mysqld SQL scan row than %d. Ctrl-C to end.\n", $1);
    printf("%-10s %-6s %6s %10s %s\n", "TIME(ms)", "PID", "MS", "SCAN_NUM", "QUERY");
}
uprobe:/usr/local/mysql/bin/mysqld:*dispatch_command*{
    $COM_QUERY = (uint8)3;
    if (arg2 == $COM_QUERY) {
        @query[tid] = str(*arg1);
        @start[tid] = nsecs;
    }
}
uprobe:/usr/local/mysql/bin/mysqld:*row_search_mvcc*{
    @scan_num[tid]++;
}
uretprobe:/usr/local/mysql/bin/mysqld:*dispatch_command* /@start[tid]/{
    $dur = (nsecs - @start[tid]) / 1000000;
    if (@scan_num[tid] > $1) {
        printf("%-10u %-6d %6d %10d %s\n", elapsed / 1000000, pid, $dur, @scan_num[tid], @query[tid]);
    }
    delete(@query[tid]);
    delete(@start[tid]);
    delete(@scan_num[tid]);
}

脚本运行效果如下:

$ sudo BPFTRACE_STRLEN=80 bpftrace trace_mysql_scan.bt 200
Attaching 4 probes...
Tracing mysqld SQL scan row than 200. Ctrl-C to end.
TIME(ms)   PID        MS   SCAN_NUM QUERY
150614     1892        4        300 select * from app_log limit 300
                                    # 全表扫描,慢!
17489      1892      424      43717 select count(*) from app_log                                     
                                    # 大范围索引扫描,慢!
193013     1892      253      20000 select count(*) from app_log where id < 20000                    
                                    # 深分页,会查询前20300条,取最后300条,慢!
213395     1892      209      20300 select * from app_log limit 20000,300                            
                                    # 索引效果不佳,虽然只会查到一条数据,但扫描数据量不会少,慢!
430374     1892      186      15000 select * from app_log where id < 20000 and seq = 15000 limit 1

如上所示,app_log是我建的一张测试表,共43716条数据,其中id字段是自增主键,seq值与id值一样,但没有索引。

可以看到上面的几个场景,不管什么场景,只要扫描行数变大,耗时就会变长,但也都没有超过500毫秒的,原因是这个表很小,数据可以全部缓存在内存中。

可见,像bpftrace这样的动态追踪工具是非常强大的,而且比arthas更加灵活,arthas只能追踪单个函数,而bpftrace可以跨函数追踪。

总结

已经介绍了不少诊断工具了,这里简单概括一下它们的应用场景:

  • 软件资源观测,如ps、lsof、netstat,用来检查进程基本情况,如内存占用、打开哪些文件、创建了哪些连接等。

  • 硬件资源观测,如top、iostat、sar等,类似Windows上任务管理器一样,让你对硬件资源占用以及在进程上情况有个大概了解,最多观测到线程级别,这些工具一般只能指示进一步调查的方向,很少能直接确认原因。

  • 线程与内存剖析,如jstack、jmap等,比较容易分析线程卡住或内存oom问题,而oncpu火焰图容易找出热代码路径,分析高cpu瓶颈,offcpu火焰图则容易找出经常阻塞的代码路径,分析高耗时问题。

  • 动态追踪工具,如arthas、bpftrace等,能追踪到方法调用级,常用于问题需要深入调查的场景,如问题不在代码实现上,而在调用数据上,就像上面row_search_mvcc函数一样,抓火焰图会发现它出现频繁,但由于它是核心函数,这个频繁可能是正常的,也可能是不正常的,需要将调用次数分散到SQL上才能确认。

相关推荐:《Linux视频教程

以上がLinux コマンド収集用動的追跡ツール (詳細な例)の詳細内容です。詳細については、PHP 中国語 Web サイトの他の関連記事を参照してください。

声明
この記事は掘金で複製されています。侵害がある場合は、admin@php.cn までご連絡ください。
Linuxオペレーティングシステムの5つのコアコンポーネントLinuxオペレーティングシステムの5つのコアコンポーネントMay 08, 2025 am 12:08 AM

Linuxオペレーティングシステムの5つのコアコンポーネントは次のとおりです。1。Kernel、2。Systemライブラリ、3。SystemTools、4。SystemServices、5。FileSystem。これらのコンポーネントは、システムの安定した効率的な動作を確保するために連携し、一緒に強力で柔軟なオペレーティングシステムを形成します。

Linuxの5つの重要な要素:説明Linuxの5つの重要な要素:説明May 07, 2025 am 12:14 AM

Linuxの5つのコア要素は、1。Kernel、2。CommandLineインターフェイス、3。ファイルシステム、4。パッケージ管理、5。コミュニティおよびオープンソースです。一緒に、これらの要素はLinuxの性質と機能を定義します。

Linuxオペレーション:セキュリティとユーザー管理Linuxオペレーション:セキュリティとユーザー管理May 06, 2025 am 12:04 AM

Linuxユーザー管理とセキュリティは、次の手順を通じて達成できます。1。sudouseradd-m-gdevelopers-s/bin/bashjohnなどのコマンドを使用して、ユーザーとグループを作成します。 2. bulkly forループとchpasswdコマンドを使用して、ユーザーを作成し、パスワードポリシーを設定します。 3.一般的なエラー、ホームディレクトリ、シェル設定を確認して修正します。 4.強力な暗号化ポリシー、定期的な監査、最低限の権限の原則などのベストプラクティスを実装します。 5.パフォーマンスを最適化し、SUDOを使用し、PAMモジュールの構成を調整します。これらの方法により、ユーザーを効果的に管理でき、システムセキュリティを改善できます。

Linux操作:ファイルシステム、プロセスなどLinux操作:ファイルシステム、プロセスなどMay 05, 2025 am 12:16 AM

Linuxファイルシステムとプロセス管理のコア操作には、ファイルシステム管理とプロセス制御が含まれます。 1)ファイルシステム操作には、MKDIR、RMDIR、CP、MVなどのコマンドを使用したファイルまたはディレクトリの作成、削除、コピー、および移動が含まれます。 2)プロセス管理には、./my_script.sh&、top、killなどのコマンドを使用して、プロセスの開始、監視、殺害が含まれます。

Linux操作:シェルスクリプトと自動化Linux操作:シェルスクリプトと自動化May 04, 2025 am 12:15 AM

シェルスクリプトは、Linuxシステムでコマンドを自動実行するための強力なツールです。 1)シェルスクリプトは、通訳を介して行ごとにコマンドを実行して、可変置換と条件付き判断を処理します。 2)基本的な使用法には、TARコマンドを使用してディレクトリをバックアップするなど、バックアップ操作が含まれます。 3)高度な使用には、サービスを管理するための機能とケースステートメントの使用が含まれます。 4)デバッグスキルには、セットXを使用してデバッグモードを有効にし、コマンドが故障したときにセットEを終了することが含まれます。 5)サブシェル、使用、最適化ループを避けるために、パフォーマンスの最適化をお勧めします。

Linux操作:コア機能の理解Linux操作:コア機能の理解May 03, 2025 am 12:09 AM

Linuxは、UNIXベースのマルチユーザーのマルチタスクオペレーティングシステムで、シンプルさ、モジュール性、オープン性を強調しています。そのコア機能には、ファイルシステム:ツリー構造で整理され、Ext4、XFS、BTRFSなどの複数のファイルシステムをサポートし、DF-Tを使用してファイルシステムタイプを表示します。プロセス管理:PSコマンドを使用してプロセスを表示し、優先度の設定と信号処理を含むPIDを使用してプロセスを管理します。ネットワーク構成:IPアドレスの柔軟な設定とネットワークサービスの管理、およびsudoipaddraddを使用してIPを構成します。これらの機能は、基本的なコマンドと高度なスクリプト自動化を通じて実際の操作に適用され、効率を向上させ、エラーを削減します。

Linux:メンテナンスモードの入力と終了Linux:メンテナンスモードの入力と終了May 02, 2025 am 12:01 AM

Linuxメンテナンスモードに入る方法には次のものがあります。1。grub構成ファイルを編集し、「シングル」または「1」パラメーターを追加し、Grub構成を更新します。 2。GRUBメニューでスタートアップパラメーターを編集し、「シングル」または「1」を追加します。終了メンテナンスモードでは、システムを再起動する必要があります。これらの手順を使用すると、必要に応じてメンテナンスモードをすばやく入力して安全に終了し、システムの安定性とセキュリティを確保できます。

Linuxの理解:定義されたコアコンポーネントLinuxの理解:定義されたコアコンポーネントMay 01, 2025 am 12:19 AM

Linuxのコアコ​​ンポーネントには、カーネル、シェル、ファイルシステム、プロセス管理、メモリ管理が含まれます。 1)カーネル管理システムリソース、2)シェルはユーザーインタラクションインターフェイスを提供します。3)ファイルシステムは複数の形式をサポートします。4)プロセス管理は、フォークなどのシステムコールを通じて実装され、5)メモリ管理は仮想メモリテクノロジーを使用します。

See all articles

ホットAIツール

Undresser.AI Undress

Undresser.AI Undress

リアルなヌード写真を作成する AI 搭載アプリ

AI Clothes Remover

AI Clothes Remover

写真から衣服を削除するオンライン AI ツール。

Undress AI Tool

Undress AI Tool

脱衣画像を無料で

Clothoff.io

Clothoff.io

AI衣類リムーバー

Video Face Swap

Video Face Swap

完全無料の AI 顔交換ツールを使用して、あらゆるビデオの顔を簡単に交換できます。

ホットツール

Safe Exam Browser

Safe Exam Browser

Safe Exam Browser は、オンライン試験を安全に受験するための安全なブラウザ環境です。このソフトウェアは、あらゆるコンピュータを安全なワークステーションに変えます。あらゆるユーティリティへのアクセスを制御し、学生が無許可のリソースを使用するのを防ぎます。

SublimeText3 Mac版

SublimeText3 Mac版

神レベルのコード編集ソフト(SublimeText3)

mPDF

mPDF

mPDF は、UTF-8 でエンコードされた HTML から PDF ファイルを生成できる PHP ライブラリです。オリジナルの作者である Ian Back は、Web サイトから「オンザフライ」で PDF ファイルを出力し、さまざまな言語を処理するために mPDF を作成しました。 HTML2FPDF などのオリジナルのスクリプトよりも遅く、Unicode フォントを使用すると生成されるファイルが大きくなりますが、CSS スタイルなどをサポートし、多くの機能強化が施されています。 RTL (アラビア語とヘブライ語) や CJK (中国語、日本語、韓国語) を含むほぼすべての言語をサポートします。ネストされたブロックレベル要素 (P、DIV など) をサポートします。

メモ帳++7.3.1

メモ帳++7.3.1

使いやすく無料のコードエディター

WebStorm Mac版

WebStorm Mac版

便利なJavaScript開発ツール