Description of problem:
Pacemaker LVM monitors usually take 1 or 2 seconds to complete but periodically can take more than 90 seconds, which exceeds common timeout thresholds and causes services to be restarted in place.  We have tested on systems where we verified there are no storage-related issues that would contribute to this behavior.

Investigation has found flock() calls within the vgs and vgscan commands used by the Pacemaker LVM monitor appear to be responsible for the long delays. Increasing the number of active services on a cluster node raises the likelihood that more than one LVM monitor could run at the same time, creating the potential for flock() collisions between them.

Reducing the frequency of Pacemaker LVM monitor runs can help this problem but cannot fully avoid it. The Pacemaker LVM monitor should instead be using methods of verifying volume group availability, etc, that do not cause flock() contention in this way.

Version-Release number of selected component (if applicable):

lvm2-libs-2.02.171-8.el7.x86_64
lvm2-2.02.171-8.el7.x86_64
pcs-0.9.158-6.el7.x86_64

How reproducible:
The Pacemaker clusters we are testing on are comprised of three nodes, all Proliant DL380 G9, 16 CPU, 256GB memory.  The entire cluster runs 19 Oracle database services; the node we are testing on is running just 5 of those services.

Process accounting is enabled to track vgs and vgscan process time when monitoring is initiated by the cluster.  

Strace is used to track vgscan processes (strace -T) as called by Pacemaker.

Volume group monitoring intervals are set to 60 seconds, timeouts are set to 90 seconds.  All other resource monitoring is set to defaults.

Steps to Reproduce:
1. Create several database services utilizing SAN storage (IP resource, volume group resource, 4 lvm resources in the volume group, and the LSB script)
2. Start services and let Pacemaker initiate its own built-in LVM monitoring.
3. Observe process times via accounting on time taken to complete vgs and vgscan processes.
4. Timeouts start being registered in pacemaker.log and reflected in pcs status output for the given service..

Actual results:
Eventually, timeouts against volume group monitoring will show up in Failed Actions in pcs output.  syslogs (pacemaker.log) will show 90000msec timeout failures.  After only a few of these, the given service being monitored will restart in place since the cluster has determined there is an issue.

Expected results:
There should be no timeouts registered since there are no SAN or other storage issues being observed in the cluster.


Additional info:
The following comes from an “strace –T” of vgscan called by a Pacemaker LVM monitor. Elapsed time in seconds is within <>; this shows extended-duration flock() calls. Preceding open() calls are included to show the filenames involved.

12561 open("/run/lock/lvm/P_global:aux", O_RDWR|O_CREAT|O_APPEND, 0777) = 3 <0.000012>
12561 flock(3, LOCK_EX)                 = 0 <21.466415>


12561 open("/run/lock/lvm/P_global:aux", O_RDWR|O_CREAT|O_APPEND, 0777) = 3 <0.000019>
12561 flock(3, LOCK_EX)                 = 0 <17.003831>


12561 open("/run/lock/lvm/P_global:aux", O_RDWR|O_CREAT|O_APPEND, 0777) = 3 <0.000013>
12561 flock(3, LOCK_EX)                 = 0 <10.702100>


12561 open("/run/lock/lvm/P_global:aux", O_RDWR|O_CREAT|O_APPEND, 0777) = 3 <0.000019>
12561 flock(3, LOCK_EX)                 = 0 <7.790907>


12561 open("/run/lock/lvm/P_global:aux", O_RDWR|O_CREAT|O_APPEND, 0777) = 3 <0.000013>
12561 flock(3, LOCK_EX)                 = 0 <10.532846>


12561 open("/run/lock/lvm/P_global", O_RDWR|O_CREAT|O_APPEND, 0777) = 4 <0.000010>
12561 flock(4, LOCK_EX)                 = 0 <2.100148>