Bug 1095463
| Summary: | lvmetad has over a million sockets open after long run of raid failure testing | ||||||
|---|---|---|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | Corey Marthaler <cmarthal> | ||||
| Component: | lvm2 | Assignee: | Petr Rockai <prockai> | ||||
| lvm2 sub component: | LVM Metadata / lvmetad | QA Contact: | cluster-qe <cluster-qe> | ||||
| Status: | CLOSED ERRATA | Docs Contact: | Milan Navratil <mnavrati> | ||||
| Severity: | high | ||||||
| Priority: | urgent | CC: | agk, cmarthal, heinzm, jbrassow, msnitzer, prajnoha, prockai, rh, zkabelac | ||||
| Version: | 7.0 | Keywords: | Triaged | ||||
| Target Milestone: | rc | ||||||
| Target Release: | 7.1 | ||||||
| Hardware: | x86_64 | ||||||
| OS: | Linux | ||||||
| Whiteboard: | |||||||
| Fixed In Version: | lvm2-2.02.152-1.el7 | Doc Type: | Bug Fix | ||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2016-11-04 04:07:49 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Bug Depends On: | |||||||
| Bug Blocks: | 1295577, 1313485 | ||||||
| Attachments: |
|
||||||
Passing to prockai to give some more thoughts, but with current upstream it might be already fixed since I do not observe this. Anyway - it would be probably better to attach list of running processes for such case (ps -aux) and even at least portion of opened sockets. Number of opened file descriptors by dmeventd looks quite high as well so likely there could be some other weird actions going on behind. This is super-weird. It is dmeventd failing to open files, not lvmetad. A dump of running processes and their /proc/<pid>/fd/ would be definitely helpful. lsof | grep lvmetad will not only count the number of FDs held by lvmetad, if the socket has (as is the default) lvmetad in its name -- any processes talking to (or trying to talk to) lvmetad will be included as well. Also, is there an FD ulimit imposed on dmeventd in this scenario? Running out of FDs at ~1000 would be otherwise quite odd. Any updates on this? Does it still happen, and if yes, any chance of getting a more detailed listing of open files? This does still happen with the latest 7.1 rpms when doing extended failure testing (if you don't hit bug 1153796 first). lvcreate --virtualsize 200M --thinpool black_bird/non_synced_random_raid1_3legs_3 -n virt_non_synced_random_raid1_3legs_3 black_bird-non_synced_random_raid1_3legs_3-tpool: event registration failed: 3964:5 libdevmapper-event-lvm2thin.so dlopen failed: libdevmapper-event-lvm2thin.so: cannot open shared object file: Too many open files black_bird/non_synced_random_raid1_3legs_3: thin-pool segment monitoring function failed. black_bird-non_synced_random_raid1_3legs_3-tpool: event registration failed: 3964:11 libdevmapper-event-lvm2thin.so dlopen failed: libdevmapper-event-lvm2thin.so: cannot open shared object file: Too many open files black_bird/non_synced_random_raid1_3legs_3: thin-pool segment monitoring function failed. [root@host-114 ~]# lsof | grep lvmetad | wc -l 1058697 [root@host-114 ~]# lsof | grep dmeventd | wc -l 4194 3.10.0-184.el7.x86_64 lvm2-2.02.111-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 lvm2-libs-2.02.111-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 lvm2-cluster-2.02.111-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 device-mapper-1.02.90-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 device-mapper-libs-1.02.90-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 device-mapper-event-1.02.90-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 device-mapper-event-libs-1.02.90-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 device-mapper-persistent-data-0.3.2-1.el7 BUILT: Thu Apr 3 09:58:51 CDT 2014 cmirror-2.02.111-1.el7 BUILT: Mon Sep 29 09:18:07 CDT 2014 The patch for bug 1164234 might provide part of the answer. But as requested in comment 3, we do need to see the *actual* listings, not just the 'wc' summaries. Could you grab the complete 'lsof' output into a file for us so we can get a better idea of where the leak(s) are? (You don't have to wait for the failure to get the lsof data as it accumulates over time, grabbing it much earlier in the test should be enough to show exactly which resources are not getting released when they should be.) New code in lvm2 2.02.133 tracks resources differently - and hopefully more correctly - in already version thanks to various races it's been possible to leak file descriptors for control device. Once this version is out for testing - this bug should be rechecked. This bug was accidentally moved from POST to MODIFIED via an error in automation, please see mmccune with any questions Marking this verified in lvm2-2.02.164-4. Raid failure testing now appears to run for days with lvm2-lvmetad running. [...] ================================================================================ Iteration 32.37 started at Wed Sep 7 09:51:48 CDT 2016 ================================================================================ Scenario kill_multiple_synced_raid6_4legs: Kill multiple legs of synced 4 leg raid6 volume(s) ********* RAID hash info for this scenario ********* * names: synced_multiple_raid6_4legs_1 * sync: 1 * type: raid6 * -m |-i value: 4 * leg devices: /dev/sdc1 /dev/sdb1 /dev/sda1 /dev/sdf1 /dev/sdg1 /dev/sde1 * spanned legs: 0 * manual repair: 0 * failpv(s): /dev/sdf1 /dev/sdg1 * failnode(s): host-124 * lvmetad: 1 * cache stack: 1 * raid fault policy: warn ****************************************************** Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://rhn.redhat.com/errata/RHBA-2016-1445.html |
Created attachment 893454 [details] -vvvv of the snap create Description of problem: I noticed these errors after a day and a half of running raid + pool failure testing. The test continued to run with out any actual failures so I'm not sure how big of a deal this is, if at all. [root@host-003 ~]# lvcreate -s black_bird/synced_random_raid4_3legs_1 -L 100M black_bird-lvol0: event registration failed: 3225:7 libdevmapper-event-lvm2snapshot.so dlopen failed: libdevmapper-event-lvm2snapshot.so: cannot open shared object file: Too many open files black_bird/snapshot0: snapshot segment monitoring function failed. black_bird-lvol1: event registration failed: 3225:11 libdevmapper-event-lvm2snapshot.so dlopen failed: libdevmapper-event-lvm2snapshot.so: cannot open shared object file: Too many open files black_bird/snapshot1: snapshot segment monitoring function failed. black_bird-synced_random_raid4_3legs_1-real: event registration failed: 3225:15 libdevmapper-event-lvm2raid.so dlopen failed: libdevmapper-event-lvm2raid.so: cannot open shared object file: Too many open files black_bird/synced_random_raid4_3legs_1: raid4 segment monitoring function failed. Logical volume "lvol1" created [root@host-003 ~]# echo $? 0 [root@host-003 ~]# lvs -a -o +devices LV Attr LSize Origin Data% Cpy%Sync Devices lvol0 swi-a-s--- 100.00m synced_random_raid4_3legs_1 0.00 /dev/sdf1(0) lvol1 swi-a-s--- 100.00m synced_random_raid4_3legs_1 0.00 /dev/sdf1(25) synced_random_raid4_3legs_1 owi-a-r--- 504.00m 100.00 synced_random_raid4_3legs_1_rimage_0(0),synced_random_raid4_3legs_1_rimage_1(0),synced_random_raid4_3legs_1_rimage_2(0),synced_random_raid4_3legs_1_rimage_3(0) [synced_random_raid4_3legs_1_rimage_0] iwi-aor--- 168.00m /dev/sdc1(1) [synced_random_raid4_3legs_1_rimage_1] iwi-aor--- 168.00m /dev/sdb1(1) [synced_random_raid4_3legs_1_rimage_2] iwi-aor--- 168.00m /dev/sdh1(1) [synced_random_raid4_3legs_1_rimage_3] iwi-aor--- 168.00m /dev/sde1(1) [synced_random_raid4_3legs_1_rmeta_0] ewi-aor--- 4.00m /dev/sdc1(0) [synced_random_raid4_3legs_1_rmeta_1] ewi-aor--- 4.00m /dev/sdb1(0) [synced_random_raid4_3legs_1_rmeta_2] ewi-aor--- 4.00m /dev/sdh1(0) [synced_random_raid4_3legs_1_rmeta_3] ewi-aor--- 4.00m /dev/sde1(0) [root@host-003 ~]# lvcreate -s black_bird/synced_random_raid4_3legs_1 -vvvv -L 100M > /tmp/lvcreate 2>&1 [root@host-003 tmp]# lsof | grep lvmetad | wc -l 1060757 [root@host-003 tmp]# lsof | grep dmeventd | wc -l 1045 Version-Release number of selected component (if applicable): 3.10.0-122.el7.x86_64 lvm2-2.02.105-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014 lvm2-libs-2.02.105-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014 lvm2-cluster-2.02.105-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014 device-mapper-1.02.84-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014 device-mapper-libs-1.02.84-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014 device-mapper-event-1.02.84-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014 device-mapper-event-libs-1.02.84-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014 device-mapper-persistent-data-0.3.2-1.el7 BUILT: Thu Apr 3 09:58:51 CDT 2014 cmirror-2.02.105-14.el7 BUILT: Wed Mar 26 08:29:41 CDT 2014