• 企业400电话
  • 微网小程序
  • AI电话机器人
  • 电商代运营
  • 全 部 栏 目

    企业400电话 网络优化推广 AI电话机器人 呼叫中心 网站建设 商标✡知产 微网小程序 电商运营 彩铃•短信 增值拓展业务
    关于Oracle listener日志解析利器的使用方法

    前言

    我们在处理数据库的问题的时候,有时在数据库端看不到异常的等待,但是应用却报连接异常。

    这种情况,有可能是在压力还没有传递到数据库,在网络这层已经发生问题了。如连接风暴,此时的数据库listener的进程已经忙不过来,将连接丢弃。(在主机层面可以看到tcpListeneDrop增加)。

    我们如果去看普通的listener日志,看到的东西是这样的:

    ……
    24-FEB-2017 09:11:03 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=sqlplus@mynwdb)(HOST=mynwdb)(USER=appl))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65184)) * establish * mynwdb * 0
    24-FEB-2017 09:11:06 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=STANDARD)(HOST=mynwdb)(USER=appl))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65186)) * establish * mynwdb * 0
    24-FEB-2017 09:11:10 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=STANDARD)(HOST=mynwdb)(USER=appl))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65188)) * establish * mynwdb * 0
    24-FEB-2017 09:11:10 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=STANDARD)(HOST=mynwdb)(USER=appl))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65189)) * establish * mynwdb * 0
    Fri Feb 24 09:11:14 2017
    24-FEB-2017 09:11:14 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65194)) * establish * mynwdb * 0
    24-FEB-2017 09:11:14 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65195)) * establish * mynwdb * 0
    24-FEB-2017 09:11:15 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65196)) * establish * mynwdb * 0
    24-FEB-2017 09:11:15 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65197)) * establish * mynwdb * 0
    24-FEB-2017 09:11:15 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65198)) * establish * mynwdb * 0
    24-FEB-2017 09:11:15 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65199)) * establish * mynwdb * 0
    24-FEB-2017 09:11:15 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65200)) * establish * mynwdb * 0
    24-FEB-2017 09:11:15 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65201)) * establish * mynwdb * 0
    24-FEB-2017 09:11:16 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65202)) * establish * mynwdb * 0
    24-FEB-2017 09:11:16 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65203)) * establish * mynwdb * 0
    24-FEB-2017 09:11:16 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65204)) * establish * mynwdb * 0
    24-FEB-2017 09:11:16 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65205)) * establish * mynwdb * 0
    24-FEB-2017 09:11:16 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65206)) * establish * mynwdb * 0
    24-FEB-2017 09:11:17 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65207)) * establish * mynwdb * 0
    24-FEB-2017 09:11:17 * (CONNECT_DATA=(SID=mynwdb)(CID=(PROGRAM=INVMGR)(HOST=mynwdb)(USER=nusr))) * (ADDRESS=(PROTOCOL=tcp)(HOST=11.22.3.123)(PORT=65208)) * establish * mynwdb * 0
    ……

    这样我们会看的比较晕,不知道里面的连接数变化。

    有一个listener日志的解析利器,可以分析到这种类型的问题。下载见文末。

    用法:lsnr_analyzer.pl -t ‘time rexge' [-h] filename

    如,我们要分析24-FEB-2017 09:30~09:59的连接情况,可以如下操作:

    [ora@mynwdb trace]$ lsnr_analyzer.pl -t '24-FEB-2017 09:[3-5][0-9]' mynwdb_cut1.log
    24-FEB-2017 09:30 => Total:37
    24-FEB-2017 09:31 => Total:50
    24-FEB-2017 09:32 => Total:17
    24-FEB-2017 09:33 => Total:16
    24-FEB-2017 09:34 => Total:19
    24-FEB-2017 09:35 => Total:16
    24-FEB-2017 09:36 => Total:17
    24-FEB-2017 09:37 => Total:16
    24-FEB-2017 09:38 => Total:13
    24-FEB-2017 09:39 => Total:29
    24-FEB-2017 09:40 => Total:43
    24-FEB-2017 09:41 => Total:38
    24-FEB-2017 09:42 => Total:17
    24-FEB-2017 09:43 => Total:16
    24-FEB-2017 09:44 => Total:42
    24-FEB-2017 09:45 => Total:21
    24-FEB-2017 09:46 => Total:16
    24-FEB-2017 09:47 => Total:15
    24-FEB-2017 09:48 => Total:12
    24-FEB-2017 09:49 => Total:25
    24-FEB-2017 09:50 => Total:47
    24-FEB-2017 09:51 => Total:41
    24-FEB-2017 09:52 => Total:21
    24-FEB-2017 09:53 => Total:12
    24-FEB-2017 09:54 => Total:17
    24-FEB-2017 09:55 => Total:16
    24-FEB-2017 09:56 => Total:20
    24-FEB-2017 09:57 => Total:17
    24-FEB-2017 09:58 => Total:17
    24-FEB-2017 09:59 => Total:21
    [ora@mynwdb trace]$

    可以看到,在09:31的时候,有个连接数的增加,到了一分钟50个连接。

    我们可以加-h的参数,breakdown具体是哪些主机连接过来的:

    [ora@mynwdb trace]$ lsnr_analyzer.pl -t '24-FEB-2017 09:[3-5][0-9]' -h mynwdb_cut1.log
    24-FEB-2017 09:30 => Total:37
    11.22.3.123 37
    24-FEB-2017 09:31 => Total:50
    22.3.4.111 1
    11.22.3.123 49
    24-FEB-2017 09:32 => Total:17
    10.8.1.218 1
    11.22.3.123 16
    24-FEB-2017 09:33 => Total:16
    11.22.3.123 16
    24-FEB-2017 09:34 => Total:19
    11.22.3.123 19
    24-FEB-2017 09:35 => Total:16
    11.22.3.123 16
    24-FEB-2017 09:36 => Total:17
    22.3.4.111 1
    11.22.3.123 16
    24-FEB-2017 09:37 => Total:16
    12.5.6.221 1
    11.22.3.123 15
    24-FEB-2017 09:38 => Total:13
    11.22.3.123 13
    24-FEB-2017 09:39 => Total:29
    11.22.3.123 29
    24-FEB-2017 09:40 => Total:43
    11.22.3.123 43
    24-FEB-2017 09:41 => Total:38
    22.3.4.111 1
    11.22.3.123 37
    24-FEB-2017 09:42 => Total:17
    12.5.6.221 1
    11.22.3.123 16
    24-FEB-2017 09:43 => Total:16
    11.22.3.123 16
    24-FEB-2017 09:44 => Total:42
    11.22.3.123 42
    24-FEB-2017 09:45 => Total:21
    11.22.3.123 21
    24-FEB-2017 09:46 => Total:16
    22.3.4.111 1
    11.22.3.123 15
    24-FEB-2017 09:47 => Total:15
    12.5.6.221 1
    11.22.3.123 14
    24-FEB-2017 09:48 => Total:12
    11.22.3.123 12
    24-FEB-2017 09:49 => Total:25
    11.22.3.123 25
    24-FEB-2017 09:50 => Total:47
    11.22.3.123 47
    24-FEB-2017 09:51 => Total:41
    22.3.4.111 1
    11.22.3.123 40
    24-FEB-2017 09:52 => Total:21
    12.5.6.221 1
    11.22.3.123 20
    24-FEB-2017 09:53 => Total:12
    11.22.3.123 12
    24-FEB-2017 09:54 => Total:17
    11.22.3.123 17
    24-FEB-2017 09:55 => Total:16
    11.22.3.123 16
    24-FEB-2017 09:56 => Total:20
    22.3.4.111 1
    11.22.3.123 19
    24-FEB-2017 09:57 => Total:17
    12.5.6.221 1
    11.22.3.123 16
    24-FEB-2017 09:58 => Total:17
    11.22.3.123 17
    24-FEB-2017 09:59 => Total:21
    11.22.3.123 21
    [ora@mynwdb trace]$

    可以看到09:30的时候,是来自11.22.3.123有49个连接,来自22.3.4.111有1个连接。

    注1:lsnr_analyzer.pl 是用来分析已经establish的连接,如果是其他连接,不统计在内。

    注2:lsnr_analyzer.pl 的统计比较消耗cpu,30万行的listener日志分析大约1秒出结果,300万行的listener日志分析大约6秒出结果。所以如果listener日志比较大,建议tail剪切后统计。

    对于已经出现tcpListenDrop的情况,我们分几种情况分析:

    (1)如果是突然的连接风暴,需要控制前端的连接,如weblogic中间件逐台启动,而不是同时启动;

    (2)如果一直连接数很高,导致listener无法处理,就需要拆分listener,如按照端口拆分。

    点击下载:lsnr_analyzer.pl

    总结

    以上就是这篇文章的全部内容了,希望本文的内容对大家的学习或者工作能带来一定的帮助,如果有疑问大家可以留言交流,谢谢大家对脚本之家的支持。

    您可能感兴趣的文章:
    • Oracle 监听器密码设置方法(LISTENER)
    • Oracle Listener 动态注册 与 静态注册
    • oracle 11g的警告日志和监听日志的删除方法
    • ORACLE 报警日志如何查看?
    • Oracle日常维护中管理用户以及重做日志文件的方法
    上一篇:oracle中schema指的是什么意思
    下一篇:Oracle导dmp出现文件ORA-12154: TNS: 无法解析指定的连接标识符问题的解决方案
  • 相关文章
  • 

    © 2016-2020 巨人网络通讯 版权所有

    《增值电信业务经营许可证》 苏ICP备15040257号-8

    关于Oracle listener日志解析利器的使用方法 关于,Oracle,listener,日志,