ITPub博客

首页 > 数据库 > Oracle > [20210804]oracle rac执行命令crs_stat -t -v缓慢的分析.txt

[20210804]oracle rac执行命令crs_stat -t -v缓慢的分析.txt

原创 Oracle 作者:lfree 时间:2021-08-04 20:07:32 2 删除 编辑

[20210804]oracle rac执行命令crs_stat -t -v缓慢的分析.txt

--//链接 http://www.itpub.net/thread-2142454-1-1.html的问题:

有一套11.2.0.4的oracle rac上,执行命令 [grid@rac1 ~]$ time crs_stat -t -v 耗时近30秒,有没有兄弟支个招。数据库正常使用,
日志也没有报错,zabbix agent有时候会 agent.ping 超时。网络设备已经检查,没有什么大的异常环境:2台物理机 centos 6.10 ,
oracle rac 11.2.0.4.通过光纤交换机相连,挂载的存储大家有没有排查思路给一个呢?

--//我建议使用 strace -o aa.txt  -r -tT -f  crs_stat -t -v跟踪.
--//真心讲没有看别人的解答,实际上jieyancai已经找到问题根源,/u01/app/11.2.0/grid/log/${HOSTNAME}/client/目录下
--//clscNNN.log文件太多。

$ strace -o aa.txt  -r -tT -f  crs_stat -t -v
...

--//我们生产系统的情况。
$ grep "open" aa.txt | grep clsc|wc
   1288    9018  134173

--//检查aa.txt跟踪文件:
......
20553      0.000031 getcwd("/tmp", 4096) = 5 <0.000008>
20553      0.000025 chdir("/u01/app/11.2.0/grid/log/fyhis1/client") = 0 <0.000008>
20553      0.000026 getcwd("/u01/app/11.2.0/grid/log/fyhis1/client", 4096) = 39 <0.000006>
20553      0.000024 chdir("/tmp")       = 0 <0.000007>
20553      0.000067 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1.log", {st_mode=S_IFREG|0644, st_size=279, ...}) = 0 <0.000012>
20553      0.000051 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1.log", {st_mode=S_IFREG|0644, st_size=279, ...}) = 0 <0.000008>
20553      0.000040 access("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1.log", F_OK) = 0 <0.000009>
20553      0.000029 statfs("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1.log", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=114046550, f_bfree=52695397, f_bavail=46902169, f_files=28966912, f_ffree=28834037, f_fsid={-969085044, 169166933}, f_namelen=255, f_frsize=4096}) = 0 <0.000010>
20553      0.000040 open("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1.log", O_RDONLY) = 3 <0.000010>
20553      0.000044 close(3)            = 0 <0.000007>
......
20553      0.000060 getcwd("/tmp", 4096) = 5 <0.000018>
20553      0.000048 chdir("/u01/app/11.2.0/grid/log/fyhis1/client") = 0 <0.000014>
20553      0.000049 getcwd("/u01/app/11.2.0/grid/log/fyhis1/client", 4096) = 39 <0.000013>
20553      0.000046 chdir("/tmp")       = 0 <0.000013>
20553      0.000096 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1280.log", {st_mode=S_IFREG|0644, st_size=260, ...}) = 0 <0.000017>
20553      0.000080 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1280.log", {st_mode=S_IFREG|0644, st_size=260, ...}) = 0 <0.000015>
20553      0.000072 access("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1280.log", F_OK) = 0 <0.000016>
20553      0.000053 statfs("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1280.log", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=114046550, f_bfree=52695397, f_bavail=46902169, f_files=28966912, f_ffree=28834037, f_fsid={-969085044, 169166933}, f_namelen=255, f_frsize=4096}) = 0 <0.000018>
20553      0.000073 open("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1280.log", O_RDONLY) = 3 <0.000017>
20553      0.000058 close(3)            = 0 <0.000012>
20553      0.000047 getcwd("/tmp", 4096) = 5 <0.000013>
20553      0.000041 chdir("/u01/app/11.2.0/grid/log/fyhis1/client") = 0 <0.000014>
20553      0.000048 getcwd("/u01/app/11.2.0/grid/log/fyhis1/client", 4096) = 39 <0.000014>
20553      0.000048 chdir("/tmp")       = 0 <0.000014>
20553      0.000099 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1281.log", {st_mode=S_IFREG|0644, st_size=262, ...}) = 0 <0.000018>
20553      0.000079 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1281.log", {st_mode=S_IFREG|0644, st_size=262, ...}) = 0 <0.000023>
20553      0.000091 access("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1281.log", F_OK) = 0 <0.000015>
20553      0.000052 statfs("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1281.log", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=114046550, f_bfree=52695397, f_bavail=46902169, f_files=28966912, f_ffree=28834037, f_fsid={-969085044, 169166933}, f_namelen=255, f_frsize=4096}) = 0 <0.000018>
20553      0.000073 open("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1281.log", O_RDONLY) = 3 <0.000017>
20553      0.000058 close(3)            = 0 <0.000012>
...
20553      0.000041 chdir("/u01/app/11.2.0/grid/log/fyhis1/client") = 0 <0.000015>
20553      0.000048 getcwd("/u01/app/11.2.0/grid/log/fyhis1/client", 4096) = 39 <0.000012>
20553      0.000046 chdir("/tmp")       = 0 <0.000012>
20553      0.000092 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1285.log", {st_mode=S_IFREG|0644, st_size=262, ...}) = 0 <0.000017>
20553      0.000080 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1285.log", {st_mode=S_IFREG|0644, st_size=262, ...}) = 0 <0.000015>
20553      0.000072 access("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1285.log", F_OK) = 0 <0.000016>
20553      0.000052 statfs("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1285.log", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=114046550, f_bfree=52695397, f_bavail=46902169, f_files=28966912, f_ffree=28834037, f_fsid={-969085044, 169166933}, f_namelen=255, f_frsize=4096}) = 0 <0.000017>
20553      0.000073 open("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1285.log", O_RDONLY) = 3 <0.000016>
20553      0.000058 close(3)            = 0 <0.000012>
.....
20553      0.000045 getcwd("/tmp", 4096) = 5 <0.000014>
20553      0.000043 chdir("/u01/app/11.2.0/grid/log/fyhis1/client") = 0 <0.000015>
20553      0.000054 getcwd("/u01/app/11.2.0/grid/log/fyhis1/client", 4096) = 39 <0.000012>
20553      0.000046 chdir("/tmp")       = 0 <0.000012>
20553      0.000092 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", 0x7fff0541f8e0) = -1 ENOENT (No such file or directory) <0.000043>
--//执行时/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log文件不存在。
20553      0.000132 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", 0x7fff0541fcd0) = -1 ENOENT (No such file or directory) <0.000015>
20553      0.000151 getrlimit(RLIMIT_NOFILE, {rlim_cur=64*1024, rlim_max=64*1024}) = 0 <0.000012>
20553      0.000122 open("/u01/app/11.2.0/grid/lib/libnque11.so", O_RDONLY) = 3 <0.000019>
20553      0.000056 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\24\0\0\0\0\0\0"..., 832) = 832 <0.000013>
20553      0.000056 fstat(3, {st_mode=S_IFREG|0644, st_size=59021, ...}) = 0 <0.000012>
20553      0.000071 mmap(NULL, 1090528, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f786390d000 <0.000022>
20553      0.000055 mprotect(0x7f7863917000, 1044480, PROT_NONE) = 0 <0.000019>
20553      0.000051 mmap(0x7f7863a16000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x9000) = 0x7f7863a16000 <0.000018>
20553      0.000060 mmap(0x7f7863a17000, 992, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f7863a17000 <0.000015>
20553      0.000045 close(3)            = 0 <0.000012>
...
--//执行代码把/u01/app/11.2.0/grid/log/fyhis1/client目录下clscNNNN.log文件从N=1到1285探查1遍。
20553      0.000225 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", 0x7fff05420190) = -1 ENOENT (No such file or directory) <0.000022>
20553      0.000201 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", 0x7fff054200f0) = -1 ENOENT (No such file or directory) <0.000026>
20553      0.000078 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", 0x7fff0541fb60) = -1 ENOENT (No such file or directory) <0.000015>
20553      0.000065 access("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", F_OK) = -1 ENOENT (No such file or directory) <0.000032>
20553      0.000076 statfs("/u01/app/11.2.0/grid/log/fyhis1/client/", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=114046550, f_bfree=52695397, f_bavail=46902169, f_files=28966912, f_ffree=28834037, f_fsid={-969085044, 169166933}, f_namelen=255, f_frsize=4096}) = 0 <0.000019>
20553      0.000078 open("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 5 <0.000066>
20553      0.000125 close(5)            = 0 <0.000015>
20553      0.000059 chmod("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", 0644) = 0 <0.000022>
20553      0.000066 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 <0.000030>
20553      0.000100 access("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", F_OK) = 0 <0.000017>
20553      0.000054 statfs("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=114046550, f_bfree=52695397, f_bavail=46902169, f_files=28966912, f_ffree=28834036, f_fsid={-969085044, 169166933}, f_namelen=255, f_frsize=4096}) = 0 <0.000017>
20553      0.000076 open("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 5 <0.000022>
20553      0.000074 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 <0.000016>
20553      0.000077 stat("/u01/app/11.2.0/grid/log/fyhis1/client/clsc1286.log", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 <0.000015>
20553      0.000114 write(5, "Oracle Database 11g Clusterware "..., 114) = 114 <0.000044>
20553      0.000134 write(5, "2021-08-03 11:46:42.136: [ CRSCO"..., 73) = 73 <0.000017>
20553      0.000110 write(5, "2021-08-03 11:46:42.136: [ CRSCO"..., 75) = 75 <0.000017>
--//写入信息。时间也和下面的一致。

$ ls -ltr clsc[0-9]*.log  | grep oinstall | head
-rw-r--r-- 1 grid   oinstall  279 2016-12-24 12:18:53 clsc1.log
-rw-r--r-- 1 grid   oinstall 9893 2016-12-24 12:25:39 clsc3.log
-rw-r--r-- 1 oracle oinstall 9893 2016-12-24 12:32:08 clsc4.log
-rw-r--r-- 1 grid   oinstall  358 2016-12-29 11:16:04 clsc28.log
-rw-r--r-- 1 grid   oinstall  359 2016-12-30 11:58:17 clsc37.log
-rw-r--r-- 1 grid   oinstall  358 2016-12-30 11:59:55 clsc38.log
-rw-r--r-- 1 grid   oinstall  358 2016-12-30 12:09:19 clsc39.log
-rw-r--r-- 1 grid   oinstall  362 2016-12-30 12:09:22 clsc40.log
-rw-r--r-- 1 grid   oinstall  362 2016-12-30 12:09:23 clsc41.log
-rw-r--r-- 1 grid   oinstall  260 2016-12-30 12:09:35 clsc42.log

$ ls -ltr clsc[0-9]*.log  | grep oinstall | tail -30
-rw-r--r-- 1 grid   oinstall  262 2021-07-21 07:59:58 clsc1257.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-21 08:19:58 clsc1258.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-22 07:59:58 clsc1259.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-22 08:19:59 clsc1260.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-23 08:00:01 clsc1261.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-23 08:20:01 clsc1262.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-24 07:59:55 clsc1263.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-24 08:19:57 clsc1264.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-25 07:59:51 clsc1265.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-25 08:19:50 clsc1266.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-26 07:59:54 clsc1267.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-26 08:19:52 clsc1268.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-27 07:59:55 clsc1269.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-27 08:19:54 clsc1270.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-28 07:59:57 clsc1271.log
-rw-r--r-- 1 grid   oinstall  260 2021-07-28 08:19:55 clsc1272.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-29 07:59:58 clsc1273.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-29 08:19:57 clsc1274.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-30 08:00:00 clsc1275.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-30 08:19:59 clsc1276.log
-rw-r--r-- 1 grid   oinstall  262 2021-07-31 07:59:56 clsc1277.log
-rw-r--r-- 1 grid   oinstall  260 2021-07-31 08:19:54 clsc1278.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-01 07:59:51 clsc1279.log
-rw-r--r-- 1 grid   oinstall  260 2021-08-01 08:19:50 clsc1280.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-02 07:59:53 clsc1281.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-02 08:19:52 clsc1282.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-03 07:59:55 clsc1283.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-03 08:19:54 clsc1284.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-03 11:45:31 clsc1285.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-03 11:46:42 clsc1286.log
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
--//你还可以发现1个规律,就是正常情况下1天执行2次,我估计oracle自己检查的,时间非常固定。
--//07:59,08:19上下。最后2次时我手动执行的。
--//从时间上看从上线以来我们从来没有删除过。假设从2016-12-24开始每天产生2个。
--//(8+365+365+365+366+215)*2 = 3368
--//恩,数量相差很大啊。放弃,不探究了。

$ cat clsc125[78].log
Oracle Database 11g Clusterware Release 11.2.0.4.0 - Production Copyright 1996, 2011 Oracle. All rights reserved.
2021-07-21 07:59:58.263: [ CRSCOMM][4154296096] NAME: `UI_DATA` length=7
2021-07-21 07:59:58.263: [ CRSCOMM][4154296096] Successfully read response

Oracle Database 11g Clusterware Release 11.2.0.4.0 - Production Copyright 1996, 2011 Oracle. All rights reserved.
2021-07-21 08:19:58.462: [ CRSCOMM][4097627936] NAME: `UI_DATA` length=7
2021-07-21 08:19:58.462: [ CRSCOMM][4097627936] Successfully read response

$ crs_stat -t -v
...

$ ls -ltr clsc[0-9]*.log  | grep oinstall | tail -4
-rw-r--r-- 1 grid   oinstall  262 2021-08-03 08:19:54 clsc1284.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-03 11:45:31 clsc1285.log
-rw-r--r-- 1 grid   oinstall  262 2021-08-03 11:46:42 clsc1286.log
-rw-r--r-- 1 grid   oinstall  258 2021-08-03 12:00:29 clsc1287.log
--//你只要执行1次就产生1个.
--//解决方法很简单删除该目录下log文件。估计对方是运行zabbix 之类的监控执行了这个命令。
--//好像11g不主张使用这个命令,而是使用crsctl。
$ crsctl status res -t

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/267265/viewspace-2785306/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
熟悉oracle相关技术,擅长sql优化,rman备份与恢复,熟悉linux shell编程。

注册时间:2008-01-03

  • 博文量
    3135
  • 访问量
    6840158