技术开发 频道

共享内存段异常引起查询慢的分析处理

  【IT168 技术文档】事情的起因是系统的最终用户反映某些查询功能比较慢。简单地看了一下主机的负载以及数据库的性能状况,没发现什么异常,甚至可以说系统相当地轻闲。

  那问题出在哪?我首先观察到内存的使用率相当地高,达到99%。但是从操作上看,速度还没受到影响。不过很快想到,这个系统某些模块,用了短连接,难道是监听太慢引起的?这个库启了6个监听,分别TNSPING这几个监听,有个别监听非常慢,重启监听后,查询功能比较慢的问题得到解决。

  不过之前观察到的内存的异常使用引起了我极大的注意。这套系统,平时一般都会有几十G的空闲内存,不会达到这么高的。第一反应是用ipcs命令检查一下共享内存,发现有一个异常的共享内存段,占了60多G。  

[oracle@hostname%/oracle]ipcs -ma
  IPC status from /dev/kmem as of Mon Dec 7 10:58:53 2009
  T ID KEY MODE OWNER GROUP CREATOR CGROUP NATTCH SEGSZ CPID LPID ATIME DTIME CTIME
  Shared Memory:
  m 0 0x41180809 --rw-rw-rw- root root root root 0 348 2725 2725 2:38:57 2:38:57 2:38:50
  m 1 0x4e0c0002 --rw-rw-rw- root root root root 2 61760 2725 2727 12:27:19 18:19:39 2:38:50
  m 2 0x411c0de1 --rw-rw-rw- root root root root 2 8192 2725 2727 12:27:19 2:38:50 2:38:50
  m 3 0x00a5c581 --rw------- sfmdb users sfmdb users 11 10469376 3362 3398 2:39:38 2:39:39 2:39:38
  m 4 0x4118043d --rw------- root root root root 1 4096 3410 4745 2:40:12 no-entry 2:40:12
  m 5 0x06347849 --rw-rw-rw- root root root root 1 65544 3535 6722 17:53:03 17:53:03 2:39:47
  m 1015814 0x0c6629c9 --rw-r----- root dba root dba 0 35921048 6722 6722 17:53:03 no-entry 17:53:03
  m 819207 0x491002d0 --rw-r--r-- root root root root 0 22908 3674 3674 2:39:54 2:39:54 2:39:54
  m 5472264 0x00000000 D-rw-r----- oracle dba oracle dba 6 66640334848 5508 23604 17:58:00 17:58:00 17:58:00
  m 95387657 0x0000cace --rw-rw-rw- root sys root sys 0 2 21306 21306 20:24:33 20:24:33 20:24:29
  m 35520522 0xa57bccf8 --rw-r----- oracle dba oracle dba 12231 66640334848 3231 26942 10:58:53 10:58:53 18:10:36
  [oracle@hostname%/oracle]ipcs -ma
  IPC status from /dev/kmem as of Mon Dec 7 10:58:53 2009
  T ID KEY MODE OWNER GROUP CREATOR CGROUP NATTCH SEGSZ CPID LPID ATIME DTIME CTIME
  Shared Memory:
  m 0 0x41180809 --rw-rw-rw- root root root root 0 348 2725 2725 2:38:57 2:38:57 2:38:50
  m 1 0x4e0c0002 --rw-rw-rw- root root root root 2 61760 2725 2727 12:27:19 18:19:39 2:38:50
  m 2 0x411c0de1 --rw-rw-rw- root root root root 2 8192 2725 2727 12:27:19 2:38:50 2:38:50
  m 3 0x00a5c581 --rw------- sfmdb users sfmdb users 11 10469376 3362 3398 2:39:38 2:39:39 2:39:38
  m 4 0x4118043d --rw------- root root root root 1 4096 3410 4745 2:40:12 no-entry 2:40:12
  m 5 0x06347849 --rw-rw-rw- root root root root 1 65544 3535 6722 17:53:03 17:53:03 2:39:47
  m 1015814 0x0c6629c9 --rw-r----- root dba root dba 0 35921048 6722 6722 17:53:03 no-entry 17:53:03
  m 819207 0x491002d0 --rw-r--r-- root root root root 0 22908 3674 3674 2:39:54 2:39:54 2:39:54
  m 5472264 0x00000000 D-rw-r----- oracle dba oracle dba 6 66640334848 5508 23604 17:58:00 17:58:00 17:58:00
  m 95387657 0x0000cace --rw-rw-rw- root sys root sys 0 2 21306 21306 20:24:33 20:24:33 20:24:29
  m 35520522 0xa57bccf8 --rw-r----- oracle dba oracle dba 12231 66640334848 3231 26942 10:58:53 10:58:53 18:10:36

  

ID为”5472264″的共享内存段就是异常的共享内存段。

  为什么会出现这种情况?数据库可以确定是被重启过,询问客户这套系统的DBA,的确是在头一天出现了异常然后进行了重启。至于出现了什么样的异常,为什么要重启,这里不再深入。本文只讨论怎么样来清除这个异常的共享内存段。

  由于这个内存段的NTATTCH(number of attach)为6,在HP-UX下是清理不掉的:       

1[oracle@hostname%/oracle]ipcrm -m 5472264
2
3  ipcrm: shmid(5472264): not found
4  [oracle@hostname%/oracle]ipcrm -m 5472264
5  ipcrm: shmid(5472264): not found
6
7

    这是由于还有进程attach(理解为连接吧)到这个共享内存段上。只要找到这个进程被KILL之,就会解决问题。一种简单的方法是使用lsof来找到这些进程:

  [oracle@hostname%/oracle]lsof | egrep "COMMAND|5472264"

  [oracle@hostname%/oracle]lsof | egrep "COMMAND|5472264"

  不过简单的方法,不一定效率就高。这个系统光oracle server process就有5000个以上,lsof实在很慢。所以运行几分钟就直接放弃(因为以前在这套系统上运行过lsof命令,知道要输出完结果时间比较“漫长”)。

  OK, 手工找一下吧。从上面的ipcs输出的CTIME字段看到,正常的共享内存段是18:10左右创建的,而异常的是17:58左右创建的,那么attach到这个异常共享内存段的进程应该是在18点之前创建,而在17:58左右。首先使用”ps -ef | grep defunct“,没有发现僵死进程。然后根据这样的条件,并且经过一系列筛选,得到下面的结果: 

1 [oracle@hostname%/oracle]ps -ef | grep oraclesidname | grep "17:" | grep -v "18:17" | grep -v "11:17"
2  oracle 22586 1 1 07:17:43 ? 0:31 oraclesidname (LOCAL=NO)
3  oracle 28403 1 0 09:17:38 ? 0:02 oraclesidname (LOCAL=NO)
4  oracle 22618 1 0 07:17:59 ? 0:00 oraclesidname (LOCAL=NO)
5  oracle 7539 1 0 08:17:42 ? 0:10 oraclesidname (LOCAL=NO)
6  oracle 7419 1 0 08:17:05 ? 0:00 oraclesidname (LOCAL=NO)
7  oracle 22580 1 0 07:17:42 ? 0:36 oraclesidname (LOCAL=NO)
8  oracle 7421 1 0 08:17:06 ? 0:06 oraclesidname (LOCAL=NO)
9  oracle 7537 1 0 08:17:42 ? 0:02 oraclesidname (LOCAL=NO)
10  oracle 7535 1 0 08:17:41 ? 0:00 oraclesidname (LOCAL=NO)
11  oracle 21395 1 0 17:56:49 ? 0:01 oraclesidname (LOCAL=NO)
12  oracle 22616 1 0 07:17:59 ? 0:00 oraclesidname (LOCAL=NO)
13  oracle 20786 1 0 17:54:24 ? 0:10 oraclesidname (LOCAL=NO)
14  oracle 22614 1 0 07:17:58 ? 0:00 oraclesidname (LOCAL=NO)
15  oracle 7423 1 0 08:17:06 ? 0:18 oraclesidname (LOCAL=NO)
16  [oracle@hostname%/oracle]ps -ef | grep oraclesidname | grep "17:" | grep -v "18:17" | grep -v "11:17"
17  oracle 22586 1 1 07:17:43 ? 0:31 oraclesidname (LOCAL=NO)
18  oracle 28403 1 0 09:17:38 ? 0:02 oraclesidname (LOCAL=NO)
19  oracle 22618 1 0 07:17:59 ? 0:00 oraclesidname (LOCAL=NO)
20  oracle 7539 1 0 08:17:42 ? 0:10 oraclesidname (LOCAL=NO)
21  oracle 7419 1 0 08:17:05 ? 0:00 oraclesidname (LOCAL=NO)
22  oracle 22580 1 0 07:17:42 ? 0:36 oraclesidname (LOCAL=NO)
23  oracle 7421 1 0 08:17:06 ? 0:06 oraclesidname (LOCAL=NO)
24  oracle 7537 1 0 08:17:42 ? 0:02 oraclesidname (LOCAL=NO)
25  oracle 7535 1 0 08:17:41 ? 0:00 oraclesidname (LOCAL=NO)
26  oracle 21395 1 0 17:56:49 ? 0:01 oraclesidname (LOCAL=NO)
27  oracle 22616 1 0 07:17:59 ? 0:00 oraclesidname (LOCAL=NO)
28  oracle 20786 1 0 17:54:24 ? 0:10 oraclesidname (LOCAL=NO)
29  oracle 22614 1 0 07:17:58 ? 0:00 oraclesidname (LOCAL=NO)
30  oracle 7423 1 0 08:17:06 ? 0:18 oraclesidname (LOCAL=NO)

  看上去进程号为21395和20786的进程,正好满足前面提到的条件。KILL这两个进程,检查共享内存段,发现这个异常的共享内存段自动被清除。再检查内存的使用,内存的使用率也大幅下降,回到正常状态。

0
相关文章