Bug 30484

Summary: rpc.rstatd consumed lots of open file descriptors
Product: Base System Reporter: sec <sec>
Component: binAssignee: freebsd-bugs (Nobody) <bugs>
Status: Closed FIXED    
Severity: Affects Only Me    
Priority: Normal    
Version: Unspecified   
Hardware: Any   
OS: Any   

Description sec 2001-09-10 14:40:01 UTC 
Today my machine expirienced lots of problems since all maximum number
of open files was reached.

This resulted in amusing messages like:
lsof: can't open pipes: Too many open files in system
ps: /dev/null: Too many open files in system

and others.

I wasn't able to execute any program (besides shell-builtins)

After killing a few programs i found that 'rpc.rstatd' was the source of
the problem. lsof showed that it had consumed them all to open /dev/mem and
/dev/kmem:

[...]
rpc.rstat 58933   root  383r  VCHR        2,1 0xc035c524   6293 /dev/kmem
rpc.rstat 58933   root  384r  VCHR        2,0        0t0   6294 /dev/mem
rpc.rstat 58933   root  385r  VCHR        2,1 0xc035c524   6293 /dev/kmem
rpc.rstat 58933   root  386r  VCHR        2,0        0t0   6294 /dev/mem
rpc.rstat 58933   root  387r  VCHR        2,1 0xc035c524   6293 /dev/kmem
rpc.rstat 58933   root  388r  VCHR        2,0        0t0   6294 /dev/mem
rpc.rstat 58933   root  389r  VCHR        2,1 0xc035c524   6293 /dev/kmem

after killing it, the problem ceased.

Fix: 

Have ddb in the kernel so you can find the pid of your rpc.rstatd :->
How-To-Repeat: 
I have rpc.rstatd enabled in the inetd.conf, and query it regularely using 
xosview using a command line like this:

xsysstats -allnames -split 1x3 -display :0 -window 1 -type cpu -color red -window 2 -type disk -color red -window 3 -type packets -color red -samescale -host <myhostname>

This has happened the first time, so I can't really reproduce it. I will
cvsup today and try with a brand new kernel and world and see if thet problem
happens again.

I figured I send this now even though its incomplete, because the release
is so close, and you might want to look into it.
Comment 1 sec 2001-09-11 12:33:36 UTC 
Hi,

I investigated that problem a little further.

I cvsup'd yesterday, and did a fresh make world and rebooted.

FreeBSD yoda 4.4-RC FreeBSD 4.4-RC #0: Mon Sep 10 20:24:01 CEST 2001     root@yoda:/usr/obj/usr/src/sys/YODA  i386

The problem does persist. I start rpc.rstatd and xsysstats. and wait a
few minutes. Lsof then shows that filedescriptor leakage,
The filedescriptors remain open even if I kill "xsysstats" so this
program can't be the culprit.

yoda:~#lsof -p 1729
COMMAND    PID USER   FD   TYPE     DEVICE   SIZE/OFF   NODE NAME
rpc.rstat 1729 root  cwd   VDIR  13,131072        512      2 /
rpc.rstat 1729 root  rtd   VDIR  13,131072        512      2 /
rpc.rstat 1729 root  txt   VREG  13,131077       9308 379346 /usr/libexec/rpc.rstatd
rpc.rstat 1729 root  txt   VREG  13,131077      77224 379406 /usr/libexec/ld-elf.so.1
rpc.rstat 1729 root  txt   VREG  13,131077      30864 349800 /usr/lib/librpcsvc.so.2
rpc.rstat 1729 root  txt   VREG  13,131077      33200 349705 /usr/lib/libutil.so.3
rpc.rstat 1729 root  txt   VREG  13,131077      19360 349517 /usr/lib/libkvm.so.2
rpc.rstat 1729 root  txt   VREG  13,131077      12296 349397 /usr/lib/libdevstat.so.2
rpc.rstat 1729 root  txt   VREG  13,131077     581324 349732 /usr/lib/libc.so.4
rpc.rstat 1729 root    0u  VCHR        2,2        0t0   6295 /dev/null
rpc.rstat 1729 root    1u  VCHR        2,2        0t0   6295 /dev/null
rpc.rstat 1729 root    2u  VCHR        2,2        0t0   6295 /dev/null
rpc.rstat 1729 root    3u  IPv4 0xc577c6c0        0t0    UDP *:ircs
rpc.rstat 1729 root    4r  VCHR        2,0        0t0   6294 /dev/mem
rpc.rstat 1729 root    5r  VCHR        2,1 0xc035c8e4   6293 /dev/kmem
rpc.rstat 1729 root    6r  VCHR        2,0        0t0   6294 /dev/mem
rpc.rstat 1729 root    7r  VCHR        2,1 0xc035c8e4   6293 /dev/kmem
[...]
rpc.rstat 1729 root   48r  VCHR        2,0        0t0   6294 /dev/mem
rpc.rstat 1729 root   49r  VCHR        2,1 0xc035c8e4   6293 /dev/kmem

I have a ktrace output of a run, but it is rather large, so I will send
the full output only on request. The last part is:

  1729 rpc.rstatd CALL  socket(0x2,0x2,0x11)
  1729 rpc.rstatd RET   socket 50/0x32
  1729 rpc.rstatd CALL  getsockname(0x32,0xbfbff080,0xbfbff07c)
  1729 rpc.rstatd RET   getsockname 0
  1729 rpc.rstatd CALL  getsockopt(0x32,0,0x13,0xbfbff074,0xbfbff078)
  1729 rpc.rstatd RET   getsockopt 0
  1729 rpc.rstatd CALL  setsockopt(0x32,0,0x13,0xbfbff070,0x4)
  1729 rpc.rstatd RET   setsockopt 0
  1729 rpc.rstatd CALL  bind(0x32,0xbfbff080,0x10)
  1729 rpc.rstatd RET   bind 0
  1729 rpc.rstatd CALL  ioctl(0x32,FIONBIO,0xbfbff164)
  1729 rpc.rstatd RET   ioctl 0
  1729 rpc.rstatd CALL  sendto(0x32,0x806b1f8,0x38,0,0x806b008,0x10)
  1729 rpc.rstatd GIO   fd 50 wrote 56 bytes
       "\M^E+\^^Ï\0\0\0\0\0\0\0\^B\0\^A\M^F\240\0\0\0\^B\0\0\0\^B\0\0\0\0\0\0\
	\0\0\0\0\0\0\0\0\0\0\0\^A\M^F¡\0\0\0\^B\0\0\0\0\0\0\0\0"
  1729 rpc.rstatd RET   sendto 56/0x38
  1729 rpc.rstatd CALL  gettimeofday(0xbfbff0b0,0)
  1729 rpc.rstatd RET   gettimeofday 0
  1729 rpc.rstatd CALL  select(0x33,0xbfbff120,0,0,0xbfbff0a8)
  1729 rpc.rstatd RET   select 1
  1729 rpc.rstatd CALL  recvfrom(0x32,0x806b068,0x190,0,0xbfbff110,0xbfbff08c)
  1729 rpc.rstatd GIO   fd 50 read 28 bytes
       "\M^E+\^^Ï\0\0\0\^A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\^A"
  1729 rpc.rstatd RET   recvfrom 28/0x1c
  1729 rpc.rstatd CALL  close(0x32)
  1729 rpc.rstatd RET   close 0
  1729 rpc.rstatd CALL  close(0x32)
  1729 rpc.rstatd RET   close -1 errno 9 Bad file descriptor
  1729 rpc.rstatd CALL  stat(0x280ff8c0,0xbfbff1f0)
  1729 rpc.rstatd NAMI  "/var/run/portmapsock"
  1729 rpc.rstatd RET   stat -1 errno 2 No such file or directory
  1729 rpc.rstatd CALL  socket(0x2,0x2,0)
  1729 rpc.rstatd RET   socket 50/0x32
  1729 rpc.rstatd CALL  ioctl(0x32,SIOCGIFCONF,0xbfbfed98)
  1729 rpc.rstatd RET   ioctl 0
  1729 rpc.rstatd CALL  ioctl(0x32,SIOCGIFFLAGS,0xbfbfeda0)
  1729 rpc.rstatd RET   ioctl 0
  1729 rpc.rstatd CALL  ioctl(0x32,SIOCGIFFLAGS,0xbfbfeda0)
  1729 rpc.rstatd RET   ioctl 0
  1729 rpc.rstatd CALL  close(0x32)
  1729 rpc.rstatd RET   close 0
  1729 rpc.rstatd CALL  gettimeofday(0xbfbff178,0)
  1729 rpc.rstatd RET   gettimeofday 0
  1729 rpc.rstatd CALL  getpid
  1729 rpc.rstatd RET   getpid 1729/0x6c1
  1729 rpc.rstatd CALL  socket(0x2,0x2,0x11)
  1729 rpc.rstatd RET   socket 50/0x32
  1729 rpc.rstatd CALL  getsockname(0x32,0xbfbff090,0xbfbff08c)
  1729 rpc.rstatd RET   getsockname 0
  1729 rpc.rstatd CALL  getsockopt(0x32,0,0x13,0xbfbff084,0xbfbff088)
  1729 rpc.rstatd RET   getsockopt 0
  1729 rpc.rstatd CALL  setsockopt(0x32,0,0x13,0xbfbff080,0x4)
  1729 rpc.rstatd RET   setsockopt 0
  1729 rpc.rstatd CALL  bind(0x32,0xbfbff090,0x10)
  1729 rpc.rstatd RET   bind 0
  1729 rpc.rstatd CALL  ioctl(0x32,FIONBIO,0xbfbff174)
  1729 rpc.rstatd RET   ioctl 0
  1729 rpc.rstatd CALL  sendto(0x32,0x806b1f8,0x38,0,0x806b008,0x10)
  1729 rpc.rstatd GIO   fd 50 wrote 56 bytes
       "\M^E+&m\0\0\0\0\0\0\0\^B\0\^A\M^F\240\0\0\0\^B\0\0\0\^B\0\0\0\0\0\0\0\
	\0\0\0\0\0\0\0\0\0\0\^A\M^F¡\0\0\0\^A\0\0\0\0\0\0\0\0"
  1729 rpc.rstatd RET   sendto 56/0x38
  1729 rpc.rstatd CALL  gettimeofday(0xbfbff0c0,0)
  1729 rpc.rstatd RET   gettimeofday 0
  1729 rpc.rstatd CALL  select(0x33,0xbfbff130,0,0,0xbfbff0b8)
  1729 rpc.rstatd RET   select 1
  1729 rpc.rstatd CALL  recvfrom(0x32,0x806b068,0x190,0,0xbfbff120,0xbfbff09c)
  1729 rpc.rstatd GIO   fd 50 read 28 bytes
       "\M^E+&m\0\0\0\^A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\^A"
  1729 rpc.rstatd RET   recvfrom 28/0x1c
  1729 rpc.rstatd CALL  close(0x32)
  1729 rpc.rstatd RET   close 0
  1729 rpc.rstatd CALL  close(0x32)
  1729 rpc.rstatd RET   close -1 errno 9 Bad file descriptor
  1729 rpc.rstatd CALL  sigprocmask(0x1,0x2805cec0,0xbfbff200)
  1729 rpc.rstatd RET   sigprocmask 0
  1729 rpc.rstatd CALL  sigprocmask(0x3,0x2805ced0,0)
  1729 rpc.rstatd RET   sigprocmask 0
  1729 rpc.rstatd CALL  exit(0)

Is there anything else I can do to help fix this problem?

CU,
    Sec
-- 
Komme wieder
Comment 2 iedowse freebsd_committer freebsd_triage 2002-12-01 13:20:31 UTC 
State Changed
From-To: open->feedback


It looks like Alfred may have fixed this in revision 1.14.2.1 of 
rstat_proc.c. Can you confirm that this is fixed in 4.7-RELEASE or 
a -STABLE from after July 11, 2002?
Comment 3 iedowse freebsd_committer freebsd_triage 2002-12-07 04:51:56 UTC 
State Changed
From-To: feedback->closed


Mail to submitter bounces.