Bug 448616

Summary: udev taking up 100% of the cpu
Product: Red Hat Enterprise Linux 5 Reporter: Corey Marthaler <cmarthal>
Component: udevAssignee: Harald Hoyer <harald>
Status: CLOSED INSUFFICIENT_DATA QA Contact: qe-baseos-daemons
Severity: low Docs Contact:
Priority: low    
Version: 5.3CC: jbrassow, pknirsch
Target Milestone: rc   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-05-13 09:44:39 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
kern dump from hayes-03 none

Description Corey Marthaler 2008-05-27 20:53:00 UTC
Description of problem:
I noticed this while attempting to set up and diff 2 devices which were legs of
a mirror.

  PID USER      PR  NI  VIRT  RES  SHR S CPU %MEM    TIME+  COMMAND
  623 root      21  -4 44708  32m  368 R  100  0.4   5:52.73 udevd
31603 root      25   0 79004 3016 1448 R    9  0.0   0:41.90 find_dm_diffs

I saw this in /var/log/messages:
May 27 15:39:26 hayes-03 udevd[623]: get_netlink_msg: unable to receive kernel
netlink message: No buffer space available

[root@hayes-03 ~]# lvs -a -o +devices
  LV                            VG            Attr   LSize  Origin Snap%  Move
Log Copy%  Convert Devices                                                  
  LogVol00                      VolGroup00    -wi-ao 72.44G                    
                  /dev/sda2(0)                                             
  LogVol01                      VolGroup00    -wi-ao  1.94G                    
                  /dev/sda2(2318)                                          
  mirror_log_convert            mirror_sanity mwi-s-  3.10T                    
     0.00         mirror_log_convert_mimage_0(0),mirror_log_convert_mimage_1(0)
  [mirror_log_convert_mimage_0] mirror_sanity Iwi-ao  3.10T                    
                  /dev/etherd/e1.1p5(0)                                    
  [mirror_log_convert_mimage_0] mirror_sanity Iwi-ao  3.10T                    
                  /dev/etherd/e1.1p4(0)                                    
  [mirror_log_convert_mimage_1] mirror_sanity Iwi-ao  3.10T                    
                  /dev/etherd/e1.1p3(0)                                    
  [mirror_log_convert_mimage_1] mirror_sanity Iwi-ao  3.10T                    
                  /dev/etherd/e1.1p2(0) 

[root@hayes-03 ~]# dmsetup ls --tree
d2 (253:6)
 └─mirror_sanity-mirror_log_convert_mimage_1 (253:3)
    ├─ (152:274)
    └─ (152:275)
d1 (253:5)
 └─mirror_sanity-mirror_log_convert_mimage_0 (253:2)
    ├─ (152:276)
    └─ (152:277)
VolGroup00-LogVol01 (253:1)
 └─ (8:2)
VolGroup00-LogVol00 (253:0)
 └─ (8:2)
mirror_sanity-mirror_log_convert (253:4)
 ├─mirror_sanity-mirror_log_convert_mimage_1 (253:3)
 │  ├─ (152:274)
 │  └─ (152:275)
 └─mirror_sanity-mirror_log_convert_mimage_0 (253:2)
    ├─ (152:276)
    └─ (152:277)


[root@hayes-03 ~]# dmsetup info
Name:              d2
State:             ACTIVE
Read Ahead:        256
Tables present:    LIVE
Open count:        0
Event number:      0
Major, minor:      253, 6
Number of targets: 1

Name:              d1
State:             ACTIVE
Read Ahead:        256
Tables present:    LIVE
Open count:        0
Event number:      0
Major, minor:      253, 5
Number of targets: 1

Name:              mirror_sanity-mirror_log_convert_mimage_1
State:             ACTIVE
Read Ahead:        256
Tables present:    LIVE
Open count:        2
Event number:      0
Major, minor:      253, 3
Number of targets: 2
UUID: LVM-MQhQ3udsycEUC3qdn7nBuo4uUNcHdF3RJVoo5xyhGJAFQo4gDBISFa2derpTyP7O

Name:              VolGroup00-LogVol01
State:             ACTIVE
Read Ahead:        256
Tables present:    LIVE
Open count:        1
Event number:      0
Major, minor:      253, 1
Number of targets: 1
UUID: LVM-peXw08IDS5MX5c98r7k43kiRMtbpwTJATdDLLdIyhc1zTVHM4fQfCf8mO5OakPsz

Name:              mirror_sanity-mirror_log_convert_mimage_0
State:             ACTIVE
Read Ahead:        256
Tables present:    LIVE
Open count:        2
Event number:      0
Major, minor:      253, 2
Number of targets: 2
UUID: LVM-MQhQ3udsycEUC3qdn7nBuo4uUNcHdF3RcHeBYyoNmHxhFWTEqruz1vfC1MSpNILk

Name:              VolGroup00-LogVol00
State:             ACTIVE
Read Ahead:        256
Tables present:    LIVE
Open count:        1
Event number:      0
Major, minor:      253, 0
Number of targets: 1
UUID: LVM-peXw08IDS5MX5c98r7k43kiRMtbpwTJA6tejCLPiA7SbKqWRA8jHjef5dM4KvjE9

Name:              mirror_sanity-mirror_log_convert
State:             SUSPENDED
Read Ahead:        256
Tables present:    LIVE
Open count:        0
Event number:      0
Major, minor:      253, 4
Number of targets: 1
UUID: LVM-MQhQ3udsycEUC3qdn7nBuo4uUNcHdF3RMonxOohgrRUz375P7NMIxj8jQxuWnSgn




If I strace the process that's attempting this I see the following loop over and
over:
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x2b1693bd52b0) = 27174
close(6)                                = 0
close(4)                                = 0
read(5, "", 4)                          = 0
close(5)                                = 0
ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff16ee24e0) = -1 EINVAL (Invalid
argument)
lseek(3, 0, SEEK_CUR)                   = -1 ESPIPE (Illegal seek)
read(3, "", 4096)                       = 0
close(3)                                = 0
rt_sigaction(SIGHUP, {SIG_IGN}, {SIG_DFL}, 8) = 0
rt_sigaction(SIGINT, {SIG_IGN}, {SIG_DFL}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_IGN}, {SIG_DFL}, 8) = 0
wait4(27174, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 27174
rt_sigaction(SIGHUP, {SIG_DFL}, NULL, 8) = 0
rt_sigaction(SIGINT, {SIG_DFL}, NULL, 8) = 0
rt_sigaction(SIGQUIT, {SIG_DFL}, NULL, 8) = 0
write(1, " 203745472 -  203745535: ......."..., 128) = 128
pipe([3, 4])                            = 0
pipe([5, 6])                            = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x2b1693bd52b0) = 27175


Version-Release number of selected component (if applicable):
2.6.18-92.el5
udev-095-14.16.el5

Comment 1 Corey Marthaler 2008-05-27 21:02:49 UTC
Created attachment 306838 [details]
kern dump from hayes-03

Comment 4 Phil Knirsch 2009-09-03 15:45:06 UTC
Does this problem still happen with the latest RHEL-5.3 update version?

Thanks & regards, Phil

Comment 5 Phil Knirsch 2011-05-13 09:44:39 UTC
This request was evaluated by Red Hat Engineering for inclusion in a Red                                                                                     
Hat Enterprise Linux maintenance release.                                                                                                                    

As this bug has been in NEEDINFO for an extended period of time we are going
to close this bug due to inactivity. If you would like to pursue this
matter feel free to reopen this bug and attach the needed information.

With the goal of minimizing risk of change for deployed systems, and in
response to customer and partner requirements, Red Hat takes a conservative
approach when evaluating enhancements for inclusion in maintenance updates
for currently deployed products. The primary objectives of update releases
are to enable new hardware platform support and to resolve critical
defects.

However, Red Hat will further review this request for potential inclusion
in future major releases of Red Hat Enterprise Linux.