[drbd-mc] Lots of pvdisplay commands -> RA timeouts

Discussion:

Caspar Smit

2012-12-17 14:09:54 UTC

Hi Rasto,

I noticed this in one of my clusters:

1001 27701 0.0 0.0 10588 1316 pts/5 Ss+ 14:44 0:00
\_ bash -c export LC_ALL=C;sudo -E -p 'DRBD MC sudo pwd: '
/usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 27704 0.0 0.0 39856 1516 pts/5 S+ 14:44 0:00 |
\_ sudo -E -p DRBD MC sudo pwd: /usr/local/bin/lcmc-gui-helper-1.4.2
hw-info-daemon
root 27720 0.1 0.0 27676 4996 pts/5 S+ 14:44 0:00 |
\_ /usr/bin/perl /usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 18181 0.0 0.0 9060 1180 pts/5 S+ 14:50 0:00 |
\_ sh -c /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
2>/dev/null
root 18182 0.0 0.0 17872 1604 pts/5 D+ 14:50 0:00 |
\_ /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
1001 30573 0.0 0.0 10588 1312 pts/1 Ss+ 14:45 0:00
\_ bash -c export LC_ALL=C;sudo -E -p 'DRBD MC sudo pwd: '
/usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 30574 0.0 0.0 39856 1516 pts/1 S+ 14:45 0:00 |
\_ sudo -E -p DRBD MC sudo pwd: /usr/local/bin/lcmc-gui-helper-1.4.2
hw-info-daemon
root 30575 0.1 0.0 27676 4996 pts/1 S+ 14:45 0:00 |
\_ /usr/bin/perl /usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 18172 0.0 0.0 9060 1184 pts/1 S+ 14:50 0:00 |
\_ sh -c /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
2>/dev/null
root 18174 0.0 0.0 17872 1600 pts/1 D+ 14:50 0:00 |
\_ /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
1001 32326 0.0 0.0 10588 1312 pts/2 Ss+ 14:46 0:00
\_ bash -c export LC_ALL=C;sudo -E -p 'DRBD MC sudo pwd: '
/usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 32327 0.0 0.0 39856 1516 pts/2 S+ 14:46 0:00 |
\_ sudo -E -p DRBD MC sudo pwd: /usr/local/bin/lcmc-gui-helper-1.4.2
hw-info-daemon
root 32328 0.1 0.0 27676 4996 pts/2 S+ 14:46 0:00 |
\_ /usr/bin/perl /usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 18164 0.0 0.0 9060 1180 pts/2 S+ 14:50 0:00 |
\_ sh -c /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
2>/dev/null
root 18165 0.0 0.0 17872 1604 pts/2 D+ 14:50 0:00 |
\_ /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
1001 8139 0.0 0.0 10588 1312 pts/6 Ss+ 14:48 0:00
\_ bash -c export LC_ALL=C;sudo -E -p 'DRBD MC sudo pwd: '
/usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 8140 0.0 0.0 39856 1512 pts/6 S+ 14:48 0:00 |
\_ sudo -E -p DRBD MC sudo pwd: /usr/local/bin/lcmc-gui-helper-1.4.2
hw-info-daemon
root 8141 0.2 0.0 27676 5000 pts/6 S+ 14:48 0:00 |
\_ /usr/bin/perl /usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 18166 0.0 0.0 9060 1180 pts/6 S+ 14:50 0:00 |
\_ sh -c /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
2>/dev/null
root 18167 0.0 0.0 17872 1600 pts/6 D+ 14:50 0:00 |
\_ /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
1001 9868 0.0 0.0 10588 1316 pts/7 Ss+ 14:49 0:00
\_ bash -c export LC_ALL=C;sudo -E -p 'DRBD MC sudo pwd: '
/usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 9869 0.0 0.0 39856 1516 pts/7 S+ 14:49 0:00
\_ sudo -E -p DRBD MC sudo pwd: /usr/local/bin/lcmc-gui-helper-1.4.2
hw-info-daemon
root 9870 0.3 0.0 27676 5000 pts/7 S+ 14:49 0:00
\_ /usr/bin/perl /usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 18176 0.0 0.0 9060 1180 pts/7 S+ 14:50 0:00
\_ sh -c /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
2>/dev/null
root 18177 0.0 0.0 17872 1604 pts/7 D+ 14:50 0:00
\_ /sbin/pvdisplay -C --noheadings -o pv_name,vg_name

Why is LCMC running so many pvdisplay commands at once?

I think this is causing my RA monitors to timeout once in a while
(sometimes even two minutes timeout)

Kind regards,
Caspar Smit
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.linbit.com/pipermail/drbd-mc/attachments/20121217/e7f04b2c/attachment.htm>

Rasto Levrinc

2012-12-17 14:32:47 UTC

Permalink

Post by Caspar Smit
Hi Rasto,

...

Post by Caspar Smit
/usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 9869 0.0 0.0 39856 1516 pts/7 S+ 14:49 0:00
\_ sudo -E -p DRBD MC sudo pwd: /usr/local/bin/lcmc-gui-helper-1.4.2
hw-info-daemon
root 9870 0.3 0.0 27676 5000 pts/7 S+ 14:49 0:00
\_ /usr/bin/perl /usr/local/bin/lcmc-gui-helper-1.4.2 hw-info-daemon
root 18176 0.0 0.0 9060 1180 pts/7 S+ 14:50 0:00
\_ sh -c /sbin/pvdisplay -C --noheadings -o pv_name,vg_name 2>/dev/null
root 18177 0.0 0.0 17872 1604 pts/7 D+ 14:50 0:00
\_ /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Why is LCMC running so many pvdisplay commands at once?

Hi Caspar,

it is running it once in 10 seconds, to see if something has changed.
Can you check what does it do on your nodes?

/sbin/pvdisplay -C --noheadings -o pv_name,vg_name

Rasto

Post by Caspar Smit
I think this is causing my RA monitors to timeout once in a while (sometimes
even two minutes timeout)
Kind regards,
Caspar Smit

--
Dipl.-Ing. Rastislav Levrinc
rasto.levrinc at gmail.com
Linux Cluster Management Console
http://lcmc.sf.net/

Caspar Smit

2012-12-17 14:39:06 UTC

Permalink

2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Rasto Levrinc

Post by Caspar Smit
Hi Rasto,

...

Hi Caspar,
it is running it once in 10 seconds, to see if something has changed.
Can you check what does it do on your nodes?
/sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Rasto

# /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
/dev/sdb single_array3
/dev/sdc single_array3
/dev/sdd single_array3
/dev/sdh replicated_array1and2
/dev/sdi replicated_array1and2
/dev/sdj replicated_array1and2
/dev/sdk replicated_array1and2

I know that LCMC does monitor changes with the lcmc-gui-helper script, but
I presume the "hw-info-daemon" part has to run only once and not 5(+) times
concurrently?

Running 5x pvdisplay concurrently can really slow things down.

Kind regards,
Caspar

Post by Rasto Levrinc

Post by Caspar Smit
I think this is causing my RA monitors to timeout once in a while

(sometimes

Post by Caspar Smit
even two minutes timeout)
Kind regards,
Caspar Smit

--
Dipl.-Ing. Rastislav Levrinc
rasto.levrinc at gmail.com
Linux Cluster Management Console
http://lcmc.sf.net/
_______________________________________________
drbd-mc mailing list
drbd-mc at lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-mc

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.linbit.com/pipermail/drbd-mc/attachments/20121217/c4623ac5/attachment.htm>

Rasto Levrinc

2012-12-17 15:09:25 UTC

Permalink

Post by Caspar Smit
2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Rasto Levrinc

Post by Caspar Smit
Hi Rasto,

...

Hi Caspar,
it is running it once in 10 seconds, to see if something has changed.
Can you check what does it do on your nodes?
/sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Rasto

# /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
/dev/sdb single_array3
/dev/sdc single_array3
/dev/sdd single_array3
/dev/sdh replicated_array1and2
/dev/sdi replicated_array1and2
/dev/sdj replicated_array1and2
/dev/sdk replicated_array1and2
I know that LCMC does monitor changes with the lcmc-gui-helper script, but I
presume the "hw-info-daemon" part has to run only once and not 5(+) times
concurrently?
Running 5x pvdisplay concurrently can really slow things down.

It shouldn't run this 5x concurrently. What here probably happens, is that
the hw daemon takes too long and is assumed dead and is restarted.

Can it be that /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
hangs on or takes very long on your system, at least sometimes?

Anyway I can/should fix LCMC to deal with this situation.

Rasto

--
Dipl.-Ing. Rastislav Levrinc
rasto.levrinc at gmail.com
Linux Cluster Management Console
http://lcmc.sf.net/

Caspar Smit

2012-12-17 20:10:36 UTC

Permalink

2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Caspar Smit

Post by Caspar Smit
2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Rasto Levrinc

Post by Caspar Smit
Hi Rasto,

...

2>/dev/null

Post by Caspar Smit

Post by Rasto Levrinc

Post by Caspar Smit
root 18177 0.0 0.0 17872 1604 pts/7 D+ 14:50 0:00
\_ /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Why is LCMC running so many pvdisplay commands at once?

Hi Caspar,
it is running it once in 10 seconds, to see if something has changed.
Can you check what does it do on your nodes?
/sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Rasto

but I

Post by Caspar Smit
presume the "hw-info-daemon" part has to run only once and not 5(+) times
concurrently?
Running 5x pvdisplay concurrently can really slow things down.

It shouldn't run this 5x concurrently. What here probably happens, is that
the hw daemon takes too long and is assumed dead and is restarted.
Can it be that /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
hangs on or takes very long on your system, at least sometimes?
Yes, that is probably the case because the system is under heavy (NFS)

load.

Post by Caspar Smit
Anyway I can/should fix LCMC to deal with this situation.

That would be nice :)

Kind regards,
Caspar

Post by Caspar Smit
Rasto
--
Dipl.-Ing. Rastislav Levrinc
rasto.levrinc at gmail.com
Linux Cluster Management Console
http://lcmc.sf.net/
_______________________________________________
drbd-mc mailing list
drbd-mc at lists.linbit.com
http://lists.linbit.com/mailman/listinfo/drbd-mc

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.linbit.com/pipermail/drbd-mc/attachments/20121217/37ca87cb/attachment-0001.htm>

Rasto Levrinc

2012-12-22 22:14:03 UTC

Permalink

Post by Caspar Smit
2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Rasto Levrinc

Post by Caspar Smit
2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Rasto Levrinc

Post by Caspar Smit
Hi Rasto,

...

Hi Caspar,
it is running it once in 10 seconds, to see if something has changed.
Can you check what does it do on your nodes?
/sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Rasto

# /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
/dev/sdb single_array3
/dev/sdc single_array3
/dev/sdd single_array3
/dev/sdh replicated_array1and2
/dev/sdi replicated_array1and2
/dev/sdj replicated_array1and2
/dev/sdk replicated_array1and2
I know that LCMC does monitor changes with the lcmc-gui-helper script, but I
presume the "hw-info-daemon" part has to run only once and not 5(+) times
concurrently?
Running 5x pvdisplay concurrently can really slow things down.

It shouldn't run this 5x concurrently. What here probably happens, is that
the hw daemon takes too long and is assumed dead and is restarted.
Can it be that /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
hangs on or takes very long on your system, at least sometimes?

Yes, that is probably the case because the system is under heavy (NFS) load.

Post by Rasto Levrinc
Anyway I can/should fix LCMC to deal with this situation.

That would be nice :)

Fixed in 1.4.5. The info daemon wasn't cancelled after a timeout and it
would result in multiple instances running at the same time. Some
further optimizations are possible but this bug was the most important
at the moment.

Rasto

--
Dipl.-Ing. Rastislav Levrinc
rasto.levrinc at gmail.com
Linux Cluster Management Console
http://lcmc.sf.net/

Lars Ellenberg

2012-12-18 10:00:47 UTC

Permalink

Post by Rasto Levrinc

Post by Caspar Smit
2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Rasto Levrinc

Post by Caspar Smit
Hi Rasto,

...

Hi Caspar,
it is running it once in 10 seconds, to see if something has changed.
Can you check what does it do on your nodes?
/sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Rasto

# /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
/dev/sdb single_array3
/dev/sdc single_array3
/dev/sdd single_array3
/dev/sdh replicated_array1and2
/dev/sdi replicated_array1and2
/dev/sdj replicated_array1and2
/dev/sdk replicated_array1and2
I know that LCMC does monitor changes with the lcmc-gui-helper script, but I
presume the "hw-info-daemon" part has to run only once and not 5(+) times
concurrently?
Running 5x pvdisplay concurrently can really slow things down.

It shouldn't run this 5x concurrently. What here probably happens, is that
the hw daemon takes too long and is assumed dead and is restarted.

Which does not really improve things in this case ;-)

Post by Rasto Levrinc
Can it be that /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
hangs on or takes very long on your system, at least sometimes?

We have seen lvm commands that scan meta data take several *minutes* to
complete on a moderately busy server.
[0.1 seconds when the system is idle,
virtually "forever" when it is really busy :-)]

In part because of too many devices to be scanned, badly chosen filter
settings, badly chosen bio flags for O_DIRECT (that has been fixed since
in kernel), too long device queues (too large nr_requests),
and evil io scheduler interactions.
All tuneable, or possible to work around.
Still that brought it down to ~ 20 seconds only.

Post by Rasto Levrinc
Anyway I can/should fix LCMC to deal with this situation.

You should probably not initiate a full device scan every ten seconds,
but preferably on demand only,
or maybe every once in a while if loadavg is low.

Lars

Rasto Levrinc

2012-12-18 14:16:20 UTC

Permalink

On Tue, Dec 18, 2012 at 11:00 AM, Lars Ellenberg

Post by Lars Ellenberg

Post by Rasto Levrinc

Post by Caspar Smit
2012/12/17 Rasto Levrinc <rasto.levrinc at gmail.com>

Post by Rasto Levrinc

Post by Caspar Smit
Hi Rasto,

...

Hi Caspar,
it is running it once in 10 seconds, to see if something has changed.
Can you check what does it do on your nodes?
/sbin/pvdisplay -C --noheadings -o pv_name,vg_name
Rasto

# /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
/dev/sdb single_array3
/dev/sdc single_array3
/dev/sdd single_array3
/dev/sdh replicated_array1and2
/dev/sdi replicated_array1and2
/dev/sdj replicated_array1and2
/dev/sdk replicated_array1and2
I know that LCMC does monitor changes with the lcmc-gui-helper script, but I
presume the "hw-info-daemon" part has to run only once and not 5(+) times
concurrently?
Running 5x pvdisplay concurrently can really slow things down.

It shouldn't run this 5x concurrently. What here probably happens, is that
the hw daemon takes too long and is assumed dead and is restarted.

Which does not really improve things in this case ;-)

That's actually a regression, the old daemon must be killed, when anything
hangs, so that's the first bug.

Post by Lars Ellenberg

Post by Rasto Levrinc
Can it be that /sbin/pvdisplay -C --noheadings -o pv_name,vg_name
hangs on or takes very long on your system, at least sometimes?

We have seen lvm commands that scan meta data take several *minutes* to
complete on a moderately busy server.
[0.1 seconds when the system is idle,
virtually "forever" when it is really busy :-)]
In part because of too many devices to be scanned, badly chosen filter
settings, badly chosen bio flags for O_DIRECT (that has been fixed since
in kernel), too long device queues (too large nr_requests),
and evil io scheduler interactions.
All tuneable, or possible to work around.
Still that brought it down to ~ 20 seconds only.

Post by Rasto Levrinc
Anyway I can/should fix LCMC to deal with this situation.

You should probably not initiate a full device scan every ten seconds,
but preferably on demand only,
or maybe every once in a while if loadavg is low.

The LCMC needs to have relatively uptodate knowledge about LVM, if possible.
It could run the scan only if any pv, vg or lv has changed. I've figured out
that I could check the lvm .cache file timestamp that is written every time
any of the lvm commands are run. It wouldn't help if the lvm cache is
disabled, but I guess if somebody disables that, has also made some device
filters. And update every 10 seconds + time the scan runs or so would be
acceptable. Or maybe something clever like (time the scan runs) * 2 + 10.

Rasto