今天聊聊,如何使用mysql profiling调试python mysqldb遇到的性能问题 ?

这两天有几个烂需求,各种各样的统计数据。其中sql语句中含有like 这样的模糊查询,本来这东西不复杂,但mysql like是需要用% %符号的,恰好python的string转义用的也是% …

爬虫太狠,注释下 python mysqldb性能分析的文章原文链接, http://xiaorui.cc/?p=1884

http://xiaorui.cc/2015/08/18/%E4%BD%BF%E7%94%A8profile%E5%88%86%E6%9E%90python-mysqldb%E9%81%87%E5%88%B0%E7%9A%84%E6%80%A7%E8%83%BD%E9%97%AE%E9%A2%98/

这样就造成了不是语法的出错,就是可以顺利执行,但是无法获取正常的数据,蛋疼万分。
还有的时候是,我要确认下sql语句在mysql端到底有没有执行,我相信有些朋友也遇到过这样的问题。 除此之外,还有一个更重要的就是性能问题。要分析出这条sql语句,消耗了多少cpu io。

 当然排查问题的手段有很多,我可以直接mysql -h那台msyql服务器,然后show processlist;查看 。但是processlist是正在执行的,如果我这边的语句本来就很快,就看不到sql语句了。 

对于那种sql拼装的问题,或者是日志的记录都可以用cursor._last_executed来结局。 看名字你就知道他是干嘛的? 上次执行的语句。

下面是是mysqldb输出cursor._last_executed的sql语句。 

另外我们可以在执行sql语句之前,先执行set profiling = 1 ,让他执行调试模式,当然结束之后最好关闭。

我们可以看到每条语句的详细的执行流程。 可以看到autocommit=0 ,那么说明如果你的sql预计是insert update delete类型的,就需要cursor.commit()提交事物的。 


我们可以用show profile for query sql号码,来详细查看每条sql语句的信息。默认只是打印一些时间的消耗。 

我们可以传递更多的show profile参数。 

SHOW PROFILE [type [, type] … ] [FOR QUERY n]   [LIMIT row_count [OFFSET offset]]

type:
ALL  (所有字段)
| BLOCK IO
| CONTEXT SWITCHES
| CPU
| IPC
| MEMORY
| PAGE FAULTS
| SOURCE
| SWAPS

type是可选的,取值范围可以如下:

ALL 显示所有性能信息
BLOCK IO 显示块IO操作的次数
CONTEXT SWITCHES 显示上下文切换次数,不管是主动还是被动
CPU 显示用户CPU时间、系统CPU时间
IPC 显示发送和接收的消息数量
PAGE FAULTS 显示页错误数量
SOURCE 显示源码中的函数名称与位置
SWAPS 显示SWAP的交互次数

那我们再来看看每条sql语句他的IO操作的次数。  当然如果直接用cursor.fetchall() 打印结果,你会看得发蒙。 需要你自己对照官方的文档。对比每个字段是什么意思的。 

你可以现在mysql的cli终端下进行调试sql语句。  他的结果都是格式化好的, 所以你不用发愁像mysqldb驱动那样,需要自己来解析每个字段对照的意思。 

mysql> set profiling = 1;
Empty set, 1 warning (0.00 sec)

mysql> show variables like ‘%profili%’;
+————————+——-+
| Variable_name          | Value |
+————————+——-+
| have_profiling         | YES   |
| profiling              | ON    |
| profiling_history_size | 15    |
+————————+——-+
3 rows in set (0.00 sec)

mysql> show profile for query 11; 
+——————————–+————+ 
| Status | Duration | 
+——————————–+————+ 
| (initialization) | 0.00000425 | 
| checking query cache for query | 0.00004050 | 
| checking permissions | 0.00001050 | 
| Opening tables | 0.00018250 | 
| System lock | 0.00000450 | 
| Table lock | 0.00001775 | 
| init | 0.00001075 | 
| optimizing | 0.00000550 | 
| executing | 0.00002775 | 
| end | 0.00000450 | 
| query end | 0.00000325 | 
| storing result in query cache | 0.00000400 | 
| freeing items | 0.00000400 | 
| closing tables | 0.00000500 | 
| logging slow query | 0.00000300 | 
+——————————–+————+ 
15 rows in set (0.00 sec) 

mysql> show profile cpu for query 12;
+——————————+———–+———-+————+
| Status                       | Duration  | CPU_user | CPU_system |
+——————————+———–+———-+————+
| starting                     |  0.000183 | 0.000000 |   0.000000 |
| checking permissions         |  0.000057 | 0.000000 |   0.000000 |
| checking permissions         |  0.000059 | 0.000000 |   0.000000 |
| init                         |  0.000060 | 0.000000 |   0.000000 |
| Opening tables               |  0.000071 | 0.000000 |   0.000000 |
| System lock                  |  0.000062 | 0.000000 |   0.000000 |
| setup                        |  0.000080 | 0.000000 |   0.001000 |
| creating table               |  0.005052 | 0.003000 |   0.001000 |
| After create                 |  0.000220 | 0.000000 |   0.000000 |
| copy to tmp table            |  0.000244 | 0.000000 |   0.000000 |
| rename result table          | 11.364027 | 8.470864 |  43.612174 |
| end                          |  0.000575 | 0.000000 |   0.001000 |
| Waiting for query cache lock |  0.000062 | 0.000000 |   0.000000 |
| end                          |  0.000075 | 0.000000 |   0.000000 |
| query end                    |  0.000057 | 0.000000 |   0.000000 |
| closing tables               |  0.000061 | 0.000000 |   0.000000 |
| freeing items                |  0.000080 | 0.000000 |   0.000000 |
| logging slow query           |  0.000056 | 0.000000 |   0.000000 |
| logging slow query           |  0.000098 | 0.000000 |   0.000000 |
| cleaning up                  |  0.000059 | 0.000000 |   0.000000 |
+——————————+———–+———-+————+
20 rows in set (0.00 sec)

显示sql语句执行所消耗的cpu及block io磁盘。 

mysql> show profile CPU,SWAPS,BLOCK IO for query 13;
+———————-+———-+———-+————+————–+—————+——-+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | Swaps |
+———————-+———-+———-+————+————–+—————+——-+
| starting             | 0.000694 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| checking permissions | 0.000044 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| Opening tables       | 0.000223 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| System lock          | 0.000127 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| init                 | 0.000238 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| optimizing           | 0.000035 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| statistics           | 0.000045 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| preparing            | 0.000022 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| executing            | 0.000013 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| Sending data         | 0.000418 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| end                  | 0.000020 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| query end            | 0.000008 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| closing tables       | 0.000227 | 0.002000 |   0.000000 |            0 |             0 |     0 |
| freeing items        | 0.001550 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| logging slow query   | 0.000012 | 0.000000 |   0.000000 |            0 |             0 |     0 |
| cleaning up          | 0.000017 | 0.000000 |   0.000000 |            0 |             0 |     0 |
+———————-+———-+———-+————+————–+—————+——-+
16 rows in set (0.00 sec)

就先这样吧….   sql语句的性能优化要从各方面分析,比如 expain 索引命中情况,mysqlslowlog 慢日志。 



对Python及运维开发感兴趣的朋友可以加QQ群 : 478476595 !!!
{ 2000人qq大群内有各厂大牛,常组织线上分享及沙龙,对高性能及分布式场景感兴趣同学欢迎加入该QQ群 }

另外如果大家觉得文章对你有些作用!   帮忙点击广告. 一来能刺激我写博客的欲望,二来好维护云主机的费用.
如果想赏钱,可以用微信扫描下面的二维码. 另外再次标注博客原地址  xiaorui.cc  ……   感谢!
暂无相关产品