RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 837645 - RHEL 6.2 lvcreate hang at semaphore
Summary: RHEL 6.2 lvcreate hang at semaphore
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: lvm2
Version: 6.2
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: rc
: ---
Assignee: Peter Rajnoha
QA Contact: Cluster QE
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-07-04 14:30 UTC by atuld
Modified: 2012-12-14 08:18 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-12-14 08:18:28 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)

Description atuld 2012-07-04 14:30:31 UTC 
Description of problem:
lvcreate command hung for RHEL 6.2 

Version-Release number of selected component (if applicable):
RHEL 6 u 2 

How reproducible:
While creating lv using lvcreate command, it hung

Steps to Reproduce:
1.
2.
3.
  
Actual results:
Hung 

Expected results:
it should successfully create lv

Additional info:
When I am trying to create LV using lvcreate on RHEL 6.2, it hung at semaphore operation



#mm/memlock.c:297 Unlocked 14708736 bytes
#activate/fs.c:486 Syncing device names
#libdm-common.c:1294 Udev cookie 0xd4d27a5 (semid 1671174) decremented 
to 0
#libdm-common.c:1550 Udev cookie 0xd4d27a5 (semid 1671174) waiting for 
zero
<--no output--> Hang at this point 

below is the strace log 

Command strace lvcreate --size 16326656K --permission rw --name lv_root vg_cfttstvm52 /dev/sda2

execve("/sbin/lvcreate", ["lvcreate", "--size", "16326656K", "--permission", "rw", "--name", "lv_root", "vg_cfttstvm52", "/dev/sda2"], [/* 92 vars */]) = 0
....
....
open("/etc/udev/udev.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/dev/.udev/queue.bin", O_RDONLY) = 7
fstat(7, {st_mode=S_IFREG|0644, st_size=846, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe5981ed000
read(7, "[\3\0\0\0\0\0\0\\\3\0\0\0\0\0\0Q\0/devices/pci00"..., 4096) = 846
close(7) = 0
munmap(0x7fe5981ed000, 4096) = 0
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
stat("/dev/sda2", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 2), ...}) = 0
stat("/dev/sda2", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 2), ...}) = 0
ioctl(3, DM_DEV_CREATE, 0x1feeee0) = 0
ioctl(3, DM_TABLE_STATUS, 0x1feeee0) = 0
ioctl(3, DM_TABLE_LOAD, 0x1feeee0) = 0
open("/dev/urandom", O_RDONLY) = 7
read(7, "9\310", 2) = 2
semget(0xd4dc839, 1, IPC_CREAT|IPC_EXCL|0600) = 32769
semctl(32769, 0, SETVAL, 0x1) = 0
semctl(32769, 0, GETVAL, 0xffffffffffffffff) = 1
close(7) = 0
semop(32769, {{0, 1, 0}}, 1) = 0
semctl(32769, 0, GETVAL, 0xffffffffffffffff) = 2
ioctl(3, DM_DEV_SUSPEND, 0x1feeee0) = 0
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = 0
ioctl(3, DM_TABLE_DEPS, 0x1feeee0) = 0
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
ioctl(3, DM_DEV_STATUS, 0x1feeee0) = -1 ENXIO (No such device or address)
lseek(6, 0, SEEK_SET) = 0
read(6, "00400000-004c6000 r-xp 00000000 "..., 8192) = 4020
read(6, "7fffbb10f000-7fffbb110000 r-xp 0"..., 4172) = 164
read(6, "", 4008) = 0
munlock(0x400000, 811008) = 0
munlock(0x6c6000, 32768) = 0
munlock(0x6ce000, 28672) = 0
munlock(0x1fa4000, 10797056) = 0
munlock(0x7fe596d55000, 241664) = 0
munlock(0x7fe596f90000, 4096) = 0
munlock(0x7fe596f91000, 4096) = 0
munlock(0x7fe596f92000, 118784) = 0
munlock(0x7fe5971ae000, 4096) = 0
munlock(0x7fe5971af000, 4096) = 0
munlock(0x7fe5971b0000, 4096) = 0
munlock(0x7fe5971b1000, 1667072) = 0
munlock(0x7fe597548000, 16384) = 0
munlock(0x7fe59754c000, 4096) = 0
munlock(0x7fe59754d000, 20480) = 0
munlock(0x7fe597794000, 4096) = 0
munlock(0x7fe597795000, 159744) = 0
munlock(0x7fe5979bc000, 8192) = 0
munlock(0x7fe5979be000, 20480) = 0
munlock(0x7fe597bc2000, 4096) = 0
munlock(0x7fe597bc3000, 8192) = 0
munlock(0x7fe597dc5000, 4096) = 0
munlock(0x7fe597dc6000, 4096) = 0
munlock(0x7fe597dc7000, 57344) = 0
munlock(0x7fe597fd4000, 4096) = 0
munlock(0x7fe597fd5000, 4096) = 0
munlock(0x7fe597fd6000, 131072) = 0
munlock(0x7fe5981ee000, 28672) = 0
munlock(0x7fe5981f5000, 4096) = 0
munlock(0x7fe5981f6000, 4096) = 0
munlock(0x7fe5981f7000, 4096) = 0
munlock(0x7fffbb0b3000, 0) = 0
munlock(0x7fffbb0b3000, 290816) = 0
close(6) = 0
setpriority(PRIO_PROCESS, 0, 0) = 0
brk(0x1fff000) = 0x1fff000
semget(0xd4dc839, 1, 0) = 32769
semctl(32769, 0, GETVAL, 0xffffffffffffffff) = 2
semop(32769, {{0, -1, IPC_NOWAIT}}, 1) = 0
semop(32769, {{0, 0, 0}}, 1


Here the output of ipcs... the lvcreate command was in hung state while collecting ipcs output

------ Shared Memory Segments --------
key shmid owner perms bytes nattch status 

------ Semaphore Arrays --------
key semid owner perms nsems 
0x00000000 0 root 600 1 
0x0d4dff67 32769 root 600 1 

------ Message Queues --------
key msqid owner perms used-bytes messages 




ipcs -a -p 


------ Shared Memory Creator/Last-op --------
shmid owner cpid lpid 


------ Message Queues PIDs --------
msqid owner lspid lrpid
Comment 3 Alasdair Kergon 2012-07-04 15:05:53 UTC 
Is udev running?  Did you change any udev rules from the default installation?

(A udev rule should have fired and decremented the semaphore.)

Use -vvvv with lvm commands for debugging messages.  (So provide the complete lvcreate -vvvv output.)

Use 'dmsetup udevcookies' to view the relevant semaphore state, so provide that too.

If you need more assistance, you should open a support ticket through the Customer Portal at https://access.redhat.com/home and reference this bugzilla and supply an sosreport.
Comment 4 atuld 2012-07-04 16:28:09 UTC 
lvcreate -vvvv --size 16326656K --permission rw --name lv_root vg_cfttstvm52 /dev/sda2
#lvmcmdline.c:1045         Processing: lvcreate -vvvv --size 16326656K --permission rw --name lv_root vg_cfttstvm52 /dev/sda2
#lvmcmdline.c:1048         O_DIRECT will be used
#config/config.c:1001       global/locking_type not found in config: defaulting to 1
#config/config.c:1001       global/wait_for_locks not found in config: defaulting to 1
#locking/locking.c:242       File-based locking selected.
#config/config.c:979       global/locking_dir not found in config: defaulting to /var/lock/lvm
#activate/activate.c:403       Getting target version for linear
#ioctl/libdm-iface.c:1628         dm versions   OF   [16384]
#activate/activate.c:403       Getting target version for striped
#ioctl/libdm-iface.c:1628         dm versions   OF   [16384]
#lvcreate.c:295     Setting logging type to disk
#config/config.c:1001       activation/mirror_region_size not found in config: defaulting to 512
#lvcreate.c:603     Finding volume group "vg_cfttstvm52"
#locking/file_locking.c:235       Locking /var/lock/lvm/V_vg_cfttstvm52 WB
#locking/file_locking.c:141         _do_flock /var/lock/lvm/V_vg_cfttstvm52:aux WB
#locking/file_locking.c:141         _do_flock /var/lock/lvm/V_vg_cfttstvm52 WB
#locking/file_locking.c:51         _undo_flock /var/lock/lvm/V_vg_cfttstvm52:aux
#device/dev-cache.c:331         /dev/sr0: Added to device cache
#device/dev-cache.c:328         /dev/block/11:0: Aliased to /dev/sr0 in device cache
#device/dev-cache.c:328         /dev/scd0: Aliased to /dev/sr0 in device cache (preferred name)
#device/dev-cache.c:331         /dev/sda: Added to device cache
#device/dev-cache.c:328         /dev/block/8:0: Aliased to /dev/sda in device cache
#device/dev-cache.c:331         /dev/sda1: Added to device cache
#device/dev-cache.c:328         /dev/block/8:1: Aliased to /dev/sda1 in device cache
#device/dev-cache.c:331         /dev/sda2: Added to device cache
#device/dev-cache.c:328         /dev/block/8:2: Aliased to /dev/sda2 in device cache
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:577       (null): stat failed: Bad address
#device/dev-cache.c:546         /dev: Failed to insert devices from udev-managed directory to device cache fully
#device/dev-io.c:535         Opened /dev/sda RO O_DIRECT
#device/dev-io.c:271       /dev/sda: size is 41943040 sectors
#device/dev-io.c:137         /dev/sda: block size is 4096 bytes
#filters/filter.c:168         /dev/sda: Skipping: Partition table signature found
#device/dev-io.c:588         Closed /dev/sda
#filters/filter.c:145         /dev/scd0: Skipping: Unrecognised LVM device type 11
#device/dev-io.c:535         Opened /dev/sda1 RO O_DIRECT
#device/dev-io.c:271       /dev/sda1: size is 1024000 sectors
#device/dev-io.c:588         Closed /dev/sda1
#device/dev-io.c:271       /dev/sda1: size is 1024000 sectors
#device/dev-io.c:535         Opened /dev/sda1 RO O_DIRECT
#device/dev-io.c:137         /dev/sda1: block size is 4096 bytes
#device/dev-io.c:588         Closed /dev/sda1
#filters/filter-composite.c:31         Using /dev/sda1
#device/dev-io.c:535         Opened /dev/sda1 RO O_DIRECT
#device/dev-io.c:137         /dev/sda1: block size is 4096 bytes
#label/label.c:186       /dev/sda1: No label detected
#device/dev-io.c:588         Closed /dev/sda1
#device/dev-io.c:535         Opened /dev/sda2 RO O_DIRECT
#device/dev-io.c:271       /dev/sda2: size is 40916992 sectors
#device/dev-io.c:588         Closed /dev/sda2
#device/dev-io.c:271       /dev/sda2: size is 40916992 sectors
#device/dev-io.c:535         Opened /dev/sda2 RO O_DIRECT
#device/dev-io.c:137         /dev/sda2: block size is 4096 bytes
#device/dev-io.c:588         Closed /dev/sda2
#filters/filter-composite.c:31         Using /dev/sda2
#device/dev-io.c:535         Opened /dev/sda2 RO O_DIRECT
#device/dev-io.c:137         /dev/sda2: block size is 4096 bytes
#label/label.c:162       /dev/sda2: lvm2 label detected at sector 1
#cache/lvmcache.c:1226         lvmcache: /dev/sda2: now in VG #orphans_lvm2 (#orphans_lvm2)
#format_text/format-text.c:1187         /dev/sda2: Found metadata at 4608 size 739 (in area at 4096 size 1044480) for vg_cfttstvm52 (IpKz8K-7rBS-ocU0-27TU-NVJj-pF1N-RUHl6H)
#cache/lvmcache.c:1226         lvmcache: /dev/sda2: now in VG vg_cfttstvm52 with 1 mdas
#cache/lvmcache.c:1003         lvmcache: /dev/sda2: setting vg_cfttstvm52 VGID to IpKz8K7rBSocU027TUNVJjpF1NRUHl6H
#cache/lvmcache.c:1263         lvmcache: /dev/sda2: VG vg_cfttstvm52: Set creation host to cft-tstvm52.vxindia.veritas.com.
#label/label.c:272         Using cached label for /dev/sda2
#metadata/vg.c:53         Allocated VG vg_cfttstvm52 at 0x10f3ec0.
#label/label.c:272         Using cached label for /dev/sda2
#format_text/format-text.c:522         Read vg_cfttstvm52 metadata (1) from /dev/sda2 at 4608 size 739
#metadata/pv_manip.c:327         /dev/sda2 0:      0   4994: NULL(0:0)
#toollib.c:950         Adding PE range: start PE 0 length 4994 on /dev/sda2
#libdm-file.c:27     Creating directory "/etc/lvm/archive"
#format_text/archiver.c:128     Archiving volume group "vg_cfttstvm52" metadata (seqno 1).
#metadata/lv_manip.c:2799     Creating logical volume lv_root
#metadata/lv_manip.c:2472       Extending segment type, striped
#metadata/pv_map.c:55         Allowing allocation on /dev/sda2 start PE 0 length 4994
#metadata/lv_manip.c:1928         Trying allocation using contiguous policy.
#metadata/lv_manip.c:1596         Still need 3986 extents for 1 parallel areas and 0 log areas of 0 extents. (Total 3986 extents.)
#metadata/lv_manip.c:1276         Considering allocation area 0 as /dev/sda2 start PE 0 length 3986 leaving 1008.
#metadata/lv_manip.c:1059         Allocating parallel area 0 on /dev/sda2 start PE 0 length 3986.
#metadata/pv_manip.c:327         /dev/sda2 0:      0   3986: lv_root(0:0)
#metadata/pv_manip.c:327         /dev/sda2 1:   3986   1008: NULL(0:0)
#device/dev-io.c:588         Closed /dev/sda2
#device/dev-io.c:535         Opened /dev/sda2 RW O_DIRECT
#device/dev-io.c:137         /dev/sda2: block size is 4096 bytes
#format_text/format-text.c:629         Writing vg_cfttstvm52 metadata to /dev/sda2 at 5632 len 1004
#format_text/format-text.c:734         Pre-Committing vg_cfttstvm52 metadata (2) to /dev/sda2 header at 4096
#format_text/format-text.c:734         Committing vg_cfttstvm52 metadata (2) to /dev/sda2 header at 4096
#libdm-file.c:27     Creating directory "/etc/lvm/backup"
#format_text/archiver.c:395     Creating volume group backup "/etc/lvm/backup/vg_cfttstvm52" (seqno 2).
#format_text/format-text.c:929         Writing vg_cfttstvm52 metadata to /etc/lvm/backup/.lvm_cft-tstvm52.vxindia.veritas.com_8484_587476127
#format_text/format-text.c:973         Committing vg_cfttstvm52 metadata (2)
#format_text/format-text.c:974         Renaming /etc/lvm/backup/vg_cfttstvm52.tmp to /etc/lvm/backup/vg_cfttstvm52
#locking/file_locking.c:305       Locking LV IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA (R)
#metadata/metadata.c:3439       Finding volume group for uuid IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA
#label/label.c:162       /dev/sda2: lvm2 label detected at sector 1
#cache/lvmcache.c:1226         lvmcache: /dev/sda2: now in VG #orphans_lvm2 (#orphans_lvm2) with 1 mdas
#format_text/format-text.c:1187         /dev/sda2: Found metadata at 5632 size 1004 (in area at 4096 size 1044480) for vg_cfttstvm52 (IpKz8K-7rBS-ocU0-27TU-NVJj-pF1N-RUHl6H)
#cache/lvmcache.c:1226         lvmcache: /dev/sda2: now in VG vg_cfttstvm52 with 1 mdas
#cache/lvmcache.c:1003         lvmcache: /dev/sda2: setting vg_cfttstvm52 VGID to IpKz8K7rBSocU027TUNVJjpF1NRUHl6H
#cache/lvmcache.c:1263         lvmcache: /dev/sda2: VG vg_cfttstvm52: Set creation host to cft-tstvm52.vxindia.veritas.com.
#metadata/vg.c:53         Allocated VG vg_cfttstvm52 at 0x10fbee0.
#label/label.c:272         Using cached label for /dev/sda2
#format_text/format-text.c:522         Read vg_cfttstvm52 metadata (2) from /dev/sda2 at 5632 size 1004
#metadata/metadata.c:3445     Found volume group "vg_cfttstvm52"
#activate/activate.c:294     activation/volume_list configuration setting not defined, checking only host tags for vg_cfttstvm52/lv_root
#activate/activate.c:1556         Activating vg_cfttstvm52/lv_root.
#activate/dev_manager.c:282         Getting device info for vg_cfttstvm52-lv_root [LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA]
#ioctl/libdm-iface.c:1628         dm info  LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA NF   [16384]
#ioctl/libdm-iface.c:1628         dm info  IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA NF   [16384]
#device/dev-io.c:302       /dev/sda2: read_ahead is 256 sectors
#mm/memlock.c:402         Entering critical section (activating).
#mm/memlock.c:378         Lock:   Memlock counters: locked:0 critical:1 daemon:0 suspended:0
#mm/memlock.c:330       Locking memory
#mm/memlock.c:212         mlock        792KiB       400000 -       4c6000 r-xp 00000000 0b:00 21169                              /mnt/srt/sbin/lvm
#mm/memlock.c:212         mlock         32KiB       6c6000 -       6ce000 rw-p 000c6000 0b:00 21169                              /mnt/srt/sbin/lvm
#mm/memlock.c:212         mlock         28KiB       6ce000 -       6d5000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         mlock      10544KiB      10bd000 -      1b09000 rw-p 00000000 00:00 0                                  [heap]
#mm/memlock.c:186         mlock default filter '/libtinfo.so.' matches '7f4dbf5b6000-7f4dbf5d3000 r-xp 00000000 00:01 3670                       /lib64/libtinfo.so.5': Skipping.
#mm/memlock.c:168         mlock area unreadable 7f4dbf5d3000-7f4dbf7d3000 ---p 0001d000 00:01 3670                       /lib64/libtinfo.so.5 : Skipping.
#mm/memlock.c:186         mlock default filter '/libtinfo.so.' matches '7f4dbf7d3000-7f4dbf7d7000 rw-p 0001d000 00:01 3670                       /lib64/libtinfo.so.5': Skipping.
#mm/memlock.c:212         mlock        236KiB 7f4dbf7d7000 - 7f4dbf812000 r-xp 00000000 00:01 3666                       /lib64/libsepol.so.1
#mm/memlock.c:168         mlock area unreadable 7f4dbf812000-7f4dbfa12000 ---p 0003b000 00:01 3666                       /lib64/libsepol.so.1 : Skipping.
#mm/memlock.c:212         mlock          4KiB 7f4dbfa12000 - 7f4dbfa13000 r--p 0003b000 00:01 3666                       /lib64/libsepol.so.1
#mm/memlock.c:212         mlock          4KiB 7f4dbfa13000 - 7f4dbfa14000 rw-p 0003c000 00:01 3666                       /lib64/libsepol.so.1
#mm/memlock.c:212         mlock        116KiB 7f4dbfa14000 - 7f4dbfa31000 r-xp 00000000 00:01 3674                       /lib64/libselinux.so.1
#mm/memlock.c:168         mlock area unreadable 7f4dbfa31000-7f4dbfc30000 ---p 0001d000 00:01 3674                       /lib64/libselinux.so.1 : Skipping.
#mm/memlock.c:212         mlock          4KiB 7f4dbfc30000 - 7f4dbfc31000 r--p 0001c000 00:01 3674                       /lib64/libselinux.so.1
#mm/memlock.c:212         mlock          4KiB 7f4dbfc31000 - 7f4dbfc32000 rw-p 0001d000 00:01 3674                       /lib64/libselinux.so.1
#mm/memlock.c:212         mlock          4KiB 7f4dbfc32000 - 7f4dbfc33000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         mlock       1628KiB 7f4dbfc33000 - 7f4dbfdca000 r-xp 00000000 00:01 3681                       /lib64/libc.so.6
#mm/memlock.c:168         mlock area unreadable 7f4dbfdca000-7f4dbffca000 ---p 00197000 00:01 3681                       /lib64/libc.so.6 : Skipping.
#mm/memlock.c:212         mlock         16KiB 7f4dbffca000 - 7f4dbffce000 r--p 00197000 00:01 3681                       /lib64/libc.so.6
#mm/memlock.c:212         mlock          4KiB 7f4dbffce000 - 7f4dbffcf000 rw-p 0019b000 00:01 3681                       /lib64/libc.so.6
#mm/memlock.c:212         mlock         20KiB 7f4dbffcf000 - 7f4dbffd4000 rw-p 00000000 00:00 0 
#mm/memlock.c:186         mlock default filter '/libreadline.so.' matches '7f4dbffd4000-7f4dc000e000 r-xp 00000000 0b:00 4247                       /mnt/srt/lib64/libreadline.so.6.0': Skipping.
#mm/memlock.c:168         mlock area unreadable 7f4dc000e000-7f4dc020e000 ---p 0003a000 0b:00 4247                       /mnt/srt/lib64/libreadline.so.6.0 : Skipping.
#mm/memlock.c:186         mlock default filter '/libreadline.so.' matches '7f4dc020e000-7f4dc0216000 rw-p 0003a000 0b:00 4247                       /mnt/srt/lib64/libreadline.so.6.0': Skipping.
#mm/memlock.c:212         mlock          4KiB 7f4dc0216000 - 7f4dc0217000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         mlock        156KiB 7f4dc0217000 - 7f4dc023e000 r-xp 00000000 00:01 3692                       /lib64/libdevmapper.so.1.02
#mm/memlock.c:168         mlock area unreadable 7f4dc023e000-7f4dc043e000 ---p 00027000 00:01 3692                       /lib64/libdevmapper.so.1.02 : Skipping.
#mm/memlock.c:212         mlock          8KiB 7f4dc043e000 - 7f4dc0440000 rw-p 00027000 00:01 3692                       /lib64/libdevmapper.so.1.02
#mm/memlock.c:212         mlock         20KiB 7f4dc0440000 - 7f4dc0445000 r-xp 00000000 00:01 3695                       /lib64/libdevmapper-event.so.1.02
#mm/memlock.c:168         mlock area unreadable 7f4dc0445000-7f4dc0644000 ---p 00005000 00:01 3695                       /lib64/libdevmapper-event.so.1.02 : Skipping.
#mm/memlock.c:212         mlock          4KiB 7f4dc0644000 - 7f4dc0645000 rw-p 00004000 00:01 3695                       /lib64/libdevmapper-event.so.1.02
#mm/memlock.c:212         mlock          8KiB 7f4dc0645000 - 7f4dc0647000 r-xp 00000000 00:01 3673                       /lib64/libdl.so.2
#mm/memlock.c:168         mlock area unreadable 7f4dc0647000-7f4dc0847000 ---p 00002000 00:01 3673                       /lib64/libdl.so.2 : Skipping.
#mm/memlock.c:212         mlock          4KiB 7f4dc0847000 - 7f4dc0848000 r--p 00002000 00:01 3673                       /lib64/libdl.so.2
#mm/memlock.c:212         mlock          4KiB 7f4dc0848000 - 7f4dc0849000 rw-p 00003000 00:01 3673                       /lib64/libdl.so.2
#mm/memlock.c:212         mlock         56KiB 7f4dc0849000 - 7f4dc0857000 r-xp 00000000 00:01 3676                       /lib64/libudev.so.0
#mm/memlock.c:168         mlock area unreadable 7f4dc0857000-7f4dc0a56000 ---p 0000e000 00:01 3676                       /lib64/libudev.so.0 : Skipping.
#mm/memlock.c:212         mlock          4KiB 7f4dc0a56000 - 7f4dc0a57000 r--p 0000d000 00:01 3676                       /lib64/libudev.so.0
#mm/memlock.c:212         mlock          4KiB 7f4dc0a57000 - 7f4dc0a58000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         mlock        128KiB 7f4dc0a58000 - 7f4dc0a78000 r-xp 00000000 00:01 3691                       /lib64/ld-linux-x86-64.so.2
#mm/memlock.c:212         mlock         28KiB 7f4dc0c70000 - 7f4dc0c77000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         mlock          4KiB 7f4dc0c77000 - 7f4dc0c78000 r--p 0001f000 00:01 3691                       /lib64/ld-linux-x86-64.so.2
#mm/memlock.c:212         mlock          4KiB 7f4dc0c78000 - 7f4dc0c79000 rw-p 00020000 00:01 3691                       /lib64/ld-linux-x86-64.so.2
#mm/memlock.c:212         mlock          4KiB 7f4dc0c79000 - 7f4dc0c7a000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         mlock        280KiB 7fff16130000 - 7fff16176000 rw-p 00000000 00:00 0                          [stack]
#mm/memlock.c:176         mlock ignore filter '[vdso]' matches '7fff161ff000-7fff16200000 r-xp 00000000 00:00 0                          [vdso]': Skipping.
#mm/memlock.c:176         mlock ignore filter '[vsyscall]' matches 'ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]': Skipping.
#mm/memlock.c:297         Locked 14495744 bytes
#activate/dev_manager.c:942         Getting device info for vg_cfttstvm52-lv_root [LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA]
#ioctl/libdm-iface.c:1628         dm info  LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA OF   [16384]
#ioctl/libdm-iface.c:1628         dm info  IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA OF   [16384]
#activate/dev_manager.c:942         Getting device info for vg_cfttstvm52-lv_root-real [LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-real]
#ioctl/libdm-iface.c:1628         dm info  LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-real OF   [16384]
#ioctl/libdm-iface.c:1628         dm info  IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-real OF   [16384]
#activate/dev_manager.c:942         Getting device info for vg_cfttstvm52-lv_root-cow [LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-cow]
#ioctl/libdm-iface.c:1628         dm info  LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-cow OF   [16384]
#ioctl/libdm-iface.c:1628         dm info  IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-cow OF   [16384]
#activate/dev_manager.c:1431         Checking kernel supports striped segment type for lv_root
#metadata/metadata.c:2240         Calculated readahead of LV lv_root is 256
#libdm-deptree.c:1418     Creating vg_cfttstvm52-lv_root
#ioctl/libdm-iface.c:1628         dm create vg_cfttstvm52-lv_root LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA NF   [16384]
#libdm-deptree.c:1923     Loading vg_cfttstvm52-lv_root table (253:0)
#libdm-deptree.c:1867         Adding target to (253:0): 0 32653312 linear 8:2 2048
#ioctl/libdm-iface.c:1628         dm table   (253:0) OF   [16384]
#ioctl/libdm-iface.c:1628         dm reload   (253:0) NF   [16384]
#libdm-deptree.c:1963         Table size changed from 0 to 32653312 for vg_cfttstvm52-lv_root
#libdm-deptree.c:1076     Resuming vg_cfttstvm52-lv_root (253:0)
#libdm-common.c:1367         Udev cookie 0xd4d2977 (semid 32769) created
#libdm-common.c:1387         Udev cookie 0xd4d2977 (semid 32769) incremented to 1
#libdm-common.c:1259         Udev cookie 0xd4d2977 (semid 32769) incremented to 2
#libdm-common.c:1500         Udev cookie 0xd4d2977 (semid 32769) assigned to RESUME task(5) with flags DISABLE_LIBRARY_FALLBACK (0x20)
#ioctl/libdm-iface.c:1628         dm resume   (253:0) NF   [16384]
#libdm-common.c:845         vg_cfttstvm52-lv_root: Stacking NODE_ADD (253,0) 0:6 0660 [trust_udev]
#libdm-common.c:855         vg_cfttstvm52-lv_root: Stacking NODE_READ_AHEAD 256 (flags=1)
#activate/dev_manager.c:942         Getting device info for vg_cfttstvm52-lv_root [LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA]
#ioctl/libdm-iface.c:1628         dm info  LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA OF   [16384]
#ioctl/libdm-iface.c:1628         dm deps   (253:0) OF   [16384]
#activate/dev_manager.c:942         Getting device info for vg_cfttstvm52-lv_root-real [LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-real]
#ioctl/libdm-iface.c:1628         dm info  LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-real OF   [16384]
#ioctl/libdm-iface.c:1628         dm info  IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-real OF   [16384]
#activate/dev_manager.c:942         Getting device info for vg_cfttstvm52-lv_root-cow [LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-cow]
#ioctl/libdm-iface.c:1628         dm info  LVM-IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-cow OF   [16384]
#ioctl/libdm-iface.c:1628         dm info  IpKz8K7rBSocU027TUNVJjpF1NRUHl6HW2WdKOYY1c59idwJk6lfY2UTdnjThQMA-cow OF   [16384]
#mm/memlock.c:412         Leaving critical section (activated).
#metadata/vg.c:68         Freeing VG vg_cfttstvm52 at 0x10fbee0.
#mm/memlock.c:389         Unlock: Memlock counters: locked:1 critical:0 daemon:0 suspended:0
#mm/memlock.c:347       Unlocking memory
#mm/memlock.c:212         munlock        792KiB       400000 -       4c6000 r-xp 00000000 0b:00 21169                              /mnt/srt/sbin/lvm
#mm/memlock.c:212         munlock         32KiB       6c6000 -       6ce000 rw-p 000c6000 0b:00 21169                              /mnt/srt/sbin/lvm
#mm/memlock.c:212         munlock         28KiB       6ce000 -       6d5000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         munlock      10544KiB      10bd000 -      1b09000 rw-p 00000000 00:00 0                                  [heap]
#mm/memlock.c:186         mlock default filter '/libtinfo.so.' matches '7f4dbf5b6000-7f4dbf5d3000 r-xp 00000000 00:01 3670                       /lib64/libtinfo.so.5': Skipping.
#mm/memlock.c:168         munlock area unreadable 7f4dbf5d3000-7f4dbf7d3000 ---p 0001d000 00:01 3670                       /lib64/libtinfo.so.5 : Skipping.
#mm/memlock.c:186         mlock default filter '/libtinfo.so.' matches '7f4dbf7d3000-7f4dbf7d7000 rw-p 0001d000 00:01 3670                       /lib64/libtinfo.so.5': Skipping.
#mm/memlock.c:212         munlock        236KiB 7f4dbf7d7000 - 7f4dbf812000 r-xp 00000000 00:01 3666                       /lib64/libsepol.so.1
#mm/memlock.c:168         munlock area unreadable 7f4dbf812000-7f4dbfa12000 ---p 0003b000 00:01 3666                       /lib64/libsepol.so.1 : Skipping.
#mm/memlock.c:212         munlock          4KiB 7f4dbfa12000 - 7f4dbfa13000 r--p 0003b000 00:01 3666                       /lib64/libsepol.so.1
#mm/memlock.c:212         munlock          4KiB 7f4dbfa13000 - 7f4dbfa14000 rw-p 0003c000 00:01 3666                       /lib64/libsepol.so.1
#mm/memlock.c:212         munlock        116KiB 7f4dbfa14000 - 7f4dbfa31000 r-xp 00000000 00:01 3674                       /lib64/libselinux.so.1
#mm/memlock.c:168         munlock area unreadable 7f4dbfa31000-7f4dbfc30000 ---p 0001d000 00:01 3674                       /lib64/libselinux.so.1 : Skipping.
#mm/memlock.c:212         munlock          4KiB 7f4dbfc30000 - 7f4dbfc31000 r--p 0001c000 00:01 3674                       /lib64/libselinux.so.1
#mm/memlock.c:212         munlock          4KiB 7f4dbfc31000 - 7f4dbfc32000 rw-p 0001d000 00:01 3674                       /lib64/libselinux.so.1
#mm/memlock.c:212         munlock          4KiB 7f4dbfc32000 - 7f4dbfc33000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         munlock       1628KiB 7f4dbfc33000 - 7f4dbfdca000 r-xp 00000000 00:01 3681                       /lib64/libc.so.6
#mm/memlock.c:168         munlock area unreadable 7f4dbfdca000-7f4dbffca000 ---p 00197000 00:01 3681                       /lib64/libc.so.6 : Skipping.
#mm/memlock.c:212         munlock         16KiB 7f4dbffca000 - 7f4dbffce000 r--p 00197000 00:01 3681                       /lib64/libc.so.6
#mm/memlock.c:212         munlock          4KiB 7f4dbffce000 - 7f4dbffcf000 rw-p 0019b000 00:01 3681                       /lib64/libc.so.6
#mm/memlock.c:212         munlock         20KiB 7f4dbffcf000 - 7f4dbffd4000 rw-p 00000000 00:00 0 
#mm/memlock.c:186         mlock default filter '/libreadline.so.' matches '7f4dbffd4000-7f4dc000e000 r-xp 00000000 0b:00 4247                       /mnt/srt/lib64/libreadline.so.6.0': Skipping.
#mm/memlock.c:168         munlock area unreadable 7f4dc000e000-7f4dc020e000 ---p 0003a000 0b:00 4247                       /mnt/srt/lib64/libreadline.so.6.0 : Skipping.
#mm/memlock.c:186         mlock default filter '/libreadline.so.' matches '7f4dc020e000-7f4dc0216000 rw-p 0003a000 0b:00 4247                       /mnt/srt/lib64/libreadline.so.6.0': Skipping.
#mm/memlock.c:212         munlock          4KiB 7f4dc0216000 - 7f4dc0217000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         munlock        156KiB 7f4dc0217000 - 7f4dc023e000 r-xp 00000000 00:01 3692                       /lib64/libdevmapper.so.1.02
#mm/memlock.c:168         munlock area unreadable 7f4dc023e000-7f4dc043e000 ---p 00027000 00:01 3692                       /lib64/libdevmapper.so.1.02 : Skipping.
#mm/memlock.c:212         munlock          8KiB 7f4dc043e000 - 7f4dc0440000 rw-p 00027000 00:01 3692                       /lib64/libdevmapper.so.1.02
#mm/memlock.c:212         munlock         20KiB 7f4dc0440000 - 7f4dc0445000 r-xp 00000000 00:01 3695                       /lib64/libdevmapper-event.so.1.02
#mm/memlock.c:168         munlock area unreadable 7f4dc0445000-7f4dc0644000 ---p 00005000 00:01 3695                       /lib64/libdevmapper-event.so.1.02 : Skipping.
#mm/memlock.c:212         munlock          4KiB 7f4dc0644000 - 7f4dc0645000 rw-p 00004000 00:01 3695                       /lib64/libdevmapper-event.so.1.02
#mm/memlock.c:212         munlock          8KiB 7f4dc0645000 - 7f4dc0647000 r-xp 00000000 00:01 3673                       /lib64/libdl.so.2
#mm/memlock.c:168         munlock area unreadable 7f4dc0647000-7f4dc0847000 ---p 00002000 00:01 3673                       /lib64/libdl.so.2 : Skipping.
#mm/memlock.c:212         munlock          4KiB 7f4dc0847000 - 7f4dc0848000 r--p 00002000 00:01 3673                       /lib64/libdl.so.2
#mm/memlock.c:212         munlock          4KiB 7f4dc0848000 - 7f4dc0849000 rw-p 00003000 00:01 3673                       /lib64/libdl.so.2
#mm/memlock.c:212         munlock         56KiB 7f4dc0849000 - 7f4dc0857000 r-xp 00000000 00:01 3676                       /lib64/libudev.so.0
#mm/memlock.c:168         munlock area unreadable 7f4dc0857000-7f4dc0a56000 ---p 0000e000 00:01 3676                       /lib64/libudev.so.0 : Skipping.
#mm/memlock.c:212         munlock          4KiB 7f4dc0a56000 - 7f4dc0a57000 r--p 0000d000 00:01 3676                       /lib64/libudev.so.0
#mm/memlock.c:212         munlock          4KiB 7f4dc0a57000 - 7f4dc0a58000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         munlock        128KiB 7f4dc0a58000 - 7f4dc0a78000 r-xp 00000000 00:01 3691                       /lib64/ld-linux-x86-64.so.2
#mm/memlock.c:212         munlock         28KiB 7f4dc0c70000 - 7f4dc0c77000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         munlock          4KiB 7f4dc0c77000 - 7f4dc0c78000 r--p 0001f000 00:01 3691                       /lib64/ld-linux-x86-64.so.2
#mm/memlock.c:212         munlock          4KiB 7f4dc0c78000 - 7f4dc0c79000 rw-p 00020000 00:01 3691                       /lib64/ld-linux-x86-64.so.2
#mm/memlock.c:212         munlock          4KiB 7f4dc0c79000 - 7f4dc0c7a000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         munlock          0KiB 7fff16130000 - 7fff16130000 rw-p 00000000 00:00 0 
#mm/memlock.c:212         munlock        280KiB 7fff16130000 - 7fff16176000 rw-p 00000000 00:00 0                          [stack]
#mm/memlock.c:176         mlock ignore filter '[vdso]' matches '7fff161ff000-7fff16200000 r-xp 00000000 00:00 0                          [vdso]': Skipping.
#mm/memlock.c:176         mlock ignore filter '[vsyscall]' matches 'ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]': Skipping.
#mm/memlock.c:297         Unlocked 14495744 bytes
#activate/fs.c:486         Syncing device names
#libdm-common.c:1294         Udev cookie 0xd4d2977 (semid 32769) decremented to 1
#libdm-common.c:1550         Udev cookie 0xd4d2977 (semid 32769) waiting for zero
Comment 5 Alasdair Kergon 2012-07-04 17:23:02 UTC 
Points to a udev configuration problem on your machine.  Check your udev packages and rule installations carefully.

These messages need investigating:
#device/dev-cache.c:577       (null): stat failed: Bad address

Perhaps strace and ltrace that part of the command and see what's going on.
Comment 6 Peter Rajnoha 2012-07-04 18:09:57 UTC 
(In reply to comment #5)
> Points to a udev configuration problem on your machine.  Check your udev
> packages and rule installations carefully.
> 
> These messages need investigating:
> #device/dev-cache.c:577       (null): stat failed: Bad address
> 

...this might be related to bug #784648 (or even the same problem). The "udev returns null value" problem should be fixed in 6.3.

However, the hang on the semaphore might be a different one... If it's possible and if it's safe to do a test run, please, try to temporarily run udev in debug mode and try to grab the log:

  killall udevd
  udevd --debug &> udevd.log
  (the lvcreate command now)

Then you can kill the "udevd --debug" and go back to normal mode with "udevd --daemon".

We should see all the udev processing in the log then.
Comment 7 atuld 2012-07-05 13:10:08 UTC 
Thank you for quick responses.

this might be critical information w.r.t. this issue, so I am sharing at this point.
The scenario is, we have customized Boot image. The Boot image created for RHEL 6 and 6 U1 is working fine. I have created the boot image for RHEL 6.2 but now it is getting hang at lvcreate.

Any specific changes happened in RHEL 6 U 2 so which I need to take care here.

Can anyone provide bit detail about udev rule files which we need to take care of?
udev-*.x86_64.rpm is already part of this.

Any specific rpm need to add for this?  

Please let me know if any more information is required.
Comment 8 Alasdair Kergon 2012-07-05 13:21:34 UTC 
Please open a support ticket to take this further now at https://access.redhat.com/ referring to this bugzilla, as you'll probably need to submit an sosreport and more details of how you made the boot image and the udev diagnostics Peter mentioned.

Bugzilla is for dealing with bugs in the packages themselves and this is looking like a configuration problem at the moment rather than a software bug.
Comment 9 Peter Rajnoha 2012-09-11 10:57:52 UTC 
Did you find help through the customer portal as mentioned in comment #8? Does you problem still persist?
Comment 13 RHEL Program Management 2012-12-14 08:10:11 UTC 
This request was not resolved in time for the current release.
Red Hat invites you to ask your support representative to
propose this request, if still desired, for consideration in
the next release of Red Hat Enterprise Linux.
Comment 14 Peter Rajnoha 2012-12-14 08:18:28 UTC 
I'm closing this one as we don't have enough information to debug this problem (comment #6, comment #8, comment #9).

If you still hit this problem, please, reopen this bug report with the information requested above. Thanks.
Note You need to log in before you can comment on or make changes to this bug.