Bug 762031 (GLUSTER-299)

Summary: booster segfault while reading volume file
Product: [Community] GlusterFS Reporter: Amar Tumballi <amarts>
Component: boosterAssignee: Shehjar Tikoo <shehjart>
Status: CLOSED CURRENTRELEASE QA Contact:
Severity: high Docs Contact:
Priority: urgent    
Version: 2.0.6CC: aavati, anush, gluster-bugs, sac, vraman
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: ---
Regression: RTNR Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Amar Tumballi 2009-10-05 23:48:58 UTC
Version: 2.0.7rc9 (latest available on /opt in test cluster)


Description:

details below:

[root@brick7 ~]# cat /tmp/booster.conf 
/tmp/posix.vol /var/tmp/testbooster glusterfs log-file=/tmp/booster.log,log-level=TRACE
[root@brick7 ~]# cat /tmp/posix.vol 
volume posix
  type storage/posix
  option directory /tmp/test-export
end-volume
volume wb
  type performance/write-behind
  option flush-behind on
  subvolumes posix
end-volume
[root@brick7 ~# tail /etc/samba/smb.conf
        [public]
        comment = Public Stuff
        path = /var/tmp/testbooster
        public = yes
        writable = yes
        printable = no
[root@brick7 ~]# export GLUSTERFS_BOOSTER_FSTAB=/tmp/booster.conf 
[root@brick7 ~]# LD_PRELOAD=/opt/glusterfs/2.0.7rc9/lib/glusterfs/glusterfs-booster.so  /etc/init.d/smb restart
Segmentation fault (core dumped)


strace on /etc/init.d/smb gave following output..

execve("/etc/init.d/smb", ["/etc/init.d/smb", "start"], [/* 24 vars */]) = 0
brk(0)                                  = 0x105f7000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7ddab8000
uname({sys="Linux", node="brick7", ...}) = 0
open("/opt/glusterfs/2.0.7rc9/lib/glusterfs/glusterfs-booster.so", O_RDONLY) = 8
read(8, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\3207\0\0\0\0\0\0"..., 832) = 832
fstat(8, {st_mode=S_IFREG|0755, st_size=133049, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7ddab9000
mmap(NULL, 2164864, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8, 0) = 0x2ba7ddaba000
mprotect(0x2ba7ddacb000, 2093056, PROT_NONE) = 0
mmap(0x2ba7ddcca000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x10000) = 0x2ba7ddcca000
close(8)                                = 0
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 8
fstat(8, {st_mode=S_IFREG|0644, st_size=69979, ...}) = 0
mmap(NULL, 69979, PROT_READ, MAP_PRIVATE, 8, 0) = 0x2ba7ddccb000
close(8)                                = 0
open("/lib64/libtermcap.so.2", O_RDONLY) = 8
read(8, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\17\240d2\0\0\0"..., 832) = 832
fstat(8, {st_mode=S_IFREG|0755, st_size=15584, ...}) = 0
mmap(0x3264a00000, 2108688, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8, 0) = 0x3264a00000
mprotect(0x3264a03000, 2093056, PROT_NONE) = 0
mmap(0x3264c02000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x2000) = 0x3264c02000
close(8)                                = 0
open("/lib64/libdl.so.2", O_RDONLY)     = 8
read(8, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\16 c2\0\0\0"..., 832) = 832
fstat(8, {st_mode=S_IFREG|0755, st_size=23360, ...}) = 0
mmap(0x3263200000, 2109696, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8, 0) = 0x3263200000
mprotect(0x3263202000, 2097152, PROT_NONE) = 0
mmap(0x3263402000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x2000) = 0x3263402000
close(8)                                = 0
open("/lib64/libc.so.6", O_RDONLY)      = 8
read(8, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\331\341b2\0\0\0"..., 832) = 832
fstat(8, {st_mode=S_IFREG|0755, st_size=1699880, ...}) = 0
mmap(0x3262e00000, 3481848, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8, 0) = 0x3262e00000
mprotect(0x3262f4a000, 2093056, PROT_NONE) = 0
mmap(0x3263149000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x149000) = 0x3263149000
mmap(0x326314e000, 16632, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x326314e000
close(8)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7ddcdd000
open("/opt/glusterfs/2.0.7rc9/lib/tls/x86_64/libglusterfs.so.0", O_RDONLY) = -1 ENOENT (No such file or directory)
stat("/opt/glusterfs/2.0.7rc9/lib/tls/x86_64", 0x7fffccfeeb60) = -1 ENOENT (No such file or directory)
open("/opt/glusterfs/2.0.7rc9/lib/tls/libglusterfs.so.0", O_RDONLY) = -1 ENOENT (No such file or directory)
stat("/opt/glusterfs/2.0.7rc9/lib/tls", 0x7fffccfeeb60) = -1 ENOENT (No such file or directory)
open("/opt/glusterfs/2.0.7rc9/lib/x86_64/libglusterfs.so.0", O_RDONLY) = -1 ENOENT (No such file or directory)
stat("/opt/glusterfs/2.0.7rc9/lib/x86_64", 0x7fffccfeeb60) = -1 ENOENT (No such file or directory)
open("/opt/glusterfs/2.0.7rc9/lib/libglusterfs.so.0", O_RDONLY) = 8
read(8, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\235\0\0\0\0\0\0"..., 832) = 832
fstat(8, {st_mode=S_IFREG|0755, st_size=705471, ...}) = 0
mmap(NULL, 2436592, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8, 0) = 0x2ba7ddcde000
mprotect(0x2ba7ddd1e000, 2093056, PROT_NONE) = 0
mmap(0x2ba7ddf1d000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x3f000) = 0x2ba7ddf1d000
mmap(0x2ba7ddf1f000, 73200, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x2ba7ddf1f000
close(8)                                = 0
open("/opt/glusterfs/2.0.7rc9/lib/libglusterfsclient.so.0", O_RDONLY) = 8
read(8, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260m\0\0\0\0\0\0"..., 832) = 832
fstat(8, {st_mode=S_IFREG|0755, st_size=312504, ...}) = 0
mmap(NULL, 2256536, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8, 0) = 0x2ba7ddf31000
mprotect(0x2ba7ddf57000, 2097152, PROT_NONE) = 0
mmap(0x2ba7de157000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x26000) = 0x2ba7de157000
close(8)                                = 0
open("/opt/glusterfs/2.0.7rc9/lib/libpthread.so.0", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/lib64/libpthread.so.0", O_RDONLY) = 8
read(8, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@W`c2\0\0\0"..., 832) = 832
fstat(8, {st_mode=S_IFREG|0755, st_size=141456, ...}) = 0
mmap(0x3263600000, 2200432, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8, 0) = 0x3263600000
mprotect(0x3263615000, 2093056, PROT_NONE) = 0
mmap(0x3263814000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x14000) = 0x3263814000
mmap(0x3263816000, 13168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3263816000
close(8)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7de158000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7de159000
arch_prctl(ARCH_SET_FS, 0x2ba7de1593b0) = 0
mprotect(0x3263814000, 4096, PROT_READ) = 0
mprotect(0x3263149000, 16384, PROT_READ) = 0
mprotect(0x3263402000, 4096, PROT_READ) = 0
mprotect(0x3262c1a000, 4096, PROT_READ) = 0
munmap(0x2ba7ddccb000, 69979)           = 0
set_tid_address(0x2ba7de159440)         = 2074
set_robust_list(0x2ba7de159450, 0x18)   = 0
rt_sigaction(SIGRTMIN, {0x3263605360, [], SA_RESTORER|SA_SIGINFO, 0x326360de80}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {0x32636052b0, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x326360de80}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
getrlimit(RLIMIT_STACK, {rlim_cur=10240*1024, rlim_max=RLIM_INFINITY}) = 0
futex(0x32634030ec, FUTEX_WAKE, 2147483647) = 0
brk(0)                                  = 0x105f7000
brk(0x10618000)                         = 0x10618000
pipe([8, 12])                           = 0
close(12)                               = 0
open("/tmp/booster.conf", O_RDONLY)     = 12
fstat(12, {st_mode=S_IFREG|0644, st_size=87, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7ddccb000
read(12, "/tmp/posix.vol /var/tmp/testboos"..., 4096) = 87
read(12, "", 4096)                      = 0
read(12, "", 4096)                      = 0
mmap(NULL, 397312, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7de15a000
epoll_create(16384)                     = 13
mmap(NULL, 8388608, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7de1bb000
setrlimit(RLIMIT_CORE, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = 0
setrlimit(RLIMIT_NOFILE, {rlim_cur=RLIM_INFINITY, rlim_max=RLIM_INFINITY}) = -1 EPERM (Operation not permitted)
open("/tmp/booster.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 14
fstat(14, {st_mode=S_IFREG|0644, st_size=29916, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7de9bb000
fstat(14, {st_mode=S_IFREG|0644, st_size=29916, ...}) = 0
lseek(14, 29916, SEEK_SET)              = 29916
open("/tmp/posix.vol", O_RDONLY)        = 15
stat("/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=4096, ...}) = 0
gettimeofday({1254785414, 119326}, NULL) = 0
open("/tmp/tmpfmeHkfD", O_RDWR|O_CREAT|O_EXCL, 0600) = 16
unlink("/tmp/tmpfmeHkfD")               = 0
fcntl(16, F_GETFL)                      = 0x8002 (flags O_RDWR|O_LARGEFILE)
fstat(16, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7de9bc000
lseek(16, 0, SEEK_CUR)                  = 0
fstat(15, {st_mode=S_IFREG|0644, st_size=182, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ba7de9bd000
lseek(15, 0, SEEK_SET)                  = 0
lseek(16, 0, SEEK_SET)                  = 0
read(15, "volume posix\n  type storage/posi"..., 4096) = 182
read(15, "", 4096)                      = 0
lseek(15, 0, SEEK_SET)                  = 0
write(16, "volume posix\n  type storage/posi"..., 182) = 182
lseek(16, 0, SEEK_SET)                  = 0
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
+++ killed by SIGSEGV (core dumped) +++

Comment 1 Shehjar Tikoo 2009-10-06 02:59:02 UTC
Do you have a log file that goes with this? If not and if you're planning to run this again, run it with loglevel TRACE.

Comment 2 Amar Tumballi 2009-10-06 03:01:42 UTC
(In reply to comment #1)
> Do you have a log file that goes with this? If not and if you're planning to
> run this again, run it with loglevel TRACE.

The log file was 'created' but was empty. Nothing in log file when loglevel was TRACE || DEBUG || default

Comment 3 Shehjar Tikoo 2009-10-06 03:14:46 UTC
Yep. I am looking at that now.

Assuming core.2588 file in ~/ for root is the dump for this particular test, the backtrace is below. Note that the backtrace cannot be obtained by running `which smbd` in gdb since the crash has happened while reading the vol file, which means even before the shell(..this is a script..) has had a chance to start running. So the backtrace should be got by running gdb `which sh` core.2588.

Here it is:
Core was generated by `/bin/sh /etc/init.d/smb restart'.
Program terminated with signal 11, Segmentation fault.
#0  0x0000000000000000 in ?? ()
(gdb) bt
#0  0x0000000000000000 in ?? ()
#1  0x000000000041d645 in decode_prompt_string ()
#2  0x000000000041e84e in gather_here_documents ()
#3  0x000000000042188a in yyparse ()
#4  0x00002b4d077c74b7 in file_to_xlator_tree (ctx=0xe875fd0, fp=0xe877100)
    at ../../../libglusterfs/src/spec.y:589
#5  0x00002b4d07a11cff in glusterfs_init (init_ctx=0x7fffa3519d00, 
    fakefsid=104) at ../../../libglusterfsclient/src/libglusterfsclient.c:1174
#6  0x00002b4d07a137fd in glusterfs_mount (
    vmp=0xe87588b "/var/tmp/testbooster", ipars=0x7fffa3519d00)
    at ../../../libglusterfsclient/src/libglusterfsclient.c:1685
#7  0x00002b4d0759db74 in booster_mount (ent=0xe875c78)
    at ../../../booster/src/booster_fstab.c:423
#8  0x00002b4d0759dc13 in booster_configure (
    confpath=0x7fffa351ae6d "/var/tmp/booster.conf")
    at ../../../booster/src/booster_fstab.c:444
#9  0x00002b4d075977e4 in booster_init ()
    at ../../../booster/src/booster.c:1174
#10 0x00002b4d0759c568 in booster_lib_init ()
    at ../../../booster/src/booster.c:2735
#11 0x00002b4d0759e6a6 in __do_global_ctors_aux ()
   from /opt/glusterfs/2.0.7rc9/lib/glusterfs/glusterfs-booster.so
#12 0x00002b4d07593ff3 in _init ()
---Type <return> to continue, or q <return> to quit---


Cursory glance at the trace suggests it could be the same old conflict with the yyparse symbols inside bash.

Comment 4 Shehjar Tikoo 2009-10-06 03:23:48 UTC
Input from Bot confirms that this could be a problem with running LD_PRELOADed booster for the shell, when in fact LD_PRELOAD should be done for the smbd command only.

Comment 5 Shehjar Tikoo 2009-10-06 03:30:44 UTC
Ok. I've confirmed it. This is about clashes with the use of lex ,etc inside bash. smbd works when I start it manually by using:

[root@brick7 ~]# LD_PRELOAD=/opt/glusterfs/2.0.7/lib/glusterfs/glusterfs-booster.so /usr/sbin/smbd -s/etc/samba/smb.conf

Of course, to have a working smbd, you'll need to manually start nmbd also but without booster.