Re: 8.2 + apache == a LOT of sigprocmask

Daniil Cherednik Thu, 17 Nov 2011 00:32:31 -0800

On 17.11.2011 11:49, Kostik Belousov wrote:

On Wed, Nov 16, 2011 at 10:46:27PM -0800, Doug Barton wrote:

On 11/15/2011 02:09, Jeremy Chadwick wrote:

On Tue, Nov 15, 2011 at 11:07:45AM +0200, Kostik Belousov wrote:

On Mon, Nov 14, 2011 at 12:51:35PM -0800, Doug Barton wrote:

On 11/14/2011 12:31, Doug Barton wrote:

Trying to track down a load problem we're seeing on 8.2-RELEASE-p4 i386
in a busy web hosting environment I came across the following post:


http://lists.freebsd.org/pipermail/freebsd-questions/2011-October/234520.html

That basically describes what we're seeing as well, including the
"doesn't happen on Linux" part.

Does anyone have any ideas about this?

With incredibly similar stuff running on 7.x we didn't see this problem,
so it seems to be something new in 8.

Just took a closer look at our ktrace, and actually our pattern is
slightly different than the one in that post. In ours the second option
is null, but the third is set:

74195 httpd    0.000017 RET   sigprocmask 0
74195 httpd    0.000013 CALL  sigprocmask(SIG_BLOCK,0,0xbfbf89d4)
74195 httpd    0.000009 RET   sigprocmask 0
74195 httpd    0.000013 CALL  sigprocmask(SIG_BLOCK,0,0xbfbf89d4)
74195 httpd    0.000009 RET   sigprocmask 0
74195 httpd    0.000012 CALL  sigprocmask(SIG_BLOCK,0,0xbfbf89d4)

But repeated hundreds of times in a row.

The calls cannot come from rtld, they are generated by some setjmp()
invocation. If signal-safety is not needed, sigsetjmp() should be used
instead.

Quick grep of the apache httpd source shows a single setjmp() in their
copy of pcre. No idea is it to safe to change setjmp() into sigsetjmp(?, 0).

I hate cross-posting, but: adding freebsd-apache@ to the list.  Some of
the Apache folks (not just port committers) may have some insight to
Kostik's findings.

Thanks to everyone for the responses. We tried Kostik's suggestion and
unfortunately it didn't reduce the number of sigprocmask() calls to a
statistically significant degree.

Does anyone have any other ideas on ways to debug this? We're sort of
running out of things to test. :-/

Given how important (and prevalent) the Apache + FreeBSD combination is,
I'm kind of disturbed that we're seeing this performance problem, and if
it's something in 8.x that's also in 9.x, it would be better to fix it
prior to 9.0-RELEASE.

Since my guess appeared to be not useful, the way forward is to identify
the location of the call(s) that cause the issue. I suggest compliling
at least apache itself, libc, rtld and libthr (if used) with debugging
information. Then, attach to the running apache worker with the gdb and
set breakpoint on sigprocmask. Several backtraces from the hit breakpoint
should give enough data.

High-tech solution is to link with libunwind and add code into sigprocmask()
to gather the stacks. But I expect that gdb attach is enough.

I am sorry for repeat (I wrote about it), but what do you think aboutthis hack:


diff -u ./rtld_lock.c.orig ./rtld_lock.c
--- ./rtld_lock.c.orig 2011-11-15 07:56:14.000000000 +0000
+++ ./rtld_lock.c 2011-11-15 07:54:42.000000000 +0000
@@ -118,7 +118,7 @@
sigset_t tmp_oldsigmask;

for ( ; ; ) {
- sigprocmask(SIG_BLOCK, &fullsigmask, &tmp_oldsigmask);
+// sigprocmask(SIG_BLOCK, &fullsigmask, &tmp_oldsigmask);
if (atomic_cmpset_acq_int(&l->lock, 0, WAFLAG))
break;
sigprocmask(SIG_SETMASK, &tmp_oldsigmask, NULL);
@@ -135,7 +135,7 @@
atomic_add_rel_int(&l->lock, -RC_INCR);
else {
atomic_add_rel_int(&l->lock, -WAFLAG);
- sigprocmask(SIG_SETMASK, &oldsigmask, NULL);
+// sigprocmask(SIG_SETMASK, &oldsigmask, NULL);
}
}

This is one of source sigprocmask. Look:
truss with original /libexec/ld-elf.so.1:

#truss true
__sysctl(0xbfbfe624,0x2,0xbfbfe62c,0xbfbfe630,0x0,0x0) = 0 (0x0)
mmap(0x0,320,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 671633408 (0x28085000)
munmap(0x28085000,320) = 0 (0x0)
__sysctl(0xbfbfe688,0x2,0x2807be3c,0xbfbfe690,0x0,0x0) = 0 (0x0)

mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) =671633408 (0x28085000)

issetugid(0x28074967,0xbfbfeb4c,0x104,0x0,0x0,0x0) = 0 (0x0)
open("/etc/libmap.conf",O_RDONLY,0666) ERR#2 'No such file or directory'
open("/var/run/ld-elf.so.hints",O_RDONLY,00) = 3 (0x3)
read(3,"Ehnt\^A\0\0\0\M^@\0\0\0\M^E\0\0"...,128) = 128 (0x80)
lseek(3,0x80,SEEK_SET) = 128 (0x80)
read(3,"/lib:/usr/lib:/usr/lib/compat:/u"...,133) = 133 (0x85)
close(3) = 0 (0x0)
access("/lib/libc.so.7",0) = 0 (0x0)
open("/lib/libc.so.7",O_RDONLY,00) = 3 (0x3)

fstat(3,{ mode=-r--r--r-- ,inode=94234,size=1155172,blksize=16384 }) = 0(0x0)

pread(0x3,0x2807ad80,0x1000,0x0,0x0,0x0) = 4096 (0x1000)

mprotect(0x28191000,94208,PROT_READ|PROT_WRITE) = 0 (0x0)
close(3) = 0 (0x0)

sysarch(0xa,0xbfbfe6f0,0x2804b3cb,0x2807a2f8,0x2805de39,0x2807a2f8) = 0(0x0)

mmap(0x0,64,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 672825344 (0x281a8000)
munmap(0x281a8000,64) = 0 (0x0)

mmap(0x0,21896,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 672825344(0x281a8000)

munmap(0x281a8000,21896) = 0 (0x0)

sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
__sysctl(0xbfbfe6a4,0x2,0x28192700,0xbfbfe6ac,0x0,0x0) = 0 (0x0)

sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)

sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)

sigprocmask(SIG_SETMASK,0x0,0x0) = 0 (0x0)
process exit, rval = 0


and truss after patching:

#truss true
__sysctl(0xbfbfe5a4,0x2,0xbfbfe5ac,0xbfbfe5b0,0x0,0x0) = 0 (0x0)
mmap(0x0,320,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 671633408 (0x28085000)
munmap(0x28085000,320) = 0 (0x0)
__sysctl(0xbfbfe608,0x2,0x2807be3c,0xbfbfe610,0x0,0x0) = 0 (0x0)

mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) =671633408 (0x28085000)

issetugid(0x28074927,0xbfbfeacc,0x104,0x0,0x0,0x0) = 0 (0x0)
open("/etc/libmap.conf",O_RDONLY,0666) ERR#2 'No such file or directory'
open("/var/run/ld-elf.so.hints",O_RDONLY,00) = 3 (0x3)
read(3,"Ehnt\^A\0\0\0\M^@\0\0\0B\0\0\0\0"...,128) = 128 (0x80)
lseek(3,0x80,SEEK_SET) = 128 (0x80)
read(3,"/lib:/usr/lib:/usr/lib/compat:/u"...,66) = 66 (0x42)
close(3) = 0 (0x0)
access("/lib/libc.so.7",0) = 0 (0x0)
open("/lib/libc.so.7",O_RDONLY,00) = 3 (0x3)
fstat(3,{ mode=-r--r--r-- ,inode=12,size=1155172,blksize=16384 }) = 0 (0x0)
pread(0x3,0x2807ad80,0x1000,0x0,0x0,0x0) = 4096 (0x1000)

mprotect(0x28191000,94208,PROT_READ|PROT_WRITE) = 0 (0x0)
close(3) = 0 (0x0)

sysarch(0xa,0xbfbfe670,0x2804b3cb,0x2807a2f8,0x2805ddf9,0x2807a2f8) = 0(0x0)

mmap(0x0,64,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 672825344 (0x281a8000)
munmap(0x281a8000,64) = 0 (0x0)

mmap(0x0,21896,PROT_READ|PROT_WRITE,MAP_ANON,-1,0x0) = 672825344(0x281a8000)

munmap(0x281a8000,21896) = 0 (0x0)
__sysctl(0xbfbfe624,0x2,0x28192700,0xbfbfe62c,0x0,0x0) = 0 (0x0)
process exit, rval = 0

I am not expert in the internal structure of ld-elf.so, but I am tryingto think there is more effective way for locks. Because now we are doinga few syscalls for each dynamic loaded library in fork time.



--

С уважением,
Daniil Cherednik
.masterhost

_______________________________________________
freebsd-stable@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "freebsd-stable-unsubscr...@freebsd.org"

Re: 8.2 + apache == a LOT of sigprocmask

Reply via email to