Thinking Out Loud

December 9, 2010

Troubleshooting OEM 11g Grid Crontrol – (Too many open files)

Filed under: 11g,Grid Control — mdinh @ 3:58 am

I am running OEM 11g Grid Control on Solaris 10.

Instead of seeing charts on the OEM pages, I was seeing red X.

First, the location of the logs can be found under $EM_INSTANCE_HOME

> echo $EM_INSTANCE_HOME
/u01/app/oracle/gc_inst/em/EMGC_OMS1
/u01/app/oracle/gc_inst/em/EMGC_OMS1/sysman/log
> ll
total 11216
drwxr-----   2 oracle   dba           96 Aug 31 12:57 pafLogs
-rw-r-----   1 oracle   dba            0 Aug 31 13:02 emovm.log.0
drwxr-xr-x   9 oracle   dba         8192 Aug 31 14:39 ..
-rw-r--r--   1 oracle   dba        15264 Sep 30 06:53 secure.log
drwxr-xr-x   3 oracle   dba         8192 Dec  6 11:29 .
-rw-r-----   1 oracle   dba            0 Dec  6 11:29 emovm.log.0.lck
-rw-r-----   1 oracle   dba       387329 Dec  6 11:32 emctl.log
-rw-r-----   1 oracle   dba      2640001 Dec  8 00:00 emoms.log
-rw-r-----   1 oracle   dba      2640001 Dec  8 00:00 emoms.trc

The following errors were in the emoms.log:

2010-12-06 07:55:04,717 [[ACTIVE] ExecuteThread: '5' for queue: 'weblogic.kernel.Default (self-tuning)']
WARN  chart.EmChartBean getChartImage.5105 - EXCEPTION while generating chart image [id]: D3B6716582D334A0D8F9F9D82AAD42C8.gif

java.io.FileNotFoundException:
/u01/app/oracle/gc_inst/user_projects/domains/GCDomain/servers/EMGC_OMS1/tmp/_WL_user/emgc/n47f6s/public/images/chartCache/chartD3B6716582D334A0D8F9F9D82AAD42C8.gif.gif
(Too many open files)

This was puzzling since I remembered changing open files from 1024 to 4096 and restarting oms.

> ulimit -an
core file size        (blocks, -c) unlimited
data seg size         (kbytes, -d) unlimited
file size             (blocks, -f) unlimited
open files                    (-n) 4096
pipe size          (512 bytes, -p) 10
stack size            (kbytes, -s) 8192
cpu time             (seconds, -t) unlimited
max user processes            (-u) 29995
virtual memory        (kbytes, -v) unlimited

Let’s find WLS processes:

> ps -afe|grep oracle|grep java|grep -v grep
  oracle  7813  7754   0   Nov 02 ?         389:43 /usr/jdk/instances/jdk1.6.0_20/bin/sparcv9/java -client -Xms256m -Xmx1024m -XX:
  oracle  7191  3335   0   Nov 02 ?         127:43 /usr/jdk/instances/jdk1.6.0_20/jre/bin/sparcv9/java -classpath /usr/jdk/instanc
  oracle 26182 26159   0   Nov 12 ?         698:36 /usr/jdk/instances/jdk1.6.0_22/bin/sparcv9/java -client -Xms256m -Xmx1024m -XX:

Let’s look at the open files associated with each process:

> pfiles 7813|head
7813:   /usr/jdk/instances/jdk1.6.0_20/bin/sparcv9/java -client -Xms256m -Xmx1
  Current rlimit: 1024 file descriptors
   0: S_IFCHR mode:0666 dev:340,66 ino:36640 uid:0 gid:3 rdev:13,2
      O_RDONLY|O_LARGEFILE
      /dev/null
   1: S_IFREG mode:0640 dev:286,1000 ino:1599591 uid:15001 gid:15000 size:30922
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   2: S_IFREG mode:0640 dev:286,1000 ino:1599591 uid:15001 gid:15000 size:30922
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   3: S_IFCHR mode:0666 dev:340,66 ino:36699 uid:0 gid:3 rdev:13,12

> pfiles 7191|head
7191:   /usr/jdk/instances/jdk1.6.0_20/jre/bin/sparcv9/java -classpath /usr/jd
  Current rlimit: 1024 file descriptors
   0: S_IFIFO mode:0000 dev:322,0 ino:93191797 uid:15001 gid:15000 size:0
      O_RDWR
   1: S_IFIFO mode:0000 dev:322,0 ino:93191798 uid:15001 gid:15000 size:0
      O_RDWR
   2: S_IFIFO mode:0000 dev:322,0 ino:93191799 uid:15001 gid:15000 size:0
      O_RDWR
   3: S_IFCHR mode:0666 dev:340,66 ino:36699 uid:0 gid:3 rdev:13,12
      O_RDWR|O_LARGEFILE FD_CLOEXEC

> pfiles 26182|head
26182:  /usr/jdk/instances/jdk1.6.0_22/bin/sparcv9/java -client -Xms256m -Xmx1
  Current rlimit: 1024 file descriptors
   0: S_IFCHR mode:0666 dev:340,66 ino:36640 uid:0 gid:3 rdev:13,2
      O_RDONLY|O_LARGEFILE
      /dev/null
   1: S_IFREG mode:0640 dev:286,1000 ino:3232523 uid:15001 gid:15000 size:8965325
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   2: S_IFREG mode:0640 dev:286,1000 ino:3232523 uid:15001 gid:15000 size:8965325
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   3: S_IFCHR mode:0666 dev:340,66 ino:36699 uid:0 gid:3 rdev:13,12

It looks like WLS was started with only 1024 file descriptors.

Restart WLS after confirming open files (-n) 4096 and verify the process:

> ps -afe|grep oracle|grep java|grep -v grep
  oracle 11942 11766   0 11:27:20 ?           6:32 /usr/jdk/instances/jdk1.6.0_22/bin/sparcv9/java -client -Xms256m -Xmx1024m -XX:
  oracle 18722  3335   0 11:25:39 pts/4       0:12 /usr/jdk/instances/jdk1.6.0_22/jre/bin/sparcv9/java -classpath /usr/jdk/instanc
  oracle 20361 20266   0 11:25:51 ?           2:45 /usr/jdk/instances/jdk1.6.0_22/bin/sparcv9/java -client -Xms256m -Xmx1024m -XX:
 
> pfiles 11942|head
11942:  /usr/jdk/instances/jdk1.6.0_22/bin/sparcv9/java -client -Xms256m -Xmx1
  Current rlimit: 4096 file descriptors
   0: S_IFCHR mode:0666 dev:340,66 ino:36640 uid:0 gid:3 rdev:13,2
      O_RDONLY|O_LARGEFILE
      /dev/null
   1: S_IFREG mode:0640 dev:286,1000 ino:1609620 uid:15001 gid:15000 size:62670
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   2: S_IFREG mode:0640 dev:286,1000 ino:1609620 uid:15001 gid:15000 size:62670
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   3: S_IFCHR mode:0666 dev:340,66 ino:36699 uid:0 gid:3 rdev:13,12
 
> pfiles 18722|head
18722:  /usr/jdk/instances/jdk1.6.0_22/jre/bin/sparcv9/java -classpath /usr/jd
  Current rlimit: 4096 file descriptors
   0: S_IFIFO mode:0000 dev:322,0 ino:415173812 uid:15001 gid:15000 size:0
      O_RDWR
   1: S_IFIFO mode:0000 dev:322,0 ino:415173813 uid:15001 gid:15000 size:0
      O_RDWR
   2: S_IFIFO mode:0000 dev:322,0 ino:415173814 uid:15001 gid:15000 size:0
      O_RDWR
   3: S_IFCHR mode:0666 dev:340,66 ino:36699 uid:0 gid:3 rdev:13,12
      O_RDWR|O_LARGEFILE FD_CLOEXEC
 
> pfiles 20361|head
20361:  /usr/jdk/instances/jdk1.6.0_22/bin/sparcv9/java -client -Xms256m -Xmx1
  Current rlimit: 4096 file descriptors
   0: S_IFCHR mode:0666 dev:340,66 ino:36640 uid:0 gid:3 rdev:13,2
      O_RDONLY|O_LARGEFILE
      /dev/null
   1: S_IFREG mode:0640 dev:286,1000 ino:1610388 uid:15001 gid:15000 size:25426
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   2: S_IFREG mode:0640 dev:286,1000 ino:1610388 uid:15001 gid:15000 size:25426
      O_WRONLY|O_APPEND|O_CREAT|O_LARGEFILE
   3: S_IFCHR mode:0666 dev:340,66 ino:36699 uid:0 gid:3 rdev:13,12
About these ads

1 Comment »

  1. [...] Michael Dinh describes how he solved a tricky grid control issue. [...]

    Pingback by Log Buffer #209, A Carnival of the Vanities for DBAs | The Pythian Blog — December 13, 2010 @ 4:33 am | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

The Rubric Theme. Get a free blog at WordPress.com

Follow

Get every new post delivered to your Inbox.

Join 300 other followers

%d bloggers like this: