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 948073 - cluster mirror creation deadlocks
Summary: cluster mirror creation deadlocks
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: selinux-policy
Version: 7.0
Hardware: x86_64
OS: Linux
urgent
urgent
Target Milestone: rc
: ---
Assignee: Miroslav Grepl
QA Contact: Milos Malik
URL:
Whiteboard:
: 966943 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-04-03 22:33 UTC by Corey Marthaler
Modified: 2014-06-18 02:20 UTC (History)
11 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-06-13 12:48:16 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Corey Marthaler 2013-04-03 22:33:34 UTC
Description of problem:
# Note, I made sure to have a 3.8 kern to avoid the issues seen in 915058.

[root@qalvm-01 ~]# uname -ar
Linux qalvm-01 3.8.0-0.40.el7.x86_64 #1 SMP Thu Feb 28 17:41:03 EST 2013 x86_64 x86_64 x86_64 GNU/Linux

[root@qalvm-01 ~]# pcs status
Cluster name: QALVM
Last updated: Wed Apr  3 17:25:14 2013
Last change: Wed Apr  3 17:11:14 2013 via crmd on qalvm-03
Stack: corosync
Current DC: qalvm-01 (1) - partition with quorum
Version: 1.1.8-4.el7-5db5f53
3 Nodes configured, unknown expected votes
0 Resources configured.

Online: [ qalvm-01 qalvm-02 qalvm-03 ]

Full list of resources:

[root@qalvm-01 ~]# pcs config
Cluster Name: QALVM
Corosync Nodes:
 qalvm-01 qalvm-02 qalvm-03 
Pacemaker Nodes:
 qalvm-01 qalvm-02 qalvm-03 

Resources: 

Location Constraints:
Ordering Constraints:
Colocation Constraints:

Cluster Properties:
 dc-version: 1.1.8-4.el7-5db5f53
 cluster-infrastructure: corosync


[root@qalvm-01 ~]# service cmirrord status
cmirrord.service - LSB: Starts and stops cmirrord
          Loaded: loaded (/etc/rc.d/init.d/cmirrord)
          Active: active (running) since Wed 2013-04-03 17:21:51 CDT; 3min 37s ago
         Process: 1301 ExecStart=/etc/rc.d/init.d/cmirrord start (code=exited, status=0/SUCCESS)
          CGroup: name=systemd:/system/cmirrord.service
                  ââ1305 cmirrord

Apr 03 17:21:51 qalvm-01 cmirrord[1305]: Adding local/5
Apr 03 17:21:51 qalvm-01 cmirrord[1305]: used_pfds = 1, free_pfds = 0
Apr 03 17:21:51 qalvm-01 cmirrord[1305]: Starting cmirrord:
Apr 03 17:21:51 qalvm-01 cmirrord[1305]: Built: Apr  3 2013 09:28:29
Apr 03 17:21:51 qalvm-01 cmirrord[1301]: Starting cmirrord: [  OK  ]
Apr 03 17:21:51 qalvm-01 cmirrord[1305]: Compiled with debugging.
Apr 03 17:21:51 qalvm-01 systemd[1]: Started LSB: Starts and stops cmirrord.
cmirror is running.


[root@qalvm-01 ~]# service clvmd status
clvmd.service - LSB: This service is Clusterd LVM Daemon.
          Loaded: loaded (/etc/rc.d/init.d/clvmd)
          Active: active (running) since Wed 2013-04-03 17:21:58 CDT; 3min 38s ago
         Process: 1330 ExecStart=/etc/rc.d/init.d/clvmd start (code=exited, status=0/SUCCESS)
          CGroup: name=systemd:/system/clvmd.service
                  ââ1335 clvmd -T30

Apr 03 17:21:53 qalvm-01 clvmd[1335]: Cluster LVM daemon started - connected to Corosync
Apr 03 17:21:54 qalvm-01 clvmd[1330]: Starting clvmd:
Apr 03 17:21:58 qalvm-01 clvmd[1330]: Activating VG(s):   2 logical volume(s) in volume group "rhel_qalvm-01" now active
Apr 03 17:21:58 qalvm-01 clvmd[1330]: [  OK  ]
Apr 03 17:21:58 qalvm-01 systemd[1]: Started LSB: This service is Clusterd LVM Daemon..
Clustered Volume Groups: (none)
Active clustered Logical Volumes: (none)


[root@qalvm-01 ~]# pvscan
  PV /dev/sda2   VG rhel_qalvm-01   lvm2 [24.51 GiB / 0    free]
  Total: 1 [24.51 GiB] / in use: 1 [24.51 GiB] / in no VG: 0 [0   ]

[root@qalvm-01 ~]# pvcreate /dev/vd[abcdefgh]
  Physical volume "/dev/vda" successfully created
  Physical volume "/dev/vdb" successfully created
  Physical volume "/dev/vdc" successfully created
  Physical volume "/dev/vdd" successfully created
  Physical volume "/dev/vde" successfully created
  Physical volume "/dev/vdf" successfully created
  Physical volume "/dev/vdg" successfully created
  Physical volume "/dev/vdh" successfully created

[root@qalvm-01 ~]# vgcreate qalvm /dev/vd[abcdefgh]
  Clustered volume group "qalvm" successfully created

[root@qalvm-01 ~]# pvscan
  PV /dev/sda2   VG rhel_qalvm-01   lvm2 [24.51 GiB / 0    free]
  PV /dev/vda    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  PV /dev/vdb    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  PV /dev/vdc    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  PV /dev/vdd    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  PV /dev/vde    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  PV /dev/vdf    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  PV /dev/vdg    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  PV /dev/vdh    VG qalvm           lvm2 [10.00 GiB / 10.00 GiB free]
  Total: 9 [104.48 GiB] / in use: 9 [104.48 GiB] / in no VG: 0 [0   ]

# Note, cluster linear creation works.

[root@qalvm-01 ~]# lvcreate -n clv -L 100M qalvm
  Logical volume "clv" created

[root@qalvm-01 ~]# lvs -a -o +devices
  LV   VG            Attr      LSize   Pool Origin Data%  Move Log Cpy%Sync Convert Devices        
  clv  qalvm         -wi-a---- 100.00m                                              /dev/vda(0)    
  root rhel_qalvm-01 -wi-ao---  20.57g                                              /dev/sda2(1008)
  swap rhel_qalvm-01 -wi-ao---   3.94g                                              /dev/sda2(0)   


[root@qalvm-01 ~]# lvcreate -n cmirror -m 1 -L 100M qalvm
  Error locking on node 2: Command timed out
  Error locking on node 1: Command timed out
  Error locking on node 3: Command timed out
  Failed to activate new LV.
  Error locking on node 2: Command timed out
  Error locking on node 1: Command timed out
  Error locking on node 3: Command timed out
  Unable to deactivate failed new LV. Manual intervention required.
[DEADLOCK]

# This is looping in the console:

Apr  3 17:26:53 qalvm-01 kernel: [  674.888633] device-mapper: dm-log-userspace: version 1.1.0 loaded
Apr  3 17:27:12 qalvm-01 cmirrord[1305]: Unable to open log device, /dev/mapper/qalvm-cmirror_mlog: Permission denied
Apr  3 17:27:12 qalvm-01 cmirrord[1305]: Failed to create cluster log (LVM-9ulbclVcTS2TlDrzWYOprmoXxEo916lBokm48Gw9AL7uIPCCjGfh8hfeZLlUpON9)
Apr  3 17:27:12 qalvm-01 cmirrord[1305]: argv[0] = clustered-disk
Apr  3 17:27:12 qalvm-01 cmirrord[1305]: argv[1] = 253:3
Apr  3 17:27:12 qalvm-01 cmirrord[1305]: argv[2] = 1024
[  708.897102] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/0] - retrying
Apr  3 17:27:27 qalvm-01 kernel: [  708.897102] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/0] - retrying
Apr  3 17:27:27 qalvm-01 cmirrord[1305]: Unable to open log device, /dev/mapper/qalvm-cmirror_mlog: Permission denied
Apr  3 17:27:27 qalvm-01 cmirrord[1305]: Failed to create cluster log (LVM-9ulbclVcTS2TlDrzWYOprmoXxEo916lBokm48Gw9AL7uIPCCjGfh8hfeZLlUpON9)
Apr  3 17:27:27 qalvm-01 cmirrord[1305]: argv[0] = clustered-disk
Apr  3 17:27:27 qalvm-01 cmirrord[1305]: argv[1] = 253:3
Apr  3 17:27:27 qalvm-01 cmirrord[1305]: argv[2] = 1024
[  723.898122] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/1] - retrying
Apr  3 17:27:42 qalvm-01 kernel: [  723.898122] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/1] - retrying
Apr  3 17:27:42 qalvm-01 cmirrord[1305]: Unable to open log device, /dev/mapper/qalvm-cmirror_mlog: Permission denied
Apr  3 17:27:42 qalvm-01 cmirrord[1305]: Failed to create cluster log (LVM-9ulbclVcTS2TlDrzWYOprmoXxEo916lBokm48Gw9AL7uIPCCjGfh8hfeZLlUpON9)
Apr  3 17:27:42 qalvm-01 cmirrord[1305]: argv[0] = clustered-disk
Apr  3 17:27:42 qalvm-01 cmirrord[1305]: argv[1] = 253:3
Apr  3 17:27:42 qalvm-01 cmirrord[1305]: argv[2] = 1024
[  738.899094] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/2] - retrying
Apr  3 17:27:57 qalvm-01 kernel: [  738.899094] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/2] - retrying
Apr  3 17:27:57 qalvm-01 cmirrord[1305]: Unable to open log device, /dev/mapper/qalvm-cmirror_mlog: Permission denied
Apr  3 17:27:57 qalvm-01 cmirrord[1305]: Failed to create cluster log (LVM-9ulbclVcTS2TlDrzWYOprmoXxEo916lBokm48Gw9AL7uIPCCjGfh8hfeZLlUpON9)
Apr  3 17:27:57 qalvm-01 cmirrord[1305]: argv[0] = clustered-disk
Apr  3 17:27:57 qalvm-01 cmirrord[1305]: argv[1] = 253:3
Apr  3 17:27:57 qalvm-01 cmirrord[1305]: argv[2] = 1024
[  753.900124] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/3] - retrying
Apr  3 17:28:12 qalvm-01 kernel: [  753.900124] device-mapper: dm-log-userspace: [ZLlUpON9] Request timed out: [1/3] - retrying
Apr  3 17:28:12 qalvm-01 cmirrord[1305]: Unable to open log device, /dev/mapper/qalvm-cmirror_mlog: Permission denied
Apr  3 17:28:12 qalvm-01 cmirrord[1305]: Failed to create cluster log (LVM-9ulbclVcTS2TlDrzWYOprmoXxEo916lBokm48Gw9AL7uIPCCjGfh8hfeZLlUpON9)
Apr  3 17:28:12 qalvm-01 cmirrord[1305]: argv[0] = clustered-disk
Apr  3 17:28:12 qalvm-01 cmirrord[1305]: argv[1] = 253:3
Apr  3 17:28:12 qalvm-01 cmirrord[1305]: argv[2] = 1024


Version-Release number of selected component (if applicable):
3.8.0-0.40.el7.x86_64

lvm2-2.02.99-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013
lvm2-libs-2.02.99-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013
lvm2-cluster-2.02.99-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013
device-mapper-1.02.78-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013
device-mapper-libs-1.02.78-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013
device-mapper-event-1.02.78-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013
device-mapper-event-libs-1.02.78-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013
cmirror-2.02.99-0.10.el7    BUILT: Wed Apr  3 08:28:34 CDT 2013


How reproducible:
Everytime

Comment 1 Corey Marthaler 2013-04-03 23:03:52 UTC
FWIW, cluster stripe creation works:

[root@qalvm-01 ~]# vgcreate qalvm /dev/vd[abcdefgh]
  Clustered volume group "qalvm" successfully created

[root@qalvm-01 ~]# lvcreate -i 2 -n cstripe -L 100M qalvm
  Using default stripesize 64.00 KiB
  Rounding size (25 extents) up to stripe boundary size (26 extents)
  Logical volume "cstripe" created

[root@qalvm-01 ~]# lvs -a -o +devices
  LV      VG            Attr      LSize   Pool Origin Data%  Move Log Cpy%Sync Convert Devices                
  cstripe qalvm         -wi-a---- 104.00m                                              /dev/vda(0),/dev/vdb(0)

Comment 2 Nenad Peric 2013-04-12 15:34:35 UTC
This seems to be a selinux issue, someone needs to take a look at default contexts the process and files created get. 

I got the same errors today:

Apr 12 10:24:35 tardis-03-port1 cmirrord[2530]: Failed to create cluster log (LVM-ras4qfNlT38hBNQvsPLBzcWhBerOduJTDqlRqi1vuDQOtFJe4HOk1r4ekRzs7wIq)
Apr 12 10:24:35 tardis-03-port1 cmirrord[2530]: argv[0] = clustered-disk
Apr 12 10:24:35 tardis-03-port1 cmirrord[2530]: argv[1] = 253:4
Apr 12 10:24:35 tardis-03-port1 cmirrord[2530]: argv[2] = 1024
Apr 12 10:24:50 tardis-03-port1 kernel: [  598.149052] device-mapper: dm-log-userspace: [kRzs7wIq] Request timed out: [1/10] - retrying
Apr 12 10:24:50 tardis-03-port1 cmirrord[2530]: Unable to open log device, /dev/mapper/linear_3_5702-linear_3_57020_mlog: Permission denied
Apr 12 10:24:50 tardis-03-port1 cmirrord[2530]: Failed to create cluster log (LVM-ras4qfNlT38hBNQvsPLBzcWhBerOduJTDqlRqi1vuDQOtFJe4HOk1r4ekRzs7wIq)
Apr 12 10:24:50 tardis-03-port1 cmirrord[2530]: argv[0] = clustered-disk
Apr 12 10:24:50 tardis-03-port1 cmirrord[2530]: argv[1] = 253:4
Apr 12 10:24:50 tardis-03-port1 cmirrord[2530]: argv[2] = 1024 


But after moving selinux to permissive, it started working.

Comment 3 Zdenek Kabelac 2013-05-14 09:05:08 UTC
Can we get selinux messages ?
'ausearch -sv no'

What is the domain in use ?

To me it looks more like selinux bug.

Comment 4 Nenad Peric 2013-05-15 11:13:46 UTC
Here is the output related to LV creation:

time->Wed May 15 06:09:07 2013
type=SYSCALL msg=audit(1368590947.667:156): arch=c000003e syscall=2 success=no exit=-13 a0=7fff9c1c7e10 a1=4002 a2=7d0 a3=0 items=0 ppid=1 pid=2054 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cmirrord" exe="/usr/sbin/cmirrord" subj=system_u:system_r:cmirrord_t:s0 key=(null)
type=AVC msg=audit(1368590947.667:156): avc:  denied  { read write } for  pid=2054 comm="cmirrord" name="dm-4" dev="devtmpfs" ino=39932 scontext=system_u:system_r:cmirrord_t:s0 tcontext=system_u:object_r:fixed_disk_device_t:s0 tclass=blk_file
----
time->Wed May 15 06:09:22 2013
type=SYSCALL msg=audit(1368590962.668:173): arch=c000003e syscall=2 success=no exit=-13 a0=7fff9c1c7e10 a1=4002 a2=7d0 a3=0 items=0 ppid=1 pid=2054 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cmirrord" exe="/usr/sbin/cmirrord" subj=system_u:system_r:cmirrord_t:s0 key=(null)
type=AVC msg=audit(1368590962.668:173): avc:  denied  { read write } for  pid=2054 comm="cmirrord" name="dm-4" dev="devtmpfs" ino=39932 scontext=system_u:system_r:cmirrord_t:s0 tcontext=system_u:object_r:fixed_disk_device_t:s0 tclass=blk_file


Not sure if this can be called a selinux bug, but rather rules issue, since they do not seem to even be defined for this case and then it keeps denying access.

Comment 5 Marian Csontos 2013-05-15 13:32:34 UTC
The device has the same context on RHEL6. Not sure about cmirrord: do not have one running here.

Reassigning to selinux-policy.

Comment 6 Miroslav Grepl 2013-05-16 11:47:17 UTC
Does it work if you execute

# grep cmirrord_t /var/log/audit/audit.log |audit2allow -M mypol
# semodule -i mypol.pp

Comment 7 Nenad Peric 2013-05-17 06:17:19 UTC
That is not enough, since the first denial prevents other denials to be shown, so that was not enough for the auto policy creation to work. 

I re-ran it with permissive mode and got the full denial list, and here's the result:



require {
	type cluster_tmpfs_t;
	type cmirrord_t;
	type fixed_disk_device_t;
	class capability sys_admin;
	class blk_file { read write open };
	class file { read write open };
}

#============= cmirrord_t ==============
allow cmirrord_t cluster_tmpfs_t:file { read write open };
allow cmirrord_t fixed_disk_device_t:blk_file { read write open };
allow cmirrord_t self:capability sys_admin;





And with this module active and SElinux enforcing, it works: 

[root@tardis-01-port1 ~]# getenforce
Enforcing

[root@tardis-01-port1 ~]# lvcreate -n mirrored -L120M -m1 cvg
  Logical volume "mirrored" created

[root@tardis-01-port1 ~]# lvs
  LV       VG                   Attr      LSize   Pool Origin Data%  Move Log           Cpy%Sync Convert
  mirrored cvg                  mwi-a-m-- 120.00m                         mirrored_mlog   100.00        
  home     rhel_tardis-01-port1 -wi-ao--- 224.88g                                                       
  root     rhel_tardis-01-port1 -wi-ao---  50.00g                                                       
  swap     rhel_tardis-01-port1 -wi-ao---   4.00g

Comment 8 Miroslav Grepl 2013-05-17 08:03:16 UTC
Ok, I added fixes to Fedora.

Comment 9 Marian Csontos 2013-05-29 13:33:59 UTC
*** Bug 966943 has been marked as a duplicate of this bug. ***

Comment 11 Ludek Smid 2014-06-13 12:48:16 UTC
This request was resolved in Red Hat Enterprise Linux 7.0.

Contact your manager or support representative in case you have further questions about the request.


Note You need to log in before you can comment on or make changes to this bug.