介绍
- log4jdbc是一个java的jdbc驱动, 可以用于记录SQL日志和SQL执行时间等信息
- log4jdbc使用SLF4J（Simple Logging Facade）作为日志系统, 其特性有:
- 支持JDBC3和JDBC4
- 易于配置: 在大部分情况下，只需要改变驱动类名并在现在jdbc url前加上"jdbc:log4", 设置好日志输出级别即可使用
- 能够自动把SQL变量值加到SQL输出日志中，改进易读性和方便调试
- 可以生成SQL语句的时间, 以供快速标识出应用程序中执行比较慢的SQL语句
- 可以生成SQL连接数信息, 以帮助识别连接池/线程问题
- 支持现有大部分JDBC驱动
使用步骤
- 下载jar包放到lib目录下: log4jdbc4-1.2.jar: 适用于jdk 1.6 & 1.7(或log4jdbc3-1.2.jar: 适用于jdk 1.4 & 1.5)
- 确保lib目录下log4jdbc.jar、log4j.jar、slf4j-api.jar、slf4j-log4j12.jar四个包存在（如果之前lib中存在slf4j-simple.jar需将slf4j-simple.jar移出lib目录）
- 修改当前JDBC driver为net.sf.log4jdbc.DriverSpy，在jdbc url前加上log4jdbc
-
例如你当前使用的jdbc配置为:
com.mysql.jdbc.Driver jdbc:mysql://localhost:1527//db-derby-10.2.2.0-bin/databases/MyDatabase -
将其改为:
net.sf.log4jdbc.DriverSpyjdbc:log4jdbc:mysql://localhost:1527//db-derby-10.2.2.0-bin/databases/MyDatabase
-
- 选择使用的logger及log级别, 并在log4j.xml(若无log4j.xml配置, 将其放在classpath即可)中设定:
- 在log4jdbc有5个log级别: DEBUG < INFO WARN ERROR FATAL DEBUG info warn error fatal p>
- 可以指定log的输出, 我们用到的两个为:
- 标准输出: ConsoleAppender
- 打印至文件: FileAppender
- 重启程序, 当程序对mysql有请求时, 便会打出所配置的log
使用log4jdbc发现的问题
-
在sqltiming的log中看到有多处select xxx from xxx where xxx=xxx;的语句, 怀疑此处的逻辑有问题, 找到相应的code, 发现其原因为开发忘记加用户是否已登陆的逻辑
//格式为：响应时间 请求时刻 sql 3 2013-03-21 13:18:52.790 SELECT COUNT(1) FROM GuideGrade WHERE guideId = 8605588 AND userEmail = 'ppppp2001@126.com' 1 2013-03-21 13:18:52.791 SELECT grade FROM GuideGrade WHERE guideId = 9321748 AND userEmail = ''; 1 2013-03-21 13:18:52.792 UPDATE GuideGrade SET grade = 5, updateTime = '2013-03-21 13:18:52' WHERE guideId = 8585852 AND userEmail = 'dddd2001@163.com' 1 2013-03-21 13:18:52.793 UPDATE GuideGrade SET grade = 1, updateTime = '2013-03-21 13:18:52' WHERE guideId = 8605588 AND userEmail = 'ppppp2001@126.com' 1 2013-03-21 13:18:52.802 UPDATE GuideGrade SET grade = 4, updateTime = '2013-03-21 13:18:52' WHERE guideId = 8516797 AND userEmail = 'eeeeeeee@163.com' 21 2013-03-21 13:18:52.844 SELECT grade FROM GuideGrade WHERE guideId = 8814769 AND userEmail = ''; 1 2013-03-21 13:18:52.853 SELECT grade FROM GuideGrade WHERE guideId = 9249748 AND userEmail = ''; 1 2013-03-21 13:18:52.853 SELECT COUNT(1) FROM UserInfo WHERE userEmail='kkkkkkk@163.com' 0 2013-03-21 13:18:52.854 SELECT COUNT(1) FROM UserInfo WHERE userEmail='kkkkkkk@163.com' 0 2013-03-21 13:18:52.856 SELECT COUNT(1) FROM GuideGrade WHERE guideId = 8643419 AND userEmail = 'kkkkkkk@163.com' 1 2013-03-21 13:18:52.858 UPDATE GuideGrade SET grade = 3, updateTime = '2013-03-21 13:18:52' WHERE guideId = 8643419 AND userEmail = 'kkkkkkk@163.com' 11 2013-03-21 13:18:52.859 SELECT grade FROM GuideGrade WHERE guideId = 9335835 AND userEmail = ''; 1 2013-03-21 13:18:52.880 SELECT grade FROM GuideGrade WHERE guideId = 9191890 AND userEmail = ''; 2 2013-03-21 13:18:52.883 SELECT grade FROM GuideGrade WHERE guideId = 7653493 AND userEmail = ''; 0 2013-03-21 13:18:52.929 SELECT grade FROM GuideGrade WHERE guideId = 8896489 AND userEmail = ''; 1 2013-03-21 13:18:52.932 SELECT COUNT(1) FROM UserInfo WHERE userEmail='hhhhhhhhhhhh@163.com' -
在sqltiming的log中看到有些语句会重复出现, 怀疑此处的逻辑有问题, 找到相应的code, 发现只需select一次即可
//格式为：响应时间 请求时刻 sql 1 2013-03-21 13:18:53.500 SELECT grade FROM GuideGrade WHERE guideId = 8937011 AND userEmail = ''; 1 2013-03-21 13:18:53.541 SELECT COUNT(1) FROM UserInfo WHERE userEmail='xxxxxx8@163.com' 0 2013-03-21 13:18:53.543 SELECT COUNT(1) FROM UserInfo WHERE userEmail='xxxxxx8@163.com' 1 2013-03-21 13:18:53.544 SELECT COUNT(1) FROM UserInfo WHERE userEmail='nnnnnnnnn@126.com' 1 2013-03-21 13:18:53.544 SELECT COUNT(1) FROM UserInfo WHERE userEmail='llllllll@163.com' 0 2013-03-21 13:18:53.545 SELECT COUNT(1) FROM UserInfo WHERE userEmail='llllllll@163.com' 1 2013-03-21 13:18:53.546 SELECT COUNT(1) FROM UserInfo WHERE userEmail='nnnnnnnnn@126.com' 未完待续, 相信你能有更好的分析手段及mysql优化收获
