1562796 – lvcreate segfault during many thin virt snapshot create attempts

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 1562796 - lvcreate segfault during many thin virt snapshot create attempts

Summary: lvcreate segfault during many thin virt snapshot create attempts

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	Red Hat Enterprise Linux 7
Classification:	Red Hat
Component:	lvm2
Sub Component:
Version:	7.5
Hardware:	x86_64
OS:	Linux
Priority:	unspecified
Severity:	high
Target Milestone:	rc
Target Release:	---
Assignee:	LVM and device-mapper development team
QA Contact:	cluster-qe@redhat.com
Docs Contact:
URL:
Whiteboard:
Duplicates (1):	1599293 (view as bug list)
Depends On:
Blocks:	1599033
TreeView+	depends on / blocked

Reported:	2018-04-02 14:12 UTC by Corey Marthaler
Modified:	2021-09-03 12:40 UTC (History)
CC List:	18 users (show)
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2020-01-27 15:47:11 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Description Corey Marthaler 2018-04-02 14:12:39 UTC

Description of problem:
This was a random failure and has not yet been reproduced.

Mar 30 06:40:39 host-086 qarshd[23071]: Running cmdline: lvcreate -k n -s /dev/snapper_thinp/origin -n 500_163
Mar 30 06:40:40 host-086 dmeventd[842]: No longer monitoring thin pool snapper_thinp-POOL-tpool.
Mar 30 06:40:40 host-086 lvm[842]: Monitoring thin pool snapper_thinp-POOL-tpool.
Mar 30 06:40:40 host-086 kernel: lvcreate[23072]: segfault at 18 ip 00007f93ac86e895 sp 00007ffe53cdb370 error 4 in libc-2.17.so[7f93ac7ec000+1c3000]
Mar 30 06:40:40 host-086 abrt-hook-ccpp: Process 23072 (lvm) of user 0 killed by SIGSEGV - dumping core


Core was generated by `lvcreate -k n -s /dev/snapper_thinp/origin -n 500_163'.
Program terminated with signal 11, Segmentation fault.
#0  0x00007f93ac86e895 in _int_malloc () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install bzip2-libs-1.0.6-13.el7.x86_64 elfutils-libelf-0.170-4.el7.x86_64 elfutils-libs-0.170-4.el7.x86_64 glibc-2.17-222.el7.x86_64 libattr-2.4.46-13.el7.x86_64 libblkid-2.23.2-52.el7.x86_64 libcap-2.22-9.el7.x86_64 libgcc-4.8.5-28.el7.x86_64 libselinux-2.5-12.el7.x86_64 libsepol-2.5-8.1.el7.x86_64 libuuid-2.23.2-52.el7.x86_64 ncurses-libs-5.9-14.20130511.el7_4.x86_64 pcre-8.32-17.el7.x86_64 readline-6.2-10.el7.x86_64 systemd-libs-219-57.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-17.el7.x86_64
(gdb) 
(gdb) bt
#0  0x00007f93ac86e895 in _int_malloc () from /lib64/libc.so.6
#1  0x00007f93ac8717dc in malloc () from /lib64/libc.so.6
#2  0x00007f93ace3553e in dm_malloc_aux (s=<optimized out>, file=<optimized out>, line=<optimized out>) at mm/dbg_malloc.c:286
#3  0x00007f93ace355b5 in dm_malloc_wrapper (s=<optimized out>, file=<optimized out>, line=<optimized out>) at mm/dbg_malloc.c:340
#4  0x000055a96f5dd235 in _aligned_io (where=where@entry=0x7ffe53cdb520, buffer=buffer@entry=0x7ffe53cdb5f0 "\330\070\233q\251U", should_write=should_write@entry=0, reason=DEV_IO_MDA_CONTENT) at device/dev-io.c:261
#5  0x000055a96f5ddb98 in dev_read (dev=0x55a971a64280, offset=<optimized out>, len=len@entry=130, reason=<optimized out>, buffer=buffer@entry=0x7ffe53cdb5f0) at device/dev-io.c:740
#6  0x000055a96f5f02bc in _find_vg_rlocn (mdah=mdah@entry=0x55a971ab2298, primary_mda=<optimized out>, vgname=0x55a971a792d0 "snapper_thinp", precommitted=precommitted@entry=0x7ffe53cdb704, dev_area=0x55a9719b38d0, 
    dev_area=0x55a9719b38d0) at format_text/format-text.c:464
#7  0x000055a96f5f1234 in _vg_write_raw (fid=<optimized out>, vg=0x55a971a79140, mda=0x55a9719b38a0) at format_text/format-text.c:754
#8  0x000055a96f624aa4 in vg_write (vg=0x55a971a79140) at metadata/metadata.c:3050
#9  0x000055a96f647a4f in update_pool_lv (lv=lv@entry=0x55a971a79ae8, activate=<optimized out>, activate@entry=0) at metadata/thin_manip.c:550
#10 0x000055a96f617dea in _lv_create_an_lv (vg=vg@entry=0x55a971a79140, lp=lp@entry=0x7ffe53cdbe80, new_lv_name=<optimized out>) at metadata/lv_manip.c:7845
#11 0x000055a96f61811f in lv_create_single (vg=vg@entry=0x55a971a79140, lp=lp@entry=0x7ffe53cdbe80) at metadata/lv_manip.c:8078
#12 0x000055a96f58f823 in _lvcreate_single (cmd=cmd@entry=0x55a97190c020, vg_name=vg_name@entry=0x55a9719580d0 "snapper_thinp", vg=vg@entry=0x55a971a79140, handle=handle@entry=0x55a971957fc8) at lvcreate.c:1651
#13 0x000055a96f5af0cf in _process_vgnameid_list (process_single_vg=0x55a96f58ec50 <_lvcreate_single>, handle=0x55a971957fc8, arg_tags=0x7ffe53cdbbf0, arg_vgnames=0x7ffe53cdbc00, vgnameids_to_process=0x7ffe53cdbc20, 
    read_flags=1048576, cmd=0x55a97190c020) at toollib.c:1984
#14 process_each_vg (cmd=cmd@entry=0x55a97190c020, argc=argc@entry=0, argv=argv@entry=0x0, one_vgname=<optimized out>, use_vgnames=use_vgnames@entry=0x0, read_flags=read_flags@entry=1048576, 
    include_internal=include_internal@entry=0, handle=handle@entry=0x55a971957fc8, process_single_vg=process_single_vg@entry=0x55a96f58ec50 <_lvcreate_single>) at toollib.c:2297
#15 0x000055a96f592f7f in lvcreate (cmd=0x55a97190c020, argc=<optimized out>, argv=<optimized out>) at lvcreate.c:1696
#16 0x000055a96f599d1b in lvm_run_command (cmd=0x55a97190c020, argc=1, argv=0x7ffe53cdc3b8) at lvmcmdline.c:3008
#17 0x000055a96f59ae9e in lvm2_main (argc=7, argv=0x7ffe53cdc388) at lvmcmdline.c:3586
#18 0x00007f93ac80e3d5 in __libc_start_main () from /lib64/libc.so.6
#19 0x000055a96f5770ae in _start ()



Here's what the test was doing:

[lvm_crypt_thinpool]  SCENARIO - [many_thin_snaps]
[lvm_crypt_thinpool]  Create 500 snapshots of an origin volume
[lvm_crypt_thinpool]  Recreating VG and PVs to increase metadata size
[lvm_crypt_thinpool]  Making pool volume
[lvm_crypt_thinpool]  lvcreate  --thinpool POOL -L 1G  --zero n --poolmetadatasize 4M snapper_thinp
[lvm_crypt_thinpool]  
[lvm_crypt_thinpool]  Sanity checking pool device (POOL) metadata
[lvm_crypt_thinpool]  thin_check /dev/mapper/snapper_thinp-meta_swap.932
[lvm_crypt_thinpool]  examining superblock
[lvm_crypt_thinpool]  examining devices tree
[lvm_crypt_thinpool]  examining mapping tree
[lvm_crypt_thinpool]  checking space map counts
[lvm_crypt_thinpool]  
[lvm_crypt_thinpool]  
[lvm_crypt_thinpool]  Making origin volume
[lvm_crypt_thinpool]  Create LV to be used as an EXTERNAL origin device
[lvm_crypt_thinpool]  lvcreate  -L 1G -n origin snapper_thinp
[lvm_crypt_thinpool]  Converting LV into an external thin origin device
[lvm_crypt_thinpool]  lvconvert --thinpool snapper_thinp/POOL --originname extorigin -T origin --yes
[lvm_crypt_thinpool]  lvcreate  -V 1G -T snapper_thinp/POOL -n other1
[lvm_crypt_thinpool]    WARNING: Sum of all thin volume sizes (2.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
[lvm_crypt_thinpool]  lvcreate  -V 1G -T snapper_thinp/POOL -n other2
[lvm_crypt_thinpool]    WARNING: Sum of all thin volume sizes (3.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
[lvm_crypt_thinpool]  lvcreate  --virtualsize 1G -T snapper_thinp/POOL -n other3
[lvm_crypt_thinpool]    WARNING: Sum of all thin volume sizes (4.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
[lvm_crypt_thinpool]  lvcreate  --virtualsize 1G -T snapper_thinp/POOL -n other4
[lvm_crypt_thinpool]    WARNING: Sum of all thin volume sizes (5.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
[lvm_crypt_thinpool]  lvcreate  --virtualsize 1G -T snapper_thinp/POOL -n other5
[lvm_crypt_thinpool]    WARNING: Sum of all thin volume sizes (6.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
[lvm_crypt_thinpool]  Making 500 snapshots of origin volume
[lvm_crypt_thinpool]  1 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_1
[lvm_crypt_thinpool]  2 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_2
                      [...]
[lvm_crypt_thinpool]  163 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_163
[lvm_crypt_thinpool]  couldn't create snapshot 500_163



[root@host-086 ccpp-2018-03-30-06:40:40-23072]# lvs -a -o +devices /dev/snapper_thinp/500_163
  LV      VG            Attr       LSize Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert Devices
  500_163 snapper_thinp Vwi---t--- 1.00g POOL origin                                                
[root@host-086 ccpp-2018-03-30-06:40:40-23072]# lvs -a -o +devices /dev/snapper_thinp/500_162
  LV      VG            Attr       LSize Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert Devices
  500_162 snapper_thinp Vwi-a-t--- 1.00g POOL origin 0.00                                           

[root@host-086 ccpp-2018-03-30-06:40:40-23072]# pvscan
  PV /dev/vda2          VG rhel_host-086   lvm2 [<7.00 GiB / 0    free]
  PV /dev/mapper/cPV4   VG snapper_thinp   lvm2 [<29.50 GiB / 27.49 GiB free]
  PV /dev/mapper/cPV5   VG snapper_thinp   lvm2 [<29.50 GiB / <29.50 GiB free]
  PV /dev/mapper/cPV6   VG snapper_thinp   lvm2 [<29.50 GiB / <29.50 GiB free]
  PV /dev/mapper/cPV7   VG snapper_thinp   lvm2 [<29.50 GiB / <29.50 GiB free]
  PV /dev/mapper/cPV8   VG snapper_thinp   lvm2 [<29.50 GiB / 29.49 GiB free]
  Total: 6 [<154.48 GiB] / in use: 6 [<154.48 GiB] / in no VG: 0 [0   ]


Version-Release number of selected component (if applicable):
3.10.0-862.el7.x86_64

lvm2-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
lvm2-libs-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
lvm2-cluster-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
lvm2-python-boom-0.8.5-4.el7    BUILT: Fri Feb 16 13:37:10 CET 2018
cmirror-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-libs-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-event-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-event-libs-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-persistent-data-0.7.3-3.el7    BUILT: Tue Nov 14 12:07:18 CET 2017


How reproducible:
Only once

Comment 2 Alasdair Kergon 2018-04-03 14:53:23 UTC

Please follow the instructions gdb printed to install the missing debuginfos and then do the backtrace again:

Missing separate debuginfos, use: debuginfo-install bzip2-libs-1.0.6-13.el7.x86_64 elfutils-libelf-0.170-4.el7.x86_64 elfutils-libs-0.170-4.el7.x86_64 glibc-2.17-222.el7.x86_64 libattr-2.4.46-13.el7.x86_64 libblkid-2.23.2-52.el7.x86_64 libcap-2.22-9.el7.x86_64 libgcc-4.8.5-28.el7.x86_64 libselinux-2.5-12.el7.x86_64 libsepol-2.5-8.1.el7.x86_64 libuuid-2.23.2-52.el7.x86_64 ncurses-libs-5.9-14.20130511.el7_4.x86_64 pcre-8.32-17.el7.x86_64 readline-6.2-10.el7.x86_64 systemd-libs-219-57.el7.x86_64 xz-libs-5.2.2-1.el7.x86_64 zlib-1.2.7-17.el7.x86_64

Comment 3 Corey Marthaler 2018-04-03 16:12:51 UTC

Core was generated by `lvcreate -k n -s /dev/snapper_thinp/origin -n 500_163'.
Program terminated with signal 11, Segmentation fault.
#0  0x00007f93ac86e895 in _int_malloc (av=av@entry=0x7f93acbb2760 <main_arena>, bytes=bytes@entry=8192) at malloc.c:3712
3712            unlink(av, victim, bck, fwd);
(gdb) bt
#0  0x00007f93ac86e895 in _int_malloc (av=av@entry=0x7f93acbb2760 <main_arena>, bytes=bytes@entry=8192) at malloc.c:3712
#1  0x00007f93ac8717dc in __GI___libc_malloc (bytes=8192) at malloc.c:2899
#2  0x00007f93ace3553e in dm_malloc_aux (s=<optimized out>, file=file@entry=0x55a96f6c8276 "device/dev-io.c", line=line@entry=261) at mm/dbg_malloc.c:286
#3  0x00007f93ace355b5 in dm_malloc_wrapper (s=<optimized out>, file=file@entry=0x55a96f6c8276 "device/dev-io.c", line=line@entry=261) at mm/dbg_malloc.c:340
#4  0x000055a96f5dd235 in _aligned_io (where=where@entry=0x7ffe53cdb520, buffer=buffer@entry=0x7ffe53cdb5f0 "\330\070\233q\251U", should_write=should_write@entry=0, reason=DEV_IO_MDA_CONTENT)
    at device/dev-io.c:261
#5  0x000055a96f5ddb98 in dev_read (dev=0x55a971a64280, offset=<optimized out>, len=len@entry=130, reason=<optimized out>, buffer=buffer@entry=0x7ffe53cdb5f0) at device/dev-io.c:740
#6  0x000055a96f5f02bc in _find_vg_rlocn (mdah=mdah@entry=0x55a971ab2298, primary_mda=<optimized out>, vgname=0x55a971a792d0 "snapper_thinp", precommitted=precommitted@entry=0x7ffe53cdb704, 
    dev_area=0x55a9719b38d0, dev_area=0x55a9719b38d0) at format_text/format-text.c:464
#7  0x000055a96f5f1234 in _vg_write_raw (fid=<optimized out>, vg=0x55a971a79140, mda=0x55a9719b38a0) at format_text/format-text.c:754
#8  0x000055a96f624aa4 in vg_write (vg=0x55a971a79140) at metadata/metadata.c:3050
#9  0x000055a96f647a4f in update_pool_lv (lv=lv@entry=0x55a971a79ae8, activate=<optimized out>, activate@entry=0) at metadata/thin_manip.c:550
#10 0x000055a96f617dea in _lv_create_an_lv (vg=vg@entry=0x55a971a79140, lp=lp@entry=0x7ffe53cdbe80, new_lv_name=<optimized out>) at metadata/lv_manip.c:7845
#11 0x000055a96f61811f in lv_create_single (vg=vg@entry=0x55a971a79140, lp=lp@entry=0x7ffe53cdbe80) at metadata/lv_manip.c:8078
#12 0x000055a96f58f823 in _lvcreate_single (cmd=cmd@entry=0x55a97190c020, vg_name=vg_name@entry=0x55a9719580d0 "snapper_thinp", vg=vg@entry=0x55a971a79140, handle=handle@entry=0x55a971957fc8)
    at lvcreate.c:1651
#13 0x000055a96f5af0cf in _process_vgnameid_list (process_single_vg=0x55a96f58ec50 <_lvcreate_single>, handle=0x55a971957fc8, arg_tags=0x7ffe53cdbbf0, arg_vgnames=0x7ffe53cdbc00, 
    vgnameids_to_process=0x7ffe53cdbc20, read_flags=1048576, cmd=0x55a97190c020) at toollib.c:1984
#14 process_each_vg (cmd=cmd@entry=0x55a97190c020, argc=argc@entry=0, argv=argv@entry=0x0, one_vgname=<optimized out>, use_vgnames=use_vgnames@entry=0x0, read_flags=read_flags@entry=1048576, 
    include_internal=include_internal@entry=0, handle=handle@entry=0x55a971957fc8, process_single_vg=process_single_vg@entry=0x55a96f58ec50 <_lvcreate_single>) at toollib.c:2297
#15 0x000055a96f592f7f in lvcreate (cmd=0x55a97190c020, argc=<optimized out>, argv=<optimized out>) at lvcreate.c:1696
#16 0x000055a96f599d1b in lvm_run_command (cmd=0x55a97190c020, argc=1, argv=0x7ffe53cdc3b8) at lvmcmdline.c:3008
#17 0x000055a96f59ae9e in lvm2_main (argc=7, argv=0x7ffe53cdc388) at lvmcmdline.c:3586
#18 0x00007f93ac80e3d5 in __libc_start_main (main=0x55a96f577080 <main>, argc=7, ubp_av=0x7ffe53cdc388, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffe53cdc378)
    at ../csu/libc-start.c:274
#19 0x000055a96f5770ae in _start ()

Comment 4 Corey Marthaler 2018-05-07 15:32:57 UTC

Reproduced this again today. Same scenario, but no crypt involved this time. Again, this happened right around the ~160th virt snapshot create attempt.

SCENARIO - [many_thin_snaps]
Create 500 snapshots of an origin volume
Recreating VG and PVs to increase metadata size
Making pool volume
Converting *Raid* volumes to thin pool and thin pool metadata devices
lvcreate  --type raid10 -m 1 -i 2 --profile thin-performance --zero n -L 4M -n meta snapper_thinp
  WARNING: Logical volume snapper_thinp/meta not zeroed.
lvcreate  --type raid10 -m 1 -i 2 --profile thin-performance --zero n -L 1G -n POOL snapper_thinp
  WARNING: Logical volume snapper_thinp/POOL not zeroed.
Waiting until all mirror|raid volumes become fully syncd...
   2/2 mirror(s) are fully synced: ( 100.00% 100.00% )
Sleeping 15 sec
Sleeping 15 sec
lvconvert --zero n --thinpool snapper_thinp/POOL --poolmetadata meta --yes
  WARNING: Converting snapper_thinp/POOL and snapper_thinp/meta to thin pool's data and metadata volumes with metadata wiping.
  THIS WILL DESTROY CONTENT OF LOGICAL VOLUME (filesystem etc.)

Sanity checking pool device (POOL) metadata
thin_check /dev/mapper/snapper_thinp-meta_swap.71
examining superblock
examining devices tree
examining mapping tree
checking space map counts


Making origin volume
lvcreate  --virtualsize 1G -T snapper_thinp/POOL -n origin
lvcreate  -V 1G -T snapper_thinp/POOL -n other1
  WARNING: Sum of all thin volume sizes (2.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
lvcreate  -V 1G -T snapper_thinp/POOL -n other2
  WARNING: Sum of all thin volume sizes (3.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
lvcreate  -V 1G -T snapper_thinp/POOL -n other3
  WARNING: Sum of all thin volume sizes (4.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
lvcreate  -V 1G -T snapper_thinp/POOL -n other4
  WARNING: Sum of all thin volume sizes (5.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
lvcreate  --virtualsize 1G -T snapper_thinp/POOL -n other5
  WARNING: Sum of all thin volume sizes (6.00 GiB) exceeds the size of thin pool snapper_thinp/POOL (1.00 GiB).
Making 500 snapshots of origin volume
1 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_1
2 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_2
3 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_3
4 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_4
5 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_5
[...]
156 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_156
157 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_157
158 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_158
159 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_159
160 lvcreate  -y -k n -s /dev/snapper_thinp/origin -n 500_160
couldn't create snapshot 500_160



May  5 04:23:58 host-092 qarshd[21887]: Running cmdline: lvcreate -k n -s /dev/snapper_thinp/origin -n 500_160
May  5 04:23:59 host-092 lvm[1607]: No longer monitoring RAID device snapper_thinp-POOL_tdata for events.
May  5 04:23:59 host-092 lvm[1607]: No longer monitoring RAID device snapper_thinp-POOL_tmeta for events.
May  5 04:23:59 host-092 dmeventd[1607]: No longer monitoring thin pool snapper_thinp-POOL-tpool.
May  5 04:23:59 host-092 lvm[1607]: Monitoring RAID device snapper_thinp-POOL_tdata for events.
May  5 04:23:59 host-092 lvm[1607]: Monitoring RAID device snapper_thinp-POOL_tmeta for events.
May  5 04:23:59 host-092 lvm[1607]: Monitoring thin pool snapper_thinp-POOL-tpool.
May  5 04:23:59 host-092 kernel: lvcreate[21888]: segfault at 18 ip 00007f54af477895 sp 00007fffa4ee3f90 error 4 in libc-2.17.so[7f54af3f5000+1c3000]




[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `lvcreate -k n -s /dev/snapper_thinp/origin -n 500_160'.
Program terminated with signal 11, Segmentation fault.
#0  0x00007f54af477895 in _int_malloc (av=av@entry=0x7f54af7bb760 <main_arena>, bytes=bytes@entry=8192) at malloc.c:3712
3712            unlink(av, victim, bck, fwd);
(gdb) bt
#0  0x00007f54af477895 in _int_malloc (av=av@entry=0x7f54af7bb760 <main_arena>, bytes=bytes@entry=8192) at malloc.c:3712
#1  0x00007f54af47a7dc in __GI___libc_malloc (bytes=8192) at malloc.c:2899
#2  0x00007f54afa3e53e in dm_malloc_aux (s=<optimized out>, file=file@entry=0x563ecf677276 "device/dev-io.c", line=line@entry=261) at mm/dbg_malloc.c:286
#3  0x00007f54afa3e5b5 in dm_malloc_wrapper (s=<optimized out>, file=file@entry=0x563ecf677276 "device/dev-io.c", line=line@entry=261) at mm/dbg_malloc.c:340
#4  0x0000563ecf58c235 in _aligned_io (where=where@entry=0x7fffa4ee4140, buffer=buffer@entry=0x563ed0134ed0 "0000000 fd:00 9260419", ' ' <repeats 20 times>, "/usr/sbin/lvm", 
    should_write=should_write@entry=0, reason=DEV_IO_MDA_HEADER) at device/dev-io.c:261
#5  0x0000563ecf58cb98 in dev_read (dev=0x563ed00cf3d8, offset=<optimized out>, len=len@entry=512, reason=reason@entry=DEV_IO_MDA_HEADER, buffer=buffer@entry=0x563ed0134ed0)
    at device/dev-io.c:740
#6  0x0000563ecf59e6cb in _raw_read_mda_header (mdah=mdah@entry=0x563ed0134ed0, primary_mda=primary_mda@entry=1, dev_area=0x563ed00478d0, dev_area=0x563ed00478d0)
    at format_text/format-text.c:337
#7  0x0000563ecf59f597 in raw_read_mda_header (mem=0x563ecffa5a60, dev_area=0x563ed00478d0, primary_mda=1) at format_text/format-text.c:390
#8  0x0000563ecf59fc76 in _vg_commit_raw_rlocn (vg=0x563ed010ce30, mda=0x563ed00478a0, precommit=1, fid=<optimized out>, fid=<optimized out>) at format_text/format-text.c:875
#9  0x0000563ecf5d3ae6 in vg_write (vg=0x563ed010ce30) at metadata/metadata.c:3084
#10 0x0000563ecf5f6a4f in update_pool_lv (lv=lv@entry=0x563ed010dad8, activate=<optimized out>, activate@entry=0) at metadata/thin_manip.c:550
#11 0x0000563ecf5c6dea in _lv_create_an_lv (vg=vg@entry=0x563ed010ce30, lp=lp@entry=0x7fffa4ee49e0, new_lv_name=<optimized out>) at metadata/lv_manip.c:7845
#12 0x0000563ecf5c711f in lv_create_single (vg=vg@entry=0x563ed010ce30, lp=lp@entry=0x7fffa4ee49e0) at metadata/lv_manip.c:8078
#13 0x0000563ecf53e823 in _lvcreate_single (cmd=cmd@entry=0x563ecffa0020, vg_name=vg_name@entry=0x563ecffec0d0 "snapper_thinp", vg=vg@entry=0x563ed010ce30, 
    handle=handle@entry=0x563ecffebfc8) at lvcreate.c:1651
#14 0x0000563ecf55e0cf in _process_vgnameid_list (process_single_vg=0x563ecf53dc50 <_lvcreate_single>, handle=0x563ecffebfc8, arg_tags=0x7fffa4ee4750, arg_vgnames=0x7fffa4ee4760, 
    vgnameids_to_process=0x7fffa4ee4780, read_flags=1048576, cmd=0x563ecffa0020) at toollib.c:1984
#15 process_each_vg (cmd=cmd@entry=0x563ecffa0020, argc=argc@entry=0, argv=argv@entry=0x0, one_vgname=<optimized out>, use_vgnames=use_vgnames@entry=0x0, 
    read_flags=read_flags@entry=1048576, include_internal=include_internal@entry=0, handle=handle@entry=0x563ecffebfc8, 
    process_single_vg=process_single_vg@entry=0x563ecf53dc50 <_lvcreate_single>) at toollib.c:2297
#16 0x0000563ecf541f7f in lvcreate (cmd=0x563ecffa0020, argc=<optimized out>, argv=<optimized out>) at lvcreate.c:1696
#17 0x0000563ecf548d1b in lvm_run_command (cmd=0x563ecffa0020, argc=1, argv=0x7fffa4ee4f18) at lvmcmdline.c:3008
#18 0x0000563ecf549e9e in lvm2_main (argc=7, argv=0x7fffa4ee4ee8) at lvmcmdline.c:3586
#19 0x00007f54af4173d5 in __libc_start_main (main=0x563ecf526080 <main>, argc=7, ubp_av=0x7fffa4ee4ee8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, 
    stack_end=0x7fffa4ee4ed8) at ../csu/libc-start.c:274
#20 0x0000563ecf5260ae in _start ()




3.10.0-862.el7.x86_64
lvm2-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
lvm2-libs-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
lvm2-cluster-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
lvm2-python-boom-0.8.5-4.el7    BUILT: Fri Feb 16 13:37:10 CET 2018
cmirror-2.02.177-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-libs-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-event-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-event-libs-1.02.146-4.el7    BUILT: Fri Feb 16 13:22:31 CET 2018
device-mapper-persistent-data-0.7.3-3.el7    BUILT: Tue Nov 14 12:07:18 CET 2017

Comment 5 Corey Marthaler 2018-05-07 16:31:08 UTC

Once in this state, lvremove and vgremove also segfault, even after a fresh reboot.


[root@host-092 ~]# cat /proc/meminfo | grep ree
MemFree:        14536788 kB
SwapFree:         839676 kB

[root@host-092 ~]# lvs -a  | wc -l
189

[root@host-092 ~]# vgremove -f snapper_thinp
Segmentation fault (core dumped)
[root@host-092 ~]# lvremove -f snapper_thinp
Segmentation fault (core dumped)

Core was generated by `lvremove -f snapper_thinp'.
Program terminated with signal 11, Segmentation fault.
#0  0x00007f563ce8c895 in _int_malloc (av=av@entry=0x7f563d1d0760 <main_arena>, bytes=bytes@entry=16384) at malloc.c:3712
3712            unlink(av, victim, bck, fwd);
(gdb) bt
#0  0x00007f563ce8c895 in _int_malloc (av=av@entry=0x7f563d1d0760 <main_arena>, bytes=bytes@entry=16384) at malloc.c:3712
#1  0x00007f563ce8f7dc in __GI___libc_malloc (bytes=bytes@entry=16384) at malloc.c:2899
#2  0x00007f563d45353e in dm_malloc_aux (s=s@entry=16384, file=file@entry=0x7f563d4639c2 "mm/pool-fast.c", line=line@entry=286) at mm/dbg_malloc.c:286
#3  0x00007f563d4535b5 in dm_malloc_wrapper (s=s@entry=16384, file=file@entry=0x7f563d4639c2 "mm/pool-fast.c", line=line@entry=286) at mm/dbg_malloc.c:340
#4  0x00007f563d453ae4 in _new_chunk (s=16384, p=<optimized out>, p=<optimized out>) at mm/pool-fast.c:286
#5  0x00007f563d453cc2 in dm_pool_alloc_aligned (p=<optimized out>, s=s@entry=13, alignment=alignment@entry=8) at mm/pool-fast.c:106
#6  0x00007f563d453d3a in dm_pool_alloc (p=<optimized out>, s=s@entry=13) at mm/pool-fast.c:90
#7  0x00007f563d4309f8 in _dup_token (mem=<optimized out>, b=0x55c4c3f8d9f0 "extent_count", e=<optimized out>) at libdm-config.c:909
#8  0x00007f563d430b8a in _make_node (parent=0x55c4c3f8d928, key_e=0x55c4c3f8d9fc "", key_b=0x55c4c3f8d9f0 "extent_count", mem=0x55c4c400ce50) at libdm-config.c:512
#9  _find_or_make_node (mem=0x55c4c400ce50, parent=parent@entry=0x55c4c3f8d928, path=path@entry=0x55c4c3f8d9f0 "extent_count", no_dup_node_check=1) at libdm-config.c:559
#10 0x00007f563d431305 in _section (p=p@entry=0x55c4c3f85a68, parent=parent@entry=0x55c4c3f8d928) at libdm-config.c:606
#11 0x00007f563d43150b in _section (p=p@entry=0x55c4c3f85a68, parent=parent@entry=0x55c4c3f8d548) at libdm-config.c:612
#12 0x00007f563d43150b in _section (p=p@entry=0x55c4c3f85a68, parent=parent@entry=0x55c4c3f87af8) at libdm-config.c:612
#13 0x00007f563d43150b in _section (p=p@entry=0x55c4c3f85a68, parent=parent@entry=0x55c4c3f85ac0) at libdm-config.c:612
#14 0x00007f563d43150b in _section (p=p@entry=0x55c4c3f85a68, parent=parent@entry=0x7fff04854140) at libdm-config.c:612
#15 0x00007f563d4316c3 in _file (p=0x55c4c3f85a68) at libdm-config.c:498
#16 _do_dm_config_parse (
    start=start@entry=0x55c4c3f91990 "snapper_thinp {\nid = \"UQosAF-dp9j-fTze-b1Al-eSGA-3Ffc-UAW2ZK\"\nseqno = 343\nformat = \"lvm2\"\nstatus = [\"RESIZEABLE\", \"READ\", \"WRITE\"]\nflags = []\nextent_size = 8192\nmax_lv = 0\nmax_pv = 0\nmetadata_copies ="..., end=0x55c4c3fa198f "", no_dup_node_check=no_dup_node_check@entry=1, cft=0x55c4c3f85a40, 
    cft=0x55c4c3f85a40) at libdm-config.c:190
#17 0x00007f563d4322a8 in dm_config_parse_without_dup_node_check (cft=cft@entry=0x55c4c3f85a40, 
    start=start@entry=0x55c4c3f91990 "snapper_thinp {\nid = \"UQosAF-dp9j-fTze-b1Al-eSGA-3Ffc-UAW2ZK\"\nseqno = 343\nformat = \"lvm2\"\nstatus = [\"RESIZEABLE\", \"READ\", \"WRITE\"]\nflags = []\nextent_size = 8192\nmax_lv = 0\nmax_pv = 0\nmetadata_copies ="..., end=<optimized out>) at libdm-config.c:205
#18 0x000055c4c20138ee in config_tree_from_string_without_dup_node_check (
    config_settings=0x55c4c3f91990 "snapper_thinp {\nid = \"UQosAF-dp9j-fTze-b1Al-eSGA-3Ffc-UAW2ZK\"\nseqno = 343\nformat = \"lvm2\"\nstatus = [\"RESIZEABLE\", \"READ\", \"WRITE\"]\nflags = []\nextent_size = 8192\nmax_lv = 0\nmax_pv = 0\nmetadata_copies ="...) at config-util.c:171
#19 0x000055c4c1f7cc67 in export_vg_to_config_tree (vg=vg@entry=0x55c4c4053060) at format_text/export.c:1111
#20 0x000055c4c1fac593 in _vg_update_embedded_copy (vg=0x55c4c4053060, vg_embedded=0x55c4c4053098) at metadata/metadata.c:926
#21 0x000055c4c1fb4b0b in vg_write (vg=0x55c4c4053060) at metadata/metadata.c:3099
#22 0x000055c4c1fd7a4f in update_pool_lv (lv=lv@entry=0x55c4c4053d08, activate=<optimized out>, activate@entry=1) at metadata/thin_manip.c:550
#23 0x000055c4c1f9e4a5 in lv_remove_single (cmd=cmd@entry=0x55c4c3ee8020, lv=lv@entry=0x55c4c4053e78, force=force@entry=DONT_PROMPT, 
    suppress_remove_message=suppress_remove_message@entry=0) at metadata/lv_manip.c:6102
#24 0x000055c4c1f9f3b6 in lv_remove_with_dependencies (cmd=cmd@entry=0x55c4c3ee8020, lv=0x55c4c4053e78, force=force@entry=DONT_PROMPT, level=level@entry=1)
    at metadata/lv_manip.c:6384
#25 0x000055c4c1fa002e in _lv_remove_segs_using_this_lv (cmd=0x55c4c3ee8020, lv=0x55c4c4053d08, force=DONT_PROMPT, level=0, lv_type=<optimized out>) at metadata/lv_manip.c:6253
#26 0x000055c4c1f9f908 in lv_remove_with_dependencies (cmd=cmd@entry=0x55c4c3ee8020, lv=lv@entry=0x55c4c4053d08, force=DONT_PROMPT, level=level@entry=0)
    at metadata/lv_manip.c:6359
#27 0x000055c4c1f435c9 in lvremove_single (cmd=cmd@entry=0x55c4c3ee8020, lv=0x55c4c4053d08, handle=handle@entry=0x55c4c3f32248) at toollib.c:4661
#28 0x000055c4c1f4090b in process_each_lv_in_vg (cmd=cmd@entry=0x55c4c3ee8020, vg=vg@entry=0x55c4c4053060, arg_lvnames=arg_lvnames@entry=0x7fff048548d0, 
    tags_in=tags_in@entry=0x0, stop_on_error=stop_on_error@entry=0, handle=handle@entry=0x55c4c3f32248, check_single_lv=check_single_lv@entry=0x0, 
    process_single_lv=process_single_lv@entry=0x55c4c1f435a0 <lvremove_single>) at toollib.c:3172
#29 0x000055c4c1f41dff in _process_lv_vgnameid_list (process_single_lv=0x55c4c1f435a0 <lvremove_single>, check_single_lv=0x0, handle=0x55c4c3f32248, arg_tags=0x7fff04854880, 
    arg_lvnames=0x7fff048548a0, arg_vgnames=0x7fff04854890, vgnameids_to_process=0x7fff048548c0, read_flags=1048576, cmd=0x55c4c3ee8020) at toollib.c:3636
#30 process_each_lv (cmd=cmd@entry=0x55c4c3ee8020, argc=argc@entry=1, argv=<optimized out>, one_vgname=one_vgname@entry=0x0, one_lvname=one_lvname@entry=0x0, 
    read_flags=read_flags@entry=1048576, handle=0x55c4c3f32248, handle@entry=0x0, check_single_lv=check_single_lv@entry=0x0, process_single_lv=0x55c4c1f435a0 <lvremove_single>)
    at toollib.c:3788
#31 0x000055c4c1f2b447 in lvremove (cmd=0x55c4c3ee8020, argc=1, argv=<optimized out>) at lvremove.c:29
#32 0x000055c4c1f29d1b in lvm_run_command (cmd=0x55c4c3ee8020, argc=1, argv=0x7fff04854db8) at lvmcmdline.c:3008
#33 0x000055c4c1f2ae9e in lvm2_main (argc=3, argv=0x7fff04854da8) at lvmcmdline.c:3586
#34 0x00007f563ce2c3d5 in __libc_start_main (main=0x55c4c1f07080 <main>, argc=3, ubp_av=0x7fff04854da8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, 
    stack_end=0x7fff04854d98) at ../csu/libc-start.c:274
#35 0x000055c4c1f070ae in _start ()

Comment 6 Yaniv Kaul 2018-12-23 07:47:36 UTC

Can you please attach complete logs? It's clear it has to do with some failed memory allocation, perhaps running out of memory or something?

Comment 9 David Teigland 2019-03-11 15:26:21 UTC

Just prior to 7.5, there were a pile of changes made to the lvm io layer, and those changes include the specific code paths implicated above.

In 7.6 the entire io layer was replaced, and the code paths above are not longer used.

So, this bug will exist in code that had a very short lifespan, but unfortunately got included in 7.5.

If a fix against the 7.5 version of lvm is needed (i.e. updating to 7.6 is not an option for some people), then I've identified the following 16 commits that we can bisect to try and find the bug, made between Dec 8-15, 2017.

5f45cb90a7d6 format_text: Transfer circular buf alloc to device layer.
beee9940a503 format_text: Separate out code paths for buffer wraparound
145ded10c29a format_text: Supply mempool directly to raw_read_mda_header.
3edc25dbdfc5 format_text: Round size written up to multiple of 4096.
78ffa44fc58f format_text: Change metadata alignment from 512 to 4096.
643df602c7d1 format_text: More refactoring of metadata offset calcs
4002f5e206ae format_text: Refactor and document metadata offset calculation.
e932c5da50a2 device: Fix an unpaired device close.
b96862ee11e0 metadata: Consistently skip metadata areas that failed.
c5ef76bf2733 device: Internal error if writing 0 bytes to dev.
b76c6951aa5c format_text: Adjust metadata alignment calculation.
053d35de473a format_text: Use absolute alignment to calculate metadata usage
2db67a8ea09a format_text: Move metadata size checking into separate fn.
46393bfca069 format_text: Log additional circular buffer information.
49d486319fa6 format_text: Replace PRI with FMT.
14b1e5270dbc format_text: Use explicit alignment in wrapping calc.

Comment 11 Zdenek Kabelac 2021-02-09 00:23:16 UTC

*** Bug 1599293 has been marked as a duplicate of this bug. ***

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