Bug 763253 (GLUSTER-1521)

Summary: Crash in mem_pool_destroy on CTRL-C
Product: [Community] GlusterFS Reporter: Shehjar Tikoo <shehjart>
Component: coreAssignee: Amar Tumballi <amarts>
Status: CLOSED DUPLICATE QA Contact:
Severity: medium Docs Contact:
Priority: low    
Version: 3.1-alphaCC: gluster-bugs, vraman
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: ---
Regression: RTP Mount Type: nfs
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Shehjar Tikoo 2010-09-03 12:17:04 UTC 
root@ubuntu8-71:~# /tmp/glusterfsd-master/sbin/glusterfs -f /tmp/shehjart-volfiles/nfs-buildbot-posix.vol -L TRACE -l /dev/stdout --no-daemon
[2010-09-02 17:27:35.154182] D [glusterfsd.c:336:get_volfp] glusterfsd: loading volume file /tmp/shehjart-volfiles/nfs-buildbot-posix.vol
[2010-09-02 17:27:35.155205] T [graph.y:192:new_volume] parser: New node for 'posix-brick'
[2010-09-02 17:27:35.155266] T [xlator.c:698:xlator_set_type] xlator: attempt to load file /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/storage/posix.so
[2010-09-02 17:27:35.155485] T [graph.y:223:volume_type] parser: Type:posix-brick:storage/posix
[2010-09-02 17:27:35.155534] T [graph.y:258:volume_option] parser: Option:posix-brick:directory:/tmp/glusterfsd-master-posix
[2010-09-02 17:27:35.155566] T [graph.y:365:volume_end] parser: end:posix-brick
[2010-09-02 17:27:35.155597] T [graph.y:192:new_volume] parser: New node for 'posix-ac'
[2010-09-02 17:27:35.155626] T [xlator.c:698:xlator_set_type] xlator: attempt to load file /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/access-control.so
[2010-09-02 17:27:35.155782] D [xlator.c:738:xlator_set_type] xlator: dlsym(notify) on /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/access-control.so: undefined symbol: notify -- neglecting
[2010-09-02 17:27:35.155821] D [xlator.c:743:xlator_set_type] xlator: dlsym(dumpops) on /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/access-control.so: undefined symbol: dumpops -- neglecting
[2010-09-02 17:27:35.155853] D [xlator.c:749:xlator_set_type] posix-ac: dlsym(mem_acct_init) on /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/access-control.so: undefined symbol: mem_acct_init -- neglecting
[2010-09-02 17:27:35.155887] D [xlator.c:765:xlator_set_type] posix-ac: Strict option validation not enforced -- neglecting
[2010-09-02 17:27:35.155915] T [graph.y:223:volume_type] parser: Type:posix-ac:features/access-control
[2010-09-02 17:27:35.155945] T [graph.y:348:volume_sub] parser: child:posix-ac->posix-brick
[2010-09-02 17:27:35.155972] T [graph.y:365:volume_end] parser: end:posix-ac
[2010-09-02 17:27:35.156000] T [graph.y:192:new_volume] parser: New node for 'posix-locked'
[2010-09-02 17:27:35.156029] T [xlator.c:698:xlator_set_type] xlator: attempt to load file /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/locks.so
[2010-09-02 17:27:35.156160] D [xlator.c:738:xlator_set_type] xlator: dlsym(notify) on /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/locks.so: undefined symbol: notify -- neglecting
[2010-09-02 17:27:35.156196] T [graph.y:223:volume_type] parser: Type:posix-locked:features/locks
[2010-09-02 17:27:35.156224] T [graph.y:348:volume_sub] parser: child:posix-locked->posix-ac
[2010-09-02 17:27:35.156251] T [graph.y:365:volume_end] parser: end:posix-locked
[2010-09-02 17:27:35.156279] T [graph.y:192:new_volume] parser: New node for 'posix'
[2010-09-02 17:27:35.156307] T [xlator.c:698:xlator_set_type] xlator: attempt to load file /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/performance/io-threads.so
[2010-09-02 17:27:35.156474] D [xlator.c:738:xlator_set_type] xlator: dlsym(notify) on /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/performance/io-threads.so: undefined symbol: notify -- neglecting
[2010-09-02 17:27:35.156510] D [xlator.c:743:xlator_set_type] xlator: dlsym(dumpops) on /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/performance/io-threads.so: undefined symbol: dumpops -- neglecting
[2010-09-02 17:27:35.156540] T [graph.y:223:volume_type] parser: Type:posix:performance/io-threads
[2010-09-02 17:27:35.156568] T [graph.y:348:volume_sub] parser: child:posix->posix-locked
[2010-09-02 17:27:35.156634] T [graph.y:365:volume_end] parser: end:posix
[2010-09-02 17:27:35.156670] T [graph.y:192:new_volume] parser: New node for 'nfs'
[2010-09-02 17:27:35.156700] T [xlator.c:698:xlator_set_type] xlator: attempt to load file /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/nfs/server.so
[2010-09-02 17:27:35.157289] D [xlator.c:743:xlator_set_type] xlator: dlsym(dumpops) on /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/nfs/server.so: undefined symbol: dumpops -- neglecting
[2010-09-02 17:27:35.157348] T [graph.y:223:volume_type] parser: Type:nfs:nfs/server
[2010-09-02 17:27:35.157392] T [graph.y:348:volume_sub] parser: child:nfs->posix
[2010-09-02 17:27:35.157434] T [graph.y:258:volume_option] parser: Option:nfs:rpc-auth.addr.allow:*
[2010-09-02 17:27:35.157462] T [graph.y:365:volume_end] parser: end:nfs
[2010-09-02 17:27:35.157573] D [xlator.c:960:xlator_mem_acct_init] nfs: Allocated mem_acct_rec for 95 types
[2010-09-02 17:27:35.157621] T [rpcsvc-auth.c:105:nfs_rpcsvc_auth_init_auth] nfsrpc: Authentication enabled: AUTH_UNIX
[2010-09-02 17:27:35.157661] T [rpcsvc-auth.c:105:nfs_rpcsvc_auth_init_auth] nfsrpc: Authentication enabled: AUTH_NULL
[2010-09-02 17:27:35.157693] T [rpcsvc.c:86:nfs_rpcsvc_stage_init] nfsrpc: event pool size: 15360
[2010-09-02 17:27:35.157793] D [rpcsvc.c:167:nfs_rpcsvc_init] nfsrpc: RPC service inited.
[2010-09-02 17:27:35.157960] T [nfs.c:345:nfs_init_subvolumes] nfs: inode table lru: 90000
[2010-09-02 17:27:35.158001] D [nfs.c:349:nfs_init_subvolumes] nfs: Initing subvolume: posix
[2010-09-02 17:27:35.199614] T [nfs.c:369:nfs_init_subvolumes] nfs: Inited volumes: 1
[2010-09-02 17:27:35.199743] D [nfs.c:520:init] nfs: NFS service started
[2010-09-02 17:27:35.199791] D [xlator.c:960:xlator_mem_acct_init] posix: Allocated mem_acct_rec for 77 types
[2010-09-02 17:27:35.199882] D [io-threads.c:2017:__iot_workers_scale] posix: scaled threads to 1 (queue_size=0/1)
[2010-09-02 17:27:35.199940] D [xlator.c:960:xlator_mem_acct_init] posix-locked: Allocated mem_acct_rec for 85 types
[2010-09-02 17:27:35.199976] D [xlator.c:960:xlator_mem_acct_init] posix-ac: Allocated mem_acct_rec for 74 types
[2010-09-02 17:27:35.200012] D [xlator.c:960:xlator_mem_acct_init] posix-brick: Allocated mem_acct_rec for 83 types
[2010-09-02 17:27:35.200147] T [posix.c:1267:posix_janitor_thread_proc] posix-brick: janitor cleaning out /.landfill
[2010-09-02 17:27:35.200233] T [nfs.c:536:notify] nfs: Notification received: 1
[2010-09-02 17:27:35.200263] T [nfs.c:536:notify] nfs: Notification received: 5
[2010-09-02 17:27:35.200292] D [nfs.c:212:nfs_subvolume_set_started] nfs: Starting up: posix , vols started till now: 1
[2010-09-02 17:27:35.200326] T [nfs-fops.c:280:nfs_fop_lookup] nfs: Lookup: /
[2010-09-02 17:27:35.200383] D [dict.c:326:dict_get] dict: @this=(nil) @key=0x7f86afb63df9
[2010-09-02 17:27:35.200395] D [dict.c:326:dict_get] dict: @this=(nil) @key=0x7f86afb63e11
[2010-09-02 17:27:35.200403] D [dict.c:326:dict_get] dict: @this=(nil) @key=0x7f86afb63e29
[2010-09-02 17:27:35.228968] T [nfs.c:546:notify] nfs: All children up, starting RPC
[2010-09-02 17:27:35.229005] D [nfs.c:107:nfs_init_versions] nfs: Initing protocol versions
[2010-09-02 17:27:35.229042] D [mount3.c:1484:mnt3svc_init] nfs-mount: Initing Mount v3 state
[2010-09-02 17:27:35.229078] T [mount3.c:1383:__mnt3_init_volume_export] nfs-mount: Volume exports enabled
[2010-09-02 17:27:35.229109] T [mount3.c:1404:mnt3_init_options] nfs-mount: Initing options for: posix
[2010-09-02 17:27:35.229141] T [mount3.c:1245:mnt3_init_export_ent] nfs-mount: Initing volume export: posix
[2010-09-02 17:27:35.229171] D [nfs.c:124:nfs_init_versions] nfs: Starting program: MOUNT3
[2010-09-02 17:27:35.229286] T [rpcsvc.c:642:nfs_rpcsvc_conn_init] nfsrpc: tx pool: 525
[2010-09-02 17:27:35.229363] T [rpcsvc.c:649:nfs_rpcsvc_conn_init] nfsrpc: rx pool: 525
[2010-09-02 17:27:35.229779] D [rpcsvc.c:665:nfs_rpcsvc_conn_init] nfsrpc: New connection inited: sockfd: 7
[2010-09-02 17:27:35.230090] D [rpcsvc.c:2720:nfs_rpcsvc_program_register] nfsrpc: New program registered: MOUNT3, Num: 100005, Ver: 3, Port: 38465
[2010-09-02 17:27:35.230134] D [mount3.c:1528:mnt1svc_init] nfs-mount: Initing Mount v1 state
[2010-09-02 17:27:35.230164] T [mount3.c:1383:__mnt3_init_volume_export] nfs-mount: Volume exports enabled
[2010-09-02 17:27:35.230191] T [mount3.c:1404:mnt3_init_options] nfs-mount: Initing options for: posix
[2010-09-02 17:27:35.230219] T [mount3.c:1245:mnt3_init_export_ent] nfs-mount: Initing volume export: posix
[2010-09-02 17:27:35.230246] D [nfs.c:124:nfs_init_versions] nfs: Starting program: MOUNT1
[2010-09-02 17:27:35.230304] T [rpcsvc.c:642:nfs_rpcsvc_conn_init] nfsrpc: tx pool: 525
[2010-09-02 17:27:35.230370] T [rpcsvc.c:649:nfs_rpcsvc_conn_init] nfsrpc: rx pool: 525
[2010-09-02 17:27:35.230794] D [rpcsvc.c:665:nfs_rpcsvc_conn_init] nfsrpc: New connection inited: sockfd: 8
[2010-09-02 17:27:35.230991] D [rpcsvc.c:2720:nfs_rpcsvc_program_register] nfsrpc: New program registered: MOUNT1, Num: 100005, Ver: 1, Port: 38466
[2010-09-02 17:27:35.231042] T [nfs3.c:4976:nfs3_init_state] nfs-nfsv3: local pool: 225
[2010-09-02 17:27:35.231274] T [nfs3.c:4896:nfs3_init_subvolume] nfs-nfsv3: Initing state: posix
[2010-09-02 17:27:35.231320] T [nfs3.c:4876:nfs3_init_subvolume_options] nfs-nfsv3: posix: read-write, no trusted_sync, no trusted_write
[2010-09-02 17:27:35.231351] D [nfs.c:124:nfs_init_versions] nfs: Starting program: NFS3
[2010-09-02 17:27:35.231460] T [rpcsvc.c:642:nfs_rpcsvc_conn_init] nfsrpc: tx pool: 525
[2010-09-02 17:27:35.231537] T [rpcsvc.c:649:nfs_rpcsvc_conn_init] nfsrpc: rx pool: 525
[2010-09-02 17:27:35.231994] D [rpcsvc.c:665:nfs_rpcsvc_conn_init] nfsrpc: New connection inited: sockfd: 9
[2010-09-02 17:27:35.232195] D [rpcsvc.c:2720:nfs_rpcsvc_program_register] nfsrpc: New program registered: NFS3, Num: 100003, Ver: 3, Port: 38467
Given volfile:
+------------------------------------------------------------------------------+
  1: volume posix-brick
  2:         type storage/posix
  3:         option directory /tmp/glusterfsd-master-posix
  4: end-volume
  5: 
  6: volume posix-ac
  7:         type features/access-control
  8:         subvolumes posix-brick
  9: end-volume
 10: 
 11: volume posix-locked
 12:         type features/locks
 13:         subvolumes posix-ac
 14: end-volume
 15: 
 16: volume posix
 17:         type performance/io-threads
 18:         subvolumes posix-locked
 19: end-volume
 20: 
 21: volume nfs
 22:         type nfs/server
 23:         subvolumes posix
 24:         option rpc-auth.addr.allow *
 25: end-volume
 26: 
 27: 

+------------------------------------------------------------------------------+
[2010-09-02 17:27:36.742010] I [glusterfsd.c:648:cleanup_and_exit] glusterfsd: shutting down
[2010-09-02 17:27:36.742049] D [nfs.c:574:fini] nfs: NFS service going down
[2010-09-02 17:27:36.742270] D [rpcsvc.c:2769:nfs_rpcsvc_program_unregister] nfsrpc: Program unregistered: MOUNT3, Num: 100005, Ver: 3, Port: 38465
[2010-09-02 17:27:36.742387] D [rpcsvc.c:2769:nfs_rpcsvc_program_unregister] nfsrpc: Program unregistered: MOUNT1, Num: 100005, Ver: 1, Port: 38466
[2010-09-02 17:27:36.742492] D [rpcsvc.c:2769:nfs_rpcsvc_program_unregister] nfsrpc: Program unregistered: NFS3, Num: 100003, Ver: 3, Port: 38467
glusterfs: mem-pool.c:252: __gf_free: Assertion `0' failed.
pending frames:

patchset: git://git.sv.gnu.org/gluster.git
signal received: 6
time of crash: 2010-09-02 17:27:36
configuration details:
argp 1
backtrace 1
dlfcn 1
fdatasync 1
libpthread 1
llistxattr 1
setfsid 1
spinlock 1
epoll.h 1
xattr.h 1
st_atim.tv_nsec 1
package-string: glusterfs 3.1.0git
/lib/libc.so.6[0x7f86b0de2100]
/lib/libc.so.6(gsignal+0x35)[0x7f86b0de2095]
/lib/libc.so.6(abort+0x110)[0x7f86b0de3af0]
/lib/libc.so.6(__assert_fail+0xef)[0x7f86b0ddb2df]
/tmp/glusterfsd-master/lib/libglusterfs.so.0(__gf_free+0x105)[0x7f86b198fd95]
/tmp/glusterfsd-master/lib/libglusterfs.so.0(mem_pool_destroy+0x1b)[0x7f86b198fdfb]
/tmp/glusterfsd-master/sbin/glusterfs[0x403c80]
/lib/libc.so.6[0x7f86b0de2100]
/lib/libpthread.so.0(pthread_cond_wait+0xb7)[0x7f86b111cb97]
/tmp/glusterfsd-master/lib/libglusterfs.so.0[0x7f86b198ed4d]
/tmp/glusterfsd-master/sbin/glusterfs(main+0x377)[0x404ba7]
/lib/libc.so.6(__libc_start_main+0xf4)[0x7f86b0dce1c4]
/tmp/glusterfsd-master/sbin/glusterfs[0x4031d9]
---------
Aborted (core dumped)


root@ubuntu8-71:~# gdb /tmp/glusterfsd-master/sbin/glusterfs core.25873 
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /tmp/glusterfsd-master/lib/libglusterfs.so.0...done.
Loaded symbols for /tmp/glusterfsd-master/lib/libglusterfs.so.0
Reading symbols from /tmp/glusterfsd-master/lib/libgfrpc.so.0...done.
Loaded symbols for /tmp/glusterfsd-master/lib/libgfrpc.so.0
Reading symbols from /tmp/glusterfsd-master/lib/libgfxdr.so.0...done.
Loaded symbols for /tmp/glusterfsd-master/lib/libgfxdr.so.0
Reading symbols from /lib/libdl.so.2...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/libpthread.so.0...done.
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux-x86-64.so.2...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Reading symbols from /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/storage/posix.so...done.
Loaded symbols for /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/storage/posix.so
Reading symbols from /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/access-control.so...done.
Loaded symbols for /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/access-control.so
Reading symbols from /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/locks.so...done.
Loaded symbols for /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/features/locks.so
Reading symbols from /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/performance/io-threads.so...done.
Loaded symbols for /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/performance/io-threads.so
Reading symbols from /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/nfs/server.so...done.
Loaded symbols for /tmp/glusterfsd-master/lib/glusterfs/3.1.0git/xlator/nfs/server.so
Reading symbols from /lib/libgcc_s.so.1...done.
Loaded symbols for /lib/libgcc_s.so.1
Core was generated by `/tmp/glusterfsd-master/sbin/glusterfs -f /tmp/shehjart-volfiles/nfs-buildbot-po'.
Program terminated with signal 6, Aborted.
[New process 25873]
[New process 25877]
[New process 25876]
[New process 25875]
[New process 25874]
#0  0x00007f86b0de2095 in raise () from /lib/libc.so.6
(gdb) bt
#0  0x00007f86b0de2095 in raise () from /lib/libc.so.6
#1  0x00007f86b0de3af0 in abort () from /lib/libc.so.6
#2  0x00007f86b0ddb2df in __assert_fail () from /lib/libc.so.6
#3  0x00007f86b198fd95 in __gf_free (free_ptr=<value optimized out>) at mem-pool.c:252
#4  0x00007f86b198fdfb in mem_pool_destroy (pool=0x62c248) at mem-pool.c:513
#5  0x0000000000403c80 in cleanup_and_exit (signum=<value optimized out>) at glusterfsd.c:670
#6  <signal handler called>
#7  0x00007f86b111cb97 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#8  0x00007f86b198ed4d in event_dispatch_epoll (event_pool=0x62c188) at event.c:838
#9  0x0000000000404ba7 in main (argc=8, argv=0x7ffffdbf12c8) at glusterfsd.c:1398
(gdb)
Comment 1 Shehjar Tikoo 2010-09-06 08:12:25 UTC 

*** This bug has been marked as a duplicate of bug 1523 ***